ostracon icon indicating copy to clipboard operation
ostracon copied to clipboard

Published 20 hours ago • verified publisher icon Finschia

Fix the test case that often fails.

Open egonspace opened this issue 3 years ago • 5 comments

Ostracon version (use ostracon version or git rev-parse --verify HEAD if installed from source): latest

ABCI app (name for built-in, URL for self-written if it's publicly available):

Environment:

  • OS (e.g. from /etc/os-release):
  • Install tools:
  • Others:

What happened: The following tests often fail in CI tests:

failed test case

--- FAIL: TestByzantinePrevoteEquivocation (30.14s)
    byzantine_test.go:285: Consensus Reactor 0
        ConsensusReactor
    byzantine_test.go:285: Consensus Reactor 1
        ConsensusReactor
    byzantine_test.go:285: Consensus Reactor 2
        ConsensusReactor
    byzantine_test.go:285: Consensus Reactor 3
        ConsensusReactor
    byzantine_test.go:287: Timed out waiting for validators to commit evidence
FAIL
coverage: 71.5% of statements
FAIL	github.com/line/ostracon/consensus	135.075s

--- FAIL: TestStartNextHeightCorrectlyAfterTimeout (0.63s)
panic: Timeout expired while waiting for NewBlockHeader event [recovered]
	panic: Timeout expired while waiting for NewBlockHeader event

goroutine 65933 [running]:
testing.tRunner.func1.2(0x1262940, 0x160d080)
	/opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1143 +0x49f
testing.tRunner.func1(0xc00d679680)
	/opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1146 +0x695
panic(0x1262940, 0x160d080)
	/opt/hostedtoolcache/go/1.16.7/x64/src/runtime/panic.go:971 +0x499
github.com/line/ostracon/consensus.ensureNewBlockHeader(0xc00918ea20, 0x1, 0xc0023158e0, 0x20, 0x20)
	/home/runner/work/ostracon/ostracon/consensus/common_test.go:661 +0x2e5
github.com/line/ostracon/consensus.TestStartNextHeightCorrectlyAfterTimeout(0xc00d679680)
	/home/runner/work/ostracon/ostracon/consensus/state_test.go:1760 +0xc7d
testing.tRunner(0xc00d679680, 0x1512310)
	/opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1193 +0x203
created by testing.(*T).Run
	/opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1238 +0x5d8
FAIL	github.com/line/ostracon/consensus	78.018s

WARNING: DATA RACE
Write at 0x00c000f085c8 by goroutine 177:
  github.com/line/ostracon/blockchain/v0.TestBadBlockStopsPeer()
      /home/runner/work/ostracon/ostracon/blockchain/v0/reactor_test.go:264 +0xf58
  testing.tRunner()
      /opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1193 +0x202

Previous read at 0x00c000f085c8 by goroutine 634:
  [failed to restore the stack]

Goroutine 177 (running) created at:
  testing.(*T).Run()
      /opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1238 +0x5d7
  testing.runTests.func1()
      /opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1511 +0xa6
  testing.tRunner()
      /opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1193 +0x202
  testing.runTests()
      /opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1509 +0x612
  testing.(*M).Run()
      /opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1417 +0x3b3
  main.main()
      _testmain.go:101 +0x356

Goroutine 634 (running) created at:
  github.com/line/ostracon/blockchain/v0.(*BlockchainReactor).OnStart()
      /home/runner/work/ostracon/ostracon/blockchain/v0/reactor.go:116 +0x175
  github.com/line/ostracon/libs/service.(*BaseService).Start()
      /home/runner/work/ostracon/ostracon/libs/service/service.go:140 +0x55e
  github.com/line/ostracon/blockchain/v0.(*BlockchainReactor).Start()
      <autogenerated>:1 +0x44
  github.com/line/ostracon/p2p.(*Switch).OnStart()
      /home/runner/work/ostracon/ostracon/p2p/switch.go:227 +0x121
  github.com/line/ostracon/libs/service.(*BaseService).Start()
      /home/runner/work/ostracon/ostracon/libs/service/service.go:140 +0x55e
  github.com/line/ostracon/p2p.StartSwitches()
      /home/runner/work/ostracon/ostracon/p2p/test_util.go:168 +0x75
  github.com/line/ostracon/p2p.MakeConnectedSwitches()
      /home/runner/work/ostracon/ostracon/p2p/test_util.go:89 +0x189
  github.com/line/ostracon/blockchain/v0.TestBadBlockStopsPeer()
      /home/runner/work/ostracon/ostracon/blockchain/v0/reactor_test.go:229 +0xd37
  testing.tRunner()
      /opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1193 +0x202
==================
--- FAIL: TestBadBlockStopsPeer (42.05s)
    testing.go:1092: race detected during execution of test

(Failing tests will continue to be added here.)

What you expected to happen:

Have you tried the latest version: yes/no

How to reproduce it (as minimally and precisely as possible):

Logs (paste a small part showing an error (< 10 lines) or link a pastebin, gist, etc. containing more of the log file):

Config (you can paste only the changes you've made):

node command runtime flags:

Please provide the output from the http://<ip>:<port>/dump_consensus_state RPC endpoint for consensus bugs

Anything else we need to know:

egonspace avatar Aug 25 '21 23:08 egonspace

I met the TestByzantinePrevoteEquivocation which is often failing. But I never met the other two. However, I met the TestWALCrash which is often failing.

I've just addressed two test cases(PR:https://github.com/line/ostracon/pull/319):

  • TestByzantinePrevoteEquivocation
  • TestWALCrash

Thanks

tnasu avatar Sep 21 '21 01:09 tnasu

These tests sometimes failed.

  • TestSwitchAcceptRoutine
  • TestProposerFrequency
  • TestStateLockPOLRelock
  • TestPEXReactorSeedModeFlushStop

Of the above, these failed 2 out of 5 times.

  • TestSwitchAcceptRoutine
  • TestProposerFrequency

Kynea0b avatar Nov 04 '21 07:11 Kynea0b

(accidentally closed by bot😱)

torao avatar Mar 07 '22 04:03 torao

Recent errors:

  • Should be re-run
--- FAIL: TestProposerFrequency (7.64s)
--- FAIL: TestStateBadVoterWithSelectedVoter (0.98s)
--- FAIL: TestSelectVoter (0.01s)
    voter_set_test.go:311: 
        	Error Trace:	/home/runner/work/ostracon/ostracon/types/voter_set_test.go:311
        	Error:      	Should be true
        	Test:       	TestSelectVoter
  • Timeout
--- FAIL: TestBroadcastTxForPeerStopsWhenReactorStops (10.04s)
  • Timing
WARNING: DATA RACE
--- FAIL: TestMempoolRemoteAppConcurrency (0.07s)
    testing.go:1312: race detected during execution of test
--- FAIL: TestBroadcastTxForPeerStopsWhenReactorStops (10.04s)
    leaktest.go:132: leaktest: timed out checking goroutines
  • Timeout and panic
panic: test timed out after 7m0s
FAIL	github.com/line/ostracon/consensus	420.828s
  • Timing and panic
panic: BlockStore can only save contiguous blocks. Wanted 149, got 147
FAIL	github.com/line/ostracon/blockchain/v0	42.016s

tnasu avatar Dec 22 '22 07:12 tnasu

Recent errors:

--- FAIL: TestLightClientAttackEvidence_Equivocation (1.10s)
    detector_test.go:115: ==> verification sequential
    detector_test.go:181: 
        	Error Trace:	/home/runner/work/ostracon/ostracon/light/detector_test.go:181
        	Error:      	Should be true
        	Test:       	TestLightClientAttackEvidence_Equivocation
    detector_test.go:190: 
        	Error Trace:	/home/runner/work/ostracon/ostracon/light/detector_test.go:190
        	Error:      	Should be true
        	Test:       	TestLightClientAttackEvidence_Equivocation
    detector_test.go:115: ==> verification skipping
    detector_test.go:181: 
        	Error Trace:	/home/runner/work/ostracon/ostracon/light/detector_test.go:181
        	Error:      	Should be true
        	Test:       	TestLightClientAttackEvidence_Equivocation
    detector_test.go:190: 
        	Error Trace:	/home/runner/work/ostracon/ostracon/light/detector_test.go:190
        	Error:      	Should be true
        	Test:       	TestLightClientAttackEvidence_Equivocation
FAIL
coverage: 78.2% of statements
FAIL	github.com/Finschia/ostracon/light	63.038s

--- FAIL: TestBroadcastTxForPeerStopsWhenReactorStops (10.03s)
    leaktest.go:132: leaktest: timed out checking goroutines
    leaktest.go:150: leaktest: leaked goroutine: goroutine 2830 [select]:
        github.com/Finschia/ostracon/p2p/conn.(*MConnection).sendRoutine(0xc003312420)
        	/home/runner/work/ostracon/ostracon/p2p/conn/connection.go:438 +0x3ec
        created by github.com/Finschia/ostracon/p2p/conn.(*MConnection).OnStart
        	/home/runner/work/ostracon/ostracon/p2p/conn/connection.go:237 +0x3a5
    leaktest.go:150: leaktest: leaked goroutine: goroutine 2831 [select]:
        net.(*pipe).read(0xc00258e780, {0xc001a7a000, 0x414, 0x7ff2b7bd6d60?})
        	/opt/hostedtoolcache/go/1.18.10/x64/src/net/pipe.go:159 +0x23d
        net.(*pipe).Read(0x414?, {0xc001a7a000, 0x414, 0x800})
        	/opt/hostedtoolcache/go/1.18.10/x64/src/net/pipe.go:142 +0x55
        io.ReadAtLeast({0x7ff2b7bc8d78, 0xc00258e780}, {0xc001a7a000, 0x414, 0x800}, 0x414)
        	/opt/hostedtoolcache/go/1.18.10/x64/src/io/io.go:331 +0xde
        io.ReadFull(...)
        	/opt/hostedtoolcache/go/1.18.10/x64/src/io/io.go:350
        github.com/Finschia/ostracon/p2p/conn.(*SecretConnection).Read(0xc0000d8100, {0xc000255800, 0x400, 0x0?})
        	/home/runner/work/ostracon/ostracon/p2p/conn/secret_connection.go:246 +0x331
        bufio.(*Reader).Read(0xc00253b980, {0xc002aa[76](https://github.com/Finschia/ostracon/actions/runs/4717569416/jobs/8366320906#step:7:77)bf, 0x1, 0x1})
        	/opt/hostedtoolcache/go/1.18.10/x64/src/bufio/bufio.go:236 +0x4db
        github.com/Finschia/ostracon/libs/protoio.(*byteReader).ReadByte(0xc001[79](https://github.com/Finschia/ostracon/actions/runs/4717569416/jobs/8366320906#step:7:80)4d50)
        	/home/runner/work/ostracon/ostracon/libs/protoio/io.go:93 +0x86
        encoding/binary.ReadUvarint({0x1419d80, 0xc001794d50})
        	/opt/hostedtoolcache/go/1.18.10/x64/src/encoding/binary/varint.go:115 +0x8c
        github.com/Finschia/ostracon/libs/protoio.(*varintReader).ReadMsg(0xc002b65f70, {0x14206b8, 0xc002e29140})
        	/home/runner/work/ostracon/ostracon/libs/protoio/reader.go:68 +0x172
        github.com/Finschia/ostracon/p2p/conn.(*MConnection).recvRoutine(0xc003312420)
        	/home/runner/work/ostracon/ostracon/p2p/conn/connection.go:593 +0x26b
        created by github.com/Finschia/ostracon/p2p/conn.(*MConnection).OnStart
        	/home/runner/work/ostracon/ostracon/p2p/conn/connection.go:238 +0x411
    leaktest.go:150: leaktest: leaked goroutine: goroutine 2[83](https://github.com/Finschia/ostracon/actions/runs/4717569416/jobs/8366320906#step:7:84)2 [select]:
        github.com/Finschia/ostracon/p2p.(*peer).metricsReporter(0xc0000dc600)
        	/home/runner/work/ostracon/ostracon/p2p/peer.go:356 +0x196
        created by github.com/Finschia/ostracon/p2p.(*peer).OnStart
        	/home/runner/work/ostracon/ostracon/p2p/peer.go:191 +0xb7
FAIL
coverage: [86](https://github.com/Finschia/ostracon/actions/runs/4717569416/jobs/8366320906#step:7:87).8% of statements
FAIL	github.com/Finschia/ostracon/mempool	1[95](https://github.com/Finschia/ostracon/actions/runs/4717569416/jobs/8366320906#step:7:96).154s

--- FAIL: TestCListMempool_SystemTestWithCacheSizeDefault (50.00s)
    clist_mempool_system_test.go:73: 
        	Error Trace:	/home/runner/work/ostracon/ostracon/mempool/clist_mempool_system_test.go:73
        	Error:      	Not equal: 
        	            	expected: 3295
        	            	actual  : 3294
        	Test:       	TestCListMempool_SystemTestWithCacheSizeDefault
FAIL
coverage: 86.8% of statements
FAIL	github.com/Finschia/ostracon/mempool	196.684s

--- FAIL: TestProposerFrequency (8.03s)
    state_test.go:450: 
        	Error Trace:	/home/runner/work/ostracon/ostracon/state/state_test.go:450
        	            				/home/runner/work/ostracon/ostracon/state/state_test.go:377
        	Error:      	Should be true
        	Test:       	TestProposerFrequency
        	Messages:   	Case 3 validator N(54): Chi-squared test failure: runs=25643, p-Value[0.030646] <= expected p-Value0.050000]. Please re-run test since This test case is a probabilistic test
FAIL
coverage: 75.9% of statements
FAIL	github.com/Finschia/ostracon/state	23.474s

--- FAIL: TestStateLockPOLRelock (0.16s)
panic: Unfortunately, there is no such LastProofHash making index validator to be proposer. Please re-run the test since find LastProofHash [recovered]
	panic: Unfortunately, there is no such LastProofHash making index validator to be proposer. Please re-run the test since find LastProofHash

goroutine 56765 [running]:
testing.tRunner.func1.2({0x11c39e0, 0x15ca800})
	/opt/hostedtoolcache/go/1.18.10/x64/src/testing/testing.go:1389 +0x366
testing.tRunner.func1()
	/opt/hostedtoolcache/go/1.18.10/x64/src/testing/testing.go:1392 +0x5d2
panic({0x11c39e0, 0x15ca800})
	/opt/hostedtoolcache/go/1.18.10/x64/src/runtime/panic.go:844 +0x258
github.com/Finschia/ostracon/consensus.forceProposer(0xc000196a80, {0xc001599400, 0x4, 0x4[83](https://github.com/Finschia/ostracon/actions/runs/4717944234/jobs/8367046251#step:7:84)d99?}, {0xc007f27be8, 0x3, 0xc007e26a60?}, {0xc007f27bd0, 0x3, 0x3}, ...)
	/home/runner/work/ostracon/ostracon/consensus/common_test.go:526 +0x650
github.com/Finschia/ostracon/consensus.TestStateLockPOLRelock(0xc0041f2b60)
	/home/runner/work/ostracon/ostracon/consensus/state_test.go:620 +0x479
testing.tRunner(0xc0041f2b60, 0x1490f28)
	/opt/hostedtoolcache/go/1.18.10/x64/src/testing/testing.go:1439 +0x214
created by testing.(*T).Run
	/opt/hostedtoolcache/go/1.18.10/x64/src/testing/testing.go:14[86](https://github.com/Finschia/ostracon/actions/runs/4717944234/jobs/8367046251#step:7:87) +0x725
FAIL	github.com/Finschia/ostracon/consensus	68.2[98](https://github.com/Finschia/ostracon/actions/runs/4717944234/jobs/8367046251#step:7:99)s

tnasu avatar Apr 17 '23 05:04 tnasu