----------------------------------------------------------- This is an automatically generated e-mail. To reply, visit: https://reviews.apache.org/r/75075/#review226628 -----------------------------------------------------------
Bad patch! Reviews applied: [75075] 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_75075"] Error: ...<truncated>... END at position 10 I0703 02:50:04.982043 185151 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 11 I0703 02:50:04.983103 185156 replica.cpp:541] Replica received write request for position 11 from __req_res__(932)@172.17.0.2:40107 I0703 02:50:04.983338 185173 replica.cpp:541] Replica received write request for position 11 from __req_res__(933)@172.17.0.2:40107 I0703 02:50:05.047437 185156 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 64.28491ms I0703 02:50:05.047438 185173 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 64.038996ms I0703 02:50:05.047533 185156 replica.cpp:712] Persisted action TRUNCATE at position 11 I0703 02:50:05.047577 185173 replica.cpp:712] Persisted action TRUNCATE at position 11 I0703 02:50:05.048483 185155 replica.cpp:695] Replica received learned notice for position 11 from log-network(41)@172.17.0.2:40107 I0703 02:50:05.048496 185153 replica.cpp:695] Replica received learned notice for position 11 from log-network(41)@172.17.0.2:40107 I0703 02:50:05.131004 185155 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 82.470577ms I0703 02:50:05.131006 185153 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 82.420965ms I0703 02:50:05.197844 185153 leveldb.cpp:460] Deleting ~5 keys from leveldb took 66.734345ms I0703 02:50:05.197846 185155 leveldb.cpp:460] Deleting ~5 keys from leveldb took 66.77994ms I0703 02:50:05.788349 185153 leveldb.cpp:527] Compacting range 0-4 took 590.454337ms I0703 02:50:05.788349 185155 leveldb.cpp:527] Compacting range 0-4 took 590.413887ms I0703 02:50:05.788502 185153 replica.cpp:712] Persisted action TRUNCATE at position 11 I0703 02:50:05.788528 185155 replica.cpp:712] Persisted action TRUNCATE at position 11 I0703 02:50:06.035414 185149 leveldb.cpp:217] Opened db in 245.189005ms I0703 02:50:06.240249 185149 leveldb.cpp:224] Compacted db in 204.788513ms I0703 02:50:06.240377 185149 leveldb.cpp:239] Created db iterator in 64252ns I0703 02:50:06.240450 185149 leveldb.cpp:245] Seeked to beginning of db in 45136ns I0703 02:50:06.240556 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 85125ns I0703 02:50:06.240650 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:06.241818 185160 catchup.cpp:342] Starting missing positions recovery I0703 02:50:06.242424 185159 catchup.cpp:368] Replica is in VOTING status I0703 02:50:06.244251 185153 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(934)@172.17.0.2:40107 I0703 02:50:06.244655 185162 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(935)@172.17.0.2:40107 I0703 02:50:06.245870 185163 recover.cpp:197] Received a recover response from a replica in VOTING status I0703 02:50:06.246543 185163 recover.cpp:197] Received a recover response from a replica in VOTING status I0703 02:50:06.248378 185169 catchup.cpp:423] Starting catch-up from position 0 to 10 I0703 02:50:06.250048 185158 replica.cpp:391] Replica received explicit promise request from __req_res__(937)@172.17.0.2:40107 for position 0 with proposal 0 I0703 02:50:06.250232 185162 replica.cpp:391] Replica received explicit promise request from __req_res__(938)@172.17.0.2:40107 for position 0 with proposal 0 I0703 02:50:06.250356 185157 replica.cpp:391] Replica received explicit promise request from __req_res__(939)@172.17.0.2:40107 for position 0 with proposal 0 I0703 02:50:06.250916 185167 replica.cpp:695] Replica received learned notice for position 0 from log-network(42)@172.17.0.2:40107 I0703 02:50:06.250947 185150 replica.cpp:695] Replica received learned notice for position 0 from log-network(42)@172.17.0.2:40107 I0703 02:50:06.250996 185151 replica.cpp:695] Replica received learned notice for position 0 from log-network(42)@172.17.0.2:40107 I0703 02:50:06.328060 185151 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 77.014528ms I0703 02:50:06.328060 185150 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 77.081404ms I0703 02:50:06.328171 185151 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:06.328071 185167 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 77.124175ms I0703 02:50:06.328217 185150 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:06.328285 185167 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:06.330636 185170 replica.cpp:391] Replica received explicit promise request from __req_res__(940)@172.17.0.2:40107 for position 1 with proposal 0 I0703 02:50:06.330904 185156 replica.cpp:391] Replica received explicit promise request from __req_res__(941)@172.17.0.2:40107 for position 1 with proposal 0 I0703 02:50:06.331012 185171 replica.cpp:391] Replica received explicit promise request from __req_res__(942)@172.17.0.2:40107 for position 1 with proposal 0 I0703 02:50:06.331763 185168 replica.cpp:695] Replica received learned notice for position 1 from log-network(42)@172.17.0.2:40107 I0703 02:50:06.331806 185161 replica.cpp:695] Replica received learned notice for position 1 from log-network(42)@172.17.0.2:40107 I0703 02:50:06.331864 185154 replica.cpp:695] Replica received learned notice for position 1 from log-network(42)@172.17.0.2:40107 I0703 02:50:06.411530 185168 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 79.723532ms I0703 02:50:06.411533 185154 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 79.620633ms I0703 02:50:06.411530 185161 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 79.696516ms I0703 02:50:06.503443 185168 leveldb.cpp:460] Deleting ~1 keys from leveldb took 91.839766ms I0703 02:50:06.503446 185161 leveldb.cpp:460] Deleting ~1 keys from leveldb took 91.738139ms I0703 02:50:06.503446 185154 leveldb.cpp:460] Deleting ~1 keys from leveldb took 91.801587ms I0703 02:50:07.274475 185154 leveldb.cpp:527] Compacting range 0-0 took 770.881154ms I0703 02:50:07.274524 185168 leveldb.cpp:527] Compacting range 0-0 took 771.018738ms I0703 02:50:07.274564 185154 replica.cpp:712] Persisted action NOP at position 1 I0703 02:50:07.274528 185161 leveldb.cpp:527] Compacting range 0-0 took 770.976872ms I0703 02:50:07.274616 185168 replica.cpp:712] Persisted action NOP at position 1 I0703 02:50:07.274682 185161 replica.cpp:712] Persisted action NOP at position 1 I0703 02:50:07.276993 185164 replica.cpp:391] Replica received explicit promise request from __req_res__(943)@172.17.0.2:40107 for position 2 with proposal 0 I0703 02:50:07.277264 185166 replica.cpp:391] Replica received explicit promise request from __req_res__(944)@172.17.0.2:40107 for position 2 with proposal 0 I0703 02:50:07.277429 185160 replica.cpp:391] Replica received explicit promise request from __req_res__(945)@172.17.0.2:40107 for position 2 with proposal 0 I0703 02:50:07.278218 185161 replica.cpp:695] Replica received learned notice for position 2 from log-network(42)@172.17.0.2:40107 I0703 02:50:07.278275 185155 replica.cpp:695] Replica received learned notice for position 2 from log-network(42)@172.17.0.2:40107 I0703 02:50:07.278381 185165 replica.cpp:695] Replica received learned notice for position 2 from log-network(42)@172.17.0.2:40107 I0703 02:50:07.348989 185155 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 70.668699ms I0703 02:50:07.389549 185165 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 111.11255ms I0703 02:50:07.389552 185161 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 111.281639ms I0703 02:50:07.431753 185155 leveldb.cpp:460] Deleting ~1 keys from leveldb took 82.705895ms I0703 02:50:07.473465 185165 leveldb.cpp:460] Deleting ~1 keys from leveldb took 83.847545ms I0703 02:50:07.473465 185161 leveldb.cpp:460] Deleting ~1 keys from leveldb took 83.808108ms I0703 02:50:08.121264 185155 leveldb.cpp:527] Compacting range 1-1 took 689.453736ms I0703 02:50:08.121335 185161 leveldb.cpp:527] Compacting range 1-1 took 647.763479ms I0703 02:50:08.121356 185155 replica.cpp:712] Persisted action NOP at position 2 I0703 02:50:08.121443 185161 replica.cpp:712] Persisted action NOP at position 2 I0703 02:50:08.223134 185165 leveldb.cpp:527] Compacting range 1-1 took 749.60249ms I0703 02:50:08.223280 185165 replica.cpp:712] Persisted action NOP at position 2 I0703 02:50:08.225579 185166 replica.cpp:391] Replica received explicit promise request from __req_res__(946)@172.17.0.2:40107 for position 3 with proposal 0 I0703 02:50:08.225807 185164 replica.cpp:391] Replica received explicit promise request from __req_res__(947)@172.17.0.2:40107 for position 3 with proposal 0 I0703 02:50:08.225996 185158 replica.cpp:391] Replica received explicit promise request from __req_res__(948)@172.17.0.2:40107 for position 3 with proposal 0 I0703 02:50:08.226670 185154 replica.cpp:695] Replica received learned notice for position 3 from log-network(42)@172.17.0.2:40107 I0703 02:50:08.226730 185160 replica.cpp:695] Replica received learned notice for position 3 from log-network(42)@172.17.0.2:40107 I0703 02:50:08.226799 185168 replica.cpp:695] Replica received learned notice for position 3 from log-network(42)@172.17.0.2:40107 I0703 02:50:08.295328 185154 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 68.597645ms I0703 02:50:08.328745 185168 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 101.900668ms I0703 02:50:08.328745 185160 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 101.963163ms I0703 02:50:08.362257 185154 leveldb.cpp:460] Deleting ~1 keys from leveldb took 66.865058ms I0703 02:50:08.398485 185168 leveldb.cpp:460] Deleting ~1 keys from leveldb took 69.688677ms I0703 02:50:08.398485 185160 leveldb.cpp:460] Deleting ~1 keys from leveldb took 69.660939ms I0703 02:50:08.896406 185154 leveldb.cpp:527] Compacting range 2-2 took 534.11417ms I0703 02:50:08.896494 185154 replica.cpp:712] Persisted action NOP at position 3 I0703 02:50:09.014814 185160 leveldb.cpp:527] Compacting range 2-2 took 616.206843ms I0703 02:50:09.014891 185168 leveldb.cpp:527] Compacting range 2-2 took 616.327087ms I0703 02:50:09.014914 185160 replica.cpp:712] Persisted action NOP at position 3 I0703 02:50:09.014987 185168 replica.cpp:712] Persisted action NOP at position 3 I0703 02:50:09.017467 185162 replica.cpp:391] Replica received explicit promise request from __req_res__(949)@172.17.0.2:40107 for position 4 with proposal 0 I0703 02:50:09.017652 185163 replica.cpp:391] Replica received explicit promise request from __req_res__(950)@172.17.0.2:40107 for position 4 with proposal 0 I0703 02:50:09.017866 185150 replica.cpp:391] Replica received explicit promise request from __req_res__(951)@172.17.0.2:40107 for position 4 with proposal 0 I0703 02:50:09.018602 185158 replica.cpp:695] Replica received learned notice for position 4 from log-network(42)@172.17.0.2:40107 I0703 02:50:09.018640 185160 replica.cpp:695] Replica received learned notice for position 4 from log-network(42)@172.17.0.2:40107 I0703 02:50:09.018729 185164 replica.cpp:695] Replica received learned notice for position 4 from log-network(42)@172.17.0.2:40107 I0703 02:50:09.066648 185160 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 47.920477ms I0703 02:50:09.100085 185164 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 81.308833ms I0703 02:50:09.100085 185158 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 81.417058ms I0703 02:50:09.151098 185160 leveldb.cpp:460] Deleting ~1 keys from leveldb took 84.37973ms I0703 02:50:09.181871 185164 leveldb.cpp:460] Deleting ~1 keys from leveldb took 81.713211ms I0703 02:50:09.181871 185158 leveldb.cpp:460] Deleting ~1 keys from leveldb took 81.671818ms I0703 02:50:09.656773 185160 leveldb.cpp:527] Compacting range 3-3 took 505.581382ms I0703 02:50:09.656877 185160 replica.cpp:712] Persisted action NOP at position 4 I0703 02:50:09.772805 185158 leveldb.cpp:527] Compacting range 3-3 took 590.813607ms I0703 02:50:09.772843 185164 leveldb.cpp:527] Compacting range 3-3 took 590.886932ms I0703 02:50:09.772922 185158 replica.cpp:712] Persisted action NOP at position 4 I0703 02:50:09.772956 185164 replica.cpp:712] Persisted action NOP at position 4 I0703 02:50:09.775306 185165 replica.cpp:391] Replica received explicit promise request from __req_res__(952)@172.17.0.2:40107 for position 5 with proposal 0 I0703 02:50:09.775547 185165 leveldb.cpp:510] Reading position from leveldb took 177663ns I0703 02:50:09.775640 185156 replica.cpp:391] Replica received explicit promise request from __req_res__(953)@172.17.0.2:40107 for position 5 with proposal 0 I0703 02:50:09.775811 185156 leveldb.cpp:510] Reading position from leveldb took 114988ns I0703 02:50:09.776075 185153 replica.cpp:391] Replica received explicit promise request from __req_res__(954)@172.17.0.2:40107 for position 5 with proposal 0 I0703 02:50:09.953477 185171 replica.cpp:391] Replica received explicit promise request from __req_res__(955)@172.17.0.2:40107 for position 5 with proposal 2 I0703 02:50:09.953670 185171 leveldb.cpp:510] Reading position from leveldb took 139953ns I0703 02:50:09.953693 185156 replica.cpp:391] Replica received explicit promise request from __req_res__(956)@172.17.0.2:40107 for position 5 with proposal 2 I0703 02:50:09.953840 185170 replica.cpp:391] Replica received explicit promise request from __req_res__(957)@172.17.0.2:40107 for position 5 with proposal 2 I0703 02:50:09.953866 185156 leveldb.cpp:510] Reading position from leveldb took 114668ns I0703 02:50:10.021943 185156 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 67.970732ms I0703 02:50:10.021950 185170 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 68.050044ms I0703 02:50:10.022037 185156 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:10.021950 185171 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 68.197393ms I0703 02:50:10.022084 185170 replica.cpp:712] Persisted action NOP at position 5 I0703 02:50:10.022130 185171 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:10.023306 185157 replica.cpp:695] Replica received learned notice for position 5 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.023371 185166 replica.cpp:695] Replica received learned notice for position 5 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.023617 185168 replica.cpp:695] Replica received learned notice for position 5 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.097266 185166 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 73.82387ms I0703 02:50:10.097268 185168 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 73.588589ms I0703 02:50:10.097267 185157 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 73.884869ms I0703 02:50:10.097422 185166 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:10.097451 185168 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:10.097506 185157 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:10.101065 185164 replica.cpp:391] Replica received explicit promise request from __req_res__(958)@172.17.0.2:40107 for position 6 with proposal 2 I0703 02:50:10.101361 185164 leveldb.cpp:510] Reading position from leveldb took 227058ns I0703 02:50:10.101420 185150 replica.cpp:391] Replica received explicit promise request from __req_res__(959)@172.17.0.2:40107 for position 6 with proposal 2 I0703 02:50:10.101625 185150 leveldb.cpp:510] Reading position from leveldb took 151060ns I0703 02:50:10.101713 185160 replica.cpp:391] Replica received explicit promise request from __req_res__(960)@172.17.0.2:40107 for position 6 with proposal 2 I0703 02:50:10.172417 185164 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 70.944198ms I0703 02:50:10.172417 185160 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 70.647058ms I0703 02:50:10.172518 185164 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:10.172418 185150 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 70.752012ms I0703 02:50:10.172560 185160 replica.cpp:712] Persisted action NOP at position 6 I0703 02:50:10.172621 185150 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:10.173852 185165 replica.cpp:695] Replica received learned notice for position 6 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.173951 185158 replica.cpp:695] Replica received learned notice for position 6 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.173983 185151 replica.cpp:695] Replica received learned notice for position 6 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.247606 185165 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 73.708222ms I0703 02:50:10.247606 185151 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 73.572189ms I0703 02:50:10.247606 185158 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 73.603208ms I0703 02:50:10.247761 185151 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:10.247700 185165 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:10.247818 185158 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:10.250535 185164 replica.cpp:391] Replica received explicit promise request from __req_res__(961)@172.17.0.2:40107 for position 7 with proposal 2 I0703 02:50:10.250715 185164 leveldb.cpp:510] Reading position from leveldb took 124114ns I0703 02:50:10.250839 185167 replica.cpp:391] Replica received explicit promise request from __req_res__(962)@172.17.0.2:40107 for position 7 with proposal 2 I0703 02:50:10.250944 185169 replica.cpp:391] Replica received explicit promise request from __req_res__(963)@172.17.0.2:40107 for position 7 with proposal 2 I0703 02:50:10.251025 185167 leveldb.cpp:510] Reading position from leveldb took 128077ns I0703 02:50:10.322809 185167 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 71.719207ms I0703 02:50:10.322810 185164 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 72.034124ms I0703 02:50:10.322904 185167 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:10.322815 185169 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 71.810888ms I0703 02:50:10.322953 185164 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:10.322993 185169 replica.cpp:712] Persisted action NOP at position 7 I0703 02:50:10.324136 185163 replica.cpp:695] Replica received learned notice for position 7 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.324208 185159 replica.cpp:695] Replica received learned notice for position 7 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.324350 185172 replica.cpp:695] Replica received learned notice for position 7 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.389689 185159 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.443441ms I0703 02:50:10.389690 185163 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.490387ms I0703 02:50:10.389784 185159 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:10.389696 185172 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.263491ms I0703 02:50:10.389835 185163 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:10.389884 185172 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:10.392372 185152 replica.cpp:391] Replica received explicit promise request from __req_res__(964)@172.17.0.2:40107 for position 8 with proposal 2 I0703 02:50:10.392508 185165 replica.cpp:391] Replica received explicit promise request from __req_res__(965)@172.17.0.2:40107 for position 8 with proposal 2 I0703 02:50:10.392622 185152 leveldb.cpp:510] Reading position from leveldb took 169027ns I0703 02:50:10.392681 185165 leveldb.cpp:510] Reading position from leveldb took 117754ns I0703 02:50:10.392928 185173 replica.cpp:391] Replica received explicit promise request from __req_res__(966)@172.17.0.2:40107 for position 8 with proposal 2 I0703 02:50:10.456532 185152 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 63.80716ms I0703 02:50:10.456524 185173 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 63.544209ms I0703 02:50:10.456553 185165 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 63.806213ms I0703 02:50:10.456679 185173 replica.cpp:712] Persisted action NOP at position 8 I0703 02:50:10.456622 185152 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:10.456724 185165 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:10.457968 185154 replica.cpp:695] Replica received learned notice for position 8 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.457985 185172 replica.cpp:695] Replica received learned notice for position 8 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.458242 185155 replica.cpp:695] Replica received learned notice for position 8 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.531740 185172 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 73.673363ms I0703 02:50:10.531766 185154 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 73.746685ms I0703 02:50:10.531818 185172 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:10.531746 185155 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 73.457255ms I0703 02:50:10.531855 185154 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:10.531922 185155 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:10.534446 185163 replica.cpp:391] Replica received explicit promise request from __req_res__(967)@172.17.0.2:40107 for position 9 with proposal 2 I0703 02:50:10.534637 185163 leveldb.cpp:510] Reading position from leveldb took 134153ns I0703 02:50:10.534710 185150 replica.cpp:391] Replica received explicit promise request from __req_res__(968)@172.17.0.2:40107 for position 9 with proposal 2 I0703 02:50:10.534885 185150 leveldb.cpp:510] Reading position from leveldb took 119268ns I0703 02:50:10.534977 185160 replica.cpp:391] Replica received explicit promise request from __req_res__(969)@172.17.0.2:40107 for position 9 with proposal 2 I0703 02:50:10.615337 185160 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 80.318971ms I0703 02:50:10.615339 185150 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 80.406276ms I0703 02:50:10.615453 185160 replica.cpp:712] Persisted action NOP at position 9 I0703 02:50:10.615337 185163 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 80.65566ms I0703 02:50:10.615499 185150 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:10.615574 185163 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:10.616897 185151 replica.cpp:695] Replica received learned notice for position 9 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.616976 185167 replica.cpp:695] Replica received learned notice for position 9 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.617046 185158 replica.cpp:695] Replica received learned notice for position 9 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.698869 185158 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 81.755238ms I0703 02:50:10.698868 185151 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 81.926077ms I0703 02:50:10.698868 185167 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 81.852979ms I0703 02:50:10.698961 185158 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:10.699066 185167 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:10.699028 185151 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:10.701448 185153 replica.cpp:391] Replica received explicit promise request from __req_res__(970)@172.17.0.2:40107 for position 10 with proposal 2 I0703 02:50:10.701547 185155 replica.cpp:391] Replica received explicit promise request from __req_res__(971)@172.17.0.2:40107 for position 10 with proposal 2 I0703 02:50:10.701635 185153 leveldb.cpp:510] Reading position from leveldb took 127450ns I0703 02:50:10.701730 185155 leveldb.cpp:510] Reading position from leveldb took 127718ns I0703 02:50:10.701818 185165 replica.cpp:391] Replica received explicit promise request from __req_res__(972)@172.17.0.2:40107 for position 10 with proposal 2 I0703 02:50:10.790910 185165 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 89.036914ms I0703 02:50:10.790910 185155 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 89.119219ms I0703 02:50:10.790910 185153 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 89.232356ms I0703 02:50:10.791052 185155 replica.cpp:712] Persisted action APPEND at position 10 I0703 02:50:10.791002 185165 replica.cpp:712] Persisted action NOP at position 10 I0703 02:50:10.791097 185153 replica.cpp:712] Persisted action APPEND at position 10 I0703 02:50:10.792147 185157 replica.cpp:695] Replica received learned notice for position 10 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.792212 185166 replica.cpp:695] Replica received learned notice for position 10 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.792249 185164 replica.cpp:695] Replica received learned notice for position 10 from log-network(42)@172.17.0.2:40107 I0703 02:50:10.874516 185157 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 82.310777ms I0703 02:50:10.874521 185164 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 82.209867ms I0703 02:50:10.874610 185157 replica.cpp:712] Persisted action APPEND at position 10 I0703 02:50:10.874523 185166 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 82.248126ms I0703 02:50:10.874656 185164 replica.cpp:712] Persisted action APPEND at position 10 I0703 02:50:10.874724 185166 replica.cpp:712] Persisted action APPEND at position 10 I0703 02:50:10.875504 185164 catchup.cpp:357] Recover process terminated I0703 02:50:10.877334 185173 leveldb.cpp:510] Reading position from leveldb took 119954ns I0703 02:50:10.877578 185173 leveldb.cpp:510] Reading position from leveldb took 112337ns I0703 02:50:10.877785 185173 leveldb.cpp:510] Reading position from leveldb took 95238ns I0703 02:50:10.877939 185173 leveldb.cpp:510] Reading position from leveldb took 73768ns I0703 02:50:10.878082 185173 leveldb.cpp:510] Reading position from leveldb took 71862ns I0703 02:50:10.878221 185173 leveldb.cpp:510] Reading position from leveldb took 69952ns [ OK ] RecoverTest.CatchupVotingWithGap (9917 ms) [ RUN ] RecoverTest.CatchupVotingOnePosition I0703 02:50:11.093268 185149 leveldb.cpp:217] Opened db in 207.611508ms I0703 02:50:11.147642 185149 leveldb.cpp:224] Compacted db in 54.326608ms I0703 02:50:11.147764 185149 leveldb.cpp:239] Created db iterator in 56419ns I0703 02:50:11.147804 185149 leveldb.cpp:245] Seeked to beginning of db in 13243ns I0703 02:50:11.147832 185149 leveldb.cpp:320] Iterated through 0 keys in the db in 10823ns I0703 02:50:11.147917 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:11.185212 185168 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 36.727705ms I0703 02:50:11.185297 185168 replica.cpp:322] Persisted replica status to VOTING I0703 02:50:11.387212 185149 leveldb.cpp:217] Opened db in 201.038315ms I0703 02:50:11.447432 185149 leveldb.cpp:224] Compacted db in 60.174272ms I0703 02:50:11.447537 185149 leveldb.cpp:239] Created db iterator in 41355ns I0703 02:50:11.447576 185149 leveldb.cpp:245] Seeked to beginning of db in 12403ns I0703 02:50:11.447602 185149 leveldb.cpp:320] Iterated through 0 keys in the db in 9853ns I0703 02:50:11.447660 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:11.504086 185172 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 55.930288ms I0703 02:50:11.504202 185172 replica.cpp:322] Persisted replica status to VOTING I0703 02:50:11.705716 185149 leveldb.cpp:217] Opened db in 200.528724ms I0703 02:50:11.764199 185149 leveldb.cpp:224] Compacted db in 58.434537ms I0703 02:50:11.764303 185149 leveldb.cpp:239] Created db iterator in 40659ns I0703 02:50:11.764343 185149 leveldb.cpp:245] Seeked to beginning of db in 12319ns I0703 02:50:11.764369 185149 leveldb.cpp:320] Iterated through 0 keys in the db in 9853ns I0703 02:50:11.764426 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:11.805873 185150 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 40.959197ms I0703 02:50:11.805956 185150 replica.cpp:322] Persisted replica status to VOTING I0703 02:50:12.024691 185149 leveldb.cpp:217] Opened db in 217.887356ms I0703 02:50:12.214280 185149 leveldb.cpp:224] Compacted db in 189.532274ms I0703 02:50:12.214393 185149 leveldb.cpp:239] Created db iterator in 49429ns I0703 02:50:12.214463 185149 leveldb.cpp:245] Seeked to beginning of db in 43642ns I0703 02:50:12.214546 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 61722ns I0703 02:50:12.214617 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:12.472870 185149 leveldb.cpp:217] Opened db in 257.915696ms I0703 02:50:12.632309 185149 leveldb.cpp:224] Compacted db in 159.389754ms I0703 02:50:12.632421 185149 leveldb.cpp:239] Created db iterator in 48103ns I0703 02:50:12.632491 185149 leveldb.cpp:245] Seeked to beginning of db in 43249ns I0703 02:50:12.632568 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 54252ns I0703 02:50:12.632640 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:12.862799 185149 leveldb.cpp:217] Opened db in 229.8424ms I0703 02:50:13.030943 185149 leveldb.cpp:224] Compacted db in 168.098965ms I0703 02:50:13.031054 185149 leveldb.cpp:239] Created db iterator in 47873ns I0703 02:50:13.031124 185149 leveldb.cpp:245] Seeked to beginning of db in 43369ns I0703 02:50:13.031224 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 78829ns I0703 02:50:13.031301 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:13.032029 185173 catchup.cpp:342] Starting missing positions recovery I0703 02:50:13.032634 185173 catchup.cpp:368] Replica is in VOTING status I0703 02:50:13.034651 185170 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(973)@172.17.0.2:40107 I0703 02:50:13.034857 185165 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(974)@172.17.0.2:40107 I0703 02:50:13.035065 185158 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(975)@172.17.0.2:40107 I0703 02:50:13.036293 185153 recover.cpp:197] Received a recover response from a replica in VOTING status I0703 02:50:13.036912 185153 recover.cpp:197] Received a recover response from a replica in VOTING status I0703 02:50:13.038277 185150 catchup.cpp:357] Recover process terminated [ OK ] RecoverTest.CatchupVotingOnePosition (2159 ms) [----------] 9 tests from RecoverTest (54445 ms total) [----------] 4 tests from LogTest [ RUN ] LogTest.WriteRead I0703 02:50:13.264997 185149 leveldb.cpp:217] Opened db in 221.150888ms I0703 02:50:13.499089 185149 leveldb.cpp:224] Compacted db in 234.056233ms I0703 02:50:13.499241 185149 leveldb.cpp:239] Created db iterator in 84544ns I0703 02:50:13.499290 185149 leveldb.cpp:245] Seeked to beginning of db in 14276ns I0703 02:50:13.499318 185149 leveldb.cpp:320] Iterated through 0 keys in the db in 10850ns I0703 02:50:13.499401 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:13.548758 185154 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 48.719486ms I0703 02:50:13.548840 185154 replica.cpp:322] Persisted replica status to VOTING I0703 02:50:13.775431 185149 leveldb.cpp:217] Opened db in 225.63157ms I0703 02:50:13.840503 185149 leveldb.cpp:224] Compacted db in 65.026286ms I0703 02:50:13.840610 185149 leveldb.cpp:239] Created db iterator in 41930ns I0703 02:50:13.840648 185149 leveldb.cpp:245] Seeked to beginning of db in 12416ns I0703 02:50:13.840675 185149 leveldb.cpp:320] Iterated through 0 keys in the db in 9783ns I0703 02:50:13.840734 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:13.884016 185162 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 42.782961ms I0703 02:50:13.884101 185162 replica.cpp:322] Persisted replica status to VOTING I0703 02:50:14.077399 185149 leveldb.cpp:217] Opened db in 192.395864ms I0703 02:50:14.265720 185149 leveldb.cpp:224] Compacted db in 188.278369ms I0703 02:50:14.265837 185149 leveldb.cpp:239] Created db iterator in 50533ns I0703 02:50:14.265909 185149 leveldb.cpp:245] Seeked to beginning of db in 44972ns I0703 02:50:14.266000 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 70222ns I0703 02:50:14.266072 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:14.513263 185149 leveldb.cpp:217] Opened db in 246.820174ms I0703 02:50:14.732457 185149 leveldb.cpp:224] Compacted db in 219.148393ms I0703 02:50:14.732573 185149 leveldb.cpp:239] Created db iterator in 49692ns I0703 02:50:14.732642 185149 leveldb.cpp:245] Seeked to beginning of db in 43702ns I0703 02:50:14.732720 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 57029ns I0703 02:50:14.732795 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:14.734014 185158 recover.cpp:437] Starting replica recovery I0703 02:50:14.734573 185158 recover.cpp:468] Replica is in VOTING status I0703 02:50:14.734925 185158 recover.cpp:447] Recover process terminated I0703 02:50:14.735646 185162 log.cpp:554] Attempting to start the writer I0703 02:50:14.738240 185154 replica.cpp:497] Replica received implicit promise request from __req_res__(976)@172.17.0.2:40107 with proposal 1 I0703 02:50:14.738368 185152 replica.cpp:497] Replica received implicit promise request from __req_res__(977)@172.17.0.2:40107 with proposal 1 I0703 02:50:14.805742 185154 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 67.440707ms I0703 02:50:14.805826 185154 replica.cpp:344] Persisted promised to 1 I0703 02:50:14.839151 185152 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 100.719018ms I0703 02:50:14.839269 185152 replica.cpp:344] Persisted promised to 1 I0703 02:50:14.840396 185160 coordinator.cpp:238] Coordinator attempting to fill missing positions I0703 02:50:14.842625 185167 replica.cpp:391] Replica received explicit promise request from __req_res__(978)@172.17.0.2:40107 for position 0 with proposal 2 I0703 02:50:14.842762 185166 replica.cpp:391] Replica received explicit promise request from __req_res__(979)@172.17.0.2:40107 for position 0 with proposal 2 I0703 02:50:14.922717 185167 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 80.019479ms I0703 02:50:14.922724 185166 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 79.877831ms I0703 02:50:14.922809 185167 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:14.922852 185166 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:14.924486 185153 replica.cpp:541] Replica received write request for position 0 from __req_res__(980)@172.17.0.2:40107 I0703 02:50:14.924634 185153 leveldb.cpp:510] Reading position from leveldb took 77839ns I0703 02:50:14.924644 185163 replica.cpp:541] Replica received write request for position 0 from __req_res__(981)@172.17.0.2:40107 I0703 02:50:14.924801 185163 leveldb.cpp:510] Reading position from leveldb took 74172ns I0703 02:50:15.006227 185153 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 81.502607ms I0703 02:50:15.006227 185163 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 81.363571ms I0703 02:50:15.006319 185153 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:15.006362 185163 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:15.007140 185172 replica.cpp:695] Replica received learned notice for position 0 from log-network(44)@172.17.0.2:40107 I0703 02:50:15.007236 185167 replica.cpp:695] Replica received learned notice for position 0 from log-network(44)@172.17.0.2:40107 I0703 02:50:15.089733 185172 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 82.514633ms I0703 02:50:15.089740 185167 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 82.459791ms I0703 02:50:15.089824 185172 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:15.089870 185167 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:15.090952 185156 log.cpp:570] Writer started with ending position 0 I0703 02:50:15.091826 185173 log.cpp:578] Attempting to append 11 bytes to the log I0703 02:50:15.092104 185171 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 I0703 02:50:15.093297 185152 replica.cpp:541] Replica received write request for position 1 from __req_res__(982)@172.17.0.2:40107 I0703 02:50:15.093377 185155 replica.cpp:541] Replica received write request for position 1 from __req_res__(983)@172.17.0.2:40107 I0703 02:50:15.173265 185155 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 79.824826ms I0703 02:50:15.173266 185152 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 79.892655ms I0703 02:50:15.173358 185155 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:15.173403 185152 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:15.174362 185150 replica.cpp:695] Replica received learned notice for position 1 from log-network(44)@172.17.0.2:40107 I0703 02:50:15.174374 185159 replica.cpp:695] Replica received learned notice for position 1 from log-network(44)@172.17.0.2:40107 I0703 02:50:15.250538 185150 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 76.124807ms I0703 02:50:15.250538 185159 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 76.069424ms I0703 02:50:15.250633 185150 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:15.250694 185159 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:15.253235 185172 leveldb.cpp:510] Reading position from leveldb took 100854ns [ OK ] LogTest.WriteRead (2216 ms) [ RUN ] LogTest.Position I0703 02:50:15.525314 185149 leveldb.cpp:217] Opened db in 264.686732ms I0703 02:50:15.607156 185149 leveldb.cpp:224] Compacted db in 81.793521ms I0703 02:50:15.607306 185149 leveldb.cpp:239] Created db iterator in 52119ns I0703 02:50:15.607342 185149 leveldb.cpp:245] Seeked to beginning of db in 11568ns I0703 02:50:15.607367 185149 leveldb.cpp:320] Iterated through 0 keys in the db in 9383ns I0703 02:50:15.607436 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:15.675563 185152 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 67.559756ms I0703 02:50:15.675621 185152 replica.cpp:322] Persisted replica status to VOTING I0703 02:50:15.977447 185149 leveldb.cpp:217] Opened db in 301.22793ms I0703 02:50:16.057163 185149 leveldb.cpp:224] Compacted db in 79.667952ms I0703 02:50:16.057278 185149 leveldb.cpp:239] Created db iterator in 51252ns I0703 02:50:16.057319 185149 leveldb.cpp:245] Seeked to beginning of db in 13216ns I0703 02:50:16.057348 185149 leveldb.cpp:320] Iterated through 0 keys in the db in 10170ns I0703 02:50:16.057418 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:16.127847 185166 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 69.850204ms I0703 02:50:16.127929 185166 replica.cpp:322] Persisted replica status to VOTING I0703 02:50:16.404614 185149 leveldb.cpp:217] Opened db in 275.831027ms I0703 02:50:16.607426 185149 leveldb.cpp:224] Compacted db in 202.766395ms I0703 02:50:16.607540 185149 leveldb.cpp:239] Created db iterator in 50016ns I0703 02:50:16.607614 185149 leveldb.cpp:245] Seeked to beginning of db in 45142ns I0703 02:50:16.607708 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 72981ns I0703 02:50:16.607781 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:16.873486 185149 leveldb.cpp:217] Opened db in 265.331507ms I0703 02:50:17.065707 185149 leveldb.cpp:224] Compacted db in 192.173813ms I0703 02:50:17.065819 185149 leveldb.cpp:239] Created db iterator in 48552ns I0703 02:50:17.065891 185149 leveldb.cpp:245] Seeked to beginning of db in 43512ns I0703 02:50:17.065966 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 54302ns I0703 02:50:17.066038 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:17.067021 185163 recover.cpp:437] Starting replica recovery I0703 02:50:17.067670 185163 recover.cpp:468] Replica is in VOTING status I0703 02:50:17.068042 185163 recover.cpp:447] Recover process terminated I0703 02:50:17.068738 185172 log.cpp:554] Attempting to start the writer I0703 02:50:17.071455 185152 replica.cpp:497] Replica received implicit promise request from __req_res__(984)@172.17.0.2:40107 with proposal 1 I0703 02:50:17.071683 185160 replica.cpp:497] Replica received implicit promise request from __req_res__(985)@172.17.0.2:40107 with proposal 1 I0703 02:50:17.174247 185152 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 102.734907ms I0703 02:50:17.174247 185160 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 102.500019ms I0703 02:50:17.174336 185152 replica.cpp:344] Persisted promised to 1 I0703 02:50:17.174386 185160 replica.cpp:344] Persisted promised to 1 I0703 02:50:17.175516 185160 coordinator.cpp:238] Coordinator attempting to fill missing positions I0703 02:50:17.177743 185167 replica.cpp:391] Replica received explicit promise request from __req_res__(986)@172.17.0.2:40107 for position 0 with proposal 2 I0703 02:50:17.177927 185157 replica.cpp:391] Replica received explicit promise request from __req_res__(987)@172.17.0.2:40107 for position 0 with proposal 2 I0703 02:50:17.257738 185167 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 79.926296ms I0703 02:50:17.257740 185157 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 79.74092ms I0703 02:50:17.257833 185167 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:17.257876 185157 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:17.259522 185158 replica.cpp:541] Replica received write request for position 0 from __req_res__(988)@172.17.0.2:40107 I0703 02:50:17.259660 185158 leveldb.cpp:510] Reading position from leveldb took 78245ns I0703 02:50:17.259706 185151 replica.cpp:541] Replica received write request for position 0 from __req_res__(989)@172.17.0.2:40107 I0703 02:50:17.259847 185151 leveldb.cpp:510] Reading position from leveldb took 82735ns I0703 02:50:17.341256 185158 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 81.525282ms I0703 02:50:17.341259 185151 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 81.348689ms I0703 02:50:17.341349 185158 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:17.341393 185151 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:17.342291 185154 replica.cpp:695] Replica received learned notice for position 0 from log-network(45)@172.17.0.2:40107 I0703 02:50:17.342308 185161 replica.cpp:695] Replica received learned notice for position 0 from log-network(45)@172.17.0.2:40107 I0703 02:50:17.483320 185154 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 140.966384ms I0703 02:50:17.483320 185161 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 140.920374ms I0703 02:50:17.483435 185154 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:17.483470 185161 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:17.484439 185168 log.cpp:570] Writer started with ending position 0 I0703 02:50:17.485354 185162 log.cpp:578] Attempting to append 11 bytes to the log I0703 02:50:17.485601 185173 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 I0703 02:50:17.486802 185157 replica.cpp:541] Replica received write request for position 1 from __req_res__(990)@172.17.0.2:40107 I0703 02:50:17.487023 185161 replica.cpp:541] Replica received write request for position 1 from __req_res__(991)@172.17.0.2:40107 I0703 02:50:17.566969 185161 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 79.879035ms I0703 02:50:17.566974 185157 leveldb.cpp:390] Persisting action (27 bytes) to leveldb took 80.085856ms I0703 02:50:17.567061 185161 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:17.567107 185157 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:17.568063 185155 replica.cpp:695] Replica received learned notice for position 1 from log-network(45)@172.17.0.2:40107 I0703 02:50:17.568094 185172 replica.cpp:695] Replica received learned notice for position 1 from log-network(45)@172.17.0.2:40107 I0703 02:50:17.650450 185172 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 82.296325ms I0703 02:50:17.650451 185155 leveldb.cpp:390] Persisting action (29 bytes) to leveldb took 82.341088ms I0703 02:50:17.650560 185172 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:17.650593 185155 replica.cpp:712] Persisted action APPEND at position 1 [ OK ] LogTest.Position (2397 ms) [ RUN ] LogTest.Metrics I0703 02:50:17.935758 185149 leveldb.cpp:217] Opened db in 278.926458ms I0703 02:50:18.015425 185149 leveldb.cpp:224] Compacted db in 79.62031ms I0703 02:50:18.015539 185149 leveldb.cpp:239] Created db iterator in 54509ns I0703 02:50:18.015581 185149 leveldb.cpp:245] Seeked to beginning of db in 13746ns I0703 02:50:18.015609 185149 leveldb.cpp:320] Iterated through 0 keys in the db in 10696ns I0703 02:50:18.015677 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:18.069566 185173 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 53.319223ms I0703 02:50:18.069648 185173 replica.cpp:322] Persisted replica status to VOTING I0703 02:50:18.329640 185149 leveldb.cpp:217] Opened db in 259.12064ms I0703 02:50:18.517323 185149 leveldb.cpp:224] Compacted db in 187.636286ms I0703 02:50:18.517436 185149 leveldb.cpp:239] Created db iterator in 50402ns I0703 02:50:18.517508 185149 leveldb.cpp:245] Seeked to beginning of db in 46402ns I0703 02:50:18.517591 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 61166ns I0703 02:50:18.517663 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:18.518610 185167 recover.cpp:437] Starting replica recovery I0703 02:50:18.519152 185167 recover.cpp:468] Replica is in VOTING status I0703 02:50:18.519500 185167 recover.cpp:447] Recover process terminated I0703 02:50:18.520133 185159 log.cpp:554] Attempting to start the writer I0703 02:50:18.522365 185153 replica.cpp:497] Replica received implicit promise request from __req_res__(992)@172.17.0.2:40107 with proposal 1 I0703 02:50:18.580245 185153 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 57.825834ms I0703 02:50:18.580328 185153 replica.cpp:344] Persisted promised to 1 I0703 02:50:18.581415 185152 coordinator.cpp:238] Coordinator attempting to fill missing positions I0703 02:50:18.583550 185165 replica.cpp:391] Replica received explicit promise request from __req_res__(993)@172.17.0.2:40107 for position 0 with proposal 2 I0703 02:50:18.638748 185165 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 55.126793ms I0703 02:50:18.638834 185165 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:18.640415 185168 replica.cpp:541] Replica received write request for position 0 from __req_res__(994)@172.17.0.2:40107 I0703 02:50:18.640553 185168 leveldb.cpp:510] Reading position from leveldb took 76738ns I0703 02:50:18.863974 185168 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 223.35471ms I0703 02:50:18.864064 185168 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:18.865016 185163 replica.cpp:695] Replica received learned notice for position 0 from log-network(46)@172.17.0.2:40107 I0703 02:50:18.922479 185163 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 57.39677ms I0703 02:50:18.922565 185163 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:18.923494 185165 log.cpp:570] Writer started with ending position 0 I0703 02:50:18.929409 185169 process.cpp:3671] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' [ OK ] LogTest.Metrics (1285 ms) [ RUN ] LogTest.ReaderCatchup I0703 02:50:19.191241 185149 leveldb.cpp:217] Opened db in 249.174232ms I0703 02:50:19.257138 185149 leveldb.cpp:224] Compacted db in 65.841518ms I0703 02:50:19.257256 185149 leveldb.cpp:239] Created db iterator in 54256ns I0703 02:50:19.257298 185149 leveldb.cpp:245] Seeked to beginning of db in 13796ns I0703 02:50:19.257333 185149 leveldb.cpp:320] Iterated through 0 keys in the db in 14650ns I0703 02:50:19.257414 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:19.300027 185155 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 42.01656ms I0703 02:50:19.300112 185155 replica.cpp:322] Persisted replica status to VOTING I0703 02:50:19.485036 185149 leveldb.cpp:217] Opened db in 184.068043ms I0703 02:50:19.548782 185149 leveldb.cpp:224] Compacted db in 63.699509ms I0703 02:50:19.548887 185149 leveldb.cpp:239] Created db iterator in 41183ns I0703 02:50:19.548928 185149 leveldb.cpp:245] Seeked to beginning of db in 12676ns I0703 02:50:19.548956 185149 leveldb.cpp:320] Iterated through 0 keys in the db in 10273ns I0703 02:50:19.549015 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:19.601943 185161 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 52.425192ms I0703 02:50:19.602035 185161 replica.cpp:322] Persisted replica status to VOTING I0703 02:50:19.837152 185149 leveldb.cpp:217] Opened db in 234.195612ms I0703 02:50:19.898852 185149 leveldb.cpp:224] Compacted db in 61.653917ms I0703 02:50:19.898958 185149 leveldb.cpp:239] Created db iterator in 41623ns I0703 02:50:19.899001 185149 leveldb.cpp:245] Seeked to beginning of db in 12726ns I0703 02:50:19.899030 185149 leveldb.cpp:320] Iterated through 0 keys in the db in 10349ns I0703 02:50:19.899091 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:19.937315 185156 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 37.7483ms I0703 02:50:19.937398 185156 replica.cpp:322] Persisted replica status to VOTING I0703 02:50:20.139478 185149 leveldb.cpp:217] Opened db in 201.260468ms I0703 02:50:20.332441 185149 leveldb.cpp:224] Compacted db in 192.918256ms I0703 02:50:20.332573 185149 leveldb.cpp:239] Created db iterator in 57698ns I0703 02:50:20.332650 185149 leveldb.cpp:245] Seeked to beginning of db in 45782ns I0703 02:50:20.332744 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 72082ns I0703 02:50:20.332816 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:20.524953 185149 leveldb.cpp:217] Opened db in 191.806192ms I0703 02:50:20.699105 185149 leveldb.cpp:224] Compacted db in 174.106545ms I0703 02:50:20.699240 185149 leveldb.cpp:239] Created db iterator in 73935ns I0703 02:50:20.699321 185149 leveldb.cpp:245] Seeked to beginning of db in 43400ns I0703 02:50:20.699398 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 54432ns I0703 02:50:20.699469 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:20.702622 185156 replica.cpp:497] Replica received implicit promise request from __req_res__(995)@172.17.0.2:40107 with proposal 1 I0703 02:50:20.702756 185159 replica.cpp:497] Replica received implicit promise request from __req_res__(996)@172.17.0.2:40107 with proposal 1 I0703 02:50:20.775743 185159 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 72.922433ms I0703 02:50:20.775743 185156 leveldb.cpp:353] Persisting metadata (8 bytes) to leveldb took 73.065807ms I0703 02:50:20.775833 185159 replica.cpp:344] Persisted promised to 1 I0703 02:50:20.775884 185156 replica.cpp:344] Persisted promised to 1 I0703 02:50:20.776999 185164 coordinator.cpp:238] Coordinator attempting to fill missing positions I0703 02:50:20.779261 185151 replica.cpp:391] Replica received explicit promise request from __req_res__(997)@172.17.0.2:40107 for position 0 with proposal 2 I0703 02:50:20.779424 185167 replica.cpp:391] Replica received explicit promise request from __req_res__(998)@172.17.0.2:40107 for position 0 with proposal 2 I0703 02:50:20.842625 185167 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 63.124719ms I0703 02:50:20.842626 185151 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 63.293922ms I0703 02:50:20.842720 185167 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:20.842761 185151 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:20.844520 185150 replica.cpp:541] Replica received write request for position 0 from __req_res__(999)@172.17.0.2:40107 I0703 02:50:20.844619 185164 replica.cpp:541] Replica received write request for position 0 from __req_res__(1000)@172.17.0.2:40107 I0703 02:50:20.844691 185150 leveldb.cpp:510] Reading position from leveldb took 95691ns I0703 02:50:20.844748 185164 leveldb.cpp:510] Reading position from leveldb took 72285ns I0703 02:50:20.901134 185164 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 56.33056ms I0703 02:50:20.901134 185150 leveldb.cpp:390] Persisting action (14 bytes) to leveldb took 56.354553ms I0703 02:50:20.901227 185164 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:20.901271 185150 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:20.902122 185158 replica.cpp:695] Replica received learned notice for position 0 from log-network(47)@172.17.0.2:40107 I0703 02:50:20.902163 185159 replica.cpp:695] Replica received learned notice for position 0 from log-network(47)@172.17.0.2:40107 I0703 02:50:20.959650 185158 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 57.462229ms I0703 02:50:20.959652 185159 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 57.423277ms I0703 02:50:20.959743 185158 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:20.959806 185159 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:20.961413 185168 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 I0703 02:50:20.962524 185172 replica.cpp:541] Replica received write request for position 1 from __req_res__(1001)@172.17.0.2:40107 I0703 02:50:20.962719 185163 replica.cpp:541] Replica received write request for position 1 from __req_res__(1002)@172.17.0.2:40107 I0703 02:50:21.037550 185163 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 74.765216ms I0703 02:50:21.037556 185172 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 74.943382ms I0703 02:50:21.037642 185163 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:21.037691 185172 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:21.038579 185165 replica.cpp:695] Replica received learned notice for position 1 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.038578 185161 replica.cpp:695] Replica received learned notice for position 1 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.118471 185165 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 79.849498ms I0703 02:50:21.118476 185161 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 79.798747ms I0703 02:50:21.118564 185165 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:21.118640 185161 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:21.119894 185156 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 2 I0703 02:50:21.120992 185158 replica.cpp:541] Replica received write request for position 2 from __req_res__(1003)@172.17.0.2:40107 I0703 02:50:21.121140 185173 replica.cpp:541] Replica received write request for position 2 from __req_res__(1004)@172.17.0.2:40107 I0703 02:50:21.185338 185173 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 64.132832ms I0703 02:50:21.185427 185173 replica.cpp:712] Persisted action APPEND at position 2 I0703 02:50:21.185398 185158 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 64.342154ms I0703 02:50:21.185555 185158 replica.cpp:712] Persisted action APPEND at position 2 I0703 02:50:21.186699 185154 replica.cpp:695] Replica received learned notice for position 2 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.186733 185165 replica.cpp:695] Replica received learned notice for position 2 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.252135 185165 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.334689ms I0703 02:50:21.252144 185154 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.390116ms I0703 02:50:21.252197 185165 replica.cpp:712] Persisted action APPEND at position 2 I0703 02:50:21.252228 185154 replica.cpp:712] Persisted action APPEND at position 2 I0703 02:50:21.253033 185163 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3 I0703 02:50:21.253836 185166 replica.cpp:541] Replica received write request for position 3 from __req_res__(1005)@172.17.0.2:40107 I0703 02:50:21.253952 185157 replica.cpp:541] Replica received write request for position 3 from __req_res__(1006)@172.17.0.2:40107 I0703 02:50:21.319016 185166 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 65.125133ms I0703 02:50:21.319020 185157 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 65.018052ms I0703 02:50:21.319109 185166 replica.cpp:712] Persisted action APPEND at position 3 I0703 02:50:21.319152 185157 replica.cpp:712] Persisted action APPEND at position 3 I0703 02:50:21.320158 185162 replica.cpp:695] Replica received learned notice for position 3 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.320159 185156 replica.cpp:695] Replica received learned notice for position 3 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.394498 185156 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 74.238385ms I0703 02:50:21.394498 185162 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 74.280194ms I0703 02:50:21.394618 185156 replica.cpp:712] Persisted action APPEND at position 3 I0703 02:50:21.394649 185162 replica.cpp:712] Persisted action APPEND at position 3 I0703 02:50:21.395892 185152 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 4 I0703 02:50:21.397164 185166 replica.cpp:541] Replica received write request for position 4 from __req_res__(1007)@172.17.0.2:40107 I0703 02:50:21.397286 185154 replica.cpp:541] Replica received write request for position 4 from __req_res__(1008)@172.17.0.2:40107 I0703 02:50:21.461337 185166 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 64.114785ms I0703 02:50:21.461338 185154 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 63.969996ms I0703 02:50:21.461432 185166 replica.cpp:712] Persisted action APPEND at position 4 I0703 02:50:21.461475 185154 replica.cpp:712] Persisted action APPEND at position 4 I0703 02:50:21.462320 185170 replica.cpp:695] Replica received learned notice for position 4 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.462354 185164 replica.cpp:695] Replica received learned notice for position 4 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.553277 185170 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 90.90579ms I0703 02:50:21.553282 185164 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 90.88782ms I0703 02:50:21.553369 185170 replica.cpp:712] Persisted action APPEND at position 4 I0703 02:50:21.553412 185164 replica.cpp:712] Persisted action APPEND at position 4 I0703 02:50:21.554638 185152 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 5 I0703 02:50:21.555773 185165 replica.cpp:541] Replica received write request for position 5 from __req_res__(1009)@172.17.0.2:40107 I0703 02:50:21.555918 185171 replica.cpp:541] Replica received write request for position 5 from __req_res__(1010)@172.17.0.2:40107 I0703 02:50:21.620167 185171 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 64.160781ms I0703 02:50:21.620168 185165 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 64.334397ms I0703 02:50:21.620275 185171 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:21.620309 185165 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:21.621255 185162 replica.cpp:695] Replica received learned notice for position 5 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.621325 185163 replica.cpp:695] Replica received learned notice for position 5 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.687064 185163 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.698141ms I0703 02:50:21.687162 185163 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:21.687065 185162 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.769066ms I0703 02:50:21.687305 185162 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:21.688333 185157 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 6 I0703 02:50:21.689375 185167 replica.cpp:541] Replica received write request for position 6 from __req_res__(1011)@172.17.0.2:40107 I0703 02:50:21.689534 185165 replica.cpp:541] Replica received write request for position 6 from __req_res__(1012)@172.17.0.2:40107 I0703 02:50:21.754120 185165 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 64.520765ms I0703 02:50:21.754123 185167 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 64.683421ms I0703 02:50:21.754221 185165 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:21.754264 185167 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:21.755097 185164 replica.cpp:695] Replica received learned notice for position 6 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.755120 185163 replica.cpp:695] Replica received learned notice for position 6 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.820796 185164 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.657646ms I0703 02:50:21.820801 185163 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.607074ms I0703 02:50:21.820888 185164 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:21.820935 185163 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:21.822247 185157 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 7 I0703 02:50:21.823441 185154 replica.cpp:541] Replica received write request for position 7 from __req_res__(1013)@172.17.0.2:40107 I0703 02:50:21.823645 185162 replica.cpp:541] Replica received write request for position 7 from __req_res__(1014)@172.17.0.2:40107 I0703 02:50:21.887645 185154 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 64.140992ms I0703 02:50:21.887645 185162 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 63.923383ms I0703 02:50:21.887739 185154 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:21.887785 185162 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:21.888650 185169 replica.cpp:695] Replica received learned notice for position 7 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.888696 185155 replica.cpp:695] Replica received learned notice for position 7 from log-network(47)@172.17.0.2:40107 I0703 02:50:21.954497 185169 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.799823ms I0703 02:50:21.954502 185155 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.760837ms I0703 02:50:21.954593 185169 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:21.954638 185155 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:21.955847 185157 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 8 I0703 02:50:21.956997 185159 replica.cpp:541] Replica received write request for position 8 from __req_res__(1015)@172.17.0.2:40107 I0703 02:50:21.957206 185167 replica.cpp:541] Replica received write request for position 8 from __req_res__(1016)@172.17.0.2:40107 I0703 02:50:22.038149 185159 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 81.075475ms I0703 02:50:22.038154 185167 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 80.873055ms I0703 02:50:22.038257 185159 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:22.038293 185167 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:22.039247 185160 replica.cpp:695] Replica received learned notice for position 8 from log-network(47)@172.17.0.2:40107 I0703 02:50:22.039284 185168 replica.cpp:695] Replica received learned notice for position 8 from log-network(47)@172.17.0.2:40107 I0703 02:50:22.104955 185160 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.658929ms I0703 02:50:22.104988 185168 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.645533ms I0703 02:50:22.105042 185160 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:22.105093 185168 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:22.106408 185154 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 9 I0703 02:50:22.107554 185152 replica.cpp:541] Replica received write request for position 9 from __req_res__(1017)@172.17.0.2:40107 I0703 02:50:22.107741 185155 replica.cpp:541] Replica received write request for position 9 from __req_res__(1018)@172.17.0.2:40107 I0703 02:50:22.171814 185152 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 64.196455ms I0703 02:50:22.171814 185155 leveldb.cpp:390] Persisting action (17 bytes) to leveldb took 64.012405ms I0703 02:50:22.171909 185152 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:22.171953 185155 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:22.172796 185165 replica.cpp:695] Replica received learned notice for position 9 from log-network(47)@172.17.0.2:40107 I0703 02:50:22.172853 185157 replica.cpp:695] Replica received learned notice for position 9 from log-network(47)@172.17.0.2:40107 I0703 02:50:22.238709 185157 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.823679ms I0703 02:50:22.238710 185165 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 65.878184ms I0703 02:50:22.238847 185157 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:22.238878 185165 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:22.240306 185156 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 10 I0703 02:50:22.241611 185155 replica.cpp:541] Replica received write request for position 10 from __req_res__(1019)@172.17.0.2:40107 I0703 02:50:22.241746 185168 replica.cpp:541] Replica received write request for position 10 from __req_res__(1020)@172.17.0.2:40107 I0703 02:50:22.305519 185168 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 63.705822ms I0703 02:50:22.305534 185155 leveldb.cpp:390] Persisting action (18 bytes) to leveldb took 63.846779ms I0703 02:50:22.305625 185168 replica.cpp:712] Persisted action APPEND at position 10 I0703 02:50:22.305663 185155 replica.cpp:712] Persisted action APPEND at position 10 I0703 02:50:22.306901 185154 replica.cpp:695] Replica received learned notice for position 10 from log-network(47)@172.17.0.2:40107 I0703 02:50:22.306998 185162 replica.cpp:695] Replica received learned notice for position 10 from log-network(47)@172.17.0.2:40107 I0703 02:50:22.372406 185154 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 65.441328ms I0703 02:50:22.372406 185162 leveldb.cpp:390] Persisting action (20 bytes) to leveldb took 65.35145ms I0703 02:50:22.372499 185154 replica.cpp:712] Persisted action APPEND at position 10 I0703 02:50:22.372545 185162 replica.cpp:712] Persisted action APPEND at position 10 I0703 02:50:22.649497 185149 leveldb.cpp:217] Opened db in 275.662325ms I0703 02:50:22.821198 185149 leveldb.cpp:224] Compacted db in 171.654262ms I0703 02:50:22.821328 185149 leveldb.cpp:239] Created db iterator in 66108ns I0703 02:50:22.821401 185149 leveldb.cpp:245] Seeked to beginning of db in 46949ns I0703 02:50:22.821491 185149 leveldb.cpp:320] Iterated through 1 keys in the db in 69332ns I0703 02:50:22.821581 185149 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0703 02:50:22.822707 185152 recover.cpp:437] Starting replica recovery I0703 02:50:22.823385 185152 recover.cpp:468] Replica is in VOTING status I0703 02:50:22.823719 185152 recover.cpp:447] Recover process terminated I0703 02:50:22.824596 185166 catchup.cpp:342] Starting missing positions recovery I0703 02:50:22.825047 185162 catchup.cpp:368] Replica is in VOTING status I0703 02:50:22.826987 185171 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(1021)@172.17.0.2:40107 I0703 02:50:22.827128 185153 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(1022)@172.17.0.2:40107 I0703 02:50:22.827349 185158 replica.cpp:677] Replica in VOTING status received a broadcasted recover request from __req_res__(1023)@172.17.0.2:40107 I0703 02:50:22.828528 185153 recover.cpp:197] Received a recover response from a replica in VOTING status I0703 02:50:22.829173 185153 recover.cpp:197] Received a recover response from a replica in VOTING status I0703 02:50:22.830585 185162 catchup.cpp:423] Starting catch-up from position 0 to 9 I0703 02:50:22.832823 185160 replica.cpp:391] Replica received explicit promise request from __req_res__(1024)@172.17.0.2:40107 for position 0 with proposal 0 I0703 02:50:22.832928 185164 replica.cpp:391] Replica received explicit promise request from __req_res__(1025)@172.17.0.2:40107 for position 0 with proposal 0 I0703 02:50:22.832983 185160 leveldb.cpp:510] Reading position from leveldb took 105088ns I0703 02:50:22.833066 185164 leveldb.cpp:510] Reading position from leveldb took 81738ns I0703 02:50:22.833223 185152 replica.cpp:391] Replica received explicit promise request from __req_res__(1026)@172.17.0.2:40107 for position 0 with proposal 0 I0703 02:50:23.028769 185158 replica.cpp:391] Replica received explicit promise request from __req_res__(1027)@172.17.0.2:40107 for position 0 with proposal 3 I0703 02:50:23.028877 185161 replica.cpp:391] Replica received explicit promise request from __req_res__(1028)@172.17.0.2:40107 for position 0 with proposal 3 I0703 02:50:23.028955 185158 leveldb.cpp:510] Reading position from leveldb took 103028ns I0703 02:50:23.029016 185161 leveldb.cpp:510] Reading position from leveldb took 81685ns I0703 02:50:23.029203 185168 replica.cpp:391] Replica received explicit promise request from __req_res__(1029)@172.17.0.2:40107 for position 0 with proposal 3 I0703 02:50:23.125658 185168 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 96.36769ms I0703 02:50:23.125661 185158 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 96.616361ms I0703 02:50:23.125748 185168 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:23.125666 185161 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 96.592628ms I0703 02:50:23.125799 185158 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:23.125842 185161 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:23.126621 185163 replica.cpp:695] Replica received learned notice for position 0 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.126694 185159 replica.cpp:695] Replica received learned notice for position 0 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.126699 185153 replica.cpp:695] Replica received learned notice for position 0 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.209188 185153 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 82.40986ms I0703 02:50:23.209189 185163 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 82.540719ms I0703 02:50:23.209282 185153 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:23.209189 185159 leveldb.cpp:390] Persisting action (16 bytes) to leveldb took 82.477604ms I0703 02:50:23.209327 185163 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:23.209389 185159 replica.cpp:712] Persisted action NOP at position 0 I0703 02:50:23.211385 185161 replica.cpp:391] Replica received explicit promise request from __req_res__(1030)@172.17.0.2:40107 for position 1 with proposal 3 I0703 02:50:23.211535 185161 leveldb.cpp:510] Reading position from leveldb took 91615ns I0703 02:50:23.211639 185162 replica.cpp:391] Replica received explicit promise request from __req_res__(1031)@172.17.0.2:40107 for position 1 with proposal 3 I0703 02:50:23.211788 185162 leveldb.cpp:510] Reading position from leveldb took 88184ns I0703 02:50:23.211827 185158 replica.cpp:391] Replica received explicit promise request from __req_res__(1032)@172.17.0.2:40107 for position 1 with proposal 3 I0703 02:50:23.292735 185158 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 80.855383ms I0703 02:50:23.292744 185162 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 80.894456ms I0703 02:50:23.292745 185161 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 81.151383ms I0703 02:50:23.292883 185162 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:23.292825 185158 replica.cpp:712] Persisted action NOP at position 1 I0703 02:50:23.292932 185161 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:23.293695 185173 replica.cpp:695] Replica received learned notice for position 1 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.293789 185168 replica.cpp:695] Replica received learned notice for position 1 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.293810 185163 replica.cpp:695] Replica received learned notice for position 1 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.376273 185168 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.425215ms I0703 02:50:23.376287 185173 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.534646ms I0703 02:50:23.376371 185168 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:23.376287 185163 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.397393ms I0703 02:50:23.376430 185173 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:23.376459 185163 replica.cpp:712] Persisted action APPEND at position 1 I0703 02:50:23.378528 185153 replica.cpp:391] Replica received explicit promise request from __req_res__(1033)@172.17.0.2:40107 for position 2 with proposal 3 I0703 02:50:23.378649 185151 replica.cpp:391] Replica received explicit promise request from __req_res__(1034)@172.17.0.2:40107 for position 2 with proposal 3 I0703 02:50:23.378721 185153 leveldb.cpp:510] Reading position from leveldb took 115917ns I0703 02:50:23.378775 185164 replica.cpp:391] Replica received explicit promise request from __req_res__(1035)@172.17.0.2:40107 for position 2 with proposal 3 I0703 02:50:23.378862 185151 leveldb.cpp:510] Reading position from leveldb took 136834ns I0703 02:50:23.468205 185164 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 89.360767ms I0703 02:50:23.468209 185153 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 89.403353ms I0703 02:50:23.468297 185164 replica.cpp:712] Persisted action NOP at position 2 I0703 02:50:23.468209 185151 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 89.262592ms I0703 02:50:23.468348 185153 replica.cpp:712] Persisted action APPEND at position 2 I0703 02:50:23.468397 185151 replica.cpp:712] Persisted action APPEND at position 2 I0703 02:50:23.469190 185166 replica.cpp:695] Replica received learned notice for position 2 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.469252 185158 replica.cpp:695] Replica received learned notice for position 2 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.469213 185170 replica.cpp:695] Replica received learned notice for position 2 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.560114 185158 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 90.812544ms I0703 02:50:23.560122 185166 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 90.864383ms I0703 02:50:23.560124 185170 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 90.767125ms I0703 02:50:23.560207 185158 replica.cpp:712] Persisted action APPEND at position 2 I0703 02:50:23.560310 185170 replica.cpp:712] Persisted action APPEND at position 2 I0703 02:50:23.560271 185166 replica.cpp:712] Persisted action APPEND at position 2 I0703 02:50:23.562242 185172 replica.cpp:391] Replica received explicit promise request from __req_res__(1036)@172.17.0.2:40107 for position 3 with proposal 3 I0703 02:50:23.562391 185172 leveldb.cpp:510] Reading position from leveldb took 90078ns I0703 02:50:23.562381 185163 replica.cpp:391] Replica received explicit promise request from __req_res__(1037)@172.17.0.2:40107 for position 3 with proposal 3 I0703 02:50:23.562568 185163 leveldb.cpp:510] Reading position from leveldb took 91778ns I0703 02:50:23.562613 185159 replica.cpp:391] Replica received explicit promise request from __req_res__(1038)@172.17.0.2:40107 for position 3 with proposal 3 I0703 02:50:23.626958 185163 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 64.299992ms I0703 02:50:23.626951 185159 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 64.28048ms I0703 02:50:23.626951 185172 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 64.500978ms I0703 02:50:23.627050 185163 replica.cpp:712] Persisted action APPEND at position 3 I0703 02:50:23.627121 185159 replica.cpp:712] Persisted action NOP at position 3 I0703 02:50:23.627245 185172 replica.cpp:712] Persisted action APPEND at position 3 I0703 02:50:23.628072 185170 replica.cpp:695] Replica received learned notice for position 3 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.628108 185154 replica.cpp:695] Replica received learned notice for position 3 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.628103 185165 replica.cpp:695] Replica received learned notice for position 3 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.727170 185154 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 99.016872ms I0703 02:50:23.727169 185165 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 98.958797ms I0703 02:50:23.727288 185154 replica.cpp:712] Persisted action APPEND at position 3 I0703 02:50:23.727216 185170 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 99.073867ms I0703 02:50:23.727335 185165 replica.cpp:712] Persisted action APPEND at position 3 I0703 02:50:23.727380 185170 replica.cpp:712] Persisted action APPEND at position 3 I0703 02:50:23.729141 185171 replica.cpp:391] Replica received explicit promise request from __req_res__(1039)@172.17.0.2:40107 for position 4 with proposal 3 I0703 02:50:23.729291 185171 leveldb.cpp:510] Reading position from leveldb took 88368ns I0703 02:50:23.729327 185155 replica.cpp:391] Replica received explicit promise request from __req_res__(1040)@172.17.0.2:40107 for position 4 with proposal 3 I0703 02:50:23.729436 185160 replica.cpp:391] Replica received explicit promise request from __req_res__(1041)@172.17.0.2:40107 for position 4 with proposal 3 I0703 02:50:23.729526 185155 leveldb.cpp:510] Reading position from leveldb took 129334ns I0703 02:50:23.819233 185155 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 89.601049ms I0703 02:50:23.819260 185160 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 89.763951ms I0703 02:50:23.819311 185155 replica.cpp:712] Persisted action APPEND at position 4 I0703 02:50:23.819264 185171 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 89.906492ms I0703 02:50:23.819347 185160 replica.cpp:712] Persisted action NOP at position 4 I0703 02:50:23.819415 185171 replica.cpp:712] Persisted action APPEND at position 4 I0703 02:50:23.820310 185150 replica.cpp:695] Replica received learned notice for position 4 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.820317 185170 replica.cpp:695] Replica received learned notice for position 4 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.820371 185154 replica.cpp:695] Replica received learned notice for position 4 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.902850 185154 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.37973ms I0703 02:50:23.902884 185150 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.52557ms I0703 02:50:23.902937 185154 replica.cpp:712] Persisted action APPEND at position 4 I0703 02:50:23.902882 185170 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.464635ms I0703 02:50:23.902976 185150 replica.cpp:712] Persisted action APPEND at position 4 I0703 02:50:23.903041 185170 replica.cpp:712] Persisted action APPEND at position 4 I0703 02:50:23.905140 185168 replica.cpp:391] Replica received explicit promise request from __req_res__(1042)@172.17.0.2:40107 for position 5 with proposal 3 I0703 02:50:23.905293 185168 leveldb.cpp:510] Reading position from leveldb took 90948ns I0703 02:50:23.905270 185156 replica.cpp:391] Replica received explicit promise request from __req_res__(1043)@172.17.0.2:40107 for position 5 with proposal 3 I0703 02:50:23.905489 185156 leveldb.cpp:510] Reading position from leveldb took 105648ns I0703 02:50:23.905516 185163 replica.cpp:391] Replica received explicit promise request from __req_res__(1044)@172.17.0.2:40107 for position 5 with proposal 3 I0703 02:50:23.986395 185168 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 81.036023ms I0703 02:50:23.986418 185163 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 80.85304ms I0703 02:50:23.986495 185168 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:23.986426 185156 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 80.84795ms I0703 02:50:23.986541 185163 replica.cpp:712] Persisted action NOP at position 5 I0703 02:50:23.986608 185156 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:23.987423 185169 replica.cpp:695] Replica received learned notice for position 5 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.987455 185162 replica.cpp:695] Replica received learned notice for position 5 from log-network(48)@172.17.0.2:40107 I0703 02:50:23.987488 185151 replica.cpp:695] Replica received learned notice for position 5 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.253199 185151 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 265.627564ms I0703 02:50:24.253206 185169 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 265.726338ms I0703 02:50:24.253206 185162 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 265.687549ms I0703 02:50:24.253350 185169 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:24.253295 185151 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:24.253402 185162 replica.cpp:712] Persisted action APPEND at position 5 I0703 02:50:24.255336 185157 replica.cpp:391] Replica received explicit promise request from __req_res__(1045)@172.17.0.2:40107 for position 6 with proposal 3 I0703 02:50:24.255434 185150 replica.cpp:391] Replica received explicit promise request from __req_res__(1046)@172.17.0.2:40107 for position 6 with proposal 3 I0703 02:50:24.255522 185157 leveldb.cpp:510] Reading position from leveldb took 99814ns I0703 02:50:24.255587 185150 leveldb.cpp:510] Reading position from leveldb took 92085ns I0703 02:50:24.255689 185160 replica.cpp:391] Replica received explicit promise request from __req_res__(1047)@172.17.0.2:40107 for position 6 with proposal 3 I0703 02:50:24.345152 185150 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 89.496658ms I0703 02:50:24.345157 185160 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 89.40928ms I0703 02:50:24.345247 185150 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:24.345160 185157 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 89.565433ms I0703 02:50:24.345295 185160 replica.cpp:712] Persisted action NOP at position 6 I0703 02:50:24.345351 185157 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:24.346107 185152 replica.cpp:695] Replica received learned notice for position 6 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.346155 185151 replica.cpp:695] Replica received learned notice for position 6 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.346189 185168 replica.cpp:695] Replica received learned notice for position 6 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.428714 185151 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.516557ms I0703 02:50:24.428716 185152 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.561255ms I0703 02:50:24.428730 185168 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.495897ms I0703 02:50:24.428867 185152 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:24.428910 185168 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:24.428807 185151 replica.cpp:712] Persisted action APPEND at position 6 I0703 02:50:24.430989 185162 replica.cpp:391] Replica received explicit promise request from __req_res__(1048)@172.17.0.2:40107 for position 7 with proposal 3 I0703 02:50:24.431156 185156 replica.cpp:391] Replica received explicit promise request from __req_res__(1049)@172.17.0.2:40107 for position 7 with proposal 3 I0703 02:50:24.431169 185162 leveldb.cpp:510] Reading position from leveldb took 126414ns I0703 02:50:24.431320 185163 replica.cpp:391] Replica received explicit promise request from __req_res__(1050)@172.17.0.2:40107 for position 7 with proposal 3 I0703 02:50:24.431339 185156 leveldb.cpp:510] Reading position from leveldb took 92195ns I0703 02:50:24.512275 185162 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 80.96155ms I0703 02:50:24.512279 185163 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 80.898072ms I0703 02:50:24.512369 185162 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:24.512279 185156 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 80.8353ms I0703 02:50:24.512416 185163 replica.cpp:712] Persisted action NOP at position 7 I0703 02:50:24.512472 185156 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:24.513262 185172 replica.cpp:695] Replica received learned notice for position 7 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.513305 185151 replica.cpp:695] Replica received learned notice for position 7 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.513360 185157 replica.cpp:695] Replica received learned notice for position 7 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.595775 185157 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.367293ms I0703 02:50:24.595775 185172 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.468898ms I0703 02:50:24.595870 185157 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:24.595782 185151 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.435242ms I0703 02:50:24.595921 185172 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:24.595968 185151 replica.cpp:712] Persisted action APPEND at position 7 I0703 02:50:24.597831 185152 replica.cpp:391] Replica received explicit promise request from __req_res__(1051)@172.17.0.2:40107 for position 8 with proposal 3 I0703 02:50:24.597990 185152 leveldb.cpp:510] Reading position from leveldb took 100731ns I0703 02:50:24.598021 185165 replica.cpp:391] Replica received explicit promise request from __req_res__(1052)@172.17.0.2:40107 for position 8 with proposal 3 I0703 02:50:24.598165 185165 leveldb.cpp:510] Reading position from leveldb took 87224ns I0703 02:50:24.598274 185173 replica.cpp:391] Replica received explicit promise request from __req_res__(1053)@172.17.0.2:40107 for position 8 with proposal 3 I0703 02:50:24.674088 185165 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 75.857636ms I0703 02:50:24.674104 185152 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 76.033759ms I0703 02:50:24.674104 185173 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 75.770931ms I0703 02:50:24.674181 185165 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:24.674325 185173 replica.cpp:712] Persisted action NOP at position 8 I0703 02:50:24.674257 185152 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:24.675297 185162 replica.cpp:695] Replica received learned notice for position 8 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.675345 185156 replica.cpp:695] Replica received learned notice for position 8 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.675323 185166 replica.cpp:695] Replica received learned notice for position 8 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.787904 185166 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 112.475528ms I0703 02:50:24.787905 185162 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 112.546507ms I0703 02:50:24.787911 185156 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 112.517594ms I0703 02:50:24.788053 185162 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:24.788012 185166 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:24.788103 185156 replica.cpp:712] Persisted action APPEND at position 8 I0703 02:50:24.790292 185158 replica.cpp:391] Replica received explicit promise request from __req_res__(1054)@172.17.0.2:40107 for position 9 with proposal 3 I0703 02:50:24.790411 185172 replica.cpp:391] Replica received explicit promise request from __req_res__(1055)@172.17.0.2:40107 for position 9 with proposal 3 I0703 02:50:24.790441 185158 leveldb.cpp:510] Reading position from leveldb took 88542ns I0703 02:50:24.790577 185165 replica.cpp:391] Replica received explicit promise request from __req_res__(1056)@172.17.0.2:40107 for position 9 with proposal 3 I0703 02:50:24.790599 185172 leveldb.cpp:510] Reading position from leveldb took 101991ns I0703 02:50:24.871435 185165 leveldb.cpp:390] Persisting action (8 bytes) to leveldb took 80.800524ms I0703 02:50:24.871438 185158 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 80.867173ms I0703 02:50:24.871436 185172 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 80.72055ms I0703 02:50:24.871528 185165 replica.cpp:712] Persisted action NOP at position 9 I0703 02:50:24.871582 185158 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:24.871644 185172 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:24.872457 185168 replica.cpp:695] Replica received learned notice for position 9 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.872515 185159 replica.cpp:695] Replica received learned notice for position 9 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.872457 185169 replica.cpp:695] Replica received learned notice for position 9 from log-network(48)@172.17.0.2:40107 I0703 02:50:24.954984 185168 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.464311ms I0703 02:50:24.954998 185159 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.440905ms I0703 02:50:24.955090 185168 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:24.954998 185169 leveldb.cpp:390] Persisting action (19 bytes) to leveldb took 82.397796ms I0703 02:50:24.955140 185159 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:24.955250 185169 replica.cpp:712] Persisted action APPEND at position 9 I0703 02:50:24.956286 185170 catchup.cpp:357] Recover process terminated I0703 02:50:24.959213 185168 leveldb.cpp:510] Reading position from leveldb took 113835ns I0703 02:50:24.959427 185168 leveldb.cpp:510] Reading position from leveldb took 97765ns I0703 02:50:24.959621 185168 leveldb.cpp:510] Reading position from leveldb took 86362ns I0703 02:50:24.959813 185168 leveldb.cpp:510] Reading position from leveldb took 84875ns I0703 02:50:24.960002 185168 leveldb.cpp:510] Reading position from leveldb took 84271ns I0703 02:50:24.960202 185168 leveldb.cpp:510] Reading position from leveldb took 94225ns I0703 02:50:24.960393 185168 leveldb.cpp:510] Reading position from leveldb took 85282ns I0703 02:50:24.960585 185168 leveldb.cpp:510] Reading position from leveldb took 84075ns I0703 02:50:24.960770 185168 leveldb.cpp:510] Reading position from leveldb took 82138ns I0703 02:50:24.960955 185168 leveldb.cpp:510] Reading position from leveldb took 81028ns [ OK ] LogTest.ReaderCatchup (6027 ms) [----------] 4 tests from LogTest (11925 ms total) [----------] 2 tests from LogZooKeeperTest I0703 02:50:24.968773 185149 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/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:/tmp/SRC/build/mesos-1.12.0/_build/sub/3rdparty/zookeeper-3.4.8/lib/slf4j-api-1.6.1.jar [ RUN ] LogZooKeeperTest.WriteRead I0703 02:50:25.058761 185149 jvm.cpp:590] Looking up method <init>(Ljava/lang/String;)V I0703 02:50:25.059170 185149 jvm.cpp:590] Looking up method deleteOnExit()V I0703 02:50:25.060112 185149 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. I0703 02:50:25.206512 185149 jvm.cpp:590] Looking up method <init>()V I0703 02:50:25.207417 185149 jvm.cpp:590] Looking up method <init>(Lorg/apache/zookeeper/server/persistence/FileTxnSnapLog;Lorg/apache/zookeeper/server/ZooKeeperServer$DataTreeBuilder;)V *** Aborted at 1719975025 (unix time) try "date -d @1719975025" if you are using GNU date *** PC: @ 0x7f5edf914ccd OopStorage::Block::release_entries() *** SIGSEGV (@0x238) received by PID 185149 (TID 0x7f5f5a15cb40) from PID 568; stack trace: *** @ 0x7f5edf923929 os::Linux::chained_handler() @ 0x7f5edf92963b JVM_handle_linux_signal @ 0x7f5edf91c1dc signalHandler() @ 0x7f5f5b7af420 (unknown) @ 0x7f5edf914ccd OopStorage::Block::release_entries() @ 0x7f5edf914f26 OopStorage::release() @ 0x7f5edf617b21 jni_DeleteGlobalRef @ 0x7f5f6aeffaf2 JNIEnv_::DeleteGlobalRef() @ 0x7f5f6aefdc3a Jvm::deleteGlobalRef() @ 0x55f0ed05a2ea Jvm::Object::~Object() @ 0x55f0ed05f110 org::apache::zookeeper::server::ZooKeeperServer::DataTreeBuilder::~DataTreeBuilder() @ 0x55f0ed061a14 org::apache::zookeeper::server::ZooKeeperServer::BasicDataTreeBuilder::~BasicDataTreeBuilder() @ 0x55f0ed05da2f mesos::internal::tests::ZooKeeperTestServer::ZooKeeperTestServer() @ 0x55f0eba05ef6 mesos::internal::tests::ZooKeeperTest::ZooKeeperTest() @ 0x55f0eba0823f mesos::internal::tests::LogZooKeeperTest::LogZooKeeperTest() @ 0x55f0eba08350 mesos::internal::tests::LogZooKeeperTest_WriteRead_Test::LogZooKeeperTest_WriteRead_Test() @ 0x55f0eba73252 testing::internal::TestFactoryImpl<>::CreateTest() @ 0x55f0ed0a42bc testing::internal::HandleSehExceptionsInMethodIfSupported<>() @ 0x55f0ed09d88d testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x55f0ed079ac5 testing::TestInfo::Run() @ 0x55f0ed07a1cd testing::TestCase::Run() @ 0x55f0ed081567 testing::internal::UnitTestImpl::RunAllTests() @ 0x55f0ed0a54ea testing::internal::HandleSehExceptionsInMethodIfSupported<>() @ 0x55f0ed09e3f3 testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x55f0ed08007f testing::UnitTest::Run() @ 0x55f0eba90e05 RUN_ALL_TESTS() @ 0x55f0eba907cc main @ 0x7f5f5b5cd083 __libc_start_main @ 0x55f0eaad675e _start make[4]: *** [Makefile:17971: check-local] Segmentation fault (core dumped) make[4]: Leaving directory '/tmp/SRC/build/mesos-1.12.0/_build/sub/src' make[3]: *** [Makefile:15906: check-am] Error 2 make[3]: Leaving directory '/tmp/SRC/build/mesos-1.12.0/_build/sub/src' make[2]: *** [Makefile:15909: check] Error 2 make[2]: Leaving directory '/tmp/SRC/build/mesos-1.12.0/_build/sub/src' I0703 02:50:27.778990 186171 exec.cpp:560] Agent exited ... shutting down I0703 02:50:27.779693 186177 executor.cpp:190] Received SHUTDOWN event I0703 02:50:27.779769 186177 executor.cpp:843] Shutting down I0703 02:50:27.779855 186177 executor.cpp:956] Sending SIGTERM to process tree at pid 186196 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 ';' I0703 02:50:27.795308 186177 executor.cpp:969] Sent SIGTERM to the following process trees: [ -+- 186196 sh -c dd if=/dev/zero of=volume_path/file bs=1048576 count=2 && sleep 1000 \--- 186206 sleep 1000 ] I0703 02:50:27.795356 186177 executor.cpp:973] Scheduling escalation to SIGKILL in 3secs from now I0703 02:50:27.888394 186173 executor.cpp:1041] Command terminated with signal Terminated (pid: 186196) W0703 02:50:27.891803 186193 process.cpp:1917] Failed to send 'mesos.internal.StatusUpdateMessage' to '172.17.0.2:40107', connect: Failed to connect to 172.17.0.2:40107: Connection refused I0703 02:50:28.893406 186193 process.cpp:935] Stopped the socket accept loop 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/33270/console - Mesos Reviewbot On July 2, 2024, 11:39 p.m., Jason Zhou wrote: > > ----------------------------------------------------------- > This is an automatically generated e-mail. To reply, visit: > https://reviews.apache.org/r/75075/ > ----------------------------------------------------------- > > (Updated July 2, 2024, 11:39 p.m.) > > > Review request for mesos and Benjamin Mahler. > > > Repository: mesos > > > Description > ------- > > Currently the SSLProtocolTest testing with TLS v 1.0 and 1.1 do not pass > because those versions were disabled in ubuntu 20.04 > See: > https://discourse.ubuntu.com/t/spec-tls-1-0-and-1-1-are-disabled-by-default/41868 > See: > https://github.com/SoftEtherVPN/SoftEtherVPN/issues/1358#issuecomment-851427905 > > > Diffs > ----- > > 3rdparty/libprocess/src/tests/ssl_tests.cpp > c90d1da626fabd97cb77002a09a045c0f5356efb > > > Diff: https://reviews.apache.org/r/75075/diff/1/ > > > Testing > ------- > > > Thanks, > > Jason Zhou > >
