See <https://builds.apache.org/job/Mesos-Ubuntu-distcheck/136/changes>
Changes:
[yujie.jay] Added infix operator for IntervalSet.
------------------------------------------
[...truncated 55666 lines...]
I0611 18:09:23.589572 6115 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 15.353854ms
I0611 18:09:23.589604 6115 replica.cpp:320] Persisted replica status to
STARTING
I0611 18:09:23.589752 6109 recover.cpp:451] Replica is in STARTING status
I0611 18:09:23.591280 6094 replica.cpp:638] Replica in STARTING status
received a broadcasted recover request
I0611 18:09:23.591599 6114 recover.cpp:188] Received a recover response from a
replica in STARTING status
I0611 18:09:23.592650 6106 recover.cpp:542] Updating replica status to VOTING
I0611 18:09:23.605653 6100 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 12.755195ms
I0611 18:09:23.605685 6100 replica.cpp:320] Persisted replica status to VOTING
I0611 18:09:23.605819 6102 recover.cpp:556] Successfully joined the Paxos group
I0611 18:09:23.605965 6102 recover.cpp:440] Recover process terminated
I0611 18:09:23.606390 6113 log.cpp:656] Attempting to start the writer
I0611 18:09:23.610357 6098 replica.cpp:474] Replica received implicit promise
request with proposal 1
I0611 18:09:23.625741 6098 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 15.359523ms
I0611 18:09:23.625773 6098 replica.cpp:342] Persisted promised to 1
I0611 18:09:23.626090 6105 coordinator.cpp:230] Coordinator attemping to fill
missing position
I0611 18:09:23.628659 6108 replica.cpp:375] Replica received explicit promise
request for position 0 with proposal 2
I0611 18:09:23.641851 6108 leveldb.cpp:343] Persisting action (8 bytes) to
leveldb took 13.167587ms
I0611 18:09:23.641883 6108 replica.cpp:676] Persisted action at 0
I0611 18:09:23.644033 6114 replica.cpp:508] Replica received write request for
position 0
I0611 18:09:23.644163 6114 leveldb.cpp:438] Reading position from leveldb took
15381ns
I0611 18:09:23.657951 6114 leveldb.cpp:343] Persisting action (14 bytes) to
leveldb took 13.767953ms
I0611 18:09:23.657985 6114 replica.cpp:676] Persisted action at 0
I0611 18:09:23.658998 6109 replica.cpp:655] Replica received learned notice
for position 0
I0611 18:09:23.674037 6109 leveldb.cpp:343] Persisting action (16 bytes) to
leveldb took 15.009351ms
I0611 18:09:23.674070 6109 replica.cpp:676] Persisted action at 0
I0611 18:09:23.674082 6109 replica.cpp:661] Replica learned NOP action at
position 0
I0611 18:09:23.674651 6116 log.cpp:672] Writer started with ending position 0
I0611 18:09:23.676365 6116 leveldb.cpp:438] Reading position from leveldb took
14026ns
I0611 18:09:23.679301 6096 registrar.cpp:346] Successfully fetched the
registry (0B)
I0611 18:09:23.679354 6096 registrar.cpp:422] Attempting to update the
'registry'
I0611 18:09:23.681777 6108 log.cpp:680] Attempting to append 137 bytes to the
log
I0611 18:09:23.681999 6100 coordinator.cpp:340] Coordinator attempting to
write APPEND action at position 1
I0611 18:09:23.684192 6105 replica.cpp:508] Replica received write request for
position 1
I0611 18:09:23.698125 6105 leveldb.cpp:343] Persisting action (156 bytes) to
leveldb took 13.907738ms
I0611 18:09:23.698158 6105 replica.cpp:676] Persisted action at 1
I0611 18:09:23.698647 6108 replica.cpp:655] Replica received learned notice
for position 1
I0611 18:09:23.714156 6108 leveldb.cpp:343] Persisting action (158 bytes) to
leveldb took 15.48841ms
I0611 18:09:23.714187 6108 replica.cpp:676] Persisted action at 1
I0611 18:09:23.714200 6108 replica.cpp:661] Replica learned APPEND action at
position 1
I0611 18:09:23.714975 6100 registrar.cpp:479] Successfully updated 'registry'
I0611 18:09:23.715034 6100 registrar.cpp:372] Successfully recovered registrar
I0611 18:09:23.715267 6105 master.cpp:819] Recovered 0 slaves from the
Registry (99B) ; allowing 10mins for slaves to re-register
I0611 18:09:23.716007 6100 log.cpp:699] Attempting to truncate the log to 1
I0611 18:09:23.716121 6098 coordinator.cpp:340] Coordinator attempting to
write TRUNCATE action at position 2
I0611 18:09:23.717880 6114 replica.cpp:508] Replica received write request for
position 2
I0611 18:09:23.720299 6093 slave.cpp:143] Slave started on
181)@140.211.11.27:56092
I0611 18:09:23.720319 6093 credentials.hpp:35] Loading credentials for
authentication from
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/credential'
I0611 18:09:23.720412 6093 slave.cpp:243] Slave using credential for:
test-principal
I0611 18:09:23.720525 6093 slave.cpp:256] Slave resources: cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0611 18:09:23.720690 6093 slave.cpp:284] Slave hostname: hemera.apache.org
I0611 18:09:23.720702 6093 slave.cpp:285] Slave checkpoint: true
I0611 18:09:23.721190 6093 state.cpp:33] Recovering state from
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/meta'
I0611 18:09:23.721467 6107 status_update_manager.cpp:193] Recovering status
update manager
I0611 18:09:23.721760 6097 slave.cpp:3024] Finished recovery
I0611 18:09:23.722074 6097 slave.cpp:537] New master detected at
master@140.211.11.27:56092
I0611 18:09:23.722177 6097 slave.cpp:613] Authenticating with master
master@140.211.11.27:56092
I0611 18:09:23.722209 6107 status_update_manager.cpp:167] New master detected
at master@140.211.11.27:56092
I0611 18:09:23.722340 6102 authenticatee.hpp:128] Creating new client SASL
connection
I0611 18:09:23.722221 6097 slave.cpp:586] Detecting new master
I0611 18:09:23.723168 6096 master.cpp:3341] Authenticating
slave(181)@140.211.11.27:56092
I0611 18:09:23.723897 6099 authenticator.hpp:156] Creating new server SASL
connection
I0611 18:09:23.724089 6116 authenticatee.hpp:219] Received SASL authentication
mechanisms: CRAM-MD5
I0611 18:09:23.724120 6116 authenticatee.hpp:245] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0611 18:09:23.724171 6116 authenticator.hpp:262] Received SASL authentication
start
I0611 18:09:23.724330 6116 authenticator.hpp:384] Authentication requires more
steps
I0611 18:09:23.724392 6116 authenticatee.hpp:265] Received SASL authentication
step
I0611 18:09:23.724661 6094 authenticator.hpp:290] Received SASL authentication
step
I0611 18:09:23.724689 6094 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'hemera.apache.org' server FQDN:
'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0611 18:09:23.724697 6094 auxprop.cpp:153] Looking up auxiliary property
'*userPassword'
I0611 18:09:23.724709 6094 auxprop.cpp:153] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0611 18:09:23.724719 6094 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'hemera.apache.org' server FQDN:
'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0611 18:09:23.724725 6094 auxprop.cpp:103] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0611 18:09:23.724731 6094 auxprop.cpp:103] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0611 18:09:23.724745 6094 authenticator.hpp:376] Authentication success
I0611 18:09:23.724916 6101 authenticatee.hpp:305] Authentication success
I0611 18:09:23.724992 6101 slave.cpp:670] Successfully authenticated with
master master@140.211.11.27:56092
I0611 18:09:23.725143 6115 master.cpp:3381] Successfully authenticated
principal 'test-principal' at slave(181)@140.211.11.27:56092
I0611 18:09:23.725163 6101 slave.cpp:908] Will retry registration in
8.424447ms if necessary
I0611 18:09:23.725260 6115 master.cpp:2620] Registering slave at
slave(181)@140.211.11.27:56092 (hemera.apache.org) with id
20140611-180923-453759884-56092-6066-0
I0611 18:09:23.725795 6115 registrar.cpp:422] Attempting to update the
'registry'
I0611 18:09:23.725899 6066 sched.cpp:128] Version: 0.20.0
I0611 18:09:23.726253 6100 sched.cpp:224] New master detected at
master@140.211.11.27:56092
I0611 18:09:23.726275 6100 sched.cpp:274] Authenticating with master
master@140.211.11.27:56092
I0611 18:09:23.726466 6105 authenticatee.hpp:128] Creating new client SASL
connection
I0611 18:09:23.726690 6105 master.cpp:3341] Authenticating
scheduler(172)@140.211.11.27:56092
I0611 18:09:23.726848 6107 authenticator.hpp:156] Creating new server SASL
connection
I0611 18:09:23.727210 6107 authenticatee.hpp:219] Received SASL authentication
mechanisms: CRAM-MD5
I0611 18:09:23.727231 6107 authenticatee.hpp:245] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0611 18:09:23.727402 6110 authenticator.hpp:262] Received SASL authentication
start
I0611 18:09:23.727541 6110 authenticator.hpp:384] Authentication requires more
steps
I0611 18:09:23.727581 6110 authenticatee.hpp:265] Received SASL authentication
step
I0611 18:09:23.727764 6110 authenticator.hpp:290] Received SASL authentication
step
I0611 18:09:23.727787 6110 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'hemera.apache.org' server FQDN:
'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0611 18:09:23.727797 6110 auxprop.cpp:153] Looking up auxiliary property
'*userPassword'
I0611 18:09:23.727809 6110 auxprop.cpp:153] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0611 18:09:23.727823 6110 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'hemera.apache.org' server FQDN:
'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0611 18:09:23.727831 6110 auxprop.cpp:103] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0611 18:09:23.727839 6110 auxprop.cpp:103] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0611 18:09:23.727855 6110 authenticator.hpp:376] Authentication success
I0611 18:09:23.728083 6111 authenticatee.hpp:305] Authentication success
I0611 18:09:23.728308 6100 sched.cpp:348] Successfully authenticated with
master master@140.211.11.27:56092
I0611 18:09:23.728400 6100 sched.cpp:467] Sending registration request to
master@140.211.11.27:56092
I0611 18:09:23.728636 6102 master.cpp:3381] Successfully authenticated
principal 'test-principal' at scheduler(172)@140.211.11.27:56092
I0611 18:09:23.728745 6102 master.cpp:1080] Received registration request from
scheduler(172)@140.211.11.27:56092
I0611 18:09:23.728771 6102 master.cpp:1040] Authorizing framework principal
'test-principal' to receive offers for role '*'
I0611 18:09:23.729326 6099 master.cpp:1139] Registering framework
20140611-180923-453759884-56092-6066-0000 at scheduler(172)@140.211.11.27:56092
I0611 18:09:23.729604 6107 hierarchical_allocator_process.hpp:331] Added
framework 20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.729621 6107 hierarchical_allocator_process.hpp:724] No
resources available to allocate!
I0611 18:09:23.729627 6107 hierarchical_allocator_process.hpp:686] Performed
allocation for 0 slaves in 7402ns
I0611 18:09:23.729635 6095 sched.cpp:398] Framework registered with
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.729683 6095 sched.cpp:412] Scheduler::registered took 18275ns
I0611 18:09:23.734451 6114 leveldb.cpp:343] Persisting action (16 bytes) to
leveldb took 16.541316ms
I0611 18:09:23.734483 6114 replica.cpp:676] Persisted action at 2
I0611 18:09:23.734478 6097 slave.cpp:908] Will retry registration in
13.095376ms if necessary
I0611 18:09:23.734562 6108 master.cpp:2608] Ignoring register slave message
from slave(181)@140.211.11.27:56092 (hemera.apache.org) as admission is already
in progress
I0611 18:09:23.735142 6111 replica.cpp:655] Replica received learned notice
for position 2
I0611 18:09:23.747856 6102 slave.cpp:908] Will retry registration in
13.027097ms if necessary
I0611 18:09:23.747894 6098 master.cpp:2608] Ignoring register slave message
from slave(181)@140.211.11.27:56092 (hemera.apache.org) as admission is already
in progress
I0611 18:09:23.750604 6111 leveldb.cpp:343] Persisting action (18 bytes) to
leveldb took 15.439229ms
I0611 18:09:23.750689 6111 leveldb.cpp:401] Deleting ~1 keys from leveldb took
53141ns
I0611 18:09:23.750705 6111 replica.cpp:676] Persisted action at 2
I0611 18:09:23.750713 6111 replica.cpp:661] Replica learned TRUNCATE action at
position 2
I0611 18:09:23.751175 6116 log.cpp:680] Attempting to append 330 bytes to the
log
I0611 18:09:23.751462 6110 coordinator.cpp:340] Coordinator attempting to
write APPEND action at position 3
I0611 18:09:23.753593 6107 replica.cpp:508] Replica received write request for
position 3
I0611 18:09:23.761422 6113 slave.cpp:908] Will retry registration in
94.736596ms if necessary
I0611 18:09:23.761443 6106 master.cpp:2608] Ignoring register slave message
from slave(181)@140.211.11.27:56092 (hemera.apache.org) as admission is already
in progress
I0611 18:09:23.770700 6107 leveldb.cpp:343] Persisting action (349 bytes) to
leveldb took 17.076704ms
I0611 18:09:23.770735 6107 replica.cpp:676] Persisted action at 3
I0611 18:09:23.771275 6107 replica.cpp:655] Replica received learned notice
for position 3
I0611 18:09:23.787154 6107 leveldb.cpp:343] Persisting action (351 bytes) to
leveldb took 15.852605ms
I0611 18:09:23.787188 6107 replica.cpp:676] Persisted action at 3
I0611 18:09:23.787199 6107 replica.cpp:661] Replica learned APPEND action at
position 3
I0611 18:09:23.788058 6116 registrar.cpp:479] Successfully updated 'registry'
I0611 18:09:23.788111 6109 log.cpp:699] Attempting to truncate the log to 3
I0611 18:09:23.788251 6095 coordinator.cpp:340] Coordinator attempting to
write TRUNCATE action at position 4
I0611 18:09:23.788280 6109 master.cpp:2660] Registered slave
20140611-180923-453759884-56092-6066-0 at slave(181)@140.211.11.27:56092
(hemera.apache.org)
I0611 18:09:23.788426 6109 master.cpp:3763] Adding slave
20140611-180923-453759884-56092-6066-0 at slave(181)@140.211.11.27:56092
(hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]
I0611 18:09:23.789437 6097 replica.cpp:508] Replica received write request for
position 4
I0611 18:09:23.789691 6095 slave.cpp:704] Registered with master
master@140.211.11.27:56092; given slave ID
20140611-180923-453759884-56092-6066-0
I0611 18:09:23.789860 6095 slave.cpp:717] Checkpointing SlaveInfo to
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/meta/slaves/20140611-180923-453759884-56092-6066-0/slave.info'
I0611 18:09:23.790736 6110 hierarchical_allocator_process.hpp:444] Added slave
20140611-180923-453759884-56092-6066-0 (hemera.apache.org) with cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] available)
I0611 18:09:23.790808 6110 hierarchical_allocator_process.hpp:750] Offering
cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
20140611-180923-453759884-56092-6066-0 to framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.790935 6110 hierarchical_allocator_process.hpp:706] Performed
allocation for slave 20140611-180923-453759884-56092-6066-0 in 152493ns
I0611 18:09:23.791000 6110 master.hpp:720] Adding offer
20140611-180923-453759884-56092-6066-0 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
20140611-180923-453759884-56092-6066-0 (hemera.apache.org)
I0611 18:09:23.791082 6110 master.cpp:3288] Sending 1 offers to framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.791481 6104 sched.cpp:535] Scheduler::resourceOffers took
26384ns
I0611 18:09:23.794206 6099 master.hpp:730] Removing offer
20140611-180923-453759884-56092-6066-0 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
20140611-180923-453759884-56092-6066-0 (hemera.apache.org)
I0611 18:09:23.794363 6099 master.cpp:1964] Processing reply for offers: [
20140611-180923-453759884-56092-6066-0 ] on slave
20140611-180923-453759884-56092-6066-0 at slave(181)@140.211.11.27:56092
(hemera.apache.org) for framework 20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.794401 6099 master.cpp:2050] Authorizing framework principal
'test-principal' to launch task 41b34ceb-b996-4b1a-a155-28750a85193e as user
'jenkins'
I0611 18:09:23.795259 6105 master.hpp:692] Adding task
41b34ceb-b996-4b1a-a155-28750a85193e with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
20140611-180923-453759884-56092-6066-0 (hemera.apache.org)
I0611 18:09:23.795315 6105 master.cpp:2116] Launching task
41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000 with resources cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
20140611-180923-453759884-56092-6066-0 at slave(181)@140.211.11.27:56092
(hemera.apache.org)
I0611 18:09:23.795420 6116 slave.cpp:939] Got assigned task
41b34ceb-b996-4b1a-a155-28750a85193e for framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.795517 6116 slave.cpp:3296] Checkpointing FrameworkInfo to
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/meta/slaves/20140611-180923-453759884-56092-6066-0/frameworks/20140611-180923-453759884-56092-6066-0000/framework.info'
I0611 18:09:23.795667 6116 slave.cpp:3303] Checkpointing framework pid
'scheduler(172)@140.211.11.27:56092' to
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/meta/slaves/20140611-180923-453759884-56092-6066-0/frameworks/20140611-180923-453759884-56092-6066-0000/framework.pid'
I0611 18:09:23.795917 6116 slave.cpp:1049] Launching task
41b34ceb-b996-4b1a-a155-28750a85193e for framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.799888 6116 slave.cpp:3618] Checkpointing ExecutorInfo to
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/meta/slaves/20140611-180923-453759884-56092-6066-0/frameworks/20140611-180923-453759884-56092-6066-0000/executors/41b34ceb-b996-4b1a-a155-28750a85193e/executor.info'
I0611 18:09:23.800346 6116 slave.cpp:3733] Checkpointing TaskInfo to
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/meta/slaves/20140611-180923-453759884-56092-6066-0/frameworks/20140611-180923-453759884-56092-6066-0000/executors/41b34ceb-b996-4b1a-a155-28750a85193e/runs/f30bc322-fadc-4962-9026-ea54af5245bc/tasks/41b34ceb-b996-4b1a-a155-28750a85193e/task.info'
I0611 18:09:23.800547 6116 slave.cpp:1159] Queuing task
'41b34ceb-b996-4b1a-a155-28750a85193e' for executor
41b34ceb-b996-4b1a-a155-28750a85193e of framework
'20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.800616 6116 slave.cpp:426] Slave terminating
I0611 18:09:23.800807 6112 master.cpp:716] Slave
20140611-180923-453759884-56092-6066-0 at slave(181)@140.211.11.27:56092
(hemera.apache.org) disconnected
I0611 18:09:23.800838 6112 master.cpp:1441] Disconnecting slave
20140611-180923-453759884-56092-6066-0
I0611 18:09:23.801008 6107 hierarchical_allocator_process.hpp:483] Slave
20140611-180923-453759884-56092-6066-0 disconnected
I0611 18:09:23.803526 6097 leveldb.cpp:343] Persisting action (16 bytes) to
leveldb took 14.05907ms
I0611 18:09:23.803557 6097 replica.cpp:676] Persisted action at 4
I0611 18:09:23.803886 6116 replica.cpp:655] Replica received learned notice
for position 4
I0611 18:09:23.806426 6098 slave.cpp:143] Slave started on
182)@140.211.11.27:56092
I0611 18:09:23.806447 6098 credentials.hpp:35] Loading credentials for
authentication from
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/credential'
I0611 18:09:23.806540 6098 slave.cpp:243] Slave using credential for:
test-principal
I0611 18:09:23.806642 6098 slave.cpp:256] Slave resources: cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0611 18:09:23.806745 6098 slave.cpp:284] Slave hostname: hemera.apache.org
I0611 18:09:23.806764 6098 slave.cpp:285] Slave checkpoint: true
I0611 18:09:23.807410 6111 state.cpp:33] Recovering state from
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/meta'
W0611 18:09:23.808126 6111 state.cpp:558] Failed to find status updates file
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/meta/slaves/20140611-180923-453759884-56092-6066-0/frameworks/20140611-180923-453759884-56092-6066-0000/executors/41b34ceb-b996-4b1a-a155-28750a85193e/runs/f30bc322-fadc-4962-9026-ea54af5245bc/tasks/41b34ceb-b996-4b1a-a155-28750a85193e/task.updates'
W0611 18:09:23.808187 6111 state.cpp:426] Failed to find executor forked pid
file
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/meta/slaves/20140611-180923-453759884-56092-6066-0/frameworks/20140611-180923-453759884-56092-6066-0000/executors/41b34ceb-b996-4b1a-a155-28750a85193e/runs/f30bc322-fadc-4962-9026-ea54af5245bc/pids/forked.pid'
I0611 18:09:23.812697 6111 slave.cpp:3092] Recovering framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.812737 6111 slave.cpp:3468] Recovering executor
'41b34ceb-b996-4b1a-a155-28750a85193e' of framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.813668 6105 status_update_manager.cpp:193] Recovering status
update manager
I0611 18:09:23.813688 6105 status_update_manager.cpp:201] Recovering executor
'41b34ceb-b996-4b1a-a155-28750a85193e' of framework
20140611-180923-453759884-56092-6066-0000
W0611 18:09:23.813712 6105 status_update_manager.cpp:240] No updates found for
task 41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.813824 6111 slave.cpp:498] Successfully attached file
'/tmp/SlaveRecoveryTest_0_RestartBeforeContainerizerLaunch_jAqZtl/slaves/20140611-180923-453759884-56092-6066-0/frameworks/20140611-180923-453759884-56092-6066-0000/executors/41b34ceb-b996-4b1a-a155-28750a85193e/runs/f30bc322-fadc-4962-9026-ea54af5245bc'
I0611 18:09:23.814054 6111 slave.cpp:2973] Unable to reconnect to executor
'41b34ceb-b996-4b1a-a155-28750a85193e' of framework
20140611-180923-453759884-56092-6066-0000 because no libprocess PID was found
E0611 18:09:23.814156 6111 slave.cpp:2403] Termination of executor
'41b34ceb-b996-4b1a-a155-28750a85193e' of framework
'20140611-180923-453759884-56092-6066-0000' failed: Unknown container:
f30bc322-fadc-4962-9026-ea54af5245bc
E0611 18:09:23.814270 6099 slave.cpp:2692] Failed to unmonitor container for
executor 41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000: Not monitored
I0611 18:09:23.816198 6111 slave.cpp:2024] Handling status update TASK_FAILED
(UUID: 6412305a-53f4-4a61-b694-9d866bd24b88) for task
41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000 from @0.0.0.0:0
I0611 18:09:23.816228 6111 slave.cpp:3666] Terminating task
41b34ceb-b996-4b1a-a155-28750a85193e
I0611 18:09:23.816354 6116 leveldb.cpp:343] Persisting action (18 bytes) to
leveldb took 12.350597ms
I0611 18:09:23.816400 6094 status_update_manager.cpp:320] Received status
update TASK_FAILED (UUID: 6412305a-53f4-4a61-b694-9d866bd24b88) for task
41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.816413 6116 leveldb.cpp:401] Deleting ~2 keys from leveldb took
29297ns
I0611 18:09:23.816429 6116 replica.cpp:676] Persisted action at 4
I0611 18:09:23.816452 6116 replica.cpp:661] Replica learned TRUNCATE action at
position 4
I0611 18:09:23.816426 6094 status_update_manager.cpp:499] Creating
StatusUpdate stream for task 41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.816648 6094 status_update_manager.hpp:342] Checkpointing UPDATE
for status update TASK_FAILED (UUID: 6412305a-53f4-4a61-b694-9d866bd24b88) for
task 41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000
W0611 18:09:23.840720 6094 status_update_manager.cpp:381] Not forwarding
status update TASK_FAILED (UUID: 6412305a-53f4-4a61-b694-9d866bd24b88) for task
41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000 because no master is elected yet
I0611 18:09:23.840807 6094 slave.cpp:2145] Status update manager successfully
handled status update TASK_FAILED (UUID: 6412305a-53f4-4a61-b694-9d866bd24b88)
for task 41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.857518 6107 slave.cpp:1973] Cleaning up un-reregistered
executors
I0611 18:09:23.857558 6107 slave.cpp:3024] Finished recovery
I0611 18:09:23.857722 6103 hierarchical_allocator_process.hpp:686] Performed
allocation for 1 slaves in 22813ns
I0611 18:09:23.858541 6102 slave.cpp:537] New master detected at
master@140.211.11.27:56092
I0611 18:09:23.858705 6102 slave.cpp:613] Authenticating with master
master@140.211.11.27:56092
I0611 18:09:23.858736 6109 status_update_manager.cpp:167] New master detected
at master@140.211.11.27:56092
W0611 18:09:23.858820 6109 status_update_manager.cpp:181] Resending status
update TASK_FAILED (UUID: 6412305a-53f4-4a61-b694-9d866bd24b88) for task
41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.858839 6109 status_update_manager.cpp:373] Forwarding status
update TASK_FAILED (UUID: 6412305a-53f4-4a61-b694-9d866bd24b88) for task
41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000 to master@140.211.11.27:56092
I0611 18:09:23.858901 6102 slave.cpp:586] Detecting new master
I0611 18:09:23.859163 6112 authenticatee.hpp:128] Creating new client SASL
connection
I0611 18:09:23.860007 6107 sched.cpp:626] Scheduler::statusUpdate took 25331ns
I0611 18:09:23.860195 6115 master.cpp:2946] Status update TASK_FAILED (UUID:
6412305a-53f4-4a61-b694-9d866bd24b88) for task
41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000 from slave
20140611-180923-453759884-56092-6066-0 at slave(181)@140.211.11.27:56092
(hemera.apache.org)
I0611 18:09:23.860414 6115 master.hpp:710] Removing task
41b34ceb-b996-4b1a-a155-28750a85193e with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
20140611-180923-453759884-56092-6066-0 (hemera.apache.org)
I0611 18:09:23.860489 6094 sched.cpp:731] Stopping framework
'20140611-180923-453759884-56092-6066-0000'
I0611 18:09:23.860823 6099 status_update_manager.cpp:398] Received status
update acknowledgement (UUID: 6412305a-53f4-4a61-b694-9d866bd24b88) for task
41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.860841 6115 master.cpp:575] Master terminating
I0611 18:09:23.860852 6099 status_update_manager.hpp:342] Checkpointing ACK
for status update TASK_FAILED (UUID: 6412305a-53f4-4a61-b694-9d866bd24b88) for
task 41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.860890 6100 hierarchical_allocator_process.hpp:635] Recovered
cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total
allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on
slave 20140611-180923-453759884-56092-6066-0 from framework
20140611-180923-453759884-56092-6066-0000
I0611 18:09:23.861192 6115 slave.cpp:2230] master@140.211.11.27:56092 exited
W0611 18:09:23.861218 6115 slave.cpp:2233] Master disconnected! Waiting for a
new master to be elected
I0611 18:09:23.865144 6066 slave.cpp:426] Slave terminating
I0611 18:09:23.889039 6099 status_update_manager.cpp:530] Cleaning up status
update stream for task 41b34ceb-b996-4b1a-a155-28750a85193e of framework
20140611-180923-453759884-56092-6066-0000
[ OK ] SlaveRecoveryTest/0.RestartBeforeContainerizerLaunch (372 ms)
[----------] 24 tests from SlaveRecoveryTest/0 (63646 ms total)
[----------] Global test environment tear-down
../../src/tests/environment.cpp:270: Failure
Failed
Tests completed with child processes remaining:
-+- 6066
/x1/jenkins/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src/.libs/lt-mesos-tests
\-+- 9665 sh -c
/x1/jenkins/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src/mesos-executor
\-+- 9687
/x1/jenkins/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src/.libs/lt-mesos-executor
\--- 9726 ()
[==========] 367 tests from 59 test cases ran. (354262 ms total)
[ PASSED ] 367 tests.
[ FAILED ] 0 tests, listed below:
0 FAILED TESTS
YOU HAVE 5 DISABLED TESTS
I0611 18:09:23.985384 9725 process.cpp:1098] Socket closed while receiving
make[4]: *** [check-local] Error 1
I0611 18:09:23.985481 9714 exec.cpp:439] Ignoring exited event because the
driver is aborted!
make[4]: Leaving directory
`/x1/jenkins/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory
`/x1/jenkins/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory
`/x1/jenkins/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory
`/x1/jenkins/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build'
make: *** [distcheck] Error 1
Command terminated with signal Terminated (pid: 9726)
Build step 'Execute shell' marked build as failure
