----------------------------------------------------------- This is an automatically generated e-mail. To reply, visit: https://reviews.apache.org/r/75016/#review226640 -----------------------------------------------------------
Bad patch! Reviews applied: [75026, 75006, 75016] Failed command: ['bash', '-c', "set -o pipefail; export OS='ubuntu:20.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/jenkins/buildbot.sh 2>&1 | tee build_75016"] Error: ...<truncated>... on 11 I0709 01:28:11.404711 185468 replica.cpp:712] Persisted action TRUNCATE at position 11 I0709 01:28:11.405929 185481 replica.cpp:695] Replica received learned notice for position 11 from log-network(41)@172.17.0.2:46245 I0709 01:28:11.405961 185486 replica.cpp:695] Replica received learned notice for position 11 from log-network(41)@172.17.0.2:46245 I0709 01:28:11.406947 185481 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 967341ns I0709 01:28:11.406970 185486 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 967031ns I0709 01:28:11.407653 185481 leveldb.cpp:460] Deleting ~5 keys from leveldb took 640256ns I0709 01:28:11.407768 185486 leveldb.cpp:460] Deleting ~5 keys from leveldb took 722359ns I0709 01:28:11.416152 185481 leveldb.cpp:527] Compacting range 0-4 took 8.482566ms I0709 01:28:11.416231 185481 replica.cpp:712] Persisted action TRUNCATE at position 11 I0709 01:28:11.416257 185486 leveldb.cpp:527] Compacting range 0-4 took 8.439209ms I0709 01:28:11.416355 185486 replica.cpp:712] Persisted action TRUNCATE at position 11 I0709 01:28:11.422883 185463 leveldb.cpp:217] Opened db in 5.226609ms I0709 01:28:11.425750 185463 leveldb.cpp:224] Compacted db in 2.839188ms I0709 01:28:11.425876 185463 leveldb.cpp:239] Created db iterator in 46793ns I0709 01:28:11.425925 185463 leveldb.cpp:245] Seeked to beginning of db in 34644ns I0709 01:28:11.425979 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 45128ns I0709 01:28:11.426028 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:11.426764 185479 catchup.cpp:342] Starting missing positions recovery I0709 01:28:11.427434 185482 catchup.cpp:368] Replica is in VOTING status I0709 01:28:11.429745 185485 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(884)@172.17.0.2:46245 I0709 01:28:11.429891 185486 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(885)@172.17.0.2:46245 I0709 01:28:11.431025 185483 recover.cpp:197] Received a recover response from a replica in VOTING status I0709 01:28:11.431632 185483 recover.cpp:197] Received a recover response from a replica in VOTING status I0709 01:28:11.433180 185479 catchup.cpp:423] Starting catch-up from position 0 to 10 I0709 01:28:11.435174 185469 replica.cpp:391] Replica received explicit promise request from __req_res__(887)@172.17.0.2:46245 for position 0 with proposal 0 I0709 01:28:11.435336 185472 replica.cpp:391] Replica received explicit promise request from __req_res__(888)@172.17.0.2:46245 for position 0 with proposal 0 I0709 01:28:11.435412 185484 replica.cpp:391] Replica received explicit promise request from __req_res__(889)@172.17.0.2:46245 for position 0 with proposal 0 I0709 01:28:11.436445 185487 replica.cpp:695] Replica received learned notice for position 0 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.436472 185480 replica.cpp:695] Replica received learned notice for position 0 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.436655 185467 replica.cpp:695] Replica received learned notice for position 0 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.437601 185480 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 1.063186ms I0709 01:28:11.437597 185487 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 1.096357ms I0709 01:28:11.437705 185480 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:11.437760 185487 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:11.437844 185467 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 1.121133ms I0709 01:28:11.437923 185467 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:11.440353 185476 replica.cpp:391] Replica received explicit promise request from __req_res__(891)@172.17.0.2:46245 for position 1 with proposal 0 I0709 01:28:11.440397 185479 replica.cpp:391] Replica received explicit promise request from __req_res__(892)@172.17.0.2:46245 for position 1 with proposal 0 I0709 01:28:11.440531 185464 replica.cpp:391] Replica received explicit promise request from __req_res__(890)@172.17.0.2:46245 for position 1 with proposal 0 I0709 01:28:11.624364 185465 replica.cpp:391] Replica received explicit promise request from __req_res__(894)@172.17.0.2:46245 for position 1 with proposal 1 I0709 01:28:11.624538 185475 replica.cpp:391] Replica received explicit promise request from __req_res__(895)@172.17.0.2:46245 for position 1 with proposal 1 I0709 01:28:11.624601 185478 replica.cpp:391] Replica received explicit promise request from __req_res__(893)@172.17.0.2:46245 for position 1 with proposal 1 I0709 01:28:11.625577 185470 replica.cpp:695] Replica received learned notice for position 1 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.625627 185481 replica.cpp:695] Replica received learned notice for position 1 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.625777 185475 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 1.170858ms I0709 01:28:11.625898 185475 replica.cpp:712] Persisted action NOP at position 1 I0709 01:28:11.626191 185475 replica.cpp:695] Replica received learned notice for position 1 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.626605 185481 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 934925ns I0709 01:28:11.626670 185470 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 1.045948ms I0709 01:28:11.626847 185475 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 640499ns I0709 01:28:11.627712 185481 leveldb.cpp:460] Deleting ~1 keys from leveldb took 1.047389ms I0709 01:28:11.627775 185475 leveldb.cpp:460] Deleting ~1 keys from leveldb took 875498ns I0709 01:28:11.627772 185470 leveldb.cpp:460] Deleting ~1 keys from leveldb took 1.042072ms I0709 01:28:11.636087 185475 leveldb.cpp:527] Compacting range 0-0 took 8.254968ms I0709 01:28:11.636190 185475 replica.cpp:712] Persisted action NOP at position 1 I0709 01:28:11.638118 185481 leveldb.cpp:527] Compacting range 0-0 took 10.341732ms I0709 01:28:11.638139 185470 leveldb.cpp:527] Compacting range 0-0 took 10.225065ms I0709 01:28:11.638198 185481 replica.cpp:712] Persisted action NOP at position 1 I0709 01:28:11.638237 185470 replica.cpp:712] Persisted action NOP at position 1 I0709 01:28:11.638283 185482 replica.cpp:391] Replica received explicit promise request from __req_res__(898)@172.17.0.2:46245 for position 2 with proposal 1 I0709 01:28:11.638337 185481 replica.cpp:391] Replica received explicit promise request from __req_res__(896)@172.17.0.2:46245 for position 2 with proposal 1 I0709 01:28:11.638417 185470 replica.cpp:391] Replica received explicit promise request from __req_res__(897)@172.17.0.2:46245 for position 2 with proposal 1 I0709 01:28:11.639283 185482 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 943259ns I0709 01:28:11.639365 185482 replica.cpp:712] Persisted action NOP at position 2 I0709 01:28:11.639676 185485 replica.cpp:695] Replica received learned notice for position 2 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.639832 185474 replica.cpp:695] Replica received learned notice for position 2 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.639883 185467 replica.cpp:695] Replica received learned notice for position 2 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.640566 185467 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 625166ns I0709 01:28:11.640672 185485 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 985627ns I0709 01:28:11.640811 185474 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 931589ns I0709 01:28:11.640929 185467 leveldb.cpp:460] Deleting ~1 keys from leveldb took 330937ns I0709 01:28:11.641274 185485 leveldb.cpp:460] Deleting ~1 keys from leveldb took 543623ns I0709 01:28:11.641358 185474 leveldb.cpp:460] Deleting ~1 keys from leveldb took 479904ns I0709 01:28:11.649770 185485 leveldb.cpp:527] Compacting range 1-1 took 8.432093ms I0709 01:28:11.649830 185474 leveldb.cpp:527] Compacting range 1-1 took 8.465704ms I0709 01:28:11.649892 185485 replica.cpp:712] Persisted action NOP at position 2 I0709 01:28:11.649857 185467 leveldb.cpp:527] Compacting range 1-1 took 8.916706ms I0709 01:28:11.649932 185474 replica.cpp:712] Persisted action NOP at position 2 I0709 01:28:11.649989 185467 replica.cpp:712] Persisted action NOP at position 2 I0709 01:28:11.652312 185481 replica.cpp:391] Replica received explicit promise request from __req_res__(901)@172.17.0.2:46245 for position 3 with proposal 1 I0709 01:28:11.652323 185482 replica.cpp:391] Replica received explicit promise request from __req_res__(899)@172.17.0.2:46245 for position 3 with proposal 1 I0709 01:28:11.652407 185469 replica.cpp:391] Replica received explicit promise request from __req_res__(900)@172.17.0.2:46245 for position 3 with proposal 1 I0709 01:28:11.652889 185481 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 537558ns I0709 01:28:11.652922 185481 replica.cpp:712] Persisted action NOP at position 3 I0709 01:28:11.653610 185466 replica.cpp:695] Replica received learned notice for position 3 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.653645 185476 replica.cpp:695] Replica received learned notice for position 3 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.653641 185485 replica.cpp:695] Replica received learned notice for position 3 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.654634 185476 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 932549ns I0709 01:28:11.654752 185466 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 1.091995ms I0709 01:28:11.654989 185485 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 1.249452ms I0709 01:28:11.655215 185476 leveldb.cpp:460] Deleting ~1 keys from leveldb took 563410ns I0709 01:28:11.655501 185485 leveldb.cpp:460] Deleting ~1 keys from leveldb took 459186ns I0709 01:28:11.655511 185466 leveldb.cpp:460] Deleting ~1 keys from leveldb took 695032ns I0709 01:28:11.665159 185476 leveldb.cpp:527] Compacting range 2-2 took 9.940628ms I0709 01:28:11.665210 185476 replica.cpp:712] Persisted action NOP at position 3 I0709 01:28:11.665228 185485 leveldb.cpp:527] Compacting range 2-2 took 9.681775ms I0709 01:28:11.665251 185466 leveldb.cpp:527] Compacting range 2-2 took 9.643369ms I0709 01:28:11.665334 185485 replica.cpp:712] Persisted action NOP at position 3 I0709 01:28:11.665386 185466 replica.cpp:712] Persisted action NOP at position 3 I0709 01:28:11.667166 185481 replica.cpp:391] Replica received explicit promise request from __req_res__(902)@172.17.0.2:46245 for position 4 with proposal 1 I0709 01:28:11.667351 185474 replica.cpp:391] Replica received explicit promise request from __req_res__(903)@172.17.0.2:46245 for position 4 with proposal 1 I0709 01:28:11.667433 185487 replica.cpp:391] Replica received explicit promise request from __req_res__(904)@172.17.0.2:46245 for position 4 with proposal 1 I0709 01:28:11.668246 185470 replica.cpp:695] Replica received learned notice for position 4 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.668394 185468 replica.cpp:695] Replica received learned notice for position 4 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.668504 185487 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 1.00255ms I0709 01:28:11.668552 185487 replica.cpp:712] Persisted action NOP at position 4 I0709 01:28:11.668700 185487 replica.cpp:695] Replica received learned notice for position 4 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.669075 185470 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 779981ns I0709 01:28:11.669257 185487 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 546038ns I0709 01:28:11.669369 185468 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 938657ns I0709 01:28:11.669559 185470 leveldb.cpp:460] Deleting ~1 keys from leveldb took 429764ns I0709 01:28:11.669801 185487 leveldb.cpp:460] Deleting ~1 keys from leveldb took 554400ns I0709 01:28:11.670377 185468 leveldb.cpp:460] Deleting ~1 keys from leveldb took 954848ns I0709 01:28:11.680472 185468 leveldb.cpp:527] Compacting range 3-3 took 10.046384ms I0709 01:28:11.680472 185470 leveldb.cpp:527] Compacting range 3-3 took 10.923166ms I0709 01:28:11.680488 185487 leveldb.cpp:527] Compacting range 3-3 took 10.648002ms I0709 01:28:11.680590 185468 replica.cpp:712] Persisted action NOP at position 4 I0709 01:28:11.680619 185470 replica.cpp:712] Persisted action NOP at position 4 I0709 01:28:11.680676 185487 replica.cpp:712] Persisted action NOP at position 4 I0709 01:28:11.683328 185464 replica.cpp:391] Replica received explicit promise request from __req_res__(905)@172.17.0.2:46245 for position 5 with proposal 1 I0709 01:28:11.683455 185473 replica.cpp:391] Replica received explicit promise request from __req_res__(906)@172.17.0.2:46245 for position 5 with proposal 1 I0709 01:28:11.683498 185474 replica.cpp:391] Replica received explicit promise request from __req_res__(907)@172.17.0.2:46245 for position 5 with proposal 1 I0709 01:28:11.683574 185464 leveldb.cpp:510] Reading position from leveldb took 160571ns I0709 01:28:11.683676 185473 leveldb.cpp:510] Reading position from leveldb took 149022ns I0709 01:28:11.684531 185474 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 996116ns I0709 01:28:11.684615 185474 replica.cpp:712] Persisted action NOP at position 5 I0709 01:28:11.825748 185467 replica.cpp:391] Replica received explicit promise request from __req_res__(908)@172.17.0.2:46245 for position 5 with proposal 2 I0709 01:28:11.825783 185480 replica.cpp:391] Replica received explicit promise request from __req_res__(910)@172.17.0.2:46245 for position 5 with proposal 2 I0709 01:28:11.825912 185465 replica.cpp:391] Replica received explicit promise request from __req_res__(909)@172.17.0.2:46245 for position 5 with proposal 2 I0709 01:28:11.825968 185480 leveldb.cpp:510] Reading position from leveldb took 81237ns I0709 01:28:11.825995 185467 leveldb.cpp:510] Reading position from leveldb took 144560ns I0709 01:28:11.826115 185465 leveldb.cpp:510] Reading position from leveldb took 132513ns I0709 01:28:11.827150 185467 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.095777ms I0709 01:28:11.827183 185480 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 1.174678ms I0709 01:28:11.827260 185467 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:11.827296 185480 replica.cpp:712] Persisted action NOP at position 5 I0709 01:28:11.827478 185465 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.298873ms I0709 01:28:11.827551 185465 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:11.828833 185470 replica.cpp:695] Replica received learned notice for position 5 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.828948 185474 replica.cpp:695] Replica received learned notice for position 5 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.829013 185482 replica.cpp:695] Replica received learned notice for position 5 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.829908 185482 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 844821ns I0709 01:28:11.829941 185474 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 938355ns I0709 01:28:11.829942 185470 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.06699ms I0709 01:28:11.830096 185470 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:11.829975 185482 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:11.830034 185474 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:11.832904 185465 replica.cpp:391] Replica received explicit promise request from __req_res__(911)@172.17.0.2:46245 for position 6 with proposal 2 I0709 01:28:11.832950 185471 replica.cpp:391] Replica received explicit promise request from __req_res__(912)@172.17.0.2:46245 for position 6 with proposal 2 I0709 01:28:11.833050 185468 replica.cpp:391] Replica received explicit promise request from __req_res__(913)@172.17.0.2:46245 for position 6 with proposal 2 I0709 01:28:11.833134 185465 leveldb.cpp:510] Reading position from leveldb took 150823ns I0709 01:28:11.833170 185471 leveldb.cpp:510] Reading position from leveldb took 142642ns I0709 01:28:11.833895 185471 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 665099ns I0709 01:28:11.833948 185471 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:11.833938 185465 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 739572ns I0709 01:28:11.833938 185468 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 850133ns I0709 01:28:11.834040 185465 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:11.834069 185468 replica.cpp:712] Persisted action NOP at position 6 I0709 01:28:11.835479 185479 replica.cpp:695] Replica received learned notice for position 6 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.835566 185471 replica.cpp:695] Replica received learned notice for position 6 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.835724 185472 replica.cpp:695] Replica received learned notice for position 6 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.836341 185479 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 813552ns I0709 01:28:11.836386 185471 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 774700ns I0709 01:28:11.836422 185479 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:11.836486 185471 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:11.836735 185472 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 960515ns I0709 01:28:11.836813 185472 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:11.839046 185469 replica.cpp:391] Replica received explicit promise request from __req_res__(915)@172.17.0.2:46245 for position 7 with proposal 2 I0709 01:28:11.839128 185482 replica.cpp:391] Replica received explicit promise request from __req_res__(916)@172.17.0.2:46245 for position 7 with proposal 2 I0709 01:28:11.839212 185478 replica.cpp:391] Replica received explicit promise request from __req_res__(914)@172.17.0.2:46245 for position 7 with proposal 2 I0709 01:28:11.839236 185469 leveldb.cpp:510] Reading position from leveldb took 125418ns I0709 01:28:11.839422 185478 leveldb.cpp:510] Reading position from leveldb took 131538ns I0709 01:28:11.839885 185469 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 541408ns I0709 01:28:11.839931 185469 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:11.839985 185482 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 799232ns I0709 01:28:11.840063 185482 replica.cpp:712] Persisted action NOP at position 7 I0709 01:28:11.840188 185478 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 718113ns I0709 01:28:11.840265 185478 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:11.841323 185487 replica.cpp:695] Replica received learned notice for position 7 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.841485 185472 replica.cpp:695] Replica received learned notice for position 7 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.841619 185483 replica.cpp:695] Replica received learned notice for position 7 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.842272 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 926540ns I0709 01:28:11.842358 185487 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:11.842903 185483 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.234163ms I0709 01:28:11.842929 185472 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.397678ms I0709 01:28:11.843003 185483 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:11.843046 185472 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:11.845546 185467 replica.cpp:391] Replica received explicit promise request from __req_res__(917)@172.17.0.2:46245 for position 8 with proposal 2 I0709 01:28:11.845674 185479 replica.cpp:391] Replica received explicit promise request from __req_res__(919)@172.17.0.2:46245 for position 8 with proposal 2 I0709 01:28:11.845742 185467 leveldb.cpp:510] Reading position from leveldb took 135024ns I0709 01:28:11.845784 185466 replica.cpp:391] Replica received explicit promise request from __req_res__(918)@172.17.0.2:46245 for position 8 with proposal 2 I0709 01:28:11.846016 185466 leveldb.cpp:510] Reading position from leveldb took 135462ns I0709 01:28:11.846647 185467 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 821085ns I0709 01:28:11.846695 185467 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:11.846771 185479 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 1.03732ms I0709 01:28:11.846877 185479 replica.cpp:712] Persisted action NOP at position 8 I0709 01:28:11.847254 185466 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.190899ms I0709 01:28:11.847361 185466 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:11.847961 185487 replica.cpp:695] Replica received learned notice for position 8 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.848068 185474 replica.cpp:695] Replica received learned notice for position 8 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.848148 185484 replica.cpp:695] Replica received learned notice for position 8 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.848945 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 958024ns I0709 01:28:11.849031 185487 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:11.849411 185484 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.208639ms I0709 01:28:11.849416 185474 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.300066ms I0709 01:28:11.849509 185484 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:11.849596 185474 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:11.851769 185465 replica.cpp:391] Replica received explicit promise request from __req_res__(920)@172.17.0.2:46245 for position 9 with proposal 2 I0709 01:28:11.851820 185475 replica.cpp:391] Replica received explicit promise request from __req_res__(921)@172.17.0.2:46245 for position 9 with proposal 2 I0709 01:28:11.851975 185465 leveldb.cpp:510] Reading position from leveldb took 132773ns I0709 01:28:11.851984 185470 replica.cpp:391] Replica received explicit promise request from __req_res__(922)@172.17.0.2:46245 for position 9 with proposal 2 I0709 01:28:11.852021 185475 leveldb.cpp:510] Reading position from leveldb took 130950ns I0709 01:28:11.852994 185475 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 904094ns I0709 01:28:11.852993 185465 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 976431ns I0709 01:28:11.853147 185465 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:11.853034 185470 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 994338ns I0709 01:28:11.853257 185470 replica.cpp:712] Persisted action NOP at position 9 I0709 01:28:11.853085 185475 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:11.854756 185481 replica.cpp:695] Replica received learned notice for position 9 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.854990 185477 replica.cpp:695] Replica received learned notice for position 9 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.855137 185482 replica.cpp:695] Replica received learned notice for position 9 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.855650 185477 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 601395ns I0709 01:28:11.855700 185477 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:11.855787 185481 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 980544ns I0709 01:28:11.855875 185481 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:11.856002 185482 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 809847ns I0709 01:28:11.856083 185482 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:11.857583 185487 replica.cpp:391] Replica received explicit promise request from __req_res__(923)@172.17.0.2:46245 for position 10 with proposal 2 I0709 01:28:11.857692 185487 leveldb.cpp:510] Reading position from leveldb took 68729ns I0709 01:28:11.857726 185478 replica.cpp:391] Replica received explicit promise request from __req_res__(924)@172.17.0.2:46245 for position 10 with proposal 2 I0709 01:28:11.857842 185464 replica.cpp:391] Replica received explicit promise request from __req_res__(925)@172.17.0.2:46245 for position 10 with proposal 2 I0709 01:28:11.857957 185478 leveldb.cpp:510] Reading position from leveldb took 170058ns I0709 01:28:11.858489 185487 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 770044ns I0709 01:28:11.858508 185487 replica.cpp:712] Persisted action APPEND at position 10 I0709 01:28:11.859113 185478 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 1.097565ms I0709 01:28:11.859128 185464 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 1.216337ms I0709 01:28:11.859213 185478 replica.cpp:712] Persisted action APPEND at position 10 I0709 01:28:11.859302 185464 replica.cpp:712] Persisted action NOP at position 10 I0709 01:28:11.859483 185469 replica.cpp:695] Replica received learned notice for position 10 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.859815 185464 replica.cpp:695] Replica received learned notice for position 10 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.859980 185478 replica.cpp:695] Replica received learned notice for position 10 from log-network(42)@172.17.0.2:46245 I0709 01:28:11.860544 185469 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 1.01808ms I0709 01:28:11.860652 185469 replica.cpp:712] Persisted action APPEND at position 10 I0709 01:28:11.860752 185478 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 708119ns I0709 01:28:11.860806 185478 replica.cpp:712] Persisted action APPEND at position 10 I0709 01:28:11.860852 185464 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 989595ns I0709 01:28:11.860942 185464 replica.cpp:712] Persisted action APPEND at position 10 I0709 01:28:11.861574 185475 catchup.cpp:357] Recover process terminated I0709 01:28:11.863759 185472 leveldb.cpp:510] Reading position from leveldb took 109355ns I0709 01:28:11.863886 185472 leveldb.cpp:510] Reading position from leveldb took 36995ns I0709 01:28:11.863945 185472 leveldb.cpp:510] Reading position from leveldb took 26617ns I0709 01:28:11.864001 185472 leveldb.cpp:510] Reading position from leveldb took 26393ns I0709 01:28:11.864055 185472 leveldb.cpp:510] Reading position from leveldb took 24917ns I0709 01:28:11.864114 185472 leveldb.cpp:510] Reading position from leveldb took 25912ns [ OK ] RecoverTest.CatchupVotingWithGap (569 ms) [ RUN ] RecoverTest.CatchupVotingOnePosition I0709 01:28:11.876224 185463 leveldb.cpp:217] Opened db in 6.095386ms I0709 01:28:11.878087 185463 leveldb.cpp:224] Compacted db in 1.839081ms I0709 01:28:11.878221 185463 leveldb.cpp:239] Created db iterator in 49259ns I0709 01:28:11.878242 185463 leveldb.cpp:245] Seeked to beginning of db in 8819ns I0709 01:28:11.878258 185463 leveldb.cpp:320] Iterated through 0 keys in the db in 6228ns I0709 01:28:11.878315 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:11.880013 185480 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 1.234052ms I0709 01:28:11.880105 185480 replica.cpp:322] Persisted replica status to VOTING I0709 01:28:11.885087 185463 leveldb.cpp:217] Opened db in 4.246863ms I0709 01:28:11.886719 185463 leveldb.cpp:224] Compacted db in 1.608564ms I0709 01:28:11.886811 185463 leveldb.cpp:239] Created db iterator in 31187ns I0709 01:28:11.886823 185463 leveldb.cpp:245] Seeked to beginning of db in 5337ns I0709 01:28:11.886832 185463 leveldb.cpp:320] Iterated through 0 keys in the db in 3557ns I0709 01:28:11.886870 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:11.888401 185484 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 1.069893ms I0709 01:28:11.888489 185484 replica.cpp:322] Persisted replica status to VOTING I0709 01:28:11.893568 185463 leveldb.cpp:217] Opened db in 4.292917ms I0709 01:28:11.895314 185463 leveldb.cpp:224] Compacted db in 1.722998ms I0709 01:28:11.895403 185463 leveldb.cpp:239] Created db iterator in 29198ns I0709 01:28:11.895416 185463 leveldb.cpp:245] Seeked to beginning of db in 5392ns I0709 01:28:11.895426 185463 leveldb.cpp:320] Iterated through 0 keys in the db in 3700ns I0709 01:28:11.895462 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:11.896937 185468 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 822638ns I0709 01:28:11.896970 185468 replica.cpp:322] Persisted replica status to VOTING I0709 01:28:11.901962 185463 leveldb.cpp:217] Opened db in 4.495111ms I0709 01:28:11.907035 185463 leveldb.cpp:224] Compacted db in 5.05051ms I0709 01:28:11.907130 185463 leveldb.cpp:239] Created db iterator in 37473ns I0709 01:28:11.907179 185463 leveldb.cpp:245] Seeked to beginning of db in 37258ns I0709 01:28:11.907236 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 45666ns I0709 01:28:11.907285 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:11.911895 185463 leveldb.cpp:217] Opened db in 4.366473ms I0709 01:28:11.916003 185463 leveldb.cpp:224] Compacted db in 4.086443ms I0709 01:28:11.916095 185463 leveldb.cpp:239] Created db iterator in 37040ns I0709 01:28:11.916146 185463 leveldb.cpp:245] Seeked to beginning of db in 37614ns I0709 01:28:11.916198 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 42889ns I0709 01:28:11.916246 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:11.920859 185463 leveldb.cpp:217] Opened db in 4.384287ms I0709 01:28:11.925139 185463 leveldb.cpp:224] Compacted db in 4.257283ms I0709 01:28:11.925231 185463 leveldb.cpp:239] Created db iterator in 34348ns I0709 01:28:11.925271 185463 leveldb.cpp:245] Seeked to beginning of db in 29424ns I0709 01:28:11.925313 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 34626ns I0709 01:28:11.925349 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:11.925865 185472 catchup.cpp:342] Starting missing positions recovery I0709 01:28:11.926478 185464 catchup.cpp:368] Replica is in VOTING status I0709 01:28:11.928521 185474 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(926)@172.17.0.2:46245 I0709 01:28:11.928563 185481 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(927)@172.17.0.2:46245 I0709 01:28:11.928690 185473 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(928)@172.17.0.2:46245 I0709 01:28:11.929579 185479 recover.cpp:197] Received a recover response from a replica in VOTING status I0709 01:28:11.930235 185479 recover.cpp:197] Received a recover response from a replica in VOTING status I0709 01:28:11.931449 185480 catchup.cpp:357] Recover process terminated [ OK ] RecoverTest.CatchupVotingOnePosition (66 ms) [----------] 9 tests from RecoverTest (3571 ms total) [----------] 4 tests from LogTest [ RUN ] LogTest.WriteRead I0709 01:28:11.940855 185463 leveldb.cpp:217] Opened db in 4.74175ms I0709 01:28:11.942656 185463 leveldb.cpp:224] Compacted db in 1.77763ms I0709 01:28:11.942746 185463 leveldb.cpp:239] Created db iterator in 29829ns I0709 01:28:11.942759 185463 leveldb.cpp:245] Seeked to beginning of db in 5243ns I0709 01:28:11.942768 185463 leveldb.cpp:320] Iterated through 0 keys in the db in 3720ns I0709 01:28:11.942806 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:11.944574 185472 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 1.35869ms I0709 01:28:11.945389 185472 replica.cpp:322] Persisted replica status to VOTING I0709 01:28:11.951794 185463 leveldb.cpp:217] Opened db in 5.550911ms I0709 01:28:11.953687 185463 leveldb.cpp:224] Compacted db in 1.849175ms I0709 01:28:11.953773 185463 leveldb.cpp:239] Created db iterator in 37101ns I0709 01:28:11.953800 185463 leveldb.cpp:245] Seeked to beginning of db in 8449ns I0709 01:28:11.953851 185463 leveldb.cpp:320] Iterated through 0 keys in the db in 8093ns I0709 01:28:11.953910 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:11.955631 185483 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 1.21131ms I0709 01:28:11.955724 185483 replica.cpp:322] Persisted replica status to VOTING I0709 01:28:11.962352 185463 leveldb.cpp:217] Opened db in 5.720501ms I0709 01:28:11.966940 185463 leveldb.cpp:224] Compacted db in 4.545976ms I0709 01:28:11.967034 185463 leveldb.cpp:239] Created db iterator in 35018ns I0709 01:28:11.967072 185463 leveldb.cpp:245] Seeked to beginning of db in 29249ns I0709 01:28:11.967114 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 36574ns I0709 01:28:11.967149 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:11.973074 185463 leveldb.cpp:217] Opened db in 5.55607ms I0709 01:28:11.977520 185463 leveldb.cpp:224] Compacted db in 4.411421ms I0709 01:28:11.977648 185463 leveldb.cpp:239] Created db iterator in 48385ns I0709 01:28:11.977706 185463 leveldb.cpp:245] Seeked to beginning of db in 43959ns I0709 01:28:11.977783 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 65066ns I0709 01:28:11.977905 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:11.978852 185464 recover.cpp:437] Starting replica recovery I0709 01:28:11.979372 185464 recover.cpp:468] Replica is in VOTING status I0709 01:28:11.979648 185464 recover.cpp:447] Recover process terminated I0709 01:28:11.980465 185485 log.cpp:554] Attempting to start the writer I0709 01:28:11.982786 185483 replica.cpp:497] Replica received implicit promise request from __req_res__(929)@172.17.0.2:46245 with proposal 1 I0709 01:28:11.982838 185473 replica.cpp:497] Replica received implicit promise request from __req_res__(930)@172.17.0.2:46245 with proposal 1 I0709 01:28:11.984033 185483 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 1.179872ms I0709 01:28:11.984097 185483 replica.cpp:344] Persisted promised to 1 I0709 01:28:11.984107 185473 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 1.203392ms I0709 01:28:11.984192 185473 replica.cpp:344] Persisted promised to 1 I0709 01:28:11.985457 185472 coordinator.cpp:238] Coordinator attempting to fill missing positions I0709 01:28:11.987776 185467 replica.cpp:391] Replica received explicit promise request from __req_res__(931)@172.17.0.2:46245 for position 0 with proposal 2 I0709 01:28:11.987920 185468 replica.cpp:391] Replica received explicit promise request from __req_res__(932)@172.17.0.2:46245 for position 0 with proposal 2 I0709 01:28:11.988698 185468 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 688456ns I0709 01:28:11.988725 185468 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:11.988804 185467 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 946611ns I0709 01:28:11.988898 185467 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:11.990677 185484 replica.cpp:541] Replica received write request for position 0 from __req_res__(933)@172.17.0.2:46245 I0709 01:28:11.990773 185487 replica.cpp:541] Replica received write request for position 0 from __req_res__(934)@172.17.0.2:46245 I0709 01:28:11.990834 185484 leveldb.cpp:510] Reading position from leveldb took 81761ns I0709 01:28:11.990852 185487 leveldb.cpp:510] Reading position from leveldb took 38490ns I0709 01:28:11.991804 185487 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 915539ns I0709 01:28:11.991852 185487 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:11.991865 185484 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 977612ns I0709 01:28:11.991951 185484 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:11.993044 185480 replica.cpp:695] Replica received learned notice for position 0 from log-network(44)@172.17.0.2:46245 I0709 01:28:11.993093 185483 replica.cpp:695] Replica received learned notice for position 0 from log-network(44)@172.17.0.2:46245 I0709 01:28:11.994033 185480 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 934319ns I0709 01:28:11.994093 185480 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:11.994125 185483 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 975271ns I0709 01:28:11.994211 185483 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:11.995231 185478 log.cpp:570] Writer started with ending position 0 I0709 01:28:11.996109 185469 log.cpp:578] Attempting to append 11 bytes to the log I0709 01:28:11.996346 185486 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 I0709 01:28:11.997656 185476 replica.cpp:541] Replica received write request for position 1 from __req_res__(935)@172.17.0.2:46245 I0709 01:28:11.997680 185475 replica.cpp:541] Replica received write request for position 1 from __req_res__(936)@172.17.0.2:46245 I0709 01:28:11.998823 185475 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 1.088057ms I0709 01:28:11.998922 185475 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:11.998831 185476 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 1.1176ms I0709 01:28:11.999063 185476 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.000118 185478 replica.cpp:695] Replica received learned notice for position 1 from log-network(44)@172.17.0.2:46245 I0709 01:28:12.000195 185482 replica.cpp:695] Replica received learned notice for position 1 from log-network(44)@172.17.0.2:46245 I0709 01:28:12.001091 185482 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 828737ns I0709 01:28:12.001142 185482 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.001183 185478 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 1.013181ms I0709 01:28:12.001273 185478 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.003721 185466 leveldb.cpp:510] Reading position from leveldb took 133292ns [ OK ] LogTest.WriteRead (74 ms) [ RUN ] LogTest.Position I0709 01:28:12.016335 185463 leveldb.cpp:217] Opened db in 6.395423ms I0709 01:28:12.018359 185463 leveldb.cpp:224] Compacted db in 1.988378ms I0709 01:28:12.018489 185463 leveldb.cpp:239] Created db iterator in 46066ns I0709 01:28:12.018512 185463 leveldb.cpp:245] Seeked to beginning of db in 8912ns I0709 01:28:12.018527 185463 leveldb.cpp:320] Iterated through 0 keys in the db in 6084ns I0709 01:28:12.018587 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.020520 185470 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 1.357501ms I0709 01:28:12.020612 185470 replica.cpp:322] Persisted replica status to VOTING I0709 01:28:12.026574 185463 leveldb.cpp:217] Opened db in 4.966552ms I0709 01:28:12.028242 185463 leveldb.cpp:224] Compacted db in 1.628941ms I0709 01:28:12.028297 185463 leveldb.cpp:239] Created db iterator in 28607ns I0709 01:28:12.028312 185463 leveldb.cpp:245] Seeked to beginning of db in 6327ns I0709 01:28:12.028324 185463 leveldb.cpp:320] Iterated through 0 keys in the db in 4622ns I0709 01:28:12.028367 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.029865 185477 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 1.075877ms I0709 01:28:12.029958 185477 replica.cpp:322] Persisted replica status to VOTING I0709 01:28:12.035053 185463 leveldb.cpp:217] Opened db in 4.239466ms I0709 01:28:12.039182 185463 leveldb.cpp:224] Compacted db in 4.102259ms I0709 01:28:12.039292 185463 leveldb.cpp:239] Created db iterator in 41165ns I0709 01:28:12.039337 185463 leveldb.cpp:245] Seeked to beginning of db in 35643ns I0709 01:28:12.039388 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 43552ns I0709 01:28:12.039433 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.044263 185463 leveldb.cpp:217] Opened db in 4.55804ms I0709 01:28:12.048921 185463 leveldb.cpp:224] Compacted db in 4.630154ms I0709 01:28:12.049026 185463 leveldb.cpp:239] Created db iterator in 39766ns I0709 01:28:12.049072 185463 leveldb.cpp:245] Seeked to beginning of db in 34448ns I0709 01:28:12.049122 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 41266ns I0709 01:28:12.049165 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.050035 185474 recover.cpp:437] Starting replica recovery I0709 01:28:12.050482 185476 recover.cpp:468] Replica is in VOTING status I0709 01:28:12.050745 185476 recover.cpp:447] Recover process terminated I0709 01:28:12.051502 185487 log.cpp:554] Attempting to start the writer I0709 01:28:12.053892 185471 replica.cpp:497] Replica received implicit promise request from __req_res__(937)@172.17.0.2:46245 with proposal 1 I0709 01:28:12.054046 185479 replica.cpp:497] Replica received implicit promise request from __req_res__(938)@172.17.0.2:46245 with proposal 1 I0709 01:28:12.054992 185471 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 1.026864ms I0709 01:28:12.055065 185471 replica.cpp:344] Persisted promised to 1 I0709 01:28:12.055064 185479 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 966701ns I0709 01:28:12.055145 185479 replica.cpp:344] Persisted promised to 1 I0709 01:28:12.056233 185475 coordinator.cpp:238] Coordinator attempting to fill missing positions I0709 01:28:12.058415 185485 replica.cpp:391] Replica received explicit promise request from __req_res__(939)@172.17.0.2:46245 for position 0 with proposal 2 I0709 01:28:12.058522 185472 replica.cpp:391] Replica received explicit promise request from __req_res__(940)@172.17.0.2:46245 for position 0 with proposal 2 I0709 01:28:12.059247 185485 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 740082ns I0709 01:28:12.059296 185485 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.059850 185472 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 1.250663ms I0709 01:28:12.059949 185472 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.061717 185476 replica.cpp:541] Replica received write request for position 0 from __req_res__(941)@172.17.0.2:46245 I0709 01:28:12.061805 185465 replica.cpp:541] Replica received write request for position 0 from __req_res__(942)@172.17.0.2:46245 I0709 01:28:12.061867 185476 leveldb.cpp:510] Reading position from leveldb took 90541ns I0709 01:28:12.061969 185465 leveldb.cpp:510] Reading position from leveldb took 70445ns I0709 01:28:12.062815 185476 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 867159ns I0709 01:28:12.062853 185476 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.062871 185465 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 856765ns I0709 01:28:12.062953 185465 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.063977 185467 replica.cpp:695] Replica received learned notice for position 0 from log-network(45)@172.17.0.2:46245 I0709 01:28:12.064015 185470 replica.cpp:695] Replica received learned notice for position 0 from log-network(45)@172.17.0.2:46245 I0709 01:28:12.065132 185467 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 1.106672ms I0709 01:28:12.065135 185470 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 1.055791ms I0709 01:28:12.065237 185467 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.065316 185470 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.066277 185483 log.cpp:570] Writer started with ending position 0 I0709 01:28:12.067261 185468 log.cpp:578] Attempting to append 11 bytes to the log I0709 01:28:12.067627 185477 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 I0709 01:28:12.068977 185471 replica.cpp:541] Replica received write request for position 1 from __req_res__(943)@172.17.0.2:46245 I0709 01:28:12.069113 185472 replica.cpp:541] Replica received write request for position 1 from __req_res__(944)@172.17.0.2:46245 I0709 01:28:12.069775 185471 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 715982ns I0709 01:28:12.069861 185471 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.069995 185472 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 813367ns I0709 01:28:12.070082 185472 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.070988 185475 replica.cpp:695] Replica received learned notice for position 1 from log-network(45)@172.17.0.2:46245 I0709 01:28:12.070999 185482 replica.cpp:695] Replica received learned notice for position 1 from log-network(45)@172.17.0.2:46245 I0709 01:28:12.071722 185475 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 688364ns I0709 01:28:12.071774 185475 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.071805 185482 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 722695ns I0709 01:28:12.071892 185482 replica.cpp:712] Persisted action APPEND at position 1 [ OK ] LogTest.Position (66 ms) [ RUN ] LogTest.Metrics I0709 01:28:12.081689 185463 leveldb.cpp:217] Opened db in 5.257086ms I0709 01:28:12.083824 185463 leveldb.cpp:224] Compacted db in 2.105929ms I0709 01:28:12.083930 185463 leveldb.cpp:239] Created db iterator in 36627ns I0709 01:28:12.083945 185463 leveldb.cpp:245] Seeked to beginning of db in 6670ns I0709 01:28:12.083957 185463 leveldb.cpp:320] Iterated through 0 keys in the db in 4725ns I0709 01:28:12.084004 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.085366 185487 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 864941ns I0709 01:28:12.085441 185487 replica.cpp:322] Persisted replica status to VOTING I0709 01:28:12.090615 185463 leveldb.cpp:217] Opened db in 4.401646ms I0709 01:28:12.094631 185463 leveldb.cpp:224] Compacted db in 3.990614ms I0709 01:28:12.094741 185463 leveldb.cpp:239] Created db iterator in 41909ns I0709 01:28:12.094787 185463 leveldb.cpp:245] Seeked to beginning of db in 35601ns I0709 01:28:12.094841 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 48398ns I0709 01:28:12.094902 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.095880 185474 recover.cpp:437] Starting replica recovery I0709 01:28:12.096387 185474 recover.cpp:468] Replica is in VOTING status I0709 01:28:12.096658 185474 recover.cpp:447] Recover process terminated I0709 01:28:12.097594 185484 log.cpp:554] Attempting to start the writer I0709 01:28:12.099460 185465 replica.cpp:497] Replica received implicit promise request from __req_res__(945)@172.17.0.2:46245 with proposal 1 I0709 01:28:12.100492 185465 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 964432ns I0709 01:28:12.100543 185465 replica.cpp:344] Persisted promised to 1 I0709 01:28:12.101684 185477 coordinator.cpp:238] Coordinator attempting to fill missing positions I0709 01:28:12.104218 185483 replica.cpp:391] Replica received explicit promise request from __req_res__(946)@172.17.0.2:46245 for position 0 with proposal 2 I0709 01:28:12.105288 185483 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 991431ns I0709 01:28:12.105345 185483 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.107062 185477 replica.cpp:541] Replica received write request for position 0 from __req_res__(947)@172.17.0.2:46245 I0709 01:28:12.107189 185477 leveldb.cpp:510] Reading position from leveldb took 68705ns I0709 01:28:12.108246 185477 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 1.011521ms I0709 01:28:12.108330 185477 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.109396 185472 replica.cpp:695] Replica received learned notice for position 0 from log-network(46)@172.17.0.2:46245 I0709 01:28:12.110499 185472 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 1.052672ms I0709 01:28:12.110596 185472 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.111567 185478 log.cpp:570] Writer started with ending position 0 I0709 01:28:12.117408 185477 process.cpp:3671] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' [ OK ] LogTest.Metrics (53 ms) [ RUN ] LogTest.ReaderCatchup I0709 01:28:12.134904 185463 leveldb.cpp:217] Opened db in 5.688887ms I0709 01:28:12.136996 185463 leveldb.cpp:224] Compacted db in 2.062499ms I0709 01:28:12.137125 185463 leveldb.cpp:239] Created db iterator in 46162ns I0709 01:28:12.137147 185463 leveldb.cpp:245] Seeked to beginning of db in 9173ns I0709 01:28:12.137164 185463 leveldb.cpp:320] Iterated through 0 keys in the db in 6682ns I0709 01:28:12.137220 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.138748 185487 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 1.03228ms I0709 01:28:12.138824 185487 replica.cpp:322] Persisted replica status to VOTING I0709 01:28:12.143226 185463 leveldb.cpp:217] Opened db in 3.586698ms I0709 01:28:12.144591 185463 leveldb.cpp:224] Compacted db in 1.340801ms I0709 01:28:12.144701 185463 leveldb.cpp:239] Created db iterator in 35484ns I0709 01:28:12.144718 185463 leveldb.cpp:245] Seeked to beginning of db in 6672ns I0709 01:28:12.144729 185463 leveldb.cpp:320] Iterated through 0 keys in the db in 4766ns I0709 01:28:12.144774 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.146121 185471 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 929863ns I0709 01:28:12.146164 185471 replica.cpp:322] Persisted replica status to VOTING I0709 01:28:12.152592 185463 leveldb.cpp:217] Opened db in 5.70924ms I0709 01:28:12.154296 185463 leveldb.cpp:224] Compacted db in 1.675141ms I0709 01:28:12.154397 185463 leveldb.cpp:239] Created db iterator in 33795ns I0709 01:28:12.154414 185463 leveldb.cpp:245] Seeked to beginning of db in 6700ns I0709 01:28:12.154426 185463 leveldb.cpp:320] Iterated through 0 keys in the db in 4600ns I0709 01:28:12.154470 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.156062 185483 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 1.140721ms I0709 01:28:12.156155 185483 replica.cpp:322] Persisted replica status to VOTING I0709 01:28:12.161235 185463 leveldb.cpp:217] Opened db in 4.382363ms I0709 01:28:12.165212 185463 leveldb.cpp:224] Compacted db in 3.947721ms I0709 01:28:12.165316 185463 leveldb.cpp:239] Created db iterator in 39413ns I0709 01:28:12.165361 185463 leveldb.cpp:245] Seeked to beginning of db in 35639ns I0709 01:28:12.165416 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 45928ns I0709 01:28:12.165460 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.169631 185463 leveldb.cpp:217] Opened db in 3.891127ms I0709 01:28:12.173743 185463 leveldb.cpp:224] Compacted db in 4.085204ms I0709 01:28:12.173862 185463 leveldb.cpp:239] Created db iterator in 40638ns I0709 01:28:12.173907 185463 leveldb.cpp:245] Seeked to beginning of db in 34118ns I0709 01:28:12.173959 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 42246ns I0709 01:28:12.174005 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.176606 185481 replica.cpp:497] Replica received implicit promise request from __req_res__(948)@172.17.0.2:46245 with proposal 1 I0709 01:28:12.176678 185486 replica.cpp:497] Replica received implicit promise request from __req_res__(949)@172.17.0.2:46245 with proposal 1 I0709 01:28:12.177465 185481 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 787036ns I0709 01:28:12.177498 185481 replica.cpp:344] Persisted promised to 1 I0709 01:28:12.177678 185486 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 935266ns I0709 01:28:12.177723 185486 replica.cpp:344] Persisted promised to 1 I0709 01:28:12.179103 185479 coordinator.cpp:238] Coordinator attempting to fill missing positions I0709 01:28:12.180742 185471 replica.cpp:391] Replica received explicit promise request from __req_res__(951)@172.17.0.2:46245 for position 0 with proposal 2 I0709 01:28:12.180769 185482 replica.cpp:391] Replica received explicit promise request from __req_res__(950)@172.17.0.2:46245 for position 0 with proposal 2 I0709 01:28:12.181481 185471 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 696371ns I0709 01:28:12.181510 185471 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.181586 185482 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 737511ns I0709 01:28:12.181669 185482 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.183054 185475 replica.cpp:541] Replica received write request for position 0 from __req_res__(953)@172.17.0.2:46245 I0709 01:28:12.183109 185465 replica.cpp:541] Replica received write request for position 0 from __req_res__(952)@172.17.0.2:46245 I0709 01:28:12.183137 185475 leveldb.cpp:510] Reading position from leveldb took 42818ns I0709 01:28:12.183151 185465 leveldb.cpp:510] Reading position from leveldb took 22910ns I0709 01:28:12.183692 185475 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 531234ns I0709 01:28:12.183692 185465 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 531304ns I0709 01:28:12.183758 185475 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.183786 185465 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.184643 185474 replica.cpp:695] Replica received learned notice for position 0 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.184762 185485 replica.cpp:695] Replica received learned notice for position 0 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.185516 185485 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 695598ns I0709 01:28:12.185519 185474 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 826576ns I0709 01:28:12.185607 185485 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.185688 185474 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.187288 185464 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 I0709 01:28:12.188540 185481 replica.cpp:541] Replica received write request for position 1 from __req_res__(955)@172.17.0.2:46245 I0709 01:28:12.188593 185486 replica.cpp:541] Replica received write request for position 1 from __req_res__(954)@172.17.0.2:46245 I0709 01:28:12.189502 185481 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 905268ns I0709 01:28:12.189536 185481 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.189606 185486 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 947030ns I0709 01:28:12.189694 185486 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.190919 185485 replica.cpp:695] Replica received learned notice for position 1 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.191007 185480 replica.cpp:695] Replica received learned notice for position 1 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.191916 185480 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 844749ns I0709 01:28:12.191977 185480 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.192023 185485 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.04837ms I0709 01:28:12.192143 185485 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.193502 185471 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 2 I0709 01:28:12.194797 185481 replica.cpp:541] Replica received write request for position 2 from __req_res__(957)@172.17.0.2:46245 I0709 01:28:12.194847 185466 replica.cpp:541] Replica received write request for position 2 from __req_res__(956)@172.17.0.2:46245 I0709 01:28:12.195593 185481 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 743749ns I0709 01:28:12.195636 185481 replica.cpp:712] Persisted action APPEND at position 2 I0709 01:28:12.195645 185466 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 735534ns I0709 01:28:12.195726 185466 replica.cpp:712] Persisted action APPEND at position 2 I0709 01:28:12.196743 185470 replica.cpp:695] Replica received learned notice for position 2 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.196743 185472 replica.cpp:695] Replica received learned notice for position 2 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.197649 185470 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 830757ns I0709 01:28:12.197710 185472 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 855345ns I0709 01:28:12.197731 185470 replica.cpp:712] Persisted action APPEND at position 2 I0709 01:28:12.197805 185472 replica.cpp:712] Persisted action APPEND at position 2 I0709 01:28:12.199447 185467 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3 I0709 01:28:12.200870 185480 replica.cpp:541] Replica received write request for position 3 from __req_res__(959)@172.17.0.2:46245 I0709 01:28:12.200911 185481 replica.cpp:541] Replica received write request for position 3 from __req_res__(958)@172.17.0.2:46245 I0709 01:28:12.201694 185481 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 700118ns I0709 01:28:12.201730 185481 replica.cpp:712] Persisted action APPEND at position 3 I0709 01:28:12.201758 185480 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 820368ns I0709 01:28:12.201869 185480 replica.cpp:712] Persisted action APPEND at position 3 I0709 01:28:12.203207 185482 replica.cpp:695] Replica received learned notice for position 3 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.203226 185484 replica.cpp:695] Replica received learned notice for position 3 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.204275 185484 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 955754ns I0709 01:28:12.204303 185482 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.039847ms I0709 01:28:12.204360 185484 replica.cpp:712] Persisted action APPEND at position 3 I0709 01:28:12.204397 185482 replica.cpp:712] Persisted action APPEND at position 3 I0709 01:28:12.205775 185479 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 4 I0709 01:28:12.207162 185485 replica.cpp:541] Replica received write request for position 4 from __req_res__(960)@172.17.0.2:46245 I0709 01:28:12.207285 185483 replica.cpp:541] Replica received write request for position 4 from __req_res__(961)@172.17.0.2:46245 I0709 01:28:12.208216 185483 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 864094ns I0709 01:28:12.208272 185485 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 1.044996ms I0709 01:28:12.208298 185483 replica.cpp:712] Persisted action APPEND at position 4 I0709 01:28:12.208374 185485 replica.cpp:712] Persisted action APPEND at position 4 I0709 01:28:12.209573 185484 replica.cpp:695] Replica received learned notice for position 4 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.209646 185468 replica.cpp:695] Replica received learned notice for position 4 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.210645 185468 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 943983ns I0709 01:28:12.210672 185484 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.047436ms I0709 01:28:12.210750 185468 replica.cpp:712] Persisted action APPEND at position 4 I0709 01:28:12.210786 185484 replica.cpp:712] Persisted action APPEND at position 4 I0709 01:28:12.212407 185479 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 5 I0709 01:28:12.213505 185473 replica.cpp:541] Replica received write request for position 5 from __req_res__(962)@172.17.0.2:46245 I0709 01:28:12.213578 185485 replica.cpp:541] Replica received write request for position 5 from __req_res__(963)@172.17.0.2:46245 I0709 01:28:12.214501 185473 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 944412ns I0709 01:28:12.214571 185473 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:12.215016 185485 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 1.369439ms I0709 01:28:12.215116 185485 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:12.216398 185469 replica.cpp:695] Replica received learned notice for position 5 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.216432 185477 replica.cpp:695] Replica received learned notice for position 5 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.217388 185477 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 905728ns I0709 01:28:12.217392 185469 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 942087ns I0709 01:28:12.217480 185477 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:12.217561 185469 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:12.219017 185479 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 6 I0709 01:28:12.220309 185475 replica.cpp:541] Replica received write request for position 6 from __req_res__(964)@172.17.0.2:46245 I0709 01:28:12.220384 185474 replica.cpp:541] Replica received write request for position 6 from __req_res__(965)@172.17.0.2:46245 I0709 01:28:12.221071 185475 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 695851ns I0709 01:28:12.221132 185475 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:12.221164 185474 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 709247ns I0709 01:28:12.221249 185474 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:12.222404 185487 replica.cpp:695] Replica received learned notice for position 6 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.222404 185464 replica.cpp:695] Replica received learned notice for position 6 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.223284 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 808277ns I0709 01:28:12.223284 185464 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 775359ns I0709 01:28:12.223388 185487 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:12.223417 185464 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:12.224684 185471 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 7 I0709 01:28:12.225980 185486 replica.cpp:541] Replica received write request for position 7 from __req_res__(967)@172.17.0.2:46245 I0709 01:28:12.225980 185467 replica.cpp:541] Replica received write request for position 7 from __req_res__(966)@172.17.0.2:46245 I0709 01:28:12.226853 185486 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 775132ns I0709 01:28:12.226853 185467 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 748484ns I0709 01:28:12.226959 185486 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:12.226990 185467 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:12.228211 185481 replica.cpp:695] Replica received learned notice for position 7 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.228350 185465 replica.cpp:695] Replica received learned notice for position 7 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.228950 185481 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 688983ns I0709 01:28:12.228988 185481 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:12.229193 185465 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 778840ns I0709 01:28:12.229244 185465 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:12.231156 185484 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 8 I0709 01:28:12.232497 185467 replica.cpp:541] Replica received write request for position 8 from __req_res__(968)@172.17.0.2:46245 I0709 01:28:12.232654 185466 replica.cpp:541] Replica received write request for position 8 from __req_res__(969)@172.17.0.2:46245 I0709 01:28:12.233614 185466 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 891594ns I0709 01:28:12.233671 185467 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 1.105149ms I0709 01:28:12.233700 185466 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:12.233788 185467 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:12.235008 185479 replica.cpp:695] Replica received learned notice for position 8 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.235100 185473 replica.cpp:695] Replica received learned notice for position 8 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.235855 185473 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 697571ns I0709 01:28:12.235893 185479 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 834944ns I0709 01:28:12.235910 185473 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:12.235980 185479 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:12.237604 185484 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 9 I0709 01:28:12.239013 185467 replica.cpp:541] Replica received write request for position 9 from __req_res__(970)@172.17.0.2:46245 I0709 01:28:12.239152 185464 replica.cpp:541] Replica received write request for position 9 from __req_res__(971)@172.17.0.2:46245 I0709 01:28:12.240198 185467 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 1.106204ms I0709 01:28:12.240198 185464 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 1.006123ms I0709 01:28:12.240315 185467 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:12.240351 185464 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:12.241742 185476 replica.cpp:695] Replica received learned notice for position 9 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.242439 185472 replica.cpp:695] Replica received learned notice for position 9 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.242799 185476 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 975854ns I0709 01:28:12.242869 185476 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:12.243510 185472 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.022012ms I0709 01:28:12.243600 185472 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:12.245186 185486 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 10 I0709 01:28:12.246774 185481 replica.cpp:541] Replica received write request for position 10 from __req_res__(972)@172.17.0.2:46245 I0709 01:28:12.246816 185487 replica.cpp:541] Replica received write request for position 10 from __req_res__(973)@172.17.0.2:46245 I0709 01:28:12.247793 185481 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 949471ns I0709 01:28:12.247855 185487 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 968987ns I0709 01:28:12.247891 185481 replica.cpp:712] Persisted action APPEND at position 10 I0709 01:28:12.247948 185487 replica.cpp:712] Persisted action APPEND at position 10 I0709 01:28:12.248934 185473 replica.cpp:695] Replica received learned notice for position 10 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.249056 185475 replica.cpp:695] Replica received learned notice for position 10 from log-network(47)@172.17.0.2:46245 I0709 01:28:12.249644 185473 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 646533ns I0709 01:28:12.249656 185475 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 536117ns I0709 01:28:12.249673 185473 replica.cpp:712] Persisted action APPEND at position 10 I0709 01:28:12.249707 185475 replica.cpp:712] Persisted action APPEND at position 10 I0709 01:28:12.254455 185463 leveldb.cpp:217] Opened db in 3.426089ms I0709 01:28:12.258749 185463 leveldb.cpp:224] Compacted db in 4.277524ms I0709 01:28:12.258833 185463 leveldb.cpp:239] Created db iterator in 33665ns I0709 01:28:12.258862 185463 leveldb.cpp:245] Seeked to beginning of db in 23431ns I0709 01:28:12.258896 185463 leveldb.cpp:320] Iterated through 1 keys in the db in 29938ns I0709 01:28:12.258927 185463 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0709 01:28:12.259613 185467 recover.cpp:437] Starting replica recovery I0709 01:28:12.260181 185479 recover.cpp:468] Replica is in VOTING status I0709 01:28:12.260533 185479 recover.cpp:447] Recover process terminated I0709 01:28:12.261096 185472 catchup.cpp:342] Starting missing positions recovery I0709 01:28:12.261665 185487 catchup.cpp:368] Replica is in VOTING status I0709 01:28:12.263943 185484 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(974)@172.17.0.2:46245 I0709 01:28:12.263990 185468 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(975)@172.17.0.2:46245 I0709 01:28:12.264102 185470 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(976)@172.17.0.2:46245 I0709 01:28:12.264984 185469 recover.cpp:197] Received a recover response from a replica in VOTING status I0709 01:28:12.265548 185469 recover.cpp:197] Received a recover response from a replica in VOTING status I0709 01:28:12.266934 185472 catchup.cpp:423] Starting catch-up from position 0 to 9 I0709 01:28:12.269374 185464 replica.cpp:391] Replica received explicit promise request from __req_res__(977)@172.17.0.2:46245 for position 0 with proposal 0 I0709 01:28:12.269443 185465 replica.cpp:391] Replica received explicit promise request from __req_res__(978)@172.17.0.2:46245 for position 0 with proposal 0 I0709 01:28:12.269484 185466 replica.cpp:391] Replica received explicit promise request from __req_res__(979)@172.17.0.2:46245 for position 0 with proposal 0 I0709 01:28:12.269556 185464 leveldb.cpp:510] Reading position from leveldb took 105719ns I0709 01:28:12.269606 185465 leveldb.cpp:510] Reading position from leveldb took 90222ns I0709 01:28:12.447103 185482 replica.cpp:391] Replica received explicit promise request from __req_res__(980)@172.17.0.2:46245 for position 0 with proposal 3 I0709 01:28:12.447188 185483 replica.cpp:391] Replica received explicit promise request from __req_res__(981)@172.17.0.2:46245 for position 0 with proposal 3 I0709 01:28:12.447269 185482 leveldb.cpp:510] Reading position from leveldb took 89925ns I0709 01:28:12.447244 185474 replica.cpp:391] Replica received explicit promise request from __req_res__(982)@172.17.0.2:46245 for position 0 with proposal 3 I0709 01:28:12.447364 185483 leveldb.cpp:510] Reading position from leveldb took 95881ns I0709 01:28:12.448269 185483 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 858036ns I0709 01:28:12.448289 185482 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 975443ns I0709 01:28:12.448362 185483 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.448410 185482 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.448503 185474 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 1.14435ms I0709 01:28:12.448606 185474 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.449131 185482 replica.cpp:695] Replica received learned notice for position 0 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.449149 185474 replica.cpp:695] Replica received learned notice for position 0 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.449246 185473 replica.cpp:695] Replica received learned notice for position 0 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.449934 185474 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 723611ns I0709 01:28:12.449950 185482 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 775966ns I0709 01:28:12.450001 185474 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.449939 185473 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 631052ns I0709 01:28:12.450030 185482 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.450093 185473 replica.cpp:712] Persisted action NOP at position 0 I0709 01:28:12.451993 185464 replica.cpp:391] Replica received explicit promise request from __req_res__(983)@172.17.0.2:46245 for position 1 with proposal 3 I0709 01:28:12.452143 185464 leveldb.cpp:510] Reading position from leveldb took 88585ns I0709 01:28:12.452229 185476 replica.cpp:391] Replica received explicit promise request from __req_res__(984)@172.17.0.2:46245 for position 1 with proposal 3 I0709 01:28:12.452278 185486 replica.cpp:391] Replica received explicit promise request from __req_res__(985)@172.17.0.2:46245 for position 1 with proposal 3 I0709 01:28:12.452399 185476 leveldb.cpp:510] Reading position from leveldb took 93031ns I0709 01:28:12.453356 185486 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 1.014384ms I0709 01:28:12.453366 185464 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.182327ms I0709 01:28:12.453454 185486 replica.cpp:712] Persisted action NOP at position 1 I0709 01:28:12.453498 185464 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.453735 185476 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.293004ms I0709 01:28:12.453860 185476 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.454598 185467 replica.cpp:695] Replica received learned notice for position 1 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.454656 185478 replica.cpp:695] Replica received learned notice for position 1 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.454682 185487 replica.cpp:695] Replica received learned notice for position 1 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.455633 185478 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 917275ns I0709 01:28:12.455683 185467 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.031532ms I0709 01:28:12.455636 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 869750ns I0709 01:28:12.455853 185487 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.455722 185478 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.455785 185467 replica.cpp:712] Persisted action APPEND at position 1 I0709 01:28:12.457870 185471 replica.cpp:391] Replica received explicit promise request from __req_res__(986)@172.17.0.2:46245 for position 2 with proposal 3 I0709 01:28:12.457899 185472 replica.cpp:391] Replica received explicit promise request from __req_res__(987)@172.17.0.2:46245 for position 2 with proposal 3 I0709 01:28:12.458010 185470 replica.cpp:391] Replica received explicit promise request from __req_res__(988)@172.17.0.2:46245 for position 2 with proposal 3 I0709 01:28:12.458041 185472 leveldb.cpp:510] Reading position from leveldb took 53650ns I0709 01:28:12.458051 185471 leveldb.cpp:510] Reading position from leveldb took 96015ns I0709 01:28:12.458778 185470 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 706505ns I0709 01:28:12.458827 185470 replica.cpp:712] Persisted action NOP at position 2 I0709 01:28:12.458858 185472 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 730989ns I0709 01:28:12.458874 185471 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 710655ns I0709 01:28:12.458907 185472 replica.cpp:712] Persisted action APPEND at position 2 I0709 01:28:12.458967 185471 replica.cpp:712] Persisted action APPEND at position 2 I0709 01:28:12.459677 185481 replica.cpp:695] Replica received learned notice for position 2 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.459683 185478 replica.cpp:695] Replica received learned notice for position 2 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.459687 185479 replica.cpp:695] Replica received learned notice for position 2 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.460374 185479 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 526912ns I0709 01:28:12.460382 185481 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 650350ns I0709 01:28:12.460425 185479 replica.cpp:712] Persisted action APPEND at position 2 I0709 01:28:12.460462 185478 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 662515ns I0709 01:28:12.460462 185481 replica.cpp:712] Persisted action APPEND at position 2 I0709 01:28:12.460556 185478 replica.cpp:712] Persisted action APPEND at position 2 I0709 01:28:12.462666 185470 replica.cpp:391] Replica received explicit promise request from __req_res__(989)@172.17.0.2:46245 for position 3 with proposal 3 I0709 01:28:12.462745 185486 replica.cpp:391] Replica received explicit promise request from __req_res__(990)@172.17.0.2:46245 for position 3 with proposal 3 I0709 01:28:12.462787 185469 replica.cpp:391] Replica received explicit promise request from __req_res__(991)@172.17.0.2:46245 for position 3 with proposal 3 I0709 01:28:12.462838 185470 leveldb.cpp:510] Reading position from leveldb took 96953ns I0709 01:28:12.462913 185486 leveldb.cpp:510] Reading position from leveldb took 94166ns I0709 01:28:12.463815 185470 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 899330ns I0709 01:28:12.463860 185469 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 999639ns I0709 01:28:12.463900 185470 replica.cpp:712] Persisted action APPEND at position 3 I0709 01:28:12.463864 185486 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 905643ns I0709 01:28:12.463945 185469 replica.cpp:712] Persisted action NOP at position 3 I0709 01:28:12.464041 185486 replica.cpp:712] Persisted action APPEND at position 3 I0709 01:28:12.464869 185481 replica.cpp:695] Replica received learned notice for position 3 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.464922 185477 replica.cpp:695] Replica received learned notice for position 3 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.464922 185485 replica.cpp:695] Replica received learned notice for position 3 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.465714 185485 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 677023ns I0709 01:28:12.465736 185481 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 817537ns I0709 01:28:12.465780 185485 replica.cpp:712] Persisted action APPEND at position 3 I0709 01:28:12.465714 185477 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 710277ns I0709 01:28:12.465838 185481 replica.cpp:712] Persisted action APPEND at position 3 I0709 01:28:12.465899 185477 replica.cpp:712] Persisted action APPEND at position 3 I0709 01:28:12.467839 185478 replica.cpp:391] Replica received explicit promise request from __req_res__(992)@172.17.0.2:46245 for position 4 with proposal 3 I0709 01:28:12.467866 185480 replica.cpp:391] Replica received explicit promise request from __req_res__(993)@172.17.0.2:46245 for position 4 with proposal 3 I0709 01:28:12.467989 185466 replica.cpp:391] Replica received explicit promise request from __req_res__(994)@172.17.0.2:46245 for position 4 with proposal 3 I0709 01:28:12.468027 185478 leveldb.cpp:510] Reading position from leveldb took 106715ns I0709 01:28:12.468027 185480 leveldb.cpp:510] Reading position from leveldb took 83379ns I0709 01:28:12.468760 185478 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 620370ns I0709 01:28:12.468760 185480 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 614877ns I0709 01:28:12.468819 185478 replica.cpp:712] Persisted action APPEND at position 4 I0709 01:28:12.468842 185480 replica.cpp:712] Persisted action APPEND at position 4 I0709 01:28:12.468863 185466 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 803533ns I0709 01:28:12.468945 185466 replica.cpp:712] Persisted action NOP at position 4 I0709 01:28:12.469694 185485 replica.cpp:695] Replica received learned notice for position 4 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.469731 185487 replica.cpp:695] Replica received learned notice for position 4 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.469846 185473 replica.cpp:695] Replica received learned notice for position 4 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.470515 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 731291ns I0709 01:28:12.470583 185487 replica.cpp:712] Persisted action APPEND at position 4 I0709 01:28:12.470605 185485 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 860906ns I0709 01:28:12.470607 185473 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 710657ns I0709 01:28:12.470696 185485 replica.cpp:712] Persisted action APPEND at position 4 I0709 01:28:12.470755 185473 replica.cpp:712] Persisted action APPEND at position 4 I0709 01:28:12.472888 185477 replica.cpp:391] Replica received explicit promise request from __req_res__(995)@172.17.0.2:46245 for position 5 with proposal 3 I0709 01:28:12.472919 185481 replica.cpp:391] Replica received explicit promise request from __req_res__(997)@172.17.0.2:46245 for position 5 with proposal 3 I0709 01:28:12.472978 185484 replica.cpp:391] Replica received explicit promise request from __req_res__(996)@172.17.0.2:46245 for position 5 with proposal 3 I0709 01:28:12.473070 185477 leveldb.cpp:510] Reading position from leveldb took 97856ns I0709 01:28:12.473152 185484 leveldb.cpp:510] Reading position from leveldb took 97001ns I0709 01:28:12.473685 185481 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 678276ns I0709 01:28:12.473685 185477 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 589495ns I0709 01:28:12.473850 185477 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:12.473760 185481 replica.cpp:712] Persisted action NOP at position 5 I0709 01:28:12.473937 185484 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 724964ns I0709 01:28:12.474010 185484 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:12.474704 185476 replica.cpp:695] Replica received learned notice for position 5 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.474747 185470 replica.cpp:695] Replica received learned notice for position 5 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.474762 185487 replica.cpp:695] Replica received learned notice for position 5 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.476660 185476 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.914706ms I0709 01:28:12.476722 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.839131ms I0709 01:28:12.476727 185470 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.926488ms I0709 01:28:12.476747 185476 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:12.476876 185470 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:12.476821 185487 replica.cpp:712] Persisted action APPEND at position 5 I0709 01:28:12.479065 185482 replica.cpp:391] Replica received explicit promise request from __req_res__(998)@172.17.0.2:46245 for position 6 with proposal 3 I0709 01:28:12.479174 185467 replica.cpp:391] Replica received explicit promise request from __req_res__(999)@172.17.0.2:46245 for position 6 with proposal 3 I0709 01:28:12.479233 185482 leveldb.cpp:510] Reading position from leveldb took 92969ns I0709 01:28:12.479266 185469 replica.cpp:391] Replica received explicit promise request from __req_res__(1000)@172.17.0.2:46245 for position 6 with proposal 3 I0709 01:28:12.479346 185467 leveldb.cpp:510] Reading position from leveldb took 94697ns I0709 01:28:12.480301 185467 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 912155ns I0709 01:28:12.480329 185482 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.054665ms I0709 01:28:12.480394 185467 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:12.480326 185469 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 993295ns I0709 01:28:12.480427 185482 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:12.480504 185469 replica.cpp:712] Persisted action NOP at position 6 I0709 01:28:12.481477 185482 replica.cpp:695] Replica received learned notice for position 6 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.481527 185487 replica.cpp:695] Replica received learned notice for position 6 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.481559 185479 replica.cpp:695] Replica received learned notice for position 6 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.482441 185479 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 832497ns I0709 01:28:12.482497 185482 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 969570ns I0709 01:28:12.482498 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 925835ns I0709 01:28:12.482661 185487 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:12.482527 185479 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:12.482585 185482 replica.cpp:712] Persisted action APPEND at position 6 I0709 01:28:12.485283 185470 replica.cpp:391] Replica received explicit promise request from __req_res__(1001)@172.17.0.2:46245 for position 7 with proposal 3 I0709 01:28:12.485390 185475 replica.cpp:391] Replica received explicit promise request from __req_res__(1002)@172.17.0.2:46245 for position 7 with proposal 3 I0709 01:28:12.485394 185480 replica.cpp:391] Replica received explicit promise request from __req_res__(1003)@172.17.0.2:46245 for position 7 with proposal 3 I0709 01:28:12.485447 185470 leveldb.cpp:510] Reading position from leveldb took 90930ns I0709 01:28:12.485584 185475 leveldb.cpp:510] Reading position from leveldb took 114462ns I0709 01:28:12.486375 185480 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 868981ns I0709 01:28:12.486459 185480 replica.cpp:712] Persisted action NOP at position 7 I0709 01:28:12.486515 185475 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 864316ns I0709 01:28:12.486604 185475 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:12.486598 185470 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 995343ns I0709 01:28:12.486730 185470 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:12.487749 185473 replica.cpp:695] Replica received learned notice for position 7 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.487901 185468 replica.cpp:695] Replica received learned notice for position 7 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.487906 185484 replica.cpp:695] Replica received learned notice for position 7 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.488368 185473 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 593801ns I0709 01:28:12.488399 185473 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:12.488632 185468 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 671353ns I0709 01:28:12.488688 185468 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:12.488740 185484 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 738843ns I0709 01:28:12.488847 185484 replica.cpp:712] Persisted action APPEND at position 7 I0709 01:28:12.491099 185485 replica.cpp:391] Replica received explicit promise request from __req_res__(1004)@172.17.0.2:46245 for position 8 with proposal 3 I0709 01:28:12.491139 185472 replica.cpp:391] Replica received explicit promise request from __req_res__(1006)@172.17.0.2:46245 for position 8 with proposal 3 I0709 01:28:12.491184 185483 replica.cpp:391] Replica received explicit promise request from __req_res__(1005)@172.17.0.2:46245 for position 8 with proposal 3 I0709 01:28:12.491276 185485 leveldb.cpp:510] Reading position from leveldb took 95726ns I0709 01:28:12.491376 185483 leveldb.cpp:510] Reading position from leveldb took 112735ns I0709 01:28:12.492035 185485 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 715111ns I0709 01:28:12.492053 185472 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 852653ns I0709 01:28:12.492127 185485 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:12.492175 185472 replica.cpp:712] Persisted action NOP at position 8 I0709 01:28:12.492242 185483 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 799949ns I0709 01:28:12.492311 185483 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:12.493057 185483 replica.cpp:695] Replica received learned notice for position 8 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.493232 185486 replica.cpp:695] Replica received learned notice for position 8 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.493271 185464 replica.cpp:695] Replica received learned notice for position 8 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.493659 185483 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 569215ns I0709 01:28:12.493717 185483 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:12.494036 185486 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 753595ns I0709 01:28:12.494050 185464 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 721463ns I0709 01:28:12.494140 185486 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:12.494220 185464 replica.cpp:712] Persisted action APPEND at position 8 I0709 01:28:12.496318 185468 replica.cpp:391] Replica received explicit promise request from __req_res__(1007)@172.17.0.2:46245 for position 9 with proposal 3 I0709 01:28:12.496410 185468 leveldb.cpp:510] Reading position from leveldb took 53672ns I0709 01:28:12.496429 185484 replica.cpp:391] Replica received explicit promise request from __req_res__(1008)@172.17.0.2:46245 for position 9 with proposal 3 I0709 01:28:12.496592 185473 replica.cpp:391] Replica received explicit promise request from __req_res__(1009)@172.17.0.2:46245 for position 9 with proposal 3 I0709 01:28:12.496621 185484 leveldb.cpp:510] Reading position from leveldb took 106001ns I0709 01:28:12.497123 185468 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 676622ns I0709 01:28:12.497143 185468 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:12.497494 185473 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 823453ns I0709 01:28:12.497495 185484 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 757972ns I0709 01:28:12.497552 185473 replica.cpp:712] Persisted action NOP at position 9 I0709 01:28:12.497588 185484 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:12.497994 185465 replica.cpp:695] Replica received learned notice for position 9 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.498044 185476 replica.cpp:695] Replica received learned notice for position 9 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.498100 185480 replica.cpp:695] Replica received learned notice for position 9 from log-network(48)@172.17.0.2:46245 I0709 01:28:12.498813 185465 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 794003ns I0709 01:28:12.498842 185465 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:12.499224 185480 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.060726ms I0709 01:28:12.499230 185476 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 1.133481ms I0709 01:28:12.499290 185480 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:12.499322 185476 replica.cpp:712] Persisted action APPEND at position 9 I0709 01:28:12.500305 185471 catchup.cpp:357] Recover process terminated I0709 01:28:12.503562 185466 leveldb.cpp:510] Reading position from leveldb took 124925ns I0709 01:28:12.503717 185466 leveldb.cpp:510] Reading position from leveldb took 45630ns I0709 01:28:12.503780 185466 leveldb.cpp:510] Reading position from leveldb took 26988ns I0709 01:28:12.503839 185466 leveldb.cpp:510] Reading position from leveldb took 26242ns I0709 01:28:12.503893 185466 leveldb.cpp:510] Reading position from leveldb took 26273ns I0709 01:28:12.503948 185466 leveldb.cpp:510] Reading position from leveldb took 25936ns I0709 01:28:12.504002 185466 leveldb.cpp:510] Reading position from leveldb took 25596ns I0709 01:28:12.504057 185466 leveldb.cpp:510] Reading position from leveldb took 26828ns I0709 01:28:12.504112 185466 leveldb.cpp:510] Reading position from leveldb took 25634ns I0709 01:28:12.504166 185466 leveldb.cpp:510] Reading position from leveldb took 24896ns [ OK ] LogTest.ReaderCatchup (382 ms) [----------] 4 tests from LogTest (575 ms total) [----------] 2 tests from LogZooKeeperTest I0709 01:28:12.510735 185463 zookeeper.cpp:82] Using Java classpath: -Djava.class.path=/tmp/SRC/build/mesos-1.12.0/_build/sub/3rdparty/zookeeper-3.4.8/zookeeper-3.4.8.jar:/tmp/SRC/build/mesos-1.12.0/_build/sub/3rdparty/zookeeper-3.4.8/lib/slf4j-api-1.6.1.jar:/tmp/SRC/build/mesos-1.12.0/_build/sub/3rdparty/zookeeper-3.4.8/lib/log4j-1.2.16.jar:/tmp/SRC/build/mesos-1.12.0/_build/sub/3rdparty/zookeeper-3.4.8/lib/jline-0.9.94.jar:/tmp/SRC/build/mesos-1.12.0/_build/sub/3rdparty/zookeeper-3.4.8/lib/slf4j-log4j12-1.6.1.jar:/tmp/SRC/build/mesos-1.12.0/_build/sub/3rdparty/zookeeper-3.4.8/lib/netty-3.7.0.Final.jar [ RUN ] LogZooKeeperTest.WriteRead I0709 01:28:12.596753 185463 jvm.cpp:590] Looking up method <init>(Ljava/lang/String;)V I0709 01:28:12.597088 185463 jvm.cpp:590] Looking up method deleteOnExit()V I0709 01:28:12.598095 185463 jvm.cpp:590] Looking up method <init>(Ljava/io/File;Ljava/io/File;)V log4j:WARN No appenders could be found for logger (org.apache.zookeeper.server.persistence.FileTxnSnapLog). log4j:WARN Please initialize the log4j system properly. log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info. I0709 01:28:12.678138 185463 jvm.cpp:590] Looking up method <init>()V I0709 01:28:12.678855 185463 jvm.cpp:590] Looking up method <init>(Lorg/apache/zookeeper/server/persistence/FileTxnSnapLog;Lorg/apache/zookeeper/server/ZooKeeperServer$DataTreeBuilder;)V *** Aborted at 1720488492 (unix time) try "date -d @1720488492" if you are using GNU date *** PC: @ 0x7ff750bffccd OopStorage::Block::release_entries() *** SIGSEGV (@0x238) received by PID 185463 (TID 0x7ff75f41cb40) from PID 568; stack trace: *** @ 0x7ff750c0e929 os::Linux::chained_handler() @ 0x7ff750c1463b JVM_handle_linux_signal @ 0x7ff750c071dc signalHandler() @ 0x7ff760a6f420 (unknown) @ 0x7ff750bffccd OopStorage::Block::release_entries() @ 0x7ff750bfff26 OopStorage::release() @ 0x7ff750902b21 jni_DeleteGlobalRef @ 0x7ff77022d454 JNIEnv_::DeleteGlobalRef() @ 0x7ff77022b59c Jvm::deleteGlobalRef() @ 0x555b83541628 Jvm::Object::~Object() @ 0x555b8354644e org::apache::zookeeper::server::ZooKeeperServer::DataTreeBuilder::~DataTreeBuilder() @ 0x555b83548d52 org::apache::zookeeper::server::ZooKeeperServer::BasicDataTreeBuilder::~BasicDataTreeBuilder() @ 0x555b83544d6d mesos::internal::tests::ZooKeeperTestServer::ZooKeeperTestServer() @ 0x555b81ee9fcc mesos::internal::tests::ZooKeeperTest::ZooKeeperTest() @ 0x555b81eec315 mesos::internal::tests::LogZooKeeperTest::LogZooKeeperTest() @ 0x555b81eec426 mesos::internal::tests::LogZooKeeperTest_WriteRead_Test::LogZooKeeperTest_WriteRead_Test() @ 0x555b81f57328 testing::internal::TestFactoryImpl<>::CreateTest() @ 0x555b8358b5fa testing::internal::HandleSehExceptionsInMethodIfSupported<>() @ 0x555b83584bcb testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x555b83560e03 testing::TestInfo::Run() @ 0x555b8356150b testing::TestCase::Run() @ 0x555b835688a5 testing::internal::UnitTestImpl::RunAllTests() @ 0x555b8358c828 testing::internal::HandleSehExceptionsInMethodIfSupported<>() @ 0x555b83585731 testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x555b835673bd testing::UnitTest::Run() @ 0x555b81f74edb RUN_ALL_TESTS() @ 0x555b81f748a2 main @ 0x7ff76088d083 __libc_start_main @ 0x555b80fba75e _start make[4]: *** [Makefile:18022: check-local] Segmentation fault (core dumped) make[4]: Leaving directory '/tmp/SRC/build/mesos-1.12.0/_build/sub/src' I0709 01:28:13.892379 186498 exec.cpp:560] Agent exited ... shutting down make[3]: *** [Makefile:15951: check-am] Error 2 make[3]: Leaving directory '/tmp/SRC/build/mesos-1.12.0/_build/sub/src' I0709 01:28:13.893097 186488 executor.cpp:190] Received SHUTDOWN event I0709 01:28:13.893155 186488 executor.cpp:843] Shutting down I0709 01:28:13.893198 186488 executor.cpp:956] Sending SIGTERM to process tree at pid 186512 make[2]: *** [Makefile:15954: check] Error 2 make[2]: Leaving directory '/tmp/SRC/build/mesos-1.12.0/_build/sub/src' make[1]: *** [Makefile:785: check-recursive] Error 1 I0709 01:28:13.900614 186488 executor.cpp:969] Sent SIGTERM to the following process trees: [ -+- 186512 sh -c dd if=/dev/zero of=volume_path/file bs=1048576 count=2 && sleep 1000 \--- 186518 sleep 1000 ] I0709 01:28:13.900645 186488 executor.cpp:973] Scheduling escalation to SIGKILL in 3secs from now make[1]: Leaving directory '/tmp/SRC/build/mesos-1.12.0/_build/sub' make: *** [Makefile:999: distcheck] Error 1 + copy_out_test_reports + find /tmp/SRC -name '*-tests.xml' -exec cp '{}' /SRC ';' I0709 01:28:13.996764 186503 executor.cpp:1041] Command terminated with signal Terminated (pid: 186512) W0709 01:28:13.999545 186509 process.cpp:1917] Failed to send 'mesos.internal.StatusUpdateMessage' to '172.17.0.2:46245', connect: Failed to connect to 172.17.0.2:46245: Connection refused Untagged: mesos/mesos-build:ubuntu-20.04 Untagged: mesos/mesos-build@sha256:2d3cd7fed451697aba1a3103754b4a46b6a7cad64e8229fb65e5a31e6d4b413d Deleted: sha256:b978a6177f864ec24c8ab237b612c3e5e780d94875752c63681edd80d9a85bbd Deleted: sha256:3ce262d459956fd117307a4cccbe593d59a11fce0e9138bee98d634f3a536bd0 Deleted: sha256:93be824b42681ee74b5ef869b75fb8b4fc0f234ec2135b764d235bb863a722e1 Deleted: sha256:eca0ccc3c9322d20f126a1a390efe2f6862fef535a41044bdb68c492f0dd9392 Deleted: sha256:8ed5c7c631df3c9d418a68532b4957d8c8dbadc69ad70564f6fa45e4748f6957 Deleted: sha256:6988969997d24e5f91cf313970ab25e046d637808cc0d77b19de4fc385e6a0db Deleted: sha256:9a7bfb2ba9f4a5cc05f561ed15dcd86232976d79616d817df9d323b45b4407ca Deleted: sha256:92c98c8577076f502769040fce0770d08a5a5c5d41989fa70986df7b3962a293 Deleted: sha256:3ec3ded77c0ce89e931f92aed086b2a2c774a6fbd51617853decc8afa4e1087a Full log: https://ci-builds.apache.org/job/Mesos/job/Mesos-Reviewbot/33411/console - Mesos Reviewbot On May 28, 2024, 9:20 p.m., Jason Zhou wrote: > > ----------------------------------------------------------- > This is an automatically generated e-mail. To reply, visit: > https://reviews.apache.org/r/75016/ > ----------------------------------------------------------- > > (Updated May 28, 2024, 9:20 p.m.) > > > Review request for mesos and Benjamin Mahler. > > > Repository: mesos > > > Description > ------- > > Passes the device manager to the cgroups2 isolator on > containerizer startup, and sets up the ability for the > manager to be passed to the device controller and GPU isolator > > > Diffs > ----- > > src/slave/containerizer/containerizer.hpp > 691fdfe295850bce1302b4adde127d551f821b89 > src/slave/containerizer/containerizer.cpp > ba3ab43b0d56c6dabd141e40ac706568dccd72f1 > src/slave/containerizer/mesos/containerizer.hpp > 62174dfd056e1d7cc465ebdb29343bdd04de6a10 > src/slave/containerizer/mesos/containerizer.cpp > f7ff6b8e56e80881ac89ba650b7aa4f4eec3484b > src/slave/containerizer/mesos/isolators/cgroups2/cgroups2.hpp > d60215ec1c722efced2d5c59b9f99cb67d1abbbe > src/slave/containerizer/mesos/isolators/cgroups2/cgroups2.cpp > 2ca3880790be0cd092ec05a359711e2d8e641314 > src/slave/main.cpp 21b8ea74a502478fb73510a7d49bb5f28506ce8d > > > Diff: https://reviews.apache.org/r/75016/diff/4/ > > > Testing > ------- > > > Thanks, > > Jason Zhou > >
