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

Flaky tests

Open holiman opened this issue 1 year ago • 12 comments

Another round of flaky tests

  • [ ] TestUDPv5_lookup log
  • [ ] TestUDPv4_Lookup log
  • [ ] TestEth2PrepareAndGetPayload log
    • api_test.go:225: invalid number of transactions 0 != 1

holiman avatar Oct 13 '24 16:10 holiman

From the v4 log

[00:27:16]     v4_udp.go:525: TRACE[10-12|17:54:22.059] >> PING/v4                                id=fb701727441d6fd5 addr=127.0.255.7:5000 err=<nil>
[00:27:16]     v4_udp.go:576: TRACE[10-12|17:54:22.060] << PONG/v4                                id=fb701727441d6fd5 addr=127.0.255.7:5000 err="unsolicited reply"
[00:27:16]     v4_lookup_test.go:161: error mismatch: got "unsolicited reply", want %!q(<nil>)

That's odd. We send a PING, then when we get the PONG, we deem it unsolicited reply

holiman avatar Oct 14 '24 07:10 holiman

The v4 lookup test can be reproed locally with the following little change, simulating a bit of lag in the loop which handles adding the reply matcher

diff --git a/p2p/discover/v4_udp.go b/p2p/discover/v4_udp.go
index 29ae5f2c08..228175f6c8 100644
--- a/p2p/discover/v4_udp.go
+++ b/p2p/discover/v4_udp.go
@@ -466,6 +466,7 @@ func (t *UDPv4) loop() {
 			return
 
 		case p := <-t.addReplyMatcher:
+			time.Sleep(200 * time.Millisecond)
 			p.deadline = time.Now().Add(respTimeout)
 			plist.PushBack(p)
 

holiman avatar Oct 14 '24 08:10 holiman

I wonder if maybe the respTimeout is too small, at 500ms, but OTOH the logs says 17:54:22.059] >> PING/v4 and 17:54:22.060] << PONG/v4 - that's only 10ms elapsed, so should not be removed in-between.

holiman avatar Oct 14 '24 08:10 holiman

--- FAIL: TestWalletNotifications (0.54s)
    keystore_test.go:427: wallet list doesn't match required accounts: have 429, want 428
    keystore_test.go:455: can't find event with Kind=0 for 253061228b716cd444ccc9f3381792b538310045
FAIL
FAIL	github.com/ethereum/go-ethereum/accounts/keystore	8.741s

https://ci.appveyor.com/project/ethereum/go-ethereum/builds/51423452/job/wfloegv6xd3i9yo4

lightclient avatar Jan 31 '25 01:01 lightclient

--- FAIL: TestSimulatedBeaconSendWithdrawals (12.09s)
    simulated_beacon_test.go:139: timed out without including all withdrawals/txs
FAIL
FAIL	github.com/ethereum/go-ethereum/eth/catalyst	14.916s

https://ci.appveyor.com/project/ethereum/go-ethereum/builds/51457716/job/m50ess4o9qc47fur

lightclient avatar Feb 05 '25 17:02 lightclient

--- FAIL: TestBindings (129.24s)
    bind_test.go:2102: tmpdir /tmp/TestBindings1034863270/001/bindtest
    bind_test.go:2160: failed to run binding test: exit status 1

https://ci.appveyor.com/project/ethereum/go-ethereum/builds/51809451/job/201lshrjwbuq1jr0

lightclient avatar Apr 02 '25 17:04 lightclient

https://ci.appveyor.com/project/ethereum/go-ethereum/builds/51967784/job/j0cwe8348m0we1aa

--- FAIL: TestAttachWelcome (5.47s)
    test_cmd.go:261: (stderr:1) WARN [04-29|14:02:22.341] Unknown config environment variable      envvar=GETH_ARCH
    test_cmd.go:261: (stderr:1) WARN [04-29|14:02:22.437] Unknown config environment variable      envvar=GETH_CC
    test_cmd.go:261: (stderr:1) WARN [04-29|14:02:22.437] Unknown config environment variable      envvar=GETH_MINGW
    test_cmd.go:261: (stderr:1) INFO [04-29|14:02:22.452] Starting Geth on Holesky testnet...
    test_cmd.go:261: (stderr:1) INFO [04-29|14:02:22.455] Maximum peer count                       ETH=0 total=0
    test_cmd.go:261: (stderr:1) WARN [04-29|14:02:22.460] Option --miner.etherbase is deprecated as the etherbase is set by the consensus client post-merge
    test_cmd.go:261: (stderr:1) WARN [04-29|14:02:22.467] Lowering memory allowance on 32bit arch  available=5998 addressable=2048
    test_cmd.go:261: (stderr:1) INFO [04-29|14:02:22.469] Set global gas cap                       cap=50,000,000
    test_cmd.go:261: (stderr:1) INFO [04-29|14:02:22.470] Initializing the KZG library             backend=gokzg
    test_cmd.go:261: (stderr:1) INFO [04-29|14:02:22.470] Allocated trie memory caches             clean=9.00MiB dirty=16.00MiB
    test_cmd.go:261: (stderr:1) INFO [04-29|14:02:22.470] Defaulting to pebble as the backing database
    test_cmd.go:261: (stderr:1) INFO [04-29|14:02:22.470] Allocated cache and file handles         database=C:\Users\appveyor\AppData\Local\Temp\1\TestAttachWelcome162174236\001\geth\chaindata cache=32.00MiB handles=8192
