----------------------------------------------------------- This is an automatically generated e-mail. To reply, visit: https://reviews.apache.org/r/75016/#review226632 -----------------------------------------------------------
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>... sisting action (18 bytes) to leveldb took 334020ns I0704 03:37:20.306172 185492 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 381629ns I0704 03:37:20.306195 185498 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.306207 185492 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.306565 185485 replica.cpp:695] Replica received learned notice for position 10 from log-network(41)@172.17.0.2:42425 I0704 03:37:20.306592 185503 replica.cpp:695] Replica received learned notice for position 10 from log-network(41)@172.17.0.2:42425 I0704 03:37:20.306960 185503 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 341626ns I0704 03:37:20.306960 185485 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 376986ns I0704 03:37:20.306986 185503 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.306998 185485 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.307512 185496 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 11 I0704 03:37:20.308079 185492 replica.cpp:541] Replica received write request for position 11 from __req_res__(879)@172.17.0.2:42425 I0704 03:37:20.308213 185497 replica.cpp:541] Replica received write request for position 11 from __req_res__(880)@172.17.0.2:42425 I0704 03:37:20.308493 185492 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 388611ns I0704 03:37:20.308516 185492 replica.cpp:712] Persisted action TRUNCATE at position 11 I0704 03:37:20.308694 185497 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 429285ns I0704 03:37:20.308729 185497 replica.cpp:712] Persisted action TRUNCATE at position 11 I0704 03:37:20.309126 185485 replica.cpp:695] Replica received learned notice for position 11 from log-network(41)@172.17.0.2:42425 I0704 03:37:20.309126 185494 replica.cpp:695] Replica received learned notice for position 11 from log-network(41)@172.17.0.2:42425 I0704 03:37:20.309715 185494 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 553033ns I0704 03:37:20.309716 185485 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 570516ns I0704 03:37:20.310061 185494 leveldb.cpp:460] Deleting ~5 keys from leveldb took 330378ns I0704 03:37:20.310062 185485 leveldb.cpp:460] Deleting ~5 keys from leveldb took 319130ns I0704 03:37:20.317008 185485 leveldb.cpp:527] Compacting range 0-4 took 6.923104ms I0704 03:37:20.317023 185494 leveldb.cpp:527] Compacting range 0-4 took 6.950625ms I0704 03:37:20.317051 185485 replica.cpp:712] Persisted action TRUNCATE at position 11 I0704 03:37:20.317066 185494 replica.cpp:712] Persisted action TRUNCATE at position 11 I0704 03:37:20.319794 185481 leveldb.cpp:217] Opened db in 2.238158ms I0704 03:37:20.322017 185481 leveldb.cpp:224] Compacted db in 2.209585ms I0704 03:37:20.322062 185481 leveldb.cpp:239] Created db iterator in 24872ns I0704 03:37:20.322089 185481 leveldb.cpp:245] Seeked to beginning of db in 17990ns I0704 03:37:20.322125 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 30229ns I0704 03:37:20.322157 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.322520 185500 catchup.cpp:342] Starting missing positions recovery I0704 03:37:20.322882 185492 catchup.cpp:368] Replica is in VOTING status I0704 03:37:20.323978 185491 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(881)@172.17.0.2:42425 I0704 03:37:20.324030 185485 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(882)@172.17.0.2:42425 I0704 03:37:20.324496 185482 recover.cpp:197] Received a recover response from a replica in VOTING status I0704 03:37:20.324720 185482 recover.cpp:197] Received a recover response from a replica in VOTING status I0704 03:37:20.325593 185500 catchup.cpp:423] Starting catch-up from position 0 to 10 I0704 03:37:20.326851 185501 replica.cpp:391] Replica received explicit promise request from __req_res__(885)@172.17.0.2:42425 for position 0 with proposal 0 I0704 03:37:20.326854 185491 replica.cpp:391] Replica received explicit promise request from __req_res__(884)@172.17.0.2:42425 for position 0 with proposal 0 I0704 03:37:20.326869 185485 replica.cpp:391] Replica received explicit promise request from __req_res__(886)@172.17.0.2:42425 for position 0 with proposal 0 I0704 03:37:20.327440 185492 replica.cpp:695] Replica received learned notice for position 0 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.327499 185500 replica.cpp:695] Replica received learned notice for position 0 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.327518 185505 replica.cpp:695] Replica received learned notice for position 0 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.328073 185492 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 614053ns I0704 03:37:20.328100 185492 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.328258 185505 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 710733ns I0704 03:37:20.328267 185500 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 737976ns I0704 03:37:20.328286 185505 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.328312 185500 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.329479 185502 replica.cpp:391] Replica received explicit promise request from __req_res__(887)@172.17.0.2:42425 for position 1 with proposal 0 I0704 03:37:20.329602 185488 replica.cpp:391] Replica received explicit promise request from __req_res__(888)@172.17.0.2:42425 for position 1 with proposal 0 I0704 03:37:20.329677 185492 replica.cpp:391] Replica received explicit promise request from __req_res__(889)@172.17.0.2:42425 for position 1 with proposal 0 I0704 03:37:20.330099 185496 replica.cpp:695] Replica received learned notice for position 1 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.330127 185494 replica.cpp:695] Replica received learned notice for position 1 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.330188 185483 replica.cpp:695] Replica received learned notice for position 1 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.330479 185496 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 363426ns I0704 03:37:20.330480 185494 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 337481ns I0704 03:37:20.330689 185483 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 479777ns I0704 03:37:20.330865 185496 leveldb.cpp:460] Deleting ~1 keys from leveldb took 371015ns I0704 03:37:20.330866 185494 leveldb.cpp:460] Deleting ~1 keys from leveldb took 362333ns I0704 03:37:20.331076 185483 leveldb.cpp:460] Deleting ~1 keys from leveldb took 366391ns I0704 03:37:20.337401 185483 leveldb.cpp:527] Compacting range 0-0 took 6.318065ms I0704 03:37:20.337417 185496 leveldb.cpp:527] Compacting range 0-0 took 6.542733ms I0704 03:37:20.337430 185494 leveldb.cpp:527] Compacting range 0-0 took 6.542828ms I0704 03:37:20.337466 185496 replica.cpp:712] Persisted action NOP at position 1 I0704 03:37:20.337451 185483 replica.cpp:712] Persisted action NOP at position 1 I0704 03:37:20.337482 185494 replica.cpp:712] Persisted action NOP at position 1 I0704 03:37:20.338644 185497 replica.cpp:391] Replica received explicit promise request from __req_res__(891)@172.17.0.2:42425 for position 2 with proposal 0 I0704 03:37:20.338752 185487 replica.cpp:391] Replica received explicit promise request from __req_res__(890)@172.17.0.2:42425 for position 2 with proposal 0 I0704 03:37:20.338829 185491 replica.cpp:391] Replica received explicit promise request from __req_res__(892)@172.17.0.2:42425 for position 2 with proposal 0 I0704 03:37:20.339202 185490 replica.cpp:695] Replica received learned notice for position 2 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.339243 185489 replica.cpp:695] Replica received learned notice for position 2 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.339308 185491 replica.cpp:695] Replica received learned notice for position 2 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.339752 185489 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 488268ns I0704 03:37:20.339756 185490 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 532040ns I0704 03:37:20.340201 185491 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 855977ns I0704 03:37:20.340345 185489 leveldb.cpp:460] Deleting ~1 keys from leveldb took 574338ns I0704 03:37:20.340345 185490 leveldb.cpp:460] Deleting ~1 keys from leveldb took 557609ns I0704 03:37:20.340618 185491 leveldb.cpp:460] Deleting ~1 keys from leveldb took 387608ns I0704 03:37:20.347749 185491 leveldb.cpp:527] Compacting range 1-1 took 7.090328ms I0704 03:37:20.347741 185490 leveldb.cpp:527] Compacting range 1-1 took 7.373602ms I0704 03:37:20.347779 185491 replica.cpp:712] Persisted action NOP at position 2 I0704 03:37:20.347769 185489 leveldb.cpp:527] Compacting range 1-1 took 7.411434ms I0704 03:37:20.347800 185490 replica.cpp:712] Persisted action NOP at position 2 I0704 03:37:20.347821 185489 replica.cpp:712] Persisted action NOP at position 2 I0704 03:37:20.348981 185498 replica.cpp:391] Replica received explicit promise request from __req_res__(893)@172.17.0.2:42425 for position 3 with proposal 0 I0704 03:37:20.349033 185482 replica.cpp:391] Replica received explicit promise request from __req_res__(894)@172.17.0.2:42425 for position 3 with proposal 0 I0704 03:37:20.349092 185499 replica.cpp:391] Replica received explicit promise request from __req_res__(895)@172.17.0.2:42425 for position 3 with proposal 0 I0704 03:37:20.349511 185500 replica.cpp:695] Replica received learned notice for position 3 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.349536 185501 replica.cpp:695] Replica received learned notice for position 3 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.349525 185490 replica.cpp:695] Replica received learned notice for position 3 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.350163 185490 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 597660ns I0704 03:37:20.350171 185501 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 626900ns I0704 03:37:20.350167 185500 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 629801ns I0704 03:37:20.350598 185500 leveldb.cpp:460] Deleting ~1 keys from leveldb took 388455ns I0704 03:37:20.350600 185490 leveldb.cpp:460] Deleting ~1 keys from leveldb took 419230ns I0704 03:37:20.350600 185501 leveldb.cpp:460] Deleting ~1 keys from leveldb took 405500ns I0704 03:37:20.355816 185490 leveldb.cpp:527] Compacting range 2-2 took 5.182625ms I0704 03:37:20.355809 185500 leveldb.cpp:527] Compacting range 2-2 took 5.202641ms I0704 03:37:20.355847 185490 replica.cpp:712] Persisted action NOP at position 3 I0704 03:37:20.355868 185500 replica.cpp:712] Persisted action NOP at position 3 I0704 03:37:20.357358 185501 leveldb.cpp:527] Compacting range 2-2 took 6.714834ms I0704 03:37:20.357400 185501 replica.cpp:712] Persisted action NOP at position 3 I0704 03:37:20.358515 185503 replica.cpp:391] Replica received explicit promise request from __req_res__(896)@172.17.0.2:42425 for position 4 with proposal 0 I0704 03:37:20.358599 185482 replica.cpp:391] Replica received explicit promise request from __req_res__(897)@172.17.0.2:42425 for position 4 with proposal 0 I0704 03:37:20.358629 185495 replica.cpp:391] Replica received explicit promise request from __req_res__(898)@172.17.0.2:42425 for position 4 with proposal 0 I0704 03:37:20.358951 185486 replica.cpp:695] Replica received learned notice for position 4 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.358984 185504 replica.cpp:695] Replica received learned notice for position 4 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.359010 185494 replica.cpp:695] Replica received learned notice for position 4 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.359474 185486 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 511077ns I0704 03:37:20.359647 185494 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 617106ns I0704 03:37:20.359654 185504 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 655968ns I0704 03:37:20.359833 185486 leveldb.cpp:460] Deleting ~1 keys from leveldb took 343862ns I0704 03:37:20.360008 185494 leveldb.cpp:460] Deleting ~1 keys from leveldb took 343254ns I0704 03:37:20.360008 185504 leveldb.cpp:460] Deleting ~1 keys from leveldb took 331653ns I0704 03:37:20.366281 185486 leveldb.cpp:527] Compacting range 3-3 took 6.438662ms I0704 03:37:20.366310 185486 replica.cpp:712] Persisted action NOP at position 4 I0704 03:37:20.367656 185504 leveldb.cpp:527] Compacting range 3-3 took 7.630906ms I0704 03:37:20.367667 185494 leveldb.cpp:527] Compacting range 3-3 took 7.652859ms I0704 03:37:20.367702 185504 replica.cpp:712] Persisted action NOP at position 4 I0704 03:37:20.367717 185494 replica.cpp:712] Persisted action NOP at position 4 I0704 03:37:20.368856 185483 replica.cpp:391] Replica received explicit promise request from __req_res__(899)@172.17.0.2:42425 for position 5 with proposal 0 I0704 03:37:20.368886 185498 replica.cpp:391] Replica received explicit promise request from __req_res__(900)@172.17.0.2:42425 for position 5 with proposal 0 I0704 03:37:20.368958 185483 leveldb.cpp:510] Reading position from leveldb took 68639ns I0704 03:37:20.368971 185498 leveldb.cpp:510] Reading position from leveldb took 57252ns I0704 03:37:20.369004 185484 replica.cpp:391] Replica received explicit promise request from __req_res__(901)@172.17.0.2:42425 for position 5 with proposal 0 I0704 03:37:20.493605 185493 replica.cpp:391] Replica received explicit promise request from __req_res__(903)@172.17.0.2:42425 for position 5 with proposal 2 I0704 03:37:20.493605 185495 replica.cpp:391] Replica received explicit promise request from __req_res__(902)@172.17.0.2:42425 for position 5 with proposal 2 I0704 03:37:20.493626 185500 replica.cpp:391] Replica received explicit promise request from __req_res__(904)@172.17.0.2:42425 for position 5 with proposal 2 I0704 03:37:20.493784 185495 leveldb.cpp:510] Reading position from leveldb took 100319ns I0704 03:37:20.493785 185493 leveldb.cpp:510] Reading position from leveldb took 114967ns I0704 03:37:20.494446 185500 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 745205ns I0704 03:37:20.494478 185500 replica.cpp:712] Persisted action NOP at position 5 I0704 03:37:20.494747 185493 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 786791ns I0704 03:37:20.494781 185493 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.494792 185495 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 966018ns I0704 03:37:20.494868 185495 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.495630 185499 replica.cpp:695] Replica received learned notice for position 5 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.495654 185487 replica.cpp:695] Replica received learned notice for position 5 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.495676 185497 replica.cpp:695] Replica received learned notice for position 5 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.496011 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 334392ns I0704 03:37:20.496013 185499 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 362403ns I0704 03:37:20.496033 185487 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.496047 185499 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.496059 185497 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 379872ns I0704 03:37:20.496140 185497 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.497536 185498 replica.cpp:391] Replica received explicit promise request from __req_res__(905)@172.17.0.2:42425 for position 6 with proposal 2 I0704 03:37:20.497632 185498 leveldb.cpp:510] Reading position from leveldb took 68411ns I0704 03:37:20.497646 185484 replica.cpp:391] Replica received explicit promise request from __req_res__(907)@172.17.0.2:42425 for position 6 with proposal 2 I0704 03:37:20.497673 185504 replica.cpp:391] Replica received explicit promise request from __req_res__(906)@172.17.0.2:42425 for position 6 with proposal 2 I0704 03:37:20.497905 185504 leveldb.cpp:510] Reading position from leveldb took 164067ns I0704 03:37:20.498092 185498 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 438674ns I0704 03:37:20.498119 185498 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.498325 185484 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 611099ns I0704 03:37:20.498379 185484 replica.cpp:712] Persisted action NOP at position 6 I0704 03:37:20.498512 185504 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 532821ns I0704 03:37:20.498564 185504 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.498755 185489 replica.cpp:695] Replica received learned notice for position 6 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.498817 185504 replica.cpp:695] Replica received learned notice for position 6 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.498828 185482 replica.cpp:695] Replica received learned notice for position 6 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.499145 185489 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 367983ns I0704 03:37:20.499168 185489 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.499341 185482 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 474718ns I0704 03:37:20.499351 185504 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 504748ns I0704 03:37:20.499373 185482 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.499389 185504 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.500708 185488 replica.cpp:391] Replica received explicit promise request from __req_res__(908)@172.17.0.2:42425 for position 7 with proposal 2 I0704 03:37:20.500771 185496 replica.cpp:391] Replica received explicit promise request from __req_res__(909)@172.17.0.2:42425 for position 7 with proposal 2 I0704 03:37:20.500792 185488 leveldb.cpp:510] Reading position from leveldb took 55416ns I0704 03:37:20.500844 185496 leveldb.cpp:510] Reading position from leveldb took 52495ns I0704 03:37:20.500859 185483 replica.cpp:391] Replica received explicit promise request from __req_res__(910)@172.17.0.2:42425 for position 7 with proposal 2 I0704 03:37:20.501188 185496 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 320720ns I0704 03:37:20.501194 185488 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 382100ns I0704 03:37:20.501214 185496 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.501235 185488 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.501402 185483 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 518459ns I0704 03:37:20.501423 185483 replica.cpp:712] Persisted action NOP at position 7 I0704 03:37:20.501827 185502 replica.cpp:695] Replica received learned notice for position 7 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.501981 185492 replica.cpp:695] Replica received learned notice for position 7 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.502038 185494 replica.cpp:695] Replica received learned notice for position 7 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.502197 185502 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 349379ns I0704 03:37:20.502218 185502 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.502526 185494 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 454807ns I0704 03:37:20.502526 185492 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 497634ns I0704 03:37:20.502586 185494 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.502617 185492 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.504045 185486 replica.cpp:391] Replica received explicit promise request from __req_res__(911)@172.17.0.2:42425 for position 8 with proposal 2 I0704 03:37:20.504132 185486 leveldb.cpp:510] Reading position from leveldb took 59362ns I0704 03:37:20.504163 185505 replica.cpp:391] Replica received explicit promise request from __req_res__(912)@172.17.0.2:42425 for position 8 with proposal 2 I0704 03:37:20.504268 185491 replica.cpp:391] Replica received explicit promise request from __req_res__(913)@172.17.0.2:42425 for position 8 with proposal 2 I0704 03:37:20.504371 185505 leveldb.cpp:510] Reading position from leveldb took 147366ns I0704 03:37:20.504494 185486 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 339734ns I0704 03:37:20.504518 185486 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.504760 185491 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 440683ns I0704 03:37:20.504804 185491 replica.cpp:712] Persisted action NOP at position 8 I0704 03:37:20.504937 185505 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 495328ns I0704 03:37:20.504972 185505 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.504999 185484 replica.cpp:695] Replica received learned notice for position 8 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.505084 185503 replica.cpp:695] Replica received learned notice for position 8 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.505208 185505 replica.cpp:695] Replica received learned notice for position 8 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.505349 185484 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 332383ns I0704 03:37:20.505378 185484 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.505549 185505 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 314430ns I0704 03:37:20.505576 185505 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.505618 185503 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 505041ns I0704 03:37:20.505662 185503 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.506767 185491 replica.cpp:391] Replica received explicit promise request from __req_res__(914)@172.17.0.2:42425 for position 9 with proposal 2 I0704 03:37:20.506965 185491 leveldb.cpp:510] Reading position from leveldb took 137929ns I0704 03:37:20.507004 185490 replica.cpp:391] Replica received explicit promise request from __req_res__(915)@172.17.0.2:42425 for position 9 with proposal 2 I0704 03:37:20.507027 185488 replica.cpp:391] Replica received explicit promise request from __req_res__(916)@172.17.0.2:42425 for position 9 with proposal 2 I0704 03:37:20.507189 185490 leveldb.cpp:510] Reading position from leveldb took 139358ns I0704 03:37:20.507527 185491 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 492420ns I0704 03:37:20.507575 185491 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.507615 185488 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 545675ns I0704 03:37:20.507721 185490 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 473936ns I0704 03:37:20.507874 185488 replica.cpp:712] Persisted action NOP at position 9 I0704 03:37:20.507903 185490 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.508175 185489 replica.cpp:695] Replica received learned notice for position 9 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.508296 185486 replica.cpp:695] Replica received learned notice for position 9 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.508353 185504 replica.cpp:695] Replica received learned notice for position 9 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.508565 185489 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 367567ns I0704 03:37:20.508590 185489 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.508762 185504 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 362718ns I0704 03:37:20.508764 185486 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 435507ns I0704 03:37:20.508810 185504 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.508831 185486 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.510316 185488 replica.cpp:391] Replica received explicit promise request from __req_res__(918)@172.17.0.2:42425 for position 10 with proposal 2 I0704 03:37:20.510365 185495 replica.cpp:391] Replica received explicit promise request from __req_res__(917)@172.17.0.2:42425 for position 10 with proposal 2 I0704 03:37:20.510391 185488 leveldb.cpp:510] Reading position from leveldb took 50838ns I0704 03:37:20.510440 185495 leveldb.cpp:510] Reading position from leveldb took 50757ns I0704 03:37:20.510433 185496 replica.cpp:391] Replica received explicit promise request from __req_res__(919)@172.17.0.2:42425 for position 10 with proposal 2 I0704 03:37:20.510860 185488 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 449217ns I0704 03:37:20.510860 185495 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 394611ns I0704 03:37:20.510888 185488 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.510905 185495 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.511080 185496 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 598873ns I0704 03:37:20.511108 185496 replica.cpp:712] Persisted action NOP at position 10 I0704 03:37:20.511449 185492 replica.cpp:695] Replica received learned notice for position 10 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.511461 185482 replica.cpp:695] Replica received learned notice for position 10 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.511497 185501 replica.cpp:695] Replica received learned notice for position 10 from log-network(42)@172.17.0.2:42425 I0704 03:37:20.511858 185482 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 362401ns I0704 03:37:20.511860 185492 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 377805ns I0704 03:37:20.511862 185501 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 342239ns I0704 03:37:20.511880 185482 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.511891 185492 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.511909 185501 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.512228 185493 catchup.cpp:357] Recover process terminated I0704 03:37:20.512948 185504 leveldb.cpp:510] Reading position from leveldb took 39178ns I0704 03:37:20.513008 185504 leveldb.cpp:510] Reading position from leveldb took 19451ns I0704 03:37:20.513046 185504 leveldb.cpp:510] Reading position from leveldb took 18469ns I0704 03:37:20.513084 185504 leveldb.cpp:510] Reading position from leveldb took 18217ns I0704 03:37:20.513123 185504 leveldb.cpp:510] Reading position from leveldb took 17615ns I0704 03:37:20.513156 185504 leveldb.cpp:510] Reading position from leveldb took 15068ns [ OK ] RecoverTest.CatchupVotingWithGap (269 ms) [ RUN ] RecoverTest.CatchupVotingOnePosition I0704 03:37:20.523494 185481 leveldb.cpp:217] Opened db in 4.060372ms I0704 03:37:20.524639 185481 leveldb.cpp:224] Compacted db in 1.101375ms I0704 03:37:20.524706 185481 leveldb.cpp:239] Created db iterator in 38989ns I0704 03:37:20.524730 185481 leveldb.cpp:245] Seeked to beginning of db in 8472ns I0704 03:37:20.524747 185481 leveldb.cpp:320] Iterated through 0 keys in the db in 6752ns I0704 03:37:20.524801 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.525718 185499 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 519876ns I0704 03:37:20.525744 185499 replica.cpp:322] Persisted replica status to VOTING I0704 03:37:20.530216 185481 leveldb.cpp:217] Opened db in 3.190244ms I0704 03:37:20.531155 185481 leveldb.cpp:224] Compacted db in 906702ns I0704 03:37:20.531210 185481 leveldb.cpp:239] Created db iterator in 31893ns I0704 03:37:20.531230 185481 leveldb.cpp:245] Seeked to beginning of db in 7620ns I0704 03:37:20.531247 185481 leveldb.cpp:320] Iterated through 0 keys in the db in 6440ns I0704 03:37:20.531296 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.532330 185492 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 669742ns I0704 03:37:20.532384 185492 replica.cpp:322] Persisted replica status to VOTING I0704 03:37:20.536744 185481 leveldb.cpp:217] Opened db in 3.837218ms I0704 03:37:20.537734 185481 leveldb.cpp:224] Compacted db in 951764ns I0704 03:37:20.537791 185481 leveldb.cpp:239] Created db iterator in 31060ns I0704 03:37:20.537937 185481 leveldb.cpp:245] Seeked to beginning of db in 136203ns I0704 03:37:20.537958 185481 leveldb.cpp:320] Iterated through 0 keys in the db in 6430ns I0704 03:37:20.538008 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.538851 185495 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 463273ns I0704 03:37:20.538882 185495 replica.cpp:322] Persisted replica status to VOTING I0704 03:37:20.542824 185481 leveldb.cpp:217] Opened db in 3.436994ms I0704 03:37:20.545132 185481 leveldb.cpp:224] Compacted db in 2.278152ms I0704 03:37:20.545202 185481 leveldb.cpp:239] Created db iterator in 35945ns I0704 03:37:20.545246 185481 leveldb.cpp:245] Seeked to beginning of db in 32169ns I0704 03:37:20.545306 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 49554ns I0704 03:37:20.545353 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.548718 185481 leveldb.cpp:217] Opened db in 3.116894ms I0704 03:37:20.550984 185481 leveldb.cpp:224] Compacted db in 2.238997ms I0704 03:37:20.551044 185481 leveldb.cpp:239] Created db iterator in 30547ns I0704 03:37:20.551083 185481 leveldb.cpp:245] Seeked to beginning of db in 26809ns I0704 03:37:20.551127 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 34088ns I0704 03:37:20.551164 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.554332 185481 leveldb.cpp:217] Opened db in 2.951414ms I0704 03:37:20.556480 185481 leveldb.cpp:224] Compacted db in 2.125942ms I0704 03:37:20.556530 185481 leveldb.cpp:239] Created db iterator in 26097ns I0704 03:37:20.556562 185481 leveldb.cpp:245] Seeked to beginning of db in 22466ns I0704 03:37:20.556602 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 30204ns I0704 03:37:20.556640 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.557051 185497 catchup.cpp:342] Starting missing positions recovery I0704 03:37:20.557546 185497 catchup.cpp:368] Replica is in VOTING status I0704 03:37:20.558827 185485 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(920)@172.17.0.2:42425 I0704 03:37:20.558943 185496 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(921)@172.17.0.2:42425 I0704 03:37:20.559031 185500 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(922)@172.17.0.2:42425 I0704 03:37:20.559661 185499 recover.cpp:197] Received a recover response from a replica in VOTING status I0704 03:37:20.559907 185499 recover.cpp:197] Received a recover response from a replica in VOTING status I0704 03:37:20.560469 185501 catchup.cpp:357] Recover process terminated [ OK ] RecoverTest.CatchupVotingOnePosition (44 ms) [----------] 9 tests from RecoverTest (1897 ms total) [----------] 4 tests from LogTest [ RUN ] LogTest.WriteRead I0704 03:37:20.566107 185481 leveldb.cpp:217] Opened db in 2.655288ms I0704 03:37:20.566983 185481 leveldb.cpp:224] Compacted db in 851345ns I0704 03:37:20.567018 185481 leveldb.cpp:239] Created db iterator in 20045ns I0704 03:37:20.567032 185481 leveldb.cpp:245] Seeked to beginning of db in 5086ns I0704 03:37:20.567044 185481 leveldb.cpp:320] Iterated through 0 keys in the db in 4094ns I0704 03:37:20.567075 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.567781 185499 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 454663ns I0704 03:37:20.567807 185499 replica.cpp:322] Persisted replica status to VOTING I0704 03:37:20.571688 185481 leveldb.cpp:217] Opened db in 3.221416ms I0704 03:37:20.572576 185481 leveldb.cpp:224] Compacted db in 858530ns I0704 03:37:20.572644 185481 leveldb.cpp:239] Created db iterator in 38363ns I0704 03:37:20.572675 185481 leveldb.cpp:245] Seeked to beginning of db in 11300ns I0704 03:37:20.572700 185481 leveldb.cpp:320] Iterated through 0 keys in the db in 10342ns I0704 03:37:20.572768 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.573545 185483 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 411162ns I0704 03:37:20.573571 185483 replica.cpp:322] Persisted replica status to VOTING I0704 03:37:20.577569 185481 leveldb.cpp:217] Opened db in 3.460547ms I0704 03:37:20.579941 185481 leveldb.cpp:224] Compacted db in 2.345765ms I0704 03:37:20.580036 185481 leveldb.cpp:239] Created db iterator in 50965ns I0704 03:37:20.580106 185481 leveldb.cpp:245] Seeked to beginning of db in 49419ns I0704 03:37:20.580185 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 63981ns I0704 03:37:20.580250 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.583441 185481 leveldb.cpp:217] Opened db in 2.928439ms I0704 03:37:20.585507 185481 leveldb.cpp:224] Compacted db in 2.03777ms I0704 03:37:20.585573 185481 leveldb.cpp:239] Created db iterator in 37370ns I0704 03:37:20.585624 185481 leveldb.cpp:245] Seeked to beginning of db in 34259ns I0704 03:37:20.585680 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 44272ns I0704 03:37:20.585731 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.586437 185484 recover.cpp:437] Starting replica recovery I0704 03:37:20.586745 185484 recover.cpp:468] Replica is in VOTING status I0704 03:37:20.586887 185484 recover.cpp:447] Recover process terminated I0704 03:37:20.587206 185484 log.cpp:554] Attempting to start the writer I0704 03:37:20.588227 185486 replica.cpp:497] Replica received implicit promise request from __req_res__(923)@172.17.0.2:42425 with proposal 1 I0704 03:37:20.588284 185494 replica.cpp:497] Replica received implicit promise request from __req_res__(924)@172.17.0.2:42425 with proposal 1 I0704 03:37:20.588744 185494 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 447423ns I0704 03:37:20.588744 185486 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 495265ns I0704 03:37:20.588763 185494 replica.cpp:344] Persisted promised to 1 I0704 03:37:20.588773 185486 replica.cpp:344] Persisted promised to 1 I0704 03:37:20.589514 185497 coordinator.cpp:238] Coordinator attempting to fill missing positions I0704 03:37:20.590479 185488 replica.cpp:391] Replica received explicit promise request from __req_res__(925)@172.17.0.2:42425 for position 0 with proposal 2 I0704 03:37:20.590499 185483 replica.cpp:391] Replica received explicit promise request from __req_res__(926)@172.17.0.2:42425 for position 0 with proposal 2 I0704 03:37:20.590855 185483 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 324789ns I0704 03:37:20.590858 185488 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 338180ns I0704 03:37:20.590876 185483 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.590890 185488 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.591648 185490 replica.cpp:541] Replica received write request for position 0 from __req_res__(927)@172.17.0.2:42425 I0704 03:37:20.591671 185484 replica.cpp:541] Replica received write request for position 0 from __req_res__(928)@172.17.0.2:42425 I0704 03:37:20.591722 185490 leveldb.cpp:510] Reading position from leveldb took 38453ns I0704 03:37:20.591729 185484 leveldb.cpp:510] Reading position from leveldb took 30470ns I0704 03:37:20.592087 185484 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 329106ns I0704 03:37:20.592087 185490 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 330051ns I0704 03:37:20.592108 185484 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.592123 185490 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.592505 185486 replica.cpp:695] Replica received learned notice for position 0 from log-network(44)@172.17.0.2:42425 I0704 03:37:20.592509 185489 replica.cpp:695] Replica received learned notice for position 0 from log-network(44)@172.17.0.2:42425 I0704 03:37:20.592820 185486 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 298631ns I0704 03:37:20.592823 185489 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 283648ns I0704 03:37:20.592839 185486 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.592851 185489 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.593227 185492 log.cpp:570] Writer started with ending position 0 I0704 03:37:20.593665 185495 log.cpp:578] Attempting to append 11 bytes to the log I0704 03:37:20.593755 185498 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 I0704 03:37:20.594357 185489 replica.cpp:541] Replica received write request for position 1 from __req_res__(929)@172.17.0.2:42425 I0704 03:37:20.594391 185486 replica.cpp:541] Replica received write request for position 1 from __req_res__(930)@172.17.0.2:42425 I0704 03:37:20.594713 185486 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 299715ns I0704 03:37:20.594727 185486 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.594734 185489 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 349471ns I0704 03:37:20.594771 185489 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.595230 185504 replica.cpp:695] Replica received learned notice for position 1 from log-network(44)@172.17.0.2:42425 I0704 03:37:20.595284 185497 replica.cpp:695] Replica received learned notice for position 1 from log-network(44)@172.17.0.2:42425 I0704 03:37:20.595585 185504 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 345369ns I0704 03:37:20.595603 185504 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.595775 185497 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 450440ns I0704 03:37:20.595808 185497 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.597165 185482 leveldb.cpp:510] Reading position from leveldb took 53063ns [ OK ] LogTest.WriteRead (36 ms) [ RUN ] LogTest.Position I0704 03:37:20.602098 185481 leveldb.cpp:217] Opened db in 2.555157ms I0704 03:37:20.602931 185481 leveldb.cpp:224] Compacted db in 811637ns I0704 03:37:20.602962 185481 leveldb.cpp:239] Created db iterator in 19075ns I0704 03:37:20.602972 185481 leveldb.cpp:245] Seeked to beginning of db in 4179ns I0704 03:37:20.602980 185481 leveldb.cpp:320] Iterated through 0 keys in the db in 3019ns I0704 03:37:20.603008 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.603663 185486 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 447607ns I0704 03:37:20.603680 185486 replica.cpp:322] Persisted replica status to VOTING I0704 03:37:20.605998 185481 leveldb.cpp:217] Opened db in 2.032791ms I0704 03:37:20.606766 185481 leveldb.cpp:224] Compacted db in 750867ns I0704 03:37:20.606796 185481 leveldb.cpp:239] Created db iterator in 15328ns I0704 03:37:20.606804 185481 leveldb.cpp:245] Seeked to beginning of db in 3605ns I0704 03:37:20.606812 185481 leveldb.cpp:320] Iterated through 0 keys in the db in 2807ns I0704 03:37:20.606837 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.607556 185496 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 540545ns I0704 03:37:20.607595 185496 replica.cpp:322] Persisted replica status to VOTING I0704 03:37:20.609799 185481 leveldb.cpp:217] Opened db in 1.905171ms I0704 03:37:20.611966 185481 leveldb.cpp:224] Compacted db in 2.143875ms I0704 03:37:20.612035 185481 leveldb.cpp:239] Created db iterator in 30299ns I0704 03:37:20.612071 185481 leveldb.cpp:245] Seeked to beginning of db in 26647ns I0704 03:37:20.612113 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 34957ns I0704 03:37:20.612151 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.614651 185481 leveldb.cpp:217] Opened db in 2.270519ms I0704 03:37:20.616822 185481 leveldb.cpp:224] Compacted db in 2.146705ms I0704 03:37:20.616871 185481 leveldb.cpp:239] Created db iterator in 20757ns I0704 03:37:20.616894 185481 leveldb.cpp:245] Seeked to beginning of db in 16263ns I0704 03:37:20.616919 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 19698ns I0704 03:37:20.616938 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.617318 185482 recover.cpp:437] Starting replica recovery I0704 03:37:20.617537 185482 recover.cpp:468] Replica is in VOTING status I0704 03:37:20.617667 185482 recover.cpp:447] Recover process terminated I0704 03:37:20.618018 185503 log.cpp:554] Attempting to start the writer I0704 03:37:20.619240 185494 replica.cpp:497] Replica received implicit promise request from __req_res__(931)@172.17.0.2:42425 with proposal 1 I0704 03:37:20.619294 185505 replica.cpp:497] Replica received implicit promise request from __req_res__(932)@172.17.0.2:42425 with proposal 1 I0704 03:37:20.619767 185505 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 459756ns I0704 03:37:20.619767 185494 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 507394ns I0704 03:37:20.619787 185505 replica.cpp:344] Persisted promised to 1 I0704 03:37:20.619799 185494 replica.cpp:344] Persisted promised to 1 I0704 03:37:20.620316 185488 coordinator.cpp:238] Coordinator attempting to fill missing positions I0704 03:37:20.621260 185485 replica.cpp:391] Replica received explicit promise request from __req_res__(933)@172.17.0.2:42425 for position 0 with proposal 2 I0704 03:37:20.621311 185497 replica.cpp:391] Replica received explicit promise request from __req_res__(934)@172.17.0.2:42425 for position 0 with proposal 2 I0704 03:37:20.621641 185485 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 351042ns I0704 03:37:20.621671 185485 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.621852 185497 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 484134ns I0704 03:37:20.621887 185497 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.622606 185495 replica.cpp:541] Replica received write request for position 0 from __req_res__(935)@172.17.0.2:42425 I0704 03:37:20.622669 185495 leveldb.cpp:510] Reading position from leveldb took 32600ns I0704 03:37:20.622699 185503 replica.cpp:541] Replica received write request for position 0 from __req_res__(936)@172.17.0.2:42425 I0704 03:37:20.622794 185503 leveldb.cpp:510] Reading position from leveldb took 52570ns I0704 03:37:20.623064 185495 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 366354ns I0704 03:37:20.623088 185495 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.623245 185503 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 402912ns I0704 03:37:20.623279 185503 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.623677 185505 replica.cpp:695] Replica received learned notice for position 0 from log-network(45)@172.17.0.2:42425 I0704 03:37:20.623683 185493 replica.cpp:695] Replica received learned notice for position 0 from log-network(45)@172.17.0.2:42425 I0704 03:37:20.624003 185505 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 309682ns I0704 03:37:20.624007 185493 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 300130ns I0704 03:37:20.624023 185505 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.624040 185493 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.624469 185482 log.cpp:570] Writer started with ending position 0 I0704 03:37:20.624815 185504 log.cpp:578] Attempting to append 11 bytes to the log I0704 03:37:20.624907 185485 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 I0704 03:37:20.625414 185492 replica.cpp:541] Replica received write request for position 1 from __req_res__(937)@172.17.0.2:42425 I0704 03:37:20.625424 185500 replica.cpp:541] Replica received write request for position 1 from __req_res__(938)@172.17.0.2:42425 I0704 03:37:20.625769 185500 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 319425ns I0704 03:37:20.625769 185492 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 325144ns I0704 03:37:20.625788 185500 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.625797 185492 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.626235 185495 replica.cpp:695] Replica received learned notice for position 1 from log-network(45)@172.17.0.2:42425 I0704 03:37:20.626245 185489 replica.cpp:695] Replica received learned notice for position 1 from log-network(45)@172.17.0.2:42425 I0704 03:37:20.626595 185495 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 337288ns I0704 03:37:20.626597 185489 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 326465ns I0704 03:37:20.626617 185495 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.626632 185489 replica.cpp:712] Persisted action APPEND at position 1 [ OK ] LogTest.Position (29 ms) [ RUN ] LogTest.Metrics I0704 03:37:20.631517 185481 leveldb.cpp:217] Opened db in 2.444429ms I0704 03:37:20.632536 185481 leveldb.cpp:224] Compacted db in 999393ns I0704 03:37:20.632571 185481 leveldb.cpp:239] Created db iterator in 20599ns I0704 03:37:20.632581 185481 leveldb.cpp:245] Seeked to beginning of db in 3605ns I0704 03:37:20.632589 185481 leveldb.cpp:320] Iterated through 0 keys in the db in 2887ns I0704 03:37:20.632616 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.633286 185503 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 449929ns I0704 03:37:20.633306 185503 replica.cpp:322] Persisted replica status to VOTING I0704 03:37:20.635738 185481 leveldb.cpp:217] Opened db in 2.128109ms I0704 03:37:20.638021 185481 leveldb.cpp:224] Compacted db in 2.264944ms I0704 03:37:20.638058 185481 leveldb.cpp:239] Created db iterator in 19283ns I0704 03:37:20.638079 185481 leveldb.cpp:245] Seeked to beginning of db in 16043ns I0704 03:37:20.638103 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 20588ns I0704 03:37:20.638123 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.638469 185492 recover.cpp:437] Starting replica recovery I0704 03:37:20.638700 185492 recover.cpp:468] Replica is in VOTING status I0704 03:37:20.638809 185492 recover.cpp:447] Recover process terminated I0704 03:37:20.639169 185499 log.cpp:554] Attempting to start the writer I0704 03:37:20.640257 185504 replica.cpp:497] Replica received implicit promise request from __req_res__(939)@172.17.0.2:42425 with proposal 1 I0704 03:37:20.640728 185504 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 455863ns I0704 03:37:20.640746 185504 replica.cpp:344] Persisted promised to 1 I0704 03:37:20.641326 185493 coordinator.cpp:238] Coordinator attempting to fill missing positions I0704 03:37:20.642264 185491 replica.cpp:391] Replica received explicit promise request from __req_res__(940)@172.17.0.2:42425 for position 0 with proposal 2 I0704 03:37:20.642616 185491 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 318054ns I0704 03:37:20.642635 185491 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.643258 185497 replica.cpp:541] Replica received write request for position 0 from __req_res__(941)@172.17.0.2:42425 I0704 03:37:20.643313 185497 leveldb.cpp:510] Reading position from leveldb took 30838ns I0704 03:37:20.643626 185497 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 285766ns I0704 03:37:20.643640 185497 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.644030 185488 replica.cpp:695] Replica received learned notice for position 0 from log-network(46)@172.17.0.2:42425 I0704 03:37:20.644418 185488 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 367342ns I0704 03:37:20.644452 185488 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.644913 185483 log.cpp:570] Writer started with ending position 0 I0704 03:37:20.648025 185505 process.cpp:3671] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' [ OK ] LogTest.Metrics (26 ms) [ RUN ] LogTest.ReaderCatchup I0704 03:37:20.657074 185481 leveldb.cpp:217] Opened db in 2.502849ms I0704 03:37:20.658020 185481 leveldb.cpp:224] Compacted db in 916071ns I0704 03:37:20.658072 185481 leveldb.cpp:239] Created db iterator in 24098ns I0704 03:37:20.658082 185481 leveldb.cpp:245] Seeked to beginning of db in 3630ns I0704 03:37:20.658088 185481 leveldb.cpp:320] Iterated through 0 keys in the db in 2872ns I0704 03:37:20.658125 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.658846 185486 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 442110ns I0704 03:37:20.658869 185486 replica.cpp:322] Persisted replica status to VOTING I0704 03:37:20.661171 185481 leveldb.cpp:217] Opened db in 1.93342ms I0704 03:37:20.661903 185481 leveldb.cpp:224] Compacted db in 714544ns I0704 03:37:20.661942 185481 leveldb.cpp:239] Created db iterator in 20195ns I0704 03:37:20.661952 185481 leveldb.cpp:245] Seeked to beginning of db in 3668ns I0704 03:37:20.661958 185481 leveldb.cpp:320] Iterated through 0 keys in the db in 2660ns I0704 03:37:20.661986 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.662671 185503 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 419445ns I0704 03:37:20.662690 185503 replica.cpp:322] Persisted replica status to VOTING I0704 03:37:20.665899 185481 leveldb.cpp:217] Opened db in 2.855824ms I0704 03:37:20.667062 185481 leveldb.cpp:224] Compacted db in 1.146599ms I0704 03:37:20.667105 185481 leveldb.cpp:239] Created db iterator in 20799ns I0704 03:37:20.667115 185481 leveldb.cpp:245] Seeked to beginning of db in 4332ns I0704 03:37:20.667124 185481 leveldb.cpp:320] Iterated through 0 keys in the db in 3371ns I0704 03:37:20.667150 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.667825 185484 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 463789ns I0704 03:37:20.667855 185484 replica.cpp:322] Persisted replica status to VOTING I0704 03:37:20.670512 185481 leveldb.cpp:217] Opened db in 2.347703ms I0704 03:37:20.672405 185481 leveldb.cpp:224] Compacted db in 1.879211ms I0704 03:37:20.672453 185481 leveldb.cpp:239] Created db iterator in 23993ns I0704 03:37:20.672478 185481 leveldb.cpp:245] Seeked to beginning of db in 18420ns I0704 03:37:20.672515 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 33512ns I0704 03:37:20.672546 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.674834 185481 leveldb.cpp:217] Opened db in 1.991424ms I0704 03:37:20.676582 185481 leveldb.cpp:224] Compacted db in 1.738371ms I0704 03:37:20.676626 185481 leveldb.cpp:239] Created db iterator in 21112ns I0704 03:37:20.676646 185481 leveldb.cpp:245] Seeked to beginning of db in 14551ns I0704 03:37:20.676673 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 24119ns I0704 03:37:20.676698 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.678184 185494 replica.cpp:497] Replica received implicit promise request from __req_res__(942)@172.17.0.2:42425 with proposal 1 I0704 03:37:20.678193 185500 replica.cpp:497] Replica received implicit promise request from __req_res__(943)@172.17.0.2:42425 with proposal 1 I0704 03:37:20.678663 185500 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 445136ns I0704 03:37:20.678663 185494 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 453987ns I0704 03:37:20.678681 185500 replica.cpp:344] Persisted promised to 1 I0704 03:37:20.678691 185494 replica.cpp:344] Persisted promised to 1 I0704 03:37:20.679198 185494 coordinator.cpp:238] Coordinator attempting to fill missing positions I0704 03:37:20.680123 185493 replica.cpp:391] Replica received explicit promise request from __req_res__(944)@172.17.0.2:42425 for position 0 with proposal 2 I0704 03:37:20.680157 185500 replica.cpp:391] Replica received explicit promise request from __req_res__(945)@172.17.0.2:42425 for position 0 with proposal 2 I0704 03:37:20.680500 185500 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 315388ns I0704 03:37:20.680505 185493 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 333969ns I0704 03:37:20.680516 185500 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.680527 185493 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.681239 185488 replica.cpp:541] Replica received write request for position 0 from __req_res__(946)@172.17.0.2:42425 I0704 03:37:20.681263 185495 replica.cpp:541] Replica received write request for position 0 from __req_res__(947)@172.17.0.2:42425 I0704 03:37:20.681301 185488 leveldb.cpp:510] Reading position from leveldb took 33894ns I0704 03:37:20.681308 185495 leveldb.cpp:510] Reading position from leveldb took 26074ns I0704 03:37:20.681618 185488 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 285076ns I0704 03:37:20.681631 185488 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.681632 185495 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 305608ns I0704 03:37:20.681663 185495 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.682039 185486 replica.cpp:695] Replica received learned notice for position 0 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.682044 185501 replica.cpp:695] Replica received learned notice for position 0 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.682411 185486 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 354471ns I0704 03:37:20.682420 185501 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 357606ns I0704 03:37:20.682428 185486 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.682453 185501 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.683112 185502 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 I0704 03:37:20.683621 185492 replica.cpp:541] Replica received write request for position 1 from __req_res__(948)@172.17.0.2:42425 I0704 03:37:20.683635 185487 replica.cpp:541] Replica received write request for position 1 from __req_res__(949)@172.17.0.2:42425 I0704 03:37:20.683969 185492 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 326579ns I0704 03:37:20.683974 185487 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 310364ns I0704 03:37:20.683984 185492 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.683997 185487 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.684374 185497 replica.cpp:695] Replica received learned notice for position 1 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.684397 185489 replica.cpp:695] Replica received learned notice for position 1 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.684723 185497 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 325698ns I0704 03:37:20.684726 185489 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 301915ns I0704 03:37:20.684744 185497 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.684759 185489 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.685250 185483 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 2 I0704 03:37:20.685668 185486 replica.cpp:541] Replica received write request for position 2 from __req_res__(950)@172.17.0.2:42425 I0704 03:37:20.685725 185485 replica.cpp:541] Replica received write request for position 2 from __req_res__(951)@172.17.0.2:42425 I0704 03:37:20.686020 185486 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 330897ns I0704 03:37:20.686043 185486 replica.cpp:712] Persisted action APPEND at position 2 I0704 03:37:20.686189 185485 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 434233ns I0704 03:37:20.686213 185485 replica.cpp:712] Persisted action APPEND at position 2 I0704 03:37:20.686563 185496 replica.cpp:695] Replica received learned notice for position 2 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.686566 185499 replica.cpp:695] Replica received learned notice for position 2 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.686889 185496 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 309570ns I0704 03:37:20.686894 185499 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 301131ns I0704 03:37:20.686902 185496 replica.cpp:712] Persisted action APPEND at position 2 I0704 03:37:20.686914 185499 replica.cpp:712] Persisted action APPEND at position 2 I0704 03:37:20.687332 185500 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3 I0704 03:37:20.687759 185482 replica.cpp:541] Replica received write request for position 3 from __req_res__(952)@172.17.0.2:42425 I0704 03:37:20.687783 185490 replica.cpp:541] Replica received write request for position 3 from __req_res__(953)@172.17.0.2:42425 I0704 03:37:20.688102 185482 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 313401ns I0704 03:37:20.688103 185490 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 286453ns I0704 03:37:20.688122 185482 replica.cpp:712] Persisted action APPEND at position 3 I0704 03:37:20.688136 185490 replica.cpp:712] Persisted action APPEND at position 3 I0704 03:37:20.688467 185493 replica.cpp:695] Replica received learned notice for position 3 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.688479 185502 replica.cpp:695] Replica received learned notice for position 3 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.688803 185502 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 306517ns I0704 03:37:20.688807 185493 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 318815ns I0704 03:37:20.688823 185502 replica.cpp:712] Persisted action APPEND at position 3 I0704 03:37:20.688838 185493 replica.cpp:712] Persisted action APPEND at position 3 I0704 03:37:20.689214 185500 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 4 I0704 03:37:20.689671 185495 replica.cpp:541] Replica received write request for position 4 from __req_res__(954)@172.17.0.2:42425 I0704 03:37:20.689724 185488 replica.cpp:541] Replica received write request for position 4 from __req_res__(955)@172.17.0.2:42425 I0704 03:37:20.690044 185495 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 349621ns I0704 03:37:20.690066 185495 replica.cpp:712] Persisted action APPEND at position 4 I0704 03:37:20.690183 185488 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 430336ns I0704 03:37:20.690207 185488 replica.cpp:712] Persisted action APPEND at position 4 I0704 03:37:20.690593 185501 replica.cpp:695] Replica received learned notice for position 4 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.690595 185487 replica.cpp:695] Replica received learned notice for position 4 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.690917 185501 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 307311ns I0704 03:37:20.690919 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 295432ns I0704 03:37:20.690933 185501 replica.cpp:712] Persisted action APPEND at position 4 I0704 03:37:20.690946 185487 replica.cpp:712] Persisted action APPEND at position 4 I0704 03:37:20.691366 185485 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 5 I0704 03:37:20.691800 185504 replica.cpp:541] Replica received write request for position 5 from __req_res__(956)@172.17.0.2:42425 I0704 03:37:20.691895 185484 replica.cpp:541] Replica received write request for position 5 from __req_res__(957)@172.17.0.2:42425 I0704 03:37:20.692147 185504 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 326833ns I0704 03:37:20.692168 185504 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.692309 185484 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 386263ns I0704 03:37:20.692330 185484 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.692679 185503 replica.cpp:695] Replica received learned notice for position 5 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.692696 185505 replica.cpp:695] Replica received learned notice for position 5 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.693018 185505 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 300755ns I0704 03:37:20.693024 185503 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 333167ns I0704 03:37:20.693040 185505 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.693053 185503 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.693504 185497 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 6 I0704 03:37:20.693928 185483 replica.cpp:541] Replica received write request for position 6 from __req_res__(958)@172.17.0.2:42425 I0704 03:37:20.693946 185504 replica.cpp:541] Replica received write request for position 6 from __req_res__(959)@172.17.0.2:42425 I0704 03:37:20.694274 185483 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 318227ns I0704 03:37:20.694281 185504 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 315061ns I0704 03:37:20.694293 185483 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.694311 185504 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.694636 185503 replica.cpp:695] Replica received learned notice for position 6 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.694655 185485 replica.cpp:695] Replica received learned notice for position 6 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.695004 185503 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 353494ns I0704 03:37:20.695005 185485 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 327511ns I0704 03:37:20.695027 185503 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.695042 185485 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.695444 185495 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 7 I0704 03:37:20.695850 185500 replica.cpp:541] Replica received write request for position 7 from __req_res__(960)@172.17.0.2:42425 I0704 03:37:20.695873 185498 replica.cpp:541] Replica received write request for position 7 from __req_res__(961)@172.17.0.2:42425 I0704 03:37:20.696195 185500 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 319557ns I0704 03:37:20.696195 185498 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 292088ns I0704 03:37:20.696214 185500 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.696226 185498 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.696557 185489 replica.cpp:695] Replica received learned notice for position 7 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.696568 185485 replica.cpp:695] Replica received learned notice for position 7 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.696867 185485 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 279997ns I0704 03:37:20.696873 185489 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 304029ns I0704 03:37:20.696884 185485 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.696895 185489 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.697676 185499 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 8 I0704 03:37:20.698136 185498 replica.cpp:541] Replica received write request for position 8 from __req_res__(962)@172.17.0.2:42425 I0704 03:37:20.698210 185500 replica.cpp:541] Replica received write request for position 8 from __req_res__(963)@172.17.0.2:42425 I0704 03:37:20.698508 185498 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 341414ns I0704 03:37:20.698529 185498 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.698669 185500 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 429992ns I0704 03:37:20.698695 185500 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.699028 185502 replica.cpp:695] Replica received learned notice for position 8 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.699039 185496 replica.cpp:695] Replica received learned notice for position 8 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.699355 185496 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 300599ns I0704 03:37:20.699359 185502 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 313081ns I0704 03:37:20.699368 185496 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.699378 185502 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.699992 185486 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 9 I0704 03:37:20.700475 185503 replica.cpp:541] Replica received write request for position 9 from __req_res__(964)@172.17.0.2:42425 I0704 03:37:20.700515 185483 replica.cpp:541] Replica received write request for position 9 from __req_res__(965)@172.17.0.2:42425 I0704 03:37:20.700815 185483 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 273818ns I0704 03:37:20.700821 185503 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 314635ns I0704 03:37:20.700834 185483 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.700845 185503 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.701200 185499 replica.cpp:695] Replica received learned notice for position 9 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.701203 185494 replica.cpp:695] Replica received learned notice for position 9 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.701491 185499 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 276493ns I0704 03:37:20.701500 185494 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 275131ns I0704 03:37:20.701510 185499 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.701527 185494 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.701989 185487 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 10 I0704 03:37:20.702438 185485 replica.cpp:541] Replica received write request for position 10 from __req_res__(966)@172.17.0.2:42425 I0704 03:37:20.702461 185488 replica.cpp:541] Replica received write request for position 10 from __req_res__(967)@172.17.0.2:42425 I0704 03:37:20.702759 185488 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 267894ns I0704 03:37:20.702762 185485 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 294759ns I0704 03:37:20.702780 185488 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.702800 185485 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.703116 185494 replica.cpp:695] Replica received learned notice for position 10 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.703119 185495 replica.cpp:695] Replica received learned notice for position 10 from log-network(47)@172.17.0.2:42425 I0704 03:37:20.703414 185495 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 268552ns I0704 03:37:20.703419 185494 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 287437ns I0704 03:37:20.703430 185495 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.703440 185494 replica.cpp:712] Persisted action APPEND at position 10 I0704 03:37:20.706405 185481 leveldb.cpp:217] Opened db in 2.5864ms I0704 03:37:20.708231 185481 leveldb.cpp:224] Compacted db in 1.80985ms I0704 03:37:20.708276 185481 leveldb.cpp:239] Created db iterator in 24875ns I0704 03:37:20.708295 185481 leveldb.cpp:245] Seeked to beginning of db in 15775ns I0704 03:37:20.708324 185481 leveldb.cpp:320] Iterated through 1 keys in the db in 24202ns I0704 03:37:20.708350 185481 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0704 03:37:20.708779 185497 recover.cpp:437] Starting replica recovery I0704 03:37:20.709024 185497 recover.cpp:468] Replica is in VOTING status I0704 03:37:20.709138 185497 recover.cpp:447] Recover process terminated I0704 03:37:20.709460 185488 catchup.cpp:342] Starting missing positions recovery I0704 03:37:20.709686 185488 catchup.cpp:368] Replica is in VOTING status I0704 03:37:20.710600 185493 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(968)@172.17.0.2:42425 I0704 03:37:20.710634 185486 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(969)@172.17.0.2:42425 I0704 03:37:20.710677 185491 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(970)@172.17.0.2:42425 I0704 03:37:20.711166 185500 recover.cpp:197] Received a recover response from a replica in VOTING status I0704 03:37:20.711409 185500 recover.cpp:197] Received a recover response from a replica in VOTING status I0704 03:37:20.711970 185483 catchup.cpp:423] Starting catch-up from position 0 to 9 I0704 03:37:20.712863 185487 replica.cpp:391] Replica received explicit promise request from __req_res__(971)@172.17.0.2:42425 for position 0 with proposal 0 I0704 03:37:20.712890 185490 replica.cpp:391] Replica received explicit promise request from __req_res__(972)@172.17.0.2:42425 for position 0 with proposal 0 I0704 03:37:20.712898 185504 replica.cpp:391] Replica received explicit promise request from __req_res__(973)@172.17.0.2:42425 for position 0 with proposal 0 I0704 03:37:20.712939 185487 leveldb.cpp:510] Reading position from leveldb took 48851ns I0704 03:37:20.712972 185490 leveldb.cpp:510] Reading position from leveldb took 44657ns I0704 03:37:20.894012 185486 replica.cpp:391] Replica received explicit promise request from __req_res__(974)@172.17.0.2:42425 for position 0 with proposal 3 I0704 03:37:20.894086 185502 replica.cpp:391] Replica received explicit promise request from __req_res__(975)@172.17.0.2:42425 for position 0 with proposal 3 I0704 03:37:20.894167 185486 leveldb.cpp:510] Reading position from leveldb took 81623ns I0704 03:37:20.894189 185502 leveldb.cpp:510] Reading position from leveldb took 55821ns I0704 03:37:20.894263 185492 replica.cpp:391] Replica received explicit promise request from __req_res__(976)@172.17.0.2:42425 for position 0 with proposal 3 I0704 03:37:20.894788 185502 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 567044ns I0704 03:37:20.894789 185486 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 577866ns I0704 03:37:20.894820 185502 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.894837 185486 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.895036 185492 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 731504ns I0704 03:37:20.895069 185492 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.895336 185485 replica.cpp:695] Replica received learned notice for position 0 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.895341 185498 replica.cpp:695] Replica received learned notice for position 0 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.895368 185501 replica.cpp:695] Replica received learned notice for position 0 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.895694 185485 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 339108ns I0704 03:37:20.895701 185498 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 329465ns I0704 03:37:20.895718 185485 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.895731 185498 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.895872 185501 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 470516ns I0704 03:37:20.895907 185501 replica.cpp:712] Persisted action NOP at position 0 I0704 03:37:20.897080 185483 replica.cpp:391] Replica received explicit promise request from __req_res__(979)@172.17.0.2:42425 for position 1 with proposal 3 I0704 03:37:20.897084 185484 replica.cpp:391] Replica received explicit promise request from __req_res__(977)@172.17.0.2:42425 for position 1 with proposal 3 I0704 03:37:20.897110 185488 replica.cpp:391] Replica received explicit promise request from __req_res__(978)@172.17.0.2:42425 for position 1 with proposal 3 I0704 03:37:20.897248 185484 leveldb.cpp:510] Reading position from leveldb took 109212ns I0704 03:37:20.897284 185488 leveldb.cpp:510] Reading position from leveldb took 105326ns I0704 03:37:20.897434 185483 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 329640ns I0704 03:37:20.897460 185483 replica.cpp:712] Persisted action NOP at position 1 I0704 03:37:20.897861 185484 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 532763ns I0704 03:37:20.897889 185484 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.897907 185488 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 554815ns I0704 03:37:20.897960 185488 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.898411 185498 replica.cpp:695] Replica received learned notice for position 1 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.898417 185494 replica.cpp:695] Replica received learned notice for position 1 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.898473 185482 replica.cpp:695] Replica received learned notice for position 1 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.898824 185498 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 393457ns I0704 03:37:20.898828 185494 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 383479ns I0704 03:37:20.898849 185498 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.898866 185494 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.899027 185482 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 522694ns I0704 03:37:20.899075 185482 replica.cpp:712] Persisted action APPEND at position 1 I0704 03:37:20.900264 185485 replica.cpp:391] Replica received explicit promise request from __req_res__(980)@172.17.0.2:42425 for position 2 with proposal 3 I0704 03:37:20.900337 185504 replica.cpp:391] Replica received explicit promise request from __req_res__(981)@172.17.0.2:42425 for position 2 with proposal 3 I0704 03:37:20.900378 185485 leveldb.cpp:510] Reading position from leveldb took 73003ns I0704 03:37:20.900399 185490 replica.cpp:391] Replica received explicit promise request from __req_res__(982)@172.17.0.2:42425 for position 2 with proposal 3 I0704 03:37:20.900453 185504 leveldb.cpp:510] Reading position from leveldb took 71314ns I0704 03:37:20.900763 185490 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 332483ns I0704 03:37:20.900771 185485 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 338292ns I0704 03:37:20.900787 185490 replica.cpp:712] Persisted action NOP at position 2 I0704 03:37:20.900800 185485 replica.cpp:712] Persisted action APPEND at position 2 I0704 03:37:20.900954 185504 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 461691ns I0704 03:37:20.901005 185504 replica.cpp:712] Persisted action APPEND at position 2 I0704 03:37:20.901239 185482 replica.cpp:695] Replica received learned notice for position 2 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.901252 185491 replica.cpp:695] Replica received learned notice for position 2 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.901268 185499 replica.cpp:695] Replica received learned notice for position 2 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.901656 185491 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 361128ns I0704 03:37:20.901672 185482 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 399267ns I0704 03:37:20.901680 185491 replica.cpp:712] Persisted action APPEND at position 2 I0704 03:37:20.901675 185499 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 356656ns I0704 03:37:20.901710 185482 replica.cpp:712] Persisted action APPEND at position 2 I0704 03:37:20.901757 185499 replica.cpp:712] Persisted action APPEND at position 2 I0704 03:37:20.902766 185494 replica.cpp:391] Replica received explicit promise request from __req_res__(983)@172.17.0.2:42425 for position 3 with proposal 3 I0704 03:37:20.902830 185494 leveldb.cpp:510] Reading position from leveldb took 37832ns I0704 03:37:20.902863 185487 replica.cpp:391] Replica received explicit promise request from __req_res__(984)@172.17.0.2:42425 for position 3 with proposal 3 I0704 03:37:20.902902 185484 replica.cpp:391] Replica received explicit promise request from __req_res__(985)@172.17.0.2:42425 for position 3 with proposal 3 I0704 03:37:20.902964 185487 leveldb.cpp:510] Reading position from leveldb took 61450ns I0704 03:37:20.903189 185494 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 336762ns I0704 03:37:20.903208 185494 replica.cpp:712] Persisted action APPEND at position 3 I0704 03:37:20.903371 185484 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 447528ns I0704 03:37:20.903385 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 378447ns I0704 03:37:20.903400 185484 replica.cpp:712] Persisted action NOP at position 3 I0704 03:37:20.903427 185487 replica.cpp:712] Persisted action APPEND at position 3 I0704 03:37:20.903568 185493 replica.cpp:695] Replica received learned notice for position 3 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.903590 185488 replica.cpp:695] Replica received learned notice for position 3 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.903625 185487 replica.cpp:695] Replica received learned notice for position 3 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.903950 185493 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 361890ns I0704 03:37:20.903968 185493 replica.cpp:712] Persisted action APPEND at position 3 I0704 03:37:20.904126 185488 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 485016ns I0704 03:37:20.904138 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 479698ns I0704 03:37:20.904160 185488 replica.cpp:712] Persisted action APPEND at position 3 I0704 03:37:20.904177 185487 replica.cpp:712] Persisted action APPEND at position 3 I0704 03:37:20.904866 185505 replica.cpp:391] Replica received explicit promise request from __req_res__(986)@172.17.0.2:42425 for position 4 with proposal 3 I0704 03:37:20.904917 185484 replica.cpp:391] Replica received explicit promise request from __req_res__(987)@172.17.0.2:42425 for position 4 with proposal 3 I0704 03:37:20.904932 185505 leveldb.cpp:510] Reading position from leveldb took 37082ns I0704 03:37:20.904947 185491 replica.cpp:391] Replica received explicit promise request from __req_res__(988)@172.17.0.2:42425 for position 4 with proposal 3 I0704 03:37:20.904970 185484 leveldb.cpp:510] Reading position from leveldb took 33409ns I0704 03:37:20.905267 185491 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 288056ns I0704 03:37:20.905273 185505 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 323997ns I0704 03:37:20.905288 185491 replica.cpp:712] Persisted action NOP at position 4 I0704 03:37:20.905303 185505 replica.cpp:712] Persisted action APPEND at position 4 I0704 03:37:20.905437 185484 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 405055ns I0704 03:37:20.905459 185484 replica.cpp:712] Persisted action APPEND at position 4 I0704 03:37:20.905658 185495 replica.cpp:695] Replica received learned notice for position 4 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.905680 185500 replica.cpp:695] Replica received learned notice for position 4 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.905704 185483 replica.cpp:695] Replica received learned notice for position 4 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.906004 185483 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 281179ns I0704 03:37:20.906010 185495 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 335860ns I0704 03:37:20.906006 185500 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 303243ns I0704 03:37:20.906038 185495 replica.cpp:712] Persisted action APPEND at position 4 I0704 03:37:20.906028 185483 replica.cpp:712] Persisted action APPEND at position 4 I0704 03:37:20.906054 185500 replica.cpp:712] Persisted action APPEND at position 4 I0704 03:37:20.906865 185498 replica.cpp:391] Replica received explicit promise request from __req_res__(989)@172.17.0.2:42425 for position 5 with proposal 3 I0704 03:37:20.906929 185498 leveldb.cpp:510] Reading position from leveldb took 36867ns I0704 03:37:20.906932 185488 replica.cpp:391] Replica received explicit promise request from __req_res__(991)@172.17.0.2:42425 for position 5 with proposal 3 I0704 03:37:20.906932 185484 replica.cpp:391] Replica received explicit promise request from __req_res__(990)@172.17.0.2:42425 for position 5 with proposal 3 I0704 03:37:20.907006 185484 leveldb.cpp:510] Reading position from leveldb took 37708ns I0704 03:37:20.907276 185488 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 317602ns I0704 03:37:20.907282 185498 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 333653ns I0704 03:37:20.907294 185488 replica.cpp:712] Persisted action NOP at position 5 I0704 03:37:20.907311 185498 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.907445 185484 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 409395ns I0704 03:37:20.907469 185484 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.907635 185499 replica.cpp:695] Replica received learned notice for position 5 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.907646 185501 replica.cpp:695] Replica received learned notice for position 5 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.907649 185503 replica.cpp:695] Replica received learned notice for position 5 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.907948 185499 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 298881ns I0704 03:37:20.907955 185501 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 291561ns I0704 03:37:20.907951 185503 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 272257ns I0704 03:37:20.907977 185501 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.907968 185499 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.907991 185503 replica.cpp:712] Persisted action APPEND at position 5 I0704 03:37:20.908836 185494 replica.cpp:391] Replica received explicit promise request from __req_res__(992)@172.17.0.2:42425 for position 6 with proposal 3 I0704 03:37:20.908838 185483 replica.cpp:391] Replica received explicit promise request from __req_res__(993)@172.17.0.2:42425 for position 6 with proposal 3 I0704 03:37:20.908861 185484 replica.cpp:391] Replica received explicit promise request from __req_res__(994)@172.17.0.2:42425 for position 6 with proposal 3 I0704 03:37:20.908896 185494 leveldb.cpp:510] Reading position from leveldb took 34121ns I0704 03:37:20.908913 185483 leveldb.cpp:510] Reading position from leveldb took 37657ns I0704 03:37:20.909185 185483 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 249651ns I0704 03:37:20.909186 185494 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 267856ns I0704 03:37:20.909205 185483 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.909188 185484 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 299588ns I0704 03:37:20.909217 185494 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.909241 185484 replica.cpp:712] Persisted action NOP at position 6 I0704 03:37:20.909526 185488 replica.cpp:695] Replica received learned notice for position 6 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.909538 185487 replica.cpp:695] Replica received learned notice for position 6 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.909552 185486 replica.cpp:695] Replica received learned notice for position 6 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.909849 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 292116ns I0704 03:37:20.909865 185486 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 291987ns I0704 03:37:20.909871 185487 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.909881 185486 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.909852 185488 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 306203ns I0704 03:37:20.909955 185488 replica.cpp:712] Persisted action APPEND at position 6 I0704 03:37:20.910724 185503 replica.cpp:391] Replica received explicit promise request from __req_res__(995)@172.17.0.2:42425 for position 7 with proposal 3 I0704 03:37:20.910774 185496 replica.cpp:391] Replica received explicit promise request from __req_res__(996)@172.17.0.2:42425 for position 7 with proposal 3 I0704 03:37:20.910791 185503 leveldb.cpp:510] Reading position from leveldb took 37412ns I0704 03:37:20.910816 185490 replica.cpp:391] Replica received explicit promise request from __req_res__(997)@172.17.0.2:42425 for position 7 with proposal 3 I0704 03:37:20.910838 185496 leveldb.cpp:510] Reading position from leveldb took 40984ns I0704 03:37:20.911129 185496 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 261805ns I0704 03:37:20.911134 185490 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 293030ns I0704 03:37:20.911144 185496 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.911156 185490 replica.cpp:712] Persisted action NOP at position 7 I0704 03:37:20.911136 185503 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 322876ns I0704 03:37:20.911190 185503 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.911538 185482 replica.cpp:695] Replica received learned notice for position 7 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.911547 185485 replica.cpp:695] Replica received learned notice for position 7 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.911597 185505 replica.cpp:695] Replica received learned notice for position 7 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.911851 185482 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 300304ns I0704 03:37:20.911852 185485 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 290550ns I0704 03:37:20.911876 185482 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.911890 185485 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.912074 185505 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 429537ns I0704 03:37:20.912123 185505 replica.cpp:712] Persisted action APPEND at position 7 I0704 03:37:20.913036 185489 replica.cpp:391] Replica received explicit promise request from __req_res__(998)@172.17.0.2:42425 for position 8 with proposal 3 I0704 03:37:20.913059 185487 replica.cpp:391] Replica received explicit promise request from __req_res__(999)@172.17.0.2:42425 for position 8 with proposal 3 I0704 03:37:20.913100 185489 leveldb.cpp:510] Reading position from leveldb took 35337ns I0704 03:37:20.913112 185487 leveldb.cpp:510] Reading position from leveldb took 31080ns I0704 03:37:20.913121 185486 replica.cpp:391] Replica received explicit promise request from __req_res__(1000)@172.17.0.2:42425 for position 8 with proposal 3 I0704 03:37:20.913436 185486 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 288597ns I0704 03:37:20.913439 185489 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 316632ns I0704 03:37:20.913456 185486 replica.cpp:712] Persisted action NOP at position 8 I0704 03:37:20.913445 185487 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 316431ns I0704 03:37:20.913470 185489 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.913492 185487 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.913928 185499 replica.cpp:695] Replica received learned notice for position 8 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.913944 185502 replica.cpp:695] Replica received learned notice for position 8 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.913957 185497 replica.cpp:695] Replica received learned notice for position 8 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.914270 185502 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 304062ns I0704 03:37:20.914275 185497 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 299273ns I0704 03:37:20.914294 185502 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.914276 185499 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 331211ns I0704 03:37:20.914309 185497 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.914336 185499 replica.cpp:712] Persisted action APPEND at position 8 I0704 03:37:20.915134 185493 replica.cpp:391] Replica received explicit promise request from __req_res__(1001)@172.17.0.2:42425 for position 9 with proposal 3 I0704 03:37:20.915175 185483 replica.cpp:391] Replica received explicit promise request from __req_res__(1002)@172.17.0.2:42425 for position 9 with proposal 3 I0704 03:37:20.915199 185493 leveldb.cpp:510] Reading position from leveldb took 40382ns I0704 03:37:20.915180 185491 replica.cpp:391] Replica received explicit promise request from __req_res__(1003)@172.17.0.2:42425 for position 9 with proposal 3 I0704 03:37:20.915238 185483 leveldb.cpp:510] Reading position from leveldb took 35544ns I0704 03:37:20.915526 185483 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 265926ns I0704 03:37:20.915529 185493 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 298792ns I0704 03:37:20.915549 185483 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.915558 185493 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.915531 185491 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 294369ns I0704 03:37:20.915589 185491 replica.cpp:712] Persisted action NOP at position 9 I0704 03:37:20.915899 185491 replica.cpp:695] Replica received learned notice for position 9 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.915900 185488 replica.cpp:695] Replica received learned notice for position 9 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.915901 185500 replica.cpp:695] Replica received learned notice for position 9 from log-network(48)@172.17.0.2:42425 I0704 03:37:20.916275 185488 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 334962ns I0704 03:37:20.916275 185491 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 354370ns I0704 03:37:20.916296 185488 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.916311 185491 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.916473 185500 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 463478ns I0704 03:37:20.916520 185500 replica.cpp:712] Persisted action APPEND at position 9 I0704 03:37:20.916797 185484 catchup.cpp:357] Recover process terminated I0704 03:37:20.917940 185502 leveldb.cpp:510] Reading position from leveldb took 41488ns I0704 03:37:20.918018 185502 leveldb.cpp:510] Reading position from leveldb took 40388ns I0704 03:37:20.918097 185502 leveldb.cpp:510] Reading position from leveldb took 38998ns I0704 03:37:20.918169 185502 leveldb.cpp:510] Reading position from leveldb took 34421ns I0704 03:37:20.918234 185502 leveldb.cpp:510] Reading position from leveldb took 32785ns I0704 03:37:20.918303 185502 leveldb.cpp:510] Reading position from leveldb took 31070ns I0704 03:37:20.918354 185502 leveldb.cpp:510] Reading position from leveldb took 26569ns I0704 03:37:20.918409 185502 leveldb.cpp:510] Reading position from leveldb took 29136ns I0704 03:37:20.918474 185502 leveldb.cpp:510] Reading position from leveldb took 32738ns I0704 03:37:20.918521 185502 leveldb.cpp:510] Reading position from leveldb took 18060ns [ OK ] LogTest.ReaderCatchup (267 ms) [----------] 4 tests from LogTest (358 ms total) [----------] 2 tests from LogZooKeeperTest I0704 03:37:20.921766 185481 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 I0704 03:37:20.968514 185481 jvm.cpp:590] Looking up method <init>(Ljava/lang/String;)V I0704 03:37:20.968750 185481 jvm.cpp:590] Looking up method deleteOnExit()V I0704 03:37:20.969429 185481 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. I0704 03:37:21.029302 185481 jvm.cpp:590] Looking up method <init>()V I0704 03:37:21.029840 185481 jvm.cpp:590] Looking up method <init>(Lorg/apache/zookeeper/server/persistence/FileTxnSnapLog;Lorg/apache/zookeeper/server/ZooKeeperServer$DataTreeBuilder;)V *** Aborted at 1720064241 (unix time) try "date -d @1720064241" if you are using GNU date *** PC: @ 0x7f5d01134ccd OopStorage::Block::release_entries() *** SIGSEGV (@0x238) received by PID 185481 (TID 0x7f5d0f951b40) from PID 568; stack trace: *** @ 0x7f5d01143929 os::Linux::chained_handler() @ 0x7f5d0114963b JVM_handle_linux_signal @ 0x7f5d0113c1dc signalHandler() @ 0x7f5d10fa4420 (unknown) @ 0x7f5d01134ccd OopStorage::Block::release_entries() @ 0x7f5d01134f26 OopStorage::release() @ 0x7f5d00e37b21 jni_DeleteGlobalRef @ 0x7f5d20761798 JNIEnv_::DeleteGlobalRef() @ 0x7f5d2075f8e0 Jvm::deleteGlobalRef() @ 0x5638f0882628 Jvm::Object::~Object() @ 0x5638f088744e org::apache::zookeeper::server::ZooKeeperServer::DataTreeBuilder::~DataTreeBuilder() @ 0x5638f0889d52 org::apache::zookeeper::server::ZooKeeperServer::BasicDataTreeBuilder::~BasicDataTreeBuilder() @ 0x5638f0885d6d mesos::internal::tests::ZooKeeperTestServer::ZooKeeperTestServer() @ 0x5638ef22afcc mesos::internal::tests::ZooKeeperTest::ZooKeeperTest() @ 0x5638ef22d315 mesos::internal::tests::LogZooKeeperTest::LogZooKeeperTest() @ 0x5638ef22d426 mesos::internal::tests::LogZooKeeperTest_WriteRead_Test::LogZooKeeperTest_WriteRead_Test() @ 0x5638ef298328 testing::internal::TestFactoryImpl<>::CreateTest() @ 0x5638f08cc5fa testing::internal::HandleSehExceptionsInMethodIfSupported<>() @ 0x5638f08c5bcb testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x5638f08a1e03 testing::TestInfo::Run() @ 0x5638f08a250b testing::TestCase::Run() @ 0x5638f08a98a5 testing::internal::UnitTestImpl::RunAllTests() @ 0x5638f08cd828 testing::internal::HandleSehExceptionsInMethodIfSupported<>() @ 0x5638f08c6731 testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x5638f08a83bd testing::UnitTest::Run() @ 0x5638ef2b5edb RUN_ALL_TESTS() @ 0x5638ef2b58a2 main @ 0x7f5d10dc2083 __libc_start_main @ 0x5638ee2fb75e _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' make[3]: *** [Makefile:15951: check-am] Error 2 make[3]: Leaving directory '/tmp/SRC/build/mesos-1.12.0/_build/sub/src' I0704 03:37:21.999639 186524 exec.cpp:560] Agent exited ... shutting down I0704 03:37:22.000276 186504 executor.cpp:190] Received SHUTDOWN event I0704 03:37:22.000363 186504 executor.cpp:843] Shutting down I0704 03:37:22.000404 186504 executor.cpp:956] Sending SIGTERM to process tree at pid 186529 make[2]: *** [Makefile:15954: check] Error 2 I0704 03:37:22.009521 186504 executor.cpp:969] Sent SIGTERM to the following process trees: [ -+- 186529 sh -c dd if=/dev/zero of=volume_path/file bs=1048576 count=2 && sleep 1000 \--- 186535 sleep 1000 ] I0704 03:37:22.009555 186504 executor.cpp:973] Scheduling escalation to SIGKILL in 3secs from now make[2]: Leaving directory '/tmp/SRC/build/mesos-1.12.0/_build/sub/src' I0704 03:37:22.025938 186509 executor.cpp:1041] Command terminated with signal Terminated (pid: 186529) W0704 03:37:22.027676 186526 process.cpp:1917] Failed to send 'mesos.internal.StatusUpdateMessage' to '172.17.0.2:42425', connect: Failed to connect to 172.17.0.2:42425: Connection refused make[1]: *** [Makefile:785: check-recursive] Error 1 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 ';' 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/33293/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 > e193f3f1f0dab753b394c409e422aa81097a64b7 > src/slave/containerizer/mesos/isolators/cgroups2/cgroups2.cpp > 2ca3880790be0cd092ec05a359711e2d8e641314 > src/slave/main.cpp 21b8ea74a502478fb73510a7d49bb5f28506ce8d > > > Diff: https://reviews.apache.org/r/75016/diff/3/ > > > Testing > ------- > > > Thanks, > > Jason Zhou > >
