mesos-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Vinod Kone (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (MESOS-1490) LogStateTest.FetchAndStoreAndExpungeAndExpunge is flaky
Date Wed, 06 Aug 2014 21:23:11 GMT

     [ https://issues.apache.org/jira/browse/MESOS-1490?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Vinod Kone updated MESOS-1490:
------------------------------

    Target Version/s:   (was: 0.20.0)

> LogStateTest.FetchAndStoreAndExpungeAndExpunge is flaky
> -------------------------------------------------------
>
>                 Key: MESOS-1490
>                 URL: https://issues.apache.org/jira/browse/MESOS-1490
>             Project: Mesos
>          Issue Type: Bug
>          Components: test
>            Reporter: Vinod Kone
>
> [ RUN      ] LogStateTest.FetchAndStoreAndExpungeAndExpunge
> Using temporary directory '/tmp/LogStateTest_FetchAndStoreAndExpungeAndExpunge_GqoTj9'
> I0616 12:23:33.629946  2963 leveldb.cpp:176] Opened db in 31.790058ms
> I0616 12:23:33.641286  2963 leveldb.cpp:183] Compacted db in 11.009044ms
> I0616 12:23:33.641561  2963 leveldb.cpp:198] Created db iterator in 7621ns
> I0616 12:23:33.642011  2963 leveldb.cpp:204] Seeked to beginning of db in 2318ns
> I0616 12:23:33.642269  2963 leveldb.cpp:273] Iterated through 0 keys in the db in 2652ns
> I0616 12:23:33.642606  2963 replica.cpp:741] Replica recovered with log positions 0 ->
0 with 1 holes and 0 unlearned
> I0616 12:23:33.651423  2983 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb
took 8.308421ms
> I0616 12:23:33.651461  2983 replica.cpp:320] Persisted replica status to VOTING
> I0616 12:23:33.690558  2963 leveldb.cpp:176] Opened db in 33.770923ms
> I0616 12:23:33.703594  2963 leveldb.cpp:183] Compacted db in 12.436491ms
> I0616 12:23:33.704098  2963 leveldb.cpp:198] Created db iterator in 8008ns
> I0616 12:23:33.704335  2963 leveldb.cpp:204] Seeked to beginning of db in 2349ns
> I0616 12:23:33.704610  2963 leveldb.cpp:273] Iterated through 0 keys in the db in 2198ns
> I0616 12:23:33.704864  2963 replica.cpp:741] Replica recovered with log positions 0 ->
0 with 1 holes and 0 unlearned
> I0616 12:23:33.718089  2990 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb
took 12.797472ms
> I0616 12:23:33.718134  2990 replica.cpp:320] Persisted replica status to VOTING
> I0616 12:23:33.781381  2963 leveldb.cpp:176] Opened db in 59.577736ms
> I0616 12:23:33.830924  2963 leveldb.cpp:183] Compacted db in 49.148429ms
> I0616 12:23:33.831243  2963 leveldb.cpp:198] Created db iterator in 13355ns
> I0616 12:23:33.831506  2963 leveldb.cpp:204] Seeked to beginning of db in 21193ns
> I0616 12:23:33.831795  2963 leveldb.cpp:273] Iterated through 1 keys in the db in 31083ns
> I0616 12:23:33.832051  2963 replica.cpp:741] Replica recovered with log positions 0 ->
0 with 1 holes and 0 unlearned
> I0616 12:23:33.865875  2963 leveldb.cpp:176] Opened db in 33.435268ms
> I0616 12:23:33.896766  2963 leveldb.cpp:183] Compacted db in 30.273578ms
> I0616 12:23:33.897330  2963 leveldb.cpp:198] Created db iterator in 11028ns
> I0616 12:23:33.897594  2963 leveldb.cpp:204] Seeked to beginning of db in 18381ns
> I0616 12:23:33.897863  2963 leveldb.cpp:273] Iterated through 1 keys in the db in 29669ns
> I0616 12:23:33.898108  2963 replica.cpp:741] Replica recovered with log positions 0 ->
0 with 1 holes and 0 unlearned
> I0616 12:23:33.898617  2986 recover.cpp:425] Starting replica recovery
> I0616 12:23:33.898692  2986 recover.cpp:451] Replica is in VOTING status
> I0616 12:23:33.898727  2986 recover.cpp:440] Recover process terminated
> I0616 12:23:33.899284  2986 log.cpp:656] Attempting to start the writer
> I0616 12:23:33.899662  2986 replica.cpp:474] Replica received implicit promise request
with proposal 1
> I0616 12:23:33.899907  2990 replica.cpp:474] Replica received implicit promise request
with proposal 1
> I0616 12:23:33.912348  2990 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb
took 12.40255ms
> I0616 12:23:33.912400  2990 replica.cpp:342] Persisted promised to 1
> I0616 12:23:33.912690  2986 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb
took 12.999899ms
> I0616 12:23:33.912757  2986 replica.cpp:342] Persisted promised to 1
> I0616 12:23:33.912905  2986 coordinator.cpp:230] Coordinator attemping to fill missing
position
> I0616 12:23:33.913260  2986 replica.cpp:375] Replica received explicit promise request
for position 0 with proposal 2
> I0616 12:23:33.913416  2990 replica.cpp:375] Replica received explicit promise request
for position 0 with proposal 2
> I0616 12:23:33.921795  2990 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took
8.347839ms
> I0616 12:23:33.921831  2990 replica.cpp:676] Persisted action at 0
> I0616 12:23:33.922047  2986 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took
8.758297ms
> I0616 12:23:33.922379  2986 replica.cpp:676] Persisted action at 0
> I0616 12:23:33.924927  2983 replica.cpp:508] Replica received write request for position
0
> I0616 12:23:33.924969  2983 leveldb.cpp:438] Reading position from leveldb took 19309ns
> I0616 12:23:33.925101  2984 replica.cpp:508] Replica received write request for position
0
> I0616 12:23:33.925127  2984 leveldb.cpp:438] Reading position from leveldb took 10079ns
> I0616 12:23:33.934978  2984 leveldb.cpp:343] Persisting action (14 bytes) to leveldb
took 9.83074ms
> I0616 12:23:33.935020  2984 replica.cpp:676] Persisted action at 0
> I0616 12:23:33.935111  2983 leveldb.cpp:343] Persisting action (14 bytes) to leveldb
took 10.119835ms
> I0616 12:23:33.935132  2983 replica.cpp:676] Persisted action at 0
> I0616 12:23:33.935235  2983 replica.cpp:655] Replica received learned notice for position
0
> I0616 12:23:33.935333  2984 replica.cpp:655] Replica received learned notice for position
0
> I0616 12:23:33.944811  2984 leveldb.cpp:343] Persisting action (16 bytes) to leveldb
took 9.452885ms
> I0616 12:23:33.944859  2984 replica.cpp:676] Persisted action at 0
> I0616 12:23:33.944869  2984 replica.cpp:661] Replica learned NOP action at position 0
> I0616 12:23:33.945051  2984 log.cpp:672] Writer started with ending position 0
> I0616 12:23:33.945282  2984 leveldb.cpp:438] Reading position from leveldb took 20921ns
> I0616 12:23:33.946615  2983 leveldb.cpp:343] Persisting action (16 bytes) to leveldb
took 11.352783ms
> I0616 12:23:33.946643  2983 replica.cpp:676] Persisted action at 0
> I0616 12:23:33.946652  2983 replica.cpp:661] Replica learned NOP action at position 0
> I0616 12:23:33.948106  2989 log.cpp:680] Attempting to append 49 bytes to the log
> I0616 12:23:33.948148  2989 coordinator.cpp:340] Coordinator attempting to write APPEND
action at position 1
> I0616 12:23:33.948369  2989 replica.cpp:508] Replica received write request for position
1
> I0616 12:23:33.948531  2985 replica.cpp:508] Replica received write request for position
1
> I0616 12:23:33.958195  2985 leveldb.cpp:343] Persisting action (65 bytes) to leveldb
took 9.636155ms
> I0616 12:23:33.958240  2985 replica.cpp:676] Persisted action at 1
> I0616 12:23:33.958905  2989 leveldb.cpp:343] Persisting action (65 bytes) to leveldb
took 10.510293ms
> I0616 12:23:33.958935  2989 replica.cpp:676] Persisted action at 1
> I0616 12:23:33.959096  2989 replica.cpp:655] Replica received learned notice for position
1
> I0616 12:23:33.959247  2985 replica.cpp:655] Replica received learned notice for position
1
> I0616 12:23:33.969413  2985 leveldb.cpp:343] Persisting action (67 bytes) to leveldb
took 10.139698ms
> I0616 12:23:33.969461  2985 replica.cpp:676] Persisted action at 1
> I0616 12:23:33.969471  2985 replica.cpp:661] Replica learned APPEND action at position
1
> I0616 12:23:33.969825  2985 log.cpp:699] Attempting to truncate the log to 1
> I0616 12:23:33.969883  2985 coordinator.cpp:340] Coordinator attempting to write TRUNCATE
action at position 2
> I0616 12:23:33.970105  2985 replica.cpp:508] Replica received write request for position
2
> I0616 12:23:33.970396  2989 leveldb.cpp:343] Persisting action (67 bytes) to leveldb
took 11.26858ms
> I0616 12:23:33.970441  2989 replica.cpp:676] Persisted action at 1
> I0616 12:23:33.970453  2989 replica.cpp:661] Replica learned APPEND action at position
1
> I0616 12:23:33.970468  2989 replica.cpp:508] Replica received write request for position
2
> I0616 12:23:33.980139  2989 leveldb.cpp:343] Persisting action (16 bytes) to leveldb
took 9.651318ms
> I0616 12:23:33.980182  2989 replica.cpp:676] Persisted action at 2
> I0616 12:23:33.980422  2985 leveldb.cpp:343] Persisting action (16 bytes) to leveldb
took 10.293293ms
> I0616 12:23:33.980448  2985 replica.cpp:676] Persisted action at 2
> I0616 12:23:33.980654  2985 replica.cpp:655] Replica received learned notice for position
2
> I0616 12:23:33.980983  2989 replica.cpp:655] Replica received learned notice for position
2
> I0616 12:23:33.989821  2989 leveldb.cpp:343] Persisting action (18 bytes) to leveldb
took 8.809638ms
> I0616 12:23:33.989897  2989 leveldb.cpp:401] Deleting ~1 keys from leveldb took 33507ns
> I0616 12:23:33.989912  2989 replica.cpp:676] Persisted action at 2
> I0616 12:23:33.989922  2989 replica.cpp:661] Replica learned TRUNCATE action at position
2
> I0616 12:23:33.990144  2989 log.cpp:680] Attempting to append 12 bytes to the log
> I0616 12:23:33.990185  2989 coordinator.cpp:340] Coordinator attempting to write APPEND
action at position 3
> I0616 12:23:33.990409  2989 replica.cpp:508] Replica received write request for position
3
> I0616 12:23:33.990708  2985 leveldb.cpp:343] Persisting action (18 bytes) to leveldb
took 10.020056ms
> I0616 12:23:33.991072  2985 leveldb.cpp:401] Deleting ~1 keys from leveldb took 30689ns
> I0616 12:23:33.991204  2985 replica.cpp:676] Persisted action at 2
> I0616 12:23:33.991216  2985 replica.cpp:661] Replica learned TRUNCATE action at position
2
> I0616 12:23:33.991232  2985 replica.cpp:508] Replica received write request for position
3
> I0616 12:23:34.000671  2985 leveldb.cpp:343] Persisting action (28 bytes) to leveldb
took 9.4207ms
> I0616 12:23:34.001118  2985 replica.cpp:676] Persisted action at 3
> I0616 12:23:34.001459  2989 leveldb.cpp:343] Persisting action (28 bytes) to leveldb
took 11.028007ms
> I0616 12:23:34.005596  2989 replica.cpp:676] Persisted action at 3
> I0616 12:23:34.005770  2989 replica.cpp:655] Replica received learned notice for position
3
> I0616 12:23:34.006007  2985 replica.cpp:655] Replica received learned notice for position
3
> I0616 12:23:34.016319  2985 leveldb.cpp:343] Persisting action (30 bytes) to leveldb
took 10.242217ms
> I0616 12:23:34.016484  2985 replica.cpp:676] Persisted action at 3
> I0616 12:23:34.016533  2985 replica.cpp:661] Replica learned APPEND action at position
3
> I0616 12:23:34.017012  2989 leveldb.cpp:343] Persisting action (30 bytes) to leveldb
took 11.219868ms
> I0616 12:23:34.017256  2989 replica.cpp:676] Persisted action at 3
> I0616 12:23:34.019745  2989 replica.cpp:661] Replica learned APPEND action at position
3
> 2014-06-16 12:23:36,797:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:23:40,135:2963(0x7f9014632700):ZOO_WARN@zookeeper_interest@1557: Exceeded
deadline by 67ms
> 2014-06-16 12:23:40,135:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:23:43,471:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> tests/state_tests.cpp:248: Failure
> Failed to wait 10secs for future3
> 2014-06-16 12:23:46,807:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:23:50,144:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:23:53,480:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:23:56,816:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:24:00,152:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:24:03,488:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:24:06,824:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:24:10,160:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:24:13,496:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:24:16,832:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client
> 2014-06-16 12:24:20,168:2963(0x7f9014632700):ZOO_ERROR@handle_socket_error_msg@1697:
Socket [127.0.0.1:44689] zk retcode=-4, errno=111(Connection refused): server refused to accept
the client



--
This message was sent by Atlassian JIRA
(v6.2#6252)

Mime
View raw message