[...]
--- FAIL: TestAttachWelcome/ipc (4.02s)
[...]
--- FAIL: TestConsoleWelcome (30.13s)

cskiraly avatar Apr 29 '25 18:04 cskiraly

https://ci.appveyor.com/project/ethereum/go-ethereum/builds/51846301/job/gv94cs1bi9ceh9rv

--- FAIL: TestBindings (133.02s)
    bind_test.go:2102: tmpdir /tmp/TestBindings2822256013/001/bindtest
    bind_test.go:2160: failed to run binding test: exit status 1
        --- FAIL: TestTuple (0.13s)
        panic: runtime error: invalid memory address or nil pointer dereference [recovered]
        	panic: runtime error: invalid memory address or nil pointer dereference
        [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x1124cbd]
        
        goroutine 2372 [running]:
        testing.tRunner.func1.2({0x1399fa0, 0x24ff9e0})
        	/home/appveyor/.cache/geth-go-1.24.1-linux-amd64/go/src/testing/testing.go:1734 +0x21c
        testing.tRunner.func1()
        	/home/appveyor/.cache/geth-go-1.24.1-linux-amd64/go/src/testing/testing.go:1737 +0x35e
        panic({0x1399fa0?, 0x24ff9e0?})
        	/home/appveyor/.cache/geth-go-1.24.1-linux-amd64/go/src/runtime/panic.go:792 +0x132
        bindtest.TestTuple(0xc000fad180)
        	/tmp/TestBindings2822256013/001/bindtest/tuple_test.go:110 +0x173d
        testing.tRunner(0xc000fad180, 0x16d7bb0)
        	/home/appveyor/.cache/geth-go-1.24.1-linux-amd64/go/src/testing/testing.go:1792 +0xf4
        created by testing.(*T).Run in goroutine 1
        	/home/appveyor/.cache/geth-go-1.24.1-linux-amd64/go/src/testing/testing.go:1851 +0x413
        exit status 2
        FAIL	bindtest	2.956s
FAIL
FAIL	github.com/ethereum/go-ethereum/accounts/abi/abigen	133.080s

cskiraly avatar Apr 29 '25 18:04 cskiraly

https://ci.appveyor.com/project/ethereum/go-ethereum/builds/51966681/job/bohvl7vrbyr2x0iu

        === RUN   TestOverload
            overload_test.go:63: Wait bar0 event timeout
        --- FAIL: TestOverload (10.05s)

cskiraly avatar Apr 29 '25 18:04 cskiraly

https://ci.appveyor.com/project/ethereum/go-ethereum/builds/51966681/job/9itl04p6akj4rwrf

--- FAIL: TestAllowedTxSize (0.01s)
    legacypool_test.go:1255: expected rejection on slightly oversize transaction
FAIL
FAIL	github.com/ethereum/go-ethereum/core/txpool/legacypool	10.425s

cskiraly avatar Apr 29 '25 18:04 cskiraly

https://ci.appveyor.com/project/ethereum/go-ethereum/builds/51986510/job/6ngj0v1ktbyhbc1b

--- FAIL: TestSendTx (0.02s)
    api_backend_test.go:154: Unexpected error, want: in-flight transaction limit reached for delegated accounts, got: gapped-nonce tx from delegated accounts

jwasinger avatar May 05 '25 05:05 jwasinger

https://ci.appveyor.com/project/ethereum/go-ethereum/builds/52136841/job/e5at09gr4e02vvkb

--- FAIL: TestEventFilter (0.00s)
    scheduler_test.go:111: Missing call to module1.Process
    scheduler_test.go:117: Call to module1.Process with wrong events (expected [], got [{0x148a370 0xc0000080c0 <nil>}])
    scheduler_test.go:117: Call to module1.Process with wrong events (expected [{0x148a350 0xc0000080c0 {1 Life, the Universe, and Everything <nil>}}], got [])
    scheduler_test.go:117: Call to module1.Process with wrong events (expected [{0x148a330 0xc0000080c0 {1 Life, the Universe, and Everything <nil>}} {0x148a390 0xc0000080c0 <nil>}], got [{0x148a350 0xc0000080c0 {1 Life, the Universe, and Everything <nil>}}])
    scheduler_test.go:117: Call to module1.Process with wrong events (expected [], got [{0x148a330 0xc0000080c0 {1 Life, the Universe, and Everything <nil>}} {0x148a390 0xc0000080c0 <nil>}])
    scheduler_test.go:123: Unexpected call to module1.Process with events []

jwasinger avatar May 29 '25 04:05 jwasinger

WebSocketLargeRead: https://github.com/ethereum/go-ethereum/actions/runs/17145047311/job/48640027449 DeploymentLibraries: https://github.com/ethereum/go-ethereum/actions/runs/17129689768/job/48590946294

jwasinger avatar Nov 17 '25 08:11 jwasinger