See 
<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2096/changes>

Changes:

[tstclair] Fix protobuf detection on systems with Python 3 as default (part2)

------------------------------------------
[...truncated 64474 lines...]
I0910 19:26:48.764413 16939 registrar.cpp:313] Recovering registrar
I0910 19:26:48.764499 16949 recover.cpp:542] Updating replica status to VOTING
I0910 19:26:48.764755 16939 leveldb.cpp:306] Persisting metadata (8 bytes) to 
leveldb took 171301ns
I0910 19:26:48.764775 16939 replica.cpp:320] Persisted replica status to VOTING
I0910 19:26:48.764832 16942 recover.cpp:556] Successfully joined the Paxos group
I0910 19:26:48.764926 16942 recover.cpp:440] Recover process terminated
I0910 19:26:48.765118 16938 log.cpp:656] Attempting to start the writer
I0910 19:26:48.765650 16939 replica.cpp:474] Replica received implicit promise 
request with proposal 1
I0910 19:26:48.766057 16939 leveldb.cpp:306] Persisting metadata (8 bytes) to 
leveldb took 385184ns
I0910 19:26:48.766075 16939 replica.cpp:342] Persisted promised to 1
I0910 19:26:48.766372 16948 coordinator.cpp:230] Coordinator attemping to fill 
missing position
I0910 19:26:48.767041 16940 replica.cpp:375] Replica received explicit promise 
request for position 0 with proposal 2
I0910 19:26:48.767186 16940 leveldb.cpp:343] Persisting action (8 bytes) to 
leveldb took 118428ns
I0910 19:26:48.767204 16940 replica.cpp:676] Persisted action at 0
I0910 19:26:48.767714 16942 replica.cpp:508] Replica received write request for 
position 0
I0910 19:26:48.767742 16942 leveldb.cpp:438] Reading position from leveldb took 
11125ns
I0910 19:26:48.767921 16942 leveldb.cpp:343] Persisting action (14 bytes) to 
leveldb took 160862ns
I0910 19:26:48.767941 16942 replica.cpp:676] Persisted action at 0
I0910 19:26:48.768261 16938 replica.cpp:655] Replica received learned notice 
for position 0
I0910 19:26:48.768455 16938 leveldb.cpp:343] Persisting action (16 bytes) to 
leveldb took 172469ns
I0910 19:26:48.768476 16938 replica.cpp:676] Persisted action at 0
I0910 19:26:48.768486 16938 replica.cpp:661] Replica learned NOP action at 
position 0
I0910 19:26:48.768796 16945 log.cpp:672] Writer started with ending position 0
I0910 19:26:48.769300 16941 leveldb.cpp:438] Reading position from leveldb took 
15090ns
I0910 19:26:48.770851 16940 registrar.cpp:346] Successfully fetched the 
registry (0B)
I0910 19:26:48.770884 16940 registrar.cpp:422] Attempting to update the 
'registry'
I0910 19:26:48.772500 16939 log.cpp:680] Attempting to append 140 bytes to the 
log
I0910 19:26:48.772573 16944 coordinator.cpp:340] Coordinator attempting to 
write APPEND action at position 1
I0910 19:26:48.773274 16947 replica.cpp:508] Replica received write request for 
position 1
I0910 19:26:48.773840 16947 leveldb.cpp:343] Persisting action (159 bytes) to 
leveldb took 539664ns
I0910 19:26:48.773866 16947 replica.cpp:676] Persisted action at 1
I0910 19:26:48.774436 16936 replica.cpp:655] Replica received learned notice 
for position 1
I0910 19:26:48.774601 16936 leveldb.cpp:343] Persisting action (161 bytes) to 
leveldb took 142685ns
I0910 19:26:48.774621 16936 replica.cpp:676] Persisted action at 1
I0910 19:26:48.774631 16936 replica.cpp:661] Replica learned APPEND action at 
position 1
I0910 19:26:48.774991 16942 registrar.cpp:479] Successfully updated 'registry'
I0910 19:26:48.775075 16937 log.cpp:699] Attempting to truncate the log to 1
I0910 19:26:48.775092 16942 registrar.cpp:372] Successfully recovered registrar
I0910 19:26:48.775182 16936 coordinator.cpp:340] Coordinator attempting to 
write TRUNCATE action at position 2
I0910 19:26:48.775233 16934 master.cpp:1070] Recovered 0 slaves from the 
Registry (102B) ; allowing 10mins for slaves to re-register
I0910 19:26:48.775624 16944 replica.cpp:508] Replica received write request for 
position 2
I0910 19:26:48.775789 16944 leveldb.cpp:343] Persisting action (16 bytes) to 
leveldb took 137678ns
I0910 19:26:48.775809 16944 replica.cpp:676] Persisted action at 2
I0910 19:26:48.776204 16943 replica.cpp:655] Replica received learned notice 
for position 2
I0910 19:26:48.776366 16943 leveldb.cpp:343] Persisting action (18 bytes) to 
leveldb took 139485ns
I0910 19:26:48.776398 16943 leveldb.cpp:401] Deleting ~1 keys from leveldb took 
14827ns
I0910 19:26:48.776412 16943 replica.cpp:676] Persisted action at 2
I0910 19:26:48.776422 16943 replica.cpp:661] Replica learned TRUNCATE action at 
position 2
I0910 19:26:48.788455 16941 slave.cpp:167] Slave started on 
206)@67.195.81.186:41538
I0910 19:26:48.788486 16941 credentials.hpp:84] Loading credential for 
authentication from 
'/tmp/GarbageCollectorIntegrationTest_DiskUsage_rWhuy4/credential'
I0910 19:26:48.788589 16941 slave.cpp:274] Slave using credential for: 
test-principal
I0910 19:26:48.788750 16941 slave.cpp:287] Slave resources: cpus(*):2; 
mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0910 19:26:48.788856 16941 slave.cpp:315] Slave hostname: penates.apache.org
I0910 19:26:48.788871 16941 slave.cpp:316] Slave checkpoint: false
I0910 19:26:48.789297 16945 state.cpp:33] Recovering state from 
'/tmp/GarbageCollectorIntegrationTest_DiskUsage_rWhuy4/meta'
I0910 19:26:48.789433 16945 status_update_manager.cpp:193] Recovering status 
update manager
I0910 19:26:48.789624 16939 slave.cpp:3202] Finished recovery
I0910 19:26:48.789911 16937 slave.cpp:598] New master detected at 
[email protected]:41538
I0910 19:26:48.789952 16937 slave.cpp:672] Authenticating with master 
[email protected]:41538
I0910 19:26:48.789994 16948 status_update_manager.cpp:167] New master detected 
at [email protected]:41538
I0910 19:26:48.790019 16937 slave.cpp:645] Detecting new master
I0910 19:26:48.790046 16936 authenticatee.hpp:128] Creating new client SASL 
connection
I0910 19:26:48.922570 16936 master.cpp:3653] Authenticating 
slave(206)@67.195.81.186:41538
I0910 19:26:48.922710 16934 authenticator.hpp:156] Creating new server SASL 
connection
I0910 19:26:48.922807 16934 authenticatee.hpp:219] Received SASL authentication 
mechanisms: CRAM-MD5
I0910 19:26:48.922827 16934 authenticatee.hpp:245] Attempting to authenticate 
with mechanism 'CRAM-MD5'
I0910 19:26:48.922914 16940 authenticator.hpp:262] Received SASL authentication 
start
I0910 19:26:48.922978 16940 authenticator.hpp:384] Authentication requires more 
steps
I0910 19:26:48.923027 16940 authenticatee.hpp:265] Received SASL authentication 
step
I0910 19:26:48.923100 16948 authenticator.hpp:290] Received SASL authentication 
step
I0910 19:26:48.923125 16948 auxprop.cpp:81] Request to lookup properties for 
user: 'test-principal' realm: 'penates.apache.org' server FQDN: 
'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false 
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0910 19:26:48.923135 16948 auxprop.cpp:153] Looking up auxiliary property 
'*userPassword'
I0910 19:26:48.923147 16948 auxprop.cpp:153] Looking up auxiliary property 
'*cmusaslsecretCRAM-MD5'
I0910 19:26:48.923159 16948 auxprop.cpp:81] Request to lookup properties for 
user: 'test-principal' realm: 'penates.apache.org' server FQDN: 
'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false 
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0910 19:26:48.923168 16948 auxprop.cpp:103] Skipping auxiliary property 
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0910 19:26:48.923177 16948 auxprop.cpp:103] Skipping auxiliary property 
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0910 19:26:48.923192 16948 authenticator.hpp:376] Authentication success
I0910 19:26:48.923270 16947 authenticatee.hpp:305] Authentication success
I0910 19:26:48.923288 16937 master.cpp:3693] Successfully authenticated 
principal 'test-principal' at slave(206)@67.195.81.186:41538
I0910 19:26:48.923444 16947 slave.cpp:729] Successfully authenticated with 
master [email protected]:41538
I0910 19:26:48.923501 16947 slave.cpp:980] Will retry registration in 
7.844963ms if necessary
I0910 19:26:48.923569 16946 master.cpp:2843] Registering slave at 
slave(206)@67.195.81.186:41538 (penates.apache.org) with id 
20140910-192648-3125920579-41538-16920-0
I0910 19:26:48.923704 16937 registrar.cpp:422] Attempting to update the 
'registry'
I0910 19:26:48.925449 16943 log.cpp:680] Attempting to append 337 bytes to the 
log
I0910 19:26:48.925525 16940 coordinator.cpp:340] Coordinator attempting to 
write APPEND action at position 3
I0910 19:26:48.925945 16942 replica.cpp:508] Replica received write request for 
position 3
I0910 19:26:48.926174 16942 leveldb.cpp:343] Persisting action (356 bytes) to 
leveldb took 207163ns
I0910 19:26:48.926193 16942 replica.cpp:676] Persisted action at 3
I0910 19:26:48.926488 16939 replica.cpp:655] Replica received learned notice 
for position 3
I0910 19:26:48.926950 16939 leveldb.cpp:343] Persisting action (358 bytes) to 
leveldb took 437632ns
I0910 19:26:48.926970 16939 replica.cpp:676] Persisted action at 3
I0910 19:26:48.926980 16939 replica.cpp:661] Replica learned APPEND action at 
position 3
I0910 19:26:48.927336 16949 registrar.cpp:479] Successfully updated 'registry'
I0910 19:26:48.927433 16935 log.cpp:699] Attempting to truncate the log to 3
I0910 19:26:48.927454 16948 master.cpp:2883] Registered slave 
20140910-192648-3125920579-41538-16920-0 at slave(206)@67.195.81.186:41538 
(penates.apache.org)
I0910 19:26:48.927476 16948 master.cpp:4126] Adding slave 
20140910-192648-3125920579-41538-16920-0 at slave(206)@67.195.81.186:41538 
(penates.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; 
ports(*):[31000-32000]
I0910 19:26:48.927518 16947 coordinator.cpp:340] Coordinator attempting to 
write TRUNCATE action at position 4
I0910 19:26:48.927639 16940 slave.cpp:763] Registered with master 
[email protected]:41538; given slave ID 
20140910-192648-3125920579-41538-16920-0
I0910 19:26:48.927705 16940 slave.cpp:2329] Received ping from 
slave-observer(184)@67.195.81.186:41538
I0910 19:26:48.927729 16939 hierarchical_allocator_process.hpp:442] Added slave 
20140910-192648-3125920579-41538-16920-0 (penates.apache.org) with cpus(*):2; 
mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; 
disk(*):1024; ports(*):[31000-32000] available)
I0910 19:26:48.927800 16939 hierarchical_allocator_process.hpp:679] Performed 
allocation for slave 20140910-192648-3125920579-41538-16920-0 in 12139ns
I0910 19:26:48.928058 16935 replica.cpp:508] Replica received write request for 
position 4
I0910 19:26:48.928243 16935 leveldb.cpp:343] Persisting action (16 bytes) to 
leveldb took 163297ns
I0910 19:26:48.928262 16935 replica.cpp:676] Persisted action at 4
I0910 19:26:48.928544 16944 replica.cpp:655] Replica received learned notice 
for position 4
I0910 19:26:48.928731 16944 leveldb.cpp:343] Persisting action (18 bytes) to 
leveldb took 164207ns
I0910 19:26:48.928776 16944 leveldb.cpp:401] Deleting ~2 keys from leveldb took 
25159ns
I0910 19:26:48.928791 16944 replica.cpp:676] Persisted action at 4
I0910 19:26:48.928802 16944 replica.cpp:661] Replica learned TRUNCATE action at 
position 4
I0910 19:26:48.931118 16920 sched.cpp:137] Version: 0.21.0
I0910 19:26:48.931313 16943 sched.cpp:233] New master detected at 
[email protected]:41538
I0910 19:26:48.931337 16943 sched.cpp:283] Authenticating with master 
[email protected]:41538
I0910 19:26:48.931463 16936 authenticatee.hpp:128] Creating new client SASL 
connection
I0910 19:26:48.931572 16942 master.cpp:3653] Authenticating 
[email protected]:41538
I0910 19:26:48.931699 16946 authenticator.hpp:156] Creating new server SASL 
connection
I0910 19:26:48.931777 16936 authenticatee.hpp:219] Received SASL authentication 
mechanisms: CRAM-MD5
I0910 19:26:48.931799 16936 authenticatee.hpp:245] Attempting to authenticate 
with mechanism 'CRAM-MD5'
I0910 19:26:48.931850 16946 authenticator.hpp:262] Received SASL authentication 
start
I0910 19:26:48.931911 16946 authenticator.hpp:384] Authentication requires more 
steps
I0910 19:26:48.931960 16946 authenticatee.hpp:265] Received SASL authentication 
step
I0910 19:26:48.932018 16936 authenticator.hpp:290] Received SASL authentication 
step
I0910 19:26:48.932046 16936 auxprop.cpp:81] Request to lookup properties for 
user: 'test-principal' realm: 'penates.apache.org' server FQDN: 
'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false 
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0910 19:26:48.932060 16936 auxprop.cpp:153] Looking up auxiliary property 
'*userPassword'
I0910 19:26:48.932071 16936 auxprop.cpp:153] Looking up auxiliary property 
'*cmusaslsecretCRAM-MD5'
I0910 19:26:48.932085 16936 auxprop.cpp:81] Request to lookup properties for 
user: 'test-principal' realm: 'penates.apache.org' server FQDN: 
'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false 
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0910 19:26:48.932093 16936 auxprop.cpp:103] Skipping auxiliary property 
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0910 19:26:48.932101 16936 auxprop.cpp:103] Skipping auxiliary property 
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0910 19:26:48.932117 16936 authenticator.hpp:376] Authentication success
I0910 19:26:48.932165 16947 authenticatee.hpp:305] Authentication success
I0910 19:26:48.932178 16936 master.cpp:3693] Successfully authenticated 
principal 'test-principal' at 
[email protected]:41538
I0910 19:26:48.932313 16938 sched.cpp:357] Successfully authenticated with 
master [email protected]:41538
I0910 19:26:48.932334 16938 sched.cpp:476] Sending registration request to 
[email protected]:41538
I0910 19:26:48.932395 16947 master.cpp:1331] Received registration request from 
[email protected]:41538
I0910 19:26:48.990823 16947 master.cpp:1291] Authorizing framework principal 
'test-principal' to receive offers for role '*'
I0910 19:26:48.991019 16947 master.cpp:1390] Registering framework 
20140910-192648-3125920579-41538-16920-0000 at 
[email protected]:41538
I0910 19:26:48.991130 16938 hierarchical_allocator_process.hpp:329] Added 
framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.991160 16949 sched.cpp:407] Framework registered with 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.991219 16949 sched.cpp:421] Scheduler::registered took 36161ns
I0910 19:26:48.991209 16938 hierarchical_allocator_process.hpp:734] Offering 
cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 
20140910-192648-3125920579-41538-16920-0 to framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.991371 16938 hierarchical_allocator_process.hpp:659] Performed 
allocation for 1 slaves in 214618ns
I0910 19:26:48.991480 16935 master.hpp:861] Adding offer 
20140910-192648-3125920579-41538-16920-0 with resources cpus(*):2; mem(*):1024; 
disk(*):1024; ports(*):[31000-32000] on slave 
20140910-192648-3125920579-41538-16920-0 (penates.apache.org)
I0910 19:26:48.991556 16935 master.cpp:3600] Sending 1 offers to framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.991824 16938 sched.cpp:544] Scheduler::resourceOffers took 
162782ns
I0910 19:26:48.992038 16935 master.hpp:871] Removing offer 
20140910-192648-3125920579-41538-16920-0 with resources cpus(*):2; mem(*):1024; 
disk(*):1024; ports(*):[31000-32000] on slave 
20140910-192648-3125920579-41538-16920-0 (penates.apache.org)
I0910 19:26:48.992117 16935 master.cpp:2201] Processing reply for offers: [ 
20140910-192648-3125920579-41538-16920-0 ] on slave 
20140910-192648-3125920579-41538-16920-0 at slave(206)@67.195.81.186:41538 
(penates.apache.org) for framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.992144 16935 master.cpp:2284] Authorizing framework principal 
'test-principal' to launch task 0 as user 'jenkins'
I0910 19:26:48.992529 16938 master.hpp:833] Adding task 0 with resources 
cpus(*):2; mem(*):1024 on slave 20140910-192648-3125920579-41538-16920-0 
(penates.apache.org)
I0910 19:26:48.992564 16938 master.cpp:2350] Launching task 0 of framework 
20140910-192648-3125920579-41538-16920-0000 with resources cpus(*):2; 
mem(*):1024 on slave 20140910-192648-3125920579-41538-16920-0 at 
slave(206)@67.195.81.186:41538 (penates.apache.org)
I0910 19:26:48.992769 16947 slave.cpp:1011] Got assigned task 0 for framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.992931 16938 hierarchical_allocator_process.hpp:563] Recovered 
disk(*):1024; ports(*):[31000-32000] (total allocatable: disk(*):1024; 
ports(*):[31000-32000]) on slave 20140910-192648-3125920579-41538-16920-0 from 
framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.992964 16938 hierarchical_allocator_process.hpp:599] Framework 
20140910-192648-3125920579-41538-16920-0000 filtered slave 
20140910-192648-3125920579-41538-16920-0 for 5secs
I0910 19:26:48.992992 16947 slave.cpp:1121] Launching task 0 for framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.996129 16947 exec.cpp:132] Version: 0.21.0
I0910 19:26:48.996273 16947 slave.cpp:1231] Queuing task '0' for executor 
default of framework '20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.996318 16947 slave.cpp:552] Successfully attached file 
'/tmp/GarbageCollectorIntegrationTest_DiskUsage_rWhuy4/slaves/20140910-192648-3125920579-41538-16920-0/frameworks/20140910-192648-3125920579-41538-16920-0000/executors/default/runs/8be164f1-e50c-4928-ab2f-2816b07d1754'
I0910 19:26:48.996323 16935 exec.cpp:182] Executor started at: 
executor(64)@67.195.81.186:41538 with pid 16920
I0910 19:26:48.996358 16947 slave.cpp:2542] Monitoring executor 'default' of 
framework '20140910-192648-3125920579-41538-16920-0000' in container 
'8be164f1-e50c-4928-ab2f-2816b07d1754'
I0910 19:26:48.996428 16947 slave.cpp:1741] Got registration for executor 
'default' of framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.996742 16947 slave.cpp:1859] Flushing queued task 0 for executor 
'default' of framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.996820 16942 exec.cpp:206] Executor registered on slave 
20140910-192648-3125920579-41538-16920-0
I0910 19:26:48.998122 16942 exec.cpp:218] Executor::registered took 12690ns
I0910 19:26:48.998186 16942 exec.cpp:293] Executor asked to run task '0'
I0910 19:26:48.998219 16942 exec.cpp:302] Executor::launchTask took 19786ns
I0910 19:26:48.999512 16942 exec.cpp:525] Executor sending status update 
TASK_RUNNING (UUID: 1e660cfb-d289-4504-b3c8-abc1681e7e70) for task 0 of 
framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.999596 16942 slave.cpp:2093] Handling status update TASK_RUNNING 
(UUID: 1e660cfb-d289-4504-b3c8-abc1681e7e70) for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000 from 
executor(64)@67.195.81.186:41538
I0910 19:26:48.999688 16942 status_update_manager.cpp:320] Received status 
update TASK_RUNNING (UUID: 1e660cfb-d289-4504-b3c8-abc1681e7e70) for task 0 of 
framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.999706 16942 status_update_manager.cpp:499] Creating 
StatusUpdate stream for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:48.999881 16942 status_update_manager.cpp:373] Forwarding status 
update TASK_RUNNING (UUID: 1e660cfb-d289-4504-b3c8-abc1681e7e70) for task 0 of 
framework 20140910-192648-3125920579-41538-16920-0000 to 
[email protected]:41538
I0910 19:26:49.000028 16938 master.cpp:3212] Forwarding status update 
TASK_RUNNING (UUID: 1e660cfb-d289-4504-b3c8-abc1681e7e70) for task 0 of 
framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:49.000020 16942 slave.cpp:2250] Status update manager successfully 
handled status update TASK_RUNNING (UUID: 1e660cfb-d289-4504-b3c8-abc1681e7e70) 
for task 0 of framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:49.000188 16942 slave.cpp:2256] Sending acknowledgement for status 
update TASK_RUNNING (UUID: 1e660cfb-d289-4504-b3c8-abc1681e7e70) for task 0 of 
framework 20140910-192648-3125920579-41538-16920-0000 to 
executor(64)@67.195.81.186:41538
I0910 19:26:49.000252 16938 master.cpp:3178] Status update TASK_RUNNING (UUID: 
1e660cfb-d289-4504-b3c8-abc1681e7e70) for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000 from slave 
20140910-192648-3125920579-41538-16920-0 at slave(206)@67.195.81.186:41538 
(penates.apache.org)
I0910 19:26:49.000293 16936 exec.cpp:339] Executor received status update 
acknowledgement 1e660cfb-d289-4504-b3c8-abc1681e7e70 for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:49.000380 16943 sched.cpp:635] Scheduler::statusUpdate took 29257ns
I0910 19:26:49.000679 16942 master.cpp:2693] Forwarding status update 
acknowledgement 1e660cfb-d289-4504-b3c8-abc1681e7e70 for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000 to slave 
20140910-192648-3125920579-41538-16920-0 at slave(206)@67.195.81.186:41538 
(penates.apache.org)
I0910 19:26:49.000872 16942 slave.cpp:2600] Executor 'default' of framework 
20140910-192648-3125920579-41538-16920-0000 exited with status 0
I0910 19:26:49.000949 16941 status_update_manager.cpp:398] Received status 
update acknowledgement (UUID: 1e660cfb-d289-4504-b3c8-abc1681e7e70) for task 0 
of framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:49.002207 16942 slave.cpp:2093] Handling status update TASK_LOST 
(UUID: 83e0e288-f0d6-4c67-815b-6d25cd6a7cb2) for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000 from @0.0.0.0:0
I0910 19:26:49.002238 16942 slave.cpp:3913] Terminating task 0
I0910 19:26:49.002379 16942 slave.cpp:1681] Status update manager successfully 
handled status update acknowledgement (UUID: 
1e660cfb-d289-4504-b3c8-abc1681e7e70) for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000
2014-09-10 
19:26:49,082:16920(0x2ba68c803700):ZOO_ERROR@handle_socket_error_msg@1697: 
Socket [127.0.0.1:50276] zk retcode=-4, errno=111(Connection refused): server 
refused to accept the client
I0910 19:26:49.002473 16944 master.cpp:3261] Executor default of framework 
20140910-192648-3125920579-41538-16920-0000 on slave 
20140910-192648-3125920579-41538-16920-0 at slave(206)@67.195.81.186:41538 
(penates.apache.org) exited with status 0
I0910 19:26:51.357895 16942 status_update_manager.cpp:320] Received status 
update TASK_LOST (UUID: 83e0e288-f0d6-4c67-815b-6d25cd6a7cb2) for task 0 of 
framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.357982 16942 status_update_manager.cpp:373] Forwarding status 
update TASK_LOST (UUID: 83e0e288-f0d6-4c67-815b-6d25cd6a7cb2) for task 0 of 
framework 20140910-192648-3125920579-41538-16920-0000 to 
[email protected]:41538
I0910 19:26:51.358150 16942 slave.cpp:2250] Status update manager successfully 
handled status update TASK_LOST (UUID: 83e0e288-f0d6-4c67-815b-6d25cd6a7cb2) 
for task 0 of framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.358253 16945 master.cpp:3212] Forwarding status update TASK_LOST 
(UUID: 83e0e288-f0d6-4c67-815b-6d25cd6a7cb2) for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.358306 16945 master.cpp:3178] Status update TASK_LOST (UUID: 
83e0e288-f0d6-4c67-815b-6d25cd6a7cb2) for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000 from slave 
20140910-192648-3125920579-41538-16920-0 at slave(206)@67.195.81.186:41538 
(penates.apache.org)
I0910 19:26:51.358361 16945 master.hpp:851] Removing task 0 with resources 
cpus(*):2; mem(*):1024 on slave 20140910-192648-3125920579-41538-16920-0 
(penates.apache.org)
I0910 19:26:51.358428 16943 sched.cpp:635] Scheduler::statusUpdate took 11779ns
I0910 19:26:51.358537 16946 hierarchical_allocator_process.hpp:563] Recovered 
cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; 
ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 
20140910-192648-3125920579-41538-16920-0 from framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.358585 16937 master.cpp:2693] Forwarding status update 
acknowledgement 83e0e288-f0d6-4c67-815b-6d25cd6a7cb2 for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000 to slave 
20140910-192648-3125920579-41538-16920-0 at slave(206)@67.195.81.186:41538 
(penates.apache.org)
I0910 19:26:51.358681 16937 status_update_manager.cpp:398] Received status 
update acknowledgement (UUID: 83e0e288-f0d6-4c67-815b-6d25cd6a7cb2) for task 0 
of framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.358716 16937 status_update_manager.cpp:530] Cleaning up status 
update stream for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.358839 16944 slave.cpp:1681] Status update manager successfully 
handled status update acknowledgement (UUID: 
83e0e288-f0d6-4c67-815b-6d25cd6a7cb2) for task 0 of framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.358865 16944 slave.cpp:3952] Completing task 0
I0910 19:26:51.358880 16944 slave.cpp:2736] Cleaning up executor 'default' of 
framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.359010 16941 gc.cpp:56] Scheduling 
'/tmp/GarbageCollectorIntegrationTest_DiskUsage_rWhuy4/slaves/20140910-192648-3125920579-41538-16920-0/frameworks/20140910-192648-3125920579-41538-16920-0000/executors/default/runs/8be164f1-e50c-4928-ab2f-2816b07d1754'
 for gc 1.00000330565291weeks in the future
