Reorgs cause "old forked blocks" (below the reorg junction block) to be inserted/processed

sduchesneau commented 1 year ago

System information

Geth version: v1.2.10 with firehose instrumentation on top of it OS & Version: Linux Commit hash : github.com/streamingfast/go-ethereum 7535e671a0303f3c327f065d69da1ca558849420

Expected behaviour

Reorgs from block X to another version of block X should not import blocks X-2, X-1, etc. from a bad reorg. This is causing issues with our instrumentation, but we see this mostly as an odd behavior and are trying to get to the bottom of this.

Actual behaviour

We saw the following logs when block 260 caused a reorg (drop=1, add=1). See the disordered block numbers. I have anotated the logs with X next to the surprising block numbers, and appended GOOD or BAD to see which blocks are now actually canonical.

2023-08-20T22:45:08.811Z INFO (reader.geth) imported new chain segment               blocks=1  txs=46   mgas=3.663   elapsed=69.774ms    mgasps=52.492  number=31,030,257 hash=a06c6b..9a339d dirty=2.34GiB GOOD 257
2023-08-20T22:45:11.826Z INFO (reader.geth) imported new chain segment               blocks=1  txs=51   mgas=8.748   elapsed=86.243ms    mgasps=101.439 number=31,030,258 hash=981daa..7d9acb dirty=2.34GiB GOOD 258
2023-08-20T22:45:14.374Z INFO (reader.geth) imported new chain segment               blocks=1  txs=98   mgas=10.420  elapsed=127.988ms   mgasps=81.416  number=31,030,259 hash=e1c04f..4b317f dirty=2.35GiB GOOD 259
2023-08-20T22:45:18.178Z INFO (reader.geth) imported new chain segment               blocks=1  txs=72   mgas=6.949   elapsed=123.214ms   mgasps=56.398  number=31,030,260 hash=a26af1..3714e1 dirty=2.35GiB BAD 260
2023-08-20T22:45:18.903Z INFO (reader.geth) chain reorg detected                     number=31,030,259 hash=e1c04f..4b317f drop=1 dropfrom=a26af1..3714e1 add=1 addfrom=cced7d..325ef1
2023-08-20T22:45:18.905Z INFO (reader.geth) imported new chain segment               blocks=1  txs=83   mgas=7.659   elapsed=73.915ms    mgasps=103.617 number=31,030,260   hash=cced7d..325ef1 dirty=2.35GiB GOOD 260
2023-08-20T22:45:19.095Z INFO (reader.geth) imported new chain segment               blocks=1  txs=1    mgas=0.109   elapsed=1.516ms     mgasps=71.751  number=31,030,255 X hash=7e5ab0..245029 dirty=2.35GiB BAD 255
2023-08-20T22:45:19.234Z INFO (reader.geth) imported new chain segment               blocks=1  txs=1    mgas=0.109   elapsed=2.929ms     mgasps=37.146  number=31,030,256 X hash=9fd193..b84cec dirty=2.35GiB BAD 256
2023-08-20T22:45:20.310Z INFO (reader.geth) imported new chain segment               blocks=1  txs=1    mgas=0.109   elapsed=2.874ms     mgasps=37.859  number=31,030,257 X hash=b0c8f9..7c545c dirty=2.35GiB BAD 257
2023-08-20T22:45:20.493Z INFO (reader.geth) imported new chain segment               blocks=1  txs=1    mgas=0.109   elapsed=2.445ms     mgasps=44.507  number=31,030,258 X hash=8ac8d9..86e6b0 dirty=2.35GiB BAD 258
2023-08-20T22:45:20.845Z INFO (reader.geth) imported new chain segment               blocks=1  txs=68   mgas=5.853   elapsed=90.377ms    mgasps=64.760  number=31,030,261   hash=5a098f..67ae54 dirty=2.35GiB GOOD 261
2023-08-20T22:45:21.007Z INFO (reader.geth) imported new chain segment               blocks=1  txs=1    mgas=0.109   elapsed=2.154ms     mgasps=50.508  number=31,030,259 X hash=9b9152..f23e47 dirty=2.34GiB BAD 259
2023-08-20T22:45:21.809Z INFO (reader.geth) imported new chain segment               blocks=1  txs=76   mgas=5.886   elapsed=57.469ms    mgasps=102.415 number=31,030,261   hash=314e40..2c9427 dirty=2.34GiB
2023-08-20T22:45:23.147Z INFO (reader.geth) imported new chain segment               blocks=1  txs=56   mgas=3.815   elapsed=68.291ms    mgasps=55.859  number=31,030,262   hash=7d3d10..d98aeb dirty=2.35GiB
2023-08-20T22:45:26.138Z INFO (reader.geth) imported new chain segment               blocks=1  txs=40   mgas=3.057   elapsed=50.446ms    mgasps=60.602  number=31,030,263   hash=04c218..df4f66 dirty=2.35GiB

When block 31,030,260 came out, the LastFinalizedBlock was 31,030,257. Then, processing a wrong version of block 31,030,255 makes no sense to me.

Steps to reproduce the behaviour

We have seen the same pattern appear, but we cannot reproduce it on demand.

brilliant-lx commented 1 year ago

Before FastFinality is enabled, the fork choice is based on the TD(TotalDifficulty). The blocks that you marked BAD are taken as a side chain, see: https://github.com/bnb-chain/bsc/blob/master/eth/fetcher/block_fetcher.go#L380 So this the current code logic, if a remote peer broadcast "BAD" blocks with height >= (currentHeight - 11), these blocks will be imported.

I think, we can add the Finality check here, i.e. if the LastFinalizedBlock is 31,030,257, we can stop import blocks before it.

maoueh commented 1 year ago

Our Firehose tracer traces side chains and this was causing errors later downstream because our invariant is that forked blocks (side blocks) will never be emitted/imported if the fork height <= final block height.

We implemented a similar fix as yours in our geth Firehose tracer to avoid importing forked blocks that are below final height.

Thank you @brilliant-lx!

bnb-chain / bsc