https://issues.apache.org/jira/browse/MESOS-1347
On Mon, Sep 29, 2014 at 12:30 PM, Apache Jenkins Server < [email protected]> wrote: > See < > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2131/changes > > > > Changes: > > [dlester] Adds OpenCredo and WooRank to PoweredByMesos page. > > ------------------------------------------ > [...truncated 20995 lines...] > I0929 19:27:33.690207 6617 leveldb.cpp:306] Persisting metadata (8 bytes) > to leveldb took 306053ns > I0929 19:27:33.690224 6617 replica.cpp:342] Persisted promised to 1 > I0929 19:27:33.690493 6614 coordinator.cpp:230] Coordinator attemping to > fill missing position > I0929 19:27:33.691164 6616 replica.cpp:375] Replica received explicit > promise request for position 0 with proposal 2 > I0929 19:27:33.691285 6616 leveldb.cpp:343] Persisting action (8 bytes) > to leveldb took 101482ns > I0929 19:27:33.691304 6616 replica.cpp:676] Persisted action at 0 > I0929 19:27:33.691746 6623 replica.cpp:508] Replica received write > request for position 0 > I0929 19:27:33.691776 6623 leveldb.cpp:438] Reading position from leveldb > took 11754ns > I0929 19:27:33.691954 6623 leveldb.cpp:343] Persisting action (14 bytes) > to leveldb took 154753ns > I0929 19:27:33.691972 6623 replica.cpp:676] Persisted action at 0 > I0929 19:27:33.692244 6622 replica.cpp:655] Replica received learned > notice for position 0 > I0929 19:27:33.692389 6622 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 121120ns > I0929 19:27:33.692407 6622 replica.cpp:676] Persisted action at 0 > I0929 19:27:33.692417 6622 replica.cpp:661] Replica learned NOP action at > position 0 > I0929 19:27:33.692615 6615 log.cpp:672] Writer started with ending > position 0 > I0929 19:27:33.693091 6624 leveldb.cpp:438] Reading position from leveldb > took 11308ns > I0929 19:27:33.694427 6623 registrar.cpp:346] Successfully fetched the > registry (0B) > I0929 19:27:33.694454 6623 registrar.cpp:422] Attempting to update the > 'registry' > I0929 19:27:33.695809 6610 log.cpp:680] Attempting to append 142 bytes to > the log > I0929 19:27:33.695890 6615 coordinator.cpp:340] Coordinator attempting to > write APPEND action at position 1 > I0929 19:27:33.696285 6622 replica.cpp:508] Replica received write > request for position 1 > I0929 19:27:33.696734 6622 leveldb.cpp:343] Persisting action (161 bytes) > to leveldb took 424360ns > I0929 19:27:33.696753 6622 replica.cpp:676] Persisted action at 1 > I0929 19:27:33.697084 6613 replica.cpp:655] Replica received learned > notice for position 1 > I0929 19:27:33.697428 6613 leveldb.cpp:343] Persisting action (163 bytes) > to leveldb took 321272ns > I0929 19:27:33.697448 6613 replica.cpp:676] Persisted action at 1 > I0929 19:27:33.697458 6613 replica.cpp:661] Replica learned APPEND action > at position 1 > I0929 19:27:33.697747 6615 registrar.cpp:479] Successfully updated > 'registry' > I0929 19:27:33.697799 6615 registrar.cpp:372] Successfully recovered > registrar > I0929 19:27:33.697830 6622 log.cpp:699] Attempting to truncate the log to > 1 > I0929 19:27:33.697904 6611 master.cpp:1099] Recovered 0 slaves from the > Registry (104B) ; allowing 10mins for slaves to re-register > I0929 19:27:33.698005 6623 coordinator.cpp:340] Coordinator attempting to > write TRUNCATE action at position 2 > I0929 19:27:33.698477 6624 replica.cpp:508] Replica received write > request for position 2 > I0929 19:27:33.698654 6624 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 155120ns > I0929 19:27:33.698671 6624 replica.cpp:676] Persisted action at 2 > I0929 19:27:33.698987 6612 replica.cpp:655] Replica received learned > notice for position 2 > I0929 19:27:33.699115 6612 leveldb.cpp:343] Persisting action (18 bytes) > to leveldb took 105299ns > I0929 19:27:33.699148 6612 leveldb.cpp:401] Deleting ~1 keys from leveldb > took 15614ns > I0929 19:27:33.699162 6612 replica.cpp:676] Persisted action at 2 > I0929 19:27:33.699170 6612 replica.cpp:661] Replica learned TRUNCATE > action at position 2 > I0929 19:27:33.710770 6615 slave.cpp:169] Slave started on 46)@ > 67.195.81.189:39093 > I0929 19:27:33.710803 6615 credentials.hpp:84] Loading credential for > authentication from > '/tmp/GarbageCollectorIntegrationTest_DiskUsage_5meoSi/credential' > I0929 19:27:33.710908 6615 slave.cpp:276] Slave using credential for: > test-principal > I0929 19:27:33.711005 6615 slave.cpp:289] Slave resources: cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] > I0929 19:27:33.711081 6615 slave.cpp:317] Slave hostname: > proserpina.apache.org > I0929 19:27:33.711098 6615 slave.cpp:318] Slave checkpoint: false > I0929 19:27:33.711467 6617 state.cpp:33] Recovering state from > '/tmp/GarbageCollectorIntegrationTest_DiskUsage_5meoSi/meta' > I0929 19:27:33.711596 6617 status_update_manager.cpp:193] Recovering > status update manager > I0929 19:27:33.711730 6622 slave.cpp:3277] Finished recovery > I0929 19:27:33.712009 6617 slave.cpp:604] New master detected at > [email protected]:39093 > I0929 19:27:33.712050 6617 slave.cpp:678] Authenticating with master > [email protected]:39093 > I0929 19:27:33.712081 6610 status_update_manager.cpp:167] New master > detected at [email protected]:39093 > I0929 19:27:33.712152 6617 slave.cpp:651] Detecting new master > I0929 19:27:33.712177 6625 authenticatee.hpp:128] Creating new client > SASL connection > I0929 19:27:33.712275 6610 master.cpp:3737] Authenticating slave(46)@ > 67.195.81.189:39093 > I0929 19:27:33.712368 6617 authenticator.hpp:156] Creating new server > SASL connection > I0929 19:27:33.712460 6619 authenticatee.hpp:219] Received SASL > authentication mechanisms: CRAM-MD5 > I0929 19:27:33.712486 6619 authenticatee.hpp:245] Attempting to > authenticate with mechanism 'CRAM-MD5' > I0929 19:27:33.712530 6619 authenticator.hpp:262] Received SASL > authentication start > I0929 19:27:33.712574 6619 authenticator.hpp:384] Authentication requires > more steps > I0929 19:27:33.712641 6613 authenticatee.hpp:265] Received SASL > authentication step > I0929 19:27:33.712708 6613 authenticator.hpp:290] Received SASL > authentication step > I0929 19:27:33.712738 6613 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: ' > proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false > I0929 19:27:33.712749 6613 auxprop.cpp:153] Looking up auxiliary property > '*userPassword' > I0929 19:27:33.712761 6613 auxprop.cpp:153] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I0929 19:27:33.712774 6613 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: ' > proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true > I0929 19:27:33.712787 6613 auxprop.cpp:103] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I0929 19:27:33.712801 6613 auxprop.cpp:103] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I0929 19:27:33.712818 6613 authenticator.hpp:376] Authentication success > I0929 19:27:33.712877 6614 authenticatee.hpp:305] Authentication success > I0929 19:27:33.712890 6613 master.cpp:3777] Successfully authenticated > principal 'test-principal' at slave(46)@67.195.81.189:39093 > I0929 19:27:33.713059 6614 slave.cpp:735] Successfully authenticated with > master [email protected]:39093 > I0929 19:27:33.713119 6614 slave.cpp:998] Will retry registration in > 19361ns if necessary > I0929 19:27:33.713223 6619 master.cpp:2930] Registering slave at > slave(46)@67.195.81.189:39093 (proserpina.apache.org) with id > 20140929-192733-3176252227-39093-6596-0 > I0929 19:27:33.713335 6615 slave.cpp:998] Will retry registration in > 4.227055ms if necessary > I0929 19:27:33.713359 6611 registrar.cpp:422] Attempting to update the > 'registry' > I0929 19:27:33.713367 6619 master.cpp:2918] Ignoring register slave > message from slave(46)@67.195.81.189:39093 (proserpina.apache.org) as > admission is already in progress > I0929 19:27:33.714776 6615 log.cpp:680] Attempting to append 344 bytes to > the log > I0929 19:27:33.714859 6618 coordinator.cpp:340] Coordinator attempting to > write APPEND action at position 3 > I0929 19:27:33.715200 6613 replica.cpp:508] Replica received write > request for position 3 > I0929 19:27:33.715421 6613 leveldb.cpp:343] Persisting action (363 bytes) > to leveldb took 194931ns > I0929 19:27:33.715440 6613 replica.cpp:676] Persisted action at 3 > I0929 19:27:33.715760 6623 replica.cpp:655] Replica received learned > notice for position 3 > I0929 19:27:33.716230 6623 leveldb.cpp:343] Persisting action (365 bytes) > to leveldb took 444917ns > I0929 19:27:33.716250 6623 replica.cpp:676] Persisted action at 3 > I0929 19:27:33.716262 6623 replica.cpp:661] Replica learned APPEND action > at position 3 > I0929 19:27:33.716580 6620 registrar.cpp:479] Successfully updated > 'registry' > I0929 19:27:33.716696 6618 master.cpp:2970] Registered slave > 20140929-192733-3176252227-39093-6596-0 at slave(46)@67.195.81.189:39093 ( > proserpina.apache.org) > I0929 19:27:33.716704 6613 log.cpp:699] Attempting to truncate the log to > 3 > I0929 19:27:33.716725 6618 master.cpp:4180] Adding slave > 20140929-192733-3176252227-39093-6596-0 at slave(46)@67.195.81.189:39093 ( > proserpina.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000] > I0929 19:27:33.716799 6622 coordinator.cpp:340] Coordinator attempting to > write TRUNCATE action at position 4 > I0929 19:27:33.716914 6611 slave.cpp:769] Registered with master > [email protected]:39093; given slave ID > 20140929-192733-3176252227-39093-6596-0 > I0929 19:27:33.716976 6611 slave.cpp:2351] Received ping from > slave-observer(48)@67.195.81.189:39093 > I0929 19:27:33.717036 6623 hierarchical_allocator_process.hpp:442] Added > slave 20140929-192733-3176252227-39093-6596-0 (proserpina.apache.org) > with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) > I0929 19:27:33.717105 6623 hierarchical_allocator_process.hpp:679] > Performed allocation for slave 20140929-192733-3176252227-39093-6596-0 in > 9692ns > I0929 19:27:33.717315 6612 replica.cpp:508] Replica received write > request for position 4 > I0929 19:27:33.717638 6612 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 299339ns > I0929 19:27:33.717658 6612 replica.cpp:676] Persisted action at 4 > I0929 19:27:33.717993 6620 replica.cpp:655] Replica received learned > notice for position 4 > I0929 19:27:33.718130 6620 leveldb.cpp:343] Persisting action (18 bytes) > to leveldb took 111401ns > I0929 19:27:33.718179 6620 leveldb.cpp:401] Deleting ~2 keys from leveldb > took 24089ns > I0929 19:27:33.718194 6620 replica.cpp:676] Persisted action at 4 > I0929 19:27:33.718205 6620 replica.cpp:661] Replica learned TRUNCATE > action at position 4 > I0929 19:27:33.720230 6596 sched.cpp:137] Version: 0.21.0 > I0929 19:27:33.720419 6616 sched.cpp:233] New master detected at > [email protected]:39093 > I0929 19:27:33.720448 6616 sched.cpp:283] Authenticating with master > [email protected]:39093 > I0929 19:27:33.720541 6619 authenticatee.hpp:128] Creating new client > SASL connection > I0929 19:27:33.720649 6616 master.cpp:3737] Authenticating > [email protected]:39093 > I0929 19:27:33.720732 6619 authenticator.hpp:156] Creating new server > SASL connection > I0929 19:27:33.720816 6611 authenticatee.hpp:219] Received SASL > authentication mechanisms: CRAM-MD5 > I0929 19:27:33.720844 6611 authenticatee.hpp:245] Attempting to > authenticate with mechanism 'CRAM-MD5' > I0929 19:27:33.720909 6614 authenticator.hpp:262] Received SASL > authentication start > I0929 19:27:33.720968 6614 authenticator.hpp:384] Authentication requires > more steps > I0929 19:27:33.721038 6614 authenticatee.hpp:265] Received SASL > authentication step > I0929 19:27:33.721110 6619 authenticator.hpp:290] Received SASL > authentication step > I0929 19:27:33.721138 6619 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: ' > proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false > I0929 19:27:33.721149 6619 auxprop.cpp:153] Looking up auxiliary property > '*userPassword' > I0929 19:27:33.721161 6619 auxprop.cpp:153] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I0929 19:27:33.721174 6619 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: ' > proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true > I0929 19:27:33.721182 6619 auxprop.cpp:103] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I0929 19:27:33.721195 6619 auxprop.cpp:103] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I0929 19:27:33.721211 6619 authenticator.hpp:376] Authentication success > I0929 19:27:33.721262 6614 authenticatee.hpp:305] Authentication success > I0929 19:27:33.721282 6619 master.cpp:3777] Successfully authenticated > principal 'test-principal' at > [email protected]:39093 > I0929 19:27:33.721364 6614 sched.cpp:357] Successfully authenticated with > master [email protected]:39093 > I0929 19:27:33.721384 6614 sched.cpp:476] Sending registration request to > [email protected]:39093 > I0929 19:27:33.721452 6625 master.cpp:1360] Received registration request > from [email protected]:39093 > I0929 19:27:33.721478 6625 master.cpp:1320] Authorizing framework > principal 'test-principal' to receive offers for role '*' > I0929 19:27:33.721627 6618 master.cpp:1419] Registering framework > 20140929-192733-3176252227-39093-6596-0000 at > [email protected]:39093 > I0929 19:27:33.721707 6619 sched.cpp:407] Framework registered with > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.721742 6611 hierarchical_allocator_process.hpp:329] Added > framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.721784 6619 sched.cpp:421] Scheduler::registered took > 55248ns > I0929 19:27:33.721801 6611 hierarchical_allocator_process.hpp:734] > Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on > slave 20140929-192733-3176252227-39093-6596-0 to framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.721974 6611 hierarchical_allocator_process.hpp:659] > Performed allocation for 1 slaves in 205122ns > I0929 19:27:33.722015 6621 master.hpp:868] Adding offer > 20140929-192733-3176252227-39093-6596-0 with resources cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 20140929-192733-3176252227-39093-6596-0 (proserpina.apache.org) > I0929 19:27:33.722069 6621 master.cpp:3679] Sending 1 offers to framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.722326 6616 sched.cpp:544] Scheduler::resourceOffers took > 134808ns > I0929 19:27:33.722502 6621 master.hpp:877] Removing offer > 20140929-192733-3176252227-39093-6596-0 with resources cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 20140929-192733-3176252227-39093-6596-0 (proserpina.apache.org) > I0929 19:27:33.722551 6621 master.cpp:2274] Processing reply for offers: > [ 20140929-192733-3176252227-39093-6596-0 ] on slave > 20140929-192733-3176252227-39093-6596-0 at slave(46)@67.195.81.189:39093 ( > proserpina.apache.org) for framework > 20140929-192733-3176252227-39093-6596-0000 > W0929 19:27:33.722581 6621 master.cpp:1944] 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. > W0929 19:27:33.722601 6621 master.cpp:1955] 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. > I0929 19:27:33.722616 6621 master.cpp:2357] Authorizing framework > principal 'test-principal' to launch task 0 as user 'jenkins' > I0929 19:27:33.722928 6614 master.hpp:845] Adding task 0 with resources > cpus(*):2; mem(*):1024 on slave 20140929-192733-3176252227-39093-6596-0 ( > proserpina.apache.org) > I0929 19:27:33.722966 6614 master.cpp:2423] Launching task 0 of framework > 20140929-192733-3176252227-39093-6596-0000 with resources cpus(*):2; > mem(*):1024 on slave 20140929-192733-3176252227-39093-6596-0 at slave(46)@ > 67.195.81.189:39093 (proserpina.apache.org) > I0929 19:27:33.723063 6625 slave.cpp:1029] Got assigned task 0 for > framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.723165 6623 hierarchical_allocator_process.hpp:563] > Recovered disk(*):1024; ports(*):[31000-32000] (total allocatable: > disk(*):1024; ports(*):[31000-32000]) on slave > 20140929-192733-3176252227-39093-6596-0 from framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.723199 6623 hierarchical_allocator_process.hpp:599] > Framework 20140929-192733-3176252227-39093-6596-0000 filtered slave > 20140929-192733-3176252227-39093-6596-0 for 5secs > I0929 19:27:33.723265 6625 slave.cpp:1139] Launching task 0 for framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.726184 6625 exec.cpp:132] Version: 0.21.0 > I0929 19:27:33.726266 6614 exec.cpp:182] Executor started at: > executor(18)@67.195.81.189:39093 with pid 6596 > I0929 19:27:33.726286 6625 slave.cpp:1252] Queuing task '0' for executor > default of framework '20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.726331 6625 slave.cpp:560] Successfully attached file > '/tmp/GarbageCollectorIntegrationTest_DiskUsage_5meoSi/slaves/20140929-192733-3176252227-39093-6596-0/frameworks/20140929-192733-3176252227-39093-6596-0000/executors/default/runs/42edbc00-b71c-49fb-b90d-41abae736459' > I0929 19:27:33.726371 6625 slave.cpp:2617] Monitoring executor 'default' > of framework '20140929-192733-3176252227-39093-6596-0000' in container > '42edbc00-b71c-49fb-b90d-41abae736459' > I0929 19:27:33.726445 6625 slave.cpp:1762] Got registration for executor > 'default' of framework 20140929-192733-3176252227-39093-6596-0000 from > executor(18)@67.195.81.189:39093 > I0929 19:27:33.726568 6625 slave.cpp:1881] Flushing queued task 0 for > executor 'default' of framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.726606 6615 exec.cpp:206] Executor registered on slave > 20140929-192733-3176252227-39093-6596-0 > I0929 19:27:33.727777 6615 exec.cpp:218] Executor::registered took 12005ns > I0929 19:27:33.727838 6615 exec.cpp:293] Executor asked to run task '0' > I0929 19:27:33.727869 6615 exec.cpp:302] Executor::launchTask took 17937ns > I0929 19:27:33.729051 6615 exec.cpp:525] Executor sending status update > TASK_RUNNING (UUID: e0274dc9-b651-4034-8910-29c5d4b17f4c) for task 0 of > framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.729141 6615 slave.cpp:2115] Handling status update > TASK_RUNNING (UUID: e0274dc9-b651-4034-8910-29c5d4b17f4c) for task 0 of > framework 20140929-192733-3176252227-39093-6596-0000 from executor(18)@ > 67.195.81.189:39093 > I0929 19:27:33.729228 6615 status_update_manager.cpp:320] Received status > update TASK_RUNNING (UUID: e0274dc9-b651-4034-8910-29c5d4b17f4c) for task 0 > of framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.729244 6615 status_update_manager.cpp:499] Creating > StatusUpdate stream for task 0 of framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.729305 6615 status_update_manager.cpp:373] Forwarding > status update TASK_RUNNING (UUID: e0274dc9-b651-4034-8910-29c5d4b17f4c) for > task 0 of framework 20140929-192733-3176252227-39093-6596-0000 to > [email protected]:39093 > I0929 19:27:33.729485 6617 master.cpp:3301] Forwarding status update > TASK_RUNNING (UUID: e0274dc9-b651-4034-8910-29c5d4b17f4c) for task 0 of > framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:33.729542 6617 master.cpp:3273] Status update TASK_RUNNING > (UUID: e0274dc9-b651-4034-8910-29c5d4b17f4c) for task 0 of framework > 20140929-192733-3176252227-39093-6596-0000 from slave > 20140929-192733-3176252227-39093-6596-0 at slave(46)@67.195.81.189:39093 ( > proserpina.apache.org) > I0929 19:27:33.729639 6611 sched.cpp:635] Scheduler::statusUpdate took > 30441ns > I0929 19:27:33.729758 6622 master.cpp:2777] Forwarding status update > acknowledgement e0274dc9-b651-4034-8910-29c5d4b17f4c for task 0 of > framework 20140929-192733-3176252227-39093-6596-0000 to slave > 20140929-192733-3176252227-39093-6596-0 at slave(46)@67.195.81.189:39093 ( > proserpina.apache.org) > I0929 19:27:33.729779 6625 slave.cpp:2272] Status update manager > successfully handled status update TASK_RUNNING (UUID: > e0274dc9-b651-4034-8910-29c5d4b17f4c) for task 0 of framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.410068 6625 slave.cpp:2278] Sending acknowledgement for > status update TASK_RUNNING (UUID: e0274dc9-b651-4034-8910-29c5d4b17f4c) for > task 0 of framework 20140929-192733-3176252227-39093-6596-0000 to > executor(18)@67.195.81.189:39093 > I0929 19:27:35.410200 6625 slave.cpp:2675] Executor 'default' of > framework 20140929-192733-3176252227-39093-6596-0000 exited with status 0 > I0929 19:27:35.410275 6623 status_update_manager.cpp:398] Received status > update acknowledgement (UUID: e0274dc9-b651-4034-8910-29c5d4b17f4c) for > task 0 of framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.411408 6625 slave.cpp:2115] Handling status update > TASK_LOST (UUID: 6faaca53-ce83-40ff-b3f5-521ea804354e) for task 0 of > framework 20140929-192733-3176252227-39093-6596-0000 from @0.0.0.0:0 > I0929 19:27:35.411434 6625 slave.cpp:3995] Terminating task 0 > I0929 19:27:35.411547 6625 slave.cpp:1702] Status update manager > successfully handled status update acknowledgement (UUID: > e0274dc9-b651-4034-8910-29c5d4b17f4c) for task 0 of framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.411640 6625 status_update_manager.cpp:320] Received status > update TASK_LOST (UUID: 6faaca53-ce83-40ff-b3f5-521ea804354e) for task 0 of > framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.411648 6623 master.cpp:3353] Executor default of framework > 20140929-192733-3176252227-39093-6596-0000 on slave > 20140929-192733-3176252227-39093-6596-0 at slave(46)@67.195.81.189:39093 ( > proserpina.apache.org) exited with status 0 > I0929 19:27:35.411666 6625 status_update_manager.cpp:373] Forwarding > status update TASK_LOST (UUID: 6faaca53-ce83-40ff-b3f5-521ea804354e) for > task 0 of framework 20140929-192733-3176252227-39093-6596-0000 to > [email protected]:39093 > I0929 19:27:35.411679 6623 master.cpp:4514] Removing executor 'default' > with resources of framework 20140929-192733-3176252227-39093-6596-0000 on > slave 20140929-192733-3176252227-39093-6596-0 at slave(46)@ > 67.195.81.189:39093 (proserpina.apache.org) > I0929 19:27:35.411798 6621 slave.cpp:2272] Status update manager > successfully handled status update TASK_LOST (UUID: > 6faaca53-ce83-40ff-b3f5-521ea804354e) for task 0 of framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.411867 6623 master.cpp:3301] Forwarding status update > TASK_LOST (UUID: 6faaca53-ce83-40ff-b3f5-521ea804354e) for task 0 of > framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.411924 6623 master.cpp:3273] Status update TASK_LOST > (UUID: 6faaca53-ce83-40ff-b3f5-521ea804354e) for task 0 of framework > 20140929-192733-3176252227-39093-6596-0000 from slave > 20140929-192733-3176252227-39093-6596-0 at slave(46)@67.195.81.189:39093 ( > proserpina.apache.org) > I0929 19:27:35.412044 6625 sched.cpp:635] Scheduler::statusUpdate took > 12352ns > I0929 19:27:35.412045 6623 hierarchical_allocator_process.hpp:563] > Recovered cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; > ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave > 20140929-192733-3176252227-39093-6596-0 from framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.412128 6623 master.cpp:4485] Removing task 0 with > resources cpus(*):2; mem(*):1024 of framework > 20140929-192733-3176252227-39093-6596-0000 on slave > 20140929-192733-3176252227-39093-6596-0 at slave(46)@67.195.81.189:39093 ( > proserpina.apache.org) > I0929 19:27:35.412174 6623 master.cpp:2777] Forwarding status update > acknowledgement 6faaca53-ce83-40ff-b3f5-521ea804354e for task 0 of > framework 20140929-192733-3176252227-39093-6596-0000 to slave > 20140929-192733-3176252227-39093-6596-0 at slave(46)@67.195.81.189:39093 ( > proserpina.apache.org) > I0929 19:27:35.412346 6616 status_update_manager.cpp:398] Received status > update acknowledgement (UUID: 6faaca53-ce83-40ff-b3f5-521ea804354e) for > task 0 of framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.412390 6616 status_update_manager.cpp:530] Cleaning up > status update stream for task 0 of framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.412519 6621 slave.cpp:1702] Status update manager > successfully handled status update acknowledgement (UUID: > 6faaca53-ce83-40ff-b3f5-521ea804354e) for task 0 of framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.412541 6621 slave.cpp:4034] Completing task 0 > I0929 19:27:35.412554 6621 slave.cpp:2811] Cleaning up executor 'default' > of framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.412665 6616 gc.cpp:56] Scheduling > '/tmp/GarbageCollectorIntegrationTest_DiskUsage_5meoSi/slaves/20140929-192733-3176252227-39093-6596-0/frameworks/20140929-192733-3176252227-39093-6596-0000/executors/default/runs/42edbc00-b71c-49fb-b90d-41abae736459' > for gc 1.00000210012741weeks in the future > I0929 19:27:35.412681 6621 slave.cpp:2886] Cleaning up framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.412740 6616 gc.cpp:56] Scheduling > '/tmp/GarbageCollectorIntegrationTest_DiskUsage_5meoSi/slaves/20140929-192733-3176252227-39093-6596-0/frameworks/20140929-192733-3176252227-39093-6596-0000/executors/default' > for gc 1.00000210012741weeks in the future > I0929 19:27:35.412782 6612 status_update_manager.cpp:282] Closing status > update streams for framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.412793 6616 gc.cpp:56] Scheduling > '/tmp/GarbageCollectorIntegrationTest_DiskUsage_5meoSi/slaves/20140929-192733-3176252227-39093-6596-0/frameworks/20140929-192733-3176252227-39093-6596-0000' > for gc 1.00000210012741weeks in the future > I0929 19:27:35.423359 6617 slave.cpp:3132] Current usage 90.00%. Max > allowed age: 0ns > I0929 19:27:35.423506 6617 hierarchical_allocator_process.hpp:734] > Offering disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on > slave 20140929-192733-3176252227-39093-6596-0 to framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.423621 6617 hierarchical_allocator_process.hpp:659] > Performed allocation for 1 slaves in 166404ns > I0929 19:27:35.423671 6617 master.hpp:868] Adding offer > 20140929-192733-3176252227-39093-6596-1 with resources disk(*):1024; > ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave > 20140929-192733-3176252227-39093-6596-0 (proserpina.apache.org) > I0929 19:27:35.423720 6617 master.cpp:3679] Sending 1 offers to framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.423882 6614 sched.cpp:544] Scheduler::resourceOffers took > 15465ns > tests/gc_tests.cpp:675: Failure > Value of: os::exists(executorDir) > Actual: true > Expected: false > I0929 19:27:35.443688 6617 master.cpp:767] Framework > 20140929-192733-3176252227-39093-6596-0000 disconnected > I0929 19:27:35.443712 6617 master.cpp:1705] Disconnecting framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.443729 6617 master.cpp:1721] Deactivating framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.443822 6617 master.hpp:877] Removing offer > 20140929-192733-3176252227-39093-6596-1 with resources disk(*):1024; > ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave > 20140929-192733-3176252227-39093-6596-0 (proserpina.apache.org) > I0929 19:27:35.443846 6620 hierarchical_allocator_process.hpp:405] > Deactivated framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.443877 6617 master.cpp:789] Giving framework > 20140929-192733-3176252227-39093-6596-0000 0ns to failover > I0929 19:27:35.443943 6620 hierarchical_allocator_process.hpp:563] > Recovered disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 > (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; > mem(*):1024) on slave 20140929-192733-3176252227-39093-6596-0 from > framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.443974 6610 master.cpp:3549] Framework failover timeout, > removing framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.443991 6610 master.cpp:4041] Removing framework > 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.444080 6613 slave.cpp:1435] Asked to shut down framework > 20140929-192733-3176252227-39093-6596-0000 by [email protected]:39093 > W0929 19:27:35.583452 6613 slave.cpp:1450] Cannot shut down unknown > framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.444135 6610 master.cpp:676] Master terminating > I0929 19:27:35.444231 6616 hierarchical_allocator_process.hpp:360] > Removed framework 20140929-192733-3176252227-39093-6596-0000 > I0929 19:27:35.583642 6616 slave.cpp:2436] [email protected]:39093 > exited > W0929 19:27:35.583662 6616 slave.cpp:2439] Master disconnected! Waiting > for a new master to be elected > F0929 19:27:35.583662 6596 logging.cpp:57] RAW: Pure virtual method called > @ 0x2b5deb5974ed google::LogMessage::Fail() > @ 0x2b5deb59ebe6 google::RawLog__() > @ 0x5067c6 > mesos::internal::tests::Cluster::Slaves::shutdown() > @ 0x7b1da4 > mesos::internal::tests::MesosTest::ShutdownSlaves() > @ 0x9a4073 > testing::internal::HandleExceptionsInMethodIfSupported<>() > @ 0x99b210 testing::Test::Run() > @ 0x99b2ee testing::TestInfo::Run() > @ 0x99b3f5 testing::TestCase::Run() > @ 0x99b698 testing::internal::UnitTestImpl::RunAllTests() > @ 0x99b937 testing::UnitTest::Run() > @ 0x492683 main > @ 0x2b5ded2bdec5 (unknown) > @ 0x4a15d8 (unknown) > make[3]: *** [check-local] Aborted > make[3]: Leaving directory `< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src > '> > make[2]: *** [check-am] Error 2 > make[2]: Leaving directory `< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src > '> > make[1]: *** [check] Error 2 > make[1]: Leaving directory `< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src > '> > make: *** [check-recursive] Error 1 > I0929 19:27:38.442497 8952 exec.cpp:86] Committing suicide by killing the > process group > I0929 19:27:38.442507 8962 exec.cpp:86] Committing suicide by killing the > process group > I0929 19:27:38.442538 8934 exec.cpp:86] Committing suicide by killing the > process group > Test finished > Exit status: 2 > Build step 'Execute shell' marked build as failure > Recording test results >
