ethereum-optimism / op-geth

GNU Lesser General Public License v3.0
255 stars 653 forks source link

Simulator "Stopping work on payload" / reason=timeout #288

Open bas-vk opened 2 months ago

bas-vk commented 2 months ago

System information

op-geth v1.101309.0-rc.2 / v1.101311.0-rc.1 (tried both)

Expected behaviour

In our tests we use the simulator extensively. We recently switched from go-ethereum to op-geth and use ethclient/simulated for our tests. Sometimes the simulator stops producing blocks. Expected behaviour is that the simulator keeps on producing blocks.

Actual behaviour

INFO [04-04|21:52:39.246] Updated payload                          id=0xe46277cf3367acf8 number=3  hash=dcd614..2d9e0b txs=0  withdrawals=0 gas=0         fees=0           root=6aee59..2c44e7 elapsed="177.504µs"
INFO [04-04|21:52:39.246] Imported new potential chain segment     number=3  hash=dcd614..2d9e0b blocks=1 txs=0  mgas=0.000 elapsed="360.978µs" mgasps=0.000   snapdiffs=883.00B triedirty=5.22KiB
INFO [04-04|21:52:39.247] Chain head was updated                   number=3  hash=dcd614..2d9e0b root=6aee59..2c44e7 elapsed="130.876µs"
INFO [04-04|21:52:39.247] Starting work on payload                 id=0xdd8c77b2883e5d28
INFO [04-04|21:52:39.247] Stopping work on payload                 id=0xe46277cf3367acf8 reason=delivery elapsed=1
INFO [04-04|21:52:39.248] Updated payload                          id=0xdd8c77b2883e5d28 number=4  hash=4c7c64..40aeaf txs=0  withdrawals=0 gas=0         fees=0           root=6aee59..2c44e7 elapsed="301.266µs"
INFO [04-04|21:52:39.248] Stopping work on payload                 id=0xdd8c77b2883e5d28 reason=delivery elapsed=0
INFO [04-04|21:52:39.248] Imported new potential chain segment     number=4  hash=4c7c64..40aeaf blocks=1 txs=0  mgas=0.000 elapsed="405.762µs" mgasps=0.000   snapdiffs=883.00B triedirty=5.22KiB
INFO [04-04|21:52:39.249] Chain head was updated                   number=4  hash=4c7c64..40aeaf root=6aee59..2c44e7 elapsed="135.325µs"
INFO [04-04|21:52:39.249] Starting work on payload                 id=0x2fa44f85b982dd71
INFO [04-04|21:52:39.250] Updated payload                          id=0x2fa44f85b982dd71 number=5  hash=999578..16833f txs=0  withdrawals=0 gas=0         fees=0           root=6aee59..2c44e7 elapsed="593.405µs"
INFO [04-04|21:52:39.250] Stopping work on payload                 id=0x2fa44f85b982dd71 reason=delivery elapsed=0
INFO [04-04|21:52:39.251] Imported new potential chain segment     number=5  hash=999578..16833f blocks=1 txs=0  mgas=0.000 elapsed="[379](https://github.com/river-build/river-stage/actions/runs/8561748914/job/23463630134?pr=313#step:21:380).173µs" mgasps=0.000   snapdiffs=883.00B triedirty=5.22KiB
INFO [04-04|21:52:39.251] Chain head was updated                   number=5  hash=999578..16833f root=6aee59..2c44e7 elapsed="172.354µs"
INFO [04-04|21:52:39.252] Starting work on payload                 id=0xa278c1b3f9bf98f0
INFO [04-04|21:52:39.253] Updated payload                          id=0xa278c1b3f9bf98f0 number=6  hash=9a424e..2a8fdd txs=0  withdrawals=0 gas=0         fees=0           root=6aee59..2c44e7 elapsed="132.99µs"
INFO [04-04|21:52:41.253] Stopping work on payload                 id=0xa278c1b3f9bf98f0 reason=timeout  elapsed=2000
panic: test timed out after 20m0s

Steps to reproduce the behaviour

Use the ethclient/simulated.Backend and commit blocks from tests.

Backtrace

goroutine 602 [sync.Cond.Wait, 19 minutes]:
sync.runtime_notifyListWait(0xc000523c50, 0x0)
    /opt/hostedtoolcache/go/1.21.8/x64/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0xc000523c40)
    /opt/hostedtoolcache/go/1.21.8/x64/src/sync/cond.go:70 +0x76
github.com/ethereum/go-ethereum/miner.(*Payload).WaitFull(0xc0008a9580)
    /home/runner/go/pkg/mod/github.com/ethereum-optimism/op-geth@v1.101309.0-rc.2/miner/payload_building.go:188 +0xa8
github.com/ethereum/go-ethereum/eth/catalyst.(*payloadQueue).waitFull(0xc0001d5320, {0xa2, 0x78, 0xc1, 0xb3, 0xf9, 0xbf, 0x98, 0xf0})
    /home/runner/go/pkg/mod/github.com/ethereum-optimism/op-geth@v1.101309.0-rc.2/eth/catalyst/queue.go:106 +0x2d0
github.com/ethereum/go-ethereum/eth/catalyst.(*SimulatedBeacon).sealBlock(0xc0009b6790, {0x429f620, 0x0, 0x0}, 0x660f2127)
    /home/runner/go/pkg/mod/github.com/ethereum-optimism/op-geth@v1.101309.0-rc.2/eth/catalyst/simulated_beacon.go:171 +0x74b
github.com/ethereum/go-ethereum/eth/catalyst.(*SimulatedBeacon).Commit(0xc0009b6790)
    /home/runner/go/pkg/mod/github.com/ethereum-optimism/op-geth@v1.101309.0-rc.2/eth/catalyst/simulated_beacon.go:251 +0x205
github.com/ethereum/go-ethereum/ethclient/simulated.(*Backend).Commit(...)
    /home/runner/go/pkg/mod/github.com/ethereum-optimism/op-geth@v1.101309.0-rc.2/ethclient/simulated/backend.go:183