[
https://issues.apache.org/jira/browse/MESOS-531?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13694238#comment-13694238
]
Vinod Kone commented on MESOS-531:
----------------------------------
lets bump the default for AWAIT_READY to 10s?
> CoordinatorTest.MultipleAppendsNotLearnedFill is flaky on Jenkins.
> ------------------------------------------------------------------
>
> Key: MESOS-531
> URL: https://issues.apache.org/jira/browse/MESOS-531
> Project: Mesos
> Issue Type: Bug
> Reporter: Benjamin Mahler
> Assignee: Benjamin Hindman
>
> Possibly related to: https://issues.apache.org/jira/browse/MESOS-301
> [ RUN ] CoordinatorTest.MultipleAppendsNotLearnedFill
> I0626 20:41:20.289326 21774 replica.cpp:230] Opened db in 237.445813ms
> I0626 20:41:20.308446 21774 replica.cpp:237] Compacted db in 19.002175ms
> I0626 20:41:20.315197 21774 replica.cpp:253] Created db iterator in 7.332us
> I0626 20:41:20.334137 21774 replica.cpp:259] Seeked to beginning of db in
> 1.932us
> I0626 20:41:20.334539 21774 replica.cpp:310] Iterated through 0 keys in the
> db in 615ns
> I0626 20:41:20.335080 21774 replica.cpp:1040] Replica recovered with log
> positions 0 -> 0 and holes { 0 } and unlearned { }
> I0626 20:41:20.523996 21774 replica.cpp:230] Opened db in 188.349334ms
> I0626 20:41:20.555011 21774 replica.cpp:237] Compacted db in 30.939383ms
> I0626 20:41:20.555060 21774 replica.cpp:253] Created db iterator in 10.073us
> I0626 20:41:20.579107 21774 replica.cpp:259] Seeked to beginning of db in
> 7.307us
> I0626 20:41:20.599915 21774 replica.cpp:310] Iterated through 0 keys in the
> db in 732ns
> I0626 20:41:20.607065 21774 replica.cpp:1040] Replica recovered with log
> positions 0 -> 0 and holes { 0 } and unlearned { }
> I0626 20:41:20.607624 21774 coordinator.cpp:61] Coordinator attempting to get
> elected within 4.999999232secs
> I0626 20:41:20.608510 21912 replica.cpp:777] Replica received implicit
> promise request for 1
> I0626 20:41:20.608522 21917 replica.cpp:777] Replica received implicit
> promise request for 1
> I0626 20:41:20.710583 21912 replica.cpp:354] Persisting promise (6 bytes) to
> leveldb took 101.963472ms
> I0626 20:41:20.735069 21912 replica.cpp:953] Persisted promise to 1
> I0626 20:41:20.727517 21917 replica.cpp:354] Persisting promise (6 bytes) to
> leveldb took 117.919493ms
> I0626 20:41:20.739506 21917 replica.cpp:953] Persisted promise to 1
> I0626 20:41:20.740284 21774 coordinator.cpp:115] Coordinator elected,
> attempting to fill missing positions
> I0626 20:41:20.740641 21774 coordinator.cpp:396] Coordinator attempting to
> fill position 0 in the log
> I0626 20:41:20.741108 21914 replica.cpp:705] Replica received explicit
> promise request for 1 for position 0
> I0626 20:41:20.741199 21916 replica.cpp:705] Replica received explicit
> promise request for 1 for position 0
> I0626 20:41:20.768059 21914 replica.cpp:385] Persisting action (8 bytes) to
> leveldb took 26.626278ms
> I0626 20:41:20.795083 21914 replica.cpp:968] Persisted action at 0
> I0626 20:41:20.789412 21916 replica.cpp:385] Persisting action (8 bytes) to
> leveldb took 47.504565ms
> I0626 20:41:20.807698 21916 replica.cpp:968] Persisted action at 0
> I0626 20:41:20.823902 21774 coordinator.cpp:226] Coordinator attempting to
> write NOP action at position 0 within 4.78372608secs
> I0626 20:41:20.824486 21916 replica.cpp:808] Replica received write request
> for position 0
> I0626 20:41:20.825059 21916 replica.cpp:470] Reading position from leveldb
> took 15.527us
> I0626 20:41:20.862961 21916 replica.cpp:385] Persisting action (14 bytes) to
> leveldb took 37.290911ms
> I0626 20:41:20.862998 21916 replica.cpp:968] Persisted action at 0
> I0626 20:41:20.871186 21774 coordinator.cpp:317] Coordinator attempting to
> commit NOP action at position 0
> I0626 20:41:20.879195 21919 replica.cpp:808] Replica received write request
> for position 0
> I0626 20:41:20.889878 21919 replica.cpp:470] Reading position from leveldb
> took 8.181us
> I0626 20:41:20.919744 21919 replica.cpp:385] Persisting action (16 bytes) to
> leveldb took 24.685238ms
> I0626 20:41:20.919786 21919 replica.cpp:968] Persisted action at 0
> I0626 20:41:20.920251 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 0
> I0626 20:41:20.920711 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 1 within 4.999993088secs
> I0626 20:41:20.927342 21918 replica.cpp:808] Replica received write request
> for position 1
> I0626 20:41:20.994742 21918 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 53.357611ms
> I0626 20:41:20.994783 21918 replica.cpp:968] Persisted action at 1
> I0626 20:41:21.003219 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 1
> I0626 20:41:21.013100 21915 replica.cpp:808] Replica received write request
> for position 1
> I0626 20:41:21.078357 21915 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 64.882431ms
> I0626 20:41:21.078403 21915 replica.cpp:968] Persisted action at 1
> I0626 20:41:21.087177 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 1
> I0626 20:41:21.091090 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 2 within 4.99999488secs
> I0626 20:41:21.099269 21915 replica.cpp:808] Replica received write request
> for position 2
> I0626 20:41:21.219250 21915 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 91.141975ms
> I0626 20:41:21.219358 21915 replica.cpp:968] Persisted action at 2
> I0626 20:41:21.227320 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 2
> I0626 20:41:21.239523 21916 replica.cpp:808] Replica received write request
> for position 2
> I0626 20:41:21.287796 21916 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 48.019459ms
> I0626 20:41:21.295094 21916 replica.cpp:968] Persisted action at 2
> I0626 20:41:21.303203 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 2
> I0626 20:41:21.318981 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 3 within 4.999994112secs
> I0626 20:41:21.319692 21919 replica.cpp:808] Replica received write request
> for position 3
> I0626 20:41:21.352903 21919 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 32.915002ms
> I0626 20:41:21.352957 21919 replica.cpp:968] Persisted action at 3
> I0626 20:41:21.359335 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 3
> I0626 20:41:21.359695 21915 replica.cpp:808] Replica received write request
> for position 3
> I0626 20:41:21.419529 21915 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 52.467613ms
> I0626 20:41:21.427070 21915 replica.cpp:968] Persisted action at 3
> I0626 20:41:21.427574 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 3
> I0626 20:41:21.428028 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 4 within 4.999994112secs
> I0626 20:41:21.428659 21915 replica.cpp:808] Replica received write request
> for position 4
> I0626 20:41:21.455736 21915 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 26.806304ms
> I0626 20:41:21.455778 21915 replica.cpp:968] Persisted action at 4
> I0626 20:41:21.479257 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 4
> I0626 20:41:21.503290 21913 replica.cpp:808] Replica received write request
> for position 4
> I0626 20:41:21.537670 21913 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 34.117047ms
> I0626 20:41:21.537742 21913 replica.cpp:968] Persisted action at 4
> I0626 20:41:21.538226 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 4
> I0626 20:41:21.538622 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 5 within 4.999994112secs
> I0626 20:41:21.539290 21913 replica.cpp:808] Replica received write request
> for position 5
> I0626 20:41:21.564021 21913 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 24.500044ms
> I0626 20:41:21.564059 21913 replica.cpp:968] Persisted action at 5
> I0626 20:41:21.571207 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 5
> I0626 20:41:21.591270 21916 replica.cpp:808] Replica received write request
> for position 5
> I0626 20:41:21.629318 21916 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 34.212925ms
> I0626 20:41:21.629400 21916 replica.cpp:968] Persisted action at 5
> I0626 20:41:21.629915 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 5
> I0626 20:41:21.630229 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 6 within 4.999995136secs
> I0626 20:41:21.630880 21918 replica.cpp:808] Replica received write request
> for position 6
> I0626 20:41:21.677770 21918 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 46.614006ms
> I0626 20:41:21.677819 21918 replica.cpp:968] Persisted action at 6
> I0626 20:41:21.683238 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 6
> I0626 20:41:21.699316 21919 replica.cpp:808] Replica received write request
> for position 6
> I0626 20:41:21.729264 21919 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 22.204145ms
> I0626 20:41:21.729676 21919 replica.cpp:968] Persisted action at 6
> I0626 20:41:21.735285 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 6
> I0626 20:41:21.735566 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 7 within 4.9999936secs
> I0626 20:41:21.736253 21915 replica.cpp:808] Replica received write request
> for position 7
> I0626 20:41:21.763922 21915 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 27.472401ms
> I0626 20:41:21.763962 21915 replica.cpp:968] Persisted action at 7
> I0626 20:41:21.783509 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 7
> I0626 20:41:21.805896 21915 replica.cpp:808] Replica received write request
> for position 7
> I0626 20:41:21.861004 21915 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 21.942984ms
> I0626 20:41:21.861044 21915 replica.cpp:968] Persisted action at 7
> I0626 20:41:21.867172 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 7
> I0626 20:41:21.871148 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 8 within 4.99999616secs
> I0626 20:41:21.875263 21919 replica.cpp:808] Replica received write request
> for position 8
> I0626 20:41:21.930502 21919 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 41.428199ms
> I0626 20:41:21.939056 21919 replica.cpp:968] Persisted action at 8
> I0626 20:41:21.939671 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 8
> I0626 20:41:21.940099 21913 replica.cpp:808] Replica received write request
> for position 8
> I0626 20:41:21.975831 21913 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 35.384641ms
> I0626 20:41:21.975870 21913 replica.cpp:968] Persisted action at 8
> I0626 20:41:21.976367 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 8
> I0626 20:41:21.976743 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 9 within 4.999994112secs
> I0626 20:41:22.003428 21916 replica.cpp:808] Replica received write request
> for position 9
> I0626 20:41:22.097714 21916 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 90.627852ms
> I0626 20:41:22.103101 21916 replica.cpp:968] Persisted action at 9
> I0626 20:41:22.119375 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 9
> I0626 20:41:22.123510 21915 replica.cpp:808] Replica received write request
> for position 9
> I0626 20:41:22.517976 21915 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 366.866721ms
> I0626 20:41:22.634582 21915 replica.cpp:968] Persisted action at 9
> I0626 20:41:22.663561 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 9
> I0626 20:41:22.663754 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 10 within 4.999992832secs
> I0626 20:41:22.664383 21915 replica.cpp:808] Replica received write request
> for position 10
> I0626 20:41:22.749339 21915 replica.cpp:385] Persisting action (18 bytes) to
> leveldb took 84.660755ms
> I0626 20:41:22.749498 21915 replica.cpp:968] Persisted action at 10
> I0626 20:41:22.755388 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 10
> I0626 20:41:22.775377 21918 replica.cpp:808] Replica received write request
> for position 10
> I0626 20:41:22.803761 21918 replica.cpp:385] Persisting action (20 bytes) to
> leveldb took 20.68537ms
> I0626 20:41:22.804170 21918 replica.cpp:968] Persisted action at 10
> I0626 20:41:22.844249 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 10
> I0626 20:41:23.054677 21774 replica.cpp:230] Opened db in 183.449273ms
> I0626 20:41:23.111276 21774 replica.cpp:237] Compacted db in 56.510958ms
> I0626 20:41:23.111356 21774 replica.cpp:253] Created db iterator in 5.844us
> I0626 20:41:23.111747 21774 replica.cpp:259] Seeked to beginning of db in
> 1.167us
> I0626 20:41:23.119043 21774 replica.cpp:310] Iterated through 0 keys in the
> db in 459ns
> I0626 20:41:23.139217 21774 replica.cpp:1040] Replica recovered with log
> positions 0 -> 0 and holes { 0 } and unlearned { }
> I0626 20:41:23.140028 21774 coordinator.cpp:61] Coordinator attempting to get
> elected within 4.99998592secs
> I0626 20:41:23.141047 21915 replica.cpp:777] Replica received implicit
> promise request for 1
> I0626 20:41:23.141069 21914 replica.cpp:777] Replica received implicit
> promise request for 1
> I0626 20:41:23.141240 21915 replica.cpp:781] Replica denying promise request
> for 1
> I0626 20:41:23.142765 21774 coordinator.cpp:61] Coordinator attempting to get
> elected within 4.99999872secs
> I0626 20:41:23.236892 21914 replica.cpp:354] Persisting promise (6 bytes) to
> leveldb took 94.860911ms
> I0626 20:41:23.237288 21914 replica.cpp:953] Persisted promise to 1
> I0626 20:41:23.243592 21913 replica.cpp:777] Replica received implicit
> promise request for 2
> I0626 20:41:23.243639 21916 replica.cpp:777] Replica received implicit
> promise request for 2
> I0626 20:41:23.311789 21913 replica.cpp:354] Persisting promise (6 bytes) to
> leveldb took 44.663944ms
> I0626 20:41:23.323551 21913 replica.cpp:953] Persisted promise to 2
> I0626 20:41:23.392300 21916 replica.cpp:354] Persisting promise (6 bytes) to
> leveldb took 69.141155ms
> I0626 20:41:23.395490 21916 replica.cpp:953] Persisted promise to 2
> I0626 20:41:23.396211 21774 coordinator.cpp:115] Coordinator elected,
> attempting to fill missing positions
> I0626 20:41:23.396749 21774 coordinator.cpp:396] Coordinator attempting to
> fill position 0 in the log
> I0626 20:41:23.397155 21916 replica.cpp:705] Replica received explicit
> promise request for 2 for position 0
> I0626 20:41:23.397258 21915 replica.cpp:705] Replica received explicit
> promise request for 2 for position 0
> I0626 20:41:23.397424 21916 replica.cpp:470] Reading position from leveldb
> took 16.991us
> I0626 20:41:23.436779 21915 replica.cpp:385] Persisting action (8 bytes) to
> leveldb took 38.895284ms
> I0626 20:41:23.445092 21916 replica.cpp:385] Persisting action (14 bytes) to
> leveldb took 46.738579ms
> I0626 20:41:23.476065 21916 replica.cpp:968] Persisted action at 0
> I0626 20:41:23.475684 21915 replica.cpp:968] Persisted action at 0
> I0626 20:41:23.483412 21774 coordinator.cpp:226] Coordinator attempting to
> write NOP action at position 0 within 4.659352576secs
> I0626 20:41:23.508016 21914 replica.cpp:808] Replica received write request
> for position 0
> I0626 20:41:23.535081 21914 replica.cpp:470] Reading position from leveldb
> took 19.925us
> I0626 20:41:23.598891 21914 replica.cpp:385] Persisting action (14 bytes) to
> leveldb took 31.794238ms
> I0626 20:41:23.619079 21914 replica.cpp:968] Persisted action at 0
> I0626 20:41:23.619822 21774 coordinator.cpp:317] Coordinator attempting to
> commit NOP action at position 0
> I0626 20:41:23.620852 21917 replica.cpp:808] Replica received write request
> for position 0
> I0626 20:41:23.621188 21917 replica.cpp:470] Reading position from leveldb
> took 12.396us
> I0626 20:41:23.651787 21917 replica.cpp:385] Persisting action (16 bytes) to
> leveldb took 30.098942ms
> I0626 20:41:23.651824 21917 replica.cpp:968] Persisted action at 0
> I0626 20:41:23.659102 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 0
> I0626 20:41:23.669332 21774 coordinator.cpp:396] Coordinator attempting to
> fill position 1 in the log
> I0626 20:41:23.675351 21919 replica.cpp:705] Replica received explicit
> promise request for 2 for position 1
> I0626 20:41:23.675426 21912 replica.cpp:705] Replica received explicit
> promise request for 2 for position 1
> I0626 20:41:23.683060 21919 replica.cpp:470] Reading position from leveldb
> took 12.668us
> I0626 20:41:23.748842 21912 replica.cpp:385] Persisting action (8 bytes) to
> leveldb took 42.732767ms
> I0626 20:41:23.771150 21912 replica.cpp:968] Persisted action at 1
> I0626 20:41:23.770740 21919 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 64.103326ms
> I0626 20:41:23.772492 21919 replica.cpp:968] Persisted action at 1
> I0626 20:41:23.773185 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 1 within 4.369583616secs
> I0626 20:41:23.773668 21913 replica.cpp:808] Replica received write request
> for position 1
> I0626 20:41:23.773900 21913 replica.cpp:470] Reading position from leveldb
> took 31.376us
> I0626 20:41:23.798800 21913 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 24.487176ms
> I0626 20:41:23.798853 21913 replica.cpp:968] Persisted action at 1
> I0626 20:41:23.799362 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 1
> I0626 20:41:23.799837 21915 replica.cpp:808] Replica received write request
> for position 1
> I0626 20:41:23.800123 21915 replica.cpp:470] Reading position from leveldb
> took 7.923us
> I0626 20:41:23.853301 21915 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 52.650456ms
> I0626 20:41:23.853366 21915 replica.cpp:968] Persisted action at 1
> I0626 20:41:23.859273 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 1
> I0626 20:41:23.867152 21774 coordinator.cpp:396] Coordinator attempting to
> fill position 2 in the log
> I0626 20:41:23.883357 21913 replica.cpp:705] Replica received explicit
> promise request for 2 for position 2
> I0626 20:41:23.883427 21915 replica.cpp:705] Replica received explicit
> promise request for 2 for position 2
> I0626 20:41:23.905468 21913 replica.cpp:470] Reading position from leveldb
> took 26.87us
> I0626 20:41:24.010098 21915 replica.cpp:385] Persisting action (8 bytes) to
> leveldb took 67.007264ms
> I0626 20:41:24.026720 21915 replica.cpp:968] Persisted action at 2
> I0626 20:41:24.039180 21913 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 93.785236ms
> I0626 20:41:24.039219 21913 replica.cpp:968] Persisted action at 2
> I0626 20:41:24.059291 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 2 within 4.083469824secs
> I0626 20:41:24.152204 21916 replica.cpp:808] Replica received write request
> for position 2
> I0626 20:41:24.207103 21916 replica.cpp:470] Reading position from leveldb
> took 20.477us
> I0626 20:41:24.297492 21916 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 70.184444ms
> I0626 20:41:24.297580 21916 replica.cpp:968] Persisted action at 2
> I0626 20:41:24.314306 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 2
> I0626 20:41:24.351313 21914 replica.cpp:808] Replica received write request
> for position 2
> I0626 20:41:24.371170 21914 replica.cpp:470] Reading position from leveldb
> took 26.576us
> I0626 20:41:24.443598 21914 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 72.01364ms
> I0626 20:41:24.443743 21914 replica.cpp:968] Persisted action at 2
> I0626 20:41:24.444273 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 2
> I0626 20:41:24.444576 21774 coordinator.cpp:396] Coordinator attempting to
> fill position 3 in the log
> I0626 20:41:24.445240 21913 replica.cpp:705] Replica received explicit
> promise request for 2 for position 3
> I0626 20:41:24.445255 21916 replica.cpp:705] Replica received explicit
> promise request for 2 for position 3
> I0626 20:41:24.445966 21916 replica.cpp:470] Reading position from leveldb
> took 16.94us
> I0626 20:41:24.477943 21913 replica.cpp:385] Persisting action (8 bytes) to
> leveldb took 32.457971ms
> I0626 20:41:24.511087 21913 replica.cpp:968] Persisted action at 3
> I0626 20:41:24.504189 21916 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 25.827586ms
> I0626 20:41:24.531059 21916 replica.cpp:968] Persisted action at 3
> I0626 20:41:24.531718 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 3 within 3.6110528secs
> I0626 20:41:24.532310 21918 replica.cpp:808] Replica received write request
> for position 3
> I0626 20:41:24.532635 21918 replica.cpp:470] Reading position from leveldb
> took 10.518us
> I0626 20:41:24.581715 21918 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 48.61473ms
> I0626 20:41:24.581756 21918 replica.cpp:968] Persisted action at 3
> I0626 20:41:24.584699 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 3
> I0626 20:41:24.591269 21916 replica.cpp:808] Replica received write request
> for position 3
> I0626 20:41:24.601011 21916 replica.cpp:470] Reading position from leveldb
> took 7.182us
> I0626 20:41:24.636215 21916 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 34.690083ms
> I0626 20:41:24.636250 21916 replica.cpp:968] Persisted action at 3
> I0626 20:41:24.642242 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 3
> I0626 20:41:24.647207 21774 coordinator.cpp:396] Coordinator attempting to
> fill position 4 in the log
> I0626 20:41:24.655419 21914 replica.cpp:705] Replica received explicit
> promise request for 2 for position 4
> I0626 20:41:24.655449 21912 replica.cpp:705] Replica received explicit
> promise request for 2 for position 4
> I0626 20:41:24.663072 21914 replica.cpp:470] Reading position from leveldb
> took 13.025us
> I0626 20:41:24.752864 21912 replica.cpp:385] Persisting action (8 bytes) to
> leveldb took 63.273747ms
> I0626 20:41:24.752964 21912 replica.cpp:968] Persisted action at 4
> I0626 20:41:24.771162 21914 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 76.064668ms
> I0626 20:41:24.812331 21914 replica.cpp:968] Persisted action at 4
> I0626 20:41:24.839303 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 4 within 3.303465728secs
> I0626 20:41:24.893604 21919 replica.cpp:808] Replica received write request
> for position 4
> I0626 20:41:24.893775 21919 replica.cpp:470] Reading position from leveldb
> took 32.084us
> I0626 20:41:24.927736 21919 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 33.511705ms
> I0626 20:41:24.927777 21919 replica.cpp:968] Persisted action at 4
> I0626 20:41:24.975308 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 4
> I0626 20:41:24.983397 21915 replica.cpp:808] Replica received write request
> for position 4
> I0626 20:41:24.991194 21915 replica.cpp:470] Reading position from leveldb
> took 33.638us
> I0626 20:41:25.030565 21915 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 31.506767ms
> I0626 20:41:25.039055 21915 replica.cpp:968] Persisted action at 4
> I0626 20:41:25.039706 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 4
> I0626 20:41:25.040030 21774 coordinator.cpp:396] Coordinator attempting to
> fill position 5 in the log
> I0626 20:41:25.040755 21914 replica.cpp:705] Replica received explicit
> promise request for 2 for position 5
> I0626 20:41:25.040809 21918 replica.cpp:705] Replica received explicit
> promise request for 2 for position 5
> I0626 20:41:25.040969 21914 replica.cpp:470] Reading position from leveldb
> took 17.849us
> I0626 20:41:25.731782 21914 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 689.848034ms
> I0626 20:41:25.731890 21914 replica.cpp:968] Persisted action at 5
> I0626 20:41:25.731782 21918 replica.cpp:385] Persisting action (8 bytes) to
> leveldb took 690.345411ms
> I0626 20:41:25.935171 21918 replica.cpp:968] Persisted action at 5
> I0626 20:41:25.959568 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 5 within 2.183219712secs
> I0626 20:41:25.987756 21914 replica.cpp:808] Replica received write request
> for position 5
> I0626 20:41:26.023177 21914 replica.cpp:470] Reading position from leveldb
> took 25.73us
> I0626 20:41:26.807257 21914 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 783.485219ms
> I0626 20:41:26.807368 21914 replica.cpp:968] Persisted action at 5
> I0626 20:41:26.831714 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 5
> I0626 20:41:26.943361 21912 replica.cpp:808] Replica received write request
> for position 5
> I0626 20:41:27.013192 21912 replica.cpp:470] Reading position from leveldb
> took 26.435us
> I0626 20:41:27.136229 21912 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 113.172463ms
> I0626 20:41:27.136286 21912 replica.cpp:968] Persisted action at 5
> I0626 20:41:27.137073 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 5
> I0626 20:41:27.168833 21774 coordinator.cpp:396] Coordinator attempting to
> fill position 6 in the log
> I0626 20:41:27.195685 21917 replica.cpp:705] Replica received explicit
> promise request for 2 for position 6
> I0626 20:41:27.195741 21919 replica.cpp:705] Replica received explicit
> promise request for 2 for position 6
> I0626 20:41:27.238976 21917 replica.cpp:470] Reading position from leveldb
> took 40.612us
> I0626 20:41:27.312754 21919 replica.cpp:385] Persisting action (8 bytes) to
> leveldb took 73.706819ms
> I0626 20:41:27.443476 21917 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 110.879543ms
> I0626 20:41:27.455013 21917 replica.cpp:968] Persisted action at 6
> I0626 20:41:27.453696 21919 replica.cpp:968] Persisted action at 6
> I0626 20:41:27.456243 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 6 within 686.525696ms
> I0626 20:41:27.456938 21916 replica.cpp:808] Replica received write request
> for position 6
> I0626 20:41:27.457139 21916 replica.cpp:470] Reading position from leveldb
> took 23.735us
> I0626 20:41:27.496920 21916 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 39.292541ms
> I0626 20:41:27.496959 21916 replica.cpp:968] Persisted action at 6
> I0626 20:41:27.531868 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 6
> I0626 20:41:27.651242 21913 replica.cpp:808] Replica received write request
> for position 6
> I0626 20:41:27.660727 21913 replica.cpp:470] Reading position from leveldb
> took 31.153us
> I0626 20:41:27.718060 21913 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 51.000821ms
> I0626 20:41:27.723131 21913 replica.cpp:968] Persisted action at 6
> I0626 20:41:27.743257 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 6
> I0626 20:41:27.764978 21774 coordinator.cpp:396] Coordinator attempting to
> fill position 7 in the log
> I0626 20:41:27.771358 21915 replica.cpp:705] Replica received explicit
> promise request for 2 for position 7
> I0626 20:41:27.771390 21912 replica.cpp:705] Replica received explicit
> promise request for 2 for position 7
> I0626 20:41:27.779307 21915 replica.cpp:470] Reading position from leveldb
> took 29.999us
> I0626 20:41:27.834671 21912 replica.cpp:385] Persisting action (8 bytes) to
> leveldb took 51.314695ms
> I0626 20:41:27.891047 21912 replica.cpp:968] Persisted action at 7
> I0626 20:41:27.871721 21915 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 28.643979ms
> I0626 20:41:27.899489 21915 replica.cpp:968] Persisted action at 7
> I0626 20:41:27.900194 21774 coordinator.cpp:226] Coordinator attempting to
> write APPEND action at position 7 within 242.566656ms
> I0626 20:41:27.900635 21913 replica.cpp:808] Replica received write request
> for position 7
> I0626 20:41:27.900951 21913 replica.cpp:470] Reading position from leveldb
> took 9.194us
> I0626 20:41:27.933037 21913 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 31.555207ms
> I0626 20:41:27.933074 21913 replica.cpp:968] Persisted action at 7
> I0626 20:41:27.959275 21774 coordinator.cpp:317] Coordinator attempting to
> commit APPEND action at position 7
> I0626 20:41:27.983212 21916 replica.cpp:808] Replica received write request
> for position 7
> I0626 20:41:27.983522 21916 replica.cpp:470] Reading position from leveldb
> took 8.346us
> I0626 20:41:28.017935 21916 replica.cpp:385] Persisting action (19 bytes) to
> leveldb took 33.885755ms
> I0626 20:41:28.018018 21916 replica.cpp:968] Persisted action at 7
> I0626 20:41:28.023262 21774 coordinator.cpp:385] Telling other replicas of
> learned action at position 7
> I0626 20:41:28.031113 21774 coordinator.cpp:396] Coordinator attempting to
> fill position 8 in the log
> I0626 20:41:28.040364 21913 replica.cpp:705] Replica received explicit
> promise request for 2 for position 8
> I0626 20:41:28.040405 21918 replica.cpp:705] Replica received explicit
> promise request for 2 for position 8
> I0626 20:41:28.071641 21913 replica.cpp:470] Reading position from leveldb
> took 39.919us
> I0626 20:41:28.143702 21774 coordinator.cpp:499] Coordinator timed out
> attempting to fill position 8 in the log
> tests/log_tests.cpp:846: Failure
> result is NONE
> I0626 20:41:28.170296 21918 replica.cpp:385] Persisting action (8 bytes) to
> leveldb took 95.220196ms
> I0626 20:41:28.170302 21913 replica.cpp:385] Persisting action (17 bytes) to
> leveldb took 94.763157ms
> I0626 20:41:28.170440 21918 replica.cpp:968] Persisted action at 8
> I0626 20:41:28.170812 21913 replica.cpp:968] Persisted action at 8
> [ FAILED ] CoordinatorTest.MultipleAppendsNotLearnedFill (8121 ms)
--
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
