go-ethereum icon indicating copy to clipboard operation
go-ethereum copied to clipboard

Flaky tests

Open rjl493456442 opened this issue 1 year ago • 4 comments

You may choose any flaky test to fix if you are interested, but be aware that some flaky tests could be complicated.

If you want to investigate the failure, you could add

log.SetDefault(log.NewLogger(log.NewGlogHandler(log.NewTerminalHandler(os.Stderr, false))))

in the test to stream out the logs.

Besides, you could use stress tool to verify if your fix is correct, instructions as follow:

  • go install golang.org/x/tools/cmd/stress@latest
  • cd to the package
  • run go test -c
  • run stress ./<package-name>.test <your test>

  • [x] TestUpdatedKeyfileContents
--- FAIL: TestUpdatedKeyfileContents (7.04s)
    account_cache_test.go:366: First replacement failed
    account_cache_test.go:367: 
        got  [{0x7EF5A6135f1FD6a02593eEdC869c6D41D934aef8 keystore:///tmp/eth-keystore-updatedkeyfilecontents-test-21927-2834323236070515189/aaa}]
        want [{0xf466859eAD1932D743d622CB74FC058882E[864](https://ci.appveyor.com/project/ethereum/go-ethereum/builds/49872631/job/l6n26y9xk0vsgxkm#L864)8A keystore:///tmp/eth-keystore-updatedkeyfilecontents-test-21927-2834323236070515189/aaa}]

  • [x] TestSkeletonSyncRetrievals
--- FAIL: TestSkeletonSyncRetrievals (2.40s)
    skeleton_test.go:908: test 6, mid state: dropped peers mismatch: have 0, want 1
FAIL

  • [x] TestBuildPayload
--- FAIL: TestBuildPayload (0.00s)
    payload_building_test.go:182: Unexpected transaction set
FAIL

  • [x] TestServerPortMapping
--- FAIL: TestServerPortMapping (0.01s)
    server_nat_test.go:45: listen udp [::]:50414: bind: An attempt was made to access a socket in a way forbidden by its access permissions.

  • [ ] TestWalletNotifications
--- FAIL: TestWalletNotifications (0.83s)
    keystore_test.go:427: wallet list doesn't match required accounts: have 491, want 490
    keystore_test.go:455: can't find event with Kind=2 for 56fe5c503fb7f1850298b7d6896cfd8019b525e1
FAIL

  • [ ] TestTable_revalidateSyncRecord
--- FAIL: TestTable_revalidateSyncRecord (2.00s)
    table_reval.go:170: DEBUG[06-05|13:46:45.901] Node revalidated                          b=9 id=0100000000000000 checks=1 q=fast
    table_test.go:427: Table did not send revalidation ping
FAIL

  • [ ] TestHTTPNodeRPC
--- FAIL: TestHTTPNodeRPC (10.01s)
    http_test.go:587: context deadline exceeded
FAIL
FAIL	github.com/ethereum/go-ethereum/p2p/simulations	12.163s
  • [ ] TestJWT
--- FAIL: TestJWT (0.01s)
    rpcstack.go:168: INFO [08-02|16:49:51.995] WebSocket enabled                         url=ws://127.0.0.1:42707
    rpcstack.go:175: INFO [08-02|16:49:51.995] HTTP server started                       endpoint=127.0.0.1:42707 auth=true prefix= cors= vhosts=
    rpcstack_test.go:378: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:378: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:378: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:378: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:378: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:440: tc 0-ws, token '***': expected not to allow,  got ok
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization bearer ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization Bearer: ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization Bearer:***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack_test.go:444: checking RPC/HTTP on http://127.0.0.1:42707/ [Authorization ***
    rpcstack.go:290: INFO [08-02|16:49:52.008] HTTP server stopped                       endpoint=127.0.0.1:42707
FAIL

rjl493456442 avatar May 24 '24 02:05 rjl493456442

Found a new flaky test TestDisable from https://ci.appveyor.com/project/ethereum/go-ethereum/builds/49926124/job/2nw6ofdur8xt4ox6

Will draft a PR to fix it.

Update: Larger maxDiffLayers causes a higher probability of failing. If maxDiffLayers = 7, it always fails

lilasxie avatar Jun 01 '24 02:06 lilasxie

Found a new flaky test TestDisable from https://ci.appveyor.com/project/ethereum/go-ethereum/builds/49926124/job/2nw6ofdur8xt4ox6

Will draft a PR to fix it.

Update: Larger maxDiffLayers causes a higher probability of failing. If maxDiffLayers = 7, it always fails

@rjl493456442 Hi sir, here for PR #29901

lilasxie avatar Jun 03 '24 10:06 lilasxie

@rjl493456442 Found TestUpdatedKeyfileContents is still flaky. I don't think #29867 fixed the issue.

--- FAIL: TestUpdatedKeyfileContents (2.11s)
    account_cache_test.go:399: Emptying account file failed
    account_cache_test.go:400: wasn't notified of new accounts
FAIL

Following is the stress test output:

5s: 48 runs so far, 0 failures
10s: 96 runs so far, 0 failures
15s: 155 runs so far, 0 failures
20s: 216 runs so far, 0 failures
25s: 264 runs so far, 0 failures
30s: 323 runs so far, 0 failures
35s: 384 runs so far, 0 failures
40s: 432 runs so far, 0 failures
45s: 488 runs so far, 0 failures
50s: 552 runs so far, 0 failures
55s: 600 runs so far, 0 failures
1m0s: 650 runs so far, 0 failures
1m5s: 718 runs so far, 0 failures
1m10s: 768 runs so far, 0 failures
1m15s: 816 runs so far, 0 failures
1m20s: 885 runs so far, 0 failures
1m25s: 936 runs so far, 0 failures
1m30s: 984 runs so far, 0 failures
1m35s: 1052 runs so far, 0 failures

/tmp/go-stress-20240623T160258-2662963029
--- FAIL: TestUpdatedKeyfileContents (2.11s)
    account_cache_test.go:399: Emptying account file failed
    account_cache_test.go:400: wasn't notified of new accounts
FAIL


ERROR: exit status 1

1m40s: 1103 runs so far, 1 failures (0.09%)
1m45s: 1152 runs so far, 1 failures (0.09%)
1m50s: 1210 runs so far, 1 failures (0.08%)

/tmp/go-stress-20240623T160258-3255354051
--- FAIL: TestUpdatedKeyfileContents (2.21s)
    account_cache_test.go:399: Emptying account file failed
    account_cache_test.go:400: wasn't notified of new accounts
FAIL


ERROR: exit status 1

1m55s: 1269 runs so far, 2 failures (0.16%)

/tmp/go-stress-20240623T160258-645289654
--- FAIL: TestUpdatedKeyfileContents (2.21s)
    account_cache_test.go:399: Emptying account file failed
    account_cache_test.go:400: wasn't notified of new accounts
FAIL


ERROR: exit status 1

Halimao avatar Jun 23 '24 08:06 Halimao

Seems like TestHTTPWriteTimeout is also flaky: https://ci.appveyor.com/project/ethereum/go-ethereum/builds/50081925/job/eg9afjcao7qspxss

lightclient avatar Jun 24 '24 18:06 lightclient

This issue is a bit sprawling. It was a good intent, to collect the info in one place. But now it's just a lot of work to figure out if the particular things listed here is still flaky, or if they have been fixed.

Let's close this, and then open a new one with fresh info

holiman avatar Oct 08 '24 11:10 holiman