erigon icon indicating copy to clipboard operation
erigon copied to clipboard
verified publisher icon erigontech

[downloader] InsertHeader: Rejected header marked as bad

Open harshsingh-cs opened this issue 1 year ago • 2 comments

I encountered a issue where the node would stop syncing with logs [downloader] InsertHeader: Rejected header marked as bad and restarting the node would fix the problem. Could you please help me identify what could be causing this.

System information

Erigon version: ./erigon --version 2.60.8

OS & Version: Windows/Linux/OSX Linux Commit hash:

Erigon Command (with flags/config):

- erigon
        - --chain=bor-mainnet
        - --datadir=/home/erigon/persistence/data
        - --http.addr=0.0.0.0
        - --rpc.accessList=/home/erigon/acl-config/acl.json
        - --rpc.batch.limit=10000
        - --rpc.txfeecap=100
        - --http.api=eth,erigon,web3,net,debug,txpool,trace
        - --http.vhosts=*
        - --http.corsdomain=null
        - --http
        - --ws
        - --db.pagesize=16384
        - --ethash.dagdir=/home/erigon/persistence/dag
        - --maxpeers=100
        - --identity=
        - --private.api.addr=0.0.0.0:9090
        - --private.api.ratelimit=640000
        - --rpc.returndata.limit=500000
        - --metrics
        - --metrics.addr=0.0.0.0
        - --healthcheck
        - --port=30303
        - --db.size.limit=16TB
        - --torrent.download.rate=512mb
        - --torrent.download.slots=5
        - --bor.milestone=true
        - --staticpeers=
        - --http.timeouts.read=300s
        - --bor.heimdall=http://

Consensus Layer:

Consensus Layer Command (with flags/config):

Chain/Network: Polygon Mainnet

Expected behaviour

Node to sync

Actual behaviour

Node stopped syncing

Steps to reproduce the behaviour

The issue seems to not reproducable

Backtrace

[WARN] [09-18|14:13:56.147] [downloader] InsertHeader: Rejected header marked as bad hash=0x0e9e0e097d76c024559655ab11cb6bfe1d6d32a0d76afad8f3e260f0a12ce041 height=61977312
[WARN] [09-18|14:13:56.148] [downloader] InsertHeader: Rejected header marked as bad hash=0x0e9e0e097d76c024559655ab11cb6bfe1d6d32a0d76afad8f3e260f0a12ce041 height=61977312
[WARN] [09-18|14:13:56.148] [downloader] InsertHeader: Rejected header marked as bad hash=0x0e9e0e097d76c024559655ab11cb6bfe1d6d32a0d76afad8f3e260f0a12ce041 height=61977312

harshsingh-cs avatar Sep 19 '24 15:09 harshsingh-cs

Same issue with Erigon 3

[WARN] [10-28|06:54:48.630] [downloader] InsertHeader: Rejected header marked as bad hash=0x5c00f61db6f3a09554e1950812300a7bcdcd16a0e928ebb26827b725fbce0af5 height=63537984
[DBUG] [10-28|06:54:48.633] [2/9 Headers] Requested header           from=63538152 length=192
[WARN] [10-28|06:54:48.635] [downloader] InsertHeader: Rejected header marked as bad hash=0x5c00f61db6f3a09554e1950812300a7bcdcd16a0e928ebb26827b725fbce0af5 height=63537984
[DBUG] [10-28|06:54:48.642] [2/9 Headers] Requested header           from=63538552 length=192

awskii avatar Oct 28 '24 06:10 awskii

I don't know if adding this issue to the 2.60.9-fixes milestone means that is has been somehow fixed but the issue still prevails in 2.60.9-501a53b7:

