mesos-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Joris Van Remoortere (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (MESOS-2118) ShutdownTest.ShutdownEndpointGoodACLs is flaky, runs forever.
Date Mon, 24 Nov 2014 18:51:14 GMT

    [ https://issues.apache.org/jira/browse/MESOS-2118?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14223284#comment-14223284
] 

Joris Van Remoortere commented on MESOS-2118:
---------------------------------------------

[~bmahler] could you see if this is still an issue after applying https://reviews.apache.org/r/28367?

> ShutdownTest.ShutdownEndpointGoodACLs is flaky, runs forever.
> -------------------------------------------------------------
>
>                 Key: MESOS-2118
>                 URL: https://issues.apache.org/jira/browse/MESOS-2118
>             Project: Mesos
>          Issue Type: Bug
>          Components: technical debt, test
>         Environment: CentOS 6
>            Reporter: Benjamin Mahler
>
> Looks like this test never finished cleanly:
> {noformat}
> DEBUG: [ RUN      ] ShutdownTest.ShutdownEndpointGoodACLs
> DEBUG: Using temporary directory '/tmp/ShutdownTest_ShutdownEndpointGoodACLs_PNU8y4'
> DEBUG: I1116 08:33:03.597002 12611 leveldb.cpp:176] Opened db in 1.679773ms
> DEBUG: I1116 08:33:03.597597 12611 leveldb.cpp:183] Compacted db in 571410ns
> DEBUG: I1116 08:33:03.597615 12611 leveldb.cpp:198] Created db iterator in 1957ns
> DEBUG: I1116 08:33:03.597620 12611 leveldb.cpp:204] Seeked to beginning of db in 370ns
> DEBUG: I1116 08:33:03.597626 12611 leveldb.cpp:273] Iterated through 0 keys in the db
in 121ns
> DEBUG: I1116 08:33:03.597636 12611 replica.cpp:741] Replica recovered with log positions
0 -> 0 with 1 holes and 0 unlearned
> DEBUG: I1116 08:33:03.597851 12638 recover.cpp:437] Starting replica recovery
> DEBUG: I1116 08:33:03.597950 12638 recover.cpp:463] Replica is in EMPTY status
> DEBUG: I1116 08:33:03.598697 12634 replica.cpp:638] Replica in EMPTY status received
a broadcasted recover request
> DEBUG: I1116 08:33:03.599009 12648 recover.cpp:188] Received a recover response from
a replica in EMPTY status
> DEBUG: I1116 08:33:03.599309 12626 recover.cpp:554] Updating replica status to STARTING
> DEBUG: I1116 08:33:03.599762 12627 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 399340ns
> DEBUG: I1116 08:33:03.599786 12627 replica.cpp:320] Persisted replica status to STARTING
> DEBUG: I1116 08:33:03.599922 12650 recover.cpp:463] Replica is in STARTING status
> DEBUG: I1116 08:33:03.600464 12649 replica.cpp:638] Replica in STARTING status received
a broadcasted recover request
> DEBUG: I1116 08:33:03.600662 12630 recover.cpp:188] Received a recover response from
a replica in STARTING status
> DEBUG: I1116 08:33:03.600997 12651 recover.cpp:554] Updating replica status to VOTING
> DEBUG: I1116 08:33:03.601369 12639 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 239227ns
> DEBUG: I1116 08:33:03.601387 12639 replica.cpp:320] Persisted replica status to VOTING
> DEBUG: I1116 08:33:03.601625 12651 recover.cpp:568] Successfully joined the Paxos group
> DEBUG: I1116 08:33:03.601764 12651 recover.cpp:452] Recover process terminated
> DEBUG: I1116 08:33:03.609264 12648 master.cpp:318] Master 20141116-083303-1711542956-42834-12611
(atlc-bev-05-sr1.corpdc.twttr.net) started on 172.18.4.102:42834
> DEBUG: I1116 08:33:03.609294 12648 master.cpp:364] Master only allowing authenticated
frameworks to register
> DEBUG: I1116 08:33:03.609305 12648 master.cpp:369] Master only allowing authenticated
slaves to register
> DEBUG: I1116 08:33:03.609316 12648 credentials.hpp:36] Loading credentials for authentication
from '/tmp/ShutdownTest_ShutdownEndpointGoodACLs_PNU8y4/credentials'
> DEBUG: I1116 08:33:03.609416 12648 master.cpp:413] Authorization enabled
> DEBUG: I1116 08:33:03.609822 12639 master.cpp:1263] The newly elected leader is master@172.18.4.102:42834
with id 20141116-083303-1711542956-42834-12611
> DEBUG: I1116 08:33:03.609835 12639 master.cpp:1276] Elected as the leading master!
> DEBUG: I1116 08:33:03.609841 12639 master.cpp:1094] Recovering from registrar
> DEBUG: I1116 08:33:03.609895 12627 registrar.cpp:313] Recovering registrar
> DEBUG: I1116 08:33:03.610188 12626 log.cpp:656] Attempting to start the writer
> DEBUG: I1116 08:33:03.610788 12632 replica.cpp:474] Replica received implicit promise
request with proposal 1
> DEBUG: I1116 08:33:03.611081 12632 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 273337ns
> DEBUG: I1116 08:33:03.611096 12632 replica.cpp:342] Persisted promised to 1
> DEBUG: I1116 08:33:03.611469 12641 coordinator.cpp:230] Coordinator attemping to fill
missing position
> DEBUG: I1116 08:33:03.612118 12634 replica.cpp:375] Replica received explicit promise
request for position 0 with proposal 2
> DEBUG: I1116 08:33:03.612368 12634 leveldb.cpp:343] Persisting action (8 bytes) to leveldb
took 232013ns
> DEBUG: I1116 08:33:03.612390 12634 replica.cpp:676] Persisted action at 0
> DEBUG: I1116 08:33:03.612936 12640 replica.cpp:508] Replica received write request for
position 0
> DEBUG: I1116 08:33:03.612962 12640 leveldb.cpp:438] Reading position from leveldb took
8951ns
> DEBUG: I1116 08:33:03.613075 12640 leveldb.cpp:343] Persisting action (14 bytes) to leveldb
took 97733ns
> DEBUG: I1116 08:33:03.613088 12640 replica.cpp:676] Persisted action at 0
> DEBUG: I1116 08:33:03.613435 12648 replica.cpp:655] Replica received learned notice for
position 0
> DEBUG: I1116 08:33:03.613695 12648 leveldb.cpp:343] Persisting action (16 bytes) to leveldb
took 241135ns
> DEBUG: I1116 08:33:03.613709 12648 replica.cpp:676] Persisted action at 0
> DEBUG: I1116 08:33:03.613716 12648 replica.cpp:661] Replica learned NOP action at position
0
> DEBUG: I1116 08:33:03.614004 12637 log.cpp:672] Writer started with ending position 0
> DEBUG: I1116 08:33:03.614518 12638 leveldb.cpp:438] Reading position from leveldb took
11321ns
> DEBUG: I1116 08:33:03.616251 12634 registrar.cpp:346] Successfully fetched the registry
(0B) in 6336us
> DEBUG: I1116 08:33:03.616283 12634 registrar.cpp:445] Applied 1 operations in 1565ns;
attempting to update the 'registry'
> DEBUG: I1116 08:33:03.618041 12631 log.cpp:680] Attempting to append 153 bytes to the
log
> DEBUG: I1116 08:33:03.618234 12627 coordinator.cpp:340] Coordinator attempting to write
APPEND action at position 1
> DEBUG: I1116 08:33:03.618708 12627 replica.cpp:508] Replica received write request for
position 1
> DEBUG: I1116 08:33:03.619055 12627 leveldb.cpp:343] Persisting action (172 bytes) to
leveldb took 326461ns
> DEBUG: I1116 08:33:03.619071 12627 replica.cpp:676] Persisted action at 1
> DEBUG: I1116 08:33:03.619359 12638 replica.cpp:655] Replica received learned notice for
position 1
> DEBUG: I1116 08:33:03.619635 12638 leveldb.cpp:343] Persisting action (174 bytes) to
leveldb took 255575ns
> DEBUG: I1116 08:33:03.619657 12638 replica.cpp:676] Persisted action at 1
> DEBUG: I1116 08:33:03.619667 12638 replica.cpp:661] Replica learned APPEND action at
position 1
> DEBUG: I1116 08:33:03.619976 12639 registrar.cpp:490] Successfully updated the 'registry'
in 3.675904ms
> DEBUG: I1116 08:33:03.620025 12639 registrar.cpp:376] Successfully recovered registrar
> DEBUG: I1116 08:33:03.620079 12629 log.cpp:699] Attempting to truncate the log to 1
> DEBUG: I1116 08:33:03.620496 12649 master.cpp:1121] Recovered 0 slaves from the Registry
(115B) ; allowing 10mins for slaves to re-register
> DEBUG: I1116 08:33:03.620504 12626 coordinator.cpp:340] Coordinator attempting to write
TRUNCATE action at position 2
> DEBUG: I1116 08:33:03.620971 12654 replica.cpp:508] Replica received write request for
position 2
> DEBUG: I1116 08:33:03.621232 12654 leveldb.cpp:343] Persisting action (16 bytes) to leveldb
took 245704ns
> DEBUG: I1116 08:33:03.621247 12654 replica.cpp:676] Persisted action at 2
> DEBUG: I1116 08:33:03.621649 12638 replica.cpp:655] Replica received learned notice for
position 2
> DEBUG: I1116 08:33:03.621922 12638 leveldb.cpp:343] Persisting action (18 bytes) to leveldb
took 252335ns
> DEBUG: I1116 08:33:03.621950 12638 leveldb.cpp:401] Deleting ~1 keys from leveldb took
13419ns
> DEBUG: I1116 08:33:03.621959 12638 replica.cpp:676] Persisted action at 2
> DEBUG: I1116 08:33:03.621966 12638 replica.cpp:661] Replica learned TRUNCATE action at
position 2
> DEBUG: I1116 08:33:03.635592 12611 sched.cpp:148] Version: 0.22.0-rc0
> DEBUG: I1116 08:33:03.636092 12652 sched.cpp:245] New master detected at master@172.18.4.102:42834
> DEBUG: I1116 08:33:03.636126 12652 sched.cpp:301] Authenticating with master master@172.18.4.102:42834
> DEBUG: I1116 08:33:03.636133 12652 sched.cpp:308] Using default CRAM-MD5 authenticatee
> DEBUG: I1116 08:33:03.636348 12654 authenticatee.hpp:138] Creating new client SASL connection
> DEBUG: I1116 08:33:03.636590 12631 master.cpp:3896] Authenticating scheduler-38732cf0-d6db-44a1-a95b-b3763e10555d@172.18.4.102:42834
> DEBUG: I1116 08:33:03.636613 12631 master.cpp:3907] Using default CRAM-MD5 authenticator
> DEBUG: I1116 08:33:03.636693 12626 authenticator.hpp:170] Creating new server SASL connection
> DEBUG: I1116 08:33:03.636988 12652 authenticatee.hpp:229] Received SASL authentication
mechanisms: CRAM-MD5
> DEBUG: I1116 08:33:03.637004 12652 authenticatee.hpp:255] Attempting to authenticate
with mechanism 'CRAM-MD5'
> DEBUG: I1116 08:33:03.637030 12652 authenticator.hpp:276] Received SASL authentication
start
> DEBUG: I1116 08:33:03.637126 12652 authenticator.hpp:398] Authentication requires more
steps
> DEBUG: I1116 08:33:03.637266 12627 authenticatee.hpp:275] Received SASL authentication
step
> DEBUG: I1116 08:33:03.637338 12654 authenticator.hpp:304] Received SASL authentication
step
> DEBUG: I1116 08:33:03.637367 12654 authenticator.hpp:390] Authentication success
> DEBUG: I1116 08:33:03.637419 12641 authenticatee.hpp:315] Authentication success
> DEBUG: I1116 08:33:03.637423 12654 master.cpp:3954] Successfully authenticated principal
'test-principal' at scheduler-38732cf0-d6db-44a1-a95b-b3763e10555d@172.18.4.102:42834
> DEBUG: I1116 08:33:03.637684 12635 sched.cpp:389] Successfully authenticated with master
master@172.18.4.102:42834
> DEBUG: I1116 08:33:03.637755 12630 master.cpp:1383] Received registration request for
framework 'default' at scheduler-38732cf0-d6db-44a1-a95b-b3763e10555d@172.18.4.102:42834
> DEBUG: I1116 08:33:03.637780 12630 master.cpp:1342] Authorizing framework principal 'test-principal'
to receive offers for role '*'
> DEBUG: I1116 08:33:03.637987 12633 master.cpp:1447] Registering framework 20141116-083303-1711542956-42834-12611-0000
(default) at scheduler-38732cf0-d6db-44a1-a95b-b3763e10555d@172.18.4.102:42834
> DEBUG: I1116 08:33:03.638067 12635 hierarchical_allocator_process.hpp:329] Added framework
20141116-083303-1711542956-42834-12611-0000
> DEBUG: I1116 08:33:03.638491 12654 sched.cpp:439] Framework registered with 20141116-083303-1711542956-42834-12611-0000
> DEBUG: I1116 08:33:03.639173 12638 master.cpp:4266] Removing framework 20141116-083303-1711542956-42834-12611-0000
(default) at scheduler-38732cf0-d6db-44a1-a95b-b3763e10555d@172.18.4.102:42834
> DEBUG: I1116 08:33:03.639245 12636 hierarchical_allocator_process.hpp:405] Deactivated
framework 20141116-083303-1711542956-42834-12611-0000
> DEBUG: I1116 08:33:03.639276 12636 hierarchical_allocator_process.hpp:360] Removed framework
20141116-083303-1711542956-42834-12611-0000
> DEBUG: 2014-11-16 08:33:06,261:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:09,597:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:12,932:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:16,265:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:19,602:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:22,936:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:26,273:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:29,608:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:32,943:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:36,280:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:39,616:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:42,952:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:46,286:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:49,620:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:52,954:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> DEBUG: 2014-11-16 08:33:56,288:12611(0x7f5c34a30700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:43782] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message