See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/315/changes>
Changes: [vinodkone] Fixed the slave to do disk usage calculations on the filesystem on which the slave work directory is mounted. Review: https://reviews.apache.org/r/10661 [vinodkone] Fixed master to consolidate tasks upon slave re-registration. Review: https://reviews.apache.org/r/10724 [vinodkone] Cleaned up logging in slave, status update manager and executor driver. Review: https://reviews.apache.org/r/10708 ------------------------------------------ [...truncated 8795 lines...] I0427 05:29:48.326751 3958 slave.cpp:488] Slave asked to shut down by [email protected]:47553 I0427 05:29:48.328047 3958 slave.cpp:443] Slave terminating I0427 05:29:48.327203 3952 hierarchical_allocator_process.hpp:359] Deactivated framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.326030 3956 sched.cpp:422] Stopping framework '201304270529-1015726915-47553-3718-0000' [ OK ] GarbageCollectorIntegrationTest.ExitedExecutor (70 ms) [ RUN ] GarbageCollectorIntegrationTest.DiskUsage I0427 05:29:48.330303 3952 master.cpp:311] Master started on 67.195.138.60:47553 I0427 05:29:48.330414 3952 master.cpp:326] Master ID: 201304270529-1015726915-47553-3718 I0427 05:29:48.330782 3959 slave.cpp:212] Slave started on 40)@67.195.138.60:47553 I0427 05:29:48.331260 3953 sched.cpp:182] New master at [email protected]:47553 W0427 05:29:48.331290 3955 master.cpp:83] No whitelist given. Advertising offers for all slaves I0427 05:29:48.331341 3958 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : [email protected]:47553 I0427 05:29:48.331488 3952 master.cpp:605] Elected as master! I0427 05:29:48.334235 3952 master.cpp:648] Registering framework 201304270529-1015726915-47553-3718-0000 at scheduler(31)@67.195.138.60:47553 I0427 05:29:48.331634 3959 slave.cpp:213] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0427 05:29:48.335474 3952 hierarchical_allocator_process.hpp:268] Added framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.335486 3957 sched.cpp:217] Framework registered with 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.336483 3959 slave.cpp:532] New master detected at [email protected]:47553 I0427 05:29:48.336508 3952 hierarchical_allocator_process.hpp:668] No resources available to allocate! I0427 05:29:48.337949 3952 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 1.442402000000000ms I0427 05:29:48.337527 3958 status_update_manager.cpp:154] New master detected at [email protected]:47553 I0427 05:29:48.337493 3959 slave.cpp:547] Postponing registration until recovery is complete I0427 05:29:48.339664 3959 slave.cpp:393] Finished recovery I0427 05:29:48.340198 3959 master.cpp:970] Attempting to register slave on janus.apache.org at slave(40)@67.195.138.60:47553 I0427 05:29:48.340600 3959 master.cpp:1272] Master now considering a slave at janus.apache.org:47553 as active I0427 05:29:48.341070 3959 master.cpp:1938] Adding slave 201304270529-1015726915-47553-3718-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0427 05:29:48.341608 3959 slave.cpp:592] Registered with master [email protected]:47553; given slave ID 201304270529-1015726915-47553-3718-0 I0427 05:29:48.341682 3956 hierarchical_allocator_process.hpp:395] Added slave 201304270529-1015726915-47553-3718-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) I0427 05:29:48.342587 3956 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.343047 3956 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 to framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.344496 3956 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304270529-1015726915-47553-3718-0 in 1.922335000000000ms I0427 05:29:48.344524 3959 master.hpp:311] Adding offer 201304270529-1015726915-47553-3718-0 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.345417 3959 master.cpp:1375] Sending 1 offers to framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.345916 3957 sched.cpp:282] Received 1 offers I0427 05:29:48.346488 3959 master.cpp:1608] Processing reply for offer 201304270529-1015726915-47553-3718-0 on slave 201304270529-1015726915-47553-3718-0 (janus.apache.org) for framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.346884 3959 master.hpp:289] Adding task 0 with resources cpus=2; mem=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.347390 3959 master.cpp:1727] Launching task 0 of framework 201304270529-1015726915-47553-3718-0000 with resources cpus=2; mem=1024 on slave 201304270529-1015726915-47553-3718-0 (janus.apache.org) I0427 05:29:48.347911 3957 slave.cpp:721] Got assigned task 0 for framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.347949 3952 hierarchical_allocator_process.hpp:471] Framework 201304270529-1015726915-47553-3718-0000 left ports=[31000-32000]; disk=1024 unused on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.349160 3952 hierarchical_allocator_process.hpp:497] Framework 201304270529-1015726915-47553-3718-0000 filtered slave 201304270529-1015726915-47553-3718-0 for 5.000000000000000secs I0427 05:29:48.348549 3957 slave.cpp:819] Launching task 0 for framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.347965 3959 master.hpp:321] Removing offer 201304270529-1015726915-47553-3718-0 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.352440 3957 paths.hpp:302] Created executor directory '/tmp/GarbageCollectorIntegrationTest_DiskUsage_kngotR/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default/runs/693c061b-b2bb-4717-b2aa-9b7f7bfc8ad4' I0427 05:29:48.352628 3957 slave.cpp:930] Queuing task '0' for executor default of framework '201304270529-1015726915-47553-3718-0000 I0427 05:29:48.353600 3957 slave.cpp:514] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_DiskUsage_kngotR/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default/runs/693c061b-b2bb-4717-b2aa-9b7f7bfc8ad4' I0427 05:29:48.352783 3959 exec.cpp:170] Executor started at: executor(16)@67.195.138.60:47553 with pid 3718 I0427 05:29:48.354542 3959 slave.cpp:1382] Got registration for executor 'default' of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.355049 3959 slave.cpp:1497] Flushing queued task 0 for executor 'default' of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.355069 3952 exec.cpp:194] Executor registered on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.356883 3952 exec.cpp:258] Executor asked to run task '0' I0427 05:29:48.358541 3952 exec.cpp:404] Executor sending status update TASK_RUNNING (UUID: ca527cff-46d4-4058-b8da-d565f6284306) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.358603 3952 slave.cpp:1726] Handling status update TASK_RUNNING (UUID: ca527cff-46d4-4058-b8da-d565f6284306) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.359011 3955 status_update_manager.cpp:289] Received status update TASK_RUNNING (UUID: ca527cff-46d4-4058-b8da-d565f6284306) for task 0 of framework 201304270529-1015726915-47553-3718-0000 with checkpoint=false I0427 05:29:48.359417 3955 status_update_manager.cpp:449] Creating StatusUpdate stream for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.359959 3955 status_update_manager.cpp:335] Forwarding status update TASK_RUNNING (UUID: ca527cff-46d4-4058-b8da-d565f6284306) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to [email protected]:47553 I0427 05:29:48.360445 3953 master.cpp:1134] Status update from (147)@67.195.138.60:47553: task 0 of framework 201304270529-1015726915-47553-3718-0000 is now in state TASK_RUNNING I0427 05:29:48.360503 3955 slave.cpp:1783] Status update manager successfully handled status update TASK_RUNNING (UUID: ca527cff-46d4-4058-b8da-d565f6284306) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.361362 3955 slave.cpp:1789] Sending acknowledgement for status update TASK_RUNNING (UUID: ca527cff-46d4-4058-b8da-d565f6284306) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to executor(16)@67.195.138.60:47553 I0427 05:29:48.360963 3952 sched.cpp:327] Received status update TASK_RUNNING (UUID: ca527cff-46d4-4058-b8da-d565f6284306) for task 0 of framework 201304270529-1015726915-47553-3718-0000 from slave(40)@67.195.138.60:47553 I0427 05:29:48.361888 3953 exec.cpp:290] Executor received status update acknowledgement �R|�F�@X���e�(C for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.362433 3952 sched.cpp:360] Sending ACK for status update TASK_RUNNING (UUID: ca527cff-46d4-4058-b8da-d565f6284306) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to slave(40)@67.195.138.60:47553 I0427 05:29:48.362656 3959 process.cpp:2921] Handling HTTP event for process 'files' with path: '/files/browse.json' I0427 05:29:48.363471 3955 status_update_manager.cpp:359] Received status update acknowledgement ca527cff-46d4-4058-b8da-d565f6284306 for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.364508 3960 process.cpp:870] Socket closed while receiving I0427 05:29:48.364686 3955 slave.cpp:1332] Status update manager successfully handled status update acknowledgement ca527cff-46d4-4058-b8da-d565f6284306 for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.365829 3955 slave.cpp:2031] Executor 'default' of framework 201304270529-1015726915-47553-3718-0000 has exited with status '0' I0427 05:29:48.367409 3955 slave.cpp:1726] Handling status update TASK_LOST (UUID: 639c1330-be0e-4211-82fe-eab5d326f569) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.367652 3958 status_update_manager.cpp:289] Received status update TASK_LOST (UUID: 639c1330-be0e-4211-82fe-eab5d326f569) for task 0 of framework 201304270529-1015726915-47553-3718-0000 with checkpoint=false I0427 05:29:48.367914 3952 master.cpp:1236] Executor default of framework 201304270529-1015726915-47553-3718-0000 on slave 201304270529-1015726915-47553-3718-0 (janus.apache.org) exited with status 0 I0427 05:29:48.368437 3958 status_update_manager.cpp:335] Forwarding status update TASK_LOST (UUID: 639c1330-be0e-4211-82fe-eab5d326f569) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to [email protected]:47553 I0427 05:29:48.369369 3958 slave.cpp:1783] Status update manager successfully handled status update TASK_LOST (UUID: 639c1330-be0e-4211-82fe-eab5d326f569) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.369372 3957 master.cpp:1134] Status update from (147)@67.195.138.60:47553: task 0 of framework 201304270529-1015726915-47553-3718-0000 is now in state TASK_LOST I0427 05:29:48.369758 3958 slave.cpp:1789] Sending acknowledgement for status update TASK_LOST (UUID: 639c1330-be0e-4211-82fe-eab5d326f569) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to executor(16)@67.195.138.60:47553 I0427 05:29:48.370329 3957 master.hpp:301] Removing task 0 with resources cpus=2; mem=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.370340 3954 sched.cpp:327] Received status update TASK_LOST (UUID: 639c1330-be0e-4211-82fe-eab5d326f569) for task 0 of framework 201304270529-1015726915-47553-3718-0000 from slave(40)@67.195.138.60:47553 I0427 05:29:48.371395 3955 hierarchical_allocator_process.hpp:544] Recovered cpus=2; mem=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304270529-1015726915-47553-3718-0 from framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.371810 3954 sched.cpp:360] Sending ACK for status update TASK_LOST (UUID: 639c1330-be0e-4211-82fe-eab5d326f569) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to slave(40)@67.195.138.60:47553 I0427 05:29:48.373071 3954 status_update_manager.cpp:359] Received status update acknowledgement 639c1330-be0e-4211-82fe-eab5d326f569 for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.373451 3954 status_update_manager.cpp:480] Cleaning up status update stream for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.373970 3954 slave.cpp:1332] Status update manager successfully handled status update acknowledgement 639c1330-be0e-4211-82fe-eab5d326f569 for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.374446 3954 slave.cpp:2166] Cleaning up executor 'default' of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.375108 3959 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_kngotR/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default/runs/693c061b-b2bb-4717-b2aa-9b7f7bfc8ad4' for removal I0427 05:29:48.375489 3959 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_kngotR/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default' for removal I0427 05:29:48.375154 3954 slave.cpp:2230] Cleaning up framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.377148 3959 status_update_manager.cpp:251] Closing status update streams for framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.377192 3953 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_kngotR/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000' for removal I0427 05:29:48.385491 3957 slave.cpp:2482] Current disk usage 100.00%. Max allowed age: 0.000000000000000ns I0427 05:29:48.385591 3952 gc.cpp:167] Pruning directories with remaining removal time 1.000000000000000weeks I0427 05:29:48.385938 3952 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_kngotR/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default/runs/693c061b-b2bb-4717-b2aa-9b7f7bfc8ad4 I0427 05:29:48.386874 3952 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_kngotR/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default/runs/693c061b-b2bb-4717-b2aa-9b7f7bfc8ad4' I0427 05:29:48.387315 3952 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_kngotR/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default I0427 05:29:48.387814 3952 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_kngotR/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default' I0427 05:29:48.388223 3952 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_kngotR/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000 I0427 05:29:48.388782 3952 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_kngotR/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000' I0427 05:29:48.395747 3955 process.cpp:2921] Handling HTTP event for process 'files' with path: '/files/browse.json' I0427 05:29:48.396363 3960 process.cpp:870] Socket closed while receiving I0427 05:29:48.397335 3952 sched.cpp:422] Stopping framework '201304270529-1015726915-47553-3718-0000' I0427 05:29:48.397342 3718 master.cpp:479] Master terminating I0427 05:29:48.397790 3718 master.cpp:285] Shutting down master I0427 05:29:48.398305 3959 hierarchical_allocator_process.hpp:359] Deactivated framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.397810 3956 slave.cpp:488] Slave asked to shut down by [email protected]:47553 I0427 05:29:48.399226 3956 slave.cpp:443] Slave terminating [ OK ] GarbageCollectorIntegrationTest.DiskUsage (71 ms) [ RUN ] GarbageCollectorIntegrationTest.Unschedule I0427 05:29:48.401166 3954 master.cpp:311] Master started on 67.195.138.60:47553 I0427 05:29:48.401206 3956 slave.cpp:212] Slave started on 41)@67.195.138.60:47553 I0427 05:29:48.401751 3956 slave.cpp:213] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0427 05:29:48.401247 3954 master.cpp:326] Master ID: 201304270529-1015726915-47553-3718 I0427 05:29:48.402722 3956 slave.cpp:532] New master detected at [email protected]:47553 I0427 05:29:48.403167 3956 slave.cpp:547] Postponing registration until recovery is complete I0427 05:29:48.402993 3958 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : [email protected]:47553 I0427 05:29:48.403199 3953 status_update_manager.cpp:154] New master detected at [email protected]:47553 W0427 05:29:48.402971 3952 master.cpp:83] No whitelist given. Advertising offers for all slaves I0427 05:29:48.403658 3956 slave.cpp:393] Finished recovery I0427 05:29:48.403801 3954 master.cpp:605] Elected as master! I0427 05:29:48.406949 3954 master.cpp:970] Attempting to register slave on janus.apache.org at slave(41)@67.195.138.60:47553 I0427 05:29:48.407362 3954 master.cpp:1272] Master now considering a slave at janus.apache.org:47553 as active I0427 05:29:48.407866 3954 master.cpp:1938] Adding slave 201304270529-1015726915-47553-3718-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 I0427 05:29:48.408471 3959 slave.cpp:592] Registered with master [email protected]:47553; given slave ID 201304270529-1015726915-47553-3718-0 I0427 05:29:48.408491 3954 hierarchical_allocator_process.hpp:395] Added slave 201304270529-1015726915-47553-3718-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) I0427 05:29:48.408993 3958 sched.cpp:182] New master at [email protected]:47553 I0427 05:29:48.409359 3954 hierarchical_allocator_process.hpp:632] No users to allocate resources! I0427 05:29:48.410810 3957 master.cpp:648] Registering framework 201304270529-1015726915-47553-3718-0000 at scheduler(32)@67.195.138.60:47553 I0427 05:29:48.411142 3954 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304270529-1015726915-47553-3718-0 in 1.782723000000000ms I0427 05:29:48.412163 3954 hierarchical_allocator_process.hpp:268] Added framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.412678 3954 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.413152 3954 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 to framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.413743 3954 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 1.077742000000000ms I0427 05:29:48.411691 3958 sched.cpp:217] Framework registered with 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.413806 3952 master.hpp:311] Adding offer 201304270529-1015726915-47553-3718-0 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.415395 3952 master.cpp:1375] Sending 1 offers to framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.415884 3959 sched.cpp:282] Received 1 offers I0427 05:29:48.416524 3954 master.cpp:1608] Processing reply for offer 201304270529-1015726915-47553-3718-0 on slave 201304270529-1015726915-47553-3718-0 (janus.apache.org) for framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.416883 3954 master.hpp:289] Adding task 0 with resources cpus=2; mem=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.417341 3954 master.cpp:1727] Launching task 0 of framework 201304270529-1015726915-47553-3718-0000 with resources cpus=2; mem=1024 on slave 201304270529-1015726915-47553-3718-0 (janus.apache.org) I0427 05:29:48.417879 3953 slave.cpp:721] Got assigned task 0 for framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.417922 3959 hierarchical_allocator_process.hpp:471] Framework 201304270529-1015726915-47553-3718-0000 left ports=[31000-32000]; disk=1024 unused on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.417920 3954 master.hpp:321] Removing offer 201304270529-1015726915-47553-3718-0 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.419327 3953 slave.cpp:819] Launching task 0 for framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.419749 3959 hierarchical_allocator_process.hpp:497] Framework 201304270529-1015726915-47553-3718-0000 filtered slave 201304270529-1015726915-47553-3718-0 for 5.000000000000000secs I0427 05:29:48.422103 3953 paths.hpp:302] Created executor directory '/tmp/GarbageCollectorIntegrationTest_Unschedule_XPAGFP/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default/runs/e7084204-d206-4679-bdb8-0409280c1f0e' I0427 05:29:48.422262 3953 slave.cpp:930] Queuing task '0' for executor default of framework '201304270529-1015726915-47553-3718-0000 I0427 05:29:48.422400 3952 exec.cpp:170] Executor started at: executor(17)@67.195.138.60:47553 with pid 3718 I0427 05:29:48.422613 3953 slave.cpp:514] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_Unschedule_XPAGFP/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default/runs/e7084204-d206-4679-bdb8-0409280c1f0e' I0427 05:29:48.423655 3953 slave.cpp:1382] Got registration for executor 'default' of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.425041 3953 slave.cpp:1497] Flushing queued task 0 for executor 'default' of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.425076 3955 exec.cpp:194] Executor registered on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.426100 3955 exec.cpp:258] Executor asked to run task '0' I0427 05:29:48.428163 3955 exec.cpp:404] Executor sending status update TASK_RUNNING (UUID: 07acdc65-48d1-4cef-af6c-fc42802db832) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.428241 3955 slave.cpp:1726] Handling status update TASK_RUNNING (UUID: 07acdc65-48d1-4cef-af6c-fc42802db832) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.428640 3955 status_update_manager.cpp:289] Received status update TASK_RUNNING (UUID: 07acdc65-48d1-4cef-af6c-fc42802db832) for task 0 of framework 201304270529-1015726915-47553-3718-0000 with checkpoint=false I0427 05:29:48.429036 3955 status_update_manager.cpp:449] Creating StatusUpdate stream for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.429554 3955 status_update_manager.cpp:335] Forwarding status update TASK_RUNNING (UUID: 07acdc65-48d1-4cef-af6c-fc42802db832) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to [email protected]:47553 I0427 05:29:48.430076 3956 slave.cpp:1783] Status update manager successfully handled status update TASK_RUNNING (UUID: 07acdc65-48d1-4cef-af6c-fc42802db832) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.430078 3954 master.cpp:1134] Status update from (151)@67.195.138.60:47553: task 0 of framework 201304270529-1015726915-47553-3718-0000 is now in state TASK_RUNNING I0427 05:29:48.430469 3956 slave.cpp:1789] Sending acknowledgement for status update TASK_RUNNING (UUID: 07acdc65-48d1-4cef-af6c-fc42802db832) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to executor(17)@67.195.138.60:47553 I0427 05:29:48.432607 3954 exec.cpp:290] Executor received status update acknowledgement ��eH�L��l�B�-�2 for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.431584 3952 sched.cpp:327] Received status update TASK_RUNNING (UUID: 07acdc65-48d1-4cef-af6c-fc42802db832) for task 0 of framework 201304270529-1015726915-47553-3718-0000 from slave(41)@67.195.138.60:47553 I0427 05:29:48.433673 3952 sched.cpp:360] Sending ACK for status update TASK_RUNNING (UUID: 07acdc65-48d1-4cef-af6c-fc42802db832) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to slave(41)@67.195.138.60:47553 I0427 05:29:48.434573 3955 status_update_manager.cpp:359] Received status update acknowledgement 07acdc65-48d1-4cef-af6c-fc42802db832 for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.434584 3953 slave.cpp:2031] Executor 'default' of framework 201304270529-1015726915-47553-3718-0000 has exited with status '0' I0427 05:29:48.437227 3953 slave.cpp:1726] Handling status update TASK_LOST (UUID: 718e9c2f-ad57-4cc9-a533-9a6591e84fb5) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.437460 3957 master.cpp:1236] Executor default of framework 201304270529-1015726915-47553-3718-0000 on slave 201304270529-1015726915-47553-3718-0 (janus.apache.org) exited with status 0 I0427 05:29:48.437471 3953 slave.cpp:1332] Status update manager successfully handled status update acknowledgement 07acdc65-48d1-4cef-af6c-fc42802db832 for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.437489 3955 status_update_manager.cpp:289] Received status update TASK_LOST (UUID: 718e9c2f-ad57-4cc9-a533-9a6591e84fb5) for task 0 of framework 201304270529-1015726915-47553-3718-0000 with checkpoint=false I0427 05:29:48.438570 3955 status_update_manager.cpp:335] Forwarding status update TASK_LOST (UUID: 718e9c2f-ad57-4cc9-a533-9a6591e84fb5) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to [email protected]:47553 I0427 05:29:48.439332 3958 master.cpp:1134] Status update from (151)@67.195.138.60:47553: task 0 of framework 201304270529-1015726915-47553-3718-0000 is now in state TASK_LOST I0427 05:29:48.439833 3958 master.hpp:301] Removing task 0 with resources cpus=2; mem=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.439378 3955 slave.cpp:1783] Status update manager successfully handled status update TASK_LOST (UUID: 718e9c2f-ad57-4cc9-a533-9a6591e84fb5) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.439873 3952 sched.cpp:327] Received status update TASK_LOST (UUID: 718e9c2f-ad57-4cc9-a533-9a6591e84fb5) for task 0 of framework 201304270529-1015726915-47553-3718-0000 from slave(41)@67.195.138.60:47553 I0427 05:29:48.440362 3957 hierarchical_allocator_process.hpp:544] Recovered cpus=2; mem=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304270529-1015726915-47553-3718-0 from framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.441218 3955 slave.cpp:1789] Sending acknowledgement for status update TASK_LOST (UUID: 718e9c2f-ad57-4cc9-a533-9a6591e84fb5) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to executor(17)@67.195.138.60:47553 I0427 05:29:48.441728 3952 sched.cpp:360] Sending ACK for status update TASK_LOST (UUID: 718e9c2f-ad57-4cc9-a533-9a6591e84fb5) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to slave(41)@67.195.138.60:47553 I0427 05:29:48.443219 3952 status_update_manager.cpp:359] Received status update acknowledgement 718e9c2f-ad57-4cc9-a533-9a6591e84fb5 for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.443652 3952 status_update_manager.cpp:480] Cleaning up status update stream for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.444210 3952 slave.cpp:1332] Status update manager successfully handled status update acknowledgement 718e9c2f-ad57-4cc9-a533-9a6591e84fb5 for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.445654 3952 slave.cpp:2166] Cleaning up executor 'default' of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.446413 3954 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_XPAGFP/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default/runs/e7084204-d206-4679-bdb8-0409280c1f0e' for removal I0427 05:29:48.446431 3952 slave.cpp:2230] Cleaning up framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.446877 3954 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_XPAGFP/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default' for removal I0427 05:29:48.447326 3959 status_update_manager.cpp:251] Closing status update streams for framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.447924 3954 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_XPAGFP/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000' for removal I0427 05:29:48.448079 3955 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.449481 3955 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 to framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.450217 3955 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 2.151441000000000ms I0427 05:29:48.450268 3954 master.hpp:311] Adding offer 201304270529-1015726915-47553-3718-1 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.452105 3954 master.cpp:1375] Sending 1 offers to framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.452605 3953 sched.cpp:282] Received 1 offers I0427 05:29:48.453244 3954 master.cpp:1608] Processing reply for offer 201304270529-1015726915-47553-3718-1 on slave 201304270529-1015726915-47553-3718-0 (janus.apache.org) for framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.453644 3954 master.hpp:289] Adding task 0 with resources cpus=2; mem=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.454243 3954 master.cpp:1727] Launching task 0 of framework 201304270529-1015726915-47553-3718-0000 with resources cpus=2; mem=1024 on slave 201304270529-1015726915-47553-3718-0 (janus.apache.org) I0427 05:29:48.455348 3953 slave.cpp:721] Got assigned task 0 for framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.455414 3954 master.hpp:321] Removing offer 201304270529-1015726915-47553-3718-1 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.455425 3956 hierarchical_allocator_process.hpp:471] Framework 201304270529-1015726915-47553-3718-0000 left ports=[31000-32000]; disk=1024 unused on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.457020 3956 hierarchical_allocator_process.hpp:497] Framework 201304270529-1015726915-47553-3718-0000 filtered slave 201304270529-1015726915-47553-3718-0 for 5.000000000000000secs I0427 05:29:48.456363 3953 gc.cpp:84] Unscheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_XPAGFP/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000' for removal I0427 05:29:48.458174 3955 gc.cpp:84] Unscheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_XPAGFP/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default' for removal I0427 05:29:48.458544 3959 slave.cpp:819] Launching task 0 for framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.460209 3959 paths.hpp:302] Created executor directory '/tmp/GarbageCollectorIntegrationTest_Unschedule_XPAGFP/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default/runs/c7227594-52e2-4d04-89e4-e45bf049bca9' I0427 05:29:48.460394 3959 slave.cpp:930] Queuing task '0' for executor default of framework '201304270529-1015726915-47553-3718-0000 I0427 05:29:48.460670 3959 slave.cpp:514] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_Unschedule_XPAGFP/slaves/201304270529-1015726915-47553-3718-0/frameworks/201304270529-1015726915-47553-3718-0000/executors/default/runs/c7227594-52e2-4d04-89e4-e45bf049bca9' I0427 05:29:48.460548 3955 exec.cpp:170] Executor started at: executor(18)@67.195.138.60:47553 with pid 3718 I0427 05:29:48.461629 3955 slave.cpp:1382] Got registration for executor 'default' of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.462152 3955 slave.cpp:1497] Flushing queued task 0 for executor 'default' of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.462203 3957 exec.cpp:194] Executor registered on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.463141 3957 exec.cpp:258] Executor asked to run task '0' I0427 05:29:48.464773 3957 exec.cpp:404] Executor sending status update TASK_RUNNING (UUID: b1dd271c-b244-4882-9697-cd5fdbbe6eb1) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.464840 3957 slave.cpp:1726] Handling status update TASK_RUNNING (UUID: b1dd271c-b244-4882-9697-cd5fdbbe6eb1) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.465576 3957 status_update_manager.cpp:289] Received status update TASK_RUNNING (UUID: b1dd271c-b244-4882-9697-cd5fdbbe6eb1) for task 0 of framework 201304270529-1015726915-47553-3718-0000 with checkpoint=false I0427 05:29:48.465914 3957 status_update_manager.cpp:449] Creating StatusUpdate stream for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.466419 3957 status_update_manager.cpp:335] Forwarding status update TASK_RUNNING (UUID: b1dd271c-b244-4882-9697-cd5fdbbe6eb1) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to [email protected]:47553 I0427 05:29:48.466963 3953 master.cpp:1134] Status update from (151)@67.195.138.60:47553: task 0 of framework 201304270529-1015726915-47553-3718-0000 is now in state TASK_RUNNING I0427 05:29:48.466979 3956 slave.cpp:1783] Status update manager successfully handled status update TASK_RUNNING (UUID: b1dd271c-b244-4882-9697-cd5fdbbe6eb1) for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.467900 3956 slave.cpp:1789] Sending acknowledgement for status update TASK_RUNNING (UUID: b1dd271c-b244-4882-9697-cd5fdbbe6eb1) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to executor(18)@67.195.138.60:47553 I0427 05:29:48.467433 3953 sched.cpp:327] Received status update TASK_RUNNING (UUID: b1dd271c-b244-4882-9697-cd5fdbbe6eb1) for task 0 of framework 201304270529-1015726915-47553-3718-0000 from slave(41)@67.195.138.60:47553 I0427 05:29:48.468874 3954 exec.cpp:290] Executor received status update acknowledgement ��' �DH����_��n� for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.469307 3953 sched.cpp:360] Sending ACK for status update TASK_RUNNING (UUID: b1dd271c-b244-4882-9697-cd5fdbbe6eb1) for task 0 of framework 201304270529-1015726915-47553-3718-0000 to slave(41)@67.195.138.60:47553 I0427 05:29:48.470327 3953 status_update_manager.cpp:359] Received status update acknowledgement b1dd271c-b244-4882-9697-cd5fdbbe6eb1 for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.470775 3953 slave.cpp:1332] Status update manager successfully handled status update acknowledgement b1dd271c-b244-4882-9697-cd5fdbbe6eb1 for task 0 of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.478283 3956 sched.cpp:422] Stopping framework '201304270529-1015726915-47553-3718-0000' I0427 05:29:48.478288 3718 master.cpp:479] Master terminating I0427 05:29:48.478749 3718 master.cpp:285] Shutting down master I0427 05:29:48.478754 3957 slave.cpp:488] Slave asked to shut down by [email protected]:47553 I0427 05:29:48.479199 3954 hierarchical_allocator_process.hpp:359] Deactivated framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.479218 3718 master.hpp:301] Removing task 0 with resources cpus=2; mem=1024 on slave 201304270529-1015726915-47553-3718-0 I0427 05:29:48.479635 3957 slave.cpp:1101] Asked to shut down framework 201304270529-1015726915-47553-3718-0000 by [email protected]:47553 I0427 05:29:48.480705 3958 hierarchical_allocator_process.hpp:544] Recovered cpus=2; mem=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304270529-1015726915-47553-3718-0 from framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.481984 3957 slave.cpp:1126] Shutting down framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.482872 3957 slave.cpp:2299] Shutting down executor 'default' of framework 201304270529-1015726915-47553-3718-0000 I0427 05:29:48.483402 3957 slave.cpp:443] Slave terminating I0427 05:29:48.483839 3957 slave.cpp:1101] Asked to shut down framework 201304270529-1015726915-47553-3718-0000 by @0.0.0.0:0 W0427 05:29:48.484314 3957 slave.cpp:1122] Ignoring shutdown framework 201304270529-1015726915-47553-3718-0000 because it is terminating I0427 05:29:48.483417 3959 exec.cpp:323] Executor asked to shutdown pure virtual method called terminate called without an active exception [ OK ] GarbageCollectorIntegrationTest.Unschedule (85 ms) /bin/bash: line 5: 3718 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