I0910 19:26:51.359025 16944 slave.cpp:2811] Cleaning up framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.359071 16941 gc.cpp:56] Scheduling 
'/tmp/GarbageCollectorIntegrationTest_DiskUsage_rWhuy4/slaves/20140910-192648-3125920579-41538-16920-0/frameworks/20140910-192648-3125920579-41538-16920-0000/executors/default'
 for gc 1.00000330565291weeks in the future
I0910 19:26:51.359107 16936 status_update_manager.cpp:282] Closing status 
update streams for framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.359122 16941 gc.cpp:56] Scheduling 
'/tmp/GarbageCollectorIntegrationTest_DiskUsage_rWhuy4/slaves/20140910-192648-3125920579-41538-16920-0/frameworks/20140910-192648-3125920579-41538-16920-0000'
 for gc 1.00000330565291weeks in the future
I0910 19:26:51.374511 16943 slave.cpp:3057] Current usage 90.00%. Max allowed 
age: 0ns
I0910 19:26:51.374598 16937 hierarchical_allocator_process.hpp:734] Offering 
disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 
20140910-192648-3125920579-41538-16920-0 to framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.374737 16937 hierarchical_allocator_process.hpp:659] Performed 
allocation for 1 slaves in 184926ns
I0910 19:26:51.374829 16949 master.hpp:861] Adding offer 
20140910-192648-3125920579-41538-16920-1 with resources disk(*):1024; 
ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 
20140910-192648-3125920579-41538-16920-0 (penates.apache.org)
I0910 19:26:51.374918 16949 master.cpp:3600] Sending 1 offers to framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.375082 16939 sched.cpp:544] Scheduler::resourceOffers took 
11642ns
tests/gc_tests.cpp:675: Failure
Value of: os::exists(executorDir)
  Actual: true
