[
https://issues.apache.org/jira/browse/MESOS-467?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Benjamin Mahler reopened MESOS-467:
-----------------------------------
Looks like this is still flaky on Jenkins:
[ RUN ] AllocatorTest/0.FrameworkExited
I0628 14:16:37.970865 7553 master.cpp:228] Master started on 67.195.138.9:56600
I0628 14:16:37.971328 7557 slave.cpp:112] Slave started on
386)@67.195.138.9:56600
I0628 14:16:37.971740 7558 sched.cpp:177] New master at
[email protected]:56600
I0628 14:16:37.978132 7553 master.cpp:243] Master ID:
201306281416-160088899-56600-7509
I0628 14:16:37.986162 7557 slave.cpp:204] Slave resources: cpus=3; mem=1024;
ports=[31000-32000]; disk=829417
W0628 14:16:38.002224 7555 master.cpp:83] No whitelist given. Advertising
offers for all slaves
I0628 14:16:38.002297 7553 master.cpp:526] Elected as master!
I0628 14:16:38.002305 7554 hierarchical_allocator_process.hpp:295]
Initializing hierarchical allocator process with master :
[email protected]:56600
I0628 14:16:38.010397 7557 slave.cpp:528] New master detected at
[email protected]:56600
I0628 14:16:38.026053 7553 master.cpp:569] Registering framework
201306281416-160088899-56600-7509-0000 at scheduler(351)@67.195.138.9:56600
I0628 14:16:38.041909 7557 slave.cpp:543] Postponing registration until
recovery is complete
I0628 14:16:38.041919 7552 status_update_manager.cpp:155] New master detected
at [email protected]:56600
I0628 14:16:38.049914 7556 sched.cpp:222] Framework registered with
201306281416-160088899-56600-7509-0000
I0628 14:16:38.049950 7553 hierarchical_allocator_process.hpp:327] Added
framework 201306281416-160088899-56600-7509-0000
I0628 14:16:38.057847 7557 slave.cpp:389] Finished recovery
I0628 14:16:38.081763 7553 hierarchical_allocator_process.hpp:705] No
resources available to allocate!
I0628 14:16:38.089858 7555 master.cpp:891] Attempting to register slave on
vesta.apache.org at slave(386)@67.195.138.9:56600
I0628 14:16:38.097714 7553 hierarchical_allocator_process.hpp:667] Performed
allocation for 0 slaves in 15.952758ms
I0628 14:16:38.105694 7555 master.cpp:1851] Adding slave
201306281416-160088899-56600-7509-0 at vesta.apache.org with cpus=3; mem=1024;
ports=[31000-32000]; disk=829417
I0628 14:16:38.113656 7553 hierarchical_allocator_process.hpp:705] No
resources available to allocate!
I0628 14:16:38.121665 7556 slave.cpp:588] Registered with master
[email protected]:56600; given slave ID 201306281416-160088899-56600-7509-0
I0628 14:16:38.129602 7553 hierarchical_allocator_process.hpp:667] Performed
allocation for 0 slaves in 15.946626ms
I0628 14:16:38.177227 7553 hierarchical_allocator_process.hpp:449] Added slave
201306281416-160088899-56600-7509-0 (vesta.apache.org) with cpus=3; mem=1024;
ports=[31000-32000]; disk=829417 (and cpus=3; mem=1024; ports=[31000-32000];
disk=829417 available)
I0628 14:16:38.189623 7553 hierarchical_allocator_process.hpp:727] Offering
cpus=3; mem=1024; ports=[31000-32000]; disk=829417 on slave
201306281416-160088899-56600-7509-0 to framework
201306281416-160088899-56600-7509-0000
I0628 14:16:38.201607 7553 hierarchical_allocator_process.hpp:687] Performed
allocation for slave 201306281416-160088899-56600-7509-0 in 12.005788ms
I0628 14:16:38.201689 7556 master.hpp:313] Adding offer
201306281416-160088899-56600-7509-0 with resources cpus=3; mem=1024;
ports=[31000-32000]; disk=829417 on slave 201306281416-160088899-56600-7509-0
I0628 14:16:38.225489 7556 master.cpp:1239] Sending 1 offers to framework
201306281416-160088899-56600-7509-0000
I0628 14:16:38.227385 7552 hierarchical_allocator_process.hpp:667] Performed
allocation for 1 slaves in 25.963us
I0628 14:16:38.237709 7557 master.cpp:1472] Processing reply for offer
201306281416-160088899-56600-7509-0 on slave
201306281416-160088899-56600-7509-0 (vesta.apache.org) for framework
201306281416-160088899-56600-7509-0000
I0628 14:16:38.261311 7557 master.hpp:291] Adding task 0 with resources
cpus=2; mem=512 on slave 201306281416-160088899-56600-7509-0
I0628 14:16:38.273157 7557 master.cpp:1591] Launching task 0 of framework
201306281416-160088899-56600-7509-0000 with resources cpus=2; mem=512 on slave
201306281416-160088899-56600-7509-0 (vesta.apache.org)
I0628 14:16:38.285259 7557 master.hpp:323] Removing offer
201306281416-160088899-56600-7509-0 with resources cpus=3; mem=1024;
ports=[31000-32000]; disk=829417 on slave 201306281416-160088899-56600-7509-0
I0628 14:16:38.285265 7556 slave.cpp:738] Got assigned task 0 for framework
201306281416-160088899-56600-7509-0000
I0628 14:16:38.285382 7555 hierarchical_allocator_process.hpp:526] Framework
201306281416-160088899-56600-7509-0000 left cpus=1; mem=512;
ports=[31000-32000]; disk=829417 unused on slave
201306281416-160088899-56600-7509-0
I0628 14:16:38.321060 7555 hierarchical_allocator_process.hpp:569] Framework
201306281416-160088899-56600-7509-0000 filtered slave
201306281416-160088899-56600-7509-0 for 5secs
I0628 14:16:38.332952 7555 hierarchical_allocator_process.hpp:797] Filtered
cpus=1; mem=512; ports=[31000-32000]; disk=829417 on slave
201306281416-160088899-56600-7509-0 for framework
201306281416-160088899-56600-7509-0000
I0628 14:16:38.344833 7555 hierarchical_allocator_process.hpp:667] Performed
allocation for 1 slaves in 11.912219ms
I0628 14:16:38.309285 7556 slave.cpp:836] Launching task 0 for framework
201306281416-160088899-56600-7509-0000
I0628 14:16:38.369714 7556 paths.hpp:303] Created executor directory
'/tmp/AllocatorTest_0_FrameworkExited_w073lC/slaves/201306281416-160088899-56600-7509-0/frameworks/201306281416-160088899-56600-7509-0000/executors/default/runs/a183083a-0e0d-432b-8c47-d8d28f57777f'
I0628 14:16:38.380807 7556 slave.cpp:947] Queuing task '0' for executor
default of framework '201306281416-160088899-56600-7509-0000
I0628 14:16:38.381000 7553 exec.cpp:170] Executor started at:
executor(140)@67.195.138.9:56600 with pid 7509
I0628 14:16:38.392632 7556 slave.cpp:510] Successfully attached file
'/tmp/AllocatorTest_0_FrameworkExited_w073lC/slaves/201306281416-160088899-56600-7509-0/frameworks/201306281416-160088899-56600-7509-0000/executors/default/runs/a183083a-0e0d-432b-8c47-d8d28f57777f'
I0628 14:16:38.407886 7557 hierarchical_allocator_process.hpp:797] Filtered
cpus=1; mem=512; ports=[31000-32000]; disk=829417 on slave
201306281416-160088899-56600-7509-0 for framework
201306281416-160088899-56600-7509-0000
I0628 14:16:38.428479 7557 hierarchical_allocator_process.hpp:667] Performed
allocation for 1 slaves in 20.645236ms
I0628 14:16:38.416568 7556 slave.cpp:1394] Got registration for executor
'default' of framework 201306281416-160088899-56600-7509-0000
I0628 14:16:38.452517 7556 slave.cpp:1509] Flushing queued task 0 for executor
'default' of framework 201306281416-160088899-56600-7509-0000
I0628 14:16:38.452575 7552 exec.cpp:194] Executor registered on slave
201306281416-160088899-56600-7509-0
I0628 14:16:38.468389 7552 exec.cpp:258] Executor asked to run task '0'
I0628 14:16:38.476779 7554 sched.cpp:177] New master at
[email protected]:56600
I0628 14:16:38.484357 7552 master.cpp:569] Registering framework
201306281416-160088899-56600-7509-0001 at scheduler(352)@67.195.138.9:56600
I0628 14:16:38.490658 7554 hierarchical_allocator_process.hpp:797] Filtered
cpus=1; mem=512; ports=[31000-32000]; disk=829417 on slave
201306281416-160088899-56600-7509-0 for framework
201306281416-160088899-56600-7509-0000
I0628 14:16:38.492234 7557 sched.cpp:222] Framework registered with
201306281416-160088899-56600-7509-0001
I0628 14:16:38.500146 7554 hierarchical_allocator_process.hpp:667] Performed
allocation for 1 slaves in 9.532914ms
I0628 14:16:38.516088 7554 hierarchical_allocator_process.hpp:327] Added
framework 201306281416-160088899-56600-7509-0001
I0628 14:16:38.524067 7554 hierarchical_allocator_process.hpp:727] Offering
cpus=1; mem=512; ports=[31000-32000]; disk=829417 on slave
201306281416-160088899-56600-7509-0 to framework
201306281416-160088899-56600-7509-0001
I0628 14:16:38.532140 7554 hierarchical_allocator_process.hpp:667] Performed
allocation for 1 slaves in 8.101539ms
I0628 14:16:38.532209 7553 master.hpp:313] Adding offer
201306281416-160088899-56600-7509-1 with resources cpus=1; mem=512;
ports=[31000-32000]; disk=829417 on slave 201306281416-160088899-56600-7509-0
I0628 14:16:38.547988 7553 master.cpp:1239] Sending 1 offers to framework
201306281416-160088899-56600-7509-0001
I0628 14:16:38.556159 7559 master.cpp:1472] Processing reply for offer
201306281416-160088899-56600-7509-1 on slave
201306281416-160088899-56600-7509-0 (vesta.apache.org) for framework
201306281416-160088899-56600-7509-0001
I0628 14:16:38.563982 7559 master.hpp:291] Adding task 0 with resources
cpus=1; mem=256 on slave 201306281416-160088899-56600-7509-0
I0628 14:16:38.566889 7553 hierarchical_allocator_process.hpp:667] Performed
allocation for 1 slaves in 22.879us
I0628 14:16:38.571841 7559 master.cpp:1591] Launching task 0 of framework
201306281416-160088899-56600-7509-0001 with resources cpus=1; mem=256 on slave
201306281416-160088899-56600-7509-0 (vesta.apache.org)
I0628 14:16:38.587870 7556 slave.cpp:738] Got assigned task 0 for framework
201306281416-160088899-56600-7509-0001
I0628 14:16:38.587870 7559 master.hpp:323] Removing offer
201306281416-160088899-56600-7509-1 with resources cpus=1; mem=512;
ports=[31000-32000]; disk=829417 on slave 201306281416-160088899-56600-7509-0
I0628 14:16:38.588042 7552 hierarchical_allocator_process.hpp:526] Framework
201306281416-160088899-56600-7509-0001 left mem=256; ports=[31000-32000];
disk=829417 unused on slave 201306281416-160088899-56600-7509-0
I0628 14:16:38.611732 7552 hierarchical_allocator_process.hpp:569] Framework
201306281416-160088899-56600-7509-0001 filtered slave
201306281416-160088899-56600-7509-0 for 5secs
I0628 14:16:38.595968 7556 slave.cpp:836] Launching task 0 for framework
201306281416-160088899-56600-7509-0001
I0628 14:16:38.628501 7556 paths.hpp:303] Created executor directory
'/tmp/AllocatorTest_0_FrameworkExited_w073lC/slaves/201306281416-160088899-56600-7509-0/frameworks/201306281416-160088899-56600-7509-0001/executors/default/runs/3d76a911-879b-44e2-8bca-dfce8d0e8b48'
I0628 14:16:38.630003 7555 hierarchical_allocator_process.hpp:667] Performed
allocation for 1 slaves in 34.638us
I0628 14:16:38.635759 7556 slave.cpp:947] Queuing task '0' for executor
default of framework '201306281416-160088899-56600-7509-0001
I0628 14:16:38.635907 7559 exec.cpp:170] Executor started at:
executor(141)@67.195.138.9:56600 with pid 7509
I0628 14:16:38.651556 7556 slave.cpp:510] Successfully attached file
'/tmp/AllocatorTest_0_FrameworkExited_w073lC/slaves/201306281416-160088899-56600-7509-0/frameworks/201306281416-160088899-56600-7509-0001/executors/default/runs/3d76a911-879b-44e2-8bca-dfce8d0e8b48'
I0628 14:16:38.667559 7556 slave.cpp:1394] Got registration for executor
'default' of framework 201306281416-160088899-56600-7509-0001
I0628 14:16:38.675551 7556 slave.cpp:1509] Flushing queued task 0 for executor
'default' of framework 201306281416-160088899-56600-7509-0001
I0628 14:16:38.675571 7557 exec.cpp:194] Executor registered on slave
201306281416-160088899-56600-7509-0
I0628 14:16:38.691474 7557 exec.cpp:258] Executor asked to run task '0'
I0628 14:16:38.693771 7553 hierarchical_allocator_process.hpp:667] Performed
allocation for 1 slaves in 31.913us
I0628 14:16:38.699625 7557 sched.cpp:427] Stopping framework
'201306281416-160088899-56600-7509-0000'
I0628 14:16:38.715381 7555 master.cpp:697] Asked to unregister framework
201306281416-160088899-56600-7509-0000
I0628 14:16:38.723366 7555 master.hpp:303] Removing task 0 with resources
cpus=2; mem=512 on slave 201306281416-160088899-56600-7509-0
I0628 14:16:38.723418 7559 slave.cpp:1111] Asked to shut down framework
201306281416-160088899-56600-7509-0000 by [email protected]:56600
I0628 14:16:38.723453 7558 hierarchical_allocator_process.hpp:412] Deactivated
framework 201306281416-160088899-56600-7509-0000
I0628 14:16:38.747288 7558 hierarchical_allocator_process.hpp:616] Recovered
cpus=2; mem=512 (total allocatable: cpus=2; mem=768; ports=[31000-32000];
disk=829417) on slave 201306281416-160088899-56600-7509-0 from framework
201306281416-160088899-56600-7509-0000
I0628 14:16:38.755251 7558 hierarchical_allocator_process.hpp:367] Removed
framework 201306281416-160088899-56600-7509-0000
I0628 14:16:38.739254 7559 slave.cpp:1136] Shutting down framework
201306281416-160088899-56600-7509-0000
I0628 14:16:38.763190 7558 hierarchical_allocator_process.hpp:727] Offering
cpus=2; mem=768; ports=[31000-32000]; disk=829417 on slave
201306281416-160088899-56600-7509-0 to framework
201306281416-160088899-56600-7509-0001
I0628 14:16:38.779216 7558 hierarchical_allocator_process.hpp:667] Performed
allocation for 1 slaves in 16.053938ms
I0628 14:16:38.779266 7555 master.hpp:313] Adding offer
201306281416-160088899-56600-7509-2 with resources cpus=2; mem=768;
ports=[31000-32000]; disk=829417 on slave 201306281416-160088899-56600-7509-0
I0628 14:16:38.771142 7559 slave.cpp:2327] Shutting down executor 'default' of
framework 201306281416-160088899-56600-7509-0000
I0628 14:16:38.795081 7555 master.cpp:1239] Sending 1 offers to framework
201306281416-160088899-56600-7509-0001
I0628 14:16:38.803055 7559 exec.cpp:323] Executor asked to shutdown
I0628 14:16:38.811171 7553 sched.cpp:427] Stopping framework
'201306281416-160088899-56600-7509-0001'
I0628 14:16:38.811226 7556 master.cpp:385] Master terminating
I0628 14:16:38.834969 7552 slave.cpp:484] Slave asked to shut down by
[email protected]:56600
I0628 14:16:38.834990 7509 master.cpp:207] Shutting down master
I0628 14:16:38.850955 7509 master.hpp:303] Removing task 0 with resources
cpus=1; mem=256 on slave 201306281416-160088899-56600-7509-0
I0628 14:16:38.842918 7552 slave.cpp:1111] Asked to shut down framework
201306281416-160088899-56600-7509-0001 by [email protected]:56600
I0628 14:16:38.837260 7556 hierarchical_allocator_process.hpp:667] Performed
allocation for 1 slaves in 15.638us
I0628 14:16:38.858973 7509 master.hpp:323] Removing offer
201306281416-160088899-56600-7509-2 with resources cpus=2; mem=768;
ports=[31000-32000]; disk=829417 on slave 201306281416-160088899-56600-7509-0
I0628 14:16:38.866812 7552 slave.cpp:1136] Shutting down framework
201306281416-160088899-56600-7509-0001
I0628 14:16:38.874801 7556 hierarchical_allocator_process.hpp:412] Deactivated
framework 201306281416-160088899-56600-7509-0001
I0628 14:16:38.898751 7556 hierarchical_allocator_process.hpp:616] Recovered
cpus=1; mem=256 (total allocatable: cpus=1; mem=256; ports=[]; disk=0) on slave
201306281416-160088899-56600-7509-0 from framework
201306281416-160088899-56600-7509-0001
I0628 14:16:38.890737 7552 slave.cpp:2327] Shutting down executor 'default' of
framework 201306281416-160088899-56600-7509-0001
I0628 14:16:38.906779 7556 hierarchical_allocator_process.hpp:616] Recovered
cpus=2; mem=768; ports=[31000-32000]; disk=829417 (total allocatable: cpus=3;
mem=1024; ports=[31000-32000]; disk=829417) on slave
201306281416-160088899-56600-7509-0 from framework
201306281416-160088899-56600-7509-0001
I0628 14:16:38.922716 7556 hierarchical_allocator_process.hpp:367] Removed
framework 201306281416-160088899-56600-7509-0001
I0628 14:16:38.914747 7559 exec.cpp:323] Executor asked to shutdown
../../src/tests/allocator_tests.cpp:804: Failure
Mock function called more times than expected - returning directly.
Function call: shutdown(0x2b5044027870)
Expected: to be called at most once
Actual: called twice - over-saturated and active
I0628 14:16:38.914723 7552 slave.cpp:1111] Asked to shut down framework
201306281416-160088899-56600-7509-0000 by [email protected]:56600
I0628 14:16:38.930670 7556 hierarchical_allocator_process.hpp:477] Removed
slave 201306281416-160088899-56600-7509-0
W0628 14:16:38.946576 7552 slave.cpp:1132] Ignoring shutdown framework
201306281416-160088899-56600-7509-0000 because it is terminating
I0628 14:16:38.954548 7556 hierarchical_allocator_process.hpp:700] No users to
allocate resources!
I0628 14:16:38.962510 7552 slave.cpp:439] Slave terminating
I0628 14:16:38.970494 7556 hierarchical_allocator_process.hpp:667] Performed
allocation for 0 slaves in 15.944777ms
I0628 14:16:38.978466 7552 slave.cpp:1111] Asked to shut down framework
201306281416-160088899-56600-7509-0001 by @0.0.0.0:0
W0628 14:16:38.994410 7552 slave.cpp:1132] Ignoring shutdown framework
201306281416-160088899-56600-7509-0001 because it is terminating
I0628 14:16:39.002374 7552 slave.cpp:1111] Asked to shut down framework
201306281416-160088899-56600-7509-0000 by @0.0.0.0:0
W0628 14:16:39.010360 7552 slave.cpp:1132] Ignoring shutdown framework
201306281416-160088899-56600-7509-0000 because it is terminating
[ FAILED ] AllocatorTest/0.FrameworkExited, where TypeParam =
mesos::internal::master::allocator::HierarchicalAllocatorProcess<mesos::internal::master::allocator::DRFSorter,
mesos::internal::master::allocator::DRFSorter> (1048 ms)
> AllocatorTest.FrameworkExited is flaky
> --------------------------------------
>
> Key: MESOS-467
> URL: https://issues.apache.org/jira/browse/MESOS-467
> Project: Mesos
> Issue Type: Bug
> Reporter: Thomas Marshall
> Assignee: Benjamin Hindman
> Fix For: 0.13.0
>
>
> Note: Google Test filter = *TaskFinished*-
> [==========] Running 1 test from 1 test case.
> [----------] Global test environment set-up.
> [----------] 1 test from AllocatorTest/0, where TypeParam =
> mesos::internal::master::HierarchicalAllocatorProcess<mesos::internal::master::DRFSorter,
> mesos::internal::master::DRFSorter>
> [ RUN ] AllocatorTest/0.TaskFinished
> ../../src/tests/allocator_tests.cpp:1098: Failure
> Mock function called more times than expected - returning directly.
> Function call: resourceOffers(0x7fff58d85380, @0x10b1089e8 { 224-byte
> object <30-C0 74-09 01-00 00-00 00-00 00-00 00-00 00-00 00-75 05-15 EC-7F
> 00-00 00-90 04-15 EC-7F 00-00 70-90 04-15 EC-7F 00-00 20-22 03-15 EC-7F 00-00
> 88-C2 05-15 EC-7F 00-00 04-00 00-00 04-00 00-00 ... F8-C2 05-15 EC-7F 00-00
> 01-00 00-00 01-00 00-00 04-00 00-00 EC-7F 00-00 C0-74 05-15 EC-7F 00-00 18-C3
> 05-15 EC-7F 00-00 04-00 00-00 04-00 00-00 04-00 00-00 01-00 00-00 00-00 00-00
> 0F-00 00-00> })
> Expected: to be called once
> Actual: called twice - over-saturated and active
> Segmentation fault: 11
--
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