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/04/18 00:38:08 UTC

Build failed in Jenkins: Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #308

See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/308/changes>

Changes:

[bmahler] Added a NOHIERARCHY_ prefix to filter out Cgroups tests that require
no hierarchy to be mounted.

From: Thomas Marshall <tw...@gmail.com>
Review: https://reviews.apache.org/r/10531

[vinodkone] Moved checkpointing of forked PID into ExecutorLauncher and made
process isolator exec mesos-launcher.

This review is based on BenH's review: https://reviews.apache.org/r/10114/

Review: https://reviews.apache.org/r/10581

------------------------------------------
[...truncated 8583 lines...]
I0417 22:38:07.674355 22840 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : master@67.195.138.60:35095
W0417 22:38:07.674419 22844 master.cpp:81] No whitelist given. Advertising offers for all slaves
I0417 22:38:07.674522 22843 sched.cpp:182] New master at master@67.195.138.60:35095
I0417 22:38:07.674527 22845 master.cpp:603] Elected as master!
I0417 22:38:07.673913 22841 slave.cpp:210] Slave started on 38)@67.195.138.60:35095
I0417 22:38:07.677664 22841 slave.cpp:211] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0417 22:38:07.677264 22845 master.cpp:646] Registering framework 201304172238-1015726915-35095-22798-0000 at scheduler(29)@67.195.138.60:35095
I0417 22:38:07.678666 22846 sched.cpp:217] Framework registered with 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.678679 22845 hierarchical_allocator_process.hpp:268] Added framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.679647 22845 hierarchical_allocator_process.hpp:668] No resources available to allocate!
I0417 22:38:07.678509 22841 slave.cpp:530] New master detected at master@67.195.138.60:35095
I0417 22:38:07.680960 22845 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 1.314436000000000ms
I0417 22:38:07.681542 22841 slave.cpp:545] Postponing registration until recovery is complete
I0417 22:38:07.681565 22847 status_update_manager.cpp:154] New master detected at master@67.195.138.60:35095
I0417 22:38:07.682476 22841 slave.cpp:391] Finished recovery
I0417 22:38:07.683449 22842 master.cpp:968] Attempting to register slave on janus.apache.org at slave(38)@67.195.138.60:35095
I0417 22:38:07.683893 22842 master.cpp:1224] Master now considering a slave at janus.apache.org:35095 as active
I0417 22:38:07.684428 22842 master.cpp:1862] Adding slave 201304172238-1015726915-35095-22798-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0417 22:38:07.684962 22841 slave.cpp:590] Registered with master master@67.195.138.60:35095; given slave ID 201304172238-1015726915-35095-22798-0
I0417 22:38:07.685040 22845 hierarchical_allocator_process.hpp:395] Added slave 201304172238-1015726915-35095-22798-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)
I0417 22:38:07.687127 22845 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.687657 22845 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0 to framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.688207 22845 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304172238-1015726915-35095-22798-0 in 1.091475000000000ms
I0417 22:38:07.688238 22841 master.hpp:309] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.689086 22841 master.cpp:1327] Sending 1 offers to framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.689612 22840 sched.cpp:282] Received 1 offers
I0417 22:38:07.690191 22841 master.cpp:1534] Processing reply for offer 201304172238-1015726915-35095-22798-0 on slave 201304172238-1015726915-35095-22798-0 (janus.apache.org) for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.690639 22841 master.hpp:289] Adding task with resources cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.691066 22841 master.cpp:1651] Launching task 0 of framework 201304172238-1015726915-35095-22798-0000 with resources cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0 (janus.apache.org)
I0417 22:38:07.691602 22840 slave.cpp:719] Got assigned task 0 for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.691648 22841 master.hpp:318] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.691670 22846 hierarchical_allocator_process.hpp:471] Framework 201304172238-1015726915-35095-22798-0000 left ports=[31000-32000]; disk=1024 unused on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.693315 22846 hierarchical_allocator_process.hpp:497] Framework 201304172238-1015726915-35095-22798-0000 filtered slave 201304172238-1015726915-35095-22798-0 for 5.000000000000000secs
I0417 22:38:07.692402 22840 slave.cpp:792] Launching task 0 for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.695811 22840 paths.hpp:302] Created executor directory '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/8e8bc592-7acc-43dd-9947-0d90a0986598'
I0417 22:38:07.695966 22840 slave.cpp:940] Queuing task '0' for executor default of framework '201304172238-1015726915-35095-22798-0000
I0417 22:38:07.696295 22840 slave.cpp:512] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/8e8bc592-7acc-43dd-9947-0d90a0986598'
I0417 22:38:07.696094 22844 exec.cpp:170] Executor started at: executor(14)@67.195.138.60:35095 with pid 22798
I0417 22:38:07.698055 22844 slave.cpp:1391] Got registration for executor 'default' of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.698657 22844 slave.cpp:1505] Flushing queued tasks for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.698674 22846 exec.cpp:194] Executor registered on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.699549 22846 exec.cpp:258] Executor asked to run task '0'
I0417 22:38:07.700012 22846 exec.cpp:382] Executor sending status update for task 0 in state TASK_RUNNING
I0417 22:38:07.701437 22846 slave.cpp:1733] Handling status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.701572 22841 status_update_manager.cpp:289] Received status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 with checkpoint=false
I0417 22:38:07.701794 22841 status_update_manager.cpp:451] Creating StatusUpdate stream for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.702338 22841 status_update_manager.hpp:336] Handling UPDATE for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.703683 22841 status_update_manager.cpp:335] Forwarding status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 to the master at master@67.195.138.60:35095
I0417 22:38:07.704140 22844 master.cpp:1086] Status update from (139)@67.195.138.60:35095: task 0 of framework 201304172238-1015726915-35095-22798-0000 is now in state TASK_RUNNING
I0417 22:38:07.704169 22841 slave.cpp:1793] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 to executor executor(14)@67.195.138.60:35095
I0417 22:38:07.704648 22844 sched.cpp:327] Received status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 from slave(38)@67.195.138.60:35095
I0417 22:38:07.705137 22847 exec.cpp:289] Executor received ACK for status update of task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.705754 22844 sched.cpp:360] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 to slave(38)@67.195.138.60:35095
I0417 22:38:07.705955 22841 process.cpp:2922] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0417 22:38:07.706615 22844 slave.cpp:1307] Got acknowledgement of status update for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.707628 22848 process.cpp:870] Socket closed while receiving
I0417 22:38:07.707655 22846 status_update_manager.cpp:360] Received status update acknowledgement for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.708628 22846 status_update_manager.hpp:336] Handling ACK for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.708726 22842 slave.cpp:2033] Executor 'default' of framework 201304172238-1015726915-35095-22798-0000 has exited with status 0'
I0417 22:38:07.711146 22842 slave.cpp:1733] Handling status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.711328 22844 status_update_manager.cpp:289] Received status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000 with checkpoint=false
I0417 22:38:07.711581 22844 status_update_manager.hpp:336] Handling UPDATE for status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.711381 22841 master.cpp:1188] Executor default of framework 201304172238-1015726915-35095-22798-0000 on slave 201304172238-1015726915-35095-22798-0 (janus.apache.org) exited with status 0
I0417 22:38:07.711348 22842 slave.cpp:1344] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.712051 22844 status_update_manager.cpp:335] Forwarding status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000 to the master at master@67.195.138.60:35095
I0417 22:38:07.713587 22841 master.cpp:1086] Status update from (139)@67.195.138.60:35095: task 0 of framework 201304172238-1015726915-35095-22798-0000 is now in state TASK_LOST
I0417 22:38:07.714051 22841 master.hpp:300] Removing task with resources cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.713595 22844 slave.cpp:1793] Sending ACK for status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000 to executor executor(14)@67.195.138.60:35095
I0417 22:38:07.714097 22840 sched.cpp:327] Received status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000 from slave(38)@67.195.138.60:35095
I0417 22:38:07.714615 22847 hierarchical_allocator_process.hpp:544] Recovered cpus=2; mem=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304172238-1015726915-35095-22798-0 from framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.716274 22840 sched.cpp:360] Sending ACK for status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000 to slave(38)@67.195.138.60:35095
I0417 22:38:07.717216 22840 slave.cpp:1307] Got acknowledgement of status update for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.717794 22845 status_update_manager.cpp:360] Received status update acknowledgement for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.718214 22845 status_update_manager.hpp:336] Handling ACK for status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.718724 22845 status_update_manager.cpp:482] Cleaning up status update stream for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.719571 22840 slave.cpp:1344] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.719965 22840 slave.cpp:2168] Cleaning up executor 'default' of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.720549 22840 slave.cpp:2231] Cleaning up framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.720563 22846 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/8e8bc592-7acc-43dd-9947-0d90a0986598' for removal
I0417 22:38:07.721503 22846 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default' for removal
I0417 22:38:07.720971 22847 status_update_manager.cpp:251] Closing status update streams for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.722002 22846 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000' for removal
I0417 22:38:07.730948 22847 slave.cpp:2480] Current disk usage 100.00%. Max allowed age: 0.000000000000000ns
I0417 22:38:07.731061 22844 gc.cpp:167] Pruning directories with remaining removal time 1.000000000000000weeks
I0417 22:38:07.731914 22844 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/8e8bc592-7acc-43dd-9947-0d90a0986598
I0417 22:38:07.732345 22844 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/8e8bc592-7acc-43dd-9947-0d90a0986598'
I0417 22:38:07.732964 22844 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default
I0417 22:38:07.733368 22844 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default'
I0417 22:38:07.733789 22844 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000
I0417 22:38:07.734313 22844 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000'
I0417 22:38:07.741196 22842 process.cpp:2922] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0417 22:38:07.742049 22848 process.cpp:870] Socket closed while receiving
I0417 22:38:07.742593 22798 master.cpp:477] Master terminating
I0417 22:38:07.742609 22844 sched.cpp:422] Stopping framework '201304172238-1015726915-35095-22798-0000'
I0417 22:38:07.742672 22798 master.cpp:283] Shutting down master
I0417 22:38:07.742738 22840 slave.cpp:486] Slave asked to shut down by master@67.195.138.60:35095
I0417 22:38:07.743533 22845 hierarchical_allocator_process.hpp:359] Deactivated framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.743980 22840 slave.cpp:441] Slave terminating
[       OK ] GarbageCollectorIntegrationTest.DiskUsage (73 ms)
[ RUN      ] GarbageCollectorIntegrationTest.Unschedule
I0417 22:38:07.746618 22847 master.cpp:309] Master started on 67.195.138.60:35095
I0417 22:38:07.746673 22847 master.cpp:324] Master ID: 201304172238-1015726915-35095-22798
I0417 22:38:07.747163 22840 slave.cpp:210] Slave started on 39)@67.195.138.60:35095
W0417 22:38:07.747292 22846 master.cpp:81] No whitelist given. Advertising offers for all slaves
I0417 22:38:07.747342 22841 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : master@67.195.138.60:35095
I0417 22:38:07.747442 22847 master.cpp:603] Elected as master!
I0417 22:38:07.747596 22840 slave.cpp:211] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0417 22:38:07.750393 22840 slave.cpp:530] New master detected at master@67.195.138.60:35095
I0417 22:38:07.750495 22840 slave.cpp:545] Postponing registration until recovery is complete
I0417 22:38:07.750545 22843 status_update_manager.cpp:154] New master detected at master@67.195.138.60:35095
I0417 22:38:07.751200 22840 slave.cpp:391] Finished recovery
I0417 22:38:07.752975 22840 master.cpp:968] Attempting to register slave on janus.apache.org at slave(39)@67.195.138.60:35095
I0417 22:38:07.754417 22840 master.cpp:1224] Master now considering a slave at janus.apache.org:35095 as active
I0417 22:38:07.799296 22840 master.cpp:1862] Adding slave 201304172238-1015726915-35095-22798-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0417 22:38:07.799841 22846 slave.cpp:590] Registered with master master@67.195.138.60:35095; given slave ID 201304172238-1015726915-35095-22798-0
I0417 22:38:07.799901 22845 hierarchical_allocator_process.hpp:395] Added slave 201304172238-1015726915-35095-22798-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)
I0417 22:38:07.800382 22840 sched.cpp:182] New master at master@67.195.138.60:35095
I0417 22:38:07.800755 22845 hierarchical_allocator_process.hpp:632] No users to allocate resources!
I0417 22:38:07.801659 22845 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304172238-1015726915-35095-22798-0 in 906.327000000000112us
I0417 22:38:07.801270 22844 master.cpp:646] Registering framework 201304172238-1015726915-35095-22798-0000 at scheduler(30)@67.195.138.60:35095
I0417 22:38:07.802675 22840 sched.cpp:217] Framework registered with 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.802726 22844 hierarchical_allocator_process.hpp:268] Added framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.803603 22844 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.804103 22844 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0 to framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.804653 22844 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 1.065056000000000ms
I0417 22:38:07.804716 22846 master.hpp:309] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.805588 22846 master.cpp:1327] Sending 1 offers to framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.806084 22842 sched.cpp:282] Received 1 offers
I0417 22:38:07.806666 22846 master.cpp:1534] Processing reply for offer 201304172238-1015726915-35095-22798-0 on slave 201304172238-1015726915-35095-22798-0 (janus.apache.org) for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.807031 22846 master.hpp:289] Adding task with resources cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.807476 22846 master.cpp:1651] Launching task 0 of framework 201304172238-1015726915-35095-22798-0000 with resources cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0 (janus.apache.org)
I0417 22:38:07.807996 22842 slave.cpp:719] Got assigned task 0 for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.808032 22847 hierarchical_allocator_process.hpp:471] Framework 201304172238-1015726915-35095-22798-0000 left ports=[31000-32000]; disk=1024 unused on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.808039 22846 master.hpp:318] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.809636 22842 slave.cpp:792] Launching task 0 for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.810026 22847 hierarchical_allocator_process.hpp:497] Framework 201304172238-1015726915-35095-22798-0000 filtered slave 201304172238-1015726915-35095-22798-0 for 5.000000000000000secs
I0417 22:38:07.812131 22842 paths.hpp:302] Created executor directory '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/9f5c7e9c-9501-4efa-92bf-eed129b161d0'
I0417 22:38:07.812260 22842 slave.cpp:940] Queuing task '0' for executor default of framework '201304172238-1015726915-35095-22798-0000
I0417 22:38:07.812369 22841 exec.cpp:170] Executor started at: executor(15)@67.195.138.60:35095 with pid 22798
I0417 22:38:07.812589 22842 slave.cpp:512] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/9f5c7e9c-9501-4efa-92bf-eed129b161d0'
I0417 22:38:07.813784 22842 slave.cpp:1391] Got registration for executor 'default' of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.814793 22842 slave.cpp:1505] Flushing queued tasks for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.814822 22840 exec.cpp:194] Executor registered on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.857432 22840 exec.cpp:258] Executor asked to run task '0'
I0417 22:38:07.858176 22840 exec.cpp:382] Executor sending status update for task 0 in state TASK_RUNNING
I0417 22:38:07.887481 22840 slave.cpp:1733] Handling status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.887603 22840 status_update_manager.cpp:289] Received status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 with checkpoint=false
I0417 22:38:07.888748 22840 status_update_manager.cpp:451] Creating StatusUpdate stream for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.916045 22840 status_update_manager.hpp:336] Handling UPDATE for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.916764 22840 status_update_manager.cpp:335] Forwarding status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 to the master at master@67.195.138.60:35095
I0417 22:38:07.945129 22846 master.cpp:1086] Status update from (143)@67.195.138.60:35095: task 0 of framework 201304172238-1015726915-35095-22798-0000 is now in state TASK_RUNNING
I0417 22:38:07.945148 22845 slave.cpp:1793] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 to executor executor(15)@67.195.138.60:35095
I0417 22:38:07.946176 22841 sched.cpp:327] Received status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 from slave(39)@67.195.138.60:35095
I0417 22:38:07.966217 22846 exec.cpp:289] Executor received ACK for status update of task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.966678 22841 sched.cpp:360] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 to slave(39)@67.195.138.60:35095
I0417 22:38:07.967290 22846 slave.cpp:2033] Executor 'default' of framework 201304172238-1015726915-35095-22798-0000 has exited with status 0'
I0417 22:38:07.969040 22846 slave.cpp:1733] Handling status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.969205 22840 status_update_manager.cpp:289] Received status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000 with checkpoint=false
I0417 22:38:07.969459 22840 status_update_manager.hpp:336] Handling UPDATE for status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.969260 22841 master.cpp:1188] Executor default of framework 201304172238-1015726915-35095-22798-0000 on slave 201304172238-1015726915-35095-22798-0 (janus.apache.org) exited with status 0
I0417 22:38:07.969244 22846 slave.cpp:1307] Got acknowledgement of status update for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.970971 22841 status_update_manager.cpp:360] Received status update acknowledgement for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.971380 22841 status_update_manager.hpp:336] Handling ACK for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.971863 22841 status_update_manager.cpp:335] Forwarding status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000 to the master at master@67.195.138.60:35095
I0417 22:38:07.970994 22846 slave.cpp:1793] Sending ACK for status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000 to executor executor(15)@67.195.138.60:35095
I0417 22:38:07.972877 22846 slave.cpp:1344] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.972408 22840 master.cpp:1086] Status update from (143)@67.195.138.60:35095: task 0 of framework 201304172238-1015726915-35095-22798-0000 is now in state TASK_LOST
I0417 22:38:07.974258 22840 master.hpp:300] Removing task with resources cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:07.974269 22841 sched.cpp:327] Received status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000 from slave(39)@67.195.138.60:35095
I0417 22:38:07.975208 22841 sched.cpp:360] Sending ACK for status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000 to slave(39)@67.195.138.60:35095
I0417 22:38:07.974827 22842 hierarchical_allocator_process.hpp:544] Recovered cpus=2; mem=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304172238-1015726915-35095-22798-0 from framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:07.976752 22841 slave.cpp:1307] Got acknowledgement of status update for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.003599 22841 status_update_manager.cpp:360] Received status update acknowledgement for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.004009 22841 status_update_manager.hpp:336] Handling ACK for status update TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.004479 22841 status_update_manager.cpp:482] Cleaning up status update stream for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.005007 22841 slave.cpp:1344] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.005427 22841 slave.cpp:2168] Cleaning up executor 'default' of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.006052 22847 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/9f5c7e9c-9501-4efa-92bf-eed129b161d0' for removal
I0417 22:38:08.006485 22847 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default' for removal
I0417 22:38:08.006065 22841 slave.cpp:2231] Cleaning up framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.007387 22847 status_update_manager.cpp:251] Closing status update streams for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.007453 22843 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000' for removal
I0417 22:38:08.007601 22846 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:08.008838 22846 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0 to framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.009378 22846 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 1.806216000000000ms
I0417 22:38:08.009425 22843 master.hpp:309] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:08.010241 22843 master.cpp:1327] Sending 1 offers to framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.010776 22843 sched.cpp:282] Received 1 offers
I0417 22:38:08.011327 22843 master.cpp:1534] Processing reply for offer 201304172238-1015726915-35095-22798-1 on slave 201304172238-1015726915-35095-22798-0 (janus.apache.org) for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.011744 22843 master.hpp:289] Adding task with resources cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:08.016716 22843 master.cpp:1651] Launching task 0 of framework 201304172238-1015726915-35095-22798-0000 with resources cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0 (janus.apache.org)
I0417 22:38:08.046468 22845 slave.cpp:719] Got assigned task 0 for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.046489 22846 hierarchical_allocator_process.hpp:471] Framework 201304172238-1015726915-35095-22798-0000 left ports=[31000-32000]; disk=1024 unused on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:08.046490 22843 master.hpp:318] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:08.047123 22845 gc.cpp:84] Unscheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000' for removal
I0417 22:38:08.047377 22846 hierarchical_allocator_process.hpp:497] Framework 201304172238-1015726915-35095-22798-0000 filtered slave 201304172238-1015726915-35095-22798-0 for 5.000000000000000secs
I0417 22:38:08.048488 22844 gc.cpp:84] Unscheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default' for removal
I0417 22:38:08.049361 22841 slave.cpp:792] Launching task 0 for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.050772 22841 paths.hpp:302] Created executor directory '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/c3227e94-478a-48d3-8614-0d2c92ac5ec0'
I0417 22:38:08.050909 22841 slave.cpp:940] Queuing task '0' for executor default of framework '201304172238-1015726915-35095-22798-0000
I0417 22:38:08.090430 22841 slave.cpp:512] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/c3227e94-478a-48d3-8614-0d2c92ac5ec0'
I0417 22:38:08.051069 22844 exec.cpp:170] Executor started at: executor(16)@67.195.138.60:35095 with pid 22798
I0417 22:38:08.129813 22844 slave.cpp:1391] Got registration for executor 'default' of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.148749 22844 slave.cpp:1505] Flushing queued tasks for framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.148802 22841 exec.cpp:194] Executor registered on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:08.167788 22841 exec.cpp:258] Executor asked to run task '0'
I0417 22:38:08.202324 22841 exec.cpp:382] Executor sending status update for task 0 in state TASK_RUNNING
I0417 22:38:08.204095 22841 slave.cpp:1733] Handling status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.233724 22841 status_update_manager.cpp:289] Received status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 with checkpoint=false
I0417 22:38:08.234408 22841 status_update_manager.cpp:451] Creating StatusUpdate stream for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.263043 22841 status_update_manager.hpp:336] Handling UPDATE for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.263902 22841 status_update_manager.cpp:335] Forwarding status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 to the master at master@67.195.138.60:35095
I0417 22:38:08.300575 22840 slave.cpp:1793] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 to executor executor(16)@67.195.138.60:35095
I0417 22:38:08.300995 22840 exec.cpp:289] Executor received ACK for status update of task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.300576 22841 master.cpp:1086] Status update from (143)@67.195.138.60:35095: task 0 of framework 201304172238-1015726915-35095-22798-0000 is now in state TASK_RUNNING
I0417 22:38:08.301954 22841 sched.cpp:327] Received status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 from slave(39)@67.195.138.60:35095
I0417 22:38:08.302403 22841 sched.cpp:360] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000 to slave(39)@67.195.138.60:35095
I0417 22:38:08.302870 22841 slave.cpp:1307] Got acknowledgement of status update for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.303400 22841 status_update_manager.cpp:360] Received status update acknowledgement for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.303791 22841 status_update_manager.hpp:336] Handling ACK for status update TASK_RUNNING from task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.304297 22841 slave.cpp:1344] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.309861 22798 master.cpp:477] Master terminating
I0417 22:38:08.309921 22798 master.cpp:283] Shutting down master
I0417 22:38:08.309866 22847 sched.cpp:422] Stopping framework '201304172238-1015726915-35095-22798-0000'
I0417 22:38:08.309954 22845 slave.cpp:486] Slave asked to shut down by master@67.195.138.60:35095
I0417 22:38:08.344889 22798 master.hpp:300] Removing task with resources cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
I0417 22:38:08.344926 22843 hierarchical_allocator_process.hpp:359] Deactivated framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.345803 22845 slave.cpp:1117] Asked to shut down framework 201304172238-1015726915-35095-22798-0000 by master@67.195.138.60:35095
I0417 22:38:08.347337 22845 slave.cpp:1142] Shutting down framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.347870 22845 slave.cpp:2299] Shutting down executor 'default' of framework 201304172238-1015726915-35095-22798-0000
I0417 22:38:08.348391 22845 slave.cpp:441] Slave terminating
I0417 22:38:08.348906 22845 slave.cpp:1117] Asked to shut down framework 201304172238-1015726915-35095-22798-0000 by @0.0.0.0:0
W0417 22:38:08.349412 22845 slave.cpp:1138] Ignoring shutdown framework 201304172238-1015726915-35095-22798-0000 because it is terminating
I0417 22:38:08.348423 22841 exec.cpp:321] Executor asked to shutdown
pure virtual method called
terminate called without an active exception
/bin/bash: line 5: 22798 Aborted                 ${dir}$tst
FAIL: mesos-tests
==================
1 of 1 test failed
==================
make[3]: *** [check-TESTS] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-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
Build step 'Execute shell' marked build as failure

