[ https://issues.apache.org/jira/browse/MESOS-1848?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Cody Maloney updated MESOS-1848: -------------------------------- Labels: flaky (was: ) > DRFAllocatorTest.DRFAllocatorProcess is flaky > --------------------------------------------- > > Key: MESOS-1848 > URL: https://issues.apache.org/jira/browse/MESOS-1848 > Project: Mesos > Issue Type: Bug > Components: test > Environment: Fedora 20 > Reporter: Vinod Kone > Labels: flaky > > Observed this on CI. This is pretty strange because the authentication of > both the framework and slave timed out at the very beginning, even though we > don't manipulate clocks. > {code} > [ RUN ] DRFAllocatorTest.DRFAllocatorProcess > Using temporary directory '/tmp/DRFAllocatorTest_DRFAllocatorProcess_igiR9X' > I0929 20:11:12.801327 16997 leveldb.cpp:176] Opened db in 489720ns > I0929 20:11:12.801627 16997 leveldb.cpp:183] Compacted db in 168280ns > I0929 20:11:12.801784 16997 leveldb.cpp:198] Created db iterator in 5820ns > I0929 20:11:12.801898 16997 leveldb.cpp:204] Seeked to beginning of db in > 1285ns > I0929 20:11:12.802039 16997 leveldb.cpp:273] Iterated through 0 keys in the > db in 792ns > I0929 20:11:12.802160 16997 replica.cpp:741] Replica recovered with log > positions 0 -> 0 with 1 holes and 0 unlearned > I0929 20:11:12.802441 17012 recover.cpp:425] Starting replica recovery > I0929 20:11:12.802623 17012 recover.cpp:451] Replica is in EMPTY status > I0929 20:11:12.803251 17012 replica.cpp:638] Replica in EMPTY status received > a broadcasted recover request > I0929 20:11:12.803427 17012 recover.cpp:188] Received a recover response from > a replica in EMPTY status > I0929 20:11:12.803632 17012 recover.cpp:542] Updating replica status to > STARTING > I0929 20:11:12.803911 17012 leveldb.cpp:306] Persisting metadata (8 bytes) to > leveldb took 33999ns > I0929 20:11:12.804033 17012 replica.cpp:320] Persisted replica status to > STARTING > I0929 20:11:12.804245 17012 recover.cpp:451] Replica is in STARTING status > I0929 20:11:12.804592 17012 replica.cpp:638] Replica in STARTING status > received a broadcasted recover request > I0929 20:11:12.804775 17012 recover.cpp:188] Received a recover response from > a replica in STARTING status > I0929 20:11:12.804952 17012 recover.cpp:542] Updating replica status to VOTING > I0929 20:11:12.805115 17012 leveldb.cpp:306] Persisting metadata (8 bytes) to > leveldb took 15990ns > I0929 20:11:12.805234 17012 replica.cpp:320] Persisted replica status to > VOTING > I0929 20:11:12.805366 17012 recover.cpp:556] Successfully joined the Paxos > group > I0929 20:11:12.805539 17012 recover.cpp:440] Recover process terminated > I0929 20:11:12.809062 17017 master.cpp:312] Master > 20140929-201112-2759502016-47295-16997 (fedora-20) started on > 192.168.122.164:47295 > I0929 20:11:12.809432 17017 master.cpp:358] Master only allowing > authenticated frameworks to register > I0929 20:11:12.809546 17017 master.cpp:363] Master only allowing > authenticated slaves to register > I0929 20:11:12.810169 17017 credentials.hpp:36] Loading credentials for > authentication from > '/tmp/DRFAllocatorTest_DRFAllocatorProcess_igiR9X/credentials' > I0929 20:11:12.810510 17017 master.cpp:392] Authorization enabled > I0929 20:11:12.811841 17016 master.cpp:120] No whitelist given. Advertising > offers for all slaves > I0929 20:11:12.812099 17013 hierarchical_allocator_process.hpp:299] > Initializing hierarchical allocator process with master : > master@192.168.122.164:47295 > I0929 20:11:12.813006 17017 master.cpp:1241] The newly elected leader is > master@192.168.122.164:47295 with id 20140929-201112-2759502016-47295-16997 > I0929 20:11:12.813164 17017 master.cpp:1254] Elected as the leading master! > I0929 20:11:12.813279 17017 master.cpp:1072] Recovering from registrar > I0929 20:11:12.813487 17013 registrar.cpp:312] Recovering registrar > I0929 20:11:12.813824 17013 log.cpp:656] Attempting to start the writer > I0929 20:11:12.814256 17013 replica.cpp:474] Replica received implicit > promise request with proposal 1 > I0929 20:11:12.814419 17013 leveldb.cpp:306] Persisting metadata (8 bytes) to > leveldb took 25049ns > I0929 20:11:12.814581 17013 replica.cpp:342] Persisted promised to 1 > I0929 20:11:12.814909 17013 coordinator.cpp:230] Coordinator attemping to > fill missing position > I0929 20:11:12.815340 17013 replica.cpp:375] Replica received explicit > promise request for position 0 with proposal 2 > I0929 20:11:12.815497 17013 leveldb.cpp:343] Persisting action (8 bytes) to > leveldb took 19855ns > I0929 20:11:12.815636 17013 replica.cpp:676] Persisted action at 0 > I0929 20:11:12.816066 17013 replica.cpp:508] Replica received write request > for position 0 > I0929 20:11:12.816220 17013 leveldb.cpp:438] Reading position from leveldb > took 15731ns > I0929 20:11:12.816356 17013 leveldb.cpp:343] Persisting action (14 bytes) to > leveldb took 17814ns > I0929 20:11:12.816488 17013 replica.cpp:676] Persisted action at 0 > I0929 20:11:12.820883 17012 replica.cpp:655] Replica received learned notice > for position 0 > I0929 20:11:12.821038 17012 leveldb.cpp:343] Persisting action (16 bytes) to > leveldb took 22047ns > I0929 20:11:12.821261 17012 replica.cpp:676] Persisted action at 0 > I0929 20:11:12.821374 17012 replica.cpp:661] Replica learned NOP action at > position 0 > I0929 20:11:12.821724 17012 log.cpp:672] Writer started with ending position 0 > I0929 20:11:12.822145 17012 leveldb.cpp:438] Reading position from leveldb > took 13843ns > I0929 20:11:12.823463 17012 registrar.cpp:345] Successfully fetched the > registry (0B) > I0929 20:11:12.823686 17012 registrar.cpp:421] Attempting to update the > 'registry' > I0929 20:11:12.824872 17011 log.cpp:680] Attempting to append 131 bytes to > the log > I0929 20:11:12.825119 17011 coordinator.cpp:340] Coordinator attempting to > write APPEND action at position 1 > I0929 20:11:12.825507 17011 replica.cpp:508] Replica received write request > for position 1 > I0929 20:11:12.825734 17011 leveldb.cpp:343] Persisting action (150 bytes) to > leveldb took 22771ns > I0929 20:11:12.825917 17011 replica.cpp:676] Persisted action at 1 > I0929 20:11:12.827862 17016 replica.cpp:655] Replica received learned notice > for position 1 > I0929 20:11:12.828042 17016 leveldb.cpp:343] Persisting action (152 bytes) to > leveldb took 27499ns > I0929 20:11:12.828163 17016 replica.cpp:676] Persisted action at 1 > I0929 20:11:12.828304 17016 replica.cpp:661] Replica learned APPEND action at > position 1 > I0929 20:11:12.828604 17016 log.cpp:699] Attempting to truncate the log to 1 > I0929 20:11:12.828783 17016 coordinator.cpp:340] Coordinator attempting to > write TRUNCATE action at position 2 > I0929 20:11:12.829092 17016 replica.cpp:508] Replica received write request > for position 2 > I0929 20:11:12.829241 17016 leveldb.cpp:343] Persisting action (16 bytes) to > leveldb took 24041ns > I0929 20:11:12.829370 17016 replica.cpp:676] Persisted action at 2 > I0929 20:11:12.829731 17016 replica.cpp:655] Replica received learned notice > for position 2 > I0929 20:11:12.829942 17016 leveldb.cpp:343] Persisting action (18 bytes) to > leveldb took 41634ns > I0929 20:11:12.830106 17016 leveldb.cpp:401] Deleting ~1 keys from leveldb > took 17781ns > I0929 20:11:12.830235 17016 replica.cpp:676] Persisted action at 2 > I0929 20:11:12.830405 17016 replica.cpp:661] Replica learned TRUNCATE action > at position 2 > I0929 20:11:12.833751 17012 registrar.cpp:478] Successfully updated 'registry' > I0929 20:11:12.833909 17012 registrar.cpp:371] Successfully recovered > registrar > I0929 20:11:12.834215 17018 master.cpp:1099] Recovered 0 slaves from the > Registry (95B) ; allowing 10mins for slaves to re-register > I0929 20:11:12.845304 16997 containerizer.cpp:89] Using isolation: > posix/cpu,posix/mem > I0929 20:11:12.849077 17017 slave.cpp:169] Slave started on > 1)@192.168.122.164:47295 > I0929 20:11:12.849483 17017 credentials.hpp:84] Loading credential for > authentication from > '/tmp/DRFAllocatorTest_DRFAllocatorProcess_JKh7ij/credential' > I0929 20:11:12.849735 17017 slave.cpp:276] Slave using credential for: > test-principal > I0929 20:11:12.850129 17017 slave.cpp:289] Slave resources: cpus(*):2; > mem(*):1024; disk(*):0; ports(*):[31000-32000] > I0929 20:11:12.850781 17017 slave.cpp:317] Slave hostname: fedora-20 > I0929 20:11:12.850920 17017 slave.cpp:318] Slave checkpoint: false > I0929 20:11:12.851788 17016 state.cpp:33] Recovering state from > '/tmp/DRFAllocatorTest_DRFAllocatorProcess_JKh7ij/meta' > I0929 20:11:12.852089 17016 status_update_manager.cpp:193] Recovering status > update manager > I0929 20:11:12.852355 17016 containerizer.cpp:252] Recovering containerizer > I0929 20:11:12.852949 17016 slave.cpp:3271] Finished recovery > I0929 20:11:12.853415 17016 slave.cpp:598] New master detected at > master@192.168.122.164:47295 > I0929 20:11:12.853714 17016 slave.cpp:672] Authenticating with master > master@192.168.122.164:47295 > I0929 20:11:12.853927 17013 status_update_manager.cpp:167] New master > detected at master@192.168.122.164:47295 > I0929 20:11:12.854290 17018 authenticatee.hpp:104] Initializing client SASL > I0929 20:11:12.854616 17016 slave.cpp:645] Detecting new master > I0929 20:11:12.857573 16997 sched.cpp:137] Version: 0.21.0 > I0929 20:11:12.857925 17015 sched.cpp:233] New master detected at > master@192.168.122.164:47295 > I0929 20:11:12.858435 17015 sched.cpp:283] Authenticating with master > master@192.168.122.164:47295 > I0929 20:11:12.988668 17018 authenticatee.hpp:128] Creating new client SASL > connection > I0929 20:11:12.989294 17015 authenticatee.hpp:128] Creating new client SASL > connection > I0929 20:11:13.813364 17012 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:13.813910 17012 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 559406ns > I0929 20:11:14.814724 17012 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:14.815001 17012 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 279683ns > I0929 20:11:15.816067 17011 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:15.816335 17011 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 277524ns > I0929 20:11:16.816997 17017 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:16.817261 17017 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 316868ns > I0929 20:11:17.812933 17014 master.cpp:120] No whitelist given. Advertising > offers for all slaves > I0929 20:11:17.818584 17017 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:17.818758 17017 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 174122ns > W0929 20:11:17.855309 17011 slave.cpp:746] Authentication timed out > W0929 20:11:17.858809 17014 sched.cpp:378] Authentication timed out > I0929 20:11:18.819345 17011 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:18.819602 17011 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 261229ns > I0929 20:11:19.820294 17012 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:19.820873 17012 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 590879ns > I0929 20:11:20.821741 17011 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:20.822089 17011 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 354741ns > I0929 20:11:21.823289 17017 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:21.823717 17017 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 451454ns > I0929 20:11:22.814144 17014 master.cpp:120] No whitelist given. Advertising > offers for all slaves > I0929 20:11:22.823961 17017 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:22.824234 17017 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 277050ns > tests/allocator_tests.cpp:120: Failure > Failed to wait 10secs for offers1 > I0929 20:11:23.825175 17012 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:23.825216 17012 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 48326ns > W0929 20:11:24.783859 17015 slave.cpp:710] Failed to authenticate with master > master@192.168.122.164:47295: Authentication discarded > tests/allocator_tests.cpp:115: Failure > Actual function call count doesn't match EXPECT_CALL(sched1, > resourceOffers(_, _))... > Expected: to be called once > Actual: never called - unsatisfied and active > tests/allocator_tests.cpp:112: Failure > Actual function call count doesn't match EXPECT_CALL(sched1, registered(_, _, > _))... > Expected: to be called once > Actual: never called - unsatisfied and active > I0929 20:11:24.784392 17015 slave.cpp:672] Authenticating with master > master@192.168.122.164:47295 > tests/allocator_tests.cpp:94: Failure > Actual function call count doesn't match EXPECT_CALL(allocator, slaveAdded(_, > _, _))... > Expected: to be called once > Actual: never called - unsatisfied and active > tests/allocator_tests.cpp:110: Failure > Actual function call count doesn't match EXPECT_CALL(allocator, > frameworkAdded(_, _, _))... > Expected: to be called once > Actual: never called - unsatisfied and active > I0929 20:11:24.785089 17015 authenticatee.hpp:128] Creating new client SASL > connection > I0929 20:11:24.785411 17018 master.cpp:3737] Authenticating > slave(1)@192.168.122.164:47295 > I0929 20:11:24.785806 17017 authenticator.hpp:94] Initializing server SASL > I0929 20:11:24.786264 17018 master.cpp:676] Master terminating > I0929 20:11:24.788043 17017 auxprop.cpp:45] Initialized in-memory auxiliary > property plugin > I0929 20:11:24.793727 17018 slave.cpp:2430] master@192.168.122.164:47295 > exited > W0929 20:11:24.795372 17018 slave.cpp:2433] Master disconnected! Waiting for > a new master to be elected > *** Aborted at 1412046684 (unix time) try "date -d @1412046684" if you are > using GNU date *** > PC: @ 0x7f78d32e54a8 (unknown) > *** SIGSEGV (@0x7fffb4556d18) received by PID 16997 (TID 0x7f78d5c32880) from > PID 18446744072440081688; stack trace: *** > @ 0x7f78d3de3720 (unknown) > @ 0x7f78d32e54a8 (unknown) > @ 0x4bf626 > mesos::internal::master::allocator::Allocator::~Allocator() > @ 0x7b24a0 std::_Sp_counted_ptr<>::_M_dispose() > @ 0x4ce6b9 std::_Sp_counted_base<>::_M_release() > @ 0x4ce7d8 > mesos::internal::tests::Cluster::Masters::Master::~Master() > @ 0x4d1154 std::_Rb_tree<>::_M_erase() > @ 0x4fc43b mesos::internal::tests::Cluster::Masters::shutdown() > @ 0x7ac13d mesos::internal::tests::MesosTest::Shutdown() > @ 0x99ed33 > testing::internal::HandleExceptionsInMethodIfSupported<>() > @ 0x995fc0 testing::Test::Run() > @ 0x99609e testing::TestInfo::Run() > @ 0x9961a5 testing::TestCase::Run() > @ 0x996448 testing::internal::UnitTestImpl::RunAllTests() > @ 0x9966d7 testing::UnitTest::Run() > @ 0x49513b main > @ 0x7f78d296cd65 __libc_start_main > @ 0x4a4089 (unknown) > make[3]: *** [check-local] Segmentation fault (core dumped) > [ RUN ] DRFAllocatorTest.DRFAllocatorProcess > Using temporary directory '/tmp/DRFAllocatorTest_DRFAllocatorProcess_igiR9X' > I0929 20:11:12.801327 16997 leveldb.cpp:176] Opened db in 489720ns > I0929 20:11:12.801627 16997 leveldb.cpp:183] Compacted db in 168280ns > I0929 20:11:12.801784 16997 leveldb.cpp:198] Created db iterator in 5820ns > I0929 20:11:12.801898 16997 leveldb.cpp:204] Seeked to beginning of db in > 1285ns > I0929 20:11:12.802039 16997 leveldb.cpp:273] Iterated through 0 keys in the > db in 792ns > I0929 20:11:12.802160 16997 replica.cpp:741] Replica recovered with log > positions 0 -> 0 with 1 holes and 0 unlearned > I0929 20:11:12.802441 17012 recover.cpp:425] Starting replica recovery > I0929 20:11:12.802623 17012 recover.cpp:451] Replica is in EMPTY status > I0929 20:11:12.803251 17012 replica.cpp:638] Replica in EMPTY status received > a broadcasted recover request > I0929 20:11:12.803427 17012 recover.cpp:188] Received a recover response from > a replica in EMPTY status > I0929 20:11:12.803632 17012 recover.cpp:542] Updating replica status to > STARTING > I0929 20:11:12.803911 17012 leveldb.cpp:306] Persisting metadata (8 bytes) to > leveldb took 33999ns > I0929 20:11:12.804033 17012 replica.cpp:320] Persisted replica status to > STARTING > I0929 20:11:12.804245 17012 recover.cpp:451] Replica is in STARTING status > I0929 20:11:12.804592 17012 replica.cpp:638] Replica in STARTING status > received a broadcasted recover request > I0929 20:11:12.804775 17012 recover.cpp:188] Received a recover response from > a replica in STARTING status > I0929 20:11:12.804952 17012 recover.cpp:542] Updating replica status to VOTING > I0929 20:11:12.805115 17012 leveldb.cpp:306] Persisting metadata (8 bytes) to > leveldb took 15990ns > I0929 20:11:12.805234 17012 replica.cpp:320] Persisted replica status to > VOTING > I0929 20:11:12.805366 17012 recover.cpp:556] Successfully joined the Paxos > group > I0929 20:11:12.805539 17012 recover.cpp:440] Recover process terminated > I0929 20:11:12.809062 17017 master.cpp:312] Master > 20140929-201112-2759502016-47295-16997 (fedora-20) started on > 192.168.122.164:47295 > I0929 20:11:12.809432 17017 master.cpp:358] Master only allowing > authenticated frameworks to register > I0929 20:11:12.809546 17017 master.cpp:363] Master only allowing > authenticated slaves to register > I0929 20:11:12.810169 17017 credentials.hpp:36] Loading credentials for > authentication from > '/tmp/DRFAllocatorTest_DRFAllocatorProcess_igiR9X/credentials' > I0929 20:11:12.810510 17017 master.cpp:392] Authorization enabled > I0929 20:11:12.811841 17016 master.cpp:120] No whitelist given. Advertising > offers for all slaves > I0929 20:11:12.812099 17013 hierarchical_allocator_process.hpp:299] > Initializing hierarchical allocator process with master : > master@192.168.122.164:47295 > I0929 20:11:12.813006 17017 master.cpp:1241] The newly elected leader is > master@192.168.122.164:47295 with id 20140929-201112-2759502016-47295-16997 > I0929 20:11:12.813164 17017 master.cpp:1254] Elected as the leading master! > I0929 20:11:12.813279 17017 master.cpp:1072] Recovering from registrar > I0929 20:11:12.813487 17013 registrar.cpp:312] Recovering registrar > I0929 20:11:12.813824 17013 log.cpp:656] Attempting to start the writer > I0929 20:11:12.814256 17013 replica.cpp:474] Replica received implicit > promise request with proposal 1 > I0929 20:11:12.814419 17013 leveldb.cpp:306] Persisting metadata (8 bytes) to > leveldb took 25049ns > I0929 20:11:12.814581 17013 replica.cpp:342] Persisted promised to 1 > I0929 20:11:12.814909 17013 coordinator.cpp:230] Coordinator attemping to > fill missing position > I0929 20:11:12.815340 17013 replica.cpp:375] Replica received explicit > promise request for position 0 with proposal 2 > I0929 20:11:12.815497 17013 leveldb.cpp:343] Persisting action (8 bytes) to > leveldb took 19855ns > I0929 20:11:12.815636 17013 replica.cpp:676] Persisted action at 0 > I0929 20:11:12.816066 17013 replica.cpp:508] Replica received write request > for position 0 > I0929 20:11:12.816220 17013 leveldb.cpp:438] Reading position from leveldb > took 15731ns > I0929 20:11:12.816356 17013 leveldb.cpp:343] Persisting action (14 bytes) to > leveldb took 17814ns > I0929 20:11:12.816488 17013 replica.cpp:676] Persisted action at 0 > I0929 20:11:12.820883 17012 replica.cpp:655] Replica received learned notice > for position 0 > I0929 20:11:12.821038 17012 leveldb.cpp:343] Persisting action (16 bytes) to > leveldb took 22047ns > I0929 20:11:12.821261 17012 replica.cpp:676] Persisted action at 0 > I0929 20:11:12.821374 17012 replica.cpp:661] Replica learned NOP action at > position 0 > I0929 20:11:12.821724 17012 log.cpp:672] Writer started with ending position 0 > I0929 20:11:12.822145 17012 leveldb.cpp:438] Reading position from leveldb > took 13843ns > I0929 20:11:12.823463 17012 registrar.cpp:345] Successfully fetched the > registry (0B) > I0929 20:11:12.823686 17012 registrar.cpp:421] Attempting to update the > 'registry' > I0929 20:11:12.824872 17011 log.cpp:680] Attempting to append 131 bytes to > the log > I0929 20:11:12.825119 17011 coordinator.cpp:340] Coordinator attempting to > write APPEND action at position 1 > I0929 20:11:12.825507 17011 replica.cpp:508] Replica received write request > for position 1 > I0929 20:11:12.825734 17011 leveldb.cpp:343] Persisting action (150 bytes) to > leveldb took 22771ns > I0929 20:11:12.825917 17011 replica.cpp:676] Persisted action at 1 > I0929 20:11:12.827862 17016 replica.cpp:655] Replica received learned notice > for position 1 > I0929 20:11:12.828042 17016 leveldb.cpp:343] Persisting action (152 bytes) to > leveldb took 27499ns > I0929 20:11:12.828163 17016 replica.cpp:676] Persisted action at 1 > I0929 20:11:12.828304 17016 replica.cpp:661] Replica learned APPEND action at > position 1 > I0929 20:11:12.828604 17016 log.cpp:699] Attempting to truncate the log to 1 > I0929 20:11:12.828783 17016 coordinator.cpp:340] Coordinator attempting to > write TRUNCATE action at position 2 > I0929 20:11:12.829092 17016 replica.cpp:508] Replica received write request > for position 2 > I0929 20:11:12.829241 17016 leveldb.cpp:343] Persisting action (16 bytes) to > leveldb took 24041ns > I0929 20:11:12.829370 17016 replica.cpp:676] Persisted action at 2 > I0929 20:11:12.829731 17016 replica.cpp:655] Replica received learned notice > for position 2 > I0929 20:11:12.829942 17016 leveldb.cpp:343] Persisting action (18 bytes) to > leveldb took 41634ns > I0929 20:11:12.830106 17016 leveldb.cpp:401] Deleting ~1 keys from leveldb > took 17781ns > I0929 20:11:12.830235 17016 replica.cpp:676] Persisted action at 2 > I0929 20:11:12.830405 17016 replica.cpp:661] Replica learned TRUNCATE action > at position 2 > I0929 20:11:12.833751 17012 registrar.cpp:478] Successfully updated 'registry' > I0929 20:11:12.833909 17012 registrar.cpp:371] Successfully recovered > registrar > I0929 20:11:12.834215 17018 master.cpp:1099] Recovered 0 slaves from the > Registry (95B) ; allowing 10mins for slaves to re-register > I0929 20:11:12.845304 16997 containerizer.cpp:89] Using isolation: > posix/cpu,posix/mem > I0929 20:11:12.849077 17017 slave.cpp:169] Slave started on > 1)@192.168.122.164:47295 > I0929 20:11:12.849483 17017 credentials.hpp:84] Loading credential for > authentication from > '/tmp/DRFAllocatorTest_DRFAllocatorProcess_JKh7ij/credential' > I0929 20:11:12.849735 17017 slave.cpp:276] Slave using credential for: > test-principal > I0929 20:11:12.850129 17017 slave.cpp:289] Slave resources: cpus(*):2; > mem(*):1024; disk(*):0; ports(*):[31000-32000] > I0929 20:11:12.850781 17017 slave.cpp:317] Slave hostname: fedora-20 > I0929 20:11:12.850920 17017 slave.cpp:318] Slave checkpoint: false > I0929 20:11:12.851788 17016 state.cpp:33] Recovering state from > '/tmp/DRFAllocatorTest_DRFAllocatorProcess_JKh7ij/meta' > I0929 20:11:12.852089 17016 status_update_manager.cpp:193] Recovering status > update manager > I0929 20:11:12.852355 17016 containerizer.cpp:252] Recovering containerizer > I0929 20:11:12.852949 17016 slave.cpp:3271] Finished recovery > I0929 20:11:12.853415 17016 slave.cpp:598] New master detected at > master@192.168.122.164:47295 > I0929 20:11:12.853714 17016 slave.cpp:672] Authenticating with master > master@192.168.122.164:47295 > I0929 20:11:12.853927 17013 status_update_manager.cpp:167] New master > detected at master@192.168.122.164:47295 > I0929 20:11:12.854290 17018 authenticatee.hpp:104] Initializing client SASL > I0929 20:11:12.854616 17016 slave.cpp:645] Detecting new master > I0929 20:11:12.857573 16997 sched.cpp:137] Version: 0.21.0 > I0929 20:11:12.857925 17015 sched.cpp:233] New master detected at > master@192.168.122.164:47295 > I0929 20:11:12.858435 17015 sched.cpp:283] Authenticating with master > master@192.168.122.164:47295 > I0929 20:11:12.988668 17018 authenticatee.hpp:128] Creating new client SASL > connection > I0929 20:11:12.989294 17015 authenticatee.hpp:128] Creating new client SASL > connection > I0929 20:11:13.813364 17012 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:13.813910 17012 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 559406ns > I0929 20:11:14.814724 17012 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:14.815001 17012 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 279683ns > I0929 20:11:15.816067 17011 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:15.816335 17011 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 277524ns > I0929 20:11:16.816997 17017 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:16.817261 17017 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 316868ns > I0929 20:11:17.812933 17014 master.cpp:120] No whitelist given. Advertising > offers for all slaves > I0929 20:11:17.818584 17017 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:17.818758 17017 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 174122ns > W0929 20:11:17.855309 17011 slave.cpp:746] Authentication timed out > W0929 20:11:17.858809 17014 sched.cpp:378] Authentication timed out > I0929 20:11:18.819345 17011 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:18.819602 17011 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 261229ns > I0929 20:11:19.820294 17012 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:19.820873 17012 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 590879ns > I0929 20:11:20.821741 17011 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:20.822089 17011 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 354741ns > I0929 20:11:21.823289 17017 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:21.823717 17017 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 451454ns > I0929 20:11:22.814144 17014 master.cpp:120] No whitelist given. Advertising > offers for all slaves > I0929 20:11:22.823961 17017 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:22.824234 17017 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 277050ns > tests/allocator_tests.cpp:120: Failure > Failed to wait 10secs for offers1 > I0929 20:11:23.825175 17012 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0929 20:11:23.825216 17012 hierarchical_allocator_process.hpp:659] Performed > allocation for 0 slaves in 48326ns > W0929 20:11:24.783859 17015 slave.cpp:710] Failed to authenticate with master > master@192.168.122.164:47295: Authentication discarded > tests/allocator_tests.cpp:115: Failure > Actual function call count doesn't match EXPECT_CALL(sched1, > resourceOffers(_, _))... > Expected: to be called once > Actual: never called - unsatisfied and active > tests/allocator_tests.cpp:112: Failure > Actual function call count doesn't match EXPECT_CALL(sched1, registered(_, _, > _))... > Expected: to be called once > Actual: never called - unsatisfied and active > I0929 20:11:24.784392 17015 slave.cpp:672] Authenticating with master > master@192.168.122.164:47295 > tests/allocator_tests.cpp:94: Failure > Actual function call count doesn't match EXPECT_CALL(allocator, slaveAdded(_, > _, _))... > Expected: to be called once > Actual: never called - unsatisfied and active > tests/allocator_tests.cpp:110: Failure > Actual function call count doesn't match EXPECT_CALL(allocator, > frameworkAdded(_, _, _))... > Expected: to be called once > Actual: never called - unsatisfied and active > I0929 20:11:24.785089 17015 authenticatee.hpp:128] Creating new client SASL > connection > I0929 20:11:24.785411 17018 master.cpp:3737] Authenticating > slave(1)@192.168.122.164:47295 > I0929 20:11:24.785806 17017 authenticator.hpp:94] Initializing server SASL > I0929 20:11:24.786264 17018 master.cpp:676] Master terminating > I0929 20:11:24.788043 17017 auxprop.cpp:45] Initialized in-memory auxiliary > property plugin > I0929 20:11:24.793727 17018 slave.cpp:2430] master@192.168.122.164:47295 > exited > W0929 20:11:24.795372 17018 slave.cpp:2433] Master disconnected! Waiting for > a new master to be elected > *** Aborted at 1412046684 (unix time) try "date -d @1412046684" if you are > using GNU date *** > PC: @ 0x7f78d32e54a8 (unknown) > *** SIGSEGV (@0x7fffb4556d18) received by PID 16997 (TID 0x7f78d5c32880) from > PID 18446744072440081688; stack trace: *** > @ 0x7f78d3de3720 (unknown) > @ 0x7f78d32e54a8 (unknown) > @ 0x4bf626 > mesos::internal::master::allocator::Allocator::~Allocator() > @ 0x7b24a0 std::_Sp_counted_ptr<>::_M_dispose() > @ 0x4ce6b9 std::_Sp_counted_base<>::_M_release() > @ 0x4ce7d8 > mesos::internal::tests::Cluster::Masters::Master::~Master() > @ 0x4d1154 std::_Rb_tree<>::_M_erase() > @ 0x4fc43b mesos::internal::tests::Cluster::Masters::shutdown() > @ 0x7ac13d mesos::internal::tests::MesosTest::Shutdown() > @ 0x99ed33 > testing::internal::HandleExceptionsInMethodIfSupported<>() > @ 0x995fc0 testing::Test::Run() > @ 0x99609e testing::TestInfo::Run() > @ 0x9961a5 testing::TestCase::Run() > @ 0x996448 testing::internal::UnitTestImpl::RunAllTests() > @ 0x9966d7 testing::UnitTest::Run() > @ 0x49513b main > @ 0x7f78d296cd65 __libc_start_main > @ 0x4a4089 (unknown) > make[3]: *** [check-local] Segmentation fault (core dumped) > {code} -- This message was sent by Atlassian JIRA (v6.3.4#6332)