I committed a fix:
commit ec3a5423a1205053fe4ef4a44ead0ed1338169f0
Author: Jie Yu <[email protected]>
Date: Fri Dec 4 12:26:10 2015 -0800
Fixed the flaky PersistentVolumeTest.SlaveRecovery test.
Review: https://reviews.apache.org/r/40985
On Fri, Dec 4, 2015 at 11:34 AM, Jie Yu <[email protected]> wrote:
> https://issues.apache.org/jira/browse/MESOS-3907
>
> On Fri, Dec 4, 2015 at 1:10 AM, Michael Park <[email protected]> wrote:
>
>> +Jie Yu <[email protected]> as the author of the test.
>>
>> This one looks a bit tricky to me. Will continue looking tomorrow.
>>
>> On Thu, Dec 3, 2015 at 10:50 PM Benjamin Mahler <
>> [email protected]> wrote:
>>
>>> Thank you sir!
>>>
>>> On Thu, Dec 3, 2015 at 7:45 PM, Michael Park <[email protected]>
>>> wrote:
>>>
>>>> Yep, I'll look into it once I get back to a computer.
>>>>
>>>> On Thu, Dec 3, 2015, 10:44 PM Benjamin Mahler <
>>>> [email protected]> wrote:
>>>>
>>>>> Michael, this looks like
>>>>> https://issues.apache.org/jira/browse/MESOS-3907? Can you please
>>>>> triage it?
>>>>>
>>>>> Tim, I've added details to
>>>>> https://issues.apache.org/jira/browse/MESOS-4024. Can you please
>>>>> triage it? Also, the test takes 16 seconds to finish? :(
>>>>>
>>>>> On Tue, Dec 1, 2015 at 5:13 AM, Apache Jenkins Server <
>>>>> [email protected]> wrote:
>>>>>
>>>>>> See <
>>>>>> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1298/changes
>>>>>> >
>>>>>>
>>>>>> Changes:
>>>>>>
>>>>>> [mpark] Introduced filter for non-revocable resources.
>>>>>>
>>>>>> [mpark] Updated codebase to use `nonRevocable()` where appropriate.
>>>>>>
>>>>>> ------------------------------------------
>>>>>> [...truncated 150475 lines...]
>>>>>> I1201 13:13:39.133826 30312 gc.cpp:54] Scheduling
>>>>>> '/tmp/ContentType_SchedulerTest_Message_1_TaiosT/slaves/4ee094e8-02a9-49de-b684-4d65e1dbab3a-S0/frameworks/4ee094e8-02a9-49de-b684-4d65e1dbab3a-0000/executors/default'
>>>>>> for gc 6.9999984545837days in the future
>>>>>> I1201 13:13:39.133921 30312 gc.cpp:54] Scheduling
>>>>>> '/tmp/ContentType_SchedulerTest_Message_1_TaiosT/slaves/4ee094e8-02a9-49de-b684-4d65e1dbab3a-S0/frameworks/4ee094e8-02a9-49de-b684-4d65e1dbab3a-0000'
>>>>>> for gc 6.99999845272days in the future
>>>>>> I1201 13:13:39.134052 30312 status_update_manager.cpp:282] Closing
>>>>>> status update streams for framework
>>>>>> 4ee094e8-02a9-49de-b684-4d65e1dbab3a-0000
>>>>>> I1201 13:13:39.134109 30312 status_update_manager.cpp:528] Cleaning
>>>>>> up status update stream for task df889fba-4ec5-48a2-bb6a-b82e50d823ee of
>>>>>> framework 4ee094e8-02a9-49de-b684-4d65e1dbab3a-0000
>>>>>> [ OK ] ContentType/SchedulerTest.Message/1 (620 ms)
>>>>>> [ RUN ] ContentType/SchedulerTest.Request/0
>>>>>> I1201 13:13:39.249682 30288 leveldb.cpp:174] Opened db in 108.293757ms
>>>>>> I1201 13:13:39.286597 30288 leveldb.cpp:181] Compacted db in
>>>>>> 36.820837ms
>>>>>> I1201 13:13:39.286878 30288 leveldb.cpp:196] Created db iterator in
>>>>>> 28745ns
>>>>>> I1201 13:13:39.287019 30288 leveldb.cpp:202] Seeked to beginning of
>>>>>> db in 4075ns
>>>>>> I1201 13:13:39.287135 30288 leveldb.cpp:271] Iterated through 0 keys
>>>>>> in the db in 506ns
>>>>>> I1201 13:13:39.287328 30288 replica.cpp:778] Replica recovered with
>>>>>> log positions 0 -> 0 with 1 holes and 0 unlearned
>>>>>> I1201 13:13:39.288477 30322 recover.cpp:447] Starting replica recovery
>>>>>> I1201 13:13:39.288979 30322 recover.cpp:473] Replica is in EMPTY
>>>>>> status
>>>>>> I1201 13:13:39.291091 30307 replica.cpp:674] Replica in EMPTY status
>>>>>> received a broadcasted recover request from (11259)@172.17.21.0:52024
>>>>>> I1201 13:13:39.292063 30322 recover.cpp:193] Received a recover
>>>>>> response from a replica in EMPTY status
>>>>>> I1201 13:13:39.292816 30322 recover.cpp:564] Updating replica status
>>>>>> to STARTING
>>>>>> I1201 13:13:39.310650 30317 master.cpp:365] Master
>>>>>> afc8b3bb-8b30-42f9-bb3d-e218e05c5758 (fa812f474cf4) started on
>>>>>> 172.17.21.0:52024
>>>>>> I1201 13:13:39.310979 30317 master.cpp:367] Flags at startup:
>>>>>> --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF"
>>>>>> --authenticate="false" --authenticate_slaves="true"
>>>>>> --authenticators="crammd5" --authorizers="local"
>>>>>> --credentials="/tmp/ZHbR13/credentials" --framework_sorter="drf"
>>>>>> --help="false" --hostname_lookup="true"
>>>>>> --initialize_driver_logging="true"
>>>>>> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
>>>>>> --max_slave_ping_timeouts="5" --quiet="false"
>>>>>> --recovery_slave_removal_limit="100%" --registry="replicated_log"
>>>>>> --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
>>>>>> --registry_strict="true" --root_submissions="true"
>>>>>> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
>>>>>> --user_sorter="drf" --version="false"
>>>>>> --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui"
>>>>>> --work_dir="/tmp/ZHbR13/master" --zk_session_timeout="10secs"
>>>>>> I1201 13:13:39.311813 30317 master.cpp:414] Master allowing
>>>>>> unauthenticated frameworks to register
>>>>>> I1201 13:13:39.311939 30317 master.cpp:417] Master only allowing
>>>>>> authenticated slaves to register
>>>>>> I1201 13:13:39.312055 30317 credentials.hpp:35] Loading credentials
>>>>>> for authentication from '/tmp/ZHbR13/credentials'
>>>>>> I1201 13:13:39.312582 30317 master.cpp:456] Using default 'crammd5'
>>>>>> authenticator
>>>>>> I1201 13:13:39.313015 30317 master.cpp:493] Authorization enabled
>>>>>> I1201 13:13:39.314574 30318 hierarchical.cpp:162] Initialized
>>>>>> hierarchical allocator process
>>>>>> I1201 13:13:39.314782 30318 whitelist_watcher.cpp:77] No whitelist
>>>>>> given
>>>>>> I1201 13:13:39.319352 30314 leveldb.cpp:304] Persisting metadata (8
>>>>>> bytes) to leveldb took 26.131683ms
>>>>>> I1201 13:13:39.319414 30314 replica.cpp:321] Persisted replica status
>>>>>> to STARTING
>>>>>> I1201 13:13:39.319850 30321 recover.cpp:473] Replica is in STARTING
>>>>>> status
>>>>>> I1201 13:13:39.321290 30317 master.cpp:1637] The newly elected leader
>>>>>> is [email protected]:52024 with id
>>>>>> afc8b3bb-8b30-42f9-bb3d-e218e05c5758
>>>>>> I1201 13:13:39.321327 30317 master.cpp:1650] Elected as the leading
>>>>>> master!
>>>>>> I1201 13:13:39.321348 30317 master.cpp:1395] Recovering from registrar
>>>>>> I1201 13:13:39.321607 30310 registrar.cpp:307] Recovering registrar
>>>>>> I1201 13:13:39.322362 30308 replica.cpp:674] Replica in STARTING
>>>>>> status received a broadcasted recover request from (11261)@
>>>>>> 172.17.21.0:52024
>>>>>> I1201 13:13:39.323760 30308 recover.cpp:193] Received a recover
>>>>>> response from a replica in STARTING status
>>>>>> I1201 13:13:39.324712 30308 recover.cpp:564] Updating replica status
>>>>>> to VOTING
>>>>>> I1201 13:13:39.344523 30322 leveldb.cpp:304] Persisting metadata (8
>>>>>> bytes) to leveldb took 19.367885ms
>>>>>> I1201 13:13:39.344609 30322 replica.cpp:321] Persisted replica status
>>>>>> to VOTING
>>>>>> I1201 13:13:39.344866 30322 recover.cpp:578] Successfully joined the
>>>>>> Paxos group
>>>>>> I1201 13:13:39.345070 30322 recover.cpp:462] Recover process
>>>>>> terminated
>>>>>> I1201 13:13:39.346154 30313 log.cpp:659] Attempting to start the
>>>>>> writer
>>>>>> I1201 13:13:39.348711 30322 replica.cpp:494] Replica received
>>>>>> implicit promise request from (11262)@172.17.21.0:52024 with
>>>>>> proposal 1
>>>>>> I1201 13:13:39.369730 30322 leveldb.cpp:304] Persisting metadata (8
>>>>>> bytes) to leveldb took 20.816751ms
>>>>>> I1201 13:13:39.369815 30322 replica.cpp:343] Persisted promised to 1
>>>>>> I1201 13:13:39.371050 30322 coordinator.cpp:238] Coordinator
>>>>>> attempting to fill missing positions
>>>>>> I1201 13:13:39.373064 30322 replica.cpp:389] Replica received
>>>>>> explicit promise request from (11263)@172.17.21.0:52024 for position
>>>>>> 0 with proposal 2
>>>>>> I1201 13:13:39.394858 30322 leveldb.cpp:341] Persisting action (8
>>>>>> bytes) to leveldb took 21.553914ms
>>>>>> I1201 13:13:39.394944 30322 replica.cpp:713] Persisted action at 0
>>>>>> I1201 13:13:39.397928 30320 replica.cpp:538] Replica received write
>>>>>> request for position 0 from (11264)@172.17.21.0:52024
>>>>>> I1201 13:13:39.398121 30320 leveldb.cpp:436] Reading position from
>>>>>> leveldb took 138547ns
>>>>>> I1201 13:13:39.420068 30320 leveldb.cpp:341] Persisting action (14
>>>>>> bytes) to leveldb took 21.856586ms
>>>>>> I1201 13:13:39.420158 30320 replica.cpp:713] Persisted action at 0
>>>>>> I1201 13:13:39.421149 30320 replica.cpp:692] Replica received learned
>>>>>> notice for position 0 from @0.0.0.0:0
>>>>>> I1201 13:13:39.445179 30320 leveldb.cpp:341] Persisting action (16
>>>>>> bytes) to leveldb took 22.672674ms
>>>>>> I1201 13:13:39.445264 30320 replica.cpp:713] Persisted action at 0
>>>>>> I1201 13:13:39.445297 30320 replica.cpp:698] Replica learned NOP
>>>>>> action at position 0
>>>>>> I1201 13:13:39.446470 30317 log.cpp:675] Writer started with ending
>>>>>> position 0
>>>>>> I1201 13:13:39.448024 30317 leveldb.cpp:436] Reading position from
>>>>>> leveldb took 54316ns
>>>>>> I1201 13:13:39.457492 30314 registrar.cpp:340] Successfully fetched
>>>>>> the registry (0B) in 135.67488ms
>>>>>> I1201 13:13:39.457800 30314 registrar.cpp:439] Applied 1 operations
>>>>>> in 58207ns; attempting to update the 'registry'
>>>>>> I1201 13:13:39.461079 30307 log.cpp:683] Attempting to append 171
>>>>>> bytes to the log
>>>>>> I1201 13:13:39.461359 30307 coordinator.cpp:348] Coordinator
>>>>>> attempting to write APPEND action at position 1
>>>>>> I1201 13:13:39.462405 30315 replica.cpp:538] Replica received write
>>>>>> request for position 1 from (11265)@172.17.21.0:52024
>>>>>> I1201 13:13:39.486935 30315 leveldb.cpp:341] Persisting action (190
>>>>>> bytes) to leveldb took 24.470564ms
>>>>>> I1201 13:13:39.487015 30315 replica.cpp:713] Persisted action at 1
>>>>>> I1201 13:13:39.488296 30311 replica.cpp:692] Replica received learned
>>>>>> notice for position 1 from @0.0.0.0:0
>>>>>> I1201 13:13:39.512262 30311 leveldb.cpp:341] Persisting action (192
>>>>>> bytes) to leveldb took 23.909555ms
>>>>>> I1201 13:13:39.512357 30311 replica.cpp:713] Persisted action at 1
>>>>>> I1201 13:13:39.512395 30311 replica.cpp:698] Replica learned APPEND
>>>>>> action at position 1
>>>>>> I1201 13:13:39.514448 30315 registrar.cpp:484] Successfully updated
>>>>>> the 'registry' in 56.57088ms
>>>>>> I1201 13:13:39.514611 30315 registrar.cpp:370] Successfully recovered
>>>>>> registrar
>>>>>> I1201 13:13:39.514899 30315 log.cpp:702] Attempting to truncate the
>>>>>> log to 1
>>>>>> I1201 13:13:39.515408 30321 master.cpp:1447] Recovered 0 slaves from
>>>>>> the Registry (132B) ; allowing 10mins for slaves to re-register
>>>>>> I1201 13:13:39.515601 30321 hierarchical.cpp:174] Allocator recovery
>>>>>> is not supported yet
>>>>>> I1201 13:13:39.515990 30311 coordinator.cpp:348] Coordinator
>>>>>> attempting to write TRUNCATE action at position 2
>>>>>> I1201 13:13:39.519279 30322 replica.cpp:538] Replica received write
>>>>>> request for position 2 from (11266)@172.17.21.0:52024
>>>>>> I1201 13:13:39.545508 30322 leveldb.cpp:341] Persisting action (16
>>>>>> bytes) to leveldb took 26.14166ms
>>>>>> I1201 13:13:39.545591 30322 replica.cpp:713] Persisted action at 2
>>>>>> I1201 13:13:39.547046 30311 replica.cpp:692] Replica received learned
>>>>>> notice for position 2 from @0.0.0.0:0
>>>>>> I1201 13:13:39.570616 30311 leveldb.cpp:341] Persisting action (18
>>>>>> bytes) to leveldb took 22.715014ms
>>>>>> I1201 13:13:39.570765 30311 leveldb.cpp:399] Deleting ~1 keys from
>>>>>> leveldb took 68387ns
>>>>>> I1201 13:13:39.570792 30311 replica.cpp:713] Persisted action at 2
>>>>>> I1201 13:13:39.570827 30311 replica.cpp:698] Replica learned TRUNCATE
>>>>>> action at position 2
>>>>>> I1201 13:13:39.581652 30288 scheduler.cpp:154] Version: 0.27.0
>>>>>> I1201 13:13:39.582635 30316 scheduler.cpp:236] New master detected at
>>>>>> [email protected]:52024
>>>>>> I1201 13:13:39.596861 30321 scheduler.cpp:298] Sending SUBSCRIBE call
>>>>>> to [email protected]:52024
>>>>>> I1201 13:13:39.603560 30314 process.cpp:3067] Handling HTTP event for
>>>>>> process 'master' with path: '/master/api/v1/scheduler'
>>>>>> I1201 13:13:39.603791 30314 http.cpp:336] HTTP POST for
>>>>>> /master/api/v1/scheduler from 172.17.21.0:58671
>>>>>> I1201 13:13:39.604238 30314 master.cpp:1899] Received subscription
>>>>>> request for HTTP framework 'default'
>>>>>> I1201 13:13:39.604393 30314 master.cpp:1676] Authorizing framework
>>>>>> principal 'test-principal' to receive offers for role '*'
>>>>>> I1201 13:13:39.605239 30308 master.cpp:1991] Subscribing framework
>>>>>> 'default' with checkpointing disabled and capabilities [ ]
>>>>>> I1201 13:13:39.605927 30308 hierarchical.cpp:220] Added framework
>>>>>> afc8b3bb-8b30-42f9-bb3d-e218e05c5758-0000
>>>>>> I1201 13:13:39.606053 30308 hierarchical.cpp:1062] No resources
>>>>>> available to allocate!
>>>>>> I1201 13:13:39.606200 30308 hierarchical.cpp:1155] No inverse offers
>>>>>> to send out!
>>>>>> I1201 13:13:39.606287 30308 hierarchical.cpp:957] Performed
>>>>>> allocation for 0 slaves in 278800ns
>>>>>> I1201 13:13:39.606386 30308 master.hpp:1542] Sending heartbeat to
>>>>>> afc8b3bb-8b30-42f9-bb3d-e218e05c5758-0000
>>>>>> I1201 13:13:39.610970 30313 scheduler.cpp:457] Enqueuing event
>>>>>> SUBSCRIBED received from [email protected]:52024
>>>>>> I1201 13:13:39.611906 30313 scheduler.cpp:457] Enqueuing event
>>>>>> HEARTBEAT received from [email protected]:52024
>>>>>> I1201 13:13:39.612519 30313 master_maintenance_tests.cpp:172]
>>>>>> Ignoring HEARTBEAT event
>>>>>> I1201 13:13:39.613566 30322 scheduler.cpp:298] Sending REQUEST call
>>>>>> to [email protected]:52024
>>>>>> I1201 13:13:39.616225 30314 process.cpp:3067] Handling HTTP event for
>>>>>> process 'master' with path: '/master/api/v1/scheduler'
>>>>>> I1201 13:13:39.616303 30314 http.cpp:336] HTTP POST for
>>>>>> /master/api/v1/scheduler from 172.17.21.0:58672
>>>>>> I1201 13:13:39.616457 30314 master.cpp:2646] Processing REQUEST call
>>>>>> for framework afc8b3bb-8b30-42f9-bb3d-e218e05c5758-0000 (default)
>>>>>> I1201 13:13:39.616729 30314 hierarchical.cpp:492] Received resource
>>>>>> request from framework afc8b3bb-8b30-42f9-bb3d-e218e05c5758-0000
>>>>>> I1201 13:13:39.618245 30316 master.cpp:938] Master terminating
>>>>>> I1201 13:13:39.618852 30316 hierarchical.cpp:260] Removed framework
>>>>>> afc8b3bb-8b30-42f9-bb3d-e218e05c5758-0000
>>>>>> E1201 13:13:39.625231 30320 scheduler.cpp:431] End-Of-File received
>>>>>> from master. The master closed the event stream
>>>>>> [ OK ] ContentType/SchedulerTest.Request/0 (537 ms)
>>>>>> [ RUN ] ContentType/SchedulerTest.Request/1
>>>>>> I1201 13:13:39.781806 30288 leveldb.cpp:174] Opened db in 103.133011ms
>>>>>> I1201 13:13:39.823753 30288 leveldb.cpp:181] Compacted db in
>>>>>> 41.862895ms
>>>>>> I1201 13:13:39.824023 30288 leveldb.cpp:196] Created db iterator in
>>>>>> 28393ns
>>>>>> I1201 13:13:39.824106 30288 leveldb.cpp:202] Seeked to beginning of
>>>>>> db in 3402ns
>>>>>> I1201 13:13:39.824213 30288 leveldb.cpp:271] Iterated through 0 keys
>>>>>> in the db in 424ns
>>>>>> I1201 13:13:39.824362 30288 replica.cpp:778] Replica recovered with
>>>>>> log positions 0 -> 0 with 1 holes and 0 unlearned
>>>>>> I1201 13:13:39.825932 30314 recover.cpp:447] Starting replica recovery
>>>>>> I1201 13:13:39.829377 30312 recover.cpp:473] Replica is in EMPTY
>>>>>> status
>>>>>> I1201 13:13:39.831303 30321 replica.cpp:674] Replica in EMPTY status
>>>>>> received a broadcasted recover request from (11270)@172.17.21.0:52024
>>>>>> I1201 13:13:39.831908 30312 recover.cpp:193] Received a recover
>>>>>> response from a replica in EMPTY status
>>>>>> I1201 13:13:39.832659 30308 recover.cpp:564] Updating replica status
>>>>>> to STARTING
>>>>>> I1201 13:13:39.842226 30310 master.cpp:365] Master
>>>>>> f1235cbb-2af4-4048-8379-cb927ec30140 (fa812f474cf4) started on
>>>>>> 172.17.21.0:52024
>>>>>> I1201 13:13:39.842382 30310 master.cpp:367] Flags at startup:
>>>>>> --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF"
>>>>>> --authenticate="false" --authenticate_slaves="true"
>>>>>> --authenticators="crammd5" --authorizers="local"
>>>>>> --credentials="/tmp/BZ8798/credentials" --framework_sorter="drf"
>>>>>> --help="false" --hostname_lookup="true"
>>>>>> --initialize_driver_logging="true"
>>>>>> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
>>>>>> --max_slave_ping_timeouts="5" --quiet="false"
>>>>>> --recovery_slave_removal_limit="100%" --registry="replicated_log"
>>>>>> --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
>>>>>> --registry_strict="true" --root_submissions="true"
>>>>>> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
>>>>>> --user_sorter="drf" --version="false"
>>>>>> --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui"
>>>>>> --work_dir="/tmp/BZ8798/master" --zk_session_timeout="10secs"
>>>>>> I1201 13:13:39.843057 30310 master.cpp:414] Master allowing
>>>>>> unauthenticated frameworks to register
>>>>>> I1201 13:13:39.843125 30310 master.cpp:417] Master only allowing
>>>>>> authenticated slaves to register
>>>>>> I1201 13:13:39.843212 30310 credentials.hpp:35] Loading credentials
>>>>>> for authentication from '/tmp/BZ8798/credentials'
>>>>>> I1201 13:13:39.854533 30310 master.cpp:456] Using default 'crammd5'
>>>>>> authenticator
>>>>>> I1201 13:13:39.854784 30310 master.cpp:493] Authorization enabled
>>>>>> I1201 13:13:39.855118 30316 whitelist_watcher.cpp:77] No whitelist
>>>>>> given
>>>>>> I1201 13:13:39.855201 30307 hierarchical.cpp:162] Initialized
>>>>>> hierarchical allocator process
>>>>>> I1201 13:13:39.857786 30308 master.cpp:1637] The newly elected leader
>>>>>> is [email protected]:52024 with id
>>>>>> f1235cbb-2af4-4048-8379-cb927ec30140
>>>>>> I1201 13:13:39.857890 30308 master.cpp:1650] Elected as the leading
>>>>>> master!
>>>>>> I1201 13:13:39.858012 30308 master.cpp:1395] Recovering from registrar
>>>>>> I1201 13:13:39.858214 30321 registrar.cpp:307] Recovering registrar
>>>>>> I1201 13:13:39.987658 30312 leveldb.cpp:304] Persisting metadata (8
>>>>>> bytes) to leveldb took 154.538135ms
>>>>>> I1201 13:13:39.987746 30312 replica.cpp:321] Persisted replica status
>>>>>> to STARTING
>>>>>> I1201 13:13:39.988102 30309 recover.cpp:473] Replica is in STARTING
>>>>>> status
>>>>>> I1201 13:13:39.989462 30312 replica.cpp:674] Replica in STARTING
>>>>>> status received a broadcasted recover request from (11272)@
>>>>>> 172.17.21.0:52024
>>>>>> I1201 13:13:39.989681 30319 recover.cpp:193] Received a recover
>>>>>> response from a replica in STARTING status
>>>>>> I1201 13:13:39.990227 30315 recover.cpp:564] Updating replica status
>>>>>> to VOTING
>>>>>> 2015-12-01
>>>>>> 13:13:40,008:30288(0x2b1492486700):ZOO_ERROR@handle_socket_error_msg@1697:
>>>>>> Socket [127.0.0.1:38773] zk retcode=-4, errno=111(Connection
>>>>>> refused): server refused to accept the client
>>>>>> I1201 13:13:40.144186 30315 leveldb.cpp:304] Persisting metadata (8
>>>>>> bytes) to leveldb took 153.522723ms
>>>>>> I1201 13:13:40.144278 30315 replica.cpp:321] Persisted replica status
>>>>>> to VOTING
>>>>>> I1201 13:13:40.144538 30315 recover.cpp:578] Successfully joined the
>>>>>> Paxos group
>>>>>> I1201 13:13:40.144737 30315 recover.cpp:462] Recover process
>>>>>> terminated
>>>>>> I1201 13:13:40.145442 30315 log.cpp:659] Attempting to start the
>>>>>> writer
>>>>>> I1201 13:13:40.147264 30315 replica.cpp:494] Replica received
>>>>>> implicit promise request from (11273)@172.17.21.0:52024 with
>>>>>> proposal 1
>>>>>> I1201 13:13:40.177583 30315 leveldb.cpp:304] Persisting metadata (8
>>>>>> bytes) to leveldb took 30.196031ms
>>>>>> I1201 13:13:40.177677 30315 replica.cpp:343] Persisted promised to 1
>>>>>> I1201 13:13:40.178966 30315 coordinator.cpp:238] Coordinator
>>>>>> attempting to fill missing positions
>>>>>> I1201 13:13:40.180896 30308 replica.cpp:389] Replica received
>>>>>> explicit promise request from (11274)@172.17.21.0:52024 for position
>>>>>> 0 with proposal 2
>>>>>> I1201 13:13:40.202713 30308 leveldb.cpp:341] Persisting action (8
>>>>>> bytes) to leveldb took 21.637902ms
>>>>>> I1201 13:13:40.202796 30308 replica.cpp:713] Persisted action at 0
>>>>>> I1201 13:13:40.204490 30315 replica.cpp:538] Replica received write
>>>>>> request for position 0 from (11275)@172.17.21.0:52024
>>>>>> I1201 13:13:40.204653 30315 leveldb.cpp:436] Reading position from
>>>>>> leveldb took 57423ns
>>>>>> I1201 13:13:40.227870 30315 leveldb.cpp:341] Persisting action (14
>>>>>> bytes) to leveldb took 23.068613ms
>>>>>> I1201 13:13:40.227952 30315 replica.cpp:713] Persisted action at 0
>>>>>> I1201 13:13:40.228931 30315 replica.cpp:692] Replica received learned
>>>>>> notice for position 0 from @0.0.0.0:0
>>>>>> I1201 13:13:40.253105 30315 leveldb.cpp:341] Persisting action (16
>>>>>> bytes) to leveldb took 24.122945ms
>>>>>> I1201 13:13:40.253196 30315 replica.cpp:713] Persisted action at 0
>>>>>> I1201 13:13:40.253229 30315 replica.cpp:698] Replica learned NOP
>>>>>> action at position 0
>>>>>> I1201 13:13:40.261934 30319 log.cpp:675] Writer started with ending
>>>>>> position 0
>>>>>> I1201 13:13:40.263435 30319 leveldb.cpp:436] Reading position from
>>>>>> leveldb took 51852ns
>>>>>> I1201 13:13:40.264667 30319 registrar.cpp:340] Successfully fetched
>>>>>> the registry (0B) in 406.404096ms
>>>>>> I1201 13:13:40.264837 30319 registrar.cpp:439] Applied 1 operations
>>>>>> in 32037ns; attempting to update the 'registry'
>>>>>> I1201 13:13:40.266000 30319 log.cpp:683] Attempting to append 171
>>>>>> bytes to the log
>>>>>> I1201 13:13:40.266196 30319 coordinator.cpp:348] Coordinator
>>>>>> attempting to write APPEND action at position 1
>>>>>> I1201 13:13:40.267202 30319 replica.cpp:538] Replica received write
>>>>>> request for position 1 from (11276)@172.17.21.0:52024
>>>>>> I1201 13:13:40.306112 30319 leveldb.cpp:341] Persisting action (190
>>>>>> bytes) to leveldb took 38.855065ms
>>>>>> I1201 13:13:40.306206 30319 replica.cpp:713] Persisted action at 1
>>>>>> I1201 13:13:40.311035 30312 replica.cpp:692] Replica received learned
>>>>>> notice for position 1 from @0.0.0.0:0
>>>>>> I1201 13:13:40.339625 30312 leveldb.cpp:341] Persisting action (192
>>>>>> bytes) to leveldb took 28.359915ms
>>>>>> I1201 13:13:40.339715 30312 replica.cpp:713] Persisted action at 1
>>>>>> I1201 13:13:40.339754 30312 replica.cpp:698] Replica learned APPEND
>>>>>> action at position 1
>>>>>> I1201 13:13:40.341955 30309 registrar.cpp:484] Successfully updated
>>>>>> the 'registry' in 77.036288ms
>>>>>> I1201 13:13:40.342131 30309 registrar.cpp:370] Successfully recovered
>>>>>> registrar
>>>>>> I1201 13:13:40.342241 30313 log.cpp:702] Attempting to truncate the
>>>>>> log to 1
>>>>>> I1201 13:13:40.342452 30313 coordinator.cpp:348] Coordinator
>>>>>> attempting to write TRUNCATE action at position 2
>>>>>> I1201 13:13:40.343538 30317 replica.cpp:538] Replica received write
>>>>>> request for position 2 from (11277)@172.17.21.0:52024
>>>>>> I1201 13:13:40.344214 30309 master.cpp:1447] Recovered 0 slaves from
>>>>>> the Registry (132B) ; allowing 10mins for slaves to re-register
>>>>>> I1201 13:13:40.344310 30309 hierarchical.cpp:174] Allocator recovery
>>>>>> is not supported yet
>>>>>> I1201 13:13:40.373257 30317 leveldb.cpp:341] Persisting action (16
>>>>>> bytes) to leveldb took 29.65284ms
>>>>>> I1201 13:13:40.373345 30317 replica.cpp:713] Persisted action at 2
>>>>>> I1201 13:13:40.374905 30317 replica.cpp:692] Replica received learned
>>>>>> notice for position 2 from @0.0.0.0:0
>>>>>> I1201 13:13:40.406621 30317 leveldb.cpp:341] Persisting action (18
>>>>>> bytes) to leveldb took 31.661429ms
>>>>>> I1201 13:13:40.406776 30317 leveldb.cpp:399] Deleting ~1 keys from
>>>>>> leveldb took 75229ns
>>>>>> I1201 13:13:40.406803 30317 replica.cpp:713] Persisted action at 2
>>>>>> I1201 13:13:40.406837 30317 replica.cpp:698] Replica learned TRUNCATE
>>>>>> action at position 2
>>>>>> I1201 13:13:40.416626 30288 scheduler.cpp:154] Version: 0.27.0
>>>>>> I1201 13:13:40.418025 30317 scheduler.cpp:236] New master detected at
>>>>>> [email protected]:52024
>>>>>> I1201 13:13:40.419311 30311 scheduler.cpp:298] Sending SUBSCRIBE call
>>>>>> to [email protected]:52024
>>>>>> I1201 13:13:40.421510 30309 process.cpp:3067] Handling HTTP event for
>>>>>> process 'master' with path: '/master/api/v1/scheduler'
>>>>>> I1201 13:13:40.421581 30309 http.cpp:336] HTTP POST for
>>>>>> /master/api/v1/scheduler from 172.17.21.0:58674
>>>>>> I1201 13:13:40.421988 30309 master.cpp:1899] Received subscription
>>>>>> request for HTTP framework 'default'
>>>>>> I1201 13:13:40.422067 30309 master.cpp:1676] Authorizing framework
>>>>>> principal 'test-principal' to receive offers for role '*'
>>>>>> I1201 13:13:40.422495 30309 master.cpp:1991] Subscribing framework
>>>>>> 'default' with checkpointing disabled and capabilities [ ]
>>>>>> I1201 13:13:40.423338 30314 hierarchical.cpp:220] Added framework
>>>>>> f1235cbb-2af4-4048-8379-cb927ec30140-0000
>>>>>> I1201 13:13:40.423396 30314 hierarchical.cpp:1062] No resources
>>>>>> available to allocate!
>>>>>> I1201 13:13:40.423430 30314 hierarchical.cpp:1155] No inverse offers
>>>>>> to send out!
>>>>>> I1201 13:13:40.423452 30314 hierarchical.cpp:957] Performed
>>>>>> allocation for 0 slaves in 88470ns
>>>>>> I1201 13:13:40.423480 30314 master.hpp:1542] Sending heartbeat to
>>>>>> f1235cbb-2af4-4048-8379-cb927ec30140-0000
>>>>>> I1201 13:13:40.430143 30314 scheduler.cpp:457] Enqueuing event
>>>>>> SUBSCRIBED received from [email protected]:52024
>>>>>> I1201 13:13:40.431577 30311 scheduler.cpp:457] Enqueuing event
>>>>>> HEARTBEAT received from [email protected]:52024
>>>>>> I1201 13:13:40.432108 30311 master_maintenance_tests.cpp:172]
>>>>>> Ignoring HEARTBEAT event
>>>>>> I1201 13:13:40.432857 30310 scheduler.cpp:298] Sending REQUEST call
>>>>>> to [email protected]:52024
>>>>>> I1201 13:13:40.435833 30318 process.cpp:3067] Handling HTTP event for
>>>>>> process 'master' with path: '/master/api/v1/scheduler'
>>>>>> I1201 13:13:40.435905 30318 http.cpp:336] HTTP POST for
>>>>>> /master/api/v1/scheduler from 172.17.21.0:58675
>>>>>> I1201 13:13:40.436228 30318 master.cpp:2646] Processing REQUEST call
>>>>>> for framework f1235cbb-2af4-4048-8379-cb927ec30140-0000 (default)
>>>>>> I1201 13:13:40.436463 30318 hierarchical.cpp:492] Received resource
>>>>>> request from framework f1235cbb-2af4-4048-8379-cb927ec30140-0000
>>>>>> I1201 13:13:40.437156 30312 master.cpp:938] Master terminating
>>>>>> I1201 13:13:40.438628 30315 hierarchical.cpp:260] Removed framework
>>>>>> f1235cbb-2af4-4048-8379-cb927ec30140-0000
>>>>>> E1201 13:13:40.449956 30313 scheduler.cpp:431] End-Of-File received
>>>>>> from master. The master closed the event stream
>>>>>> [ OK ] ContentType/SchedulerTest.Request/1 (802 ms)
>>>>>> [----------] 22 tests from ContentType/SchedulerTest (17087 ms total)
>>>>>>
>>>>>> [----------] Global test environment tear-down
>>>>>> [==========] 860 tests from 115 test cases ran. (821953 ms total)
>>>>>> [ PASSED ] 858 tests.
>>>>>> [ FAILED ] 2 tests, listed below:
>>>>>> [ FAILED ] HealthCheckTest.CheckCommandTimeout
>>>>>> [ FAILED ] PersistentVolumeTest.SlaveRecovery
>>>>>>
>>>>>> 2 FAILED TESTS
>>>>>> YOU HAVE 7 DISABLED TESTS
>>>>>>
>>>>>> make[4]: *** [check-local] Error 1
>>>>>> make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
>>>>>> make[3]: *** [check-am] Error 2
>>>>>> make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
>>>>>> make[2]: *** [check] Error 2
>>>>>> make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
>>>>>> make[1]: *** [check-recursive] Error 1
>>>>>> make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
>>>>>> make: *** [distcheck] Error 1
>>>>>> + docker rmi mesos-1448971321-13066
>>>>>> Untagged: mesos-1448971321-13066:latest
>>>>>> Deleted:
>>>>>> 579aa525055c35024667aa78495048284fba4c5b49fb29fe980cee2e96c770d2
>>>>>> Deleted:
>>>>>> 0db305a5ce4fab92189e208ed71bd4fa9ec3acbb71c95d6a3c4c6b59aebedb67
>>>>>> Deleted:
>>>>>> b0a83d7dfef1dc69cf7d71ba729a02710bc99981b0cb6d43535ac104a55ec6da
>>>>>> Deleted:
>>>>>> d4411f19e3629671ec868c87b65a0174ceeeabd93128b3930deef45bebd0ff65
>>>>>> Deleted:
>>>>>> 31f86a323ee991dfb2bfd36e4d4203b69c5ae9d734d7905e3f8c7b6c7d6dfc49
>>>>>> Deleted:
>>>>>> d9b9b23572603497de08cf63696bf0cd3749860e66750c66731b677283000283
>>>>>> Deleted:
>>>>>> 15578fc9ac532712bd7e77464040842070ad5173f41b9b1a6b2be80808c9d79a
>>>>>> Deleted:
>>>>>> 8ca7b89d896734687e673149f0cf7e5655929b799d4d176ee2500a8cc0b7b698
>>>>>> Deleted:
>>>>>> daf73a12ec932adb3289e201f1e580c423b3835c71682443e802d91830529e97
>>>>>> Deleted:
>>>>>> 0952f15e04c7ae8aafee3024a0ce6bebec38dad0274ee3b3d0ec4dab46d35bab
>>>>>> Deleted:
>>>>>> 72393d27e5e3eaa9ecaa1f381756032c7c96acbb1dc3b249d11b9f1b0557128d
>>>>>> Deleted:
>>>>>> 561e3d0690dbac5b70bc45e9beeb186c71fe0343e7dde3c682b67cb569deae5b
>>>>>> Deleted:
>>>>>> 095e8a4bc98539ee10c69a064e32a0bb58693c3c649fcb20e39fae8449003b7f
>>>>>> Build step 'Execute shell' marked build as failure
>>>>>>
>>>>>
>>>>>
>>>
>
