See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2146/changes>
Changes: [benjamin.hindman] Install Python libraries during make install. ------------------------------------------ [...truncated 21052 lines...] I1006 19:42:04.844101 15820 recover.cpp:556] Successfully joined the Paxos group I1006 19:42:04.844164 15820 recover.cpp:440] Recover process terminated I1006 19:42:04.844360 15820 log.cpp:656] Attempting to start the writer I1006 19:42:04.844717 15822 replica.cpp:474] Replica received implicit promise request with proposal 1 I1006 19:42:04.845252 15822 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 520310ns I1006 19:42:04.845264 15822 replica.cpp:342] Persisted promised to 1 I1006 19:42:04.845511 15823 coordinator.cpp:230] Coordinator attemping to fill missing position I1006 19:42:04.845927 15817 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2 I1006 19:42:04.846384 15817 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 439409ns I1006 19:42:04.846396 15817 replica.cpp:676] Persisted action at 0 I1006 19:42:04.846745 15817 replica.cpp:508] Replica received write request for position 0 I1006 19:42:04.846770 15817 leveldb.cpp:438] Reading position from leveldb took 12298ns I1006 19:42:04.847331 15817 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 546281ns I1006 19:42:04.847343 15817 replica.cpp:676] Persisted action at 0 I1006 19:42:04.847537 15830 replica.cpp:655] Replica received learned notice for position 0 I1006 19:42:04.848074 15830 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 521455ns I1006 19:42:04.848085 15830 replica.cpp:676] Persisted action at 0 I1006 19:42:04.848091 15830 replica.cpp:661] Replica learned NOP action at position 0 I1006 19:42:04.848264 15824 log.cpp:672] Writer started with ending position 0 I1006 19:42:04.848626 15818 leveldb.cpp:438] Reading position from leveldb took 11063ns I1006 19:42:04.849668 15818 registrar.cpp:345] Successfully fetched the registry (0B) I1006 19:42:04.849694 15818 registrar.cpp:421] Attempting to update the 'registry' I1006 19:42:04.850710 15831 log.cpp:680] Attempting to append 139 bytes to the log I1006 19:42:04.850759 15818 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1 I1006 19:42:04.851038 15825 replica.cpp:508] Replica received write request for position 1 I1006 19:42:04.851479 15825 leveldb.cpp:343] Persisting action (158 bytes) to leveldb took 423323ns I1006 19:42:04.851490 15825 replica.cpp:676] Persisted action at 1 I1006 19:42:04.851696 15826 replica.cpp:655] Replica received learned notice for position 1 I1006 19:42:04.852164 15826 leveldb.cpp:343] Persisting action (160 bytes) to leveldb took 454905ns I1006 19:42:04.852177 15826 replica.cpp:676] Persisted action at 1 I1006 19:42:04.852183 15826 replica.cpp:661] Replica learned APPEND action at position 1 I1006 19:42:04.852458 15830 registrar.cpp:478] Successfully updated 'registry' I1006 19:42:04.852509 15830 registrar.cpp:371] Successfully recovered registrar I1006 19:42:04.852530 15822 log.cpp:699] Attempting to truncate the log to 1 I1006 19:42:04.852603 15830 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2 I1006 19:42:04.852603 15831 master.cpp:1099] Recovered 0 slaves from the Registry (101B) ; allowing 10mins for slaves to re-register I1006 19:42:04.852905 15817 replica.cpp:508] Replica received write request for position 2 I1006 19:42:04.853329 15817 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 410445ns I1006 19:42:04.853343 15817 replica.cpp:676] Persisted action at 2 I1006 19:42:04.853521 15826 replica.cpp:655] Replica received learned notice for position 2 I1006 19:42:04.853915 15826 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 379132ns I1006 19:42:04.853938 15826 leveldb.cpp:401] Deleting ~1 keys from leveldb took 11608ns I1006 19:42:04.853945 15826 replica.cpp:676] Persisted action at 2 I1006 19:42:04.853951 15826 replica.cpp:661] Replica learned TRUNCATE action at position 2 I1006 19:42:04.864882 15823 slave.cpp:169] Slave started on 64)@67.195.81.187:43016 I1006 19:42:04.864903 15823 credentials.hpp:84] Loading credential for authentication from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_gDUWFr/credential' I1006 19:42:04.864974 15823 slave.cpp:276] Slave using credential for: test-principal I1006 19:42:04.865057 15823 slave.cpp:289] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1006 19:42:04.865103 15823 slave.cpp:317] Slave hostname: pomona.apache.org I1006 19:42:04.865113 15823 slave.cpp:318] Slave checkpoint: false I1006 19:42:04.865408 15832 state.cpp:33] Recovering state from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_gDUWFr/meta' I1006 19:42:04.865516 15830 status_update_manager.cpp:193] Recovering status update manager I1006 19:42:04.865622 15827 slave.cpp:3271] Finished recovery I1006 19:42:04.865859 15829 slave.cpp:598] New master detected at [email protected]:43016 I1006 19:42:04.865886 15829 slave.cpp:672] Authenticating with master [email protected]:43016 I1006 19:42:04.865907 15822 status_update_manager.cpp:167] New master detected at [email protected]:43016 I1006 19:42:04.865944 15829 slave.cpp:645] Detecting new master I1006 19:42:04.865957 15826 authenticatee.hpp:128] Creating new client SASL connection I1006 19:42:04.866082 15819 master.cpp:3737] Authenticating slave(64)@67.195.81.187:43016 I1006 19:42:04.866144 15824 authenticator.hpp:156] Creating new server SASL connection I1006 19:42:04.866220 15823 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I1006 19:42:04.866235 15823 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I1006 19:42:04.866266 15823 authenticator.hpp:262] Received SASL authentication start I1006 19:42:04.866364 15823 authenticator.hpp:384] Authentication requires more steps I1006 19:42:04.866396 15823 authenticatee.hpp:265] Received SASL authentication step I1006 19:42:04.866437 15823 authenticator.hpp:290] Received SASL authentication step I1006 19:42:04.866454 15823 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 I1006 19:42:04.866461 15823 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1006 19:42:05.013681 15823 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1006 19:42:05.013716 15823 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 I1006 19:42:05.013730 15823 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1006 19:42:05.013736 15823 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1006 19:42:05.013759 15823 authenticator.hpp:376] Authentication success I1006 19:42:05.013818 15823 authenticatee.hpp:305] Authentication success I1006 19:42:05.013841 15823 master.cpp:3777] Successfully authenticated principal 'test-principal' at slave(64)@67.195.81.187:43016 I1006 19:42:05.013941 15827 slave.cpp:729] Successfully authenticated with master [email protected]:43016 I1006 19:42:05.013996 15827 slave.cpp:992] Will retry registration in 6.684706ms if necessary I1006 19:42:05.014068 15827 master.cpp:2930] Registering slave at slave(64)@67.195.81.187:43016 (pomona.apache.org) with id 20141006-194204-3142697795-43016-15803-0 I1006 19:42:05.014188 15831 registrar.cpp:421] Attempting to update the 'registry' I1006 19:42:05.015367 15821 log.cpp:680] Attempting to append 315 bytes to the log I1006 19:42:05.015429 15829 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3 I1006 19:42:05.015708 15822 replica.cpp:508] Replica received write request for position 3 I1006 19:42:05.015967 15822 leveldb.cpp:343] Persisting action (334 bytes) to leveldb took 240079ns I1006 19:42:05.015980 15822 replica.cpp:676] Persisted action at 3 I1006 19:42:05.016202 15821 replica.cpp:655] Replica received learned notice for position 3 I1006 19:42:05.016850 15821 leveldb.cpp:343] Persisting action (336 bytes) to leveldb took 632588ns I1006 19:42:05.016863 15821 replica.cpp:676] Persisted action at 3 I1006 19:42:05.016870 15821 replica.cpp:661] Replica learned APPEND action at position 3 I1006 19:42:05.017120 15821 registrar.cpp:478] Successfully updated 'registry' I1006 19:42:05.017202 15828 master.cpp:2970] Registered slave 20141006-194204-3142697795-43016-15803-0 at slave(64)@67.195.81.187:43016 (pomona.apache.org) I1006 19:42:05.017216 15828 master.cpp:4180] Adding slave 20141006-194204-3142697795-43016-15803-0 at slave(64)@67.195.81.187:43016 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1006 19:42:05.017242 15817 log.cpp:699] Attempting to truncate the log to 3 I1006 19:42:05.017338 15822 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I1006 19:42:05.017411 15830 slave.cpp:763] Registered with master [email protected]:43016; given slave ID 20141006-194204-3142697795-43016-15803-0 I1006 19:42:05.017535 15829 hierarchical_allocator_process.hpp:442] Added slave 20141006-194204-3142697795-43016-15803-0 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I1006 19:42:05.017596 15829 hierarchical_allocator_process.hpp:679] Performed allocation for slave 20141006-194204-3142697795-43016-15803-0 in 10703ns I1006 19:42:05.017639 15830 slave.cpp:2345] Received ping from slave-observer(60)@67.195.81.187:43016 I1006 19:42:05.017684 15827 replica.cpp:508] Replica received write request for position 4 I1006 19:42:05.018401 15827 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 699483ns I1006 19:42:05.018414 15827 replica.cpp:676] Persisted action at 4 I1006 19:42:05.018606 15820 replica.cpp:655] Replica received learned notice for position 4 I1006 19:42:05.019253 15820 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 630779ns I1006 19:42:05.019337 15820 leveldb.cpp:401] Deleting ~2 keys from leveldb took 13101ns I1006 19:42:05.019347 15820 replica.cpp:676] Persisted action at 4 I1006 19:42:05.019353 15820 replica.cpp:661] Replica learned TRUNCATE action at position 4 I1006 19:42:05.019770 15803 sched.cpp:137] Version: 0.21.0 I1006 19:42:05.019932 15823 sched.cpp:233] New master detected at [email protected]:43016 I1006 19:42:05.019951 15823 sched.cpp:283] Authenticating with master [email protected]:43016 I1006 19:42:05.020015 15819 authenticatee.hpp:128] Creating new client SASL connection I1006 19:42:05.020108 15824 master.cpp:3737] Authenticating [email protected]:43016 I1006 19:42:05.020177 15820 authenticator.hpp:156] Creating new server SASL connection I1006 19:42:05.020238 15819 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I1006 19:42:05.020254 15819 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I1006 19:42:05.020357 15832 authenticator.hpp:262] Received SASL authentication start I1006 19:42:05.020390 15832 authenticator.hpp:384] Authentication requires more steps I1006 19:42:05.020422 15832 authenticatee.hpp:265] Received SASL authentication step I1006 19:42:05.020462 15832 authenticator.hpp:290] Received SASL authentication step I1006 19:42:05.020476 15832 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 I1006 19:42:05.020481 15832 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1006 19:42:05.020489 15832 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1006 19:42:05.020500 15832 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 I1006 19:42:05.020506 15832 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1006 19:42:05.020510 15832 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1006 19:42:05.020519 15832 authenticator.hpp:376] Authentication success I1006 19:42:05.020557 15822 authenticatee.hpp:305] Authentication success I1006 19:42:05.020565 15832 master.cpp:3777] Successfully authenticated principal 'test-principal' at [email protected]:43016 I1006 19:42:05.020654 15822 sched.cpp:357] Successfully authenticated with master [email protected]:43016 I1006 19:42:05.020666 15822 sched.cpp:476] Sending registration request to [email protected]:43016 I1006 19:42:05.020719 15824 master.cpp:1360] Received registration request from [email protected]:43016 I1006 19:42:05.020740 15824 master.cpp:1320] Authorizing framework principal 'test-principal' to receive offers for role '*' I1006 19:42:05.020867 15828 master.cpp:1419] Registering framework 20141006-194204-3142697795-43016-15803-0000 at [email protected]:43016 I1006 19:42:05.020936 15826 sched.cpp:407] Framework registered with 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.020954 15822 hierarchical_allocator_process.hpp:329] Added framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.020972 15826 sched.cpp:421] Scheduler::registered took 21508ns I1006 19:42:05.021003 15822 hierarchical_allocator_process.hpp:734] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141006-194204-3142697795-43016-15803-0 to framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.021109 15822 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 138182ns I1006 19:42:05.021141 15823 master.hpp:868] Adding offer 20141006-194204-3142697795-43016-15803-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141006-194204-3142697795-43016-15803-0 (pomona.apache.org) I1006 19:42:05.188371 15823 master.cpp:3679] Sending 1 offers to framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.188660 15823 sched.cpp:544] Scheduler::resourceOffers took 135781ns I1006 19:42:05.188834 15832 master.hpp:877] Removing offer 20141006-194204-3142697795-43016-15803-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141006-194204-3142697795-43016-15803-0 (pomona.apache.org) I1006 19:42:05.188873 15832 master.cpp:2274] Processing reply for offers: [ 20141006-194204-3142697795-43016-15803-0 ] on slave 20141006-194204-3142697795-43016-15803-0 at slave(64)@67.195.81.187:43016 (pomona.apache.org) for framework 20141006-194204-3142697795-43016-15803-0000 W1006 19:42:05.188895 15832 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. W1006 19:42:05.188909 15832 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. I1006 19:42:05.188917 15832 master.cpp:2357] Authorizing framework principal 'test-principal' to launch task 0 as user 'jenkins' I1006 19:42:05.189211 15831 master.hpp:845] Adding task 0 with resources cpus(*):2; mem(*):1024 on slave 20141006-194204-3142697795-43016-15803-0 (pomona.apache.org) I1006 19:42:05.189232 15831 master.cpp:2423] Launching task 0 of framework 20141006-194204-3142697795-43016-15803-0000 with resources cpus(*):2; mem(*):1024 on slave 20141006-194204-3142697795-43016-15803-0 at slave(64)@67.195.81.187:43016 (pomona.apache.org) I1006 19:42:05.189381 15817 slave.cpp:1023] Got assigned task 0 for framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.189450 15830 hierarchical_allocator_process.hpp:563] Recovered disk(*):1024; ports(*):[31000-32000] (total allocatable: disk(*):1024; ports(*):[31000-32000]) on slave 20141006-194204-3142697795-43016-15803-0 from framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.189481 15830 hierarchical_allocator_process.hpp:599] Framework 20141006-194204-3142697795-43016-15803-0000 filtered slave 20141006-194204-3142697795-43016-15803-0 for 5secs I1006 19:42:05.189556 15817 slave.cpp:1133] Launching task 0 for framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.191867 15817 exec.cpp:132] Version: 0.21.0 I1006 19:42:05.191932 15824 exec.cpp:182] Executor started at: executor(30)@67.195.81.187:43016 with pid 15803 I1006 19:42:05.191978 15817 slave.cpp:1246] Queuing task '0' for executor default of framework '20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.192011 15817 slave.cpp:554] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_DiskUsage_gDUWFr/slaves/20141006-194204-3142697795-43016-15803-0/frameworks/20141006-194204-3142697795-43016-15803-0000/executors/default/runs/82905578-9585-482c-b137-cfe8a128d946' I1006 19:42:05.192036 15817 slave.cpp:1756] Got registration for executor 'default' of framework 20141006-194204-3142697795-43016-15803-0000 from executor(30)@67.195.81.187:43016 I1006 19:42:05.192116 15817 slave.cpp:1875] Flushing queued task 0 for executor 'default' of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.192150 15831 exec.cpp:206] Executor registered on slave 20141006-194204-3142697795-43016-15803-0 I1006 19:42:05.192188 15817 slave.cpp:2611] Monitoring executor 'default' of framework '20141006-194204-3142697795-43016-15803-0000' in container '82905578-9585-482c-b137-cfe8a128d946' I1006 19:42:05.193032 15831 exec.cpp:218] Executor::registered took 12723ns I1006 19:42:05.193074 15831 exec.cpp:293] Executor asked to run task '0' I1006 19:42:05.193097 15831 exec.cpp:302] Executor::launchTask took 15367ns I1006 19:42:05.193979 15831 exec.cpp:525] Executor sending status update TASK_RUNNING (UUID: 4614714d-25f0-4911-b529-7b75fae20002) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.194059 15831 slave.cpp:2109] Handling status update TASK_RUNNING (UUID: 4614714d-25f0-4911-b529-7b75fae20002) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 from executor(30)@67.195.81.187:43016 I1006 19:42:05.194144 15828 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 4614714d-25f0-4911-b529-7b75fae20002) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.194157 15828 status_update_manager.cpp:499] Creating StatusUpdate stream for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.194217 15828 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 4614714d-25f0-4911-b529-7b75fae20002) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 to [email protected]:43016 I1006 19:42:05.194314 15817 master.cpp:3301] Forwarding status update TASK_RUNNING (UUID: 4614714d-25f0-4911-b529-7b75fae20002) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.194365 15822 slave.cpp:2266] Status update manager successfully handled status update TASK_RUNNING (UUID: 4614714d-25f0-4911-b529-7b75fae20002) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.194367 15817 master.cpp:3273] Status update TASK_RUNNING (UUID: 4614714d-25f0-4911-b529-7b75fae20002) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 from slave 20141006-194204-3142697795-43016-15803-0 at slave(64)@67.195.81.187:43016 (pomona.apache.org) I1006 19:42:05.194386 15822 slave.cpp:2272] Sending acknowledgement for status update TASK_RUNNING (UUID: 4614714d-25f0-4911-b529-7b75fae20002) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 to executor(30)@67.195.81.187:43016 I1006 19:42:05.194450 15827 exec.cpp:339] Executor received status update acknowledgement 4614714d-25f0-4911-b529-7b75fae20002 for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.194463 15819 sched.cpp:635] Scheduler::statusUpdate took 24798ns I1006 19:42:05.194545 15821 master.cpp:2777] Forwarding status update acknowledgement 4614714d-25f0-4911-b529-7b75fae20002 for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 to slave 20141006-194204-3142697795-43016-15803-0 at slave(64)@67.195.81.187:43016 (pomona.apache.org) I1006 19:42:05.194658 15821 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 4614714d-25f0-4911-b529-7b75fae20002) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.194679 15819 slave.cpp:2669] Executor 'default' of framework 20141006-194204-3142697795-43016-15803-0000 exited with status 0 I1006 19:42:05.195574 15819 slave.cpp:2109] Handling status update TASK_LOST (UUID: 03657af1-b8ca-4008-8147-e41c53b5a93d) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 from @0.0.0.0:0 I1006 19:42:05.195595 15819 slave.cpp:3989] Terminating task 0 I1006 19:42:05.195688 15819 slave.cpp:1696] Status update manager successfully handled status update acknowledgement (UUID: 4614714d-25f0-4911-b529-7b75fae20002) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:05.195720 15822 master.cpp:3353] Executor default of framework 20141006-194204-3142697795-43016-15803-0000 on slave 20141006-194204-3142697795-43016-15803-0 at slave(64)@67.195.81.187:43016 (pomona.apache.org) exited with status 0 I1006 19:42:05.195742 15822 master.cpp:4514] Removing executor 'default' with resources of framework 20141006-194204-3142697795-43016-15803-0000 on slave 20141006-194204-3142697795-43016-15803-0 at slave(64)@67.195.81.187:43016 (pomona.apache.org) I1006 19:42:05.195781 15823 status_update_manager.cpp:320] Received status update TASK_LOST (UUID: 03657af1-b8ca-4008-8147-e41c53b5a93d) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.592005 15823 status_update_manager.cpp:373] Forwarding status update TASK_LOST (UUID: 03657af1-b8ca-4008-8147-e41c53b5a93d) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 to [email protected]:43016 I1006 19:42:07.592191 15823 slave.cpp:2266] Status update manager successfully handled status update TASK_LOST (UUID: 03657af1-b8ca-4008-8147-e41c53b5a93d) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.592232 15826 master.cpp:3301] Forwarding status update TASK_LOST (UUID: 03657af1-b8ca-4008-8147-e41c53b5a93d) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.592381 15830 sched.cpp:635] Scheduler::statusUpdate took 16216ns I1006 19:42:07.592381 15826 master.cpp:3273] Status update TASK_LOST (UUID: 03657af1-b8ca-4008-8147-e41c53b5a93d) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 from slave 20141006-194204-3142697795-43016-15803-0 at slave(64)@67.195.81.187:43016 (pomona.apache.org) I1006 19:42:07.592470 15826 master.cpp:4485] Removing task 0 with resources cpus(*):2; mem(*):1024 of framework 20141006-194204-3142697795-43016-15803-0000 on slave 20141006-194204-3142697795-43016-15803-0 at slave(64)@67.195.81.187:43016 (pomona.apache.org) I1006 19:42:07.592509 15826 master.cpp:2777] Forwarding status update acknowledgement 03657af1-b8ca-4008-8147-e41c53b5a93d for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 to slave 20141006-194204-3142697795-43016-15803-0 at slave(64)@67.195.81.187:43016 (pomona.apache.org) I1006 19:42:07.592551 15827 hierarchical_allocator_process.hpp:563] Recovered cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 20141006-194204-3142697795-43016-15803-0 from framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.592591 15828 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 03657af1-b8ca-4008-8147-e41c53b5a93d) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.592617 15828 status_update_manager.cpp:530] Cleaning up status update stream for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.592720 15822 slave.cpp:1696] Status update manager successfully handled status update acknowledgement (UUID: 03657af1-b8ca-4008-8147-e41c53b5a93d) for task 0 of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.592743 15822 slave.cpp:4028] Completing task 0 I1006 19:42:07.592753 15822 slave.cpp:2805] Cleaning up executor 'default' of framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.592840 15828 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_gDUWFr/slaves/20141006-194204-3142697795-43016-15803-0/frameworks/20141006-194204-3142697795-43016-15803-0000/executors/default/runs/82905578-9585-482c-b137-cfe8a128d946' for gc 1.0000029852182weeks in the future I1006 19:42:07.592885 15822 slave.cpp:2880] Cleaning up framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.592893 15828 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_gDUWFr/slaves/20141006-194204-3142697795-43016-15803-0/frameworks/20141006-194204-3142697795-43016-15803-0000/executors/default' for gc 1.0000029852182weeks in the future I1006 19:42:07.592939 15829 status_update_manager.cpp:282] Closing status update streams for framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.592986 15818 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_gDUWFr/slaves/20141006-194204-3142697795-43016-15803-0/frameworks/20141006-194204-3142697795-43016-15803-0000' for gc 1.0000029852182weeks in the future I1006 19:42:07.608999 15821 slave.cpp:3126] Current usage 90.00%. Max allowed age: 0ns I1006 19:42:07.609114 15820 hierarchical_allocator_process.hpp:734] Offering disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 20141006-194204-3142697795-43016-15803-0 to framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.609201 15820 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 132527ns I1006 19:42:07.609241 15820 master.hpp:868] Adding offer 20141006-194204-3142697795-43016-15803-1 with resources disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 20141006-194204-3142697795-43016-15803-0 (pomona.apache.org) I1006 19:42:07.609274 15820 master.cpp:3679] Sending 1 offers to framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.609472 15826 sched.cpp:544] Scheduler::resourceOffers took 13142ns tests/gc_tests.cpp:675: Failure Value of: os::exists(executorDir) Actual: true Expected: false I1006 19:42:07.629362 15822 master.cpp:767] Framework 20141006-194204-3142697795-43016-15803-0000 disconnected I1006 19:42:07.629374 15822 master.cpp:1705] Disconnecting framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.629379 15822 master.cpp:1721] Deactivating framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.629429 15822 master.hpp:877] Removing offer 20141006-194204-3142697795-43016-15803-1 with resources disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 20141006-194204-3142697795-43016-15803-0 (pomona.apache.org) I1006 19:42:07.629468 15822 master.cpp:789] Giving framework 20141006-194204-3142697795-43016-15803-0000 0ns to failover I1006 19:42:07.629498 15831 hierarchical_allocator_process.hpp:405] Deactivated framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.629549 15827 master.cpp:3549] Framework failover timeout, removing framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.629560 15827 master.cpp:4041] Removing framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.629601 15831 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 20141006-194204-3142697795-43016-15803-0 from framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.629634 15827 slave.cpp:1429] Asked to shut down framework 20141006-194204-3142697795-43016-15803-0000 by [email protected]:43016 W1006 19:42:07.629648 15827 slave.cpp:1444] Cannot shut down unknown framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.629688 15831 hierarchical_allocator_process.hpp:360] Removed framework 20141006-194204-3142697795-43016-15803-0000 I1006 19:42:07.629696 15803 master.cpp:676] Master terminating I1006 19:42:07.629833 15823 slave.cpp:2430] [email protected]:43016 exited W1006 19:42:07.629848 15823 slave.cpp:2433] Master disconnected! Waiting for a new master to be elected F1006 19:42:07.629848 15803 logging.cpp:57] RAW: Pure virtual method called @ 0x2b173ee9a06d google::LogMessage::Fail() @ 0x2b173eea1766 google::RawLog__() @ 0x5043d6 mesos::internal::tests::Cluster::Slaves::shutdown() @ 0x7b2614 mesos::internal::tests::MesosTest::ShutdownSlaves() @ 0x9a4573 testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x99b710 testing::Test::Run() @ 0x99b7ee testing::TestInfo::Run() @ 0x99b8f5 testing::TestCase::Run() @ 0x99bb98 testing::internal::UnitTestImpl::RunAllTests() @ 0x99be37 testing::UnitTest::Run() @ 0x491483 main @ 0x2b1740bc1ec5 (unknown) @ 0x49d478 (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 Test finished Exit status: 2 Build step 'Execute shell' marked build as failure Recording test results