Okt 27 03:58:57 polygon erigon[693]: [INFO] [10-27|03:58:57.373] [5/15 Bodies] Downloading block bodies   block_num=63512314 delivery/sec=19.5MB wasted/sec=139.5KB remaining=12564 delivered=100518 blk/sec=3350 cache=5.9MB alloc=6.8GB sys=14.0GB
Okt 27 03:59:10 polygon erigon[693]: [INFO] [10-27|03:59:10.655] [txpool] stat                            pending=0 baseFee=0 queued=30000 alloc=8.2GB sys=14.0GB
Okt 27 03:59:27 polygon erigon[693]: [INFO] [10-27|03:59:27.373] [5/15 Bodies] Downloading block bodies   block_num=63521894 delivery/sec=17.3MB wasted/sec=274.5KB remaining=2984 delivered=110030 blk/sec=3667 cache=5.8MB alloc=9.6GB sys=14.0GB
Okt 27 03:59:35 polygon erigon[693]: [INFO] [10-27|03:59:35.430] [5/15 Bodies] Processed                  highest=63524879 blocks=1246221 in=25118.057 blk/sec=49
Okt 27 03:59:35 polygon erigon[693]: [INFO] [10-27|03:59:35.430] [5/15 Bodies] DONE                       in=6h58m38.057558861s
Okt 27 03:59:35 polygon erigon[693]: [INFO] [10-27|03:59:35.431] [6/15 Senders] Started                   from=62278658 to=63524879
Okt 27 04:00:05 polygon erigon[693]: [INFO] [10-27|04:00:05.431] [6/15 Senders] Recovery                  block_number=63495314 ch=9995/10000
Okt 27 04:00:16 polygon erigon[693]: [INFO] [10-27|04:00:16.272] [7/15 Execution] Blocks execution        from=62278658 to=63524879
Okt 27 04:00:17 polygon erigon[693]: [WARN] [10-27|04:00:17.365] [7/15 Execution] Execution failed        block=62278659 hash=0x7a640f569649fe32308eab60228bb8b2389c290b36d1451d524ebdb92ab8d353 err="invalid block: mismatched receipt headers for block 62278659 (0x775456cdb781cf999be292b7ee49596c207fb53d5b2b581fd867979ddefcb516 != 0x441c612fbccfde41893844101b766b5c142df62a8c0b1d264100b7fa40f75f9b)"
Okt 27 04:00:17 polygon erigon[693]: [INFO] [10-27|04:00:17.366] [7/15 Execution] Completed on            block=62278658
Okt 27 04:00:57 polygon erigon[693]: [INFO] [10-27|04:00:57.266] [p2p] GoodPeers                          eth68=38 eth67=2
Okt 27 04:00:58 polygon erigon[693]: [INFO] [10-27|04:00:58.342] [mem] memory stats                       Rss=114.9MB Size=0B Pss=114.9MB SharedClean=99.7KB SharedDirty=0B PrivateClean=101.1MB PrivateDirty=13.7MB Referenced=114.9MB Anonymous=13.7MB Swap=0B alloc=7.9GB sys=14.3GB
Okt 27 04:01:00 polygon erigon[693]: [INFO] [10-27|04:01:00.387] RPC Daemon notified of new headers       from=61905928 to=61906952 amount=1024 hash=0xe57e9220e0fe244dc9e877b8c70c605fef2cc21ce89dbd6bd637916fc5856b58 header sending=3.335483764s log sending=341ns
Okt 27 04:01:00 polygon erigon[693]: [INFO] [10-27|04:01:00.387] Timings (slower than 50ms)               Snapshots=1.721s Headers=3m0.499s BorHeimdall=4m40.717s BlockHashes=3m3.767s Bodies=6h58m38.057s Senders=40.842s Execution=1.093s Unwind Headers=39.675s
Okt 27 04:01:02 polygon erigon[693]: [INFO] [10-27|04:01:02.043] [2/15 Headers] Waiting for headers...    from=62278658
Okt 27 04:01:02 polygon erigon[693]: [WARN] [10-27|04:01:02.043] [downloader] Rejected header marked as bad hash=0x01340dc940b4ec11112c68643c00ba9363f0d61edffce252226122a3ad50e4fb height=63524878
Okt 27 04:01:02 polygon erigon[693]: [WARN] [10-27|04:01:02.043] [downloader] Rejected header marked as bad hash=0xec7e7379992ed7fc403ba086e21aaa6c124aca817fbc17fa75bb341c76b6117c height=63524879
Okt 27 04:01:02 polygon erigon[693]: [WARN] [10-27|04:01:02.046] [downloader] Rejected header marked as bad hash=0xb0fd9a9eec9f25a3f5968a6eb0daf93dd6214d3b778f22af979c48d52524bed1 height=63524880
Okt 27 04:01:07 polygon erigon[693]: [INFO] [10-27|04:01:07.202] [snapshots:bor:retire] Blocks Stat       blocks=47500k indices=47500k alloc=10.3GB sys=14.3GB
Okt 27 04:01:32 polygon erigon[693]: [INFO] [10-27|04:01:32.043] [2/15 Headers] No block headers to write in this log period number=62278658 blk/second=0.000 alloc=9.9GB sys=14.3GB invalidHeaders=0 rejectedBadHeaders=3
Okt 27 04:01:56 polygon erigon[693]: [WARN] [10-27|04:01:56.568] [downloader] Rejected header marked as bad hash=0xb0fd9a9eec9f25a3f5968a6eb0daf93dd6214d3b778f22af979c48d52524bed1 height=63524880
Okt 27 04:01:56 polygon erigon[693]: [WARN] [10-27|04:01:56.571] [downloader] Rejected header marked as bad hash=0xb0fd9a9eec9f25a3f5968a6eb0daf93dd6214d3b778f22af979c48d52524bed1 height=63524880
Okt 27 04:01:56 polygon erigon[693]: [WARN] [10-27|04:01:56.572] [downloader] Rejected header marked as bad hash=0xb0fd9a9eec9f25a3f5968a6eb0daf93dd6214d3b778f22af979c48d52524bed1 height=63524880
Okt 27 04:01:56 polygon erigon[693]: [WARN] [10-27|04:01:56.575] [downloader] Rejected header marked as bad hash=0xb0fd9a9eec9f25a3f5968a6eb0daf93dd6214d3b778f22af979c48d52524bed1 height=63524880
Okt 27 04:01:56 polygon erigon[693]: [WARN] [10-27|04:01:56.795] [downloader] Rejected header marked as bad hash=0xb0fd9a9eec9f25a3f5968a6eb0daf93dd6214d3b778f22af979c48d52524bed1 height=63524880

