[ 
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

Reply via email to