Expected: false
I0910 19:26:51.394896 16938 master.cpp:741] Framework 
20140910-192648-3125920579-41538-16920-0000 disconnected
I0910 19:26:51.394915 16938 master.cpp:1687] Deactivating framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.394991 16938 master.hpp:871] Removing offer 
20140910-192648-3125920579-41538-16920-1 with resources disk(*):1024; 
ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 
20140910-192648-3125920579-41538-16920-0 (penates.apache.org)
I0910 19:26:51.395015 16937 hierarchical_allocator_process.hpp:405] Deactivated 
framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.395074 16938 master.cpp:763] Giving framework 
20140910-192648-3125920579-41538-16920-0000 0ns to failover
I0910 19:26:51.395109 16937 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 20140910-192648-3125920579-41538-16920-0 from framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.395280 16948 master.cpp:3471] Framework failover timeout, 
removing framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.395305 16948 master.cpp:3976] Removing framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.395391 16941 slave.cpp:1414] Asked to shut down framework 
20140910-192648-3125920579-41538-16920-0000 by [email protected]:41538
W0910 19:26:51.395419 16941 slave.cpp:1429] Cannot shut down unknown framework 
20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.395443 16948 master.cpp:650] Master terminating
I0910 19:26:51.395524 16937 hierarchical_allocator_process.hpp:360] Removed 
framework 20140910-192648-3125920579-41538-16920-0000
I0910 19:26:51.395673 16945 slave.cpp:2361] [email protected]:41538 exited
W0910 19:26:51.395694 16945 slave.cpp:2364] Master disconnected! Waiting for a 
new master to be elected
F0910 19:26:51.395694 16920 logging.cpp:57] RAW: Pure virtual method called
    @     0x2ba2cbfc59bd  google::LogMessage::Fail()
    @     0x2ba2cbfcd0b6  google::RawLog__()
    @           0x505826  mesos::internal::tests::Cluster::Slaves::shutdown()
    @           0x79d2f4  mesos::internal::tests::MesosTest::ShutdownSlaves()
    @           0x98c153  
testing::internal::HandleExceptionsInMethodIfSupported<>()
    @           0x9832f0  testing::Test::Run()
    @           0x9833ce  testing::TestInfo::Run()
    @           0x9834d5  testing::TestCase::Run()
    @           0x983778  testing::internal::UnitTestImpl::RunAllTests()
    @           0x983a17  testing::UnitTest::Run()
    @           0x491cb3  main
    @     0x2ba2cdce4ec5  (unknown)
    @           0x4a02c8  (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

Reply via email to