GhostTyper avatar Oct 29 '24 02:10 GhostTyper

Hi, this issue is usually caused due to Heimdall falling out of sync. To fix the issue you can use the integration tool to unwind beyond the bad block and restart Erigon, which should start syncing normally.

integration --chain bor-mainnet --datadir <your datadir> --unwind <distance>

shohamc1 avatar Jan 08 '25 03:01 shohamc1

happens with erigon v3 (3.0.0-alpha5) a lot (during past few weeks). Restarts usually fixes that, with no unwind required.

tmeinlschmidt avatar Jan 12 '25 20:01 tmeinlschmidt

@tmeinlschmidt can you check your Heimdall logs to see if it was healthy during this period? Any restarts or loss of all p2p peers?

shohamc1 avatar Jan 13 '25 00:01 shohamc1

Hello, I just wanted to create an own issue, but I found this one. In our case the reboot does not work. We have to manually unwind, when the error occurs. Our main problem is, that Erigon spams the InsertHeader: Rejected header marked as bad log messages every few milliseconds without doing anything else. Even if we restart Erigon it just proceeds with spamming the logs after it is started. Some time ago, there was also an OOM when this happend, which was fixed, as can be seen here https://github.com/erigontech/erigon/issues/11387. In our current case the problem occured after a quite synchron reboot of Heimdall and Erigon, due to a maintenance window. Then Heimdall took about 40 minutes to find peers. In this time Erigon started writing these logs in milliseconds. Even after Heimdall found peers and started working normally Erigon continued writing this message in milliseconds and no restart helped. As mentioned before only the manual unwind lets Erigon work again without this behavior in our case. We still run Erigon in version v2.61.0.

MrFreezeDZ avatar Mar 11 '25 08:03 MrFreezeDZ

Closing this issue, this issue does not happen in the new sync algorithm (--polygon.sync, enabled by default)

shohamc1 avatar Apr 07 '25 06:04 shohamc1