You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by "Benjamin Mahler (JIRA)" <ji...@apache.org> on 2013/04/18 00:53:19 UTC
[jira] [Commented] (MESOS-395)
FaultToleranceTest.SchedulerFailoverFrameworkMessage test is flaky.
[ https://issues.apache.org/jira/browse/MESOS-395?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13634559#comment-13634559 ]
Benjamin Mahler commented on MESOS-395:
---------------------------------------
Another instance on Jenkins looks similar:
[ 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
> FaultToleranceTest.SchedulerFailoverFrameworkMessage test is flaky.
> -------------------------------------------------------------------
>
> Key: MESOS-395
> URL: https://issues.apache.org/jira/browse/MESOS-395
> Project: Mesos
> Issue Type: Bug
> Reporter: Benjamin Mahler
> Assignee: Benjamin Hindman
>
> This failed on Jenkins, see output below.
> [ RUN ] FaultToleranceTest.SchedulerFailoverFrameworkMessage
> I0314 04:28:38.647588 15531 master.cpp:309] Master started on 67.195.138.60:53734
> I0314 04:28:38.647660 15531 master.cpp:324] Master ID: 201303140428-1015726915-53734-15499
> I0314 04:28:38.648110 15529 slave.cpp:202] Slave started on 53)@67.195.138.60:53734
> I0314 04:28:38.648202 15530 hierarchical_allocator_process.hpp:234] Initializing hierarchical allocator process with master : master@67.195.138.60:53734
> W0314 04:28:38.648231 15525 master.cpp:79] No whitelist given. Advertising offers for all slaves
> I0314 04:28:38.648370 15531 master.cpp:553] Elected as master!
> I0314 04:28:38.648437 15524 sched.cpp:182] New master at master@67.195.138.60:53734
> I0314 04:28:38.648470 15529 slave.cpp:203] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
> I0314 04:28:38.651875 15527 master.cpp:596] Registering framework 201303140428-1015726915-53734-15499-0000 at scheduler(42)@67.195.138.60:53734
> I0314 04:28:38.652915 15524 sched.cpp:217] Framework registered with 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.652926 15527 hierarchical_allocator_process.hpp:266] Added framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.653851 15527 hierarchical_allocator_process.hpp:666] No resources available to allocate!
> I0314 04:28:38.655067 15527 hierarchical_allocator_process.hpp:597] Performed allocation for 0 slaves in 1.22ms
> I0314 04:28:38.652744 15529 slave.cpp:468] New master detected at master@67.195.138.60:53734
> I0314 04:28:38.656069 15529 slave.cpp:380] Finished recovery
> I0314 04:28:38.656072 15530 status_update_manager.cpp:131] New master detected at master@67.195.138.60:53734
> I0314 04:28:38.656733 15527 master.cpp:918] Attempting to register slave on janus.apache.org at slave(53)@67.195.138.60:53734
> I0314 04:28:38.657591 15527 master.cpp:1153] Master now considering a slave at janus.apache.org:53734 as active
> I0314 04:28:38.658236 15527 master.cpp:1729] Adding slave 201303140428-1015726915-53734-15499-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
> I0314 04:28:38.658807 15529 slave.cpp:502] Registered with master; given slave ID 201303140428-1015726915-53734-15499-0
> I0314 04:28:38.658917 15526 hierarchical_allocator_process.hpp:393] Added slave 201303140428-1015726915-53734-15499-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=2; mem=1024; ports=[31000-32000]; disk=1024 available)
> I0314 04:28:38.660892 15526 hierarchical_allocator_process.hpp:658] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
> I0314 04:28:38.662082 15526 hierarchical_allocator_process.hpp:684] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0 to framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.662931 15526 hierarchical_allocator_process.hpp:617] Performed allocation for slave 201303140428-1015726915-53734-15499-0 in 2.06ms
> I0314 04:28:38.662966 15527 master.hpp:305] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
> I0314 04:28:38.663732 15527 master.cpp:1256] Sending 1 offers to framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.664222 15531 sched.cpp:282] Received 1 offers
> I0314 04:28:38.665107 15528 master.cpp:1463] Processing reply for offer 201303140428-1015726915-53734-15499-0 on slave 201303140428-1015726915-53734-15499-0 (janus.apache.org) for framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.665501 15528 master.hpp:285] Adding task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
> I0314 04:28:38.665874 15528 master.cpp:1580] Launching task 1 of framework 201303140428-1015726915-53734-15499-0000 with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0 (janus.apache.org)
> I0314 04:28:38.666404 15525 slave.cpp:614] Got assigned task 1 for framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.666474 15528 master.hpp:314] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
> I0314 04:28:38.668900 15525 paths.hpp:302] Created executor directory '/tmp/FaultToleranceTest_SchedulerFailoverFrameworkMessage_A2apii/slaves/201303140428-1015726915-53734-15499-0/frameworks/201303140428-1015726915-53734-15499-0000/executors/default/runs/565e63a1-a4dd-4d93-8c13-6e85a20ec2de'
> I0314 04:28:38.669179 15527 slave.cpp:451] Successfully attached file '/tmp/FaultToleranceTest_SchedulerFailoverFrameworkMessage_A2apii/slaves/201303140428-1015726915-53734-15499-0/frameworks/201303140428-1015726915-53734-15499-0000/executors/default/runs/565e63a1-a4dd-4d93-8c13-6e85a20ec2de'
> I0314 04:28:38.669302 15525 exec.cpp:170] Executor started at: executor(17)@67.195.138.60:53734 with pid 15499
> I0314 04:28:38.670753 15525 slave.cpp:1008] Got registration for executor 'default' of framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.671393 15525 slave.cpp:1083] Flushing queued tasks for framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.671438 15528 exec.cpp:194] Executor registered on slave 201303140428-1015726915-53734-15499-0
> I0314 04:28:38.672396 15528 exec.cpp:258] Executor asked to run task '1'
> I0314 04:28:38.672799 15528 exec.cpp:382] Executor sending status update for task 1 in state TASK_RUNNING
> I0314 04:28:38.674502 15524 slave.cpp:1191] Handling status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.674540 15524 slave.cpp:1238] Forwarding status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to the status update manager
> I0314 04:28:38.675204 15528 status_update_manager.cpp:253] Received status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.675647 15528 status_update_manager.cpp:402] Creating StatusUpdate stream for task 1 of framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.676182 15528 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.676656 15528 status_update_manager.cpp:288] Forwarding status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to the master at master@67.195.138.60:53734
> I0314 04:28:38.677193 15531 master.cpp:1016] Status update from (266)@67.195.138.60:53734: task 1 of framework 201303140428-1015726915-53734-15499-0000 is now in state TASK_RUNNING
> I0314 04:28:38.677217 15529 slave.cpp:1300] Sending ACK for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000 to executor executor(17)@67.195.138.60:53734
> I0314 04:28:38.677693 15527 sched.cpp:327] Status update: task 1 of framework 201303140428-1015726915-53734-15499-0000 is now in state TASK_RUNNING
> I0314 04:28:38.678215 15531 exec.cpp:289] Executor received ACK for status update of task 1 of framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.679352 15527 slave.cpp:967] Got acknowledgement of status update for task 1 of framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.679553 15529 sched.cpp:182] New master at master@67.195.138.60:53734
> I0314 04:28:38.680408 15527 status_update_manager.cpp:313] Received status update acknowledgement for task 1 of framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.681324 15527 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 1 of framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.680902 15528 master.cpp:631] Re-registering framework 201303140428-1015726915-53734-15499-0000 at scheduler(43)@67.195.138.60:53734
> I0314 04:28:38.682379 15528 master.cpp:650] Framework 201303140428-1015726915-53734-15499-0000 failed over
> I0314 04:28:38.683537 15527 sched.cpp:413] Got error 'Framework failed over'
> I0314 04:28:38.684315 15527 sched.cpp:446] Aborting framework '201303140428-1015726915-53734-15499-0000'
> W0314 04:28:38.684795 15527 master.cpp:748] scheduler(42)@67.195.138.60:53734 tried to deactivate framework; expecting scheduler(43)@67.195.138.60:53734
> I0314 04:28:38.683559 15529 sched.cpp:217] Framework registered with 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.683568 15528 slave.cpp:954] Updating framework 201303140428-1015726915-53734-15499-0000 pid to scheduler(43)@67.195.138.60:53734
> I0314 04:28:38.686815 15528 slave.cpp:1328] Sending message for framework 201303140428-1015726915-53734-15499-0000 to scheduler(43)@67.195.138.60:53734
> I0314 04:28:38.688077 15528 sched.cpp:401] Received framework message
> I0314 04:28:38.688607 15499 slave.cpp:389] Slave terminating
> I0314 04:28:38.688612 15526 sched.cpp:422] Stopping framework '201303140428-1015726915-53734-15499-0000'
> I0314 04:28:38.688647 15524 sched.cpp:422] Stopping framework '201303140428-1015726915-53734-15499-0000'
> I0314 04:28:38.689035 15499 slave.cpp:889] Asked to shut down framework 201303140428-1015726915-53734-15499-0000 by @0.0.0.0:0
> I0314 04:28:38.689618 15530 master.cpp:724] Asked to unregister framework 201303140428-1015726915-53734-15499-0000
> W0314 04:28:38.691184 15530 master.cpp:731] scheduler(42)@67.195.138.60:53734 tried to unregister framework; expecting scheduler(43)@67.195.138.60:53734
> I0314 04:28:38.690610 15499 slave.cpp:894] Shutting down framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.693922 15499 slave.cpp:1612] Shutting down executor 'default' of framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.692955 15530 master.cpp:724] Asked to unregister framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.695543 15527 hierarchical_allocator_process.hpp:357] Deactivated framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.695054 15531 status_update_manager.cpp:232] Closing status update streams for framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.695585 15530 master.hpp:296] Removing task with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201303140428-1015726915-53734-15499-0
> I0314 04:28:38.697087 15530 master.cpp:477] Master terminating
> I0314 04:28:38.696569 15531 status_update_manager.cpp:433] Cleaning up status update stream for task 1 of framework 201303140428-1015726915-53734-15499-0000
> I0314 04:28:38.695039 15525 exec.cpp:321] Executor asked to shutdown
> pure virtual method called
> terminate called without an active exception
> I0314 04:28:38.697149 15526 hierarchical_allocator_process.hpp:542] Recovered cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201303140428-1015726915-53734-15499-0 from framework 201303140428-1015726915-53734-15499-0000
> /bin/bash: line 5: 15499 Aborted ${dir}$tst
> FAIL: mesos-tests
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira