Benjamin Mahler created MESOS-1803:
--------------------------------------
Summary: Strict/RegistrarTest.remove test is flaky on jenkins.
Key: MESOS-1803
URL: https://issues.apache.org/jira/browse/MESOS-1803
Project: Mesos
Issue Type: Bug
Components: test
Reporter: Benjamin Mahler
Assignee: Benjamin Mahler
https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2374/consoleFull
{noformat}
[ RUN ] Strict/RegistrarTest.remove/1
Using temporary directory '/tmp/Strict_RegistrarTest_remove_1_3QvnOW'
I0916 22:59:02.112568 21026 leveldb.cpp:176] Opened db in 1.779835ms
I0916 22:59:02.112896 21026 leveldb.cpp:183] Compacted db in 301862ns
I0916 22:59:02.112916 21026 leveldb.cpp:198] Created db iterator in 3065ns
I0916 22:59:02.112926 21026 leveldb.cpp:204] Seeked to beginning of db in 475ns
I0916 22:59:02.112936 21026 leveldb.cpp:273] Iterated through 0 keys in the db
in 330ns
I0916 22:59:02.112951 21026 replica.cpp:741] Replica recovered with log
positions 0 -> 0 with 1 holes and 0 unlearned
I0916 22:59:02.113654 21054 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 421460ns
I0916 22:59:02.113674 21054 replica.cpp:320] Persisted replica status to VOTING
I0916 22:59:02.115900 21026 leveldb.cpp:176] Opened db in 1.947919ms
I0916 22:59:02.116263 21026 leveldb.cpp:183] Compacted db in 338043ns
I0916 22:59:02.116283 21026 leveldb.cpp:198] Created db iterator in 2809ns
I0916 22:59:02.116293 21026 leveldb.cpp:204] Seeked to beginning of db in 468ns
I0916 22:59:02.116302 21026 leveldb.cpp:273] Iterated through 0 keys in the db
in 195ns
I0916 22:59:02.116317 21026 replica.cpp:741] Replica recovered with log
positions 0 -> 0 with 1 holes and 0 unlearned
I0916 22:59:02.117013 21043 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 472891ns
I0916 22:59:02.117034 21043 replica.cpp:320] Persisted replica status to VOTING
I0916 22:59:02.119240 21026 leveldb.cpp:176] Opened db in 1.950367ms
I0916 22:59:02.120455 21026 leveldb.cpp:183] Compacted db in 1.188056ms
I0916 22:59:02.120481 21026 leveldb.cpp:198] Created db iterator in 4370ns
I0916 22:59:02.120499 21026 leveldb.cpp:204] Seeked to beginning of db in 7977ns
I0916 22:59:02.120517 21026 leveldb.cpp:273] Iterated through 1 keys in the db
in 8479ns
I0916 22:59:02.120533 21026 replica.cpp:741] Replica recovered with log
positions 0 -> 0 with 1 holes and 0 unlearned
I0916 22:59:02.122890 21026 leveldb.cpp:176] Opened db in 2.301327ms
I0916 22:59:02.124325 21026 leveldb.cpp:183] Compacted db in 1.406223ms
I0916 22:59:02.124351 21026 leveldb.cpp:198] Created db iterator in 4185ns
I0916 22:59:02.124368 21026 leveldb.cpp:204] Seeked to beginning of db in 7167ns
I0916 22:59:02.124387 21026 leveldb.cpp:273] Iterated through 1 keys in the db
in 8182ns
I0916 22:59:02.124403 21026 replica.cpp:741] Replica recovered with log
positions 0 -> 0 with 1 holes and 0 unlearned
I0916 22:59:02.124579 21047 recover.cpp:425] Starting replica recovery
I0916 22:59:02.124651 21047 recover.cpp:451] Replica is in VOTING status
I0916 22:59:02.124793 21047 recover.cpp:440] Recover process terminated
I0916 22:59:02.126404 21046 registrar.cpp:313] Recovering registrar
I0916 22:59:02.126597 21050 log.cpp:656] Attempting to start the writer
I0916 22:59:02.127259 21041 replica.cpp:474] Replica received implicit promise
request with proposal 1
I0916 22:59:02.127321 21050 replica.cpp:474] Replica received implicit promise
request with proposal 1
I0916 22:59:02.127835 21041 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 547018ns
I0916 22:59:02.127858 21041 replica.cpp:342] Persisted promised to 1
I0916 22:59:02.127835 21050 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 487588ns
I0916 22:59:02.127887 21050 replica.cpp:342] Persisted promised to 1
I0916 22:59:02.128387 21055 coordinator.cpp:230] Coordinator attemping to fill
missing position
I0916 22:59:02.129546 21042 replica.cpp:375] Replica received explicit promise
request for position 0 with proposal 2
I0916 22:59:02.129600 21053 replica.cpp:375] Replica received explicit promise
request for position 0 with proposal 2
I0916 22:59:02.129982 21042 leveldb.cpp:343] Persisting action (8 bytes) to
leveldb took 406954ns
I0916 22:59:02.129982 21053 leveldb.cpp:343] Persisting action (8 bytes) to
leveldb took 357253ns
I0916 22:59:02.130009 21042 replica.cpp:676] Persisted action at 0
I0916 22:59:02.130029 21053 replica.cpp:676] Persisted action at 0
I0916 22:59:02.130543 21041 replica.cpp:508] Replica received write request for
position 0
I0916 22:59:02.130585 21041 leveldb.cpp:438] Reading position from leveldb took
17424ns
I0916 22:59:02.130599 21046 replica.cpp:508] Replica received write request for
position 0
I0916 22:59:02.130635 21046 leveldb.cpp:438] Reading position from leveldb took
12702ns
I0916 22:59:02.130728 21041 leveldb.cpp:343] Persisting action (14 bytes) to
leveldb took 112749ns
I0916 22:59:02.130749 21041 replica.cpp:676] Persisted action at 0
I0916 22:59:02.130795 21046 leveldb.cpp:343] Persisting action (14 bytes) to
leveldb took 131300ns
I0916 22:59:02.130820 21046 replica.cpp:676] Persisted action at 0
I0916 22:59:02.131093 21042 replica.cpp:655] Replica received learned notice
for position 0
I0916 22:59:02.131163 21048 replica.cpp:655] Replica received learned notice
for position 0
I0916 22:59:02.131232 21042 leveldb.cpp:343] Persisting action (16 bytes) to
leveldb took 117351ns
I0916 22:59:02.131256 21042 replica.cpp:676] Persisted action at 0
I0916 22:59:02.131273 21042 replica.cpp:661] Replica learned NOP action at
position 0
I0916 22:59:02.131340 21048 leveldb.cpp:343] Persisting action (16 bytes) to
leveldb took 148690ns
I0916 22:59:02.131358 21048 replica.cpp:676] Persisted action at 0
I0916 22:59:02.131369 21048 replica.cpp:661] Replica learned NOP action at
position 0
I0916 22:59:02.131569 21046 log.cpp:672] Writer started with ending position 0
I0916 22:59:02.131950 21055 leveldb.cpp:438] Reading position from leveldb took
15477ns
I0916 22:59:02.133436 21052 registrar.cpp:346] Successfully fetched the
registry (0B)
I0916 22:59:02.133471 21052 registrar.cpp:422] Attempting to update the
'registry'
I0916 22:59:02.134899 21049 log.cpp:680] Attempting to append 144 bytes to the
log
I0916 22:59:02.134968 21048 coordinator.cpp:340] Coordinator attempting to
write APPEND action at position 1
I0916 22:59:02.135306 21042 replica.cpp:508] Replica received write request for
position 1
I0916 22:59:02.135407 21052 replica.cpp:508] Replica received write request for
position 1
I0916 22:59:02.135717 21052 leveldb.cpp:343] Persisting action (163 bytes) to
leveldb took 279603ns
I0916 22:59:02.135721 21042 leveldb.cpp:343] Persisting action (163 bytes) to
leveldb took 388839ns
I0916 22:59:02.135742 21052 replica.cpp:676] Persisted action at 1
I0916 22:59:02.135752 21042 replica.cpp:676] Persisted action at 1
I0916 22:59:02.136090 21049 replica.cpp:655] Replica received learned notice
for position 1
I0916 22:59:02.136127 21047 replica.cpp:655] Replica received learned notice
for position 1
I0916 22:59:02.136256 21049 leveldb.cpp:343] Persisting action (165 bytes) to
leveldb took 141908ns
I0916 22:59:02.136267 21047 leveldb.cpp:343] Persisting action (165 bytes) to
leveldb took 111061ns
I../../src/tests/registrar_tests.cpp:257: Failure
0916 22:59:02.136276 21049 replica.cpp:676] Persisted action at 1
Failed to wait 10secs for registrar.recover(master)
I0916 22:59:14.265326 21049 replica.cpp:661] Replica learned APPEND action at
position 1
I0916 22:59:02.136291 21047 replica.cpp:676] Persisted action at 1
E0916 22:59:07.135143 21046 registrar.cpp:500] Registrar aborting: Failed to
update 'registry': Failed to perform store within 5secs
I0916 22:59:14.265393 21047 replica.cpp:661] Replica learned APPEND action at
position 1
[ FAILED ] Strict/RegistrarTest.remove/1, where GetParam() = true (12156 ms)
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