Re: Build failed in Jenkins: Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #308

Posted by Benjamin Mahler <be...@gmail.com>.
Possibly related: https://issues.apache.org/jira/browse/MESOS-395


On Wed, Apr 17, 2013 at 3:38 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:

> See <
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/308/changes
> >
>
> Changes:
>
> [bmahler] Added a NOHIERARCHY_ prefix to filter out Cgroups tests that
> require
> no hierarchy to be mounted.
>
> From: Thomas Marshall <tw...@gmail.com>
> Review: https://reviews.apache.org/r/10531
>
> [vinodkone] Moved checkpointing of forked PID into ExecutorLauncher and
> made
> process isolator exec mesos-launcher.
>
> This review is based on BenH's review: https://reviews.apache.org/r/10114/
>
> Review: https://reviews.apache.org/r/10581
>
> ------------------------------------------
> [...truncated 8583 lines...]
> I0417 22:38:07.674355 22840 hierarchical_allocator_process.hpp:236]
> Initializing hierarchical allocator process with master :
> master@67.195.138.60:35095
> W0417 22:38:07.674419 22844 master.cpp:81] No whitelist given. Advertising
> offers for all slaves
> I0417 22:38:07.674522 22843 sched.cpp:182] New master at
> master@67.195.138.60:35095
> I0417 22:38:07.674527 22845 master.cpp:603] Elected as master!
> I0417 22:38:07.673913 22841 slave.cpp:210] Slave started on 38)@
> 67.195.138.60:35095
> I0417 22:38:07.677664 22841 slave.cpp:211] Slave resources: cpus=2;
> mem=1024; ports=[31000-32000]; disk=1024
> I0417 22:38:07.677264 22845 master.cpp:646] Registering framework
> 201304172238-1015726915-35095-22798-0000 at scheduler(29)@
> 67.195.138.60:35095
> I0417 22:38:07.678666 22846 sched.cpp:217] Framework registered with
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.678679 22845 hierarchical_allocator_process.hpp:268] Added
> framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.679647 22845 hierarchical_allocator_process.hpp:668] No
> resources available to allocate!
> I0417 22:38:07.678509 22841 slave.cpp:530] New master detected at
> master@67.195.138.60:35095
> I0417 22:38:07.680960 22845 hierarchical_allocator_process.hpp:599]
> Performed allocation for 0 slaves in 1.314436000000000ms
> I0417 22:38:07.681542 22841 slave.cpp:545] Postponing registration until
> recovery is complete
> I0417 22:38:07.681565 22847 status_update_manager.cpp:154] New master
> detected at master@67.195.138.60:35095
> I0417 22:38:07.682476 22841 slave.cpp:391] Finished recovery
> I0417 22:38:07.683449 22842 master.cpp:968] Attempting to register slave
> on janus.apache.org at slave(38)@67.195.138.60:35095
> I0417 22:38:07.683893 22842 master.cpp:1224] Master now considering a
> slave at janus.apache.org:35095 as active
> I0417 22:38:07.684428 22842 master.cpp:1862] Adding slave
> 201304172238-1015726915-35095-22798-0 at janus.apache.org with cpus=2;
> mem=1024; ports=[31000-32000]; disk=1024
> I0417 22:38:07.684962 22841 slave.cpp:590] Registered with master
> master@67.195.138.60:35095; given slave ID
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.685040 22845 hierarchical_allocator_process.hpp:395] Added
> slave 201304172238-1015726915-35095-22798-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)
> I0417 22:38:07.687127 22845 hierarchical_allocator_process.hpp:660] Found
> available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on
> slave 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.687657 22845 hierarchical_allocator_process.hpp:686]
> Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304172238-1015726915-35095-22798-0 to framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.688207 22845 hierarchical_allocator_process.hpp:619]
> Performed allocation for slave 201304172238-1015726915-35095-22798-0 in
> 1.091475000000000ms
> I0417 22:38:07.688238 22841 master.hpp:309] Adding offer with resources
> cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.689086 22841 master.cpp:1327] Sending 1 offers to framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.689612 22840 sched.cpp:282] Received 1 offers
> I0417 22:38:07.690191 22841 master.cpp:1534] Processing reply for offer
> 201304172238-1015726915-35095-22798-0 on slave
> 201304172238-1015726915-35095-22798-0 (janus.apache.org) for framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.690639 22841 master.hpp:289] Adding task with resources
> cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.691066 22841 master.cpp:1651] Launching task 0 of framework
> 201304172238-1015726915-35095-22798-0000 with resources cpus=2; mem=1024 on
> slave 201304172238-1015726915-35095-22798-0 (janus.apache.org)
> I0417 22:38:07.691602 22840 slave.cpp:719] Got assigned task 0 for
> framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.691648 22841 master.hpp:318] Removing offer with resources
> cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.691670 22846 hierarchical_allocator_process.hpp:471]
> Framework 201304172238-1015726915-35095-22798-0000 left
> ports=[31000-32000]; disk=1024 unused on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.693315 22846 hierarchical_allocator_process.hpp:497]
> Framework 201304172238-1015726915-35095-22798-0000 filtered slave
> 201304172238-1015726915-35095-22798-0 for 5.000000000000000secs
> I0417 22:38:07.692402 22840 slave.cpp:792] Launching task 0 for framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.695811 22840 paths.hpp:302] Created executor directory
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/8e8bc592-7acc-43dd-9947-0d90a0986598'
> I0417 22:38:07.695966 22840 slave.cpp:940] Queuing task '0' for executor
> default of framework '201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.696295 22840 slave.cpp:512] Successfully attached file
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/8e8bc592-7acc-43dd-9947-0d90a0986598'
> I0417 22:38:07.696094 22844 exec.cpp:170] Executor started at:
> executor(14)@67.195.138.60:35095 with pid 22798
> I0417 22:38:07.698055 22844 slave.cpp:1391] Got registration for executor
> 'default' of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.698657 22844 slave.cpp:1505] Flushing queued tasks for
> framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.698674 22846 exec.cpp:194] Executor registered on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.699549 22846 exec.cpp:258] Executor asked to run task '0'
> I0417 22:38:07.700012 22846 exec.cpp:382] Executor sending status update
> for task 0 in state TASK_RUNNING
> I0417 22:38:07.701437 22846 slave.cpp:1733] Handling status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.701572 22841 status_update_manager.cpp:289] Received status
> update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 with checkpoint=false
> I0417 22:38:07.701794 22841 status_update_manager.cpp:451] Creating
> StatusUpdate stream for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.702338 22841 status_update_manager.hpp:336] Handling UPDATE
> for status update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.703683 22841 status_update_manager.cpp:335] Forwarding
> status update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 to the master at
> master@67.195.138.60:35095
> I0417 22:38:07.704140 22844 master.cpp:1086] Status update from (139)@
> 67.195.138.60:35095: task 0 of framework
> 201304172238-1015726915-35095-22798-0000 is now in state TASK_RUNNING
> I0417 22:38:07.704169 22841 slave.cpp:1793] Sending ACK for status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 to executor executor(14)@
> 67.195.138.60:35095
> I0417 22:38:07.704648 22844 sched.cpp:327] Received status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 from slave(38)@
> 67.195.138.60:35095
> I0417 22:38:07.705137 22847 exec.cpp:289] Executor received ACK for status
> update of task 0 of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.705754 22844 sched.cpp:360] Sending ACK for status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 to slave(38)@67.195.138.60:35095
> I0417 22:38:07.705955 22841 process.cpp:2922] Handling HTTP event for
> process 'files' with path: '/files/browse.json'
> I0417 22:38:07.706615 22844 slave.cpp:1307] Got acknowledgement of status
> update for task 0 of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.707628 22848 process.cpp:870] Socket closed while receiving
> I0417 22:38:07.707655 22846 status_update_manager.cpp:360] Received status
> update acknowledgement for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.708628 22846 status_update_manager.hpp:336] Handling ACK
> for status update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.708726 22842 slave.cpp:2033] Executor 'default' of
> framework 201304172238-1015726915-35095-22798-0000 has exited with status 0'
> I0417 22:38:07.711146 22842 slave.cpp:1733] Handling status update
> TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.711328 22844 status_update_manager.cpp:289] Received status
> update TASK_LOST from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 with checkpoint=false
> I0417 22:38:07.711581 22844 status_update_manager.hpp:336] Handling UPDATE
> for status update TASK_LOST from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.711381 22841 master.cpp:1188] Executor default of framework
> 201304172238-1015726915-35095-22798-0000 on slave
> 201304172238-1015726915-35095-22798-0 (janus.apache.org) exited with
> status 0
> I0417 22:38:07.711348 22842 slave.cpp:1344] Status update manager
> successfully handled status update acknowledgement for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.712051 22844 status_update_manager.cpp:335] Forwarding
> status update TASK_LOST from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 to the master at
> master@67.195.138.60:35095
> I0417 22:38:07.713587 22841 master.cpp:1086] Status update from (139)@
> 67.195.138.60:35095: task 0 of framework
> 201304172238-1015726915-35095-22798-0000 is now in state TASK_LOST
> I0417 22:38:07.714051 22841 master.hpp:300] Removing task with resources
> cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.713595 22844 slave.cpp:1793] Sending ACK for status update
> TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
> to executor executor(14)@67.195.138.60:35095
> I0417 22:38:07.714097 22840 sched.cpp:327] Received status update
> TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
> from slave(38)@67.195.138.60:35095
> I0417 22:38:07.714615 22847 hierarchical_allocator_process.hpp:544]
> Recovered cpus=2; mem=1024 (total allocatable: cpus=2; mem=1024;
> ports=[31000-32000]; disk=1024) on slave
> 201304172238-1015726915-35095-22798-0 from framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.716274 22840 sched.cpp:360] Sending ACK for status update
> TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
> to slave(38)@67.195.138.60:35095
> I0417 22:38:07.717216 22840 slave.cpp:1307] Got acknowledgement of status
> update for task 0 of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.717794 22845 status_update_manager.cpp:360] Received status
> update acknowledgement for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.718214 22845 status_update_manager.hpp:336] Handling ACK
> for status update TASK_LOST from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.718724 22845 status_update_manager.cpp:482] Cleaning up
> status update stream for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.719571 22840 slave.cpp:1344] Status update manager
> successfully handled status update acknowledgement for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.719965 22840 slave.cpp:2168] Cleaning up executor 'default'
> of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.720549 22840 slave.cpp:2231] Cleaning up framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.720563 22846 gc.cpp:56] Scheduling
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/8e8bc592-7acc-43dd-9947-0d90a0986598'
> for removal
> I0417 22:38:07.721503 22846 gc.cpp:56] Scheduling
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default'
> for removal
> I0417 22:38:07.720971 22847 status_update_manager.cpp:251] Closing status
> update streams for framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.722002 22846 gc.cpp:56] Scheduling
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000'
> for removal
> I0417 22:38:07.730948 22847 slave.cpp:2480] Current disk usage 100.00%.
> Max allowed age: 0.000000000000000ns
> I0417 22:38:07.731061 22844 gc.cpp:167] Pruning directories with remaining
> removal time 1.000000000000000weeks
> I0417 22:38:07.731914 22844 gc.cpp:134] Deleting
> /tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/8e8bc592-7acc-43dd-9947-0d90a0986598
> I0417 22:38:07.732345 22844 gc.cpp:143] Deleted
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/8e8bc592-7acc-43dd-9947-0d90a0986598'
> I0417 22:38:07.732964 22844 gc.cpp:134] Deleting
> /tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default
> I0417 22:38:07.733368 22844 gc.cpp:143] Deleted
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default'
> I0417 22:38:07.733789 22844 gc.cpp:134] Deleting
> /tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.734313 22844 gc.cpp:143] Deleted
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_iZJtYa/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000'
> I0417 22:38:07.741196 22842 process.cpp:2922] Handling HTTP event for
> process 'files' with path: '/files/browse.json'
> I0417 22:38:07.742049 22848 process.cpp:870] Socket closed while receiving
> I0417 22:38:07.742593 22798 master.cpp:477] Master terminating
> I0417 22:38:07.742609 22844 sched.cpp:422] Stopping framework
> '201304172238-1015726915-35095-22798-0000'
> I0417 22:38:07.742672 22798 master.cpp:283] Shutting down master
> I0417 22:38:07.742738 22840 slave.cpp:486] Slave asked to shut down by
> master@67.195.138.60:35095
> I0417 22:38:07.743533 22845 hierarchical_allocator_process.hpp:359]
> Deactivated framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.743980 22840 slave.cpp:441] Slave terminating
> [       OK ] GarbageCollectorIntegrationTest.DiskUsage (73 ms)
> [ RUN      ] GarbageCollectorIntegrationTest.Unschedule
> I0417 22:38:07.746618 22847 master.cpp:309] Master started on
> 67.195.138.60:35095
> I0417 22:38:07.746673 22847 master.cpp:324] Master ID:
> 201304172238-1015726915-35095-22798
> I0417 22:38:07.747163 22840 slave.cpp:210] Slave started on 39)@
> 67.195.138.60:35095
> W0417 22:38:07.747292 22846 master.cpp:81] No whitelist given. Advertising
> offers for all slaves
> I0417 22:38:07.747342 22841 hierarchical_allocator_process.hpp:236]
> Initializing hierarchical allocator process with master :
> master@67.195.138.60:35095
> I0417 22:38:07.747442 22847 master.cpp:603] Elected as master!
> I0417 22:38:07.747596 22840 slave.cpp:211] Slave resources: cpus=2;
> mem=1024; ports=[31000-32000]; disk=1024
> I0417 22:38:07.750393 22840 slave.cpp:530] New master detected at
> master@67.195.138.60:35095
> I0417 22:38:07.750495 22840 slave.cpp:545] Postponing registration until
> recovery is complete
> I0417 22:38:07.750545 22843 status_update_manager.cpp:154] New master
> detected at master@67.195.138.60:35095
> I0417 22:38:07.751200 22840 slave.cpp:391] Finished recovery
> I0417 22:38:07.752975 22840 master.cpp:968] Attempting to register slave
> on janus.apache.org at slave(39)@67.195.138.60:35095
> I0417 22:38:07.754417 22840 master.cpp:1224] Master now considering a
> slave at janus.apache.org:35095 as active
> I0417 22:38:07.799296 22840 master.cpp:1862] Adding slave
> 201304172238-1015726915-35095-22798-0 at janus.apache.org with cpus=2;
> mem=1024; ports=[31000-32000]; disk=1024
> I0417 22:38:07.799841 22846 slave.cpp:590] Registered with master
> master@67.195.138.60:35095; given slave ID
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.799901 22845 hierarchical_allocator_process.hpp:395] Added
> slave 201304172238-1015726915-35095-22798-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)
> I0417 22:38:07.800382 22840 sched.cpp:182] New master at
> master@67.195.138.60:35095
> I0417 22:38:07.800755 22845 hierarchical_allocator_process.hpp:632] No
> users to allocate resources!
> I0417 22:38:07.801659 22845 hierarchical_allocator_process.hpp:619]
> Performed allocation for slave 201304172238-1015726915-35095-22798-0 in
> 906.327000000000112us
> I0417 22:38:07.801270 22844 master.cpp:646] Registering framework
> 201304172238-1015726915-35095-22798-0000 at scheduler(30)@
> 67.195.138.60:35095
> I0417 22:38:07.802675 22840 sched.cpp:217] Framework registered with
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.802726 22844 hierarchical_allocator_process.hpp:268] Added
> framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.803603 22844 hierarchical_allocator_process.hpp:660] Found
> available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on
> slave 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.804103 22844 hierarchical_allocator_process.hpp:686]
> Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304172238-1015726915-35095-22798-0 to framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.804653 22844 hierarchical_allocator_process.hpp:599]
> Performed allocation for 1 slaves in 1.065056000000000ms
> I0417 22:38:07.804716 22846 master.hpp:309] Adding offer with resources
> cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.805588 22846 master.cpp:1327] Sending 1 offers to framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.806084 22842 sched.cpp:282] Received 1 offers
> I0417 22:38:07.806666 22846 master.cpp:1534] Processing reply for offer
> 201304172238-1015726915-35095-22798-0 on slave
> 201304172238-1015726915-35095-22798-0 (janus.apache.org) for framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.807031 22846 master.hpp:289] Adding task with resources
> cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.807476 22846 master.cpp:1651] Launching task 0 of framework
> 201304172238-1015726915-35095-22798-0000 with resources cpus=2; mem=1024 on
> slave 201304172238-1015726915-35095-22798-0 (janus.apache.org)
> I0417 22:38:07.807996 22842 slave.cpp:719] Got assigned task 0 for
> framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.808032 22847 hierarchical_allocator_process.hpp:471]
> Framework 201304172238-1015726915-35095-22798-0000 left
> ports=[31000-32000]; disk=1024 unused on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.808039 22846 master.hpp:318] Removing offer with resources
> cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.809636 22842 slave.cpp:792] Launching task 0 for framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.810026 22847 hierarchical_allocator_process.hpp:497]
> Framework 201304172238-1015726915-35095-22798-0000 filtered slave
> 201304172238-1015726915-35095-22798-0 for 5.000000000000000secs
> I0417 22:38:07.812131 22842 paths.hpp:302] Created executor directory
> '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/9f5c7e9c-9501-4efa-92bf-eed129b161d0'
> I0417 22:38:07.812260 22842 slave.cpp:940] Queuing task '0' for executor
> default of framework '201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.812369 22841 exec.cpp:170] Executor started at:
> executor(15)@67.195.138.60:35095 with pid 22798
> I0417 22:38:07.812589 22842 slave.cpp:512] Successfully attached file
> '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/9f5c7e9c-9501-4efa-92bf-eed129b161d0'
> I0417 22:38:07.813784 22842 slave.cpp:1391] Got registration for executor
> 'default' of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.814793 22842 slave.cpp:1505] Flushing queued tasks for
> framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.814822 22840 exec.cpp:194] Executor registered on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.857432 22840 exec.cpp:258] Executor asked to run task '0'
> I0417 22:38:07.858176 22840 exec.cpp:382] Executor sending status update
> for task 0 in state TASK_RUNNING
> I0417 22:38:07.887481 22840 slave.cpp:1733] Handling status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.887603 22840 status_update_manager.cpp:289] Received status
> update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 with checkpoint=false
> I0417 22:38:07.888748 22840 status_update_manager.cpp:451] Creating
> StatusUpdate stream for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.916045 22840 status_update_manager.hpp:336] Handling UPDATE
> for status update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.916764 22840 status_update_manager.cpp:335] Forwarding
> status update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 to the master at
> master@67.195.138.60:35095
> I0417 22:38:07.945129 22846 master.cpp:1086] Status update from (143)@
> 67.195.138.60:35095: task 0 of framework
> 201304172238-1015726915-35095-22798-0000 is now in state TASK_RUNNING
> I0417 22:38:07.945148 22845 slave.cpp:1793] Sending ACK for status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 to executor executor(15)@
> 67.195.138.60:35095
> I0417 22:38:07.946176 22841 sched.cpp:327] Received status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 from slave(39)@
> 67.195.138.60:35095
> I0417 22:38:07.966217 22846 exec.cpp:289] Executor received ACK for status
> update of task 0 of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.966678 22841 sched.cpp:360] Sending ACK for status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 to slave(39)@67.195.138.60:35095
> I0417 22:38:07.967290 22846 slave.cpp:2033] Executor 'default' of
> framework 201304172238-1015726915-35095-22798-0000 has exited with status 0'
> I0417 22:38:07.969040 22846 slave.cpp:1733] Handling status update
> TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.969205 22840 status_update_manager.cpp:289] Received status
> update TASK_LOST from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 with checkpoint=false
> I0417 22:38:07.969459 22840 status_update_manager.hpp:336] Handling UPDATE
> for status update TASK_LOST from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.969260 22841 master.cpp:1188] Executor default of framework
> 201304172238-1015726915-35095-22798-0000 on slave
> 201304172238-1015726915-35095-22798-0 (janus.apache.org) exited with
> status 0
> I0417 22:38:07.969244 22846 slave.cpp:1307] Got acknowledgement of status
> update for task 0 of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.970971 22841 status_update_manager.cpp:360] Received status
> update acknowledgement for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.971380 22841 status_update_manager.hpp:336] Handling ACK
> for status update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.971863 22841 status_update_manager.cpp:335] Forwarding
> status update TASK_LOST from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 to the master at
> master@67.195.138.60:35095
> I0417 22:38:07.970994 22846 slave.cpp:1793] Sending ACK for status update
> TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
> to executor executor(15)@67.195.138.60:35095
> I0417 22:38:07.972877 22846 slave.cpp:1344] Status update manager
> successfully handled status update acknowledgement for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.972408 22840 master.cpp:1086] Status update from (143)@
> 67.195.138.60:35095: task 0 of framework
> 201304172238-1015726915-35095-22798-0000 is now in state TASK_LOST
> I0417 22:38:07.974258 22840 master.hpp:300] Removing task with resources
> cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
> I0417 22:38:07.974269 22841 sched.cpp:327] Received status update
> TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
> from slave(39)@67.195.138.60:35095
> I0417 22:38:07.975208 22841 sched.cpp:360] Sending ACK for status update
> TASK_LOST from task 0 of framework 201304172238-1015726915-35095-22798-0000
> to slave(39)@67.195.138.60:35095
> I0417 22:38:07.974827 22842 hierarchical_allocator_process.hpp:544]
> Recovered cpus=2; mem=1024 (total allocatable: cpus=2; mem=1024;
> ports=[31000-32000]; disk=1024) on slave
> 201304172238-1015726915-35095-22798-0 from framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:07.976752 22841 slave.cpp:1307] Got acknowledgement of status
> update for task 0 of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.003599 22841 status_update_manager.cpp:360] Received status
> update acknowledgement for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.004009 22841 status_update_manager.hpp:336] Handling ACK
> for status update TASK_LOST from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.004479 22841 status_update_manager.cpp:482] Cleaning up
> status update stream for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.005007 22841 slave.cpp:1344] Status update manager
> successfully handled status update acknowledgement for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.005427 22841 slave.cpp:2168] Cleaning up executor 'default'
> of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.006052 22847 gc.cpp:56] Scheduling
> '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/9f5c7e9c-9501-4efa-92bf-eed129b161d0'
> for removal
> I0417 22:38:08.006485 22847 gc.cpp:56] Scheduling
> '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default'
> for removal
> I0417 22:38:08.006065 22841 slave.cpp:2231] Cleaning up framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.007387 22847 status_update_manager.cpp:251] Closing status
> update streams for framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.007453 22843 gc.cpp:56] Scheduling
> '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000'
> for removal
> I0417 22:38:08.007601 22846 hierarchical_allocator_process.hpp:660] Found
> available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on
> slave 201304172238-1015726915-35095-22798-0
> I0417 22:38:08.008838 22846 hierarchical_allocator_process.hpp:686]
> Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304172238-1015726915-35095-22798-0 to framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.009378 22846 hierarchical_allocator_process.hpp:599]
> Performed allocation for 1 slaves in 1.806216000000000ms
> I0417 22:38:08.009425 22843 master.hpp:309] Adding offer with resources
> cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:08.010241 22843 master.cpp:1327] Sending 1 offers to framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.010776 22843 sched.cpp:282] Received 1 offers
> I0417 22:38:08.011327 22843 master.cpp:1534] Processing reply for offer
> 201304172238-1015726915-35095-22798-1 on slave
> 201304172238-1015726915-35095-22798-0 (janus.apache.org) for framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.011744 22843 master.hpp:289] Adding task with resources
> cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
> I0417 22:38:08.016716 22843 master.cpp:1651] Launching task 0 of framework
> 201304172238-1015726915-35095-22798-0000 with resources cpus=2; mem=1024 on
> slave 201304172238-1015726915-35095-22798-0 (janus.apache.org)
> I0417 22:38:08.046468 22845 slave.cpp:719] Got assigned task 0 for
> framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.046489 22846 hierarchical_allocator_process.hpp:471]
> Framework 201304172238-1015726915-35095-22798-0000 left
> ports=[31000-32000]; disk=1024 unused on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:08.046490 22843 master.hpp:318] Removing offer with resources
> cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:08.047123 22845 gc.cpp:84] Unscheduling
> '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000'
> for removal
> I0417 22:38:08.047377 22846 hierarchical_allocator_process.hpp:497]
> Framework 201304172238-1015726915-35095-22798-0000 filtered slave
> 201304172238-1015726915-35095-22798-0 for 5.000000000000000secs
> I0417 22:38:08.048488 22844 gc.cpp:84] Unscheduling
> '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default'
> for removal
> I0417 22:38:08.049361 22841 slave.cpp:792] Launching task 0 for framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.050772 22841 paths.hpp:302] Created executor directory
> '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/c3227e94-478a-48d3-8614-0d2c92ac5ec0'
> I0417 22:38:08.050909 22841 slave.cpp:940] Queuing task '0' for executor
> default of framework '201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.090430 22841 slave.cpp:512] Successfully attached file
> '/tmp/GarbageCollectorIntegrationTest_Unschedule_6TZBP6/slaves/201304172238-1015726915-35095-22798-0/frameworks/201304172238-1015726915-35095-22798-0000/executors/default/runs/c3227e94-478a-48d3-8614-0d2c92ac5ec0'
> I0417 22:38:08.051069 22844 exec.cpp:170] Executor started at:
> executor(16)@67.195.138.60:35095 with pid 22798
> I0417 22:38:08.129813 22844 slave.cpp:1391] Got registration for executor
> 'default' of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.148749 22844 slave.cpp:1505] Flushing queued tasks for
> framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.148802 22841 exec.cpp:194] Executor registered on slave
> 201304172238-1015726915-35095-22798-0
> I0417 22:38:08.167788 22841 exec.cpp:258] Executor asked to run task '0'
> I0417 22:38:08.202324 22841 exec.cpp:382] Executor sending status update
> for task 0 in state TASK_RUNNING
> I0417 22:38:08.204095 22841 slave.cpp:1733] Handling status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.233724 22841 status_update_manager.cpp:289] Received status
> update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 with checkpoint=false
> I0417 22:38:08.234408 22841 status_update_manager.cpp:451] Creating
> StatusUpdate stream for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.263043 22841 status_update_manager.hpp:336] Handling UPDATE
> for status update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.263902 22841 status_update_manager.cpp:335] Forwarding
> status update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 to the master at
> master@67.195.138.60:35095
> I0417 22:38:08.300575 22840 slave.cpp:1793] Sending ACK for status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 to executor executor(16)@
> 67.195.138.60:35095
> I0417 22:38:08.300995 22840 exec.cpp:289] Executor received ACK for status
> update of task 0 of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.300576 22841 master.cpp:1086] Status update from (143)@
> 67.195.138.60:35095: task 0 of framework
> 201304172238-1015726915-35095-22798-0000 is now in state TASK_RUNNING
> I0417 22:38:08.301954 22841 sched.cpp:327] Received status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 from slave(39)@
> 67.195.138.60:35095
> I0417 22:38:08.302403 22841 sched.cpp:360] Sending ACK for status update
> TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000 to slave(39)@67.195.138.60:35095
> I0417 22:38:08.302870 22841 slave.cpp:1307] Got acknowledgement of status
> update for task 0 of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.303400 22841 status_update_manager.cpp:360] Received status
> update acknowledgement for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.303791 22841 status_update_manager.hpp:336] Handling ACK
> for status update TASK_RUNNING from task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.304297 22841 slave.cpp:1344] Status update manager
> successfully handled status update acknowledgement for task 0 of framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.309861 22798 master.cpp:477] Master terminating
> I0417 22:38:08.309921 22798 master.cpp:283] Shutting down master
> I0417 22:38:08.309866 22847 sched.cpp:422] Stopping framework
> '201304172238-1015726915-35095-22798-0000'
> I0417 22:38:08.309954 22845 slave.cpp:486] Slave asked to shut down by
> master@67.195.138.60:35095
> I0417 22:38:08.344889 22798 master.hpp:300] Removing task with resources
> cpus=2; mem=1024 on slave 201304172238-1015726915-35095-22798-0
> I0417 22:38:08.344926 22843 hierarchical_allocator_process.hpp:359]
> Deactivated framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.345803 22845 slave.cpp:1117] Asked to shut down framework
> 201304172238-1015726915-35095-22798-0000 by master@67.195.138.60:35095
> I0417 22:38:08.347337 22845 slave.cpp:1142] Shutting down framework
> 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.347870 22845 slave.cpp:2299] Shutting down executor
> 'default' of framework 201304172238-1015726915-35095-22798-0000
> I0417 22:38:08.348391 22845 slave.cpp:441] Slave terminating
> I0417 22:38:08.348906 22845 slave.cpp:1117] Asked to shut down framework
> 201304172238-1015726915-35095-22798-0000 by @0.0.0.0:0
> W0417 22:38:08.349412 22845 slave.cpp:1138] Ignoring shutdown framework
> 201304172238-1015726915-35095-22798-0000 because it is terminating
> I0417 22:38:08.348423 22841 exec.cpp:321] Executor asked to shutdown
> pure virtual method called
> terminate called without an active exception
> /bin/bash: line 5: 22798 Aborted                 ${dir}$tst
> FAIL: mesos-tests
> ==================
> 1 of 1 test failed
> ==================
> make[3]: *** [check-TESTS] Error 1
> make[3]: Leaving directory `<
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-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
> Build step 'Execute shell' marked build as failure
>

Build failed in Jenkins: Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #309

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/309/changes>

Changes:

[vinodkone] Fixed a bug in the status update manager to properly handle duplicate
ACK of an old update when waiting for the ACK of a new update.

Review: https://reviews.apache.org/r/10596

------------------------------------------
[...truncated 8742 lines...]
I0418 07:16:37.290413 17217 slave.cpp:792] Launching task 0 for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.290943 17215 hierarchical_allocator_process.hpp:497] Framework 201304180716-1015726915-45205-16494-0000 filtered slave 201304180716-1015726915-45205-16494-0 for 5.000000000000000secs
I0418 07:16:37.293324 17217 paths.hpp:302] Created executor directory '/tmp/GarbageCollectorIntegrationTest_DiskUsage_UBNhiy/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default/runs/c74b5dae-db62-4145-b75d-760238152c4a'
I0418 07:16:37.293535 17217 slave.cpp:940] Queuing task '0' for executor default of framework '201304180716-1015726915-45205-16494-0000
I0418 07:16:37.293751 17217 slave.cpp:512] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_DiskUsage_UBNhiy/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default/runs/c74b5dae-db62-4145-b75d-760238152c4a'
I0418 07:16:37.293669 17212 exec.cpp:170] Executor started at: executor(15)@67.195.138.60:45205 with pid 16494
I0418 07:16:37.294668 17212 slave.cpp:1397] Got registration for executor 'default' of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.295196 17212 slave.cpp:1511] Flushing queued tasks for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.295243 17214 exec.cpp:194] Executor registered on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.296180 17214 exec.cpp:258] Executor asked to run task '0'
I0418 07:16:37.296639 17214 exec.cpp:382] Executor sending status update for task 0 in state TASK_RUNNING
I0418 07:16:37.298332 17214 slave.cpp:1739] Handling status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.298466 17214 status_update_manager.cpp:289] Received status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 with checkpoint=false
I0418 07:16:37.298751 17214 status_update_manager.cpp:450] Creating StatusUpdate stream for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.299280 17214 status_update_manager.hpp:350] Handling UPDATE for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.299754 17214 status_update_manager.cpp:335] Forwarding status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 to the master at master@67.195.138.60:45205
I0418 07:16:37.301328 17215 master.cpp:1086] Status update from (143)@67.195.138.60:45205: task 0 of framework 201304180716-1015726915-45205-16494-0000 is now in state TASK_RUNNING
I0418 07:16:37.301355 17211 slave.cpp:1799] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 to executor executor(15)@67.195.138.60:45205
I0418 07:16:37.302654 17215 sched.cpp:327] Received status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 from slave(39)@67.195.138.60:45205
I0418 07:16:37.303622 17215 sched.cpp:360] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 to slave(39)@67.195.138.60:45205
I0418 07:16:37.303091 17217 exec.cpp:289] Executor received ACK for status update of task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.303877 17211 process.cpp:2922] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0418 07:16:37.304141 17218 slave.cpp:1307] Got acknowledgement of status update for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.305860 17218 status_update_manager.cpp:360] Received status update acknowledgement 30009419-5ba9-4c05-81d8-798fe23523bd for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.305866 17219 process.cpp:870] Socket closed while receiving
I0418 07:16:37.306226 17218 status_update_manager.hpp:350] Handling ACK for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.307450 17218 slave.cpp:1350] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.307798 17218 slave.cpp:2039] Executor 'default' of framework 201304180716-1015726915-45205-16494-0000 has exited with status '0'
I0418 07:16:37.309689 17218 slave.cpp:1739] Handling status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.309999 17218 master.cpp:1188] Executor default of framework 201304180716-1015726915-45205-16494-0000 on slave 201304180716-1015726915-45205-16494-0 (janus.apache.org) exited with status 0
I0418 07:16:37.310060 17214 status_update_manager.cpp:289] Received status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000 with checkpoint=false
I0418 07:16:37.311444 17214 status_update_manager.hpp:350] Handling UPDATE for status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.312294 17214 status_update_manager.cpp:335] Forwarding status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000 to the master at master@67.195.138.60:45205
I0418 07:16:37.313225 17211 master.cpp:1086] Status update from (143)@67.195.138.60:45205: task 0 of framework 201304180716-1015726915-45205-16494-0000 is now in state TASK_LOST
I0418 07:16:37.313292 17216 slave.cpp:1799] Sending ACK for status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000 to executor executor(15)@67.195.138.60:45205
I0418 07:16:37.314069 17211 master.hpp:300] Removing task with resources cpus=2; mem=1024 on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.314084 17212 sched.cpp:327] Received status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000 from slave(39)@67.195.138.60:45205
I0418 07:16:37.315444 17213 hierarchical_allocator_process.hpp:544] Recovered cpus=2; mem=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304180716-1015726915-45205-16494-0 from framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.315984 17212 sched.cpp:360] Sending ACK for status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000 to slave(39)@67.195.138.60:45205
I0418 07:16:37.317596 17211 slave.cpp:1307] Got acknowledgement of status update for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.318403 17212 status_update_manager.cpp:360] Received status update acknowledgement c15adb49-4048-415d-a352-934bad4492d3 for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.319119 17212 status_update_manager.hpp:350] Handling ACK for status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.319926 17212 status_update_manager.cpp:481] Cleaning up status update stream for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.320802 17212 slave.cpp:1350] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.321441 17212 slave.cpp:2174] Cleaning up executor 'default' of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.322407 17211 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_UBNhiy/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default/runs/c74b5dae-db62-4145-b75d-760238152c4a' for removal
I0418 07:16:37.322476 17212 slave.cpp:2237] Cleaning up framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.348384 17211 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_UBNhiy/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default' for removal
I0418 07:16:37.349144 17214 status_update_manager.cpp:251] Closing status update streams for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.350582 17211 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_UBNhiy/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000' for removal
I0418 07:16:37.352890 17216 slave.cpp:2486] Current disk usage 100.00%. Max allowed age: 0.000000000000000ns
I0418 07:16:37.353041 17211 gc.cpp:167] Pruning directories with remaining removal time 1.000000000000000weeks
I0418 07:16:37.353345 17211 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_UBNhiy/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default/runs/c74b5dae-db62-4145-b75d-760238152c4a
I0418 07:16:37.353888 17211 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_UBNhiy/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default/runs/c74b5dae-db62-4145-b75d-760238152c4a'
I0418 07:16:37.354444 17211 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_UBNhiy/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default
I0418 07:16:37.355499 17211 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_UBNhiy/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default'
I0418 07:16:37.355934 17211 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_UBNhiy/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000
I0418 07:16:37.357035 17211 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_UBNhiy/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000'
I0418 07:16:37.363436 17216 process.cpp:2922] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0418 07:16:37.364131 17219 process.cpp:870] Socket closed while receiving
I0418 07:16:37.364555 16494 master.cpp:477] Master terminating
I0418 07:16:37.364575 17212 sched.cpp:422] Stopping framework '201304180716-1015726915-45205-16494-0000'
I0418 07:16:37.364645 16494 master.cpp:283] Shutting down master
I0418 07:16:37.364687 17211 slave.cpp:486] Slave asked to shut down by master@67.195.138.60:45205
I0418 07:16:37.366152 17211 slave.cpp:441] Slave terminating
I0418 07:16:37.365638 17215 hierarchical_allocator_process.hpp:359] Deactivated framework 201304180716-1015726915-45205-16494-0000
[       OK ] GarbageCollectorIntegrationTest.DiskUsage (156 ms)
[ RUN      ] GarbageCollectorIntegrationTest.Unschedule
I0418 07:16:37.368106 17212 master.cpp:309] Master started on 67.195.138.60:45205
I0418 07:16:37.368151 17212 master.cpp:324] Master ID: 201304180716-1015726915-45205-16494
I0418 07:16:37.368768 17216 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : master@67.195.138.60:45205
W0418 07:16:37.368801 17217 master.cpp:81] No whitelist given. Advertising offers for all slaves
I0418 07:16:37.368827 17212 master.cpp:603] Elected as master!
I0418 07:16:37.368829 17218 slave.cpp:210] Slave started on 40)@67.195.138.60:45205
I0418 07:16:37.370579 17218 slave.cpp:211] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0418 07:16:37.371526 17218 slave.cpp:530] New master detected at master@67.195.138.60:45205
I0418 07:16:37.371636 17218 slave.cpp:545] Postponing registration until recovery is complete
I0418 07:16:37.372167 17218 slave.cpp:391] Finished recovery
I0418 07:16:37.371650 17217 status_update_manager.cpp:154] New master detected at master@67.195.138.60:45205
I0418 07:16:37.372736 17212 master.cpp:968] Attempting to register slave on janus.apache.org at slave(40)@67.195.138.60:45205
I0418 07:16:37.373797 17212 master.cpp:1224] Master now considering a slave at janus.apache.org:45205 as active
I0418 07:16:37.374307 17212 master.cpp:1862] Adding slave 201304180716-1015726915-45205-16494-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0418 07:16:37.374884 17218 slave.cpp:590] Registered with master master@67.195.138.60:45205; given slave ID 201304180716-1015726915-45205-16494-0
I0418 07:16:37.374953 17213 hierarchical_allocator_process.hpp:395] Added slave 201304180716-1015726915-45205-16494-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)
I0418 07:16:37.375886 17213 hierarchical_allocator_process.hpp:632] No users to allocate resources!
I0418 07:16:37.376425 17213 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304180716-1015726915-45205-16494-0 in 537.524000000000115us
I0418 07:16:37.375376 17214 sched.cpp:182] New master at master@67.195.138.60:45205
I0418 07:16:37.377634 17218 master.cpp:646] Registering framework 201304180716-1015726915-45205-16494-0000 at scheduler(31)@67.195.138.60:45205
I0418 07:16:37.378001 17218 sched.cpp:217] Framework registered with 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.378041 17214 hierarchical_allocator_process.hpp:268] Added framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.378964 17214 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.379433 17214 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304180716-1015726915-45205-16494-0 to framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.380033 17214 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 1.081115000000000ms
I0418 07:16:37.380075 17218 master.hpp:309] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.413480 17218 master.cpp:1327] Sending 1 offers to framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.414785 17217 sched.cpp:282] Received 1 offers
I0418 07:16:37.423296 17218 master.cpp:1534] Processing reply for offer 201304180716-1015726915-45205-16494-0 on slave 201304180716-1015726915-45205-16494-0 (janus.apache.org) for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.423748 17218 master.hpp:289] Adding task with resources cpus=2; mem=1024 on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.424221 17218 master.cpp:1651] Launching task 0 of framework 201304180716-1015726915-45205-16494-0000 with resources cpus=2; mem=1024 on slave 201304180716-1015726915-45205-16494-0 (janus.apache.org)
I0418 07:16:37.424900 17217 slave.cpp:719] Got assigned task 0 for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.424934 17213 hierarchical_allocator_process.hpp:471] Framework 201304180716-1015726915-45205-16494-0000 left ports=[31000-32000]; disk=1024 unused on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.424938 17218 master.hpp:318] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.425508 17217 slave.cpp:792] Launching task 0 for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.425993 17213 hierarchical_allocator_process.hpp:497] Framework 201304180716-1015726915-45205-16494-0000 filtered slave 201304180716-1015726915-45205-16494-0 for 5.000000000000000secs
I0418 07:16:37.428192 17217 paths.hpp:302] Created executor directory '/tmp/GarbageCollectorIntegrationTest_Unschedule_VGAsYN/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default/runs/9bdef11a-e156-479e-ab56-24a4824ca990'
I0418 07:16:37.428315 17217 slave.cpp:940] Queuing task '0' for executor default of framework '201304180716-1015726915-45205-16494-0000
I0418 07:16:37.428627 17217 slave.cpp:512] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_Unschedule_VGAsYN/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default/runs/9bdef11a-e156-479e-ab56-24a4824ca990'
I0418 07:16:37.428428 17212 exec.cpp:170] Executor started at: executor(16)@67.195.138.60:45205 with pid 16494
I0418 07:16:37.430233 17212 slave.cpp:1397] Got registration for executor 'default' of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.430758 17212 slave.cpp:1511] Flushing queued tasks for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.430794 17215 exec.cpp:194] Executor registered on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.431730 17215 exec.cpp:258] Executor asked to run task '0'
I0418 07:16:37.432255 17215 exec.cpp:382] Executor sending status update for task 0 in state TASK_RUNNING
I0418 07:16:37.433987 17218 slave.cpp:1739] Handling status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.434098 17218 status_update_manager.cpp:289] Received status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 with checkpoint=false
I0418 07:16:37.434370 17218 status_update_manager.cpp:450] Creating StatusUpdate stream for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.434905 17218 status_update_manager.hpp:350] Handling UPDATE for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.435384 17218 status_update_manager.cpp:335] Forwarding status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 to the master at master@67.195.138.60:45205
I0418 07:16:37.435924 17216 master.cpp:1086] Status update from (147)@67.195.138.60:45205: task 0 of framework 201304180716-1015726915-45205-16494-0000 is now in state TASK_RUNNING
I0418 07:16:37.435930 17218 slave.cpp:1799] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 to executor executor(16)@67.195.138.60:45205
I0418 07:16:37.436420 17215 sched.cpp:327] Received status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 from slave(40)@67.195.138.60:45205
I0418 07:16:37.437386 17215 sched.cpp:360] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 to slave(40)@67.195.138.60:45205
I0418 07:16:37.438122 17213 slave.cpp:1307] Got acknowledgement of status update for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.438467 17213 status_update_manager.cpp:360] Received status update acknowledgement 25011e6f-ed76-491b-8a32-f5c148b4fad5 for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.438892 17213 status_update_manager.hpp:350] Handling ACK for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.439435 17213 slave.cpp:1350] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.436868 17216 exec.cpp:289] Executor received ACK for status update of task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.440436 17218 slave.cpp:2039] Executor 'default' of framework 201304180716-1015726915-45205-16494-0000 has exited with status '0'
I0418 07:16:37.442150 17218 slave.cpp:1739] Handling status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.442304 17218 status_update_manager.cpp:289] Received status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000 with checkpoint=false
I0418 07:16:37.442514 17218 status_update_manager.hpp:350] Handling UPDATE for status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.443022 17218 status_update_manager.cpp:335] Forwarding status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000 to the master at master@67.195.138.60:45205
I0418 07:16:37.443589 17218 slave.cpp:1799] Sending ACK for status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000 to executor executor(16)@67.195.138.60:45205
I0418 07:16:37.442324 17214 master.cpp:1188] Executor default of framework 201304180716-1015726915-45205-16494-0000 on slave 201304180716-1015726915-45205-16494-0 (janus.apache.org) exited with status 0
I0418 07:16:37.444607 17214 master.cpp:1086] Status update from (147)@67.195.138.60:45205: task 0 of framework 201304180716-1015726915-45205-16494-0000 is now in state TASK_LOST
I0418 07:16:37.445049 17214 master.hpp:300] Removing task with resources cpus=2; mem=1024 on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.445061 17213 sched.cpp:327] Received status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000 from slave(40)@67.195.138.60:45205
I0418 07:16:37.446055 17213 sched.cpp:360] Sending ACK for status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000 to slave(40)@67.195.138.60:45205
I0418 07:16:37.445598 17216 hierarchical_allocator_process.hpp:544] Recovered cpus=2; mem=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304180716-1015726915-45205-16494-0 from framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.446547 17214 slave.cpp:1307] Got acknowledgement of status update for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.447603 17214 status_update_manager.cpp:360] Received status update acknowledgement 255009fb-0291-46b0-bf02-72026670e96a for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.448024 17214 status_update_manager.hpp:350] Handling ACK for status update TASK_LOST from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.449015 17214 status_update_manager.cpp:481] Cleaning up status update stream for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.449509 17214 slave.cpp:1350] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.449957 17214 slave.cpp:2174] Cleaning up executor 'default' of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.450558 17214 slave.cpp:2237] Cleaning up framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.451005 17212 status_update_manager.cpp:251] Closing status update streams for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.450567 17215 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_VGAsYN/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default/runs/9bdef11a-e156-479e-ab56-24a4824ca990' for removal
I0418 07:16:37.452321 17215 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_VGAsYN/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default' for removal
I0418 07:16:37.452803 17215 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_VGAsYN/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000' for removal
I0418 07:16:37.452921 17212 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.455879 17212 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304180716-1015726915-45205-16494-0 to framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.456483 17212 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 3.574621000000000ms
I0418 07:16:37.456537 17215 master.hpp:309] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.490437 17215 master.cpp:1327] Sending 1 offers to framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.491746 17215 sched.cpp:282] Received 1 offers
I0418 07:16:37.493075 17215 master.cpp:1534] Processing reply for offer 201304180716-1015726915-45205-16494-1 on slave 201304180716-1015726915-45205-16494-0 (janus.apache.org) for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.497746 17215 master.hpp:289] Adding task with resources cpus=2; mem=1024 on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.498929 17215 master.cpp:1651] Launching task 0 of framework 201304180716-1015726915-45205-16494-0000 with resources cpus=2; mem=1024 on slave 201304180716-1015726915-45205-16494-0 (janus.apache.org)
I0418 07:16:37.500180 17215 master.hpp:318] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.500282 17218 hierarchical_allocator_process.hpp:471] Framework 201304180716-1015726915-45205-16494-0000 left ports=[31000-32000]; disk=1024 unused on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.500298 17211 slave.cpp:719] Got assigned task 0 for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.505596 17218 hierarchical_allocator_process.hpp:497] Framework 201304180716-1015726915-45205-16494-0000 filtered slave 201304180716-1015726915-45205-16494-0 for 5.000000000000000secs
I0418 07:16:37.506443 17211 gc.cpp:84] Unscheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_VGAsYN/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000' for removal
I0418 07:16:37.507362 17211 gc.cpp:84] Unscheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_VGAsYN/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default' for removal
I0418 07:16:37.507830 17211 slave.cpp:792] Launching task 0 for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.510072 17211 paths.hpp:302] Created executor directory '/tmp/GarbageCollectorIntegrationTest_Unschedule_VGAsYN/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default/runs/4790a0bc-a377-49a2-b9eb-58a589e695a7'
I0418 07:16:37.510252 17211 slave.cpp:940] Queuing task '0' for executor default of framework '201304180716-1015726915-45205-16494-0000
I0418 07:16:37.510499 17211 slave.cpp:512] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_Unschedule_VGAsYN/slaves/201304180716-1015726915-45205-16494-0/frameworks/201304180716-1015726915-45205-16494-0000/executors/default/runs/4790a0bc-a377-49a2-b9eb-58a589e695a7'
I0418 07:16:37.510397 17216 exec.cpp:170] Executor started at: executor(17)@67.195.138.60:45205 with pid 16494
I0418 07:16:37.512166 17216 slave.cpp:1397] Got registration for executor 'default' of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.512681 17216 slave.cpp:1511] Flushing queued tasks for framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.512763 17211 exec.cpp:194] Executor registered on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.513721 17211 exec.cpp:258] Executor asked to run task '0'
I0418 07:16:37.514224 17211 exec.cpp:382] Executor sending status update for task 0 in state TASK_RUNNING
I0418 07:16:37.516043 17211 slave.cpp:1739] Handling status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.520176 17211 status_update_manager.cpp:289] Received status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 with checkpoint=false
I0418 07:16:37.521855 17211 status_update_manager.cpp:450] Creating StatusUpdate stream for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.523046 17211 status_update_manager.hpp:350] Handling UPDATE for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.524006 17211 status_update_manager.cpp:335] Forwarding status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 to the master at master@67.195.138.60:45205
I0418 07:16:37.524929 17211 master.cpp:1086] Status update from (147)@67.195.138.60:45205: task 0 of framework 201304180716-1015726915-45205-16494-0000 is now in state TASK_RUNNING
I0418 07:16:37.524986 17215 slave.cpp:1799] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 to executor executor(17)@67.195.138.60:45205
I0418 07:16:37.526214 17214 exec.cpp:289] Executor received ACK for status update of task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.525760 17211 sched.cpp:327] Received status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 from slave(40)@67.195.138.60:45205
I0418 07:16:37.527286 17211 sched.cpp:360] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000 to slave(40)@67.195.138.60:45205
I0418 07:16:37.527956 17215 slave.cpp:1307] Got acknowledgement of status update for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.529233 17215 status_update_manager.cpp:360] Received status update acknowledgement 36ee8808-a571-46fd-bb07-5987341ca7a2 for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.530756 17215 status_update_manager.hpp:350] Handling ACK for status update TASK_RUNNING from task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.532199 17211 slave.cpp:1350] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.543370 16494 master.cpp:477] Master terminating
I0418 07:16:37.543483 16494 master.cpp:283] Shutting down master
I0418 07:16:37.543840 17213 hierarchical_allocator_process.hpp:359] Deactivated framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.543390 17217 sched.cpp:422] Stopping framework '201304180716-1015726915-45205-16494-0000'
I0418 07:16:37.543846 16494 master.hpp:300] Removing task with resources cpus=2; mem=1024 on slave 201304180716-1015726915-45205-16494-0
I0418 07:16:37.543536 17218 slave.cpp:486] Slave asked to shut down by master@67.195.138.60:45205
I0418 07:16:37.546010 17218 slave.cpp:1117] Asked to shut down framework 201304180716-1015726915-45205-16494-0000 by master@67.195.138.60:45205
I0418 07:16:37.561247 17218 slave.cpp:1142] Shutting down framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.561872 17218 slave.cpp:2305] Shutting down executor 'default' of framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.545367 17212 hierarchical_allocator_process.hpp:544] Recovered cpus=2; mem=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304180716-1015726915-45205-16494-0 from framework 201304180716-1015726915-45205-16494-0000
I0418 07:16:37.562427 17218 slave.cpp:1874] master@67.195.138.60:45205 exited
W0418 07:16:37.564131 17218 slave.cpp:1877] Master disconnected! Waiting for a new master to be elected
I0418 07:16:37.564851 17218 slave.cpp:441] Slave terminating
I0418 07:16:37.565737 17218 slave.cpp:1117] Asked to shut down framework 201304180716-1015726915-45205-16494-0000 by @0.0.0.0:0
W0418 07:16:37.566270 17218 slave.cpp:1138] Ignoring shutdown framework 201304180716-1015726915-45205-16494-0000 because it is terminating
[       OK ] GarbageCollectorIntegrationTest.Unschedule (200 ms)
[----------] 5 tests from GarbageCollectorIntegrationTest (1008 ms total)

[----------] 8 tests from ResourceOffersTest
[ RUN      ] ResourceOffersTest.ResourceOfferWithMultipleSlaves
I0418 07:16:37.562449 17216 exec.cpp:321] Executor asked to shutdown
I0418 07:16:37.570739 17215 master.cpp:309] Master started on 67.195.138.60:45205
I0418 07:16:37.570962 17215 master.cpp:324] Master ID: 201304180716-1015726915-45205-16494
I0418 07:16:37.570878 17213 slave.cpp:210] Slave started on 43)@67.195.138.60:45205
I0418 07:16:37.570869 17217 slave.cpp:210] Slave started on 41)@67.195.138.60:45205
I0418 07:16:37.572803 17217 slave.cpp:211] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0418 07:16:37.570932 17218 slave.cpp:210] Slave started on 45)@67.195.138.60:45205
I0418 07:16:37.570852 17214 slave.cpp:210] Slave started on 42)@67.195.138.60:45205
I0418 07:16:37.570994 17211 slave.cpp:210] Slave started on 46)@67.195.138.60:45205
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x0000000001ad4e90, pid=16494, tid=47304309556992
#
# JRE version: 6.0_20-b02
# Java VM: Java HotSpot(TM) 64-Bit Server VM (16.3-b01 mixed mode linux-amd64 )
# Problematic frame:
# C  0x0000000001ad4e90
#
# An error report file with more information is saved as:
# <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src/hs_err_pid16494.log>
I0418 07:16:37.576920 17211 slave.cpp:211] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
#
# If you would like to submit a bug report, please visit:
#   http://java.sun.com/webapps/bugreport/crash.jsp
#
I0418 07:16:37.571655 17213 slave.cpp:211] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
/bin/bash: line 5: 16494 Aborted                 ${dir}$tst
FAIL: mesos-tests
==================
1 of 1 test failed
==================
make[3]: *** [check-TESTS] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-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
Build step 'Execute shell' marked build as failure