orbs-network / orbs-network-go

Orbs node virtual chain core reference implementation in Go
MIT License
48 stars 12 forks source link

BlockSync TestSyncCompletePetitionerSyncFlow is flaky #192

Closed talkol closed 6 years ago

talkol commented 6 years ago

This test is very stable locally on my machine and takes 10 ms

But see this CI run: https://circleci.com/gh/orbs-network/orbs-network-go/835

It fails with some very strange issues:

--- FAIL: TestSyncCompletePetitionerSyncFlow (0.10s)
    require.go:794: 
            Error Trace:    harness.go:51
                                        block_sync_test.go:202
                                        context.go:8
                                        block_sync_test.go:164
            Error:          Received unexpected error:
                            Function #2 HandleBlockConsensus executed 0 times, expected: 4
            Test:           TestSyncCompletePetitionerSyncFlow
info 2018-09-07T21:03:52.391455Z Trying to commit a block service=block-storage block-height=1 function=blockstorage.(*service).CommitBlock source=services/blockstorage/service.go:84 
info 2018-09-07T21:03:52.391488Z Committed a block service=block-storage block-height=1 function=blockstorage.(*service).CommitBlock source=services/blockstorage/service.go:105 
info 2018-09-07T21:03:52.391797Z Trying to commit a block service=block-storage block-height=1 function=blockstorage.(*service).CommitBlock source=services/blockstorage/service.go:84 
info 2018-09-07T21:03:52.391830Z Committed a block service=block-storage block-height=1 function=blockstorage.(*service).CommitBlock source=services/blockstorage/service.go:105 
info 2018-09-07T21:03:52.392015Z Trying to commit a block service=block-storage block-height=2 function=blockstorage.(*service).CommitBlock source=services/blockstorage/service.go:84 
info 2018-09-07T21:03:52.392255Z Trying to commit a block service=block-storage block-height=1 function=blockstorage.(*service).CommitBlock source=services/blockstorage/service.go:84 
error 2018-09-07T21:03:52.392268Z protocol version mismatch service=block-storage expected=1 received=1869f function=blockstorage.(*service).validateProtocolVersion source=services/blockstorage/service.go:349 
--
FAIL
FAIL    github.com/orbs-network/orbs-network-go/services/blockstorage/test  0.327s

This seems strange: error 2018-09-07T21:03:52.392268Z protocol version mismatch service=block-storage expected=1 received=1869f

How could it get such a value for protocol version? Maybe it's the log from a different test?

If the protocol version is a red herring, the issue could be related to Eventually timeout. Try to increase the number 4 in this line harness.verifyMocks(t, 4) at the end of the test..

jlevison commented 6 years ago

protocol version: 1869f is 99999 decimal and we do have tests running this, so i would actually bet it happens from a different test (TestCommitBlockReturnsErrorWhenProtocolVersionMismatches in commit_block_test.go)

the timeout is strange, as 4 would mean 80ms (4*20), and it ran for 100, i will review and increase the timeout, as it seems like a verification timeout issue - as you mentioned and we spoke, we need to make the flakiness identification process better on our machines

jlevison commented 6 years ago

pr #184 possibly fixed this