You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/03/14 03:34:18 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME #317
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/317/>
------------------------------------------
[...truncated 6422 lines...]
I0314 02:34:01.379344 6357 sched.cpp:327] Status update: task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000 is now in state TASK_RUNNING
I0314 02:34:01.380209 6907 process.cpp:878] Socket closed while receiving
I0314 02:34:01.380261 6906 exec.cpp:289] Executor received ACK for status update of task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:01.380296 6360 slave.cpp:967] Got acknowledgement of status update for task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:01.380825 6362 status_update_manager.cpp:313] Received status update acknowledgement for task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:01.381153 6362 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_RUNNING from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:01.432437 6362 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:02.205332 6362 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0314 02:34:02.212936 6362 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 7.64ms
I0314 02:34:02.380435 6359 slave.cpp:389] Slave terminating
I0314 02:34:02.381455 6907 process.cpp:878] Socket closed while receiving
I0314 02:34:02.381511 6900 exec.cpp:321] Executor asked to shutdown
I0314 02:34:02.381620 6900 exec.cpp:75] Scheduling shutdown of the executor
Waited on process 6908, returned status 15
I0314 02:34:02.381891 6905 exec.cpp:382] Executor sending status update for task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 in state TASK_FAILED
I0314 02:34:02.382141 6358 slave.cpp:202] Slave started on 20)@67.195.138.60:37302
I0314 02:34:02.382186 6358 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0314 02:34:02.382223 6361 master.cpp:558] Still acting as master!
I0314 02:34:02.382896 6358 state.cpp:33] Recovering state from /tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_V5iZ40/meta
I0314 02:34:02.384778 6359 status_update_manager.cpp:153] Recovering status update manager
I0314 02:34:02.384876 6359 status_update_manager.cpp:157] Recovering executor '24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4' of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:02.385256 6359 status_update_manager.cpp:402] Creating StatusUpdate stream for task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:02.385263 6358 slave.cpp:468] New master detected at master@67.195.138.60:37302
I0314 02:34:02.385738 6359 status_update_manager.hpp:233] Replaying status update stream for task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4
I0314 02:34:02.386617 6359 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:02.387115 6359 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:02.387837 6360 process_based_isolation_module.cpp:300] Recovering isolation module
I0314 02:34:02.387858 6359 status_update_manager.cpp:131] New master detected at master@67.195.138.60:37302
I0314 02:34:02.388214 6360 process_based_isolation_module.cpp:308] Recovering executor '24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4' of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:02.389631 6357 slave.cpp:1761] Recovering executors
I0314 02:34:02.389668 6357 slave.cpp:1765] Recovering executor '24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4' of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:02.390983 6357 slave.cpp:1847] Sending reconnect request to executor 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000 at executor(1)@67.195.138.60:49206
I0314 02:34:02.391490 6907 process.cpp:878] Socket closed while receiving
I0314 02:34:02.391552 6902 exec.cpp:216] Ignoring reconnect message from slave 201303140234-1015726915-37302-6337-0 because the driver is aborted!
I0314 02:34:02.391495 6357 slave.cpp:451] Successfully attached file '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_V5iZ40/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4/runs/2a097164-e499-4296-9801-23c63d35b97a'
I0314 02:34:03.214026 6362 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0314 02:34:03.220729 6362 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 6.75ms
I0314 02:34:03.383381 6364 process.cpp:878] Socket closed while receiving
I0314 02:34:04.222599 6359 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0314 02:34:04.222705 6359 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 184.39us
I0314 02:34:04.382905 6363 process_based_isolation_module.cpp:416] Telling slave of lost executor 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.385011 6360 slave.cpp:1437] Executor '24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4' of framework 201303140234-1015726915-37302-6337-0000 has exited with status 0
I0314 02:34:04.386641 6360 slave.cpp:1191] Handling status update TASK_FAILED from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.386795 6360 slave.cpp:1238] Forwarding status update TASK_FAILED from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000 to the status update manager
I0314 02:34:04.387336 6356 status_update_manager.cpp:253] Received status update TASK_FAILED from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.387527 6356 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_FAILED from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.387442 6359 gc.cpp:97] Scheduling /tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_V5iZ40/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4/runs/2a097164-e499-4296-9801-23c63d35b97a for removal
I0314 02:34:04.392158 6358 slave.cpp:1160] Cleaning up un-reregistered executors
I0314 02:34:04.392856 6358 slave.cpp:380] Finished recovery
W0314 02:34:04.392875 6362 master.cpp:964] Slave at slave(20)@67.195.138.60:37302 (janus.apache.org) is being allowed to re-register with an already in use id (201303140234-1015726915-37302-6337-0)
I0314 02:34:04.393424 6359 slave.cpp:547] Re-registered with master
I0314 02:34:04.382977 6363 process_utils.hpp:64] Stopping ... 6871
Sent signal to 6871
I0314 02:34:04.522972 6356 status_update_manager.hpp:314] Handling UPDATE for status update TASK_FAILED from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.523049 6356 status_update_manager.cpp:288] Forwarding status update TASK_FAILED from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000 to the master at master@67.195.138.60:37302
I0314 02:34:04.523654 6361 master.cpp:1016] Status update from (125)@67.195.138.60:37302: task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000 is now in state TASK_FAILED
I0314 02:34:04.523947 6356 sched.cpp:327] Status update: task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000 is now in state TASK_FAILED
I0314 02:34:04.523938 6361 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140234-1015726915-37302-6337-0
I0314 02:34:04.525253 6356 slave.cpp:967] Got acknowledgement of status update for task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.525342 6362 sched.cpp:422] Stopping framework '201303140234-1015726915-37302-6337-0000'
I0314 02:34:04.525810 6358 hierarchical_allocator_process.hpp:542] Recovered cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201303140234-1015726915-37302-6337-0 from framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.526232 6356 status_update_manager.cpp:313] Received status update acknowledgement for task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.528288 6356 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_FAILED from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.526908 6362 slave.cpp:439] Slave asked to shut down by @0.0.0.0:0
I0314 02:34:04.526712 6357 master.cpp:724] Asked to unregister framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.529660 6362 slave.cpp:389] Slave terminating
I0314 02:34:04.529711 6361 hierarchical_allocator_process.hpp:357] Deactivated framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.550856 6361 hierarchical_allocator_process.hpp:310] Removed framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.586948 6356 status_update_manager.hpp:314] Handling ACK for status update TASK_FAILED from task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.586993 6356 status_update_manager.cpp:433] Cleaning up status update stream for task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.587339 6356 status_update_manager.hpp:257] Deleting the meta directory for task 24a6fa30-5bc5-4d25-b6ab-83e42d58e5a4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.588508 6358 master.cpp:477] Master terminating
I0314 02:34:04.588598 6337 master.cpp:283] Shutting down master
I0314 02:34:04.589064 6358 hierarchical_allocator_process.hpp:421] Removed slave 201303140234-1015726915-37302-6337-0
[ OK ] SlaveRecoveryTest/0.RecoverTerminatedExecutor (3393 ms)
[ RUN ] SlaveRecoveryTest/0.CleanupExecutor
I0314 02:34:04.595635 6356 master.cpp:309] Master started on 67.195.138.60:37302
I0314 02:34:04.595687 6356 master.cpp:324] Master ID: 201303140234-1015726915-37302-6337
I0314 02:34:04.596644 6357 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : master@67.195.138.60:37302
I0314 02:34:04.596472 6361 sched.cpp:182] New master at master@67.195.138.60:37302
W0314 02:34:04.596668 6358 master.cpp:79] No whitelist given. Advertising offers for all slaves
I0314 02:34:04.596819 6356 master.cpp:553] Elected as master!
I0314 02:34:04.598475 6356 master.cpp:596] Registering framework 201303140234-1015726915-37302-6337-0000 at scheduler(17)@67.195.138.60:37302
I0314 02:34:04.598930 6363 sched.cpp:217] Framework registered with 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.598930 6356 hierarchical_allocator_process.hpp:266] Added framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.600051 6356 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0314 02:34:04.596151 6360 slave.cpp:202] Slave started on 21)@67.195.138.60:37302
I0314 02:34:04.601627 6360 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0314 02:34:04.601187 6356 hierarchical_allocator_process.hpp:597] Performed allocation for 0 slaves in 1.14ms
I0314 02:34:04.602458 6362 process_based_isolation_module.cpp:300] Recovering isolation module
I0314 02:34:04.602463 6360 slave.cpp:468] New master detected at master@67.195.138.60:37302
I0314 02:34:04.603618 6360 slave.cpp:380] Finished recovery
I0314 02:34:04.603642 6359 status_update_manager.cpp:131] New master detected at master@67.195.138.60:37302
I0314 02:34:04.604228 6358 master.cpp:918] Attempting to register slave on janus.apache.org at slave(21)@67.195.138.60:37302
I0314 02:34:04.605061 6358 master.cpp:1153] Master now considering a slave at janus.apache.org:37302 as active
I0314 02:34:04.605541 6358 master.cpp:1729] Adding slave 201303140234-1015726915-37302-6337-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0314 02:34:04.606215 6360 slave.cpp:502] Registered with master; given slave ID 201303140234-1015726915-37302-6337-0
I0314 02:34:04.606688 6360 paths.hpp:335] Created slave directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/meta/slaves/201303140234-1015726915-37302-6337-0'
Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/meta/slaves/201303140234-1015726915-37302-6337-0/slave.info'
I0314 02:34:04.606325 6358 hierarchical_allocator_process.hpp:393] Added slave 201303140234-1015726915-37302-6337-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=2; mem=1024; ports=[31000-32000]; disk=1024 available)
I0314 02:34:04.607595 6358 hierarchical_allocator_process.hpp:658] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140234-1015726915-37302-6337-0
I0314 02:34:04.608330 6358 hierarchical_allocator_process.hpp:684] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140234-1015726915-37302-6337-0 to framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.608932 6358 hierarchical_allocator_process.hpp:617] Performed allocation for slave 201303140234-1015726915-37302-6337-0 in 1.35ms
I0314 02:34:04.608971 6363 master.hpp:305] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140234-1015726915-37302-6337-0
I0314 02:34:04.609794 6363 master.cpp:1256] Sending 1 offers to framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.610296 6360 sched.cpp:282] Received 1 offers
I0314 02:34:04.612223 6356 master.cpp:1463] Processing reply for offer 201303140234-1015726915-37302-6337-0 on slave 201303140234-1015726915-37302-6337-0 (janus.apache.org) for framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.612332 6356 master.hpp:285] Adding task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140234-1015726915-37302-6337-0
I0314 02:34:04.612701 6356 master.cpp:1580] Launching task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140234-1015726915-37302-6337-0 (janus.apache.org)
I0314 02:34:04.613176 6363 slave.cpp:614] Got assigned task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 for framework 201303140234-1015726915-37302-6337-0000
Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/meta/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/framework.info'
Checkpointing 'scheduler(17)@67.195.138.60:37302' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/meta/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/framework.pid
I0314 02:34:04.615286 6363 paths.hpp:302] Created executor directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/runs/1448b7a1-8f68-4ada-8913-a3071a679506'
Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/meta/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/executor.info'
I0314 02:34:04.613235 6356 master.hpp:314] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140234-1015726915-37302-6337-0
I0314 02:34:04.615749 6363 paths.hpp:302] Created executor directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/meta/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/runs/1448b7a1-8f68-4ada-8913-a3071a679506'
Checkpointing Task to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/meta/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/runs/1448b7a1-8f68-4ada-8913-a3071a679506/tasks/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/task.info'
I0314 02:34:04.616458 6363 slave.cpp:451] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/runs/1448b7a1-8f68-4ada-8913-a3071a679506'
I0314 02:34:04.616456 6362 process_based_isolation_module.cpp:123] Launching 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 (<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src/mesos-executor)> in /tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/runs/1448b7a1-8f68-4ada-8913-a3071a679506 with resources ' for framework 201303140234-1015726915-37302-6337-0000
Checkpointing forked pid 6950
I0314 02:34:04.619618 6362 process_based_isolation_module.cpp:162] Forked executor at 6950
Checkpointing '6950' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/meta/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/runs/1448b7a1-8f68-4ada-8913-a3071a679506/pids/forked.pid
Fetching resources into /tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/runs/1448b7a1-8f68-4ada-8913-a3071a679506
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0314 02:34:04.662205 6955 process.cpp:1419] libprocess is initialized on 67.195.138.60:57461 for 8 cpus
I0314 02:34:04.663871 6970 exec.cpp:170] Executor started at: executor(1)@67.195.138.60:57461 with pid 6955
I0314 02:34:04.664849 6362 slave.cpp:1008] Got registration for executor '6643d306-ba6f-4355-bcaa-cfa4584d6aa4' of framework 201303140234-1015726915-37302-6337-0000
Checkpointing 'executor(1)@67.195.138.60:57461' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/meta/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/runs/1448b7a1-8f68-4ada-8913-a3071a679506/pids/libprocess.pid
I0314 02:34:04.665484 6362 slave.cpp:1083] Flushing queued tasks for framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.666044 6971 exec.cpp:194] Executor registered on slave 201303140234-1015726915-37302-6337-0
I0314 02:34:04.666072 6977 process.cpp:878] Socket closed while receiving
Registered executor on janus.apache.org
I0314 02:34:04.666189 6971 exec.cpp:258] Executor asked to run task '6643d306-ba6f-4355-bcaa-cfa4584d6aa4'
Starting task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4
sh -c 'sleep 1000'
I0314 02:34:04.666730 6971 exec.cpp:382] Executor sending status update for task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 in state TASK_RUNNING
I0314 02:34:04.668102 6357 slave.cpp:1191] Handling status update TASK_RUNNING from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.668223 6357 slave.cpp:1238] Forwarding status update TASK_RUNNING from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000 to the status update manager
I0314 02:34:04.668834 6357 status_update_manager.cpp:253] Received status update TASK_RUNNING from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.668989 6357 status_update_manager.cpp:402] Creating StatusUpdate stream for task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.669564 6357 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_RUNNING from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.748606 6357 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.748658 6357 status_update_manager.cpp:288] Forwarding status update TASK_RUNNING from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000 to the master at master@67.195.138.60:37302
I0314 02:34:04.749167 6356 master.cpp:1016] Status update from (128)@67.195.138.60:37302: task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000 is now in state TASK_RUNNING
I0314 02:34:04.749217 6361 slave.cpp:1300] Sending ACK for status update TASK_RUNNING from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000 to executor executor(1)@67.195.138.60:57461
I0314 02:34:04.751176 6969 exec.cpp:289] Executor received ACK for status update of task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.749567 6359 sched.cpp:327] Status update: task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000 is now in state TASK_RUNNING
I0314 02:34:04.751257 6977 process.cpp:878] Socket closed while receiving
I0314 02:34:04.751374 6359 slave.cpp:967] Got acknowledgement of status update for task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.751869 6359 status_update_manager.cpp:313] Received status update acknowledgement for task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.752291 6359 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_RUNNING from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:04.798799 6359 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:05.598064 6360 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0314 02:34:05.602890 6360 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 4.89ms
I0314 02:34:05.751410 6359 slave.cpp:389] Slave terminating
I0314 02:34:05.752524 6360 slave.cpp:202] Slave started on 22)@67.195.138.60:37302
I0314 02:34:05.752567 6360 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0314 02:34:05.752590 6358 master.cpp:558] Still acting as master!
I0314 02:34:05.753304 6360 state.cpp:33] Recovering state from /tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/meta
I0314 02:34:05.755173 6361 status_update_manager.cpp:153] Recovering status update manager
I0314 02:34:05.755209 6361 status_update_manager.cpp:157] Recovering executor '6643d306-ba6f-4355-bcaa-cfa4584d6aa4' of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:05.755601 6361 status_update_manager.cpp:402] Creating StatusUpdate stream for task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:05.756105 6361 status_update_manager.hpp:233] Replaying status update stream for task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4
I0314 02:34:05.756526 6361 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:05.757478 6361 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:05.755607 6360 slave.cpp:468] New master detected at master@67.195.138.60:37302
I0314 02:34:05.758187 6362 process_based_isolation_module.cpp:300] Recovering isolation module
I0314 02:34:05.758997 6362 process_based_isolation_module.cpp:308] Recovering executor '6643d306-ba6f-4355-bcaa-cfa4584d6aa4' of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:05.758401 6360 slave.cpp:483] Skipping registration because slave is started in 'cleanup' mode
I0314 02:34:05.759907 6360 slave.cpp:1761] Recovering executors
I0314 02:34:05.760375 6360 slave.cpp:1765] Recovering executor '6643d306-ba6f-4355-bcaa-cfa4584d6aa4' of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:05.761040 6360 slave.cpp:1856] Sending shutdown to executor 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000 at executor(1)@67.195.138.60:57461
I0314 02:34:05.762085 6360 slave.cpp:1612] Shutting down executor '6643d306-ba6f-4355-bcaa-cfa4584d6aa4' of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:05.762812 6977 process.cpp:878] Socket closed while receiving
I0314 02:34:05.762827 6973 exec.cpp:321] Executor asked to shutdown
I0314 02:34:05.762949 6973 exec.cpp:75] Scheduling shutdown of the executor
I0314 02:34:05.759914 6362 status_update_manager.cpp:131] New master detected at master@67.195.138.60:37302
Waited on process 6978, returned status 15
I0314 02:34:05.763187 6973 exec.cpp:382] Executor sending status update for task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 in state TASK_FAILED
I0314 02:34:05.762925 6360 slave.cpp:451] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/runs/1448b7a1-8f68-4ada-8913-a3071a679506'
I0314 02:34:05.763484 6360 slave.cpp:380] Finished recovery
I0314 02:34:06.603782 6358 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0314 02:34:06.610724 6358 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 6.97ms
I0314 02:34:06.764629 6364 process.cpp:878] Socket closed while receiving
I0314 02:34:07.611364 6359 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0314 02:34:07.618561 6359 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 7.22ms
I0314 02:34:07.754034 6363 process_based_isolation_module.cpp:416] Telling slave of lost executor 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:07.754153 6356 slave.cpp:1437] Executor '6643d306-ba6f-4355-bcaa-cfa4584d6aa4' of framework 201303140234-1015726915-37302-6337-0000 has exited with status 0
I0314 02:34:07.757725 6356 slave.cpp:1191] Handling status update TASK_FAILED from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:07.757870 6356 slave.cpp:1238] Forwarding status update TASK_FAILED from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000 to the status update manager
I0314 02:34:07.758357 6359 status_update_manager.cpp:253] Received status update TASK_FAILED from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:07.758617 6359 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_FAILED from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:07.758471 6362 gc.cpp:97] Scheduling /tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/slaves/201303140234-1015726915-37302-6337-0/frameworks/201303140234-1015726915-37302-6337-0000/executors/6643d306-ba6f-4355-bcaa-cfa4584d6aa4/runs/1448b7a1-8f68-4ada-8913-a3071a679506 for removal
I0314 02:34:07.758456 6356 slave.cpp:1561] Slave is shutting down because it is started with --recover==cleanup and all executors have terminated!
I0314 02:34:07.769192 6356 slave.cpp:1568] Archiving and deleting the meta directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_JmY68r/meta' to allow incompatible upgrade!
tar: Removing leading `/' from member names
I0314 02:34:07.801234 6356 slave.cpp:439] Slave asked to shut down by @0.0.0.0:0
I0314 02:34:07.801386 6356 slave.cpp:389] Slave terminating
I0314 02:34:07.754111 6363 process_utils.hpp:64] Stopping ... 6950
Sent signal to 6950
I0314 02:34:07.945116 6359 status_update_manager.hpp:314] Handling UPDATE for status update TASK_FAILED from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:07.945197 6359 status_update_manager.cpp:288] Forwarding status update TASK_FAILED from task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000 to the master at master@67.195.138.60:37302
I0314 02:34:07.945785 6357 master.cpp:1016] Status update from (132)@67.195.138.60:37302: task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000 is now in state TASK_FAILED
I0314 02:34:07.946079 6357 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140234-1015726915-37302-6337-0
I0314 02:34:07.946109 6361 sched.cpp:327] Status update: task 6643d306-ba6f-4355-bcaa-cfa4584d6aa4 of framework 201303140234-1015726915-37302-6337-0000 is now in state TASK_FAILED
I0314 02:34:07.946648 6356 hierarchical_allocator_process.hpp:542] Recovered cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201303140234-1015726915-37302-6337-0 from framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:07.947057 6362 sched.cpp:422] Stopping framework '201303140234-1015726915-37302-6337-0000'
I0314 02:34:07.947928 6357 master.cpp:724] Asked to unregister framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:07.948575 6363 hierarchical_allocator_process.hpp:357] Deactivated framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:07.948860 6363 hierarchical_allocator_process.hpp:310] Removed framework 201303140234-1015726915-37302-6337-0000
I0314 02:34:07.948766 6337 master.cpp:477] Master terminating
I0314 02:34:07.949815 6337 master.cpp:283] Shutting down master
I0314 02:34:07.950402 6356 hierarchical_allocator_process.hpp:421] Removed slave 201303140234-1015726915-37302-6337-0
[ OK ] SlaveRecoveryTest/0.CleanupExecutor (3356 ms)
[----------] 6 tests from SlaveRecoveryTest/0 (12334 ms total)
[----------] 6 tests from SlaveRecoveryTest/1, where TypeParam = mesos::internal::slave::CgroupsIsolationModule
[ RUN ] SlaveRecoveryTest/1.RecoverSlaveState
../../src/tests/utils.hpp:188: Failure
cgroups::mount(TEST_CGROUPS_HIERARCHY, subsystems): Failed to mount 'cpu,cpuacct,memory,freezer' at '/tmp/mesos_test_cgroup': Operation not permitted
-------------------------------------------------------------
We cannot run any cgroups tests that require
a hierarchy with subsystems 'cpu,cpuacct,memory,freezer'
because we failed to find an existing hierarchy
or create a new one. You can either remove all existing
hierarchies, or disable this test case
(i.e., --gtest_filter=-SlaveRecoveryTest/1.*).
-------------------------------------------------------------
I0314 02:34:07.952579 6362 master.cpp:309] Master started on 67.195.138.60:37302
I0314 02:34:07.952673 6362 master.cpp:324] Master ID: 201303140234-1015726915-37302-6337
I0314 02:34:07.953006 6358 slave.cpp:202] Slave started on 23)@67.195.138.60:37302
I0314 02:34:07.953454 6358 slave.cpp:203] Slave resources: cpus=8; mem=15025; ports=[31000-32000]; disk=14028
Using cgroups requires root permissions
../../src/tests/filter.hpp:67: ERROR: this mock object (used in test SlaveRecoveryTest/1.RecoverSlaveState) should be deleted but never is. Its address is @0x139e790.
ERROR: 1 leaked mock object found at program exit.
FAIL: mesos-tests
==================
1 of 1 test failed
==================
make[3]: *** [check-TESTS] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src'>
make: *** [check-recursive] Error 1
Process leaked file descriptors. See http://wiki.jenkins-ci.org/display/JENKINS/Spawning+processes+from+build for more information
Build step 'Execute shell' marked build as failure
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME #319
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/319/changes>
Changes:
[vinodkone] Added checkpoint field to slave info and fixed master to remove
slaves that have disabled checkpointing.
Review: https://reviews.apache.org/r/9927
[benh] Explicitly disabled tests with the CgroupsIsolationModule type
parameter.
Review: https://reviews.apache.org/r/9920
[benh] Added a TERMINATING process state to avoid filtering or enqueing
events after process cleanup has begun.
https://reviews.apache.org/r/9922
[vinodkone] Fixed the master to send updated framework pids and relink to the
reregistered slave.
Review: https://reviews.apache.org/r/9918
------------------------------------------
[...truncated 6454 lines...]
I0315 01:16:54.200036 24473 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 01:16:54.216889 24473 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 16.88ms
I0315 01:16:54.350396 24470 slave.cpp:390] Slave terminating
I0315 01:16:54.350605 24473 master.cpp:521] Slave 201303150116-1015726915-49340-24450-0(janus.apache.org) disconnected
I0315 01:16:54.351173 24779 process.cpp:878] Socket closed while receiving
I0315 01:16:54.351202 24771 exec.cpp:321] Executor asked to shutdown
I0315 01:16:54.351323 24774 exec.cpp:75] Scheduling shutdown of the executor
Waited on process 24780, returned status 15
I0315 01:16:54.351536 24773 exec.cpp:382] Executor sending status update for task 2cda50a5-44f1-4282-aee1-c9af21457b60 in state TASK_FAILED
I0315 01:16:54.351557 24469 slave.cpp:202] Slave started on 20)@67.195.138.60:49340
I0315 01:16:54.351595 24469 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0315 01:16:54.352246 24469 state.cpp:33] Recovering state from /tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_neaSYz/meta
I0315 01:16:54.351651 24470 master.cpp:576] Still acting as master!
I0315 01:16:54.353718 24472 status_update_manager.cpp:153] Recovering status update manager
I0315 01:16:54.353865 24472 status_update_manager.cpp:157] Recovering executor '2cda50a5-44f1-4282-aee1-c9af21457b60' of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:54.354353 24472 status_update_manager.cpp:402] Creating StatusUpdate stream for task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:54.354193 24469 slave.cpp:457] New master detected at master@67.195.138.60:49340
I0315 01:16:54.354882 24472 status_update_manager.hpp:233] Replaying status update stream for task 2cda50a5-44f1-4282-aee1-c9af21457b60
I0315 01:16:54.355752 24472 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:54.356232 24472 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:54.356930 24473 process_based_isolation_module.cpp:300] Recovering isolation module
I0315 01:16:54.357249 24473 process_based_isolation_module.cpp:308] Recovering executor '2cda50a5-44f1-4282-aee1-c9af21457b60' of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:54.356950 24472 status_update_manager.cpp:131] New master detected at master@67.195.138.60:49340
I0315 01:16:54.358147 24471 slave.cpp:1758] Recovering executors
I0315 01:16:54.358636 24471 slave.cpp:1762] Recovering executor '2cda50a5-44f1-4282-aee1-c9af21457b60' of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:54.359338 24471 slave.cpp:1844] Sending reconnect request to executor 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000 at executor(1)@67.195.138.60:47148
I0315 01:16:54.360571 24779 process.cpp:878] Socket closed while receiving
I0315 01:16:54.360635 24777 exec.cpp:216] Ignoring reconnect message from slave 201303150116-1015726915-49340-24450-0 because the driver is aborted!
I0315 01:16:54.360599 24471 slave.cpp:440] Successfully attached file '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_neaSYz/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/2cda50a5-44f1-4282-aee1-c9af21457b60/runs/674f6360-d7ee-4756-8e21-ad1928cf8302'
I0315 01:16:55.217609 24472 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 01:16:55.225368 24472 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 7.79ms
I0315 01:16:55.353036 24477 process.cpp:878] Socket closed while receiving
I0315 01:16:56.227113 24474 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 01:16:56.233194 24474 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 6.12ms
I0315 01:16:56.352308 24474 process_based_isolation_module.cpp:416] Telling slave of lost executor 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.352409 24470 slave.cpp:1434] Executor '2cda50a5-44f1-4282-aee1-c9af21457b60' of framework 201303150116-1015726915-49340-24450-0000 has exited with status 0
I0315 01:16:56.355842 24470 slave.cpp:1188] Handling status update TASK_FAILED from task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.355995 24470 slave.cpp:1235] Forwarding status update TASK_FAILED from task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000 to the status update manager
I0315 01:16:56.356487 24469 status_update_manager.cpp:253] Received status update TASK_FAILED from task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.356577 24471 gc.cpp:97] Scheduling /tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_neaSYz/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/2cda50a5-44f1-4282-aee1-c9af21457b60/runs/674f6360-d7ee-4756-8e21-ad1928cf8302 for removal
I0315 01:16:56.356724 24469 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_FAILED from task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.361495 24475 slave.cpp:1157] Cleaning up un-reregistered executors
I0315 01:16:56.361985 24475 slave.cpp:381] Finished recovery
W0315 01:16:56.362040 24473 master.cpp:983] Slave at slave(20)@67.195.138.60:49340 (janus.apache.org) is being allowed to re-register with an already in use id (201303150116-1015726915-49340-24450-0)
I0315 01:16:56.374301 24472 slave.cpp:536] Re-registered with master
I0315 01:16:56.352390 24474 process_utils.hpp:64] Stopping ... 24752
Sent signal to 24752
I0315 01:16:56.434831 24469 status_update_manager.hpp:314] Handling UPDATE for status update TASK_FAILED from task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.434895 24469 status_update_manager.cpp:288] Forwarding status update TASK_FAILED from task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000 to the master at master@67.195.138.60:49340
I0315 01:16:56.435355 24473 master.cpp:1054] Status update from (125)@67.195.138.60:49340: task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000 is now in state TASK_FAILED
I0315 01:16:56.435739 24470 sched.cpp:327] Status update: task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000 is now in state TASK_FAILED
I0315 01:16:56.436223 24470 slave.cpp:964] Got acknowledgement of status update for task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.436697 24470 status_update_manager.cpp:313] Received status update acknowledgement for task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.437082 24470 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_FAILED from task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.435747 24473 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150116-1015726915-49340-24450-0
I0315 01:16:56.436303 24450 sched.cpp:422] Stopping framework '201303150116-1015726915-49340-24450-0000'
I0315 01:16:56.438206 24475 hierarchical_allocator_process.hpp:542] Recovered cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201303150116-1015726915-49340-24450-0 from framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.446329 24450 slave.cpp:428] Slave asked to shut down by @0.0.0.0:0
I0315 01:16:56.446357 24473 master.cpp:742] Asked to unregister framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.477685 24450 slave.cpp:390] Slave terminating
I0315 01:16:56.498335 24473 hierarchical_allocator_process.hpp:357] Deactivated framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.506286 24472 master.cpp:521] Slave 201303150116-1015726915-49340-24450-0(janus.apache.org) disconnected
I0315 01:16:56.506320 24473 hierarchical_allocator_process.hpp:310] Removed framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.559798 24470 status_update_manager.hpp:314] Handling ACK for status update TASK_FAILED from task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.560212 24470 status_update_manager.cpp:433] Cleaning up status update stream for task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.560627 24470 status_update_manager.hpp:257] Deleting the meta directory for task 2cda50a5-44f1-4282-aee1-c9af21457b60 of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.561700 24450 master.cpp:477] Master terminating
I0315 01:16:56.561743 24450 master.cpp:283] Shutting down master
I0315 01:16:56.562260 24469 hierarchical_allocator_process.hpp:421] Removed slave 201303150116-1015726915-49340-24450-0
[ OK ] SlaveRecoveryTest/0.RecoverTerminatedExecutor (3369 ms)
[ RUN ] SlaveRecoveryTest/0.CleanupExecutor
I0315 01:16:56.564337 24471 master.cpp:309] Master started on 67.195.138.60:49340
I0315 01:16:56.564385 24471 master.cpp:324] Master ID: 201303150116-1015726915-49340-24450
I0315 01:16:56.564411 24474 slave.cpp:202] Slave started on 21)@67.195.138.60:49340
I0315 01:16:56.565208 24474 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0315 01:16:56.564836 24476 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : master@67.195.138.60:49340
W0315 01:16:56.564865 24475 master.cpp:79] No whitelist given. Advertising offers for all slaves
I0315 01:16:56.565002 24471 master.cpp:571] Elected as master!
I0315 01:16:56.564456 24472 sched.cpp:182] New master at master@67.195.138.60:49340
I0315 01:16:56.566009 24469 process_based_isolation_module.cpp:300] Recovering isolation module
I0315 01:16:56.566032 24474 slave.cpp:457] New master detected at master@67.195.138.60:49340
I0315 01:16:56.568629 24474 slave.cpp:381] Finished recovery
I0315 01:16:56.567739 24472 master.cpp:614] Registering framework 201303150116-1015726915-49340-24450-0000 at scheduler(17)@67.195.138.60:49340
I0315 01:16:56.568645 24469 status_update_manager.cpp:131] New master detected at master@67.195.138.60:49340
I0315 01:16:56.570289 24475 sched.cpp:217] Framework registered with 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.570315 24472 master.cpp:936] Attempting to register slave on janus.apache.org at slave(21)@67.195.138.60:49340
I0315 01:16:56.571666 24472 master.cpp:1191] Master now considering a slave at janus.apache.org:49340 as active
I0315 01:16:56.572165 24472 master.cpp:1767] Adding slave 201303150116-1015726915-49340-24450-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0315 01:16:56.570328 24473 hierarchical_allocator_process.hpp:266] Added framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.573120 24473 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 01:16:56.573616 24473 hierarchical_allocator_process.hpp:597] Performed allocation for 0 slaves in 496.67us
I0315 01:16:56.574131 24473 hierarchical_allocator_process.hpp:393] Added slave 201303150116-1015726915-49340-24450-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=2; mem=1024; ports=[31000-32000]; disk=1024 available)
I0315 01:16:56.574609 24473 hierarchical_allocator_process.hpp:658] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150116-1015726915-49340-24450-0
I0315 01:16:56.572718 24471 slave.cpp:491] Registered with master; given slave ID 201303150116-1015726915-49340-24450-0
I0315 01:16:56.575618 24471 paths.hpp:335] Created slave directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/meta/slaves/201303150116-1015726915-49340-24450-0'
Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/meta/slaves/201303150116-1015726915-49340-24450-0/slave.info'
I0315 01:16:56.575112 24473 hierarchical_allocator_process.hpp:684] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150116-1015726915-49340-24450-0 to framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.576800 24473 hierarchical_allocator_process.hpp:617] Performed allocation for slave 201303150116-1015726915-49340-24450-0 in 2.20ms
I0315 01:16:56.576830 24474 master.hpp:305] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150116-1015726915-49340-24450-0
I0315 01:16:56.578352 24474 master.cpp:1294] Sending 1 offers to framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.578840 24471 sched.cpp:282] Received 1 offers
I0315 01:16:56.580510 24469 master.cpp:1501] Processing reply for offer 201303150116-1015726915-49340-24450-0 on slave 201303150116-1015726915-49340-24450-0 (janus.apache.org) for framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.580698 24469 master.hpp:285] Adding task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150116-1015726915-49340-24450-0
I0315 01:16:56.580951 24469 master.cpp:1618] Launching task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150116-1015726915-49340-24450-0 (janus.apache.org)
I0315 01:16:56.581488 24476 slave.cpp:603] Got assigned task a3565c16-11ab-4845-90aa-594265a25e9b for framework 201303150116-1015726915-49340-24450-0000
Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/meta/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/framework.info'
Checkpointing 'scheduler(17)@67.195.138.60:49340' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/meta/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/framework.pid
I0315 01:16:56.583545 24476 paths.hpp:302] Created executor directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/a3565c16-11ab-4845-90aa-594265a25e9b/runs/7bbf426e-352b-4458-a622-3641954f9791'
Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/meta/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/a3565c16-11ab-4845-90aa-594265a25e9b/executor.info'
I0315 01:16:56.581521 24469 master.hpp:314] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150116-1015726915-49340-24450-0
I0315 01:16:56.583973 24476 paths.hpp:302] Created executor directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/meta/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/a3565c16-11ab-4845-90aa-594265a25e9b/runs/7bbf426e-352b-4458-a622-3641954f9791'
Checkpointing Task to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/meta/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/a3565c16-11ab-4845-90aa-594265a25e9b/runs/7bbf426e-352b-4458-a622-3641954f9791/tasks/a3565c16-11ab-4845-90aa-594265a25e9b/task.info'
I0315 01:16:56.584699 24476 slave.cpp:440] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/a3565c16-11ab-4845-90aa-594265a25e9b/runs/7bbf426e-352b-4458-a622-3641954f9791'
I0315 01:16:56.584704 24471 process_based_isolation_module.cpp:123] Launching a3565c16-11ab-4845-90aa-594265a25e9b (<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src/mesos-executor)> in /tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/a3565c16-11ab-4845-90aa-594265a25e9b/runs/7bbf426e-352b-4458-a622-3641954f9791 with resources ' for framework 201303150116-1015726915-49340-24450-0000
Checkpointing forked pid 24822
Checkpointing '24822' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/meta/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/a3565c16-11ab-4845-90aa-594265a25e9b/runs/7bbf426e-352b-4458-a622-3641954f9791/pids/forked.pid
I0315 01:16:56.587703 24471 process_based_isolation_module.cpp:162] Forked executor at 24822
Fetching resources into /tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/a3565c16-11ab-4845-90aa-594265a25e9b/runs/7bbf426e-352b-4458-a622-3641954f9791
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0315 01:16:56.630276 24827 process.cpp:1419] libprocess is initialized on 67.195.138.60:59502 for 8 cpus
I0315 01:16:56.631948 24841 exec.cpp:170] Executor started at: executor(1)@67.195.138.60:59502 with pid 24827
I0315 01:16:56.632731 24474 slave.cpp:1005] Got registration for executor 'a3565c16-11ab-4845-90aa-594265a25e9b' of framework 201303150116-1015726915-49340-24450-0000
Checkpointing 'executor(1)@67.195.138.60:59502' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/meta/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/a3565c16-11ab-4845-90aa-594265a25e9b/runs/7bbf426e-352b-4458-a622-3641954f9791/pids/libprocess.pid
I0315 01:16:56.633297 24474 slave.cpp:1080] Flushing queued tasks for framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.633779 24849 process.cpp:878] Socket closed while receiving
I0315 01:16:56.633853 24845 exec.cpp:194] Executor registered on slave 201303150116-1015726915-49340-24450-0
Registered executor on janus.apache.org
I0315 01:16:56.633966 24849 process.cpp:878] Socket closed while receiving
I0315 01:16:56.634078 24846 exec.cpp:258] Executor asked to run task 'a3565c16-11ab-4845-90aa-594265a25e9b'
Starting task a3565c16-11ab-4845-90aa-594265a25e9b
sh -c 'sleep 1000'
I0315 01:16:56.634605 24846 exec.cpp:382] Executor sending status update for task a3565c16-11ab-4845-90aa-594265a25e9b in state TASK_RUNNING
I0315 01:16:56.635917 24473 slave.cpp:1188] Handling status update TASK_RUNNING from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.635968 24473 slave.cpp:1235] Forwarding status update TASK_RUNNING from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000 to the status update manager
I0315 01:16:56.636538 24473 status_update_manager.cpp:253] Received status update TASK_RUNNING from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.636780 24473 status_update_manager.cpp:402] Creating StatusUpdate stream for task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.637352 24473 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_RUNNING from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.735941 24473 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.735988 24473 status_update_manager.cpp:288] Forwarding status update TASK_RUNNING from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000 to the master at master@67.195.138.60:49340
I0315 01:16:56.736498 24475 master.cpp:1054] Status update from (128)@67.195.138.60:49340: task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000 is now in state TASK_RUNNING
I0315 01:16:56.736624 24470 slave.cpp:1297] Sending ACK for status update TASK_RUNNING from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000 to executor executor(1)@67.195.138.60:59502
I0315 01:16:56.737532 24849 process.cpp:878] Socket closed while receiving
I0315 01:16:56.737570 24847 exec.cpp:289] Executor received ACK for status update of task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.736889 24472 sched.cpp:327] Status update: task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000 is now in state TASK_RUNNING
I0315 01:16:56.737825 24472 slave.cpp:964] Got acknowledgement of status update for task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.738265 24472 status_update_manager.cpp:313] Received status update acknowledgement for task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.738669 24472 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_RUNNING from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:56.802181 24472 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:57.566555 24473 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 01:16:57.566602 24473 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 83.69us
I0315 01:16:57.737936 24476 slave.cpp:390] Slave terminating
I0315 01:16:57.738162 24472 master.cpp:521] Slave 201303150116-1015726915-49340-24450-0(janus.apache.org) disconnected
I0315 01:16:57.739027 24473 slave.cpp:202] Slave started on 22)@67.195.138.60:49340
I0315 01:16:57.739063 24473 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0315 01:16:57.739123 24469 master.cpp:576] Still acting as master!
I0315 01:16:57.739748 24473 state.cpp:33] Recovering state from /tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/meta
I0315 01:16:57.741600 24476 status_update_manager.cpp:153] Recovering status update manager
I0315 01:16:57.741646 24476 status_update_manager.cpp:157] Recovering executor 'a3565c16-11ab-4845-90aa-594265a25e9b' of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:57.742023 24473 slave.cpp:457] New master detected at master@67.195.138.60:49340
I0315 01:16:57.742072 24476 status_update_manager.cpp:402] Creating StatusUpdate stream for task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:57.743021 24476 status_update_manager.hpp:233] Replaying status update stream for task a3565c16-11ab-4845-90aa-594265a25e9b
I0315 01:16:57.743916 24476 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:57.742475 24473 slave.cpp:472] Skipping registration because slave is started in 'cleanup' mode
I0315 01:16:57.744335 24476 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:57.745476 24470 process_based_isolation_module.cpp:300] Recovering isolation module
I0315 01:16:57.745823 24470 process_based_isolation_module.cpp:308] Recovering executor 'a3565c16-11ab-4845-90aa-594265a25e9b' of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:57.745486 24476 status_update_manager.cpp:131] New master detected at master@67.195.138.60:49340
I0315 01:16:57.746608 24473 slave.cpp:1758] Recovering executors
I0315 01:16:57.747170 24473 slave.cpp:1762] Recovering executor 'a3565c16-11ab-4845-90aa-594265a25e9b' of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:57.748567 24473 slave.cpp:1853] Sending shutdown to executor a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000 at executor(1)@67.195.138.60:59502
I0315 01:16:57.748816 24473 slave.cpp:1609] Shutting down executor 'a3565c16-11ab-4845-90aa-594265a25e9b' of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:57.749480 24849 process.cpp:878] Socket closed while receiving
I0315 01:16:57.749512 24848 exec.cpp:321] Executor asked to shutdown
I0315 01:16:57.749603 24848 exec.cpp:75] Scheduling shutdown of the executor
Waited on process 24850, returned status 15
I0315 01:16:57.749801 24843 exec.cpp:382] Executor sending status update for task a3565c16-11ab-4845-90aa-594265a25e9b in state TASK_FAILED
I0315 01:16:57.750157 24473 slave.cpp:440] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/a3565c16-11ab-4845-90aa-594265a25e9b/runs/7bbf426e-352b-4458-a622-3641954f9791'
I0315 01:16:57.750205 24473 slave.cpp:381] Finished recovery
I0315 01:16:58.567729 24472 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 01:16:58.573717 24472 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 6.01ms
I0315 01:16:58.751245 24477 process.cpp:878] Socket closed while receiving
I0315 01:16:59.575033 24474 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 01:16:59.581568 24474 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 6.57ms
I0315 01:16:59.740150 24470 process_based_isolation_module.cpp:416] Telling slave of lost executor a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:59.742136 24469 slave.cpp:1434] Executor 'a3565c16-11ab-4845-90aa-594265a25e9b' of framework 201303150116-1015726915-49340-24450-0000 has exited with status 0
I0315 01:16:59.743664 24469 slave.cpp:1188] Handling status update TASK_FAILED from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:59.743789 24469 slave.cpp:1235] Forwarding status update TASK_FAILED from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000 to the status update manager
I0315 01:16:59.744189 24472 status_update_manager.cpp:253] Received status update TASK_FAILED from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:59.744523 24472 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_FAILED from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:59.744297 24475 gc.cpp:97] Scheduling /tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/slaves/201303150116-1015726915-49340-24450-0/frameworks/201303150116-1015726915-49340-24450-0000/executors/a3565c16-11ab-4845-90aa-594265a25e9b/runs/7bbf426e-352b-4458-a622-3641954f9791 for removal
I0315 01:16:59.744261 24469 slave.cpp:1558] Slave is shutting down because it is started with --recover==cleanup and all executors have terminated!
I0315 01:16:59.767133 24469 slave.cpp:1565] Archiving and deleting the meta directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_POtFMh/meta' to allow incompatible upgrade!
tar: Removing leading `/' from member names
I0315 01:16:59.777994 24469 slave.cpp:428] Slave asked to shut down by @0.0.0.0:0
I0315 01:16:59.778100 24469 slave.cpp:390] Slave terminating
I0315 01:16:59.740216 24470 process_utils.hpp:64] Stopping ... 24822
Sent signal to 24822
I0315 01:16:59.831182 24472 status_update_manager.hpp:314] Handling UPDATE for status update TASK_FAILED from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:59.831274 24472 status_update_manager.cpp:288] Forwarding status update TASK_FAILED from task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000 to the master at master@67.195.138.60:49340
I0315 01:16:59.831959 24473 master.cpp:1054] Status update from (132)@67.195.138.60:49340: task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000 is now in state TASK_FAILED
I0315 01:16:59.832192 24476 sched.cpp:327] Status update: task a3565c16-11ab-4845-90aa-594265a25e9b of framework 201303150116-1015726915-49340-24450-0000 is now in state TASK_FAILED
I0315 01:16:59.832191 24473 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150116-1015726915-49340-24450-0
I0315 01:16:59.832712 24471 sched.cpp:422] Stopping framework '201303150116-1015726915-49340-24450-0000'
I0315 01:16:59.833199 24475 hierarchical_allocator_process.hpp:542] Recovered cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201303150116-1015726915-49340-24450-0 from framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:59.833587 24470 master.cpp:742] Asked to unregister framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:59.834499 24470 master.cpp:477] Master terminating
I0315 01:16:59.834522 24469 hierarchical_allocator_process.hpp:357] Deactivated framework 201303150116-1015726915-49340-24450-0000
I0315 01:16:59.834985 24450 master.cpp:283] Shutting down master
I0315 01:16:59.835469 24469 hierarchical_allocator_process.hpp:310] Removed framework 201303150116-1015726915-49340-24450-0000
[ OK ] SlaveRecoveryTest/0.CleanupExecutor (3273 ms)
[----------] 6 tests from SlaveRecoveryTest/0 (13964 ms total)
[----------] 6 tests from SlaveRecoveryTest/1, where TypeParam = mesos::internal::slave::CgroupsIsolationModule
[ RUN ] SlaveRecoveryTest/1.RecoverSlaveState
../../src/tests/utils.hpp:188: Failure
cgroups::mount(TEST_CGROUPS_HIERARCHY, subsystems): Failed to mount 'cpu,cpuacct,memory,freezer' at '/tmp/mesos_test_cgroup': Operation not permitted
-------------------------------------------------------------
We cannot run any cgroups tests that require
a hierarchy with subsystems 'cpu,cpuacct,memory,freezer'
because we failed to find an existing hierarchy
or create a new one. You can either remove all existing
hierarchies, or disable this test case
(i.e., --gtest_filter=-SlaveRecoveryTest/1.*).
-------------------------------------------------------------
I0315 01:16:59.838203 24471 master.cpp:309] Master started on 67.195.138.60:49340
I0315 01:16:59.838318 24471 master.cpp:324] Master ID: 201303150116-1015726915-49340-24450
I0315 01:16:59.838587 24475 slave.cpp:202] Slave started on 23)@67.195.138.60:49340
I0315 01:16:59.838809 24470 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : master@67.195.138.60:49340
W0315 01:16:59.838817 24473 master.cpp:79] No whitelist given. Advertising offers for all slaves
I0315 01:16:59.838978 24471 master.cpp:571] Elected as master!
I0315 01:16:59.839095 24475 slave.cpp:203] Slave resources: cpus=8; mem=15025; ports=[31000-32000]; disk=14042
Using cgroups requires root permissions
I0315 01:16:59.842336 24475 slave.cpp:457] New master detected at master@67.195.138.60:49340
I0315 01:16:59.842417 24475 slave.cpp:428] Slave asked to shut down by @0.0.0.0:0
I0315 01:16:59.842871 24475 slave.cpp:390] Slave terminating
I0315 01:16:59.842422 24471 status_update_manager.cpp:131] New master detected at master@67.195.138.60:49340
FAIL: mesos-tests
==================
1 of 1 test failed
==================
make[3]: *** [check-TESTS] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src'>
make: *** [check-recursive] Error 1
Process leaked file descriptors. See http://wiki.jenkins-ci.org/display/JENKINS/Spawning+processes+from+build for more information
Build step 'Execute shell' marked build as failure
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME #318
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/318/changes>
Changes:
[vinodkone] Fixed gtest environment to filter templated tests with a typename
that includes 'CgroupsIsolationModule'.
From: Ben Mahler <be...@gmail.com>
Review: https://reviews.apache.org/r/9906
[vinodkone] Fixed Duration to use a base unit of seconds.
From: Ben Mahler <be...@gmail.com>
Review: https://reviews.apache.org/r/9765
------------------------------------------
[...truncated 7834 lines...]
I0314 04:28:38.468829 15530 master.hpp:314] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.472054 15529 paths.hpp:302] Created executor directory '/tmp/FaultToleranceTest_SchedulerFailoverStatusUpdate_EZ7TUh/slaves/201303140428-1015726915-53734-15499-0/frameworks/201303140428-1015726915-53734-15499-0000/executors/default/runs/07ea8041-1cbd-4abf-8aa8-8bcca1212e8c'
I0314 04:28:38.518877 15527 exec.cpp:170] Executor started at: executor(15)@67.195.138.60:53734 with pid 15499
I0314 04:28:38.519075 15530 slave.cpp:451] Successfully attached file '/tmp/FaultToleranceTest_SchedulerFailoverStatusUpdate_EZ7TUh/slaves/201303140428-1015726915-53734-15499-0/frameworks/201303140428-1015726915-53734-15499-0000/executors/default/runs/07ea8041-1cbd-4abf-8aa8-8bcca1212e8c'
I0314 04:28:38.550557 15530 slave.cpp:1008] Got registration for executor 'default' of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.551113 15530 slave.cpp:1083] Flushing queued tasks for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.551180 15526 exec.cpp:194] Executor registered on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.552011 15526 exec.cpp:258] Executor asked to run task '1'
I0314 04:28:38.552484 15526 exec.cpp:382] Executor sending status update for task 1 in state TASK_RUNNING
I0314 04:28:38.553957 15526 slave.cpp:1191] Handling status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.554003 15526 slave.cpp:1238] Forwarding status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to the status update manager
I0314 04:28:38.554433 15529 status_update_manager.cpp:253] Received status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.554841 15529 status_update_manager.cpp:402] Creating StatusUpdate stream for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.555320 15529 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.555788 15529 status_update_manager.cpp:288] Forwarding status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to the master at master@67.195.138.60:53734
I0314 04:28:38.556344 15526 master.cpp:1016] Status update from (254)@67.195.138.60:53734: task 1 of framework 201303140428-1015726915-53734-15499-0000 is now in state TASK_RUNNING
I0314 04:28:38.556463 15530 slave.cpp:1300] Sending ACK for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to executor executor(15)@67.195.138.60:53734
I0314 04:28:38.557268 15530 exec.cpp:289] Executor received ACK for status update of task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.557045 15529 sched.cpp:182] New master at master@67.195.138.60:53734
I0314 04:28:38.558259 15531 master.cpp:631] Re-registering framework 201303140428-1015726915-53734-15499-0000 at scheduler(40)@67.195.138.60:53734
I0314 04:28:38.558715 15531 master.cpp:650] Framework 201303140428-1015726915-53734-15499-0000 failed over
I0314 04:28:38.559947 15529 sched.cpp:413] Got error 'Framework failed over'
I0314 04:28:38.559999 15525 sched.cpp:217] Framework registered with 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.560026 15527 slave.cpp:954] Updating framework 201303140428-1015726915-53734-15499-0000 pid to scheduler(40)@67.195.138.60:53734
I0314 04:28:38.560369 15529 sched.cpp:446] Aborting framework '201303140428-1015726915-53734-15499-0000'
I0314 04:28:38.561105 15530 hierarchical_allocator_process.hpp:666] No resources available to allocate!
W0314 04:28:38.561171 15524 master.cpp:79] No whitelist given. Advertising offers for all slaves
I0314 04:28:38.561210 15531 status_update_manager.cpp:378] Checking for unacknowledged status updates
I0314 04:28:38.561441 15525 monitor.cpp:208] Publishing resource usage for executor 'default' of framework '201303140428-1015726915-53734-15499-0000'
W0314 04:28:38.561843 15529 master.cpp:748] scheduler(39)@67.195.138.60:53734 tried to deactivate framework; expecting scheduler(40)@67.195.138.60:53734
I0314 04:28:38.562273 15530 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 1.18ms
W0314 04:28:38.563680 15531 status_update_manager.cpp:387] Resending status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.567484 15531 status_update_manager.cpp:288] Forwarding status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to the master at master@67.195.138.60:53734
I0314 04:28:38.569103 15528 master.cpp:1016] Status update from (254)@67.195.138.60:53734: task 1 of framework 201303140428-1015726915-53734-15499-0000 is now in state TASK_RUNNING
I0314 04:28:38.569509 15528 sched.cpp:327] Status update: task 1 of framework 201303140428-1015726915-53734-15499-0000 is now in state TASK_RUNNING
I0314 04:28:38.569977 15527 sched.cpp:422] Stopping framework '201303140428-1015726915-53734-15499-0000'
I0314 04:28:38.570019 15528 sched.cpp:422] Stopping framework '201303140428-1015726915-53734-15499-0000'
I0314 04:28:38.570034 15525 slave.cpp:967] Got acknowledgement of status update for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.570533 15526 master.cpp:724] Asked to unregister framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.571532 15531 status_update_manager.cpp:313] Received status update acknowledgement for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.572396 15531 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
W0314 04:28:38.571876 15526 master.cpp:731] scheduler(39)@67.195.138.60:53734 tried to unregister framework; expecting scheduler(40)@67.195.138.60:53734
I0314 04:28:38.573675 15526 master.cpp:724] Asked to unregister framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.574609 15529 hierarchical_allocator_process.hpp:357] Deactivated framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.574635 15530 slave.cpp:889] Asked to shut down framework 201303140428-1015726915-53734-15499-0000 by master@67.195.138.60:53734
I0314 04:28:38.575855 15530 slave.cpp:894] Shutting down framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.576340 15530 slave.cpp:1612] Shutting down executor 'default' of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.574667 15526 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.576927 15524 exec.cpp:321] Executor asked to shutdown
I0314 04:28:38.576959 15527 status_update_manager.cpp:232] Closing status update streams for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.578560 15525 hierarchical_allocator_process.hpp:542] Recovered cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201303140428-1015726915-53734-15499-0 from framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.579071 15530 slave.cpp:389] Slave terminating
I0314 04:28:38.579551 15527 status_update_manager.cpp:433] Cleaning up status update stream for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.580101 15525 hierarchical_allocator_process.hpp:310] Removed framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.580500 15530 slave.cpp:889] Asked to shut down framework 201303140428-1015726915-53734-15499-0000 by @0.0.0.0:0
I0314 04:28:38.581997 15530 slave.cpp:894] Shutting down framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.582470 15530 slave.cpp:1612] Shutting down executor 'default' of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.583169 15526 status_update_manager.cpp:232] Closing status update streams for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.583261 15528 master.cpp:1001] Asked to unregister slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.585218 15528 master.cpp:477] Master terminating
I0314 04:28:38.585242 15524 hierarchical_allocator_process.hpp:421] Removed slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.586066 15499 master.cpp:283] Shutting down master
[ OK ] FaultToleranceTest.SchedulerFailoverStatusUpdate (139 ms)
[ RUN ] FaultToleranceTest.ForwardStatusUpdateUnknownExecutor
I0314 04:28:38.588567 15527 master.cpp:309] Master started on 67.195.138.60:53734
I0314 04:28:38.588664 15527 master.cpp:324] Master ID: 201303140428-1015726915-53734-15499
I0314 04:28:38.589020 15530 slave.cpp:202] Slave started on 52)@67.195.138.60:53734
I0314 04:28:38.589285 15531 sched.cpp:182] New master at master@67.195.138.60:53734
I0314 04:28:38.589800 15524 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : master@67.195.138.60:53734
W0314 04:28:38.589856 15528 master.cpp:79] No whitelist given. Advertising offers for all slaves
I0314 04:28:38.590016 15527 master.cpp:553] Elected as master!
I0314 04:28:38.592614 15527 master.cpp:596] Registering framework 201303140428-1015726915-53734-15499-0000 at scheduler(41)@67.195.138.60:53734
I0314 04:28:38.590142 15530 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0314 04:28:38.593916 15530 slave.cpp:468] New master detected at master@67.195.138.60:53734
I0314 04:28:38.593125 15526 sched.cpp:217] Framework registered with 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.593124 15525 hierarchical_allocator_process.hpp:266] Added framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.596139 15525 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0314 04:28:38.595074 15529 status_update_manager.cpp:131] New master detected at master@67.195.138.60:53734
I0314 04:28:38.595039 15530 slave.cpp:380] Finished recovery
I0314 04:28:38.596606 15525 hierarchical_allocator_process.hpp:597] Performed allocation for 0 slaves in 467.30us
I0314 04:28:38.597738 15524 master.cpp:918] Attempting to register slave on janus.apache.org at slave(52)@67.195.138.60:53734
I0314 04:28:38.598517 15524 master.cpp:1153] Master now considering a slave at janus.apache.org:53734 as active
I0314 04:28:38.599035 15524 master.cpp:1729] Adding slave 201303140428-1015726915-53734-15499-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0314 04:28:38.599823 15531 slave.cpp:502] Registered with master; given slave ID 201303140428-1015726915-53734-15499-0
I0314 04:28:38.599925 15530 hierarchical_allocator_process.hpp:393] Added slave 201303140428-1015726915-53734-15499-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=2; mem=1024; ports=[31000-32000]; disk=1024 available)
I0314 04:28:38.601771 15530 hierarchical_allocator_process.hpp:658] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.602344 15530 hierarchical_allocator_process.hpp:684] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0 to framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.603672 15530 hierarchical_allocator_process.hpp:617] Performed allocation for slave 201303140428-1015726915-53734-15499-0 in 1.92ms
I0314 04:28:38.603730 15531 master.hpp:305] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.604671 15531 master.cpp:1256] Sending 1 offers to framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.605167 15531 sched.cpp:282] Received 1 offers
I0314 04:28:38.605837 15524 master.cpp:1463] Processing reply for offer 201303140428-1015726915-53734-15499-0 on slave 201303140428-1015726915-53734-15499-0 (janus.apache.org) for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.606396 15524 master.hpp:285] Adding task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.606807 15524 master.cpp:1580] Launching task 1 of framework 201303140428-1015726915-53734-15499-0000 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0 (janus.apache.org)
I0314 04:28:38.607317 15529 slave.cpp:614] Got assigned task 1 for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.607367 15524 master.hpp:314] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.609212 15529 paths.hpp:302] Created executor directory '/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_J73E1h/slaves/201303140428-1015726915-53734-15499-0/frameworks/201303140428-1015726915-53734-15499-0000/executors/default/runs/dee2a3cd-476c-4a18-947b-9c57f238431e'
I0314 04:28:38.609585 15528 slave.cpp:451] Successfully attached file '/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_J73E1h/slaves/201303140428-1015726915-53734-15499-0/frameworks/201303140428-1015726915-53734-15499-0000/executors/default/runs/dee2a3cd-476c-4a18-947b-9c57f238431e'
I0314 04:28:38.609675 15530 exec.cpp:170] Executor started at: executor(16)@67.195.138.60:53734 with pid 15499
I0314 04:28:38.610303 15530 slave.cpp:1008] Got registration for executor 'default' of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.611786 15530 slave.cpp:1083] Flushing queued tasks for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.611815 15526 exec.cpp:194] Executor registered on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.612839 15526 exec.cpp:258] Executor asked to run task '1'
I0314 04:28:38.613276 15526 exec.cpp:382] Executor sending status update for task 1 in state TASK_RUNNING
I0314 04:28:38.614953 15529 slave.cpp:1191] Handling status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.614991 15529 slave.cpp:1238] Forwarding status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to the status update manager
I0314 04:28:38.615417 15528 status_update_manager.cpp:253] Received status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.615823 15528 status_update_manager.cpp:402] Creating StatusUpdate stream for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.616475 15528 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.617012 15528 status_update_manager.cpp:288] Forwarding status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to the master at master@67.195.138.60:53734
I0314 04:28:38.617640 15527 master.cpp:1016] Status update from (260)@67.195.138.60:53734: task 1 of framework 201303140428-1015726915-53734-15499-0000 is now in state TASK_RUNNING
I0314 04:28:38.617671 15525 slave.cpp:1300] Sending ACK for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to executor executor(16)@67.195.138.60:53734
I0314 04:28:38.618126 15531 sched.cpp:327] Status update: task 1 of framework 201303140428-1015726915-53734-15499-0000 is now in state TASK_RUNNING
I0314 04:28:38.618552 15527 exec.cpp:289] Executor received ACK for status update of task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.619081 15525 slave.cpp:967] Got acknowledgement of status update for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.620079 15525 status_update_manager.cpp:313] Received status update acknowledgement for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.621201 15525 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.620352 15531 slave.cpp:1191] Handling status update TASK_RUNNING from task task2 of framework 201303140428-1015726915-53734-15499-0000
W0314 04:28:38.622195 15531 slave.cpp:1214] Could not find executor for task task2 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.622735 15531 slave.cpp:1238] Forwarding status update TASK_RUNNING from task task2 of framework 201303140428-1015726915-53734-15499-0000 to the status update manager
I0314 04:28:38.623652 15527 status_update_manager.cpp:253] Received status update TASK_RUNNING from task task2 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.624085 15527 status_update_manager.cpp:402] Creating StatusUpdate stream for task task2 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.626417 15527 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task task2 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.626885 15527 status_update_manager.cpp:288] Forwarding status update TASK_RUNNING from task task2 of framework 201303140428-1015726915-53734-15499-0000 to the master at master@67.195.138.60:53734
I0314 04:28:38.627512 15531 master.cpp:1016] Status update from (260)@67.195.138.60:53734: task task2 of framework 201303140428-1015726915-53734-15499-0000 is now in state TASK_RUNNING
W0314 04:28:38.628726 15531 master.cpp:1048] Status update from (260)@67.195.138.60:53734 (janus.apache.org): error, couldn't lookup task task2
I0314 04:28:38.628783 15529 sched.cpp:327] Status update: task task2 of framework 201303140428-1015726915-53734-15499-0000 is now in state TASK_RUNNING
I0314 04:28:38.630244 15529 slave.cpp:967] Got acknowledgement of status update for task task2 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.630275 15524 sched.cpp:422] Stopping framework '201303140428-1015726915-53734-15499-0000'
I0314 04:28:38.630724 15530 status_update_manager.cpp:313] Received status update acknowledgement for task task2 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.632550 15530 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task task2 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.631140 15529 master.cpp:724] Asked to unregister framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.633766 15524 hierarchical_allocator_process.hpp:357] Deactivated framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.633788 15528 slave.cpp:889] Asked to shut down framework 201303140428-1015726915-53734-15499-0000 by master@67.195.138.60:53734
I0314 04:28:38.634719 15528 slave.cpp:894] Shutting down framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.635238 15528 slave.cpp:1612] Shutting down executor 'default' of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.635756 15531 exec.cpp:321] Executor asked to shutdown
I0314 04:28:38.635779 15530 status_update_manager.cpp:232] Closing status update streams for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.633805 15529 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.636291 15499 slave.cpp:389] Slave terminating
I0314 04:28:38.638355 15499 slave.cpp:889] Asked to shut down framework 201303140428-1015726915-53734-15499-0000 by @0.0.0.0:0
I0314 04:28:38.638063 15526 hierarchical_allocator_process.hpp:542] Recovered cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201303140428-1015726915-53734-15499-0 from framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.636793 15530 status_update_manager.cpp:433] Cleaning up status update stream for task task2 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.639960 15530 status_update_manager.cpp:433] Cleaning up status update stream for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.639370 15526 hierarchical_allocator_process.hpp:310] Removed framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.638816 15499 slave.cpp:894] Shutting down framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.641362 15499 slave.cpp:1612] Shutting down executor 'default' of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.642901 15528 status_update_manager.cpp:232] Closing status update streams for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.642971 15525 master.cpp:1001] Asked to unregister slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.644134 15525 master.cpp:477] Master terminating
I0314 04:28:38.644157 15531 hierarchical_allocator_process.hpp:421] Removed slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.646106 15499 master.cpp:283] Shutting down master
[ OK ] FaultToleranceTest.ForwardStatusUpdateUnknownExecutor (59 ms)
[ RUN ] FaultToleranceTest.SchedulerFailoverFrameworkMessage
I0314 04:28:38.647588 15531 master.cpp:309] Master started on 67.195.138.60:53734
I0314 04:28:38.647660 15531 master.cpp:324] Master ID: 201303140428-1015726915-53734-15499
I0314 04:28:38.648110 15529 slave.cpp:202] Slave started on 53)@67.195.138.60:53734
I0314 04:28:38.648202 15530 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : master@67.195.138.60:53734
W0314 04:28:38.648231 15525 master.cpp:79] No whitelist given. Advertising offers for all slaves
I0314 04:28:38.648370 15531 master.cpp:553] Elected as master!
I0314 04:28:38.648437 15524 sched.cpp:182] New master at master@67.195.138.60:53734
I0314 04:28:38.648470 15529 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0314 04:28:38.651875 15527 master.cpp:596] Registering framework 201303140428-1015726915-53734-15499-0000 at scheduler(42)@67.195.138.60:53734
I0314 04:28:38.652915 15524 sched.cpp:217] Framework registered with 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.652926 15527 hierarchical_allocator_process.hpp:266] Added framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.653851 15527 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0314 04:28:38.655067 15527 hierarchical_allocator_process.hpp:597] Performed allocation for 0 slaves in 1.22ms
I0314 04:28:38.652744 15529 slave.cpp:468] New master detected at master@67.195.138.60:53734
I0314 04:28:38.656069 15529 slave.cpp:380] Finished recovery
I0314 04:28:38.656072 15530 status_update_manager.cpp:131] New master detected at master@67.195.138.60:53734
I0314 04:28:38.656733 15527 master.cpp:918] Attempting to register slave on janus.apache.org at slave(53)@67.195.138.60:53734
I0314 04:28:38.657591 15527 master.cpp:1153] Master now considering a slave at janus.apache.org:53734 as active
I0314 04:28:38.658236 15527 master.cpp:1729] Adding slave 201303140428-1015726915-53734-15499-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0314 04:28:38.658807 15529 slave.cpp:502] Registered with master; given slave ID 201303140428-1015726915-53734-15499-0
I0314 04:28:38.658917 15526 hierarchical_allocator_process.hpp:393] Added slave 201303140428-1015726915-53734-15499-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=2; mem=1024; ports=[31000-32000]; disk=1024 available)
I0314 04:28:38.660892 15526 hierarchical_allocator_process.hpp:658] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.662082 15526 hierarchical_allocator_process.hpp:684] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0 to framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.662931 15526 hierarchical_allocator_process.hpp:617] Performed allocation for slave 201303140428-1015726915-53734-15499-0 in 2.06ms
I0314 04:28:38.662966 15527 master.hpp:305] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.663732 15527 master.cpp:1256] Sending 1 offers to framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.664222 15531 sched.cpp:282] Received 1 offers
I0314 04:28:38.665107 15528 master.cpp:1463] Processing reply for offer 201303140428-1015726915-53734-15499-0 on slave 201303140428-1015726915-53734-15499-0 (janus.apache.org) for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.665501 15528 master.hpp:285] Adding task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.665874 15528 master.cpp:1580] Launching task 1 of framework 201303140428-1015726915-53734-15499-0000 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0 (janus.apache.org)
I0314 04:28:38.666404 15525 slave.cpp:614] Got assigned task 1 for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.666474 15528 master.hpp:314] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.668900 15525 paths.hpp:302] Created executor directory '/tmp/FaultToleranceTest_SchedulerFailoverFrameworkMessage_A2apii/slaves/201303140428-1015726915-53734-15499-0/frameworks/201303140428-1015726915-53734-15499-0000/executors/default/runs/565e63a1-a4dd-4d93-8c13-6e85a20ec2de'
I0314 04:28:38.669179 15527 slave.cpp:451] Successfully attached file '/tmp/FaultToleranceTest_SchedulerFailoverFrameworkMessage_A2apii/slaves/201303140428-1015726915-53734-15499-0/frameworks/201303140428-1015726915-53734-15499-0000/executors/default/runs/565e63a1-a4dd-4d93-8c13-6e85a20ec2de'
I0314 04:28:38.669302 15525 exec.cpp:170] Executor started at: executor(17)@67.195.138.60:53734 with pid 15499
I0314 04:28:38.670753 15525 slave.cpp:1008] Got registration for executor 'default' of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.671393 15525 slave.cpp:1083] Flushing queued tasks for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.671438 15528 exec.cpp:194] Executor registered on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.672396 15528 exec.cpp:258] Executor asked to run task '1'
I0314 04:28:38.672799 15528 exec.cpp:382] Executor sending status update for task 1 in state TASK_RUNNING
I0314 04:28:38.674502 15524 slave.cpp:1191] Handling status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.674540 15524 slave.cpp:1238] Forwarding status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to the status update manager
I0314 04:28:38.675204 15528 status_update_manager.cpp:253] Received status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.675647 15528 status_update_manager.cpp:402] Creating StatusUpdate stream for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.676182 15528 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.676656 15528 status_update_manager.cpp:288] Forwarding status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to the master at master@67.195.138.60:53734
I0314 04:28:38.677193 15531 master.cpp:1016] Status update from (266)@67.195.138.60:53734: task 1 of framework 201303140428-1015726915-53734-15499-0000 is now in state TASK_RUNNING
I0314 04:28:38.677217 15529 slave.cpp:1300] Sending ACK for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to executor executor(17)@67.195.138.60:53734
I0314 04:28:38.677693 15527 sched.cpp:327] Status update: task 1 of framework 201303140428-1015726915-53734-15499-0000 is now in state TASK_RUNNING
I0314 04:28:38.678215 15531 exec.cpp:289] Executor received ACK for status update of task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.679352 15527 slave.cpp:967] Got acknowledgement of status update for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.679553 15529 sched.cpp:182] New master at master@67.195.138.60:53734
I0314 04:28:38.680408 15527 status_update_manager.cpp:313] Received status update acknowledgement for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.681324 15527 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.680902 15528 master.cpp:631] Re-registering framework 201303140428-1015726915-53734-15499-0000 at scheduler(43)@67.195.138.60:53734
I0314 04:28:38.682379 15528 master.cpp:650] Framework 201303140428-1015726915-53734-15499-0000 failed over
I0314 04:28:38.683537 15527 sched.cpp:413] Got error 'Framework failed over'
I0314 04:28:38.684315 15527 sched.cpp:446] Aborting framework '201303140428-1015726915-53734-15499-0000'
W0314 04:28:38.684795 15527 master.cpp:748] scheduler(42)@67.195.138.60:53734 tried to deactivate framework; expecting scheduler(43)@67.195.138.60:53734
I0314 04:28:38.683559 15529 sched.cpp:217] Framework registered with 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.683568 15528 slave.cpp:954] Updating framework 201303140428-1015726915-53734-15499-0000 pid to scheduler(43)@67.195.138.60:53734
I0314 04:28:38.686815 15528 slave.cpp:1328] Sending message for framework 201303140428-1015726915-53734-15499-0000 to scheduler(43)@67.195.138.60:53734
I0314 04:28:38.688077 15528 sched.cpp:401] Received framework message
I0314 04:28:38.688607 15499 slave.cpp:389] Slave terminating
I0314 04:28:38.688612 15526 sched.cpp:422] Stopping framework '201303140428-1015726915-53734-15499-0000'
I0314 04:28:38.688647 15524 sched.cpp:422] Stopping framework '201303140428-1015726915-53734-15499-0000'
I0314 04:28:38.689035 15499 slave.cpp:889] Asked to shut down framework 201303140428-1015726915-53734-15499-0000 by @0.0.0.0:0
I0314 04:28:38.689618 15530 master.cpp:724] Asked to unregister framework 201303140428-1015726915-53734-15499-0000
W0314 04:28:38.691184 15530 master.cpp:731] scheduler(42)@67.195.138.60:53734 tried to unregister framework; expecting scheduler(43)@67.195.138.60:53734
I0314 04:28:38.690610 15499 slave.cpp:894] Shutting down framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.693922 15499 slave.cpp:1612] Shutting down executor 'default' of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.692955 15530 master.cpp:724] Asked to unregister framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.695543 15527 hierarchical_allocator_process.hpp:357] Deactivated framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.695054 15531 status_update_manager.cpp:232] Closing status update streams for framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.695585 15530 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
I0314 04:28:38.697087 15530 master.cpp:477] Master terminating
I0314 04:28:38.696569 15531 status_update_manager.cpp:433] Cleaning up status update stream for task 1 of framework 201303140428-1015726915-53734-15499-0000
I0314 04:28:38.695039 15525 exec.cpp:321] Executor asked to shutdown
pure virtual method called
terminate called without an active exception
I0314 04:28:38.697149 15526 hierarchical_allocator_process.hpp:542] Recovered cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201303140428-1015726915-53734-15499-0 from framework 201303140428-1015726915-53734-15499-0000
/bin/bash: line 5: 15499 Aborted ${dir}$tst
FAIL: mesos-tests
==================
1 of 1 test failed
==================
make[3]: *** [check-TESTS] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src'>
make: *** [check-recursive] Error 1
Process leaked file descriptors. See http://wiki.jenkins-ci.org/display/JENKINS/Spawning+processes+from+build for more information
Build step 'Execute shell' marked build as failure