Benjamin Mahler created MESOS-1348:
--------------------------------------
Summary: The SlaveRecoveryTest.GCExecutor test leaks child
processes.
Key: MESOS-1348
URL: https://issues.apache.org/jira/browse/MESOS-1348
Project: Mesos
Issue Type: Bug
Components: test
Affects Versions: 0.19.0
Reporter: Benjamin Mahler
Fix For: 0.19.0
{noformat}
[ RUN ] SlaveRecoveryTest/0.GCExecutor
Using temporary directory '/tmp/SlaveRecoveryTest_0_GCExecutor_LQg5dN'
I0509 21:21:11.538439 11408 leveldb.cpp:174] Opened db in 105.331039ms
I0509 21:21:11.549141 11408 leveldb.cpp:181] Compacted db in 10.684677ms
I0509 21:21:11.549161 11408 leveldb.cpp:196] Created db iterator in 3548ns
I0509 21:21:11.549170 11408 leveldb.cpp:202] Seeked to beginning of db in 692ns
I0509 21:21:11.549175 11408 leveldb.cpp:271] Iterated through 0 keys in the db
in 376ns
I0509 21:21:11.549192 11408 replica.cpp:741] Replica recovered with log
positions 0 -> 0 with 1 holes and 0 unlearned
I0509 21:21:11.549522 11453 recover.cpp:425] Starting replica recovery
I0509 21:21:11.549705 11453 recover.cpp:451] Replica is in EMPTY status
I0509 21:21:11.550089 11456 master.cpp:267] Master
20140509-212111-160088899-33285-11408 (vesta.apache.org) started on
67.195.138.9:33285
I0509 21:21:11.550112 11456 master.cpp:304] Master only allowing authenticated
frameworks to register
I0509 21:21:11.550117 11456 master.cpp:309] Master only allowing authenticated
slaves to register
I0509 21:21:11.550122 11456 credentials.hpp:35] Loading credentials for
authentication
W0509 21:21:11.550164 11456 credentials.hpp:48] Failed to stat credentials file
'file:///tmp/SlaveRecoveryTest_0_GCExecutor_LQg5dN/credentials': No such file
or directory
I0509 21:21:11.550330 11454 replica.cpp:638] Replica in EMPTY status received a
broadcasted recover request
I0509 21:21:11.550456 11458 master.cpp:104] No whitelist given. Advertising
offers for all slaves
I0509 21:21:11.550462 11455 hierarchical_allocator_process.hpp:301]
Initializing hierarchical allocator process with master :
[email protected]:33285
I0509 21:21:11.550505 11458 recover.cpp:188] Received a recover response from a
replica in EMPTY status
I0509 21:21:11.554205 11457 recover.cpp:542] Updating replica status to STARTING
I0509 21:21:11.554463 11458 master.cpp:919] The newly elected leader is
[email protected]:33285 with id 20140509-212111-160088899-33285-11408
I0509 21:21:11.554478 11458 master.cpp:929] Elected as the leading master!
I0509 21:21:11.554492 11458 master.cpp:750] Recovering from registrar
I0509 21:21:11.554553 11457 registrar.cpp:313] Recovering registrar
I0509 21:21:11.575019 11459 leveldb.cpp:304] Persisting metadata (8 bytes) to
leveldb took 20.458205ms
I0509 21:21:11.575052 11459 replica.cpp:320] Persisted replica status to
STARTING
I0509 21:21:11.575181 11458 recover.cpp:451] Replica is in STARTING status
I0509 21:21:11.575682 11455 replica.cpp:638] Replica in STARTING status
received a broadcasted recover request
I0509 21:21:11.575809 11458 recover.cpp:188] Received a recover response from a
replica in STARTING status
I0509 21:21:11.576114 11454 recover.cpp:542] Updating replica status to VOTING
I0509 21:21:11.582481 11460 leveldb.cpp:304] Persisting metadata (8 bytes) to
leveldb took 6.22694ms
I0509 21:21:11.582502 11460 replica.cpp:320] Persisted replica status to VOTING
I0509 21:21:11.582552 11460 recover.cpp:556] Successfully joined the Paxos group
I0509 21:21:11.582653 11460 recover.cpp:440] Recover process terminated
I0509 21:21:11.582799 11460 log.cpp:656] Attempting to start the writer
I0509 21:21:11.583464 11459 replica.cpp:474] Replica received implicit promise
request with proposal 1
I0509 21:21:11.591889 11459 leveldb.cpp:304] Persisting metadata (8 bytes) to
leveldb took 8.412506ms
I0509 21:21:11.591905 11459 replica.cpp:342] Persisted promised to 1
I0509 21:21:11.592381 11453 coordinator.cpp:230] Coordinator attemping to fill
missing position
I0509 21:21:11.592998 11457 replica.cpp:375] Replica received explicit promise
request for position 0 with proposal 2
I0509 21:21:11.599869 11457 leveldb.cpp:341] Persisting action (8 bytes) to
leveldb took 6.850362ms
I0509 21:21:11.599889 11457 replica.cpp:676] Persisted action at 0
I0509 21:21:11.600340 11460 replica.cpp:508] Replica received write request for
position 0
I0509 21:21:11.600368 11460 leveldb.cpp:436] Reading position from leveldb took
12586ns
I0509 21:21:11.607838 11460 leveldb.cpp:341] Persisting action (14 bytes) to
leveldb took 7.458006ms
I0509 21:21:11.607853 11460 replica.cpp:676] Persisted action at 0
I0509 21:21:11.608006 11456 replica.cpp:655] Replica received learned notice
for position 0
I0509 21:21:11.618237 11456 leveldb.cpp:341] Persisting action (16 bytes) to
leveldb took 10.214141ms
I0509 21:21:11.618253 11456 replica.cpp:676] Persisted action at 0
I0509 21:21:11.618262 11456 replica.cpp:661] Replica learned NOP action at
position 0
I0509 21:21:11.618461 11454 log.cpp:672] Writer started with ending position 0
I0509 21:21:11.619083 11455 leveldb.cpp:436] Reading position from leveldb took
7410ns
I0509 21:21:11.620265 11458 registrar.cpp:346] Successfully fetched the
registry (0B)
I0509 21:21:11.620301 11458 registrar.cpp:422] Attempting to update the
'registry'
I0509 21:21:11.621338 11457 log.cpp:680] Attempting to append 134 bytes to the
log
I0509 21:21:11.621433 11455 coordinator.cpp:340] Coordinator attempting to
write APPEND action at position 1
I0509 21:21:11.621750 11456 replica.cpp:508] Replica received write request for
position 1
I0509 21:21:11.630163 11456 leveldb.cpp:341] Persisting action (153 bytes) to
leveldb took 8.398411ms
I0509 21:21:11.630178 11456 replica.cpp:676] Persisted action at 1
I0509 21:21:11.630439 11455 replica.cpp:655] Replica received learned notice
for position 1
I0509 21:21:11.638134 11455 leveldb.cpp:341] Persisting action (155 bytes) to
leveldb took 7.668877ms
I0509 21:21:11.638149 11455 replica.cpp:676] Persisted action at 1
I0509 21:21:11.638156 11455 replica.cpp:661] Replica learned APPEND action at
position 1
I0509 21:21:11.638533 11460 registrar.cpp:479] Successfully updated 'registry'
I0509 21:21:11.638597 11460 registrar.cpp:372] Successfully recovered registrar
I0509 21:21:11.638685 11455 log.cpp:699] Attempting to truncate the log to 1
I0509 21:21:11.638741 11456 coordinator.cpp:340] Coordinator attempting to
write TRUNCATE action at position 2
I0509 21:21:11.638808 11460 master.cpp:777] Recovered 0 slaves from the
Registry (97B) ; allowing 10mins for slaves to re-register
I0509 21:21:11.639102 11456 replica.cpp:508] Replica received write request for
position 2
I0509 21:21:11.647333 11408 mesos_containerizer.cpp:122] Using isolation:
posix/cpu,posix/mem
I0509 21:21:11.649085 11455 slave.cpp:143] Slave started on
156)@67.195.138.9:33285
I0509 21:21:11.649109 11455 credentials.hpp:35] Loading credentials for
authentication
W0509 21:21:11.649163 11455 credentials.hpp:48] Failed to stat credentials file
'file:///tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/credential': No such file or
directory
I0509 21:21:11.649184 11455 slave.cpp:233] Slave using credential for:
test-principal
I0509 21:21:11.649303 11455 slave.cpp:246] Slave resources: cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0509 21:21:11.649358 11455 slave.cpp:274] Slave hostname: vesta.apache.org
I0509 21:21:11.649366 11455 slave.cpp:275] Slave checkpoint: true
I0509 21:21:11.649843 11455 state.cpp:33] Recovering state from
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta'
I0509 21:21:11.649984 11458 status_update_manager.cpp:193] Recovering status
update manager
I0509 21:21:11.650068 11457 mesos_containerizer.cpp:279] Recovering
containerizer
I0509 21:21:11.650316 11459 slave.cpp:2962] Finished recovery
I0509 21:21:11.650678 11455 slave.cpp:527] New master detected at
[email protected]:33285
I0509 21:21:11.650710 11455 slave.cpp:587] Authenticating with master
[email protected]:33285
I0509 21:21:11.650732 11457 status_update_manager.cpp:167] New master detected
at [email protected]:33285
I0509 21:21:11.650763 11455 slave.cpp:560] Detecting new master
I0509 21:21:11.650785 11457 authenticatee.hpp:128] Creating new client SASL
connection
I0509 21:21:11.650845 11408 sched.cpp:121] Version: 0.19.0
I0509 21:21:11.650872 11455 master.cpp:2798] Authenticating
slave(156)@67.195.138.9:33285
I0509 21:21:11.650993 11460 authenticator.hpp:148] Creating new server SASL
connection
I0509 21:21:11.651012 11455 sched.cpp:217] New master detected at
[email protected]:33285
I0509 21:21:11.651026 11455 sched.cpp:268] Authenticating with master
[email protected]:33285
I0509 21:21:11.651057 11460 authenticatee.hpp:219] Received SASL authentication
mechanisms: CRAM-MD5
I0509 21:21:11.651075 11460 authenticatee.hpp:245] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0509 21:21:11.651108 11455 authenticatee.hpp:128] Creating new client SASL
connection
I0509 21:21:11.651141 11457 authenticator.hpp:254] Received SASL authentication
start
I0509 21:21:11.651165 11455 master.cpp:2798] Authenticating
scheduler(137)@67.195.138.9:33285
I0509 21:21:11.651180 11457 authenticator.hpp:342] Authentication requires more
steps
I0509 21:21:11.651206 11457 authenticatee.hpp:265] Received SASL authentication
step
I0509 21:21:11.651234 11455 authenticator.hpp:148] Creating new server SASL
connection
I0509 21:21:11.651244 11457 authenticator.hpp:282] Received SASL authentication
step
I0509 21:21:11.651263 11457 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'vesta.apache.org' server FQDN:
'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0509 21:21:11.651274 11457 auxprop.cpp:153] Looking up auxiliary property
'*userPassword'
I0509 21:21:11.651279 11455 authenticatee.hpp:219] Received SASL authentication
mechanisms: CRAM-MD5
I0509 21:21:11.651288 11457 auxprop.cpp:153] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0509 21:21:11.651293 11455 authenticatee.hpp:245] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0509 21:21:11.651298 11457 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'vesta.apache.org' server FQDN:
'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0509 21:21:11.651306 11457 auxprop.cpp:103] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0509 21:21:11.651311 11457 auxprop.cpp:103] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0509 21:21:11.651314 11455 authenticator.hpp:254] Received SASL authentication
start
I0509 21:21:11.651324 11457 authenticator.hpp:334] Authentication success
I0509 21:21:11.651336 11455 authenticator.hpp:342] Authentication requires more
steps
I0509 21:21:11.651347 11457 authenticatee.hpp:305] Authentication success
I0509 21:21:11.651358 11455 master.cpp:2838] Successfully authenticated
slave(156)@67.195.138.9:33285
I0509 21:21:11.651368 11457 authenticatee.hpp:265] Received SASL authentication
step
I0509 21:21:11.651409 11455 authenticator.hpp:282] Received SASL authentication
step
I0509 21:21:11.651433 11455 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'vesta.apache.org' server FQDN:
'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0509 21:21:11.651433 11457 slave.cpp:644] Successfully authenticated with
master [email protected]:33285
I0509 21:21:11.651440 11455 auxprop.cpp:153] Looking up auxiliary property
'*userPassword'
I0509 21:21:11.651449 11455 auxprop.cpp:153] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0509 21:21:11.651458 11455 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'vesta.apache.org' server FQDN:
'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0509 21:21:11.651463 11455 auxprop.cpp:103] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0509 21:21:11.651468 11455 auxprop.cpp:103] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0509 21:21:11.651470 11457 slave.cpp:873] Will retry registration in
9.45033204secs if necessary
I0509 21:21:11.651478 11455 authenticator.hpp:334] Authentication success
I0509 21:21:11.651520 11455 authenticatee.hpp:305] Authentication success
I0509 21:21:11.651533 11457 master.cpp:2134] Registering slave at
slave(156)@67.195.138.9:33285 (vesta.apache.org) with id
20140509-212111-160088899-33285-11408-0
I0509 21:21:11.651569 11455 sched.cpp:342] Successfully authenticated with
master [email protected]:33285
I0509 21:21:11.651579 11455 sched.cpp:461] Sending registration request to
[email protected]:33285
I0509 21:21:11.651603 11457 master.cpp:2838] Successfully authenticated
scheduler(137)@67.195.138.9:33285
I0509 21:21:11.651687 11457 master.cpp:978] Received registration request from
scheduler(137)@67.195.138.9:33285
I0509 21:21:11.651726 11457 master.cpp:996] Registering framework
20140509-212111-160088899-33285-11408-0000 at scheduler(137)@67.195.138.9:33285
I0509 21:21:11.651765 11455 registrar.cpp:422] Attempting to update the
'registry'
I0509 21:21:11.651780 11457 sched.cpp:392] Framework registered with
20140509-212111-160088899-33285-11408-0000
I0509 21:21:11.651798 11457 sched.cpp:406] Scheduler::registered took 9242ns
I0509 21:21:11.651832 11457 hierarchical_allocator_process.hpp:331] Added
framework 20140509-212111-160088899-33285-11408-0000
I0509 21:21:11.651844 11457 hierarchical_allocator_process.hpp:725] No
resources available to allocate!
I0509 21:21:11.651850 11457 hierarchical_allocator_process.hpp:687] Performed
allocation for 0 slaves in 6108ns
I0509 21:21:11.654062 11456 leveldb.cpp:341] Persisting action (16 bytes) to
leveldb took 14.938775ms
I0509 21:21:11.654083 11456 replica.cpp:676] Persisted action at 2
I0509 21:21:11.654297 11456 replica.cpp:655] Replica received learned notice
for position 2
I0509 21:21:11.661996 11456 leveldb.cpp:341] Persisting action (18 bytes) to
leveldb took 7.685873ms
I0509 21:21:11.662040 11456 leveldb.cpp:399] Deleting ~1 keys from leveldb took
20377ns
I0509 21:21:11.662052 11456 replica.cpp:676] Persisted action at 2
I0509 21:21:11.662060 11456 replica.cpp:661] Replica learned TRUNCATE action at
position 2
I0509 21:21:11.662277 11457 log.cpp:680] Attempting to append 327 bytes to the
log
I0509 21:21:11.662328 11456 coordinator.cpp:340] Coordinator attempting to
write APPEND action at position 3
I0509 21:21:11.662644 11458 replica.cpp:508] Replica received write request for
position 3
I0509 21:21:11.669971 11458 leveldb.cpp:341] Persisting action (346 bytes) to
leveldb took 7.314151ms
I0509 21:21:11.669989 11458 replica.cpp:676] Persisted action at 3
I0509 21:21:11.670292 11455 replica.cpp:655] Replica received learned notice
for position 3
I0509 21:21:11.677922 11455 leveldb.cpp:341] Persisting action (348 bytes) to
leveldb took 7.612095ms
I0509 21:21:11.677942 11455 replica.cpp:676] Persisted action at 3
I0509 21:21:11.677983 11455 replica.cpp:661] Replica learned APPEND action at
position 3
I0509 21:21:11.678267 11457 registrar.cpp:479] Successfully updated 'registry'
I0509 21:21:11.678355 11458 log.cpp:699] Attempting to truncate the log to 3
I0509 21:21:11.678407 11460 coordinator.cpp:340] Coordinator attempting to
write TRUNCATE action at position 4
I0509 21:21:11.678601 11454 master.cpp:2174] Registered slave
20140509-212111-160088899-33285-11408-0 at slave(156)@67.195.138.9:33285
(vesta.apache.org)
I0509 21:21:11.678732 11453 replica.cpp:508] Replica received write request for
position 4
I0509 21:21:11.678714 11454 master.cpp:3283] Adding slave
20140509-212111-160088899-33285-11408-0 at slave(156)@67.195.138.9:33285
(vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]
I0509 21:21:11.678834 11457 slave.cpp:677] Registered with master
[email protected]:33285; given slave ID
20140509-212111-160088899-33285-11408-0
I0509 21:21:11.678964 11457 slave.cpp:690] Checkpointing SlaveInfo to
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/slave.info'
I0509 21:21:11.678977 11458 hierarchical_allocator_process.hpp:444] Added slave
20140509-212111-160088899-33285-11408-0 (vesta.apache.org) with cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] available)
I0509 21:21:11.679034 11458 hierarchical_allocator_process.hpp:751] Offering
cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
20140509-212111-160088899-33285-11408-0 to framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:11.679150 11458 hierarchical_allocator_process.hpp:707] Performed
allocation for slave 20140509-212111-160088899-33285-11408-0 in 142987ns
I0509 21:21:11.679208 11455 master.hpp:612] Adding offer
20140509-212111-160088899-33285-11408-0 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
20140509-212111-160088899-33285-11408-0 (vesta.apache.org)
I0509 21:21:11.679254 11455 master.cpp:2747] Sending 1 offers to framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:11.679355 11455 sched.cpp:529] Scheduler::resourceOffers took
19812ns
I0509 21:21:11.680557 11454 master.hpp:622] Removing offer
20140509-212111-160088899-33285-11408-0 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
20140509-212111-160088899-33285-11408-0 (vesta.apache.org)
I0509 21:21:11.680605 11454 master.cpp:1810] Processing reply for offers: [
20140509-212111-160088899-33285-11408-0 ] on slave
20140509-212111-160088899-33285-11408-0 at slave(156)@67.195.138.9:33285
(vesta.apache.org) for framework 20140509-212111-160088899-33285-11408-0000
I0509 21:21:11.680687 11454 master.hpp:584] Adding task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
20140509-212111-160088899-33285-11408-0 (vesta.apache.org)
I0509 21:21:11.680735 11454 master.cpp:2922] Launching task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000 with resources cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
20140509-212111-160088899-33285-11408-0 at slave(156)@67.195.138.9:33285
(vesta.apache.org)
I0509 21:21:11.680836 11460 slave.cpp:907] Got assigned task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 for framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:11.680918 11460 slave.cpp:3156] Checkpointing FrameworkInfo to
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/framework.info'
I0509 21:21:11.681078 11460 slave.cpp:3163] Checkpointing framework pid
'scheduler(137)@67.195.138.9:33285' to
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/framework.pid'
I0509 21:21:11.681282 11460 slave.cpp:1017] Launching task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 for framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:11.683256 11460 slave.cpp:3478] Checkpointing ExecutorInfo to
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/executors/b1cfcb14-dbd1-417a-b991-5fa6feeecb52/executor.info'
I0509 21:21:11.687294 11455 mesos_containerizer.cpp:523] Starting container
'a0c0c8bb-a49b-41ba-8820-303f8575dced' for executor
'b1cfcb14-dbd1-417a-b991-5fa6feeecb52' of framework
'20140509-212111-160088899-33285-11408-0000'
I0509 21:21:11.687309 11460 slave.cpp:3575] Checkpointing TaskInfo to
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/executors/b1cfcb14-dbd1-417a-b991-5fa6feeecb52/runs/a0c0c8bb-a49b-41ba-8820-303f8575dced/tasks/b1cfcb14-dbd1-417a-b991-5fa6feeecb52/task.info'
I0509 21:21:11.687446 11460 slave.cpp:1127] Queuing task
'b1cfcb14-dbd1-417a-b991-5fa6feeecb52' for executor
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
'20140509-212111-160088899-33285-11408-0000
I0509 21:21:11.687495 11460 slave.cpp:488] Successfully attached file
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/executors/b1cfcb14-dbd1-417a-b991-5fa6feeecb52/runs/a0c0c8bb-a49b-41ba-8820-303f8575dced'
I0509 21:21:11.688833 11456 launcher.cpp:117] Forked child with pid '13390' for
container 'a0c0c8bb-a49b-41ba-8820-303f8575dced'
I0509 21:21:11.688928 11456 mesos_containerizer.cpp:746] Checkpointing
executor's forked pid 13390 to
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/executors/b1cfcb14-dbd1-417a-b991-5fa6feeecb52/runs/a0c0c8bb-a49b-41ba-8820-303f8575dced/pids/forked.pid'
I0509 21:21:11.690093 11459 mesos_containerizer.cpp:623] Fetching URIs for
container 'a0c0c8bb-a49b-41ba-8820-303f8575dced' using command
'/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src/mesos-fetcher'
I0509 21:21:11.693989 11453 leveldb.cpp:341] Persisting action (16 bytes) to
leveldb took 15.15451ms
I0509 21:21:11.694051 11453 replica.cpp:676] Persisted action at 4
I0509 21:21:11.694946 11458 replica.cpp:655] Replica received learned notice
for position 4
I0509 21:21:11.709843 11458 leveldb.cpp:341] Persisting action (18 bytes) to
leveldb took 14.857452ms
I0509 21:21:11.710093 11458 leveldb.cpp:399] Deleting ~2 keys from leveldb took
31693ns
I0509 21:21:11.710160 11458 replica.cpp:676] Persisted action at 4
I0509 21:21:11.710249 11458 replica.cpp:661] Replica learned TRUNCATE action at
position 4
I0509 21:21:12.312875 11454 slave.cpp:2299] Monitoring executor
'b1cfcb14-dbd1-417a-b991-5fa6feeecb52' of framework
'20140509-212111-160088899-33285-11408-0000' in container
'a0c0c8bb-a49b-41ba-8820-303f8575dced'
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0509 21:21:12.344542 13412 process.cpp:1671] libprocess is initialized on
67.195.138.9:43624 for 8 cpus
I0509 21:21:12.345546 13412 exec.cpp:131] Version: 0.19.0
I0509 21:21:12.346982 13433 exec.cpp:181] Executor started at:
executor(1)@67.195.138.9:43624 with pid 13412
I0509 21:21:12.347771 11455 slave.cpp:1607] Got registration for executor
'b1cfcb14-dbd1-417a-b991-5fa6feeecb52' of framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.347853 11455 slave.cpp:1692] Checkpointing executor pid
'executor(1)@67.195.138.9:43624' to
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/executors/b1cfcb14-dbd1-417a-b991-5fa6feeecb52/runs/a0c0c8bb-a49b-41ba-8820-303f8575dced/pids/libprocess.pid'
I0509 21:21:12.348752 11455 slave.cpp:1726] Flushing queued task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 for executor
'b1cfcb14-dbd1-417a-b991-5fa6feeecb52' of framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.348840 11461 process.cpp:1098] Socket closed while receiving
I0509 21:21:12.349097 11461 process.cpp:1098] Socket closed while receiving
I0509 21:21:12.349094 13434 process.cpp:1037] Socket closed while receiving
I0509 21:21:12.349144 13428 exec.cpp:205] Executor registered on slave
20140509-212111-160088899-33285-11408-0
I0509 21:21:12.349303 13434 process.cpp:1037] Socket closed while receiving
I0509 21:21:12.350088 13428 exec.cpp:217] Executor::registered took 126658ns
Registered executor on vesta.apache.org
I0509 21:21:12.350244 13428 exec.cpp:292] Executor asked to run task
'b1cfcb14-dbd1-417a-b991-5fa6feeecb52'
I0509 21:21:12.350296 13428 exec.cpp:301] Executor::launchTask took 38562ns
Starting task b1cfcb14-dbd1-417a-b991-5fa6feeecb52
Forked command at 13435
sh -c 'sleep 1000'
I0509 21:21:12.351841 13426 exec.cpp:524] Executor sending status update
TASK_RUNNING (UUID: f750bad1-a42a-4d35-bb9d-386636cc76a3) for task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.352150 11458 slave.cpp:1962] Handling status update TASK_RUNNING
(UUID: f750bad1-a42a-4d35-bb9d-386636cc76a3) for task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000 from executor(1)@67.195.138.9:43624
I0509 21:21:12.352262 11458 status_update_manager.cpp:320] Received status
update TASK_RUNNING (UUID: f750bad1-a42a-4d35-bb9d-386636cc76a3) for task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.352335 11458 status_update_manager.cpp:499] Creating
StatusUpdate stream for task b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.352601 11458 status_update_manager.hpp:342] Checkpointing UPDATE
for status update TASK_RUNNING (UUID: f750bad1-a42a-4d35-bb9d-386636cc76a3) for
task b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.442677 11458 status_update_manager.cpp:373] Forwarding status
update TASK_RUNNING (UUID: f750bad1-a42a-4d35-bb9d-386636cc76a3) for task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000 to [email protected]:33285
I0509 21:21:12.442862 11456 master.cpp:2450] Status update TASK_RUNNING (UUID:
f750bad1-a42a-4d35-bb9d-386636cc76a3) for task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000 from slave
20140509-212111-160088899-33285-11408-0 at slave(156)@67.195.138.9:33285
(vesta.apache.org)
I0509 21:21:12.442915 11458 slave.cpp:2083] Status update manager successfully
handled status update TASK_RUNNING (UUID: f750bad1-a42a-4d35-bb9d-386636cc76a3)
for task b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.442924 11458 slave.cpp:2089] Sending acknowledgement for status
update TASK_RUNNING (UUID: f750bad1-a42a-4d35-bb9d-386636cc76a3) for task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000 to executor(1)@67.195.138.9:43624
I0509 21:21:12.443009 11460 sched.cpp:620] Scheduler::statusUpdate took 38809ns
I0509 21:21:12.443135 11461 process.cpp:1098] Socket closed while receiving
I0509 21:21:12.443212 13434 process.cpp:1037] Socket closed while receiving
I0509 21:21:12.443253 11458 status_update_manager.cpp:398] Received status
update acknowledgement (UUID: f750bad1-a42a-4d35-bb9d-386636cc76a3) for task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.443274 11458 status_update_manager.hpp:342] Checkpointing ACK
for status update TASK_RUNNING (UUID: f750bad1-a42a-4d35-bb9d-386636cc76a3) for
task b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.443305 13429 exec.cpp:338] Executor received status update
acknowledgement f750bad1-a42a-4d35-bb9d-386636cc76a3 for task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.443379 11460 slave.cpp:416] Slave terminating
I0509 21:21:12.443456 11460 master.cpp:688] Slave
20140509-212111-160088899-33285-11408-0 at slave(156)@67.195.138.9:33285
(vesta.apache.org) disconnected
I0509 21:21:12.443475 11460 master.cpp:1260] Disconnecting slave
20140509-212111-160088899-33285-11408-0
I0509 21:21:12.443608 11455 hierarchical_allocator_process.hpp:483] Slave
20140509-212111-160088899-33285-11408-0 disconnected
I0509 21:21:12.475613 11461 process.cpp:1098] Socket closed while receiving
I0509 21:21:12.475674 13429 exec.cpp:378] Executor asked to shutdown
IShutting down
0509 21:21:12.475738 13429 exec.cpp:393] Executor::shutdown took 6056ns
Sending SIGTERM to process tree at pid 13435
I0509 21:21:12.475675 13434 process.cpp:1037] Socket closed while receiving
I0509 21:21:12.475750 13430 exec.cpp:77] Scheduling shutdown of the executor
I0509 21:21:12.475955 11408 mesos_containerizer.cpp:122] Using isolation:
posix/cpu,posix/mem
I0509 21:21:12.477824 11459 slave.cpp:143] Slave started on
157)@67.195.138.9:33285
I0509 21:21:12.477840 11459 credentials.hpp:35] Loading credentials for
authentication
W0509 21:21:12.477920 11459 credentials.hpp:48] Failed to stat credentials file
'file:///tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/credential': No such file or
directory
I0509 21:21:12.477987 11459 slave.cpp:233] Slave using credential for:
test-principal
I0509 21:21:12.478101 11459 slave.cpp:246] Slave resources: cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0509 21:21:12.478158 11459 slave.cpp:274] Slave hostname: vesta.apache.org
I0509 21:21:12.478166 11459 slave.cpp:275] Slave checkpoint: true
I0509 21:21:12.478714 11455 state.cpp:33] Recovering state from
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta'
W0509 21:21:12.479399 11455 state.cpp:331] Failed to find the latest run of
executor 'b1cfcb14-dbd1-417a-b991-5fa6feeecb52' of framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.479683 11459 slave.cpp:3030] Recovering framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.479702 11459 slave.cpp:3328] Recovering executor
'b1cfcb14-dbd1-417a-b991-5fa6feeecb52' of framework
20140509-212111-160088899-33285-11408-0000
W0509 21:21:12.479709 11459 slave.cpp:3334] Skipping recovery of executor
'b1cfcb14-dbd1-417a-b991-5fa6feeecb52' of framework
20140509-212111-160088899-33285-11408-0000 because its latest run or executor
info cannot be recovered
I0509 21:21:12.479763 11459 slave.cpp:2571] Cleaning up framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.479765 11455 gc.cpp:56] Scheduling
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/executors/b1cfcb14-dbd1-417a-b991-5fa6feeecb52'
for gc 6.99998287350815days in the future
I0509 21:21:12.479816 11455 gc.cpp:56] Scheduling
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/executors/b1cfcb14-dbd1-417a-b991-5fa6feeecb52'
for gc 6.99998287321778days in the future
I0509 21:21:12.479846 11455 gc.cpp:56] Scheduling
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000'
for gc 6.99999444686518days in the future
I0509 21:21:12.479874 11455 gc.cpp:56] Scheduling
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000'
for gc 6.99999444659556days in the future
I0509 21:21:12.479904 11455 status_update_manager.cpp:282] Closing status
update streams for framework 20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.480051 11456 status_update_manager.cpp:193] Recovering status
update manager
I0509 21:21:12.480062 11456 status_update_manager.cpp:201] Recovering executor
'b1cfcb14-dbd1-417a-b991-5fa6feeecb52' of framework
20140509-212111-160088899-33285-11408-0000
W0509 21:21:12.480068 11456 status_update_manager.cpp:205] Skipping recovering
updates of executor 'b1cfcb14-dbd1-417a-b991-5fa6feeecb52' of framework
20140509-212111-160088899-33285-11408-0000 because its info cannot be recovered
I0509 21:21:12.480387 11453 mesos_containerizer.cpp:279] Recovering
containerizer
W0509 21:21:12.480403 11453 mesos_containerizer.cpp:287] Skipping recovery of
executor 'b1cfcb14-dbd1-417a-b991-5fa6feeecb52' of framework
20140509-212111-160088899-33285-11408-0000 because its info could not be
recovered
I0509 21:21:12.480837 11458 slave.cpp:2962] Finished recovery
I0509 21:21:12.481205 11460 slave.cpp:527] New master detected at
[email protected]:33285
I0509 21:21:12.481232 11460 slave.cpp:587] Authenticating with master
[email protected]:33285
I0509 21:21:12.481286 11453 status_update_manager.cpp:167] New master detected
at [email protected]:33285
I0509 21:21:12.481298 11460 slave.cpp:560] Detecting new master
I0509 21:21:12.481358 11453 authenticatee.hpp:128] Creating new client SASL
connection
I0509 21:21:12.481498 11456 master.cpp:2798] Authenticating
slave(157)@67.195.138.9:33285
I0509 21:21:12.481632 11453 authenticator.hpp:148] Creating new server SASL
connection
I0509 21:21:12.481729 11455 authenticatee.hpp:219] Received SASL authentication
mechanisms: CRAM-MD5
I0509 21:21:12.481752 11455 authenticatee.hpp:245] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0509 21:21:12.481806 11455 authenticator.hpp:254] Received SASL authentication
start
I0509 21:21:12.481853 11455 authenticator.hpp:342] Authentication requires more
steps
I0509 21:21:12.481880 11455 authenticatee.hpp:265] Received SASL authentication
step
I0509 21:21:12.481935 11455 authenticator.hpp:282] Received SASL authentication
step
I0509 21:21:12.481966 11455 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'vesta.apache.org' server FQDN:
'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0509 21:21:12.481973 11455 auxprop.cpp:153] Looking up auxiliary property
'*userPassword'
I0509 21:21:12.481984 11455 auxprop.cpp:153] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0509 21:21:12.481994 11455 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'vesta.apache.org' server FQDN:
'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0509 21:21:12.482002 11455 auxprop.cpp:103] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0509 21:21:12.482007 11455 auxprop.cpp:103] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0509 21:21:12.482017 11455 authenticator.hpp:334] Authentication success
I0509 21:21:12.482056 11453 authenticatee.hpp:305] Authentication success
I0509 21:21:12.482066 11455 master.cpp:2838] Successfully authenticated
slave(157)@67.195.138.9:33285
I0509 21:21:12.482174 11453 slave.cpp:644] Successfully authenticated with
master [email protected]:33285
I0509 21:21:12.482211 11453 slave.cpp:833] Reregistering completed framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.482260 11453 slave.cpp:873] Will retry registration in
6.836005163secs if necessary
W0509 21:21:12.482391 11457 master.cpp:2248] Slave at
slave(157)@67.195.138.9:33285 (vesta.apache.org) is being allowed to
re-register with an already in use id (20140509-212111-160088899-33285-11408-0)
W0509 21:21:12.482426 11457 master.cpp:2966] Sending TASK_LOST for task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000 unknown to the slave
20140509-212111-160088899-33285-11408-0 at slave(157)@67.195.138.9:33285
(vesta.apache.org)
I0509 21:21:12.482434 11453 slave.cpp:727] Re-registered with master
[email protected]:33285
I0509 21:21:12.483248 11457 master.cpp:2450] Status update TASK_LOST (UUID:
e2dc8b90-824a-4bb7-8caa-16345becb95b) for task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 of framework
20140509-212111-160088899-33285-11408-0000 from slave
20140509-212111-160088899-33285-11408-0 at slave(157)@67.195.138.9:33285
(vesta.apache.org)
I0509 21:21:12.483307 11456 sched.cpp:620] Scheduler::statusUpdate took 7885ns
I0509 21:21:12.483317 11457 master.hpp:602] Removing task
b1cfcb14-dbd1-417a-b991-5fa6feeecb52 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
20140509-212111-160088899-33285-11408-0 (vesta.apache.org)
I0509 21:21:12.483492 11456 hierarchical_allocator_process.hpp:636] Recovered
cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total
allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on
slave 20140509-212111-160088899-33285-11408-0 from framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.483525 11456 hierarchical_allocator_process.hpp:497] Slave
20140509-212111-160088899-33285-11408-0 reconnected
I0509 21:21:12.491060 11457 hierarchical_allocator_process.hpp:751] Offering
cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
20140509-212111-160088899-33285-11408-0 to framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.491248 11457 hierarchical_allocator_process.hpp:687] Performed
allocation for 1 slaves in 242634ns
I0509 21:21:12.491304 11456 master.hpp:612] Adding offer
20140509-212111-160088899-33285-11408-1 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
20140509-212111-160088899-33285-11408-0 (vesta.apache.org)
I0509 21:21:12.491369 11456 master.cpp:2747] Sending 1 offers to framework
20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.491544 11453 sched.cpp:529] Scheduler::resourceOffers took
18763ns
Killing the following process trees:
[
-+- 13435 sh -c sleep 1000
\--- 13436 sleep 1000
]
I0509 21:21:12.511373 11460 hierarchical_allocator_process.hpp:687] Performed
allocation for 1 slaves in 21442ns
I0509 21:21:12.511620 11459 master.cpp:104] No whitelist given. Advertising
offers for all slaves
I0509 21:21:12.511742 11457 gc.cpp:134] Deleting
/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/executors/b1cfcb14-dbd1-417a-b991-5fa6feeecb52
I0509 21:21:12.511713 11455 slave.cpp:2817] Current usage 40.87%. Max allowed
age: 3.438910272322743days
I0509 21:21:12.511934 11457 gc.cpp:143] Deleted
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/executors/b1cfcb14-dbd1-417a-b991-5fa6feeecb52'
I0509 21:21:12.511989 11457 gc.cpp:167] Pruning directories with remaining
removal time 0ns
I0509 21:21:12.512001 11457 gc.cpp:167] Pruning directories with remaining
removal time 0ns
I0509 21:21:12.512008 11457 gc.cpp:167] Pruning directories with remaining
removal time 0ns
I0509 21:21:12.512025 11457 gc.cpp:134] Deleting
/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/executors/b1cfcb14-dbd1-417a-b991-5fa6feeecb52
I0509 21:21:12.512311 11457 gc.cpp:143] Deleted
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000/executors/b1cfcb14-dbd1-417a-b991-5fa6feeecb52'
I0509 21:21:12.512347 11457 gc.cpp:155] Ignoring gc event at 0ns as the paths
were already removed, or were unscheduled
I0509 21:21:12.512370 11457 gc.cpp:134] Deleting
/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.512416 11457 gc.cpp:143] Deleted
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000'
I0509 21:21:12.512449 11457 gc.cpp:134] Deleting
/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000
I0509 21:21:12.512547 11457 gc.cpp:143] Deleted
'/tmp/SlaveRecoveryTest_0_GCExecutor_vX3tsQ/meta/slaves/20140509-212111-160088899-33285-11408-0/frameworks/20140509-212111-160088899-33285-11408-0000'
I0509 21:21:12.512574 11457 gc.cpp:155] Ignoring gc event at 0ns as the paths
were already removed, or were unscheduled
I0509 21:21:12.512588 11457 gc.cpp:155] Ignoring gc event at 0ns as the paths
were already removed, or were unscheduled
I0509 21:21:12.512603 11457 gc.cpp:155] Ignoring gc event at 0ns as the paths
were already removed, or were unscheduled
I0509 21:21:12.531309 11458 sched.cpp:731] Stopping framework
'20140509-212111-160088899-33285-11408-0000'
I0509 21:21:12.531358 11408 master.cpp:550] Master terminating
I0509 21:21:12.531482 11408 master.hpp:622] Removing offer
20140509-212111-160088899-33285-11408-1 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
20140509-212111-160088899-33285-11408-0 (vesta.apache.org)
I0509 21:21:12.531733 11460 slave.cpp:2168] [email protected]:33285 exited
W0509 21:21:12.531754 11460 slave.cpp:2171] Master disconnected! Waiting for a
new master to be elected
I0509 21:21:12.533133 11408 slave.cpp:416] Slave terminating
[ OK ] SlaveRecoveryTest/0.GCExecutor (1102 ms)
[----------] 24 tests from SlaveRecoveryTest/0 (63658 ms total)
{noformat}
Test tear down:
{noformat}
[----------] Global test environment tear-down
../../src/tests/environment.cpp:258: Failure
Failed
Tests completed with child processes remaining:
-+- 11408
/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src/.libs/lt-mesos-tests
\-+- 13390 sh -c
/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src/mesos-executor
\--- 13412
/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src/.libs/lt-mesos-executor
[==========] 279 tests from 45 test cases ran. (171208 ms total)
[ PASSED ] 279 tests.
[ FAILED ] 0 tests, listed below:
{noformat}
--
This message was sent by Atlassian JIRA
(v6.2#6252)
