See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/279/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 6413 lines...] I0314 02:45:57.498234 4567 sched.cpp:327] Status update: task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 is now in state TASK_RUNNING I0314 02:45:57.499212 4567 slave.cpp:967] Got acknowledgement of status update for task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:45:57.499694 4568 status_update_manager.cpp:313] Received status update acknowledgement for task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:45:57.500115 4568 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_RUNNING from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:45:57.575804 4568 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:45:58.330994 4567 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 02:45:58.340879 4567 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 9.94ms I0314 02:45:58.499305 4568 slave.cpp:389] Slave terminating I0314 02:45:58.500519 4878 exec.cpp:321] Executor asked to shutdown I0314 02:45:58.500524 4879 process.cpp:878] Socket closed while receiving I0314 02:45:58.500623 4878 exec.cpp:75] Scheduling shutdown of the executor Waited on process 4880, returned status 15 I0314 02:45:58.500912 4878 exec.cpp:382] Executor sending status update for task 5f8d9be0-95aa-4a46-b588-258f86199e45 in state TASK_FAILED I0314 02:45:58.501000 4561 slave.cpp:202] Slave started on 20)@67.195.138.60:39366 I0314 02:45:58.501085 4561 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0314 02:45:58.501735 4561 state.cpp:33] Recovering state from /tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_Q9koA9/meta I0314 02:45:58.503298 4561 slave.cpp:468] New master detected at [email protected]:39366 I0314 02:45:58.503402 4561 status_update_manager.cpp:153] Recovering status update manager I0314 02:45:58.501215 4567 master.cpp:558] Still acting as master! I0314 02:45:58.503707 4561 status_update_manager.cpp:157] Recovering executor '5f8d9be0-95aa-4a46-b588-258f86199e45' of framework 201303140245-1015726915-39366-4488-0000 I0314 02:45:58.504730 4561 status_update_manager.cpp:402] Creating StatusUpdate stream for task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:45:58.505213 4561 status_update_manager.hpp:233] Replaying status update stream for task 5f8d9be0-95aa-4a46-b588-258f86199e45 I0314 02:45:58.505620 4561 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:45:58.506115 4561 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:45:58.506866 4566 process_based_isolation_module.cpp:300] Recovering isolation module I0314 02:45:58.507169 4566 process_based_isolation_module.cpp:308] Recovering executor '5f8d9be0-95aa-4a46-b588-258f86199e45' of framework 201303140245-1015726915-39366-4488-0000 I0314 02:45:58.506901 4561 status_update_manager.cpp:131] New master detected at [email protected]:39366 I0314 02:45:58.508074 4563 slave.cpp:1761] Recovering executors I0314 02:45:58.509245 4563 slave.cpp:1765] Recovering executor '5f8d9be0-95aa-4a46-b588-258f86199e45' of framework 201303140245-1015726915-39366-4488-0000 I0314 02:45:58.509898 4563 slave.cpp:1847] Sending reconnect request to executor 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 at executor(1)@67.195.138.60:44893 I0314 02:45:58.510865 4877 exec.cpp:216] Ignoring reconnect message from slave 201303140245-1015726915-39366-4488-0 because the driver is aborted! I0314 02:45:58.510871 4879 process.cpp:878] Socket closed while receiving I0314 02:45:58.510663 4563 slave.cpp:451] Successfully attached file '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_Q9koA9/slaves/201303140245-1015726915-39366-4488-0/frameworks/201303140245-1015726915-39366-4488-0000/executors/5f8d9be0-95aa-4a46-b588-258f86199e45/runs/a4f57319-c37f-4e94-af15-116b39245de6' I0314 02:45:59.342268 4566 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 02:45:59.350966 4566 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 8.73ms I0314 02:45:59.502408 4569 process.cpp:878] Socket closed while receiving I0314 02:46:00.352658 4565 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 02:46:00.362656 4565 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 10.03ms I0314 02:46:00.502003 4563 process_based_isolation_module.cpp:416] Telling slave of lost executor 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.504009 4564 slave.cpp:1437] Executor '5f8d9be0-95aa-4a46-b588-258f86199e45' of framework 201303140245-1015726915-39366-4488-0000 has exited with status 0 I0314 02:46:00.505722 4564 slave.cpp:1191] Handling status update TASK_FAILED from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.505862 4564 slave.cpp:1238] Forwarding status update TASK_FAILED from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 to the status update manager I0314 02:46:00.506315 4567 status_update_manager.cpp:253] Received status update TASK_FAILED from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.506600 4567 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_FAILED from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.506450 4561 gc.cpp:97] Scheduling /tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_Q9koA9/slaves/201303140245-1015726915-39366-4488-0/frameworks/201303140245-1015726915-39366-4488-0000/executors/5f8d9be0-95aa-4a46-b588-258f86199e45/runs/a4f57319-c37f-4e94-af15-116b39245de6 for removal I0314 02:46:00.511068 4561 slave.cpp:1160] Cleaning up un-reregistered executors I0314 02:46:00.511482 4561 slave.cpp:380] Finished recovery W0314 02:46:00.511503 4564 master.cpp:964] Slave at slave(20)@67.195.138.60:39366 (janus.apache.org) is being allowed to re-register with an already in use id (201303140245-1015726915-39366-4488-0) I0314 02:46:00.539059 4568 slave.cpp:547] Re-registered with master I0314 02:46:00.502075 4563 process_utils.hpp:64] Stopping ... 4852 Sent signal to 4852 I0314 02:46:00.591153 4567 status_update_manager.hpp:314] Handling UPDATE for status update TASK_FAILED from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.591215 4567 status_update_manager.cpp:288] Forwarding status update TASK_FAILED from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 to the master at [email protected]:39366 I0314 02:46:00.591696 4564 master.cpp:1016] Status update from (125)@67.195.138.60:39366: task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 is now in state TASK_FAILED I0314 02:46:00.592095 4562 sched.cpp:327] Status update: task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 is now in state TASK_FAILED I0314 02:46:00.592089 4564 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140245-1015726915-39366-4488-0 I0314 02:46:00.592571 4561 slave.cpp:967] Got acknowledgement of status update for task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.592636 4568 sched.cpp:422] Stopping framework '201303140245-1015726915-39366-4488-0000' I0314 02:46:00.593947 4561 master.cpp:724] Asked to unregister framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.593526 4564 status_update_manager.cpp:313] Received status update acknowledgement for task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.594832 4564 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_FAILED from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.594203 4488 slave.cpp:439] Slave asked to shut down by @0.0.0.0:0 I0314 02:46:00.593086 4562 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 201303140245-1015726915-39366-4488-0 from framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.596593 4488 slave.cpp:389] Slave terminating I0314 02:46:00.604475 4562 hierarchical_allocator_process.hpp:357] Deactivated framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.605415 4562 hierarchical_allocator_process.hpp:310] Removed framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.649821 4564 status_update_manager.hpp:314] Handling ACK for status update TASK_FAILED from task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.649873 4564 status_update_manager.cpp:433] Cleaning up status update stream for task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.650195 4564 status_update_manager.hpp:257] Deleting the meta directory for task 5f8d9be0-95aa-4a46-b588-258f86199e45 of framework 201303140245-1015726915-39366-4488-0000 I0314 02:46:00.651263 4488 master.cpp:477] Master terminating I0314 02:46:00.651321 4488 master.cpp:283] Shutting down master I0314 02:46:00.651847 4563 hierarchical_allocator_process.hpp:421] Removed slave 201303140245-1015726915-39366-4488-0 [ OK ] SlaveRecoveryTest/0.RecoverTerminatedExecutor (3325 ms) [ RUN ] SlaveRecoveryTest/0.CleanupExecutor I0314 02:46:00.653539 4567 master.cpp:309] Master started on 67.195.138.60:39366 I0314 02:46:00.653584 4567 master.cpp:324] Master ID: 201303140246-1015726915-39366-4488 I0314 02:46:00.654223 4567 master.cpp:553] Elected as master! I0314 02:46:00.654247 4563 slave.cpp:202] Slave started on 21)@67.195.138.60:39366 I0314 02:46:00.654863 4563 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0314 02:46:00.655719 4564 process_based_isolation_module.cpp:300] Recovering isolation module I0314 02:46:00.654361 4562 sched.cpp:182] New master at [email protected]:39366 I0314 02:46:00.656419 4562 master.cpp:596] Registering framework 201303140246-1015726915-39366-4488-0000 at scheduler(17)@67.195.138.60:39366 I0314 02:46:00.655727 4563 slave.cpp:468] New master detected at [email protected]:39366 I0314 02:46:00.657273 4563 slave.cpp:380] Finished recovery W0314 02:46:00.654273 4565 master.cpp:79] No whitelist given. Advertising offers for all slaves I0314 02:46:00.656854 4561 sched.cpp:217] Framework registered with 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.654275 4568 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : [email protected]:39366 I0314 02:46:00.657292 4566 status_update_manager.cpp:131] New master detected at [email protected]:39366 I0314 02:46:00.657932 4562 master.cpp:918] Attempting to register slave on janus.apache.org at slave(21)@67.195.138.60:39366 I0314 02:46:00.661353 4562 master.cpp:1153] Master now considering a slave at janus.apache.org:39366 as active I0314 02:46:00.661840 4562 master.cpp:1729] Adding slave 201303140246-1015726915-39366-4488-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0314 02:46:00.660423 4568 hierarchical_allocator_process.hpp:266] Added framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.663985 4568 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 02:46:00.664547 4568 hierarchical_allocator_process.hpp:597] Performed allocation for 0 slaves in 562.96us I0314 02:46:00.665052 4568 hierarchical_allocator_process.hpp:393] Added slave 201303140246-1015726915-39366-4488-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:46:00.665510 4568 hierarchical_allocator_process.hpp:658] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140246-1015726915-39366-4488-0 I0314 02:46:00.666077 4568 hierarchical_allocator_process.hpp:684] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140246-1015726915-39366-4488-0 to framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.662614 4563 slave.cpp:502] Registered with master; given slave ID 201303140246-1015726915-39366-4488-0 I0314 02:46:00.666651 4568 hierarchical_allocator_process.hpp:617] Performed allocation for slave 201303140246-1015726915-39366-4488-0 in 1.15ms I0314 02:46:00.666690 4565 master.hpp:305] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140246-1015726915-39366-4488-0 I0314 02:46:00.667119 4563 paths.hpp:335] Created slave directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/meta/slaves/201303140246-1015726915-39366-4488-0' Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/meta/slaves/201303140246-1015726915-39366-4488-0/slave.info' I0314 02:46:00.668264 4565 master.cpp:1256] Sending 1 offers to framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.669756 4561 sched.cpp:282] Received 1 offers I0314 02:46:00.671548 4568 master.cpp:1463] Processing reply for offer 201303140246-1015726915-39366-4488-0 on slave 201303140246-1015726915-39366-4488-0 (janus.apache.org) for framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.671658 4568 master.hpp:285] Adding task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140246-1015726915-39366-4488-0 I0314 02:46:00.671957 4568 master.cpp:1580] Launching task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140246-1015726915-39366-4488-0 (janus.apache.org) I0314 02:46:00.672505 4565 slave.cpp:614] Got assigned task 7fe53866-8861-4545-b1c6-0c282712daa2 for framework 201303140246-1015726915-39366-4488-0000 Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/meta/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/framework.info' Checkpointing 'scheduler(17)@67.195.138.60:39366' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/meta/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/framework.pid I0314 02:46:00.672567 4568 master.hpp:314] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140246-1015726915-39366-4488-0 I0314 02:46:00.674588 4565 paths.hpp:302] Created executor directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/executors/7fe53866-8861-4545-b1c6-0c282712daa2/runs/31d523af-0393-419e-923b-8e2e353a7c8e' Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/meta/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/executors/7fe53866-8861-4545-b1c6-0c282712daa2/executor.info' I0314 02:46:00.675156 4565 paths.hpp:302] Created executor directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/meta/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/executors/7fe53866-8861-4545-b1c6-0c282712daa2/runs/31d523af-0393-419e-923b-8e2e353a7c8e' Checkpointing Task to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/meta/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/executors/7fe53866-8861-4545-b1c6-0c282712daa2/runs/31d523af-0393-419e-923b-8e2e353a7c8e/tasks/7fe53866-8861-4545-b1c6-0c282712daa2/task.info' I0314 02:46:00.675575 4565 slave.cpp:451] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/executors/7fe53866-8861-4545-b1c6-0c282712daa2/runs/31d523af-0393-419e-923b-8e2e353a7c8e' I0314 02:46:00.675582 4567 process_based_isolation_module.cpp:123] Launching 7fe53866-8861-4545-b1c6-0c282712daa2 (<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src/mesos-executor)> in /tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/executors/7fe53866-8861-4545-b1c6-0c282712daa2/runs/31d523af-0393-419e-923b-8e2e353a7c8e with resources ' for framework 201303140246-1015726915-39366-4488-0000 Checkpointing forked pid 4976 I0314 02:46:00.678549 4567 process_based_isolation_module.cpp:162] Forked executor at 4976 Checkpointing '4976' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/meta/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/executors/7fe53866-8861-4545-b1c6-0c282712daa2/runs/31d523af-0393-419e-923b-8e2e353a7c8e/pids/forked.pid Fetching resources into /tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/executors/7fe53866-8861-4545-b1c6-0c282712daa2/runs/31d523af-0393-419e-923b-8e2e353a7c8e WARNING: Logging before InitGoogleLogging() is written to STDERR I0314 02:46:00.721055 4982 process.cpp:1419] libprocess is initialized on 67.195.138.60:50716 for 8 cpus I0314 02:46:00.722681 4999 exec.cpp:170] Executor started at: executor(1)@67.195.138.60:50716 with pid 4982 I0314 02:46:00.723597 4568 slave.cpp:1008] Got registration for executor '7fe53866-8861-4545-b1c6-0c282712daa2' of framework 201303140246-1015726915-39366-4488-0000 Checkpointing 'executor(1)@67.195.138.60:50716' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/meta/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/executors/7fe53866-8861-4545-b1c6-0c282712daa2/runs/31d523af-0393-419e-923b-8e2e353a7c8e/pids/libprocess.pid I0314 02:46:00.724153 4568 slave.cpp:1083] Flushing queued tasks for framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.724748 5000 exec.cpp:194] Executor registered on slave 201303140246-1015726915-39366-4488-0 I0314 02:46:00.724750 5004 process.cpp:878] Socket closed while receiving Registered executor on janus.apache.org I0314 02:46:00.724884 5000 exec.cpp:258] Executor asked to run task '7fe53866-8861-4545-b1c6-0c282712daa2' Starting task 7fe53866-8861-4545-b1c6-0c282712daa2 sh -c 'sleep 1000' I0314 02:46:00.725443 5000 exec.cpp:382] Executor sending status update for task 7fe53866-8861-4545-b1c6-0c282712daa2 in state TASK_RUNNING I0314 02:46:00.726755 4565 slave.cpp:1191] Handling status update TASK_RUNNING from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.726797 4565 slave.cpp:1238] Forwarding status update TASK_RUNNING from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 to the status update manager I0314 02:46:00.727383 4566 status_update_manager.cpp:253] Received status update TASK_RUNNING from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.727632 4566 status_update_manager.cpp:402] Creating StatusUpdate stream for task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.728214 4566 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_RUNNING from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.805615 4566 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.805673 4566 status_update_manager.cpp:288] Forwarding status update TASK_RUNNING from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 to the master at [email protected]:39366 I0314 02:46:00.806181 4567 master.cpp:1016] Status update from (128)@67.195.138.60:39366: task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 is now in state TASK_RUNNING I0314 02:46:00.806238 4564 slave.cpp:1300] Sending ACK for status update TASK_RUNNING from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 to executor executor(1)@67.195.138.60:50716 I0314 02:46:00.807345 5004 process.cpp:878] Socket closed while receiving I0314 02:46:00.807379 5001 exec.cpp:289] Executor received ACK for status update of task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.806650 4561 sched.cpp:327] Status update: task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 is now in state TASK_RUNNING I0314 02:46:00.807620 4567 slave.cpp:967] Got acknowledgement of status update for task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.808023 4567 status_update_manager.cpp:313] Received status update acknowledgement for task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.808406 4567 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_RUNNING from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:00.858681 4567 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:01.660975 4561 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 02:46:01.661022 4561 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 86.22us I0314 02:46:01.807701 4562 slave.cpp:389] Slave terminating I0314 02:46:01.808862 4563 slave.cpp:202] Slave started on 22)@67.195.138.60:39366 I0314 02:46:01.808905 4567 master.cpp:558] Still acting as master! I0314 02:46:01.808907 4563 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0314 02:46:01.810134 4563 state.cpp:33] Recovering state from /tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/meta I0314 02:46:01.811548 4566 status_update_manager.cpp:153] Recovering status update manager I0314 02:46:01.811593 4566 status_update_manager.cpp:157] Recovering executor '7fe53866-8861-4545-b1c6-0c282712daa2' of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:01.812000 4563 slave.cpp:468] New master detected at [email protected]:39366 I0314 02:46:01.812430 4563 slave.cpp:483] Skipping registration because slave is started in 'cleanup' mode I0314 02:46:01.812039 4566 status_update_manager.cpp:402] Creating StatusUpdate stream for task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:01.813465 4566 status_update_manager.hpp:233] Replaying status update stream for task 7fe53866-8861-4545-b1c6-0c282712daa2 I0314 02:46:01.813864 4566 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:01.814368 4566 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:01.815057 4562 process_based_isolation_module.cpp:300] Recovering isolation module I0314 02:46:01.815421 4562 process_based_isolation_module.cpp:308] Recovering executor '7fe53866-8861-4545-b1c6-0c282712daa2' of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:01.815074 4566 status_update_manager.cpp:131] New master detected at [email protected]:39366 I0314 02:46:01.816236 4563 slave.cpp:1761] Recovering executors I0314 02:46:01.816865 4563 slave.cpp:1765] Recovering executor '7fe53866-8861-4545-b1c6-0c282712daa2' of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:01.818295 4563 slave.cpp:1856] Sending shutdown to executor 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 at executor(1)@67.195.138.60:50716 I0314 02:46:01.818533 4563 slave.cpp:1612] Shutting down executor '7fe53866-8861-4545-b1c6-0c282712daa2' of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:01.819368 5004 process.cpp:878] Socket closed while receiving I0314 02:46:01.819375 5002 exec.cpp:321] Executor asked to shutdown I0314 02:46:01.819510 5002 exec.cpp:75] Scheduling shutdown of the executor Waited on process 5005, returned status 15 I0314 02:46:01.819370 4563 slave.cpp:451] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/executors/7fe53866-8861-4545-b1c6-0c282712daa2/runs/31d523af-0393-419e-923b-8e2e353a7c8e' I0314 02:46:01.819733 5002 exec.cpp:382] Executor sending status update for task 7fe53866-8861-4545-b1c6-0c282712daa2 in state TASK_FAILED I0314 02:46:01.819675 4563 slave.cpp:380] Finished recovery I0314 02:46:02.661860 4565 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 02:46:02.672004 4565 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 10.17ms I0314 02:46:02.821360 4569 process.cpp:878] Socket closed while receiving I0314 02:46:03.672756 4562 hierarchical_allocator_process.hpp:666] No resources available to allocate! I0314 02:46:03.682122 4562 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 9.42ms I0314 02:46:03.810220 4561 process_based_isolation_module.cpp:416] Telling slave of lost executor 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:03.810335 4564 slave.cpp:1437] Executor '7fe53866-8861-4545-b1c6-0c282712daa2' of framework 201303140246-1015726915-39366-4488-0000 has exited with status 0 I0314 02:46:03.813653 4564 slave.cpp:1191] Handling status update TASK_FAILED from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:03.813832 4564 slave.cpp:1238] Forwarding status update TASK_FAILED from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 to the status update manager I0314 02:46:03.814189 4562 status_update_manager.cpp:253] Received status update TASK_FAILED from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:03.814537 4562 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_FAILED from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:03.814298 4565 gc.cpp:97] Scheduling /tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/slaves/201303140246-1015726915-39366-4488-0/frameworks/201303140246-1015726915-39366-4488-0000/executors/7fe53866-8861-4545-b1c6-0c282712daa2/runs/31d523af-0393-419e-923b-8e2e353a7c8e for removal I0314 02:46:03.814290 4564 slave.cpp:1561] Slave is shutting down because it is started with --recover==cleanup and all executors have terminated! I0314 02:46:03.818577 4564 slave.cpp:1568] Archiving and deleting the meta directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_v2SAL6/meta' to allow incompatible upgrade! tar: Removing leading `/' from member names I0314 02:46:03.828924 4564 slave.cpp:439] Slave asked to shut down by @0.0.0.0:0 I0314 02:46:03.829038 4564 slave.cpp:389] Slave terminating I0314 02:46:03.810303 4561 process_utils.hpp:64] Stopping ... 4976 Sent signal to 4976 I0314 02:46:03.916359 4562 status_update_manager.hpp:314] Handling UPDATE for status update TASK_FAILED from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:03.916442 4562 status_update_manager.cpp:288] Forwarding status update TASK_FAILED from task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 to the master at [email protected]:39366 I0314 02:46:03.916965 4568 master.cpp:1016] Status update from (132)@67.195.138.60:39366: task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 is now in state TASK_FAILED I0314 02:46:03.917315 4568 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140246-1015726915-39366-4488-0 I0314 02:46:03.917423 4565 sched.cpp:327] Status update: task 7fe53866-8861-4545-b1c6-0c282712daa2 of framework 201303140246-1015726915-39366-4488-0000 is now in state TASK_FAILED I0314 02:46:03.917881 4563 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 201303140246-1015726915-39366-4488-0 from framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:03.918251 4568 sched.cpp:422] Stopping framework '201303140246-1015726915-39366-4488-0000' I0314 02:46:03.919189 4568 master.cpp:724] Asked to unregister framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:03.919639 4563 hierarchical_allocator_process.hpp:357] Deactivated framework 201303140246-1015726915-39366-4488-0000 I0314 02:46:03.920106 4488 master.cpp:477] Master terminating I0314 02:46:03.920542 4488 master.cpp:283] Shutting down master I0314 02:46:03.920140 4563 hierarchical_allocator_process.hpp:310] Removed framework 201303140246-1015726915-39366-4488-0000 [ OK ] SlaveRecoveryTest/0.CleanupExecutor (3268 ms) [----------] 6 tests from SlaveRecoveryTest/0 (11946 ms total) [----------] 6 tests from SlaveRecoveryTest/1, where TypeParam = mesos::internal::slave::CgroupsIsolationModule [ RUN ] SlaveRecoveryTest/1.RecoverSlaveState ./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:46:03.923635 4488 slave.cpp:202] Slave started on 23)@67.195.138.60:39366 I0314 02:46:03.923791 4561 master.cpp:309] Master started on 67.195.138.60:39366 I0314 02:46:03.924006 4561 master.cpp:324] Master ID: 201303140246-1015726915-39366-4488 W0314 02:46:03.924605 4562 master.cpp:79] No whitelist given. Advertising offers for all slaves I0314 02:46:03.924687 4567 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : [email protected]:39366 I0314 02:46:03.924790 4561 master.cpp:553] Elected as master! I0314 02:46:03.923835 4488 slave.cpp:203] Slave resources: cpus=8; mem=15025; ports=[31000-32000]; disk=14028 Using cgroups requires root permissions ./tests/filter.hpp:67: ERROR: this mock object (used in test SlaveRecoveryTest/1.RecoverSlaveState) should be deleted but never is. Its address is @0x2a4f1a0. 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-In-Src-Set-JAVA_HOME/ws/src'> make[2]: *** [check-am] Error 2 make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'> make[1]: *** [check] Error 2 make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/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
