See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4581/display/redirect>
------------------------------------------ [...truncated 19.86 MB...] 3: I1212 03:14:20.698006 20123 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 5 3: I1212 03:14:20.698901 20107 replica.cpp:540] Replica received write request for position 5 from __req_res__(1150)@172.17.0.2:42245 3: I1212 03:14:20.698964 20125 replica.cpp:540] Replica received write request for position 5 from __req_res__(1151)@172.17.0.2:42245 3: I1212 03:14:20.700101 20125 leveldb.cpp:341] Persisting action (201 bytes) to leveldb took 1.086107ms 3: I1212 03:14:20.700105 20107 leveldb.cpp:341] Persisting action (201 bytes) to leveldb took 1.151957ms 3: I1212 03:14:20.700157 20125 replica.cpp:711] Persisted action APPEND at position 5 3: I1212 03:14:20.700166 20107 replica.cpp:711] Persisted action APPEND at position 5 3: I1212 03:14:20.700793 20128 replica.cpp:694] Replica received learned notice for position 5 from log-network(70)@172.17.0.2:42245 3: I1212 03:14:20.700840 20126 replica.cpp:694] Replica received learned notice for position 5 from log-network(70)@172.17.0.2:42245 3: I1212 03:14:20.702502 20128 leveldb.cpp:341] Persisting action (203 bytes) to leveldb took 1.662106ms 3: I1212 03:14:20.702543 20126 leveldb.cpp:341] Persisting action (203 bytes) to leveldb took 1.656316ms 3: I1212 03:14:20.702555 20128 replica.cpp:711] Persisted action APPEND at position 5 3: I1212 03:14:20.702579 20126 replica.cpp:711] Persisted action APPEND at position 5 3: I1212 03:14:20.703842 20115 registrar.cpp:552] Successfully updated the registry in 11.773952ms 3: I1212 03:14:20.704147 20114 log.cpp:579] Attempting to truncate the log to 5 3: I1212 03:14:20.704351 20109 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 6 3: I1212 03:14:20.705353 20111 replica.cpp:540] Replica received write request for position 6 from __req_res__(1152)@172.17.0.2:42245 3: I1212 03:14:20.705410 20115 replica.cpp:540] Replica received write request for position 6 from __req_res__(1153)@172.17.0.2:42245 3: I1212 03:14:20.706578 20111 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.161004ms 3: I1212 03:14:20.706634 20111 replica.cpp:711] Persisted action TRUNCATE at position 6 3: I1212 03:14:20.706642 20115 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.18517ms 3: I1212 03:14:20.706691 20115 replica.cpp:711] Persisted action TRUNCATE at position 6 3: [ OK ] RegistrarTest.Recover (108 ms) 3: [ RUN ] RegistrarTest.Admit 3: I1212 03:14:20.715862 20106 leveldb.cpp:174] Opened db in 5.431739ms 3: I1212 03:14:20.717393 20106 leveldb.cpp:181] Compacted db in 1.501022ms 3: I1212 03:14:20.717427 20106 leveldb.cpp:196] Created db iterator in 6560ns 3: I1212 03:14:20.717438 20106 leveldb.cpp:202] Seeked to beginning of db in 1380ns 3: I1212 03:14:20.717447 20106 leveldb.cpp:271] Iterated through 0 keys in the db in 769ns 3: I1212 03:14:20.717481 20106 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned 3: I1212 03:14:20.720028 20121 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.758423ms 3: I1212 03:14:20.720068 20121 replica.cpp:322] Persisted replica status to VOTING 3: I1212 03:14:20.726207 20106 leveldb.cpp:174] Opened db in 5.551115ms 3: I1212 03:14:20.727816 20106 leveldb.cpp:181] Compacted db in 1.580479ms 3: I1212 03:14:20.727846 20106 leveldb.cpp:196] Created db iterator in 4320ns 3: I1212 03:14:20.727856 20106 leveldb.cpp:202] Seeked to beginning of db in 638ns 3: I1212 03:14:20.727864 20106 leveldb.cpp:271] Iterated through 0 keys in the db in 276ns 3: I1212 03:14:20.727891 20106 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned 3: I1212 03:14:20.729348 20128 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.174285ms 3: I1212 03:14:20.729390 20128 replica.cpp:322] Persisted replica status to VOTING 3: I1212 03:14:20.734954 20106 leveldb.cpp:174] Opened db in 5.116361ms 3: I1212 03:14:20.739270 20106 leveldb.cpp:181] Compacted db in 4.287802ms 3: I1212 03:14:20.739317 20106 leveldb.cpp:196] Created db iterator in 7355ns 3: I1212 03:14:20.739337 20106 leveldb.cpp:202] Seeked to beginning of db in 10031ns 3: I1212 03:14:20.739383 20106 leveldb.cpp:271] Iterated through 1 keys in the db in 36312ns 3: I1212 03:14:20.739411 20106 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned 3: I1212 03:14:20.745800 20106 leveldb.cpp:174] Opened db in 6.210214ms 3: I1212 03:14:20.751132 20106 leveldb.cpp:181] Compacted db in 5.289271ms 3: I1212 03:14:20.751195 20106 leveldb.cpp:196] Created db iterator in 10040ns 3: I1212 03:14:20.751237 20106 leveldb.cpp:202] Seeked to beginning of db in 14750ns 3: I1212 03:14:20.751268 20106 leveldb.cpp:271] Iterated through 1 keys in the db in 20547ns 3: I1212 03:14:20.751302 20106 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned 3: I1212 03:14:20.752171 20113 recover.cpp:451] Starting replica recovery 3: I1212 03:14:20.752507 20113 recover.cpp:477] Replica is in VOTING status 3: I1212 03:14:20.752712 20113 recover.cpp:466] Recover process terminated 3: I1212 03:14:20.753470 20111 registrar.cpp:347] Recovering registrar 3: I1212 03:14:20.754216 20110 log.cpp:536] Attempting to start the writer 3: I1212 03:14:20.755709 20125 replica.cpp:496] Replica received implicit promise request from __req_res__(1154)@172.17.0.2:42245 with proposal 1 3: I1212 03:14:20.755774 20108 replica.cpp:496] Replica received implicit promise request from __req_res__(1155)@172.17.0.2:42245 with proposal 1 3: I1212 03:14:20.757131 20108 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.318257ms 3: I1212 03:14:20.757184 20108 replica.cpp:344] Persisted promised to 1 3: I1212 03:14:20.757133 20125 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.384535ms 3: I1212 03:14:20.757211 20125 replica.cpp:344] Persisted promised to 1 3: I1212 03:14:20.757817 20120 coordinator.cpp:238] Coordinator attempting to fill missing positions 3: I1212 03:14:20.758996 20114 replica.cpp:391] Replica received explicit promise request from __req_res__(1156)@172.17.0.2:42245 for position 0 with proposal 2 3: I1212 03:14:20.759091 20127 replica.cpp:391] Replica received explicit promise request from __req_res__(1157)@172.17.0.2:42245 for position 0 with proposal 2 3: I1212 03:14:20.760462 20114 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 1.423897ms 3: I1212 03:14:20.760473 20127 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 1.319372ms 3: I1212 03:14:20.760506 20114 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.760512 20127 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.761435 20112 replica.cpp:540] Replica received write request for position 0 from __req_res__(1158)@172.17.0.2:42245 3: I1212 03:14:20.761490 20112 leveldb.cpp:436] Reading position from leveldb took 24945ns 3: I1212 03:14:20.761538 20115 replica.cpp:540] Replica received write request for position 0 from __req_res__(1159)@172.17.0.2:42245 3: I1212 03:14:20.761584 20115 leveldb.cpp:436] Reading position from leveldb took 20990ns 3: I1212 03:14:20.762795 20115 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 1.179115ms 3: I1212 03:14:20.762836 20115 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.762837 20112 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 1.289904ms 3: I1212 03:14:20.762866 20112 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.763309 20129 replica.cpp:694] Replica received learned notice for position 0 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.763316 20125 replica.cpp:694] Replica received learned notice for position 0 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.764516 20125 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.161177ms 3: I1212 03:14:20.764545 20129 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.197253ms 3: I1212 03:14:20.764564 20125 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.764593 20129 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.765050 20130 log.cpp:552] Writer started with ending position 0 3: I1212 03:14:20.766294 20123 leveldb.cpp:436] Reading position from leveldb took 32705ns 3: I1212 03:14:20.767248 20121 registrar.cpp:391] Successfully fetched the registry (0B) in 13.73696ms 3: I1212 03:14:20.767405 20121 registrar.cpp:495] Applied 1 operations in 42658ns; attempting to update the registry 3: I1212 03:14:20.768095 20113 log.cpp:560] Attempting to append 178 bytes to the log 3: I1212 03:14:20.768259 20116 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 3: I1212 03:14:20.768910 20126 replica.cpp:540] Replica received write request for position 1 from __req_res__(1160)@172.17.0.2:42245 3: I1212 03:14:20.769001 20130 replica.cpp:540] Replica received write request for position 1 from __req_res__(1161)@172.17.0.2:42245 3: I1212 03:14:20.770799 20130 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 1.754726ms 3: I1212 03:14:20.770802 20126 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 1.847037ms 3: I1212 03:14:20.770843 20130 replica.cpp:711] Persisted action APPEND at position 1 3: I1212 03:14:20.770858 20126 replica.cpp:711] Persisted action APPEND at position 1 3: I1212 03:14:20.771314 20119 replica.cpp:694] Replica received learned notice for position 1 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.771373 20107 replica.cpp:694] Replica received learned notice for position 1 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.772511 20107 leveldb.cpp:341] Persisting action (199 bytes) to leveldb took 1.061378ms 3: I1212 03:14:20.772529 20119 leveldb.cpp:341] Persisting action (199 bytes) to leveldb took 1.192696ms 3: I1212 03:14:20.772547 20107 replica.cpp:711] Persisted action APPEND at position 1 3: I1212 03:14:20.772553 20119 replica.cpp:711] Persisted action APPEND at position 1 3: I1212 03:14:20.773450 20116 registrar.cpp:552] Successfully updated the registry in 5.965056ms 3: I1212 03:14:20.773577 20116 registrar.cpp:424] Successfully recovered registrar 3: I1212 03:14:20.773645 20125 log.cpp:579] Attempting to truncate the log to 1 3: I1212 03:14:20.773823 20114 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2 3: I1212 03:14:20.774284 20126 registrar.cpp:495] Applied 1 operations in 47800ns; attempting to update the registry 3: I1212 03:14:20.774366 20123 replica.cpp:540] Replica received write request for position 2 from __req_res__(1162)@172.17.0.2:42245 3: I1212 03:14:20.774449 20119 replica.cpp:540] Replica received write request for position 2 from __req_res__(1163)@172.17.0.2:42245 3: I1212 03:14:20.775576 20119 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.0825ms 3: I1212 03:14:20.775580 20123 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.176778ms 3: I1212 03:14:20.775606 20119 replica.cpp:711] Persisted action TRUNCATE at position 2 3: I1212 03:14:20.775615 20123 replica.cpp:711] Persisted action TRUNCATE at position 2 3: I1212 03:14:20.776062 20124 replica.cpp:694] Replica received learned notice for position 2 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.776070 20114 replica.cpp:694] Replica received learned notice for position 2 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.777273 20114 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 1.181214ms 3: I1212 03:14:20.777295 20124 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 1.20511ms 3: I1212 03:14:20.777348 20114 leveldb.cpp:399] Deleting ~1 keys from leveldb took 42519ns 3: I1212 03:14:20.777362 20114 replica.cpp:711] Persisted action TRUNCATE at position 2 3: I1212 03:14:20.777371 20124 leveldb.cpp:399] Deleting ~1 keys from leveldb took 33056ns 3: I1212 03:14:20.777387 20124 replica.cpp:711] Persisted action TRUNCATE at position 2 3: I1212 03:14:20.778157 20130 log.cpp:560] Attempting to append 200 bytes to the log 3: I1212 03:14:20.778255 20111 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3 3: I1212 03:14:20.778851 20107 replica.cpp:540] Replica received write request for position 3 from __req_res__(1164)@172.17.0.2:42245 3: I1212 03:14:20.778934 20112 replica.cpp:540] Replica received write request for position 3 from __req_res__(1165)@172.17.0.2:42245 3: I1212 03:14:20.780124 20112 leveldb.cpp:341] Persisting action (219 bytes) to leveldb took 1.150246ms 3: I1212 03:14:20.780124 20107 leveldb.cpp:341] Persisting action (219 bytes) to leveldb took 1.232604ms 3: I1212 03:14:20.780159 20112 replica.cpp:711] Persisted action APPEND at position 3 3: I1212 03:14:20.780169 20107 replica.cpp:711] Persisted action APPEND at position 3 3: I1212 03:14:20.780570 20109 replica.cpp:694] Replica received learned notice for position 3 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.780583 20113 replica.cpp:694] Replica received learned notice for position 3 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.782502 20109 leveldb.cpp:341] Persisting action (221 bytes) to leveldb took 1.90278ms 3: I1212 03:14:20.782549 20109 replica.cpp:711] Persisted action APPEND at position 3 3: I1212 03:14:20.782557 20113 leveldb.cpp:341] Persisting action (221 bytes) to leveldb took 1.951102ms 3: I1212 03:14:20.782582 20113 replica.cpp:711] Persisted action APPEND at position 3 3: I1212 03:14:20.783301 20111 registrar.cpp:552] Successfully updated the registry in 8.969984ms 3: I1212 03:14:20.783488 20110 log.cpp:579] Attempting to truncate the log to 3 3: I1212 03:14:20.783601 20122 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4 3: I1212 03:14:20.783854 20110 registrar.cpp:495] Applied 1 operations in 57766ns; attempting to update the registry 3: I1212 03:14:20.784181 20109 replica.cpp:540] Replica received write request for position 4 from __req_res__(1166)@172.17.0.2:42245 3: I1212 03:14:20.784255 20110 replica.cpp:540] Replica received write request for position 4 from __req_res__(1167)@172.17.0.2:42245 3: I1212 03:14:20.785573 20110 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.273605ms 3: I1212 03:14:20.785573 20109 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.361189ms 3: I1212 03:14:20.785604 20110 replica.cpp:711] Persisted action TRUNCATE at position 4 3: I1212 03:14:20.785610 20109 replica.cpp:711] Persisted action TRUNCATE at position 4 3: I1212 03:14:20.785996 20125 replica.cpp:694] Replica received learned notice for position 4 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.786012 20119 replica.cpp:694] Replica received learned notice for position 4 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.787437 20119 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 1.400181ms 3: I1212 03:14:20.787474 20125 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 1.453964ms 3: I1212 03:14:20.787514 20119 leveldb.cpp:399] Deleting ~2 keys from leveldb took 29140ns 3: I1212 03:14:20.787529 20119 replica.cpp:711] Persisted action TRUNCATE at position 4 3: I1212 03:14:20.787541 20125 leveldb.cpp:399] Deleting ~2 keys from leveldb took 42391ns 3: I1212 03:14:20.787561 20125 replica.cpp:711] Persisted action TRUNCATE at position 4 3: I1212 03:14:20.788338 20107 log.cpp:560] Attempting to append 200 bytes to the log 3: I1212 03:14:20.788453 20120 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 5 3: I1212 03:14:20.789144 20117 replica.cpp:540] Replica received write request for position 5 from __req_res__(1168)@172.17.0.2:42245 3: I1212 03:14:20.789253 20115 replica.cpp:540] Replica received write request for position 5 from __req_res__(1169)@172.17.0.2:42245 3: I1212 03:14:20.790977 20115 leveldb.cpp:341] Persisting action (219 bytes) to leveldb took 1.688382ms 3: I1212 03:14:20.790979 20117 leveldb.cpp:341] Persisting action (219 bytes) to leveldb took 1.797704ms 3: I1212 03:14:20.791003 20115 replica.cpp:711] Persisted action APPEND at position 5 3: I1212 03:14:20.791009 20117 replica.cpp:711] Persisted action APPEND at position 5 3: I1212 03:14:20.791435 20127 replica.cpp:694] Replica received learned notice for position 5 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.791443 20125 replica.cpp:694] Replica received learned notice for position 5 from log-network(71)@172.17.0.2:42245 3: I1212 03:14:20.792557 20127 leveldb.cpp:341] Persisting action (221 bytes) to leveldb took 1.096127ms 3: I1212 03:14:20.792557 20125 leveldb.cpp:341] Persisting action (221 bytes) to leveldb took 1.090837ms 3: I1212 03:14:20.792593 20127 replica.cpp:711] Persisted action APPEND at position 5 3: I1212 03:14:20.792599 20125 replica.cpp:711] Persisted action APPEND at position 5 3: I1212 03:14:20.793468 20107 registrar.cpp:552] Successfully updated the registry in 9.562112ms 3: I1212 03:14:20.793689 20113 log.cpp:579] Attempting to truncate the log to 5 3: I1212 03:14:20.793814 20108 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 6 3: I1212 03:14:20.794476 20120 replica.cpp:540] Replica received write request for position 6 from __req_res__(1170)@172.17.0.2:42245 3: I1212 03:14:20.794565 20116 replica.cpp:540] Replica received write request for position 6 from __req_res__(1171)@172.17.0.2:42245 3: I1212 03:14:20.795738 20116 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.13803ms 3: I1212 03:14:20.795738 20120 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.231776ms 3: I1212 03:14:20.795768 20116 replica.cpp:711] Persisted action TRUNCATE at position 6 3: I1212 03:14:20.795778 20120 replica.cpp:711] Persisted action TRUNCATE at position 6 3: [ OK ] RegistrarTest.Admit (89 ms) 3: [ RUN ] RegistrarTest.UpdateSlave 3: I1212 03:14:20.804826 20106 leveldb.cpp:174] Opened db in 5.586411ms 3: I1212 03:14:20.806411 20106 leveldb.cpp:181] Compacted db in 1.552419ms 3: I1212 03:14:20.806462 20106 leveldb.cpp:196] Created db iterator in 7826ns 3: I1212 03:14:20.806476 20106 leveldb.cpp:202] Seeked to beginning of db in 1300ns 3: I1212 03:14:20.806486 20106 leveldb.cpp:271] Iterated through 0 keys in the db in 630ns 3: I1212 03:14:20.806537 20106 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned 3: I1212 03:14:20.808310 20129 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.353817ms 3: I1212 03:14:20.808358 20129 replica.cpp:322] Persisted replica status to VOTING 3: I1212 03:14:20.814646 20106 leveldb.cpp:174] Opened db in 5.658316ms 3: I1212 03:14:20.816398 20106 leveldb.cpp:181] Compacted db in 1.69977ms 3: I1212 03:14:20.816460 20106 leveldb.cpp:196] Created db iterator in 6807ns 3: I1212 03:14:20.816476 20106 leveldb.cpp:202] Seeked to beginning of db in 1076ns 3: I1212 03:14:20.816488 20106 leveldb.cpp:271] Iterated through 0 keys in the db in 434ns 3: I1212 03:14:20.816527 20106 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned 3: I1212 03:14:20.818156 20116 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.34757ms 3: I1212 03:14:20.818187 20116 replica.cpp:322] Persisted replica status to VOTING 3: I1212 03:14:20.825314 20106 leveldb.cpp:174] Opened db in 6.658422ms 3: I1212 03:14:20.830602 20106 leveldb.cpp:181] Compacted db in 5.236456ms 3: I1212 03:14:20.830649 20106 leveldb.cpp:196] Created db iterator in 7689ns 3: I1212 03:14:20.830672 20106 leveldb.cpp:202] Seeked to beginning of db in 10842ns 3: I1212 03:14:20.830704 20106 leveldb.cpp:271] Iterated through 1 keys in the db in 23308ns 3: I1212 03:14:20.830751 20106 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned 3: I1212 03:14:20.836263 20106 leveldb.cpp:174] Opened db in 5.311914ms 3: I1212 03:14:20.841884 20106 leveldb.cpp:181] Compacted db in 5.571596ms 3: I1212 03:14:20.841931 20106 leveldb.cpp:196] Created db iterator in 7883ns 3: I1212 03:14:20.841951 20106 leveldb.cpp:202] Seeked to beginning of db in 10047ns 3: I1212 03:14:20.841989 20106 leveldb.cpp:271] Iterated through 1 keys in the db in 21864ns 3: I1212 03:14:20.842034 20106 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned 3: I1212 03:14:20.842619 20121 recover.cpp:451] Starting replica recovery 3: I1212 03:14:20.842869 20117 recover.cpp:477] Replica is in VOTING status 3: I1212 03:14:20.843039 20117 recover.cpp:466] Recover process terminated 3: I1212 03:14:20.843698 20120 registrar.cpp:347] Recovering registrar 3: I1212 03:14:20.844262 20127 log.cpp:536] Attempting to start the writer 3: I1212 03:14:20.845438 20129 replica.cpp:496] Replica received implicit promise request from __req_res__(1172)@172.17.0.2:42245 with proposal 1 3: I1212 03:14:20.845505 20125 replica.cpp:496] Replica received implicit promise request from __req_res__(1173)@172.17.0.2:42245 with proposal 1 3: I1212 03:14:20.846873 20129 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.38903ms 3: I1212 03:14:20.846873 20125 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.311726ms 3: I1212 03:14:20.846905 20129 replica.cpp:344] Persisted promised to 1 3: I1212 03:14:20.846915 20125 replica.cpp:344] Persisted promised to 1 3: I1212 03:14:20.847472 20108 coordinator.cpp:238] Coordinator attempting to fill missing positions 3: I1212 03:14:20.848841 20121 replica.cpp:391] Replica received explicit promise request from __req_res__(1174)@172.17.0.2:42245 for position 0 with proposal 2 3: I1212 03:14:20.848914 20125 replica.cpp:391] Replica received explicit promise request from __req_res__(1175)@172.17.0.2:42245 for position 0 with proposal 2 3: I1212 03:14:20.850497 20121 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 1.612296ms 3: I1212 03:14:20.850497 20125 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 1.541733ms 3: I1212 03:14:20.850538 20121 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.850567 20125 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.851430 20130 replica.cpp:540] Replica received write request for position 0 from __req_res__(1176)@172.17.0.2:42245 3: I1212 03:14:20.851488 20130 leveldb.cpp:436] Reading position from leveldb took 24888ns 3: I1212 03:14:20.851496 20120 replica.cpp:540] Replica received write request for position 0 from __req_res__(1177)@172.17.0.2:42245 3: I1212 03:14:20.851557 20120 leveldb.cpp:436] Reading position from leveldb took 21060ns 3: I1212 03:14:20.852921 20120 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 1.315871ms 3: I1212 03:14:20.852926 20130 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 1.385369ms 3: I1212 03:14:20.852968 20120 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.852974 20130 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.853531 20119 replica.cpp:694] Replica received learned notice for position 0 from log-network(72)@172.17.0.2:42245 3: I1212 03:14:20.853539 20117 replica.cpp:694] Replica received learned notice for position 0 from log-network(72)@172.17.0.2:42245 3: I1212 03:14:20.854714 20117 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.14085ms 3: I1212 03:14:20.854740 20117 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.854740 20119 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.174643ms 3: I1212 03:14:20.854768 20119 replica.cpp:711] Persisted action NOP at position 0 3: I1212 03:14:20.855103 20116 log.cpp:552] Writer started with ending position 0 3: I1212 03:14:20.856050 20130 leveldb.cpp:436] Reading position from leveldb took 26758ns 3: I1212 03:14:20.856905 20109 registrar.cpp:391] Successfully fetched the registry (0B) in 13.154048ms 3: I1212 03:14:20.857102 20109 registrar.cpp:495] Applied 1 operations in 75953ns; attempting to update the registry 3: I1212 03:14:20.857733 20118 log.cpp:560] Attempting to append 178 bytes to the log 3: I1212 03:14:20.857892 20126 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 3: I1212 03:14:20.858431 20108 replica.cpp:540] Replica received write request for position 1 from __req_res__(1178)@172.17.0.2:42245 3: I1212 03:14:20.858510 20126 replica.cpp:540] Replica received write request for position 1 from __req_res__(1179)@172.17.0.2:42245 write /dev/stdout: resource temporarily unavailable + docker rmi mesos-1513045913-9714 Build step 'Execute shell' marked build as failure
