[
https://issues.apache.org/jira/browse/MESOS-467?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13722836#comment-13722836
]
Benjamin Mahler commented on MESOS-467:
---------------------------------------
Another instance:
https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/1488/consoleFull
[ RUN ] AllocatorTest/0.FrameworkExited
I0728 05:44:39.545348 17336 master.cpp:230] Master started on
67.195.138.60:45691
I0728 05:44:39.546047 17336 master.cpp:245] Master ID:
201307280544-1015726915-45691-17316
W0728 05:44:39.546617 17343 master.cpp:83] No whitelist given. Advertising
offers for all slaves
I0728 05:44:39.546826 17338 hierarchical_allocator_process.hpp:287]
Initializing hierarchical allocator process with master :
[email protected]:45691
I0728 05:44:39.546831 17336 master.cpp:583] Elected as master!
I0728 05:44:39.556061 17342 slave.cpp:113] Slave started on
101)@67.195.138.60:45691
I0728 05:44:39.556202 17342 slave.cpp:213] Slave resources: cpus(*):3;
mem(*):1024; disk(*):21354; ports(*):[31000-32000]
I0728 05:44:39.556380 17340 sched.cpp:178] New master at
[email protected]:45691
I0728 05:44:39.556979 17342 slave.cpp:537] New master detected at
[email protected]:45691
I0728 05:44:39.557143 17343 master.cpp:633] Registering framework
201307280544-1015726915-45691-17316-0000 at scheduler(91)@67.195.138.60:45691
I0728 05:44:39.557354 17342 slave.cpp:552] Postponing registration until
recovery is complete
I0728 05:44:39.557368 17340 status_update_manager.cpp:155] New master detected
at [email protected]:45691
I0728 05:44:39.557891 17338 sched.cpp:237] Framework registered with
201307280544-1015726915-45691-17316-0000
I0728 05:44:39.557934 17343 hierarchical_allocator_process.hpp:317] Added
framework 201307280544-1015726915-45691-17316-0000
I0728 05:44:39.560631 17343 hierarchical_allocator_process.hpp:684] No
resources available to allocate!
I0728 05:44:39.560160 17338 sched.cpp:251] Scheduler::registered took 12.749us
I0728 05:44:39.559191 17342 slave.cpp:398] Finished recovery
I0728 05:44:39.561105 17343 hierarchical_allocator_process.hpp:646] Performed
allocation for 0 slaves in 474.704us
I0728 05:44:39.562180 17339 master.cpp:962] Attempting to register slave on
janus.apache.org at slave(101)@67.195.138.60:45691
I0728 05:44:39.563069 17339 master.cpp:1941] Adding slave
201307280544-1015726915-45691-17316-0 at janus.apache.org with cpus(*):3;
mem(*):1024; disk(*):21354; ports(*):[31000-32000]
I0728 05:44:39.563609 17337 slave.cpp:597] Registered with master
[email protected]:45691; given slave ID 201307280544-1015726915-45691-17316-0
I0728 05:44:39.563770 17340 hierarchical_allocator_process.hpp:430] Added slave
201307280544-1015726915-45691-17316-0 (janus.apache.org) with cpus(*):3;
mem(*):1024; disk(*):21354; ports(*):[31000-32000] (and cpus(*):3; mem(*):1024;
disk(*):21354; ports(*):[31000-32000] available)
I0728 05:44:39.564587 17340 hierarchical_allocator_process.hpp:709] Offering
cpus(*):3; mem(*):1024; disk(*):21354; ports(*):[31000-32000] on slave
201307280544-1015726915-45691-17316-0 to framework
201307280544-1015726915-45691-17316-0000
I0728 05:44:39.565152 17340 hierarchical_allocator_process.hpp:666] Performed
allocation for slave 201307280544-1015726915-45691-17316-0 in 597.027us
I0728 05:44:39.565206 17337 master.hpp:328] Adding offer
201307280544-1015726915-45691-17316-0 with resources cpus(*):3; mem(*):1024;
disk(*):21354; ports(*):[31000-32000] on slave
201307280544-1015726915-45691-17316-0
I0728 05:44:39.566119 17337 master.cpp:1322] Sending 1 offers to framework
201307280544-1015726915-45691-17316-0000
I0728 05:44:39.567075 17337 sched.cpp:340] Scheduler::resourceOffers took
162.134us
I0728 05:44:39.567379 17337 master.cpp:1555] Processing reply for offer
201307280544-1015726915-45691-17316-0 on slave
201307280544-1015726915-45691-17316-0 (janus.apache.org) for framework
201307280544-1015726915-45691-17316-0000
I0728 05:44:39.567862 17337 master.hpp:306] Adding task 0 with resources
cpus(*):2; mem(*):512 on slave 201307280544-1015726915-45691-17316-0
I0728 05:44:39.568305 17337 master.cpp:1674] Launching task 0 of framework
201307280544-1015726915-45691-17316-0000 with resources cpus(*):2; mem(*):512
on slave 201307280544-1015726915-45691-17316-0 (janus.apache.org)
I0728 05:44:39.568869 17343 slave.cpp:747] Got assigned task 0 for framework
201307280544-1015726915-45691-17316-0000
I0728 05:44:39.569494 17343 slave.cpp:845] Launching task 0 for framework
201307280544-1015726915-45691-17316-0000
I0728 05:44:39.568992 17341 hierarchical_allocator_process.hpp:505] Framework
201307280544-1015726915-45691-17316-0000 left cpus(*):1; mem(*):512;
disk(*):21354; ports(*):[31000-32000] unused on slave
201307280544-1015726915-45691-17316-0
I0728 05:44:39.571177 17341 hierarchical_allocator_process.hpp:548] Framework
201307280544-1015726915-45691-17316-0000 filtered slave
201307280544-1015726915-45691-17316-0 for 5secs
I0728 05:44:39.568920 17337 master.hpp:338] Removing offer
201307280544-1015726915-45691-17316-0 with resources cpus(*):3; mem(*):1024;
disk(*):21354; ports(*):[31000-32000] on slave
201307280544-1015726915-45691-17316-0
I0728 05:44:39.571307 17343 paths.hpp:303] Created executor directory
'/tmp/AllocatorTest_0_FrameworkExited_QcyASa/slaves/201307280544-1015726915-45691-17316-0/frameworks/201307280544-1015726915-45691-17316-0000/executors/default/runs/96ea8b32-8d62-45c0-890a-9cb4da406f4e'
I0728 05:44:39.572602 17343 slave.cpp:956] Queuing task '0' for executor
default of framework '201307280544-1015726915-45691-17316-0000
I0728 05:44:39.572986 17343 slave.cpp:519] Successfully attached file
'/tmp/AllocatorTest_0_FrameworkExited_QcyASa/slaves/201307280544-1015726915-45691-17316-0/frameworks/201307280544-1015726915-45691-17316-0000/executors/default/runs/96ea8b32-8d62-45c0-890a-9cb4da406f4e'
I0728 05:44:39.572757 17336 exec.cpp:171] Executor started at:
executor(33)@67.195.138.60:45691 with pid 17316
I0728 05:44:39.573977 17336 slave.cpp:1423] Got registration for executor
'default' of framework 201307280544-1015726915-45691-17316-0000
I0728 05:44:39.574506 17336 slave.cpp:1538] Flushing queued task 0 for executor
'default' of framework 201307280544-1015726915-45691-17316-0000
I0728 05:44:39.574542 17339 exec.cpp:195] Executor registered on slave
201307280544-1015726915-45691-17316-0
I0728 05:44:39.575780 17339 exec.cpp:206] Executor::registered took 10.559us
I0728 05:44:39.576272 17339 exec.cpp:274] Executor asked to run task '0'
I0728 05:44:39.576740 17339 exec.cpp:283] Executor::launchTask took 18.296us
I0728 05:44:39.577118 17341 sched.cpp:178] New master at
[email protected]:45691
I0728 05:44:39.577848 17342 master.cpp:633] Registering framework
201307280544-1015726915-45691-17316-0001 at scheduler(92)@67.195.138.60:45691
I0728 05:44:39.578296 17341 sched.cpp:237] Framework registered with
201307280544-1015726915-45691-17316-0001
I0728 05:44:39.579476 17341 sched.cpp:251] Scheduler::registered took 10.494us
I0728 05:44:39.578330 17342 hierarchical_allocator_process.hpp:317] Added
framework 201307280544-1015726915-45691-17316-0001
I0728 05:44:39.580471 17342 hierarchical_allocator_process.hpp:709] Offering
cpus(*):1; mem(*):512; disk(*):21354; ports(*):[31000-32000] on slave
201307280544-1015726915-45691-17316-0 to framework
201307280544-1015726915-45691-17316-0001
I0728 05:44:39.581039 17342 hierarchical_allocator_process.hpp:782] Filtered
on slave 201307280544-1015726915-45691-17316-0 for framework
201307280544-1015726915-45691-17316-0000
I0728 05:44:39.581104 17340 master.hpp:328] Adding offer
201307280544-1015726915-45691-17316-1 with resources cpus(*):1; mem(*):512;
disk(*):21354; ports(*):[31000-32000] on slave
201307280544-1015726915-45691-17316-0
I0728 05:44:39.581946 17340 master.cpp:1322] Sending 1 offers to framework
201307280544-1015726915-45691-17316-0001
I0728 05:44:39.581423 17342 hierarchical_allocator_process.hpp:646] Performed
allocation for 1 slaves in 986.226us
I0728 05:44:39.582679 17337 sched.cpp:340] Scheduler::resourceOffers took
184.453us
I0728 05:44:39.584354 17337 master.cpp:1555] Processing reply for offer
201307280544-1015726915-45691-17316-1 on slave
201307280544-1015726915-45691-17316-0 (janus.apache.org) for framework
201307280544-1015726915-45691-17316-0001
I0728 05:44:39.584774 17337 master.hpp:306] Adding task 0 with resources
cpus(*):1; mem(*):256 on slave 201307280544-1015726915-45691-17316-0
I0728 05:44:39.585314 17337 master.cpp:1674] Launching task 0 of framework
201307280544-1015726915-45691-17316-0001 with resources cpus(*):1; mem(*):256
on slave 201307280544-1015726915-45691-17316-0 (janus.apache.org)
I0728 05:44:39.585803 17340 slave.cpp:747] Got assigned task 0 for framework
201307280544-1015726915-45691-17316-0001
I0728 05:44:39.585886 17337 master.hpp:338] Removing offer
201307280544-1015726915-45691-17316-1 with resources cpus(*):1; mem(*):512;
disk(*):21354; ports(*):[31000-32000] on slave
201307280544-1015726915-45691-17316-0
I0728 05:44:39.585945 17338 hierarchical_allocator_process.hpp:505] Framework
201307280544-1015726915-45691-17316-0001 left mem(*):256; disk(*):21354;
ports(*):[31000-32000] unused on slave 201307280544-1015726915-45691-17316-0
I0728 05:44:39.587718 17338 hierarchical_allocator_process.hpp:548] Framework
201307280544-1015726915-45691-17316-0001 filtered slave
201307280544-1015726915-45691-17316-0 for 5secs
I0728 05:44:39.586916 17340 slave.cpp:845] Launching task 0 for framework
201307280544-1015726915-45691-17316-0001
I0728 05:44:39.590025 17340 paths.hpp:303] Created executor directory
'/tmp/AllocatorTest_0_FrameworkExited_QcyASa/slaves/201307280544-1015726915-45691-17316-0/frameworks/201307280544-1015726915-45691-17316-0001/executors/default/runs/5089e7c2-ee3a-4d29-82cc-c6e4a864ef0b'
I0728 05:44:39.590183 17340 slave.cpp:956] Queuing task '0' for executor
default of framework '201307280544-1015726915-45691-17316-0001
I0728 05:44:39.590538 17340 slave.cpp:519] Successfully attached file
'/tmp/AllocatorTest_0_FrameworkExited_QcyASa/slaves/201307280544-1015726915-45691-17316-0/frameworks/201307280544-1015726915-45691-17316-0001/executors/default/runs/5089e7c2-ee3a-4d29-82cc-c6e4a864ef0b'
I0728 05:44:39.590304 17337 exec.cpp:171] Executor started at:
executor(34)@67.195.138.60:45691 with pid 17316
I0728 05:44:39.591727 17337 slave.cpp:1423] Got registration for executor
'default' of framework 201307280544-1015726915-45691-17316-0001
I0728 05:44:39.592270 17337 slave.cpp:1538] Flushing queued task 0 for executor
'default' of framework 201307280544-1015726915-45691-17316-0001
I0728 05:44:39.592315 17336 exec.cpp:195] Executor registered on slave
201307280544-1015726915-45691-17316-0
I0728 05:44:39.593175 17336 exec.cpp:206] Executor::registered took 11.709us
I0728 05:44:39.593696 17336 exec.cpp:274] Executor asked to run task '0'
I0728 05:44:39.594187 17336 exec.cpp:283] Executor::launchTask took 19.223us
I0728 05:44:39.594408 17338 sched.cpp:498] Stopping framework
'201307280544-1015726915-45691-17316-0000'
I0728 05:44:39.595914 17341 master.cpp:768] Asked to unregister framework
201307280544-1015726915-45691-17316-0000
I0728 05:44:39.596395 17338 slave.cpp:1140] Asked to shut down framework
201307280544-1015726915-45691-17316-0000 by [email protected]:45691
I0728 05:44:39.596402 17341 master.hpp:318] Removing task 0 with resources
cpus(*):2; mem(*):512 on slave 201307280544-1015726915-45691-17316-0
I0728 05:44:39.596441 17340 hierarchical_allocator_process.hpp:393] Deactivated
framework 201307280544-1015726915-45691-17316-0000
I0728 05:44:39.597856 17340 hierarchical_allocator_process.hpp:595] Recovered
cpus(*):2; mem(*):512 (total allocatable: mem(*):768; disk(*):21354;
ports(*):[31000-32000]; cpus(*):2) on slave
201307280544-1015726915-45691-17316-0 from framework
201307280544-1015726915-45691-17316-0000
I0728 05:44:39.598290 17340 hierarchical_allocator_process.hpp:348] Removed
framework 201307280544-1015726915-45691-17316-0000
I0728 05:44:39.598780 17340 hierarchical_allocator_process.hpp:709] Offering
mem(*):768; disk(*):21354; ports(*):[31000-32000]; cpus(*):2 on slave
201307280544-1015726915-45691-17316-0 to framework
201307280544-1015726915-45691-17316-0001
I0728 05:44:39.599339 17340 hierarchical_allocator_process.hpp:646] Performed
allocation for 1 slaves in 591.665us
I0728 05:44:39.596827 17338 slave.cpp:1165] Shutting down framework
201307280544-1015726915-45691-17316-0000
I0728 05:44:39.599407 17337 master.hpp:328] Adding offer
201307280544-1015726915-45691-17316-2 with resources mem(*):768; disk(*):21354;
ports(*):[31000-32000]; cpus(*):2 on slave 201307280544-1015726915-45691-17316-0
I0728 05:44:39.601564 17337 master.cpp:1322] Sending 1 offers to framework
201307280544-1015726915-45691-17316-0001
I0728 05:44:39.601083 17338 slave.cpp:2356] Shutting down executor 'default' of
framework 201307280544-1015726915-45691-17316-0000
I0728 05:44:39.602571 17341 sched.cpp:340] Scheduler::resourceOffers took
22.595us
I0728 05:44:39.603423 17341 sched.cpp:498] Stopping framework
'201307280544-1015726915-45691-17316-0001'
I0728 05:44:39.602937 17339 exec.cpp:360] Executor asked to shutdown
I0728 05:44:39.604413 17339 exec.cpp:375] Executor::shutdown took 13.194us
I0728 05:44:39.602673 17316 master.cpp:436] Master terminating
I0728 05:44:39.605444 17316 master.cpp:209] Shutting down master
I0728 05:44:39.605959 17337 hierarchical_allocator_process.hpp:393] Deactivated
framework 201307280544-1015726915-45691-17316-0001
I0728 05:44:39.605445 17338 slave.cpp:493] Slave asked to shut down by
[email protected]:45691
I0728 05:44:39.606889 17338 slave.cpp:1140] Asked to shut down framework
201307280544-1015726915-45691-17316-0001 by [email protected]:45691
I0728 05:44:39.607355 17338 slave.cpp:1165] Shutting down framework
201307280544-1015726915-45691-17316-0001
I0728 05:44:39.607890 17338 slave.cpp:2356] Shutting down executor 'default' of
framework 201307280544-1015726915-45691-17316-0001
I0728 05:44:39.608600 17338 slave.cpp:1140] Asked to shut down framework
201307280544-1015726915-45691-17316-0000 by [email protected]:45691
W0728 05:44:39.609060 17338 slave.cpp:1161] Ignoring shutdown framework
201307280544-1015726915-45691-17316-0000 because it is terminating
I0728 05:44:39.608614 17342 exec.cpp:360] Executor asked to shutdown
../../src/tests/allocator_tests.cpp:1172: Failure
Mock function called more times than expected - returning directly.
Function call: shutdown(0x2b6dd00260e0)
Expected: to be called at most once
Actual: called twice - over-saturated and active
I0728 05:44:39.610100 17342 exec.cpp:375] Executor::shutdown took 84.056us
I0728 05:44:39.609534 17338 slave.cpp:1912] [email protected]:45691 exited
W0728 05:44:39.611049 17338 slave.cpp:1915] Master disconnected! Waiting for a
new master to be elected
I0728 05:44:39.611551 17338 slave.cpp:1140] Asked to shut down framework
201307280544-1015726915-45691-17316-0001 by [email protected]:45691
W0728 05:44:39.612752 17338 slave.cpp:1161] Ignoring shutdown framework
201307280544-1015726915-45691-17316-0001 because it is terminating
I0728 05:44:39.605974 17316 master.hpp:318] Removing task 0 with resources
cpus(*):1; mem(*):256 on slave 201307280544-1015726915-45691-17316-0
I0728 05:44:39.613939 17316 master.hpp:338] Removing offer
201307280544-1015726915-45691-17316-2 with resources mem(*):768; disk(*):21354;
ports(*):[31000-32000]; cpus(*):2 on slave 201307280544-1015726915-45691-17316-0
I0728 05:44:39.614019 17343 hierarchical_allocator_process.hpp:595] Recovered
cpus(*):1; mem(*):256 (total allocatable: cpus(*):1; mem(*):256) on slave
201307280544-1015726915-45691-17316-0 from framework
201307280544-1015726915-45691-17316-0001
I0728 05:44:39.614902 17343 hierarchical_allocator_process.hpp:595] Recovered
mem(*):768; disk(*):21354; ports(*):[31000-32000]; cpus(*):2 (total
allocatable: cpus(*):3; mem(*):1024; disk(*):21354; ports(*):[31000-32000]) on
slave 201307280544-1015726915-45691-17316-0 from framework
201307280544-1015726915-45691-17316-0001
I0728 05:44:39.615298 17343 hierarchical_allocator_process.hpp:348] Removed
framework 201307280544-1015726915-45691-17316-0001
I0728 05:44:39.615813 17343 hierarchical_allocator_process.hpp:456] Removed
slave 201307280544-1015726915-45691-17316-0
I0728 05:44:39.614557 17316 slave.cpp:448] Slave terminating
I0728 05:44:39.617005 17316 slave.cpp:1140] Asked to shut down framework
201307280544-1015726915-45691-17316-0001 by @0.0.0.0:0
W0728 05:44:39.617482 17316 slave.cpp:1161] Ignoring shutdown framework
201307280544-1015726915-45691-17316-0001 because it is terminating
I0728 05:44:39.617980 17316 slave.cpp:1140] Asked to shut down framework
201307280544-1015726915-45691-17316-0000 by @0.0.0.0:0
W0728 05:44:39.618458 17316 slave.cpp:1161] Ignoring shutdown framework
201307280544-1015726915-45691-17316-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> (74 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
