See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/282/changes>
Changes: [benh] Fixed deadlock when cleaning up a process. Review: https://reviews.apache.org/r/9916 [vinodkone] Fixed killtree to guard against session ids being reported as '0' by '/bin/ps' on OSX 10.8. Review: https://reviews.apache.org/r/9915 ------------------------------------------ [...truncated 5863 lines...] I0314 03:08:38.249241 30312 status_update_manager.cpp:313] Received status update acknowledgement for task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:38.249624 30312 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_RUNNING from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:38.392360 30312 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:38.942834 30309 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 03:08:38.958271 30309 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 15.49ms I0314 03:08:39.247882 30311 slave.cpp:389] Slave terminating I0314 03:08:39.257347 31474 process.cpp:878] Socket closed while receiving I0314 03:08:39.257417 31471 exec.cpp:321] Executor asked to shutdown I0314 03:08:39.257592 31469 exec.cpp:75] Scheduling shutdown of the executor Waited on process 31476, returned status 15 I0314 03:08:39.257930 31466 exec.cpp:382] Executor sending status update for task e9a0ea71-72ed-49e9-92df-b23c72c94684 in state TASK_FAILED I0314 03:08:39.257577 30315 slave.cpp:202] Slave started on 20)@67.195.138.60:53758 I0314 03:08:39.257674 30314 master.cpp:558] Still acting as master! I0314 03:08:39.295455 30315 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0314 03:08:39.303661 30315 state.cpp:33] Recovering state from /tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_iu0iYc/meta I0314 03:08:39.333508 30313 status_update_manager.cpp:153] Recovering status update manager I0314 03:08:39.333576 30313 status_update_manager.cpp:157] Recovering executor 'e9a0ea71-72ed-49e9-92df-b23c72c94684' of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:39.333956 30313 status_update_manager.cpp:402] Creating StatusUpdate stream for task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:39.334508 30313 status_update_manager.hpp:233] Replaying status update stream for task e9a0ea71-72ed-49e9-92df-b23c72c94684 I0314 03:08:39.335068 30313 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:39.334108 30315 slave.cpp:468] New master detected at [email protected]:53758 I0314 03:08:39.335608 30313 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:39.337437 30310 process_based_isolation_module.cpp:300] Recovering isolation module I0314 03:08:39.337470 30313 status_update_manager.cpp:131] New master detected at [email protected]:53758 I0314 03:08:39.339122 30310 process_based_isolation_module.cpp:308] Recovering executor 'e9a0ea71-72ed-49e9-92df-b23c72c94684' of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:39.340770 30315 slave.cpp:1761] Recovering executors I0314 03:08:39.340891 30315 slave.cpp:1765] Recovering executor 'e9a0ea71-72ed-49e9-92df-b23c72c94684' of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:39.341636 30315 slave.cpp:1847] Sending reconnect request to executor e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 at executor(1)@67.195.138.60:59487 I0314 03:08:39.342741 31472 exec.cpp:216] Ignoring reconnect message from slave 201303140308-1015726915-53758-29966-0 because the driver is aborted! I0314 03:08:39.342792 31474 process.cpp:878] Socket closed while receiving I0314 03:08:39.342680 30315 slave.cpp:451] Successfully attached file '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_iu0iYc/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/e9a0ea71-72ed-49e9-92df-b23c72c94684/runs/2e1c876e-7651-4bd0-bf90-f4d5986729bb' I0314 03:08:39.959401 30310 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 03:08:39.974426 30310 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 15.09ms I0314 03:08:40.259269 30317 process.cpp:878] Socket closed while receiving I0314 03:08:40.976572 30311 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 03:08:40.998919 30311 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 22.39ms I0314 03:08:41.259099 30310 process_based_isolation_module.cpp:416] Telling slave of lost executor e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.282227 30314 slave.cpp:1437] Executor 'e9a0ea71-72ed-49e9-92df-b23c72c94684' of framework 201303140308-1015726915-53758-29966-0000 has exited with status 0 I0314 03:08:41.284159 30314 slave.cpp:1191] Handling status update TASK_FAILED from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.284315 30314 slave.cpp:1238] Forwarding status update TASK_FAILED from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 to the status update manager I0314 03:08:41.291090 30314 status_update_manager.cpp:253] Received status update TASK_FAILED from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.291203 30314 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_FAILED from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.291265 30311 gc.cpp:97] Scheduling /tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_iu0iYc/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/e9a0ea71-72ed-49e9-92df-b23c72c94684/runs/2e1c876e-7651-4bd0-bf90-f4d5986729bb for removal I0314 03:08:41.343586 30311 slave.cpp:1160] Cleaning up un-reregistered executors I0314 03:08:41.345000 30311 slave.cpp:380] Finished recovery W0314 03:08:41.345641 30311 master.cpp:964] Slave at slave(20)@67.195.138.60:53758 (janus.apache.org) is being allowed to re-register with an already in use id (201303140308-1015726915-53758-29966-0) I0314 03:08:41.345896 30311 slave.cpp:547] Re-registered with master I0314 03:08:41.383406 30314 status_update_manager.hpp:314] Handling UPDATE for status update TASK_FAILED from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.383811 30314 status_update_manager.cpp:288] Forwarding status update TASK_FAILED from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 to the master at [email protected]:53758 I0314 03:08:41.384874 30316 master.cpp:1016] Status update from (116)@67.195.138.60:53758: task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 is now in state TASK_FAILED I0314 03:08:41.385746 30316 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140308-1015726915-53758-29966-0 I0314 03:08:41.385817 30314 sched.cpp:327] Status update: task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 is now in state TASK_FAILED I0314 03:08:41.386294 30309 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 201303140308-1015726915-53758-29966-0 from framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.386471 30314 slave.cpp:967] Got acknowledgement of status update for task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.386783 30316 sched.cpp:422] Stopping framework '201303140308-1015726915-53758-29966-0000' I0314 03:08:41.387852 30312 master.cpp:724] Asked to unregister framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.387461 30314 status_update_manager.cpp:313] Received status update acknowledgement for task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.388530 30309 slave.cpp:439] Slave asked to shut down by @0.0.0.0:0 I0314 03:08:41.388572 30315 hierarchical_allocator_process.hpp:357] Deactivated framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.389801 30314 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_FAILED from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.390447 30309 slave.cpp:389] Slave terminating I0314 03:08:41.391196 30315 hierarchical_allocator_process.hpp:310] Removed framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.441908 30314 status_update_manager.hpp:314] Handling ACK for status update TASK_FAILED from task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.442018 30314 status_update_manager.cpp:433] Cleaning up status update stream for task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.442386 30314 status_update_manager.hpp:257] Deleting the meta directory for task e9a0ea71-72ed-49e9-92df-b23c72c94684 of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.282218 30310 process_utils.hpp:64] Stopping ... 31445 Sent signal to 31445 I0314 03:08:41.444497 30312 master.cpp:477] Master terminating I0314 03:08:41.444694 29966 master.cpp:283] Shutting down master I0314 03:08:41.445487 30311 hierarchical_allocator_process.hpp:421] Removed slave 201303140308-1015726915-53758-29966-0 [ OK ] SlaveRecoveryTest/0.RecoverTerminatedExecutor (3545 ms) [ RUN ] SlaveRecoveryTest/0.CleanupExecutor I0314 03:08:41.447518 30313 master.cpp:309] Master started on 67.195.138.60:53758 I0314 03:08:41.447602 30313 master.cpp:324] Master ID: 201303140308-1015726915-53758-29966 I0314 03:08:41.448062 30315 slave.cpp:202] Slave started on 21)@67.195.138.60:53758 I0314 03:08:41.448413 30315 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0314 03:08:41.449403 30315 slave.cpp:468] New master detected at [email protected]:53758 W0314 03:08:41.448248 30311 master.cpp:79] No whitelist given. Advertising offers for all slaves I0314 03:08:41.448573 30314 sched.cpp:182] New master at [email protected]:53758 I0314 03:08:41.448596 30313 master.cpp:553] Elected as master! I0314 03:08:41.451009 30313 master.cpp:596] Registering framework 201303140308-1015726915-53758-29966-0000 at scheduler(17)@67.195.138.60:53758 I0314 03:08:41.449486 30315 status_update_manager.cpp:131] New master detected at [email protected]:53758 I0314 03:08:41.448225 30312 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : [email protected]:53758 I0314 03:08:41.453174 30312 hierarchical_allocator_process.hpp:266] Added framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.452282 30313 sched.cpp:217] Framework registered with 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.449414 30316 process_based_isolation_module.cpp:300] Recovering isolation module I0314 03:08:41.453626 30312 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 03:08:41.455250 30312 hierarchical_allocator_process.hpp:597] Performed allocation for 0 slaves in 1.62ms I0314 03:08:41.454799 30314 slave.cpp:380] Finished recovery I0314 03:08:41.456426 30314 master.cpp:918] Attempting to register slave on janus.apache.org at slave(21)@67.195.138.60:53758 I0314 03:08:41.456670 30314 master.cpp:1153] Master now considering a slave at janus.apache.org:53758 as active I0314 03:08:41.457140 30314 master.cpp:1729] Adding slave 201303140308-1015726915-53758-29966-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0314 03:08:41.457665 30311 slave.cpp:502] Registered with master; given slave ID 201303140308-1015726915-53758-29966-0 I0314 03:08:41.458200 30311 paths.hpp:335] Created slave directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/meta/slaves/201303140308-1015726915-53758-29966-0' Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/meta/slaves/201303140308-1015726915-53758-29966-0/slave.info' I0314 03:08:41.457754 30316 hierarchical_allocator_process.hpp:393] Added slave 201303140308-1015726915-53758-29966-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 03:08:41.459121 30316 hierarchical_allocator_process.hpp:658] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140308-1015726915-53758-29966-0 I0314 03:08:41.460468 30316 hierarchical_allocator_process.hpp:684] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140308-1015726915-53758-29966-0 to framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.461010 30316 hierarchical_allocator_process.hpp:617] Performed allocation for slave 201303140308-1015726915-53758-29966-0 in 1.90ms I0314 03:08:41.461066 30312 master.hpp:305] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140308-1015726915-53758-29966-0 I0314 03:08:41.495239 30312 master.cpp:1256] Sending 1 offers to framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.495817 30311 sched.cpp:282] Received 1 offers I0314 03:08:41.497558 30314 master.cpp:1463] Processing reply for offer 201303140308-1015726915-53758-29966-0 on slave 201303140308-1015726915-53758-29966-0 (janus.apache.org) for framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.497663 30314 master.hpp:285] Adding task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140308-1015726915-53758-29966-0 I0314 03:08:41.497987 30314 master.cpp:1580] Launching task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140308-1015726915-53758-29966-0 (janus.apache.org) I0314 03:08:41.498608 30309 slave.cpp:614] Got assigned task ccc0b02c-305a-4714-815d-2122e8eb0b7e for framework 201303140308-1015726915-53758-29966-0000 Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/meta/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/framework.info' Checkpointing 'scheduler(17)@67.195.138.60:53758' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/meta/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/framework.pid I0314 03:08:41.498618 30314 master.hpp:314] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140308-1015726915-53758-29966-0 I0314 03:08:41.500859 30309 paths.hpp:302] Created executor directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/ccc0b02c-305a-4714-815d-2122e8eb0b7e/runs/edaf0e49-784e-4005-a1ac-b9bf323e76a8' Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/meta/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/ccc0b02c-305a-4714-815d-2122e8eb0b7e/executor.info' I0314 03:08:41.501284 30309 paths.hpp:302] Created executor directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/meta/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/ccc0b02c-305a-4714-815d-2122e8eb0b7e/runs/edaf0e49-784e-4005-a1ac-b9bf323e76a8' Checkpointing Task to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/meta/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/ccc0b02c-305a-4714-815d-2122e8eb0b7e/runs/edaf0e49-784e-4005-a1ac-b9bf323e76a8/tasks/ccc0b02c-305a-4714-815d-2122e8eb0b7e/task.info' I0314 03:08:41.501582 30312 process_based_isolation_module.cpp:123] Launching ccc0b02c-305a-4714-815d-2122e8eb0b7e (<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src/mesos-executor)> in /tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/ccc0b02c-305a-4714-815d-2122e8eb0b7e/runs/edaf0e49-784e-4005-a1ac-b9bf323e76a8 with resources ' for framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.501590 30309 slave.cpp:451] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/ccc0b02c-305a-4714-815d-2122e8eb0b7e/runs/edaf0e49-784e-4005-a1ac-b9bf323e76a8' Checkpointing forked pid 31737 Checkpointing '31737' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/meta/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/ccc0b02c-305a-4714-815d-2122e8eb0b7e/runs/edaf0e49-784e-4005-a1ac-b9bf323e76a8/pids/forked.pid I0314 03:08:41.502466 30312 process_based_isolation_module.cpp:162] Forked executor at 31737 Fetching resources into /tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/ccc0b02c-305a-4714-815d-2122e8eb0b7e/runs/edaf0e49-784e-4005-a1ac-b9bf323e76a8 WARNING: Logging before InitGoogleLogging() is written to STDERR I0314 03:08:41.535228 31743 process.cpp:1419] libprocess is initialized on 67.195.138.60:35099 for 8 cpus I0314 03:08:41.536911 31761 exec.cpp:170] Executor started at: executor(1)@67.195.138.60:35099 with pid 31743 I0314 03:08:41.537703 30309 slave.cpp:1008] Got registration for executor 'ccc0b02c-305a-4714-815d-2122e8eb0b7e' of framework 201303140308-1015726915-53758-29966-0000 Checkpointing 'executor(1)@67.195.138.60:35099' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/meta/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/ccc0b02c-305a-4714-815d-2122e8eb0b7e/runs/edaf0e49-784e-4005-a1ac-b9bf323e76a8/pids/libprocess.pid I0314 03:08:41.538689 31765 process.cpp:878] Socket closed while receiving I0314 03:08:41.538694 31757 exec.cpp:194] Executor registered on slave 201303140308-1015726915-53758-29966-0 Registered executor on janus.apache.org I0314 03:08:41.538286 30309 slave.cpp:1083] Flushing queued tasks for framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.556706 31765 process.cpp:878] Socket closed while receiving I0314 03:08:41.556788 31762 exec.cpp:258] Executor asked to run task 'ccc0b02c-305a-4714-815d-2122e8eb0b7e' Starting task ccc0b02c-305a-4714-815d-2122e8eb0b7e sh -c 'sleep 1000' I0314 03:08:41.557314 31762 exec.cpp:382] Executor sending status update for task ccc0b02c-305a-4714-815d-2122e8eb0b7e in state TASK_RUNNING I0314 03:08:41.558758 30312 slave.cpp:1191] Handling status update TASK_RUNNING from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.558843 30312 slave.cpp:1238] Forwarding status update TASK_RUNNING from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 to the status update manager I0314 03:08:41.559547 30315 status_update_manager.cpp:253] Received status update TASK_RUNNING from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.559753 30315 status_update_manager.cpp:402] Creating StatusUpdate stream for task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.560386 30315 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_RUNNING from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.660384 30315 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.660537 30315 status_update_manager.cpp:288] Forwarding status update TASK_RUNNING from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 to the master at [email protected]:53758 I0314 03:08:41.661111 30315 master.cpp:1016] Status update from (119)@67.195.138.60:53758: task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 is now in state TASK_RUNNING I0314 03:08:41.661165 30316 slave.cpp:1300] Sending ACK for status update TASK_RUNNING from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 to executor executor(1)@67.195.138.60:35099 I0314 03:08:41.662380 31759 exec.cpp:289] Executor received ACK for status update of task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.662505 31765 process.cpp:878] Socket closed while receiving I0314 03:08:41.661448 30315 sched.cpp:327] Status update: task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 is now in state TASK_RUNNING I0314 03:08:41.663516 30313 slave.cpp:967] Got acknowledgement of status update for task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.663898 30310 status_update_manager.cpp:313] Received status update acknowledgement for task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.664221 30310 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_RUNNING from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:41.793869 30310 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:42.454028 30312 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 03:08:42.454097 30312 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 116.99us I0314 03:08:42.663465 30313 slave.cpp:389] Slave terminating I0314 03:08:42.664940 30313 slave.cpp:202] Slave started on 22)@67.195.138.60:53758 I0314 03:08:42.664979 30313 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0314 03:08:42.665051 30312 master.cpp:558] Still acting as master! I0314 03:08:42.665860 30313 state.cpp:33] Recovering state from /tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/meta I0314 03:08:42.667713 30315 status_update_manager.cpp:153] Recovering status update manager I0314 03:08:42.667762 30315 status_update_manager.cpp:157] Recovering executor 'ccc0b02c-305a-4714-815d-2122e8eb0b7e' of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:42.668175 30313 slave.cpp:468] New master detected at [email protected]:53758 I0314 03:08:42.668190 30315 status_update_manager.cpp:402] Creating StatusUpdate stream for task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:42.669159 30315 status_update_manager.hpp:233] Replaying status update stream for task ccc0b02c-305a-4714-815d-2122e8eb0b7e I0314 03:08:42.669579 30315 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:42.668618 30313 slave.cpp:483] Skipping registration because slave is started in 'cleanup' mode I0314 03:08:42.670500 30315 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:42.671602 30314 process_based_isolation_module.cpp:300] Recovering isolation module I0314 03:08:42.671946 30314 process_based_isolation_module.cpp:308] Recovering executor 'ccc0b02c-305a-4714-815d-2122e8eb0b7e' of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:42.671623 30315 status_update_manager.cpp:131] New master detected at [email protected]:53758 I0314 03:08:42.672955 30309 slave.cpp:1761] Recovering executors I0314 03:08:42.674394 30309 slave.cpp:1765] Recovering executor 'ccc0b02c-305a-4714-815d-2122e8eb0b7e' of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:42.675016 30309 slave.cpp:1856] Sending shutdown to executor ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 at executor(1)@67.195.138.60:35099 I0314 03:08:42.675338 30309 slave.cpp:1612] Shutting down executor 'ccc0b02c-305a-4714-815d-2122e8eb0b7e' of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:42.676249 31765 process.cpp:878] Socket closed while receiving I0314 03:08:42.676271 31764 exec.cpp:321] Executor asked to shutdown I0314 03:08:42.676491 31760 exec.cpp:75] Scheduling shutdown of the executor Waited on process 31767, returned status 15 I0314 03:08:42.676532 30309 slave.cpp:451] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/ccc0b02c-305a-4714-815d-2122e8eb0b7e/runs/edaf0e49-784e-4005-a1ac-b9bf323e76a8' I0314 03:08:42.676759 31761 exec.cpp:382] Executor sending status update for task ccc0b02c-305a-4714-815d-2122e8eb0b7e in state TASK_FAILED I0314 03:08:42.676699 30309 slave.cpp:380] Finished recovery I0314 03:08:43.520195 30315 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 03:08:43.520618 30315 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 557.13us I0314 03:08:43.680387 30317 process.cpp:878] Socket closed while receiving I0314 03:08:44.522330 30314 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 03:08:44.522403 30314 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 157.63us I0314 03:08:44.666672 30313 process_based_isolation_module.cpp:416] Telling slave of lost executor ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:44.667598 30310 slave.cpp:1437] Executor 'ccc0b02c-305a-4714-815d-2122e8eb0b7e' of framework 201303140308-1015726915-53758-29966-0000 has exited with status 0 I0314 03:08:44.668920 30310 slave.cpp:1191] Handling status update TASK_FAILED from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:44.669052 30310 slave.cpp:1238] Forwarding status update TASK_FAILED from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 to the status update manager I0314 03:08:44.669527 30315 status_update_manager.cpp:253] Received status update TASK_FAILED from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:44.669810 30315 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_FAILED from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:44.669688 30311 gc.cpp:97] Scheduling /tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/slaves/201303140308-1015726915-53758-29966-0/frameworks/201303140308-1015726915-53758-29966-0000/executors/ccc0b02c-305a-4714-815d-2122e8eb0b7e/runs/edaf0e49-784e-4005-a1ac-b9bf323e76a8 for removal I0314 03:08:44.669612 30310 slave.cpp:1561] Slave is shutting down because it is started with --recover==cleanup and all executors have terminated! I0314 03:08:44.671216 30310 slave.cpp:1568] Archiving and deleting the meta directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_5GHbK3/meta' to allow incompatible upgrade! I0314 03:08:44.666918 30313 process_utils.hpp:64] Stopping ... 31737 Sent signal to 31737 tar: Removing leading `/' from member names I0314 03:08:44.776381 30315 status_update_manager.hpp:314] Handling UPDATE for status update TASK_FAILED from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:44.776485 30315 status_update_manager.cpp:288] Forwarding status update TASK_FAILED from task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 to the master at [email protected]:53758 I0314 03:08:44.818114 30310 slave.cpp:439] Slave asked to shut down by @0.0.0.0:0 I0314 03:08:44.822600 30309 master.cpp:1016] Status update from (123)@67.195.138.60:53758: task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 is now in state TASK_FAILED I0314 03:08:44.822806 30310 slave.cpp:389] Slave terminating I0314 03:08:44.823273 30309 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140308-1015726915-53758-29966-0 I0314 03:08:44.823308 30313 sched.cpp:327] Status update: task ccc0b02c-305a-4714-815d-2122e8eb0b7e of framework 201303140308-1015726915-53758-29966-0000 is now in state TASK_FAILED I0314 03:08:44.824872 30310 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 201303140308-1015726915-53758-29966-0 from framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:44.825326 30313 sched.cpp:422] Stopping framework '201303140308-1015726915-53758-29966-0000' I0314 03:08:44.826272 30309 master.cpp:724] Asked to unregister framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:44.826810 30315 hierarchical_allocator_process.hpp:357] Deactivated framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:44.827190 29966 master.cpp:477] Master terminating I0314 03:08:44.827841 29966 master.cpp:283] Shutting down master I0314 03:08:44.827415 30315 hierarchical_allocator_process.hpp:310] Removed framework 201303140308-1015726915-53758-29966-0000 I0314 03:08:44.828915 30315 hierarchical_allocator_process.hpp:421] Removed slave 201303140308-1015726915-53758-29966-0 [ OK ] SlaveRecoveryTest/0.CleanupExecutor (3384 ms) [----------] 6 tests from SlaveRecoveryTest/0 (16859 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 03:08:44.831661 30311 master.cpp:309] Master started on 67.195.138.60:53758 I0314 03:08:44.831730 30311 master.cpp:324] Master ID: 201303140308-1015726915-53758-29966 I0314 03:08:44.832206 30316 slave.cpp:202] Slave started on 23)@67.195.138.60:53758 W0314 03:08:44.833508 30314 master.cpp:79] No whitelist given. Advertising offers for all slaves I0314 03:08:44.833528 30309 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : [email protected]:53758 I0314 03:08:44.833717 30311 master.cpp:553] Elected as master! I0314 03:08:44.833812 30316 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 @0x104af20. 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-Disable-Java-Disable-Python-Disable-Webui/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-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'> make[1]: *** [check] Error 2 make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/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
