Taking a look. On Wed, Oct 22, 2014 at 4:50 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/2473/changes > > > > Changes: > > [dhamon] Differentiate between slave and offer ids > > ------------------------------------------ > [...truncated 25823 lines...] > I1022 23:49:58.784020 28603 master.cpp:363] Master only allowing > authenticated slaves to register > I1022 23:49:58.784030 28603 credentials.hpp:36] Loading credentials for > authentication from > '/tmp/ReconciliationTest_UnacknowledgedTerminalTask_VbLvU8/credentials' > I1022 23:49:58.784097 28608 leveldb.cpp:306] Persisting metadata (8 bytes) > to leveldb took 1.060798ms > I1022 23:49:58.784119 28608 replica.cpp:320] Persisted replica status to > STARTING > I1022 23:49:58.784139 28603 master.cpp:392] Authorization enabled > I1022 23:49:58.784201 28608 recover.cpp:463] Replica is in STARTING status > I1022 23:49:58.784397 28608 master.cpp:120] No whitelist given. > Advertising offers for all slaves > I1022 23:49:58.784747 28611 hierarchical_allocator_process.hpp:299] > Initializing hierarchical allocator process with master : > [email protected]:36297 > I1022 23:49:58.784898 28613 master.cpp:1242] The newly elected leader is > [email protected]:36297 with id 20141022-234958-3142697795-36297-28588 > I1022 23:49:58.784914 28613 master.cpp:1255] Elected as the leading master! > I1022 23:49:58.784924 28613 master.cpp:1073] Recovering from registrar > I1022 23:49:58.784926 28611 replica.cpp:638] Replica in STARTING status > received a broadcasted recover request > I1022 23:49:58.784993 28613 registrar.cpp:313] Recovering registrar > I1022 23:49:58.785223 28611 recover.cpp:188] Received a recover response > from a replica in STARTING status > I1022 23:49:58.785341 28611 recover.cpp:554] Updating replica status to > VOTING > I1022 23:49:58.785760 28611 leveldb.cpp:306] Persisting metadata (8 bytes) > to leveldb took 333269ns > I1022 23:49:58.785778 28611 replica.cpp:320] Persisted replica status to > VOTING > I1022 23:49:58.785825 28611 recover.cpp:568] Successfully joined the Paxos > group > I1022 23:49:58.785892 28611 recover.cpp:452] Recover process terminated > I1022 23:49:58.786036 28611 log.cpp:656] Attempting to start the writer > I1022 23:49:58.786501 28606 replica.cpp:474] Replica received implicit > promise request with proposal 1 > I1022 23:49:58.786792 28606 leveldb.cpp:306] Persisting metadata (8 bytes) > to leveldb took 271018ns > I1022 23:49:58.786810 28606 replica.cpp:342] Persisted promised to 1 > I1022 23:49:58.787049 28606 coordinator.cpp:230] Coordinator attemping to > fill missing position > I1022 23:49:58.787730 28610 replica.cpp:375] Replica received explicit > promise request for position 0 with proposal 2 > I1022 23:49:58.788100 28610 leveldb.cpp:343] Persisting action (8 bytes) > to leveldb took 347683ns > I1022 23:49:58.788116 28610 replica.cpp:676] Persisted action at 0 > I1022 23:49:58.788492 28610 replica.cpp:508] Replica received write > request for position 0 > I1022 23:49:58.788524 28610 leveldb.cpp:438] Reading position from leveldb > took 16351ns > I1022 23:49:58.788832 28610 leveldb.cpp:343] Persisting action (14 bytes) > to leveldb took 288220ns > I1022 23:49:58.788848 28610 replica.cpp:676] Persisted action at 0 > I1022 23:49:58.789029 28610 replica.cpp:655] Replica received learned > notice for position 0 > I1022 23:49:58.789222 28610 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 176617ns > I1022 23:49:58.789238 28610 replica.cpp:676] Persisted action at 0 > I1022 23:49:58.789247 28610 replica.cpp:661] Replica learned NOP action at > position 0 > I1022 23:49:58.789477 28610 log.cpp:672] Writer started with ending > position 0 > I1022 23:49:58.789831 28610 leveldb.cpp:438] Reading position from leveldb > took 11010ns > I1022 23:49:58.791254 28610 registrar.cpp:346] Successfully fetched the > registry (0B) in 6.239744ms > I1022 23:49:58.791309 28610 registrar.cpp:445] Applied 1 operations in > 4398ns; attempting to update the 'registry' > I1022 23:49:58.792754 28610 log.cpp:680] Attempting to append 139 bytes to > the log > I1022 23:49:58.792817 28610 coordinator.cpp:340] Coordinator attempting to > write APPEND action at position 1 > I1022 23:49:58.793117 28610 replica.cpp:508] Replica received write > request for position 1 > I1022 23:49:58.793505 28610 leveldb.cpp:343] Persisting action (158 bytes) > to leveldb took 368961ns > I1022 23:49:58.793524 28610 replica.cpp:676] Persisted action at 1 > I1022 23:49:58.793771 28610 replica.cpp:655] Replica received learned > notice for position 1 > I1022 23:49:58.794075 28610 leveldb.cpp:343] Persisting action (160 bytes) > to leveldb took 288311ns > I1022 23:49:58.794092 28610 replica.cpp:676] Persisted action at 1 > I1022 23:49:58.794102 28610 replica.cpp:661] Replica learned APPEND action > at position 1 > I1022 23:49:58.794467 28610 registrar.cpp:490] Successfully updated the > 'registry' in 3.129088ms > I1022 23:49:58.794522 28610 registrar.cpp:376] Successfully recovered > registrar > I1022 23:49:58.794577 28610 log.cpp:699] Attempting to truncate the log to > 1 > I1022 23:49:58.794663 28610 master.cpp:1100] Recovered 0 slaves from the > Registry (101B) ; allowing 10mins for slaves to re-register > I1022 23:49:58.794705 28610 coordinator.cpp:340] Coordinator attempting to > write TRUNCATE action at position 2 > I1022 23:49:58.794883 28610 replica.cpp:508] Replica received write > request for position 2 > I1022 23:49:58.795156 28610 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 260060ns > I1022 23:49:58.795169 28610 replica.cpp:676] Persisted action at 2 > I1022 23:49:58.795477 28617 replica.cpp:655] Replica received learned > notice for position 2 > I1022 23:49:58.795795 28617 leveldb.cpp:343] Persisting action (18 bytes) > to leveldb took 298268ns > I1022 23:49:59.009078 28617 leveldb.cpp:401] Deleting ~1 keys from leveldb > took 62645ns > I1022 23:49:59.009115 28617 replica.cpp:676] Persisted action at 2 > I1022 23:49:59.009127 28617 replica.cpp:661] Replica learned TRUNCATE > action at position 2 > I1022 23:49:59.019134 28616 slave.cpp:169] Slave started on 92)@ > 67.195.81.187:36297 > I1022 23:49:59.019175 28616 credentials.hpp:84] Loading credential for > authentication from > '/tmp/ReconciliationTest_UnacknowledgedTerminalTask_7XsYHG/credential' > I1022 23:49:59.019275 28616 slave.cpp:276] Slave using credential for: > test-principal > I1022 23:49:59.019410 28616 slave.cpp:289] Slave resources: cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] > I1022 23:49:59.019479 28616 slave.cpp:318] Slave hostname: > pomona.apache.org > I1022 23:49:59.019490 28616 slave.cpp:319] Slave checkpoint: false > I1022 23:49:59.019891 28606 state.cpp:33] Recovering state from > '/tmp/ReconciliationTest_UnacknowledgedTerminalTask_7XsYHG/meta' > I1022 23:49:59.020009 28606 status_update_manager.cpp:197] Recovering > status update manager > I1022 23:49:59.020110 28606 slave.cpp:3437] Finished recovery > I1022 23:49:59.020411 28606 slave.cpp:597] New master detected at > [email protected]:36297 > I1022 23:49:59.020434 28606 slave.cpp:660] Authenticating with master > [email protected]:36297 > I1022 23:49:59.020488 28606 slave.cpp:633] Detecting new master > I1022 23:49:59.020531 28606 status_update_manager.cpp:171] Pausing sending > status updates > I1022 23:49:59.020570 28606 authenticatee.hpp:133] Creating new client > SASL connection > I1022 23:49:59.020679 28606 master.cpp:3847] Authenticating slave(92)@ > 67.195.81.187:36297 > I1022 23:49:59.020791 28606 authenticator.hpp:161] Creating new server > SASL connection > I1022 23:49:59.020864 28606 authenticatee.hpp:224] Received SASL > authentication mechanisms: CRAM-MD5 > I1022 23:49:59.020884 28606 authenticatee.hpp:250] Attempting to > authenticate with mechanism 'CRAM-MD5' > I1022 23:49:59.020989 28617 authenticator.hpp:267] Received SASL > authentication start > I1022 23:49:59.021031 28617 authenticator.hpp:389] Authentication requires > more steps > I1022 23:49:59.021119 28617 authenticatee.hpp:270] Received SASL > authentication step > I1022 23:49:59.021214 28617 authenticator.hpp:295] Received SASL > authentication step > I1022 23:49:59.021236 28617 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'pomona.apache.org' server FQDN: ' > pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false > I1022 23:49:59.021247 28617 auxprop.cpp:153] Looking up auxiliary property > '*userPassword' > I1022 23:49:59.021262 28617 auxprop.cpp:153] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I1022 23:49:59.021275 28617 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'pomona.apache.org' server FQDN: ' > pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true > I1022 23:49:59.021292 28617 auxprop.cpp:103] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I1022 23:49:59.021301 28617 auxprop.cpp:103] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I1022 23:49:59.021317 28617 authenticator.hpp:381] Authentication success > I1022 23:49:59.021363 28606 authenticatee.hpp:310] Authentication success > I1022 23:49:59.021374 28617 master.cpp:3887] Successfully authenticated > principal 'test-principal' at slave(92)@67.195.81.187:36297 > I1022 23:49:59.021438 28606 slave.cpp:717] Successfully authenticated with > master [email protected]:36297 > I1022 23:49:59.021492 28606 slave.cpp:1045] Will retry registration in > 942597ns if necessary > I1022 23:49:59.021574 28606 master.cpp:3026] Registering slave at > slave(92)@67.195.81.187:36297 (pomona.apache.org) with id > 20141022-234958-3142697795-36297-28588-S0 > I1022 23:49:59.021716 28606 registrar.cpp:445] Applied 1 operations in > 14399ns; attempting to update the 'registry' > I1022 23:49:59.022148 28588 sched.cpp:137] Version: 0.21.0 > I1022 23:49:59.022495 28605 sched.cpp:233] New master detected at > [email protected]:36297 > I1022 23:49:59.022516 28605 sched.cpp:283] Authenticating with master > [email protected]:36297 > I1022 23:49:59.022589 28608 authenticatee.hpp:133] Creating new client > SASL connection > I1022 23:49:59.022703 28604 slave.cpp:1045] Will retry registration in > 5.737624ms if necessary > I1022 23:49:59.022712 28608 master.cpp:3847] Authenticating > [email protected]:36297 > I1022 23:49:59.022814 28611 authenticator.hpp:161] Creating new server > SASL connection > I1022 23:49:59.022835 28608 master.cpp:3014] Ignoring register slave > message from slave(92)@67.195.81.187:36297 (pomona.apache.org) as > admission is already in progress > I1022 23:49:59.022878 28608 authenticatee.hpp:224] Received SASL > authentication mechanisms: CRAM-MD5 > I1022 23:49:59.022894 28608 authenticatee.hpp:250] Attempting to > authenticate with mechanism 'CRAM-MD5' > I1022 23:49:59.022933 28608 authenticator.hpp:267] Received SASL > authentication start > I1022 23:49:59.022969 28608 authenticator.hpp:389] Authentication requires > more steps > I1022 23:49:59.023084 28602 authenticatee.hpp:270] Received SASL > authentication step > I1022 23:49:59.023161 28612 authenticator.hpp:295] Received SASL > authentication step > I1022 23:49:59.023182 28612 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'pomona.apache.org' server FQDN: ' > pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false > I1022 23:49:59.023185 28613 log.cpp:680] Attempting to append 316 bytes to > the log > I1022 23:49:59.023191 28612 auxprop.cpp:153] Looking up auxiliary property > '*userPassword' > I1022 23:49:59.023203 28612 auxprop.cpp:153] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I1022 23:49:59.023214 28612 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'pomona.apache.org' server FQDN: ' > pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true > I1022 23:49:59.023222 28612 auxprop.cpp:103] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I1022 23:49:59.023228 28612 auxprop.cpp:103] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I1022 23:49:59.023241 28612 authenticator.hpp:381] Authentication success > I1022 23:49:59.023252 28611 coordinator.cpp:340] Coordinator attempting to > write APPEND action at position 3 > I1022 23:49:59.023316 28602 master.cpp:3887] Successfully authenticated > principal 'test-principal' at > [email protected]:36297 > I1022 23:49:59.023345 28603 authenticatee.hpp:310] Authentication success > I1022 23:49:59.023476 28612 sched.cpp:357] Successfully authenticated with > master [email protected]:36297 > I1022 23:49:59.023494 28612 sched.cpp:476] Sending registration request to > [email protected]:36297 > I1022 23:49:59.023669 28607 replica.cpp:508] Replica received write > request for position 3 > I1022 23:49:59.023797 28605 master.cpp:1362] Received registration request > for framework 'default' at > [email protected]:36297 > I1022 23:49:59.023816 28605 master.cpp:1321] Authorizing framework > principal 'test-principal' to receive offers for role '*' > I1022 23:49:59.023967 28614 master.cpp:1426] Registering framework > 20141022-234958-3142697795-36297-28588-0000 (default) at > [email protected]:36297 > I1022 23:49:59.024065 28613 hierarchical_allocator_process.hpp:329] Added > framework 20141022-234958-3142697795-36297-28588-0000 > I1022 23:49:59.024082 28613 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I1022 23:49:59.024091 28613 hierarchical_allocator_process.hpp:659] > Performed allocation for 0 slaves in 9093ns > I1022 23:49:59.024139 28613 sched.cpp:407] Framework registered with > 20141022-234958-3142697795-36297-28588-0000 > I1022 23:49:59.137439 28613 sched.cpp:421] Scheduler::registered took > 63837ns > I1022 23:49:59.029038 28606 slave.cpp:1045] Will retry registration in > 28.855729ms if necessary > I1022 23:49:59.024247 28607 leveldb.cpp:343] Persisting action (335 bytes) > to leveldb took 560041ns > I1022 23:49:59.029153 28605 master.cpp:3014] Ignoring register slave > message from slave(92)@67.195.81.187:36297 (pomona.apache.org) as > admission is already in progress > I1022 23:49:59.137543 28607 replica.cpp:676] Persisted action at 3 > I1022 23:49:59.138083 28606 replica.cpp:655] Replica received learned > notice for position 3 > I1022 23:49:59.138620 28606 leveldb.cpp:343] Persisting action (337 bytes) > to leveldb took 517056ns > I1022 23:49:59.138638 28606 replica.cpp:676] Persisted action at 3 > I1022 23:49:59.138649 28606 replica.cpp:661] Replica learned APPEND action > at position 3 > I1022 23:49:59.139158 28613 registrar.cpp:490] Successfully updated the > 'registry' in 117.417216ms > I1022 23:49:59.139292 28611 log.cpp:699] Attempting to truncate the log to > 3 > I1022 23:49:59.139355 28603 coordinator.cpp:340] Coordinator attempting to > write TRUNCATE action at position 4 > I1022 23:49:59.139505 28615 master.cpp:3080] Registered slave > 20141022-234958-3142697795-36297-28588-S0 at slave(92)@67.195.81.187:36297 > (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000] > I1022 23:49:59.139513 28611 hierarchical_allocator_process.hpp:442] Added > slave 20141022-234958-3142697795-36297-28588-S0 (pomona.apache.org) with > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) > I1022 23:49:59.139598 28611 hierarchical_allocator_process.hpp:734] > Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on > slave 20141022-234958-3142697795-36297-28588-S0 to framework > 20141022-234958-3142697795-36297-28588-0000 > I1022 23:49:59.139669 28604 slave.cpp:2517] Received ping from > slave-observer(89)@67.195.81.187:36297 > I1022 23:49:59.139720 28607 replica.cpp:508] Replica received write > request for position 4 > I1022 23:49:59.139740 28604 slave.cpp:751] Registered with master > [email protected]:36297; given slave ID > 20141022-234958-3142697795-36297-28588-S0 > I1022 23:49:59.139801 28611 hierarchical_allocator_process.hpp:679] > Performed allocation for slave 20141022-234958-3142697795-36297-28588-S0 in > 235887ns > I1022 23:49:59.139806 28613 status_update_manager.cpp:178] Resuming > sending status updates > I1022 23:49:59.139919 28617 master.cpp:3789] Sending 1 offers to framework > 20141022-234958-3142697795-36297-28588-0000 (default) at > [email protected]:36297 > I1022 23:49:59.140096 28607 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 350458ns > I1022 23:49:59.140111 28607 replica.cpp:676] Persisted action at 4 > I1022 23:49:59.140264 28617 sched.cpp:544] Scheduler::resourceOffers took > 182145ns > I1022 23:49:59.140290 28607 replica.cpp:655] Replica received learned > notice for position 4 > I1022 23:49:59.140535 28617 master.cpp:2315] Processing reply for offers: > [ 20141022-234958-3142697795-36297-28588-O0 ] on slave > 20141022-234958-3142697795-36297-28588-S0 at slave(92)@67.195.81.187:36297 > (pomona.apache.org) for framework > 20141022-234958-3142697795-36297-28588-0000 (default) at > [email protected]:36297 > I1022 23:49:59.140576 28607 leveldb.cpp:343] Persisting action (18 bytes) > to leveldb took 271109ns > W1022 23:49:59.140578 28617 master.cpp:1969] Executor default for task 0 > uses less CPUs (None) than the minimum required (0.01). Please update your > executor, as this will be mandatory in future releases. > W1022 23:49:59.140604 28617 master.cpp:1980] Executor default for task 0 > uses less memory (None) than the minimum required (32MB). Please update > your executor, as this will be mandatory in future releases. > I1022 23:49:59.140612 28607 leveldb.cpp:401] Deleting ~2 keys from leveldb > took 19045ns > I1022 23:49:59.140627 28607 replica.cpp:676] Persisted action at 4 > I1022 23:49:59.140632 28617 master.cpp:2411] Authorizing framework > principal 'test-principal' to launch task 0 as user 'jenkins' > I1022 23:49:59.140637 28607 replica.cpp:661] Replica learned TRUNCATE > action at position 4 > I1022 23:49:59.140949 28617 master.hpp:877] Adding task 0 with resources > cpus(*):1; mem(*):512 on slave 20141022-234958-3142697795-36297-28588-S0 ( > pomona.apache.org) > I1022 23:49:59.140985 28617 master.cpp:2474] Launching task 0 of > framework 20141022-234958-3142697795-36297-28588-0000 (default) at > [email protected]:36297 with > resources cpus(*):1; mem(*):512 on slave > 20141022-234958-3142697795-36297-28588-S0 at slave(92)@67.195.81.187:36297 > (pomona.apache.org) > I1022 23:49:59.141108 28604 slave.cpp:1076] Got assigned task 0 for > framework 20141022-234958-3142697795-36297-28588-0000 > I1022 23:49:59.141242 28609 hierarchical_allocator_process.hpp:563] > Recovered cpus(*):1; mem(*):512; disk(*):1024; ports(*):[31000-32000] > (total allocatable: cpus(*):1; mem(*):512; disk(*):1024; > ports(*):[31000-32000]) on slave 20141022-234958-3142697795-36297-28588-S0 > from framework 20141022-234958-3142697795-36297-28588-0000 > I1022 23:49:59.141288 28609 hierarchical_allocator_process.hpp:599] > Framework 20141022-234958-3142697795-36297-28588-0000 filtered slave > 20141022-234958-3142697795-36297-28588-S0 for 5secs > I1022 23:49:59.141373 28604 slave.cpp:1186] Launching task 0 for framework > 20141022-234958-3142697795-36297-28588-0000 > I1022 23:49:59.142989 28604 slave.cpp:3852] Launching executor default of > framework 20141022-234958-3142697795-36297-28588-0000 in work directory > '/tmp/ReconciliationTest_UnacknowledgedTerminalTask_7XsYHG/slaves/20141022-234958-3142697795-36297-28588-S0/frameworks/20141022-234958-3142697795-36297-28588-0000/executors/default/runs/ab333897-e649-4960-8580-9dcff92b63ec' > I1022 23:49:59.144456 28604 exec.cpp:132] Version: 0.21.0 > I1022 23:49:59.144541 28617 exec.cpp:182] Executor started at: > executor(34)@67.195.81.187:36297 with pid 28588 > I1022 23:49:59.144598 28604 slave.cpp:1312] Queuing task '0' for executor > default of framework '20141022-234958-3142697795-36297-28588-0000 > I1022 23:49:59.144649 28604 slave.cpp:550] Successfully attached file > '/tmp/ReconciliationTest_UnacknowledgedTerminalTask_7XsYHG/slaves/20141022-234958-3142697795-36297-28588-S0/frameworks/20141022-234958-3142697795-36297-28588-0000/executors/default/runs/ab333897-e649-4960-8580-9dcff92b63ec' > I1022 23:49:59.144696 28604 slave.cpp:2783] Monitoring executor 'default' > of framework '20141022-234958-3142697795-36297-28588-0000' in container > 'ab333897-e649-4960-8580-9dcff92b63ec' > I1022 23:49:59.144783 28604 slave.cpp:1844] Got registration for executor > 'default' of framework 20141022-234958-3142697795-36297-28588-0000 from > executor(34)@67.195.81.187:36297 > I1022 23:49:59.144930 28604 slave.cpp:1963] Flushing queued task 0 for > executor 'default' of framework 20141022-234958-3142697795-36297-28588-0000 > I1022 23:49:59.144966 28617 exec.cpp:206] Executor registered on slave > 20141022-234958-3142697795-36297-28588-S0 > I1022 23:49:59.145961 28617 exec.cpp:218] Executor::registered took 15657ns > I1022 23:49:59.146023 28617 exec.cpp:293] Executor asked to run task '0' > I1022 23:49:59.146060 28617 exec.cpp:302] Executor::launchTask took 24526ns > I1022 23:49:59.146951 28617 exec.cpp:525] Executor sending status update > TASK_FINISHED (UUID: 9eedb006-7959-48e3-bd57-b460298fc842) for task 0 of > framework 20141022-234958-3142697795-36297-28588-0000 > I1022 23:49:59.147037 28617 slave.cpp:2197] Handling status update > TASK_FINISHED (UUID: 9eedb006-7959-48e3-bd57-b460298fc842) for task 0 of > framework 20141022-234958-3142697795-36297-28588-0000 from executor(34)@ > 67.195.81.187:36297 > I1022 23:49:59.147059 28617 slave.cpp:4160] Terminating task 0 > I../../src/tests/reconciliation_tests.cpp:720: Failure > Failed to wait 10secs for update1 > ../../src/tests/reconciliation_tests.cpp:703: Failure > Actual function call count doesn't match EXPECT_CALL(sched, > statusUpdate(&driver, _))... > Expected: to be called once > 1022 23:49:59.147155 28617 status_update_manager.cpp:317] Received status > update TASK_FINISHED (UUID: 9eedb006-7959-48e3-bd57-b460298fc842) for task > 0 of framework 20141022-234958-3142697795-36297-28588-0000 > Actual: never called - unsatisfied and active > I1022 23:50:09.380831 28617 status_update_manager.cpp:494] Creating > StatusUpdate stream for task 0 of framework > 20141022-234958-3142697795-36297-28588-0000 > I1022 23:50:03.785439 28613 master.cpp:120] No whitelist given. > Advertising offers for all slaves > I1022 23:50:09.380949 28617 status_update_manager.cpp:371] Forwarding > update TASK_FINISHED (UUID: 9eedb006-7959-48e3-bd57-b460298fc842) for task > 0 of framework 20141022-234958-3142697795-36297-28588-0000 to the slave > I1022 23:50:09.380975 28606 master.cpp:768] Framework > 20141022-234958-3142697795-36297-28588-0000 (default) at > [email protected]:36297 > disconnected > I1022 23:49:59.785217 28602 hierarchical_allocator_process.hpp:816] > Filtered cpus(*):1; mem(*):512; disk(*):1024; ports(*):[31000-32000] on > slave 20141022-234958-3142697795-36297-28588-S0 for framework > 20141022-234958-3142697795-36297-28588-0000 > I1022 23:50:09.380996 28606 master.cpp:1731] Disconnecting framework > 20141022-234958-3142697795-36297-28588-0000 (default) at > [email protected]:36297 > I1022 23:50:09.381009 28606 master.cpp:1747] Deactivating framework > 20141022-234958-3142697795-36297-28588-0000 (default) at > [email protected]:36297 > I1022 23:50:09.381032 28606 master.cpp:790] Giving framework > 20141022-234958-3142697795-36297-28588-0000 (default) at > [email protected]:36297 0ns to > failover > I1022 23:50:09.381029 28602 hierarchical_allocator_process.hpp:659] > Performed allocation for 1 slaves in 9.59591129secs > I1022 23:50:09.381116 28602 hierarchical_allocator_process.hpp:405] > Deactivated framework 20141022-234958-3142697795-36297-28588-0000 > I1022 23:50:09.381554 28606 slave.cpp:2437] Forwarding the update > TASK_FINISHED (UUID: 9eedb006-7959-48e3-bd57-b460298fc842) for task 0 of > framework 20141022-234958-3142697795-36297-28588-0000 to > [email protected]:36297 > I1022 23:50:09.381731 28615 master.cpp:3659] Framework failover timeout, > removing framework 20141022-234958-3142697795-36297-28588-0000 (default) at > [email protected]:36297 > I1022 23:50:09.381752 28615 master.cpp:4195] Removing framework > 20141022-234958-3142697795-36297-28588-0000 (default) at > [email protected]:36297 > W1022 23:50:09.381784 28615 master.cpp:4636] Removing task 0 with > resources cpus(*):1; mem(*):512 of framework > 20141022-234958-3142697795-36297-28588-0000 on slave > 20141022-234958-3142697795-36297-28588-S0 at slave(92)@67.195.81.187:36297 > (pomona.apache.org) in non-terminal state TASK_STAGING > I1022 23:50:09.381868 28606 slave.cpp:2364] Status update manager > successfully handled status update TASK_FINISHED (UUID: > 9eedb006-7959-48e3-bd57-b460298fc842) for task 0 of framework > 20141022-234958-3142697795-36297-28588-0000 > I1022 23:50:09.381885 28606 slave.cpp:2370] Sending acknowledgement for > status update TASK_FINISHED (UUID: 9eedb006-7959-48e3-bd57-b460298fc842) > for task 0 of framework 20141022-234958-3142697795-36297-28588-0000 to > executor(34)@67.195.81.187:36297 > I1022 23:50:09.381944 28606 slave.cpp:1517] Asked to shut down framework > 20141022-234958-3142697795-36297-28588-0000 by [email protected]:36297 > I1022 23:50:09.381959 28606 slave.cpp:1542] Shutting down framework > 20141022-234958-3142697795-36297-28588-0000 > I1022 23:50:09.381976 28606 slave.cpp:3117] Shutting down executor > 'default' of framework 20141022-234958-3142697795-36297-28588-0000 > I1022 23:50:09.382115 28607 hierarchical_allocator_process.hpp:563] > Recovered cpus(*):1; mem(*):512 (total allocatable: cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000]) on slave > 20141022-234958-3142697795-36297-28588-S0 from framework > 20141022-234958-3142697795-36297-28588-0000 > F1022 23:50:10.381491 28602 logging.cpp:57] RAW: Pure virtual method called > I1022 23:50:09.382222 28615 master.cpp:4679] Removing executor 'default' > with resources of framework 20141022-234958-3142697795-36297-28588-0000 on > slave 20141022-234958-3142697795-36297-28588-S0 at slave(92)@ > 67.195.81.187:36297 (pomona.apache.org) > I1022 23:50:10.381491 28613 hierarchical_allocator_process.hpp:659] > Performed allocation for 1 slaves in 30737ns > I1022 23:50:12.877471 28617 hierarchical_allocator_process.hpp:360] > Removed framework 20141022-234958-3142697795-36297-28588-0000 > I1022 23:50:12.877516 28615 master.cpp:677] Master terminating > I1022 23:50:12.877804 28608 slave.cpp:2602] [email protected]:36297 > exited > W1022 23:50:12.877830 28608 slave.cpp:2605] Master disconnected! Waiting > for a new master to be elected > F1022 23:50:12.877830 28588 logging.cpp:57] RAW: Pure virtual method called > @ 0x2b89187e25dd google::LogMessage::Fail() > @ 0x2b89187e9cd6 google::RawLog__() > @ 0x2b89183f84d9 > mesos::internal::slave::ResourceMonitorProcess::collect() > @ 0x2b89187a439a process::ProcessManager::resume() > @ 0x2b89187e25dd google::LogMessage::Fail() > @ 0x2b89187a465c process::schedule() > @ 0x2b89187e9cd6 google::RawLog__() > @ 0x507226 > mesos::internal::tests::Cluster::Slaves::shutdown() > @ 0x7a7f24 > mesos::internal::tests::MesosTest::ShutdownSlaves() > @ 0x9a4713 > testing::internal::HandleExceptionsInMethodIfSupported<>() > @ 0x99b980 testing::Test::Run() > @ 0x99ba5e testing::TestInfo::Run() > @ 0x99bb65 testing::TestCase::Run() > @ 0x99be08 testing::internal::UnitTestImpl::RunAllTests() > @ 0x99c0a7 testing::UnitTest::Run() > @ 0x490aca main > @ 0x2b891a707ec5 (unknown) > @ 0x49dfa8 (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 > Test finished > Exit status: 2 > Build step 'Execute shell' marked build as failure > Recording test results >
