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 [email protected]: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 [email protected]: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 [email protected]: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 : [email protected]:37302 I0314 02:34:04.596472 6361 sched.cpp:182] New master at [email protected]: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 [email protected]: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 [email protected]: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 [email protected]: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 [email protected]: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 [email protected]: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 [email protected]: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
