You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by "Chris Lambert (JIRA)" <ji...@apache.org> on 2014/05/15 02:02:27 UTC
[jira] [Updated] (MESOS-1348) The SlaveRecoveryTest.GCExecutor test
leaks child processes.
[ https://issues.apache.org/jira/browse/MESOS-1348?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Chris Lambert updated MESOS-1348:
---------------------------------
Sprint: Q2'14 Sprint 2
> 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 : master@67.195.138.9: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 master@67.195.138.9: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 master@67.195.138.9:33285
> I0509 21:21:11.650710 11455 slave.cpp:587] Authenticating with master master@67.195.138.9:33285
> I0509 21:21:11.650732 11457 status_update_manager.cpp:167] New master detected at master@67.195.138.9: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 master@67.195.138.9:33285
> I0509 21:21:11.651026 11455 sched.cpp:268] Authenticating with master master@67.195.138.9: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 master@67.195.138.9: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 master@67.195.138.9:33285
> I0509 21:21:11.651579 11455 sched.cpp:461] Sending registration request to master@67.195.138.9: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 master@67.195.138.9: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 master@67.195.138.9: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 master@67.195.138.9:33285
> I0509 21:21:12.481232 11460 slave.cpp:587] Authenticating with master master@67.195.138.9:33285
> I0509 21:21:12.481286 11453 status_update_manager.cpp:167] New master detected at master@67.195.138.9: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 master@67.195.138.9: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 master@67.195.138.9: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] master@67.195.138.9: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)