You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/03/15 01:49:08 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #281
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/281/changes>
Changes:
[vinodkone] Added checkpoint field to slave info and fixed master to remove
slaves that have disabled checkpointing.
Review: https://reviews.apache.org/r/9927
[benh] Explicitly disabled tests with the CgroupsIsolationModule type
parameter.
Review: https://reviews.apache.org/r/9920
[benh] Added a TERMINATING process state to avoid filtering or enqueing
events after process cleanup has begun.
https://reviews.apache.org/r/9922
[vinodkone] Fixed the master to send updated framework pids and relink to the
reregistered slave.
Review: https://reviews.apache.org/r/9918
------------------------------------------
[...truncated 6456 lines...]
I0315 00:48:49.311483 5074 exec.cpp:289] Executor received ACK for status update of task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:49.311610 456 slave.cpp:964] Got acknowledgement of status update for task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:49.312111 460 status_update_manager.cpp:313] Received status update acknowledgement for task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:49.312571 460 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_RUNNING from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:49.380835 460 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:50.176609 456 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 00:48:50.176717 456 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 161.36us
I0315 00:48:50.311704 453 slave.cpp:390] Slave terminating
I0315 00:48:50.311990 454 master.cpp:521] Slave 201303150048-1015726915-45252-32038-0(janus.apache.org) disconnected
I0315 00:48:50.312906 5076 process.cpp:878] Socket closed while receiving
I0315 00:48:50.312958 5069 exec.cpp:321] Executor asked to shutdown
I0315 00:48:50.313186 5075 exec.cpp:75] Scheduling shutdown of the executor
Waited on process 5077, returned status 15
I0315 00:48:50.313402 5069 exec.cpp:382] Executor sending status update for task fbdc2883-9316-4276-958d-e7a2bd7f9e85 in state TASK_FAILED
I0315 00:48:50.313565 452 slave.cpp:202] Slave started on 20)@67.195.138.60:45252
I0315 00:48:50.313587 454 master.cpp:576] Still acting as master!
I0315 00:48:50.313665 452 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0315 00:48:50.315029 452 state.cpp:33] Recovering state from /tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_CErUh7/meta
I0315 00:48:50.316453 460 status_update_manager.cpp:153] Recovering status update manager
I0315 00:48:50.316488 460 status_update_manager.cpp:157] Recovering executor 'fbdc2883-9316-4276-958d-e7a2bd7f9e85' of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:50.316895 460 status_update_manager.cpp:402] Creating StatusUpdate stream for task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:50.317390 460 status_update_manager.hpp:233] Replaying status update stream for task fbdc2883-9316-4276-958d-e7a2bd7f9e85
I0315 00:48:50.316946 452 slave.cpp:457] New master detected at master@67.195.138.60:45252
I0315 00:48:50.317808 460 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:50.318747 460 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:50.319491 457 process_based_isolation_module.cpp:300] Recovering isolation module
I0315 00:48:50.319764 457 process_based_isolation_module.cpp:308] Recovering executor 'fbdc2883-9316-4276-958d-e7a2bd7f9e85' of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:50.319519 460 status_update_manager.cpp:131] New master detected at master@67.195.138.60:45252
I0315 00:48:50.320785 452 slave.cpp:1758] Recovering executors
I0315 00:48:50.321693 452 slave.cpp:1762] Recovering executor 'fbdc2883-9316-4276-958d-e7a2bd7f9e85' of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:50.322356 452 slave.cpp:1844] Sending reconnect request to executor fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000 at executor(1)@67.195.138.60:56519
I0315 00:48:50.322934 5076 process.cpp:878] Socket closed while receiving
I0315 00:48:50.322957 5071 exec.cpp:216] Ignoring reconnect message from slave 201303150048-1015726915-45252-32038-0 because the driver is aborted!
I0315 00:48:50.322906 452 slave.cpp:440] Successfully attached file '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_CErUh7/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/fbdc2883-9316-4276-958d-e7a2bd7f9e85/runs/e4be67ea-ddeb-43b5-96a9-24f513f722e9'
I0315 00:48:51.177485 457 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 00:48:51.187366 457 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 9.93ms
I0315 00:48:51.314903 461 process.cpp:878] Socket closed while receiving
I0315 00:48:52.189139 459 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 00:48:52.200856 459 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 11.78ms
I0315 00:48:52.314321 454 process_based_isolation_module.cpp:416] Telling slave of lost executor fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.314510 459 slave.cpp:1434] Executor 'fbdc2883-9316-4276-958d-e7a2bd7f9e85' of framework 201303150048-1015726915-45252-32038-0000 has exited with status 0
I0315 00:48:52.317998 459 slave.cpp:1188] Handling status update TASK_FAILED from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.318146 459 slave.cpp:1235] Forwarding status update TASK_FAILED from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000 to the status update manager
I0315 00:48:52.318547 456 status_update_manager.cpp:253] Received status update TASK_FAILED from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.318701 455 gc.cpp:97] Scheduling /tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_CErUh7/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/fbdc2883-9316-4276-958d-e7a2bd7f9e85/runs/e4be67ea-ddeb-43b5-96a9-24f513f722e9 for removal
I0315 00:48:52.318886 456 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_FAILED from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.323462 457 slave.cpp:1157] Cleaning up un-reregistered executors
I0315 00:48:52.323918 457 slave.cpp:381] Finished recovery
W0315 00:48:52.323966 460 master.cpp:983] Slave at slave(20)@67.195.138.60:45252 (janus.apache.org) is being allowed to re-register with an already in use id (201303150048-1015726915-45252-32038-0)
I0315 00:48:52.333757 455 slave.cpp:536] Re-registered with master
I0315 00:48:52.314499 454 process_utils.hpp:64] Stopping ... 5049
Sent signal to 5049
I0315 00:48:52.413275 456 status_update_manager.hpp:314] Handling UPDATE for status update TASK_FAILED from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.413355 456 status_update_manager.cpp:288] Forwarding status update TASK_FAILED from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000 to the master at master@67.195.138.60:45252
I0315 00:48:52.413913 452 master.cpp:1054] Status update from (125)@67.195.138.60:45252: task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000 is now in state TASK_FAILED
I0315 00:48:52.414253 452 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150048-1015726915-45252-32038-0
I0315 00:48:52.414350 456 sched.cpp:327] Status update: task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000 is now in state TASK_FAILED
I0315 00:48:52.414860 453 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 201303150048-1015726915-45252-32038-0 from framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.415699 454 slave.cpp:964] Got acknowledgement of status update for task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.415745 456 sched.cpp:422] Stopping framework '201303150048-1015726915-45252-32038-0000'
I0315 00:48:52.417050 456 master.cpp:742] Asked to unregister framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.417507 455 hierarchical_allocator_process.hpp:357] Deactivated framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.417973 455 hierarchical_allocator_process.hpp:310] Removed framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.416635 454 status_update_manager.cpp:313] Received status update acknowledgement for task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.418869 454 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_FAILED from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.417167 452 slave.cpp:428] Slave asked to shut down by @0.0.0.0:0
I0315 00:48:52.420285 452 slave.cpp:390] Slave terminating
I0315 00:48:52.420402 456 master.cpp:521] Slave 201303150048-1015726915-45252-32038-0(janus.apache.org) disconnected
I0315 00:48:52.474516 454 status_update_manager.hpp:314] Handling ACK for status update TASK_FAILED from task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.474558 454 status_update_manager.cpp:433] Cleaning up status update stream for task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.474935 454 status_update_manager.hpp:257] Deleting the meta directory for task fbdc2883-9316-4276-958d-e7a2bd7f9e85 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.476016 32038 master.cpp:477] Master terminating
I0315 00:48:52.476114 32038 master.cpp:283] Shutting down master
[ OK ] SlaveRecoveryTest/0.RecoverTerminatedExecutor (3304 ms)
[ RUN ] SlaveRecoveryTest/0.CleanupExecutor
I0315 00:48:52.478562 455 slave.cpp:202] Slave started on 21)@67.195.138.60:45252
I0315 00:48:52.478513 456 master.cpp:309] Master started on 67.195.138.60:45252
I0315 00:48:52.478961 456 master.cpp:324] Master ID: 201303150048-1015726915-45252-32038
I0315 00:48:52.479539 457 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : master@67.195.138.60:45252
I0315 00:48:52.478590 455 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
W0315 00:48:52.479568 460 master.cpp:79] No whitelist given. Advertising offers for all slaves
I0315 00:48:52.478698 453 sched.cpp:182] New master at master@67.195.138.60:45252
I0315 00:48:52.479694 456 master.cpp:571] Elected as master!
I0315 00:48:52.480712 454 process_based_isolation_module.cpp:300] Recovering isolation module
I0315 00:48:52.480715 455 slave.cpp:457] New master detected at master@67.195.138.60:45252
I0315 00:48:52.483808 455 slave.cpp:381] Finished recovery
I0315 00:48:52.482844 456 master.cpp:614] Registering framework 201303150048-1015726915-45252-32038-0000 at scheduler(17)@67.195.138.60:45252
I0315 00:48:52.483829 459 status_update_manager.cpp:131] New master detected at master@67.195.138.60:45252
I0315 00:48:52.484874 454 sched.cpp:217] Framework registered with 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.484894 456 master.cpp:936] Attempting to register slave on janus.apache.org at slave(21)@67.195.138.60:45252
I0315 00:48:52.484922 453 hierarchical_allocator_process.hpp:266] Added framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.486398 456 master.cpp:1191] Master now considering a slave at janus.apache.org:45252 as active
I0315 00:48:52.487321 456 master.cpp:1767] Adding slave 201303150048-1015726915-45252-32038-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0315 00:48:52.487840 455 slave.cpp:491] Registered with master; given slave ID 201303150048-1015726915-45252-32038-0
I0315 00:48:52.488387 455 paths.hpp:335] Created slave directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/meta/slaves/201303150048-1015726915-45252-32038-0'
Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/meta/slaves/201303150048-1015726915-45252-32038-0/slave.info'
I0315 00:48:52.486876 453 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 00:48:52.489282 453 hierarchical_allocator_process.hpp:597] Performed allocation for 0 slaves in 2.41ms
I0315 00:48:52.489824 453 hierarchical_allocator_process.hpp:393] Added slave 201303150048-1015726915-45252-32038-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=2; mem=1024; ports=[31000-32000]; disk=1024 available)
I0315 00:48:52.490278 453 hierarchical_allocator_process.hpp:658] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150048-1015726915-45252-32038-0
I0315 00:48:52.490810 453 hierarchical_allocator_process.hpp:684] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150048-1015726915-45252-32038-0 to framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.491402 453 hierarchical_allocator_process.hpp:617] Performed allocation for slave 201303150048-1015726915-45252-32038-0 in 1.14ms
I0315 00:48:52.491441 457 master.hpp:305] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150048-1015726915-45252-32038-0
I0315 00:48:52.492398 457 master.cpp:1294] Sending 1 offers to framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.493140 455 sched.cpp:282] Received 1 offers
I0315 00:48:52.494992 457 master.cpp:1501] Processing reply for offer 201303150048-1015726915-45252-32038-0 on slave 201303150048-1015726915-45252-32038-0 (janus.apache.org) for framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.495102 457 master.hpp:285] Adding task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150048-1015726915-45252-32038-0
I0315 00:48:52.495394 457 master.cpp:1618] Launching task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150048-1015726915-45252-32038-0 (janus.apache.org)
I0315 00:48:52.495894 456 slave.cpp:603] Got assigned task 050532e5-8b71-420c-8425-504e2120a801 for framework 201303150048-1015726915-45252-32038-0000
Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/meta/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/framework.info'
Checkpointing 'scheduler(17)@67.195.138.60:45252' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/meta/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/framework.pid
I0315 00:48:52.495945 457 master.hpp:314] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150048-1015726915-45252-32038-0
I0315 00:48:52.498004 456 paths.hpp:302] Created executor directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/050532e5-8b71-420c-8425-504e2120a801/runs/7ea9111f-3d4f-4698-88a9-dc8aa94b8dc5'
Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/meta/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/050532e5-8b71-420c-8425-504e2120a801/executor.info'
I0315 00:48:52.498378 456 paths.hpp:302] Created executor directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/meta/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/050532e5-8b71-420c-8425-504e2120a801/runs/7ea9111f-3d4f-4698-88a9-dc8aa94b8dc5'
Checkpointing Task to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/meta/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/050532e5-8b71-420c-8425-504e2120a801/runs/7ea9111f-3d4f-4698-88a9-dc8aa94b8dc5/tasks/050532e5-8b71-420c-8425-504e2120a801/task.info'
I0315 00:48:52.498776 456 slave.cpp:440] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/050532e5-8b71-420c-8425-504e2120a801/runs/7ea9111f-3d4f-4698-88a9-dc8aa94b8dc5'
I0315 00:48:52.498808 452 process_based_isolation_module.cpp:123] Launching 050532e5-8b71-420c-8425-504e2120a801 (<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src/mesos-executor)> in /tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/050532e5-8b71-420c-8425-504e2120a801/runs/7ea9111f-3d4f-4698-88a9-dc8aa94b8dc5 with resources ' for framework 201303150048-1015726915-45252-32038-0000
Checkpointing forked pid 5233
Checkpointing '5233I0315 00:48:52.501803 452 process_based_isolation_module.cpp:162] Forked executor at 5233
' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/meta/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/050532e5-8b71-420c-8425-504e2120a801/runs/7ea9111f-3d4f-4698-88a9-dc8aa94b8dc5/pids/forked.pid
Fetching resources into /tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/050532e5-8b71-420c-8425-504e2120a801/runs/7ea9111f-3d4f-4698-88a9-dc8aa94b8dc5
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0315 00:48:52.544399 5238 process.cpp:1419] libprocess is initialized on 67.195.138.60:55290 for 8 cpus
I0315 00:48:52.546001 5254 exec.cpp:170] Executor started at: executor(1)@67.195.138.60:55290 with pid 5238
I0315 00:48:52.546763 459 slave.cpp:1005] Got registration for executor '050532e5-8b71-420c-8425-504e2120a801' of framework 201303150048-1015726915-45252-32038-0000
Checkpointing 'executor(1)@67.195.138.60:55290' to /tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/meta/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/050532e5-8b71-420c-8425-504e2120a801/runs/7ea9111f-3d4f-4698-88a9-dc8aa94b8dc5/pids/libprocess.pid
I0315 00:48:52.547299 459 slave.cpp:1080] Flushing queued tasks for framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.547796 5256 exec.cpp:194] Executor registered on slave 201303150048-1015726915-45252-32038-0
Registered executor on janus.apache.org
I0315 00:48:52.547922 5256 exec.cpp:258] Executor asked to run task '050532e5-8b71-420c-8425-504e2120a801'
Starting task 050532e5-8b71-420c-8425-504e2120a801
sh -c 'sleep 1000'
I0315 00:48:52.548441 5256 exec.cpp:382] Executor sending status update for task 050532e5-8b71-420c-8425-504e2120a801 in state TASK_RUNNING
I0315 00:48:52.549512 5260 process.cpp:878] Socket closed while receiving
I0315 00:48:52.549947 452 slave.cpp:1188] Handling status update TASK_RUNNING from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.550034 452 slave.cpp:1235] Forwarding status update TASK_RUNNING from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000 to the status update manager
I0315 00:48:52.550664 452 status_update_manager.cpp:253] Received status update TASK_RUNNING from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.550837 452 status_update_manager.cpp:402] Creating StatusUpdate stream for task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.551410 452 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_RUNNING from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.633782 452 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.633829 452 status_update_manager.cpp:288] Forwarding status update TASK_RUNNING from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000 to the master at master@67.195.138.60:45252
I0315 00:48:52.634351 452 master.cpp:1054] Status update from (128)@67.195.138.60:45252: task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000 is now in state TASK_RUNNING
I0315 00:48:52.634711 452 sched.cpp:327] Status update: task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000 is now in state TASK_RUNNING
I0315 00:48:52.634403 457 slave.cpp:1297] Sending ACK for status update TASK_RUNNING from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000 to executor executor(1)@67.195.138.60:55290
I0315 00:48:52.635745 457 slave.cpp:964] Got acknowledgement of status update for task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.636057 5255 exec.cpp:289] Executor received ACK for status update of task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.636056 5260 process.cpp:878] Socket closed while receiving
I0315 00:48:52.636132 457 status_update_manager.cpp:313] Received status update acknowledgement for task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.636536 457 status_update_manager.hpp:283] Checkpointing ACK for status update TASK_RUNNING from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:52.693483 457 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:53.480941 459 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 00:48:53.480980 459 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 80.11us
I0315 00:48:53.635282 453 slave.cpp:390] Slave terminating
I0315 00:48:53.635416 452 master.cpp:521] Slave 201303150048-1015726915-45252-32038-0(janus.apache.org) disconnected
I0315 00:48:53.636343 457 slave.cpp:202] Slave started on 22)@67.195.138.60:45252
I0315 00:48:53.636390 457 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0315 00:48:53.636358 459 master.cpp:576] Still acting as master!
I0315 00:48:53.637101 457 state.cpp:33] Recovering state from /tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/meta
I0315 00:48:53.638916 456 status_update_manager.cpp:153] Recovering status update manager
I0315 00:48:53.638972 456 status_update_manager.cpp:157] Recovering executor '050532e5-8b71-420c-8425-504e2120a801' of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:53.639338 457 slave.cpp:457] New master detected at master@67.195.138.60:45252
I0315 00:48:53.639379 456 status_update_manager.cpp:402] Creating StatusUpdate stream for task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:53.639776 457 slave.cpp:472] Skipping registration because slave is started in 'cleanup' mode
I0315 00:48:53.640303 456 status_update_manager.hpp:233] Replaying status update stream for task 050532e5-8b71-420c-8425-504e2120a801
I0315 00:48:53.641186 456 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:53.641664 456 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:53.642345 460 process_based_isolation_module.cpp:300] Recovering isolation module
I0315 00:48:53.642724 460 process_based_isolation_module.cpp:308] Recovering executor '050532e5-8b71-420c-8425-504e2120a801' of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:53.642374 456 status_update_manager.cpp:131] New master detected at master@67.195.138.60:45252
I0315 00:48:53.643462 459 slave.cpp:1758] Recovering executors
I0315 00:48:53.644057 459 slave.cpp:1762] Recovering executor '050532e5-8b71-420c-8425-504e2120a801' of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:53.644726 459 slave.cpp:1853] Sending shutdown to executor 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000 at executor(1)@67.195.138.60:55290
I0315 00:48:53.645752 459 slave.cpp:1609] Shutting down executor '050532e5-8b71-420c-8425-504e2120a801' of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:53.646602 5260 process.cpp:878] Socket closed while receiving
I0315 00:48:53.646625 5252 exec.cpp:321] Executor asked to shutdown
I0315 00:48:53.646739 5252 exec.cpp:75] Scheduling shutdown of the executor
I0315 00:48:53.646765 459 slave.cpp:440] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/050532e5-8b71-420c-8425-504e2120a801/runs/7ea9111f-3d4f-4698-88a9-dc8aa94b8dc5'
Waited on process 5261, returned status 15
I0315 00:48:53.646944 5254 exec.cpp:382] Executor sending status update for task 050532e5-8b71-420c-8425-504e2120a801 in state TASK_FAILED
I0315 00:48:53.646819 459 slave.cpp:381] Finished recovery
I0315 00:48:54.498006 459 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 00:48:54.508005 459 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 10.01ms
I0315 00:48:54.648193 461 process.cpp:878] Socket closed while receiving
I0315 00:48:55.509248 453 hierarchical_allocator_process.hpp:666] No resources available to allocate!
I0315 00:48:55.509306 453 hierarchical_allocator_process.hpp:597] Performed allocation for 1 slaves in 79.72us
I0315 00:48:55.637455 457 process_based_isolation_module.cpp:416] Telling slave of lost executor 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:55.637585 455 slave.cpp:1434] Executor '050532e5-8b71-420c-8425-504e2120a801' of framework 201303150048-1015726915-45252-32038-0000 has exited with status 0
I0315 00:48:55.641036 455 slave.cpp:1188] Handling status update TASK_FAILED from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:55.641173 455 slave.cpp:1235] Forwarding status update TASK_FAILED from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000 to the status update manager
I0315 00:48:55.641669 456 status_update_manager.cpp:253] Received status update TASK_FAILED from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:55.641742 460 gc.cpp:97] Scheduling /tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/slaves/201303150048-1015726915-45252-32038-0/frameworks/201303150048-1015726915-45252-32038-0000/executors/050532e5-8b71-420c-8425-504e2120a801/runs/7ea9111f-3d4f-4698-88a9-dc8aa94b8dc5 for removal
I0315 00:48:55.641762 455 slave.cpp:1558] Slave is shutting down because it is started with --recover==cleanup and all executors have terminated!
I0315 00:48:55.642365 456 status_update_manager.hpp:283] Checkpointing UPDATE for status update TASK_FAILED from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:55.643285 455 slave.cpp:1565] Archiving and deleting the meta directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_VTG3eH/meta' to allow incompatible upgrade!
tar: Removing leading `/' from member names
I0315 00:48:55.676432 455 slave.cpp:428] Slave asked to shut down by @0.0.0.0:0
I0315 00:48:55.676616 455 slave.cpp:390] Slave terminating
I0315 00:48:55.637534 457 process_utils.hpp:64] Stopping ... 5233
Sent signal to 5233
I0315 00:48:55.776041 456 status_update_manager.hpp:314] Handling UPDATE for status update TASK_FAILED from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:55.776188 456 status_update_manager.cpp:288] Forwarding status update TASK_FAILED from task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000 to the master at master@67.195.138.60:45252
I0315 00:48:55.776649 453 master.cpp:1054] Status update from (132)@67.195.138.60:45252: task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000 is now in state TASK_FAILED
I0315 00:48:55.776993 453 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303150048-1015726915-45252-32038-0
I0315 00:48:55.777041 460 sched.cpp:327] Status update: task 050532e5-8b71-420c-8425-504e2120a801 of framework 201303150048-1015726915-45252-32038-0000 is now in state TASK_FAILED
I0315 00:48:55.777945 460 sched.cpp:422] Stopping framework '201303150048-1015726915-45252-32038-0000'
I0315 00:48:55.778383 453 master.cpp:742] Asked to unregister framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:55.777519 456 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 201303150048-1015726915-45252-32038-0 from framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:55.779309 456 hierarchical_allocator_process.hpp:357] Deactivated framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:55.779842 456 hierarchical_allocator_process.hpp:310] Removed framework 201303150048-1015726915-45252-32038-0000
I0315 00:48:55.779103 454 master.cpp:477] Master terminating
I0315 00:48:55.780789 32038 master.cpp:283] Shutting down master
I0315 00:48:55.781370 452 hierarchical_allocator_process.hpp:421] Removed slave 201303150048-1015726915-45252-32038-0
[ OK ] SlaveRecoveryTest/0.CleanupExecutor (3305 ms)
[----------] 6 tests from SlaveRecoveryTest/0 (13984 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.*).
-------------------------------------------------------------
I0315 00:48:55.796501 457 master.cpp:309] Master started on 67.195.138.60:45252
I0315 00:48:55.796581 457 master.cpp:324] Master ID: 201303150048-1015726915-45252-32038
I0315 00:48:55.797111 456 slave.cpp:202] Slave started on 23)@67.195.138.60:45252
W0315 00:48:55.797098 460 master.cpp:79] No whitelist given. Advertising offers for all slaves
I0315 00:48:55.797137 453 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : master@67.195.138.60:45252
I0315 00:48:55.797282 457 master.cpp:571] Elected as master!
I0315 00:48:55.797343 456 slave.cpp:203] Slave resources: cpus=8; mem=15025; ports=[31000-32000]; disk=14042
Using cgroups requires root permissions
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