Thanks for digging in Adam! I will get this fixed.
On Wed, Apr 30, 2014 at 12:29 AM, Adam Bordelon <[email protected]> wrote: > This is dying inside the first line of RetrySlaveAuthenticationTest, which > is a default StartMaster() call with default master flags. > StartMaster/start FATALs while waiting for Master::_recover, after > spawning the new Master process. > This await(_recover) dates back to bmahler's LogStorage commit > 7bf1e8a6b6d1160c65d37a03f38341604a122078 on April 16. > The logs show the master started, "Successfully recovered registrar", and > "Recovered 0 slaves from the Registry (99B) ; allowing 10mins for slaves to > re-register" all at 06:08:49.5 (slightly more than 10s before the > await(_recover) failure). The latter log message is actually logged from > _recover, so we know Master actually called _recover. > (TL;DR) Perhaps the FUTURE_DISPATCH(_recover) call in > Cluster::Masters::start() should be before process::spawn(master.master), > in case Master initializes/recovers too quickly and FUTURE_DISPATCH loses > the race? > > -A- > > > On Tue, Apr 29, 2014 at 11:26 PM, Vinod Kone <[email protected]> wrote: > >> hey adam can you triage this? >> >> >> On Tue, Apr 29, 2014 at 11:09 PM, Apache Jenkins Server < >> [email protected]> wrote: >> >>> See < >>> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2101/changes >>> > >>> >>> Changes: >>> >>> [vinod] Fixed distclean break during maven clean up. >>> >>> [idownes] Fixed some indentation. >>> >>> [benjamin.hindman] Better error message for protobuf::write. >>> >>> [benjamin.hindman] Added 'mesos-usage' for use by external >>> containerizers. >>> >>> [benjamin.hindman] Added test for slave stopping before containerizer >>> launches. >>> >>> [benjamin.hindman] Allowed passing headers to http::get/post. >>> >>> [benjamin.hindman] Updated uses of http::post. >>> >>> [benjamin.hindman] Used memory::shared_ptr instead of boost::shared_ptr. >>> >>> [benjamin.hindman] Added 'cref' and 'ref' to lambda:: namespace. >>> >>> [benjamin.hindman] Added process::async overloads for void functions. >>> >>> ------------------------------------------ >>> [...truncated 25160 lines...] >>> W0430 06:08:49.430877 30345 slave.cpp:2154] Master disconnected! Waiting >>> for a new master to be elected >>> I0430 06:08:49.431460 30344 replica.cpp:643] Replica received learned >>> notice for position 4 >>> I0430 06:08:49.432160 30344 leveldb.cpp:341] Persisting action (18 >>> bytes) to leveldb took 675495ns >>> I0430 06:08:49.432185 30344 leveldb.cpp:399] Deleting ~2 keys from >>> leveldb took 14255ns >>> I0430 06:08:49.432194 30344 replica.cpp:664] Persisted action at 4 >>> I0430 06:08:49.432204 30344 replica.cpp:649] Replica learned TRUNCATE >>> action at position 4 >>> I0430 06:08:49.433727 30322 slave.cpp:414] Slave terminating >>> [ OK ] AuthenticationTest.LeaderElectionDuringSlaveAuthentication >>> (61 ms) >>> [ RUN ] AuthenticationTest.LeaderElection >>> I0430 06:08:49.441107 30322 leveldb.cpp:174] Opened db in 2.896681ms >>> I0430 06:08:49.441488 30322 leveldb.cpp:181] Compacted db in 258457ns >>> I0430 06:08:49.441550 30322 leveldb.cpp:196] Created db iterator in >>> 4261ns >>> I0430 06:08:49.441604 30322 leveldb.cpp:202] Seeked to beginning of db >>> in 638ns >>> I0430 06:08:49.441655 30322 leveldb.cpp:271] Iterated through 0 keys in >>> the db in 620ns >>> I0430 06:08:49.441715 30322 replica.cpp:729] Replica recovered with log >>> positions 0 -> 0 with 1 holes and 0 unlearned >>> I0430 06:08:49.442021 30349 recover.cpp:425] Starting replica recovery >>> I0430 06:08:49.442101 30349 recover.cpp:451] Replica is in EMPTY status >>> I0430 06:08:49.442471 30349 replica.cpp:626] Replica in EMPTY status >>> received a broadcasted recover request >>> I0430 06:08:49.442528 30349 recover.cpp:188] Received a recover response >>> from a replica in EMPTY status >>> I0430 06:08:49.442637 30349 recover.cpp:542] Updating replica status to >>> STARTING >>> I0430 06:08:49.443323 30349 leveldb.cpp:304] Persisting metadata (8 >>> bytes) to leveldb took 613124ns >>> I0430 06:08:49.443336 30349 replica.cpp:320] Persisted replica status to >>> STARTING >>> I0430 06:08:49.443397 30349 recover.cpp:451] Replica is in STARTING >>> status >>> I0430 06:08:49.443672 30349 replica.cpp:626] Replica in STARTING status >>> received a broadcasted recover request >>> I0430 06:08:49.443718 30349 recover.cpp:188] Received a recover response >>> from a replica in STARTING status >>> I0430 06:08:49.443810 30349 recover.cpp:542] Updating replica status to >>> VOTING >>> I0430 06:08:49.443953 30349 leveldb.cpp:304] Persisting metadata (8 >>> bytes) to leveldb took 100071ns >>> I0430 06:08:49.443964 30349 replica.cpp:320] Persisted replica status to >>> VOTING >>> I0430 06:08:49.443995 30349 recover.cpp:556] Successfully joined the >>> Paxos group >>> I0430 06:08:49.444046 30349 recover.cpp:440] Recover process terminated >>> I0430 06:08:49.444860 30347 master.cpp:266] Master >>> 20140430-060849-143311683-58511-30322 (minerva.apache.org) started on >>> 67.195.138.8:58511 >>> I0430 06:08:49.444880 30347 master.cpp:303] Master only allowing >>> authenticated frameworks to register >>> I0430 06:08:49.444885 30347 master.cpp:308] Master only allowing >>> authenticated slaves to register >>> I0430 06:08:49.444890 30347 credentials.hpp:35] Loading credentials for >>> authentication >>> W0430 06:08:49.444926 30347 credentials.hpp:48] Failed to stat >>> credentials file >>> 'file:///tmp/AuthenticationTest_LeaderElection_2EYXk0/credentials': No such >>> file or directory >>> I0430 06:08:49.445458 30347 hierarchical_allocator_process.hpp:302] >>> Initializing hierarchical allocator process with master : >>> [email protected]:58511 >>> I0430 06:08:49.445492 30347 master.cpp:104] No whitelist given. >>> Advertising offers for all slaves >>> I0430 06:08:49.445680 30347 master.cpp:922] The newly elected leader is >>> [email protected]:58511 with id 20140430-060849-143311683-58511-30322 >>> I0430 06:08:49.445688 30347 master.cpp:932] Elected as the leading >>> master! >>> I0430 06:08:49.445695 30347 master.cpp:753] Recovering from registrar >>> I0430 06:08:49.445749 30347 registrar.cpp:275] Recovering registrar >>> I0430 06:08:49.445976 30347 log.cpp:656] Attempting to start the writer >>> I0430 06:08:49.446288 30347 replica.cpp:474] Replica received implicit >>> promise request with proposal 1 >>> I0430 06:08:49.446410 30347 leveldb.cpp:304] Persisting metadata (8 >>> bytes) to leveldb took 111558ns >>> I0430 06:08:49.446423 30347 replica.cpp:342] Persisted promised to 1 >>> I0430 06:08:49.446666 30347 coordinator.cpp:229] Coordinator attemping >>> to fill missing position >>> I0430 06:08:49.447002 30347 replica.cpp:375] Replica received explicit >>> promise request for position 0 with proposal 2 >>> I0430 06:08:49.447116 30347 leveldb.cpp:341] Persisting action (8 bytes) >>> to leveldb took 102007ns >>> I0430 06:08:49.447127 30347 replica.cpp:664] Persisted action at 0 >>> I0430 06:08:49.447392 30347 replica.cpp:508] Replica received write >>> request for position 0 >>> I0430 06:08:49.447412 30347 leveldb.cpp:436] Reading position from >>> leveldb took 11518ns >>> I0430 06:08:49.453721 30347 leveldb.cpp:341] Persisting action (14 >>> bytes) to leveldb took 6.293392ms >>> I0430 06:08:49.453747 30347 replica.cpp:664] Persisted action at 0 >>> I0430 06:08:49.453896 30347 replica.cpp:643] Replica received learned >>> notice for position 0 >>> I0430 06:08:49.454051 30347 leveldb.cpp:341] Persisting action (16 >>> bytes) to leveldb took 141267ns >>> I0430 06:08:49.454069 30347 replica.cpp:664] Persisted action at 0 >>> I0430 06:08:49.454080 30347 replica.cpp:649] Replica learned NOP action >>> at position 0 >>> I0430 06:08:49.454254 30346 log.cpp:672] Writer started with ending >>> position 0 >>> I0430 06:08:49.454620 30346 leveldb.cpp:436] Reading position from >>> leveldb took 10194ns >>> I0430 06:08:49.455654 30346 registrar.cpp:308] Successfully recovered >>> registrar >>> I0430 06:08:49.455674 30346 registrar.cpp:379] Attempting to update the >>> 'registry' >>> I0430 06:08:49.456663 30346 log.cpp:680] Attempting to append 137 bytes >>> to the log >>> I0430 06:08:49.456706 30346 coordinator.cpp:339] Coordinator attempting >>> to write APPEND action at position 1 >>> I0430 06:08:49.456913 30346 replica.cpp:508] Replica received write >>> request for position 1 >>> I0430 06:08:49.457074 30346 leveldb.cpp:341] Persisting action (156 >>> bytes) to leveldb took 150036ns >>> I0430 06:08:49.457087 30346 replica.cpp:664] Persisted action at 1 >>> I0430 06:08:49.457414 30348 replica.cpp:643] Replica received learned >>> notice for position 1 >>> I0430 06:08:49.457545 30348 leveldb.cpp:341] Persisting action (158 >>> bytes) to leveldb took 111489ns >>> I0430 06:08:49.457556 30348 replica.cpp:664] Persisted action at 1 >>> I0430 06:08:49.457563 30348 replica.cpp:649] Replica learned APPEND >>> action at position 1 >>> I0430 06:08:49.457769 30348 registrar.cpp:427] Successfully updated >>> 'registry' >>> I0430 06:08:49.457866 30343 log.cpp:699] Attempting to truncate the log >>> to 1 >>> I0430 06:08:49.457866 30348 master.cpp:780] Recovered 0 slaves from the >>> Registry (99B) ; allowing 10mins for slaves to re-register >>> I0430 06:08:49.457913 30348 coordinator.cpp:339] Coordinator attempting >>> to write TRUNCATE action at position 2 >>> I0430 06:08:49.458087 30348 replica.cpp:508] Replica received write >>> request for position 2 >>> I0430 06:08:49.458184 30348 leveldb.cpp:341] Persisting action (16 >>> bytes) to leveldb took 83654ns >>> I0430 06:08:49.458195 30348 replica.cpp:664] Persisted action at 2 >>> I0430 06:08:49.458333 30348 replica.cpp:643] Replica received learned >>> notice for position 2 >>> I0430 06:08:49.458415 30348 leveldb.cpp:341] Persisting action (18 >>> bytes) to leveldb took 73068ns >>> I0430 06:08:49.458441 30348 leveldb.cpp:399] Deleting ~1 keys from >>> leveldb took 13141ns >>> I0430 06:08:49.458451 30348 replica.cpp:664] Persisted action at 2 >>> I0430 06:08:49.458457 30348 replica.cpp:649] Replica learned TRUNCATE >>> action at position 2 >>> I0430 06:08:49.459568 30322 sched.cpp:121] Version: 0.19.0 >>> I0430 06:08:49.459725 30348 sched.cpp:217] New master detected at >>> [email protected]:58511 >>> I0430 06:08:49.459740 30348 sched.cpp:268] Authenticating with master >>> [email protected]:58511 >>> I0430 06:08:49.459815 30348 authenticatee.hpp:128] Creating new client >>> SASL connection >>> I0430 06:08:49.459944 30348 master.cpp:2795] Authenticating >>> scheduler(74)@67.195.138.8:58511 >>> >>> I0430 06:08:49.460014 30348 authenticator.hpp:148] Creating new server >>> SASL connection >>> I0430 06:08:49.460100 30348 authenticatee.hpp:219] Received SASL >>> authentication mechanisms: CRAM-MD5 >>> I0430 06:08:49.460115 30348 authenticatee.hpp:245] Attempting to >>> authenticate with mechanism 'CRAM-MD5' >>> I0430 06:08:49.460139 30348 authenticator.hpp:254] Received SASL >>> authentication start >>> I0430 06:08:49.460167 30348 authenticator.hpp:342] Authentication >>> requires more steps >>> I0430 06:08:49.463879 30348 sched.cpp:217] New master detected at >>> [email protected]:58511 >>> I0430 06:08:49.463973 30348 sched.cpp:323] Failed to authenticate with >>> master [email protected]:58511: master changed >>> I0430 06:08:49.463994 30348 sched.cpp:268] Authenticating with master >>> [email protected]:58511 >>> I0430 06:08:49.464052 30348 authenticatee.hpp:128] Creating new client >>> SASL connection >>> W0430 06:08:49.464123 30348 master.cpp:2830] Failed to authenticate >>> scheduler(74)@67.195.138.8:58511: Failed to communicate with >>> authenticatee >>> I0430 06:08:49.464177 30348 master.cpp:2795] Authenticating >>> scheduler(74)@67.195.138.8:58511 >>> >>> I0430 06:08:49.464236 30348 authenticator.hpp:148] Creating new server >>> SASL connection >>> I0430 06:08:49.464301 30348 authenticatee.hpp:219] Received SASL >>> authentication mechanisms: CRAM-MD5 >>> I0430 06:08:49.464314 30348 authenticatee.hpp:245] Attempting to >>> authenticate with mechanism 'CRAM-MD5' >>> I0430 06:08:49.464335 30348 authenticator.hpp:254] Received SASL >>> authentication start >>> I0430 06:08:49.464359 30348 authenticator.hpp:342] Authentication >>> requires more steps >>> I0430 06:08:49.464380 30348 authenticatee.hpp:265] Received SASL >>> authentication step >>> I0430 06:08:49.464416 30348 authenticator.hpp:282] Received SASL >>> authentication step >>> I0430 06:08:49.464432 30348 auxprop.cpp:81] Request to lookup properties >>> for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: ' >>> minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false >>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false >>> I0430 06:08:49.464438 30348 auxprop.cpp:153] Looking up auxiliary >>> property '*userPassword' >>> I0430 06:08:49.464450 30348 auxprop.cpp:153] Looking up auxiliary >>> property '*cmusaslsecretCRAM-MD5' >>> I0430 06:08:49.464459 30348 auxprop.cpp:81] Request to lookup properties >>> for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: ' >>> minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false >>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true >>> I0430 06:08:49.464465 30348 auxprop.cpp:103] Skipping auxiliary property >>> '*userPassword' since SASL_AUXPROP_AUTHZID == true >>> I0430 06:08:49.464472 30348 auxprop.cpp:103] Skipping auxiliary property >>> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true >>> I0430 06:08:49.464483 30348 authenticator.hpp:334] Authentication success >>> I0430 06:08:49.464504 30348 authenticatee.hpp:305] Authentication success >>> I0430 06:08:49.464522 30348 master.cpp:2835] Successfully authenticated >>> scheduler(74)@67.195.138.8:58511 >>> I0430 06:08:49.464570 30348 sched.cpp:342] Successfully authenticated >>> with master [email protected]:58511 >>> I0430 06:08:49.464581 30348 sched.cpp:461] Sending registration request >>> to [email protected]:58511 >>> I0430 06:08:49.464622 30348 master.cpp:981] Received registration >>> request from scheduler(74)@67.195.138.8:58511 >>> I0430 06:08:49.464647 30348 master.cpp:999] Registering framework >>> 20140430-060849-143311683-58511-30322-0000 at scheduler(74)@ >>> 67.195.138.8:58511 >>> >>> I0430 06:08:49.464697 30348 sched.cpp:392] Framework registered with >>> 20140430-060849-143311683-58511-30322-0000 >>> I0430 06:08:49.464718 30348 sched.cpp:406] Scheduler::registered took >>> 12387ns >>> I0430 06:08:49.464759 30348 hierarchical_allocator_process.hpp:332] >>> Added framework 20140430-060849-143311683-58511-30322-0000 >>> I0430 06:08:49.464769 30348 hierarchical_allocator_process.hpp:726] No >>> resources available to allocate! >>> I0430 06:08:49.464776 30348 hierarchical_allocator_process.hpp:688] >>> Performed allocation for 0 slaves in 7440ns >>> I0430 06:08:49.464843 30322 master.cpp:551] Master terminating >>> I0430 06:08:49.464926 30345 sched.cpp:731] Stopping framework >>> '20140430-060849-143311683-58511-30322-0000' >>> [ OK ] AuthenticationTest.LeaderElection (31 ms) >>> [ RUN ] AuthenticationTest.RetrySlaveAuthentication >>> I0430 06:08:49.498736 30322 leveldb.cpp:174] Opened db in 27.688285ms >>> I0430 06:08:49.499557 30322 leveldb.cpp:181] Compacted db in 770486ns >>> I0430 06:08:49.499634 30322 leveldb.cpp:196] Created db iterator in >>> 6638ns >>> I0430 06:08:49.499686 30322 leveldb.cpp:202] Seeked to beginning of db >>> in 683ns >>> I0430 06:08:49.499735 30322 leveldb.cpp:271] Iterated through 0 keys in >>> the db in 677ns >>> I0430 06:08:49.499804 30322 replica.cpp:729] Replica recovered with log >>> positions 0 -> 0 with 1 holes and 0 unlearned >>> I0430 06:08:49.500140 30349 recover.cpp:425] Starting replica recovery >>> I0430 06:08:49.500231 30349 recover.cpp:451] Replica is in EMPTY status >>> I0430 06:08:49.500625 30349 replica.cpp:626] Replica in EMPTY status >>> received a broadcasted recover request >>> I0430 06:08:49.500684 30349 recover.cpp:188] Received a recover response >>> from a replica in EMPTY status >>> I0430 06:08:49.500798 30349 recover.cpp:542] Updating replica status to >>> STARTING >>> I0430 06:08:49.501648 30349 leveldb.cpp:304] Persisting metadata (8 >>> bytes) to leveldb took 791660ns >>> I0430 06:08:49.501662 30349 replica.cpp:320] Persisted replica status to >>> STARTING >>> I0430 06:08:49.501721 30349 recover.cpp:451] Replica is in STARTING >>> status >>> I0430 06:08:49.501999 30349 replica.cpp:626] Replica in STARTING status >>> received a broadcasted recover request >>> I0430 06:08:49.502045 30349 recover.cpp:188] Received a recover response >>> from a replica in STARTING status >>> I0430 06:08:49.502137 30349 recover.cpp:542] Updating replica status to >>> VOTING >>> I0430 06:08:49.502284 30349 leveldb.cpp:304] Persisting metadata (8 >>> bytes) to leveldb took 104244ns >>> I0430 06:08:49.502295 30349 replica.cpp:320] Persisted replica status to >>> VOTING >>> I0430 06:08:49.502326 30349 recover.cpp:556] Successfully joined the >>> Paxos group >>> I0430 06:08:49.502378 30349 recover.cpp:440] Recover process terminated >>> I0430 06:08:49.503067 30349 master.cpp:266] Master >>> 20140430-060849-143311683-58511-30322 (minerva.apache.org) started on >>> 67.195.138.8:58511 >>> I0430 06:08:49.503084 30349 master.cpp:303] Master only allowing >>> authenticated frameworks to register >>> I0430 06:08:49.503090 30349 master.cpp:308] Master only allowing >>> authenticated slaves to register >>> I0430 06:08:49.503095 30349 credentials.hpp:35] Loading credentials for >>> authentication >>> W0430 06:08:49.503130 30349 credentials.hpp:48] Failed to stat >>> credentials file >>> 'file:///tmp/AuthenticationTest_RetrySlaveAuthentication_udJyoz/credentials': >>> No such file or directory >>> I0430 06:08:49.503645 30349 hierarchical_allocator_process.hpp:302] >>> Initializing hierarchical allocator process with master : >>> [email protected]:58511 >>> I0430 06:08:49.503679 30349 master.cpp:104] No whitelist given. >>> Advertising offers for all slaves >>> I0430 06:08:49.503868 30349 master.cpp:922] The newly elected leader is >>> [email protected]:58511 with id 20140430-060849-143311683-58511-30322 >>> I0430 06:08:49.503876 30349 master.cpp:932] Elected as the leading >>> master! >>> I0430 06:08:49.503882 30349 master.cpp:753] Recovering from registrar >>> I0430 06:08:49.503937 30349 registrar.cpp:275] Recovering registrar >>> I0430 06:08:49.504156 30349 log.cpp:656] Attempting to start the writer >>> I0430 06:08:49.504475 30349 replica.cpp:474] Replica received implicit >>> promise request with proposal 1 >>> I0430 06:08:49.504598 30349 leveldb.cpp:304] Persisting metadata (8 >>> bytes) to leveldb took 111380ns >>> I0430 06:08:49.504609 30349 replica.cpp:342] Persisted promised to 1 >>> I0430 06:08:49.504770 30349 coordinator.cpp:229] Coordinator attemping >>> to fill missing position >>> I0430 06:08:49.505084 30349 replica.cpp:375] Replica received explicit >>> promise request for position 0 with proposal 2 >>> I0430 06:08:49.505182 30349 leveldb.cpp:341] Persisting action (8 bytes) >>> to leveldb took 85434ns >>> I0430 06:08:49.505192 30349 replica.cpp:664] Persisted action at 0 >>> I0430 06:08:49.505431 30349 replica.cpp:508] Replica received write >>> request for position 0 >>> I0430 06:08:49.505450 30349 leveldb.cpp:436] Reading position from >>> leveldb took 10523ns >>> I0430 06:08:49.505548 30349 leveldb.cpp:341] Persisting action (14 >>> bytes) to leveldb took 84781ns >>> I0430 06:08:49.505558 30349 replica.cpp:664] Persisted action at 0 >>> I0430 06:08:49.505684 30349 replica.cpp:643] Replica received learned >>> notice for position 0 >>> I0430 06:08:49.505836 30349 leveldb.cpp:341] Persisting action (16 >>> bytes) to leveldb took 135965ns >>> I0430 06:08:49.505846 30349 replica.cpp:664] Persisted action at 0 >>> I0430 06:08:49.505853 30349 replica.cpp:649] Replica learned NOP action >>> at position 0 >>> I0430 06:08:49.505997 30349 log.cpp:672] Writer started with ending >>> position 0 >>> I0430 06:08:49.506242 30349 leveldb.cpp:436] Reading position from >>> leveldb took 6183ns >>> I0430 06:08:49.507227 30349 registrar.cpp:308] Successfully recovered >>> registrar >>> I0430 06:08:49.507243 30349 registrar.cpp:379] Attempting to update the >>> 'registry' >>> I0430 06:08:49.508235 30349 log.cpp:680] Attempting to append 137 bytes >>> to the log >>> I0430 06:08:49.508271 30349 coordinator.cpp:339] Coordinator attempting >>> to write APPEND action at position 1 >>> I0430 06:08:49.508438 30349 replica.cpp:508] Replica received write >>> request for position 1 >>> I0430 06:08:49.508555 30349 leveldb.cpp:341] Persisting action (156 >>> bytes) to leveldb took 105618ns >>> I0430 06:08:49.508610 30349 replica.cpp:664] Persisted action at 1 >>> I0430 06:08:49.508999 30342 replica.cpp:643] Replica received learned >>> notice for position 1 >>> I0430 06:08:49.509121 30342 leveldb.cpp:341] Persisting action (158 >>> bytes) to leveldb took 109883ns >>> I0430 06:08:49.509132 30342 replica.cpp:664] Persisted action at 1 >>> I0430 06:08:49.509140 30342 replica.cpp:649] Replica learned APPEND >>> action at position 1 >>> I0430 06:08:49.509374 30342 registrar.cpp:427] Successfully updated >>> 'registry' >>> I0430 06:08:49.509431 30342 log.cpp:699] Attempting to truncate the log >>> to 1 >>> I0430 06:08:49.509485 30342 master.cpp:780] Recovered 0 slaves from the >>> Registry (99B) ; allowing 10mins for slaves to re-register >>> I0430 06:08:49.509522 30342 coordinator.cpp:339] Coordinator attempting >>> to write TRUNCATE action at position 2 >>> I0430 06:08:49.509747 30349 replica.cpp:508] Replica received write >>> request for position 2 >>> I0430 06:08:49.509892 30349 leveldb.cpp:341] Persisting action (16 >>> bytes) to leveldb took 67784ns >>> I0430 06:08:49.509946 30349 replica.cpp:664] Persisted action at 2 >>> I0430 06:08:49.510172 30349 replica.cpp:643] Replica received learned >>> notice for position 2 >>> I0430 06:08:49.510367 30349 leveldb.cpp:341] Persisting action (18 >>> bytes) to leveldb took 94531ns >>> I0430 06:08:49.510431 30349 leveldb.cpp:399] Deleting ~1 keys from >>> leveldb took 9623ns >>> I0430 06:08:49.510480 30349 replica.cpp:664] Persisted action at 2 >>> I0430 06:08:49.510532 30349 replica.cpp:649] Replica learned TRUNCATE >>> action at position 2 >>> I0430 06:08:50.506840 30342 hierarchical_allocator_process.hpp:726] No >>> resources available to allocate! >>> I0430 06:08:50.506911 30342 hierarchical_allocator_process.hpp:688] >>> Performed allocation for 0 slaves in 117128ns >>> I0430 06:08:51.510942 30342 hierarchical_allocator_process.hpp:726] No >>> resources available to allocate! >>> I0430 06:08:51.510982 30342 hierarchical_allocator_process.hpp:688] >>> Performed allocation for 0 slaves in 54612ns >>> I0430 06:08:52.513665 30343 hierarchical_allocator_process.hpp:726] No >>> resources available to allocate! >>> I0430 06:08:52.513713 30343 hierarchical_allocator_process.hpp:688] >>> Performed allocation for 0 slaves in 90420ns >>> I0430 06:08:53.514034 30343 hierarchical_allocator_process.hpp:726] No >>> resources available to allocate! >>> I0430 06:08:53.514070 30343 hierarchical_allocator_process.hpp:688] >>> Performed allocation for 0 slaves in 48216ns >>> I0430 06:08:54.504179 30348 master.cpp:104] No whitelist given. >>> Advertising offers for all slaves >>> I0430 06:08:54.514416 30348 hierarchical_allocator_process.hpp:726] No >>> resources available to allocate! >>> I0430 06:08:54.514502 30348 hierarchical_allocator_process.hpp:688] >>> Performed allocation for 0 slaves in 110788ns >>> I0430 06:08:55.518991 30343 hierarchical_allocator_process.hpp:726] No >>> resources available to allocate! >>> I0430 06:08:55.519031 30343 hierarchical_allocator_process.hpp:688] >>> Performed allocation for 0 slaves in 53319ns >>> I0430 06:08:56.519583 30343 hierarchical_allocator_process.hpp:726] No >>> resources available to allocate! >>> I0430 06:08:56.519654 30343 hierarchical_allocator_process.hpp:688] >>> Performed allocation for 0 slaves in 85551ns >>> I0430 06:08:57.522794 30343 hierarchical_allocator_process.hpp:726] No >>> resources available to allocate! >>> I0430 06:08:57.522855 30343 hierarchical_allocator_process.hpp:688] >>> Performed allocation for 0 slaves in 78093ns >>> I0430 06:08:58.526785 30343 hierarchical_allocator_process.hpp:726] No >>> resources available to allocate! >>> I0430 06:08:58.526844 30343 hierarchical_allocator_process.hpp:688] >>> Performed allocation for 0 slaves in 73657ns >>> I0430 06:08:59.504978 30343 master.cpp:104] No whitelist given. >>> Advertising offers for all slaves >>> F0430 06:08:59.511245 30322 cluster.hpp:379] Failed to wait for _recover >>> *** Check failure stack trace: *** >>> I0430 06:08:59.527694 30343 hierarchical_allocator_process.hpp:726] No >>> resources available to allocate! >>> I0430 06:08:59.562788 30343 hierarchical_allocator_process.hpp:688] >>> Performed allocation for 0 slaves in 35.083369ms >>> @ 0x2ac97f1a0dbd google::LogMessage::Fail() >>> @ 0x2ac97f1a2e4f google::LogMessage::SendToLog() >>> @ 0x2ac97f1a09ac google::LogMessage::Flush() >>> @ 0x2ac97f1a36bd google::LogMessageFatal::~LogMessageFatal() >>> @ 0x716769 >>> mesos::internal::tests::Cluster::Masters::start() >>> @ 0x710da3 >>> mesos::internal::tests::MesosTest::StartMaster() >>> @ 0x571386 >>> AuthenticationTest_RetrySlaveAuthentication_Test::TestBody() >>> @ 0x86706d >>> testing::internal::HandleExceptionsInMethodIfSupported<>() >>> @ 0x85f6a1 testing::Test::Run() >>> @ 0x85f786 testing::TestInfo::Run() >>> @ 0x85f8c7 testing::TestCase::Run() >>> @ 0x85fc2e testing::internal::UnitTestImpl::RunAllTests() >>> @ 0x866bed >>> testing::internal::HandleExceptionsInMethodIfSupported<>() >>> @ 0x85ecfe testing::UnitTest::Run() >>> @ 0x49f900 main >>> @ 0x2ac9805e076d (unknown) >>> @ 0x4a91d1 (unknown) >>> make[3]: *** [check-local] Aborted >>> make[3]: Leaving directory `< >>> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src >>> '> >>> make[2]: *** [check-am] Error 2 >>> make[2]: Leaving directory `< >>> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src >>> '> >>> make[1]: *** [check] Error 2 >>> make[1]: Leaving directory `< >>> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src >>> '> >>> make: *** [check-recursive] Error 1 >>> Build step 'Execute shell' marked build as failure >>> >> >> >
