search

erigontech / erigon

Ethereum implementation on the efficiency frontier https://erigon.gitbook.io
GNU Lesser General Public License v3.0
3.12k stars 1.11k forks source link

BSC - No block headers to write in this log period block number #5703

Closed breezytm closed 1 year ago

breezytm commented 1 year ago

System information

Erigon version: erigon version 2.27.0-stable-6d8b304e

OS & Version: Linux

Commit hash : 6d8b304

Expected behaviour

Syncing to the latest block

Actual behaviour

Error: No block headers to write in this log period

bsc-node-000            | [INFO] [10-11|15:02:13.458] [p2p] GoodPeers                          eth66=86
bsc-node-000            | [INFO] [10-11|15:02:13.470] [txpool] stat                            block=0 pending=1 baseFee=0 queued=16 alloc=3.8GB sys=65.4GB
bsc-node-000            | [INFO] [10-11|15:02:31.125] [2/16 Headers] No block headers to write in this log period block number=20304127 blk/second=0.000
bsc-node-000            | [INFO] [10-11|15:02:51.125] [2/16 Headers] No block headers to write in this log period block number=20304127 blk/second=0.000
bsc-node-000            | [INFO] [10-11|15:03:11.126] [2/16 Headers] No block headers to write in this log period block number=20304127 blk/second=0.000
bsc-node-000            | [INFO] [10-11|15:03:13.468] [txpool] stat                            block=0 pending=1 baseFee=0 queued=16 alloc=3.3GB sys=65.4GB
bsc-node-000            | [INFO] [10-11|15:03:31.125] [2/16 Headers] No block headers to write in this log period block number=20304127 blk/second=0.000
bsc-node-000            | [INFO] [10-11|15:03:51.126] [2/16 Headers] No block headers to write in this log period block number=20304127 blk/second=0.000

Steps to reproduce the behaviour

    command:
      - erigon
      - --datadir=/root/.local/share/erigon
      - --chain=bsc
      - --port=29505
      - --private.api.addr=0.0.0.0:9090
      - --http=false
      - --db.pagesize=16kb
      - --prune=hrtc
      - --torrent.port=29506
      - --torrent.download.rate=1000mb
      - --torrent.download.slots=6
      - --downloader.verify
      - --batchSize=512M
      - --etl.bufferSize=512M
      - --healthcheck
      - --verbosity=3
nikolinsko commented 1 year ago

additional log:

[WARN] [10-12|11:18:19.176] [7/16 Execution] Execution failed        block=22107425 hash=0x71044292c200a2138a4b1cfe258bbeb3998e1a6cc1a06f0a380522c4527702c2 err="expected system tx (hash 0xf1753cfe253f554860cac1c86ef60fcb5bf094116afd0ddeff8548e54b30d29f, nonce 831138, to 0x0000000000000000000000000000000000001000, value 0x161441e802c87a4, gas 9223372036854775807, gasPrice 0x0, data f340fa010000000000000000000000009f8ccdafcc39f3c7d6ebf637c9151673cbc36b88), actual tx (hash 0xe053c8c705c470a3032854fa2d36b41ca638d7972d48f9c9ec344bbc8a05bca8, nonce 831138, to 0x0000000000000000000000000000000000001000, value 0x16144381caf53a4, gas 9223372036854775807, gasPrice 0x0, data f340fa010000000000000000000000009f8ccdafcc39f3c7d6ebf637c9151673cbc36b88)"
[INFO] [10-12|11:18:19.177] UnwindTo                                 block=22107424 bad_block_hash=0x71044292c200a2138a4b1cfe258bbeb3998e1a6cc1a06f0a380522c4527702c2

Erigon version: v2.28.0

mikolajsobolewski commented 1 year ago

@AdminAnticaptcha please upgrade to v2.28.0 this is the BSC hardfork Moran

nikolinsko commented 1 year ago

@AdminAnticaptcha did you do something in particular?

@mikolajsobolewski

i'm at the following commit / tag:

git_branch=heads/v2.28.0 git_tag=v2.28.0 git_commit=355837aee5ea2374bf420eff6e93360deb83d3f7

after:

[WARN] [10-12|12:17:08.820] [7/16 Execution] Execution failed        block=22107425 hash=0x71044292c200a2138a4b1cfe258bbeb3998e1a6cc1a06f0a380522c4527702c2 err="expected system tx (hash 0xf1753cfe253f554860cac1c86ef60fcb5bf094116afd0ddeff8548e54b30d29f, nonce 831138, to 0x0000000000000000000000000000000000001000, value 0x161441e802c87a4, gas 9223372036854775807, gasPrice 0x0, data f340fa010000000000000000000000009f8ccdafcc39f3c7d6ebf637c9151673cbc36b88), actual tx (hash 0xe053c8c705c470a3032854fa2d36b41ca638d7972d48f9c9ec344bbc8a05bca8, nonce 831138, to 0x0000000000000000000000000000000000001000, value 0x16144381caf53a4, gas 9223372036854775807, gasPrice 0x0, data f340fa010000000000000000000000009f8ccdafcc39f3c7d6ebf637c9151673cbc36b88)"
[INFO] [10-12|12:17:08.820] UnwindTo                                 block=22107424 bad_block_hash=0x71044292c200a2138a4b1cfe258bbeb3998e1a6cc1a06f0a380522c4527702c2
[INFO] [10-12|12:17:08.820] [7/16 Execution] Completed on            block=22107424
[INFO] [10-12|12:17:12.526] [2/16 Headers] Waiting for headers...    from=22107424

the following is looped

[INFO] [10-12|12:23:12.527] [2/16 Headers] No block headers to write in this log period block number=22107424 blk/second=0.000
[INFO] [10-12|12:23:12.527] Req/resp stats                           req=5 reqMin=22107528 reqMax=22108296 skel=15 skelMin=22108960 skelMax=22403680 resp=100 respMin=22107721 respMax=22109074 dups=30
[INFO] [10-12|12:23:12.527] [Downloader] Queue sizes                 anchors=1 links=1354 persisted=64055
[INFO] [10-12|12:23:12.527] {22107721-22109074 links=1354 (22107721-22109074)} => 14663dfdaf1c69c514afeecc726a10af8e9be6766bfa1b1f9248285873388ec9, anchorQueue.idx=0, next retry in 1.691698652s

integration shows:

Snapshots                        22107422        0
Headers                          22107424        0
BlockHashes                      22107424        0
Bodies                           22107424        0
Senders                          22107424        0
Execution                        22107424        22107422
Translation                      0               0
HashState                        22107422        0
IntermediateHashes               22107422        22107422
AccountHistoryIndex              22107422        22107422
StorageHistoryIndex              22107422        22107422
LogIndex                         22107422        22107422
CallTraces                       22107422        22107422
TxLookup                         22107422        22102422
Finish                           22107422        0

prune distance: --prune.h.older=5000 --prune.r.older=5000 --prune.t.older=5000 --prune.c.older=5000

sequence: EthTx=3541637689, NonCanonicalTx=230018

first header in db: 1
first body in db: 1

snapsthos: blocks=0, segments=0, indices=0
affixpin commented 1 year ago

The same issue, 2.28.0 update doesn't help

tinoh9 commented 1 year ago

@AdminAnticaptcha did you modify anything with your synced node?

chetanbothra commented 1 year ago

Stuck at same issue, was earlier working with 2.27.0 and before 5hrs got this issue. Upgraded erigon to 2.28.0 and still stuck at same place 

erigon-erigon-1  | [INFO] [10-12|14:41:38.054] [2/16 Headers] No block headers to write in this log period block number=22107424 blk/second=0.000
erigon-erigon-1  | [INFO] [10-12|14:41:38.054] Req/resp stats                           req=31 reqMin=22107423 reqMax=22112585 skel=14 skelMin=22108960 skelMax=22403680 resp=77 respMin=22108000 respMax=22114132 dups=85
erigon-erigon-1  | [INFO] [10-12|14:41:38.054] [Downloader] Queue sizes                 anchors=1 links=6134 persisted=59168
erigon-erigon-1  | [INFO] [10-12|14:41:38.054] {22108000-22114132 links=6134 (22108000-22114130-22114132)} => 3cc9c62721e50b37936edbcc888fc5171c056fc449eaa02666adff10d5cc1d81, anchorQueue.idx=0, next retry in 38.281912ms
chetanbothra commented 1 year ago

I just ran ./build/bin/integration stage_exec --datadir <your_datadir> --chain bsc --unwind 10 and start erigon and seems to be working as expected

@poloplayingsolo @nikolinsko @AdminAnticaptcha @breezytm can u try this once and see if this is working for u.

breezytm commented 1 year ago

I just ran ./build/bin/integration stage_exec --datadir <your_datadir> --chain bsc --unwind 10 and start erigon and seems to be working as expected

@poloplayingsolo @nikolinsko @AdminAnticaptcha @breezytm can u try this once and see if this is working for u.

In my case I am not sure if there is any data to unwind because this is a new deployment. It never synced. It does that right after finish the snapshot download.

nikolinsko commented 1 year ago

I just ran ./build/bin/integration stage_exec --datadir <your_datadir> --chain bsc --unwind 10 and start erigon and seems to be working as expected

@poloplayingsolo @nikolinsko @AdminAnticaptcha @breezytm can u try this once and see if this is working for u.

yup, seems like that fixes the issue.

Thanks for the tip.

chetanbothra commented 1 year ago

@breezytm still give a try. As i was stuck at same issue. U dnt need full sync to get complete to unwind.

a26nine commented 1 year ago

Did anyone find a workaround for this? Unwinding doesn't help.

I synced multiple nodes from scratch and now it's stuck at No block headers to write in this log period block number=xxxxx. On every restart, it adds a few blocks and then gets stuck again.

a26nine commented 1 year ago

Adding the --snap.stop flag and restarting erigon fixed this for me — multiple nodes.

tinoh9 commented 1 year ago

@a26nine I have tried your flag but it's still stucked, did you input any additional flag?

AlexeyAkhunov commented 1 year ago

Perhaps boot nodes need to be updated for BSC, can someone check

a26nine commented 1 year ago

@a26nine I have tried your flag but it's still stucked, did you input any additional flag?

I did add --downloader.verify earlier for another issue — don't know whether that would help.

breezytm commented 1 year ago

@breezytm still give a try. As i was stuck at same issue. U dnt need full sync to get complete to unwind.

This is what I am getting 

bsc-node-000            | [INFO] [10-13|13:08:38.253] [Downloader] Queue sizes                 anchors=1 links=801 persisted=65536
bsc-node-000            | [INFO] [10-13|13:08:38.253] {22139860-22140660 links=801 (22139860-22140660)} => 50669e6f4e517c35cedba5a40781c83c5286da9bc21cfc08b9ebc62d5d8824ce, anchorQueue.idx=0, next retry in 3.591337491s 
bsc-node-000            | [INFO] [10-13|13:08:58.252] [2/16 Headers] No block headers to write in this log period block number=21499999 blk/second=0.000
bsc-node-000            | [INFO] [10-13|13:08:58.252] Req/resp stats                           req=5 reqMin=22139283 reqMax=22139859 skel=13 skelMin=21501535 skelMax=21796255 resp=32 respMin=22140666 respMax=22140667 dups=7
bsc-node-000            | [INFO] [10-13|13:08:58.252] [Downloader] Queue sizes                 anchors=1 links=1192 persisted=65536
bsc-node-000            | [INFO] [10-13|13:08:58.252] {22139476-22140667 links=1192 (22139476-22140667)} => b9813bf7c311b2bff7a5945d221381ed36d2bb308d33a71d90eda071242068a5, anchorQueue.idx=0, next retry in 1.305319751s 
bsc-node-000            | [INFO] [10-13|13:09:18.252] [2/16 Headers] No block headers to write in this log period block number=21499999 blk/second=0.000
bsc-node-000            | [INFO] [10-13|13:09:18.252] Req/resp stats                           req=4 reqMin=22139283 reqMax=22139475 skel=17 skelMin=21501535 skelMax=21796255 resp=43 respMin=22140638 respMax=22140674 dups=14
bsc-node-000            | [INFO] [10-13|13:09:18.252] [Downloader] Queue sizes                 anchors=1 links=1199 persisted=65536
bsc-node-000            | [INFO] [10-13|13:09:18.253] {22139476-22140674 links=1199 (22139476-22140674)} => b9813bf7c311b2bff7a5945d221381ed36d2bb308d33a71d90eda071242068a5, anchorQueue.idx=0, next retry in 3.133441457s 
bsc-node-000            | [INFO] [10-13|13:09:28.888] [txpool] stat                            block=21499999 pending=0 baseFee=0 queued=91 alloc=2.6GB sys=5.1GB
bsc-node-000            | [INFO] [10-13|13:09:38.252] [2/16 Headers] No block headers to write in this log period block number=21499999 blk/second=0.000
bsc-node-000            | [INFO] [10-13|13:09:38.252] Req/resp stats                           req=6 reqMin=22138707 reqMax=22139475 skel=15 skelMin=21501535 skelMax=21796255 resp=46 respMin=22140671 respMax=22140681 dups=15
bsc-node-000            | [INFO] [10-13|13:09:38.252] [Downloader] Queue sizes                 anchors=1 links=1782 persisted=65536
bsc-node-000            | [INFO] [10-13|13:09:38.252] {22138900-22140681 links=1782 (22138900-22140681)} => 56042078e493a16e1caa5f922eea21a9777832bdfa601c512a9a5c03a289ed70, anchorQueue.idx=0, next retry in -3.992642ms
yixun-alpha commented 1 year ago

Just to chime in that I have the exact same issues as above on v2.28.0, have tried all workarounds in the thread (downloader.verify, snap.stop, unwind etc) without success

PolarSyncZ commented 1 year ago

I had this same issue with a new node I was spinning up from snapshots. I tried all sorts of things and was finally able to resolve it by deleting all of the snapshot files and restarting erigon then letting them re-download and index etc. It took about 24 hours but it solved the issue and my node is now functioning normally.

allada commented 1 year ago

As @PolarSyncZ said, I'd been working with them to help get their node online. I'll be updating the s3 snapshot folder in https://github.com/allada/bsc-archive-snapshot. I'll post back here with the s3 command you'all can use to download just the snapshots tomorrow-ish or you can delete the snapshots folder and torrent the files yourself.

allada commented 1 year ago

For those that want to test if your snapshot folder will fix the issue, here's what should fix the issue:

  1. make integration
  2. ./build/bin/integration stage_exec --datadir <your_datadir> --chain bsc --unwind 1000 # You might be able to get away with less blocks
  3. rm -rf <your_datadir>/snapshots/*
  4. cd <your_datadir>/snapshots && aws s3 --request-payer=requester sync s3://public-blockchain-snapshots/bsc/erigon-snapshots-folder-latest/ ./

Note: You will need an AWS account configured on the computer it is running on, as your aws account will be billed for the download costs, which is about $50USD in data xfer costs unless you are running the instance in AWS's us-west-2 data center, which it'll be about $0.10USD.

f0rmatting commented 1 year ago

For those that want to test if your snapshot folder will fix the issue, here's what should fix the issue:

  1. make integration
  2. ./build/bin/integration stage_exec --datadir <your_datadir> --chain bsc --unwind 1000 # You might be able to get away with less blocks
  3. rm -rf <your_datadir>/snapshots/*
  4. cd <your_datadir>/snapshots && aws s3 --request-payer=requester sync s3://public-blockchain-snapshots/bsc/erigon-snapshots-folder-latest/ ./

Note: You will need an AWS account configured on the computer it is running on, as your aws account will be billed for the download costs, which is about $50USD in data xfer costs unless you are running the instance in AWS's us-west-2 data center, which it'll be about $0.10USD.

Hi @allada, thanks for you snapshots file, but maybe s3 sync need "ListObjectsV2" permission When I use "aws s3 --request-payer=requester sync" return:

An error occurred (AccessDenied) when calling the ListObjectsV2 operation: Access Denied
allada commented 1 year ago

Hi @allada, thanks for you snapshots file, but maybe s3 sync need "ListObjectsV2" permission

You need to make sure the account you are using has the ability to charge your account for S3 requests. These permissions are set in your account, and IIRC you can just allow s3:ListBucket and other related permissions to resource: arn:aws:s3:::public-blockchain-snapshots and I think it'll work.

f0rmatting commented 1 year ago

Hi @allada, thanks for you snapshots file, but maybe s3 sync need "ListObjectsV2" permission

You need to make sure the account you are using has the ability to charge your account for S3 requests. These permissions are set in your account, and IIRC you can just allow s3:ListBucket and other related permissions to resource: arn:aws:s3:::public-blockchain-snapshots and I think it'll work.

@allada Thanks, it's my problem. It's syncing now.

nikolinsko commented 1 year ago

fyi: there is also https://github.com/BNB48Club/bsc-snapshots. Seems to be from a validator, so as close as trustworthy as you can get on bsc :D

1scrooge commented 1 year ago

I have the same issue Erigon version is 2.28.1 Last log:

erigon_1  | [INFO] [10-18|07:24:55.556] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.2GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:25:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:25:24.635] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:25:44.635] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:25:55.557] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.5GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:26:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:26:24.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:26:44.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:26:55.535] [p2p] GoodPeers                          eth66=20
erigon_1  | [INFO] [10-18|07:26:55.557] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.2GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:27:04.635] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:27:24.635] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:27:44.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:27:55.556] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.3GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:28:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:28:24.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:28:44.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:28:55.535] [p2p] GoodPeers                          eth66=20
erigon_1  | [INFO] [10-18|07:28:55.555] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.2GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:29:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:29:24.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:29:44.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:29:55.556] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.3GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:30:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:30:24.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:30:44.635] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:30:55.535] [p2p] GoodPeers                          eth66=20
erigon_1  | [INFO] [10-18|07:30:55.555] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.2GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:31:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000

Restart doesn't help

allada commented 1 year ago

@1scrooge, read above for fix. There is unlikely to be any "fix" by erigon since users can fix it themselves.

amurde commented 1 year ago

Same version , same problem for me. Tried to unwind stages and re-download snapshots. Stuck at the same message but different block.

nftgeek commented 1 year ago

I have the same issue Erigon version is 2.28.1 Last log:

erigon_1  | [INFO] [10-18|07:24:55.556] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.2GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:25:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:25:24.635] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:25:44.635] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:25:55.557] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.5GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:26:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:26:24.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:26:44.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:26:55.535] [p2p] GoodPeers                          eth66=20
erigon_1  | [INFO] [10-18|07:26:55.557] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.2GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:27:04.635] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:27:24.635] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:27:44.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:27:55.556] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.3GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:28:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:28:24.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:28:44.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:28:55.535] [p2p] GoodPeers                          eth66=20
erigon_1  | [INFO] [10-18|07:28:55.555] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.2GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:29:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:29:24.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:29:44.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:29:55.556] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.3GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:30:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:30:24.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:30:44.635] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000
erigon_1  | [INFO] [10-18|07:30:55.535] [p2p] GoodPeers                          eth66=20
erigon_1  | [INFO] [10-18|07:30:55.555] [txpool] stat                            block=19999999 pending=1 baseFee=0 queued=146 alloc=4.2GB sys=7.0GB
erigon_1  | [INFO] [10-18|07:31:04.634] [2/16 Headers] No block headers to write in this log period block number=20348671 blk/second=0.000

Restart doesn't help

Hi @1scrooge @amurde Double check your firewall config. I fixed this issue by allowing tcp/udp ports of downloader and sentry containers.

amurde commented 1 year ago

@nftgeek Can you please clarify? Re-checked again: ports 30303 and 42069 tcp/udp is currently opened.

As i see from documentation, sentry private port is 9091 and it should not be exposed. "...sentry process will run one eth/xx protocol (e.g. eth/66) and will be exposed to the internet on 30303...".

What you mean as downloader port?

Thanks in advance!

1scrooge commented 1 year ago

@nftgeek Firewall is OK. The bsc testnet node is fully synchronized with the same VM configuration

topu commented 1 year ago

Try adding --nat=any. It unblocked syncing on my nodes.

MysticRyuujin commented 1 year ago

This issue is affecting fresh sync nodes as well. Unwinding stage_exec does not work because it never gets past stage 2 (headers). I did try to unwind stage_headers by 10 - that resulted in Stage 1 (Snapshots) doing "Total difficulty index" - but then just got stuck in the same place at stage 2

allada commented 1 year ago

I am also noticing that the BNB chain (does not happen on ethereum chain) seems to always download the last few snapshot headers on restart, even though it was running fine just before restart.

I even tried purging the snapshots folder multiple times.

Not sure if it's related, but it happened around the same time as this issue.

allada commented 1 year ago

After doing some investigating, I'm starting to think the root cause is to do with the parlia database. If you have an old snapshot, you can try using it on a later version to see if it helps. You can also try deleting the database and restart, but it'll take many hours to rebuild and require s huge amount of ram.

naviocean commented 1 year ago

I got the same issue. I've tried to unwind but not success. Do you have any suggestions to solve this issue? 

erigon_1      | [INFO] [11-07|01:34:06.666] [Downloader] Queue sizes                 anchors=1 links=10844 persisted=65536
erigon_1      | [INFO] [11-07|01:34:06.666] {22826431-22837274 links=10844 (22826431-22837274)} => d94fc21cbb1694489fb0283949d86a4e6442b2245657e5618204315401778bb7, anchorQueue.idx=0, next retry in 4.750816381s 
erigon_1      | [INFO] [11-07|01:34:26.666] [2/16 Headers] No block headers to write in this log period block number=21499999
erigon_1      | [INFO] [11-07|01:34:26.666] Req/resp stats                           req=3 reqMin=22826238 reqMax=22826430 skel=15 skelMin=21501535 skelMax=21796255 resp=56 respMin=11092983 respMax=22837281 dups=30
erigon_1      | [INFO] [11-07|01:34:26.666] [Downloader] Queue sizes                 anchors=1 links=10851 persisted=65536
erigon_1      | [INFO] [11-07|01:34:26.666] {22826431-22837281 links=10851 (22826431-22837281)} => d94fc21cbb1694489fb0283949d86a4e6442b2245657e5618204315401778bb7, anchorQueue.idx=0, next retry in -1.512819ms 
erigon_1      | [INFO] [11-07|01:34:46.665] [2/16 Headers] No block headers to write in this log period block number=21499999
erigon_1      | [INFO] [11-07|01:34:46.665] Req/resp stats                           req=8 reqMin=22825470 reqMax=22826430 skel=16 skelMin=21501535 skelMax=21796255 resp=55 respMin=22825663 respMax=22837288 dups=25
erigon_1      | [INFO] [11-07|01:34:46.666] [Downloader] Queue sizes                 anchors=1 links=11626 persisted=65536
erigon_1      | [INFO] [11-07|01:34:46.666] {22825663-22837288 links=11626 (22825663-22837288)} => 9023a3f28a7014781b3f1238fc86d9c157b1813eb079c720d85ff2cf9356adea, anchorQueue.idx=0, next retry in 4.665706065s 
erigon_1      | [INFO] [11-07|01:35:06.666] [2/16 Headers] No block headers to write in this log period block number=21499999
erigon_1      | [INFO] [11-07|01:35:06.666] Req/resp stats                           req=10 reqMin=22824126 reqMax=22825470 skel=15 skelMin=21501535 skelMax=21796255 resp=53 respMin=22824319 respMax=22837294 dups=23
naviocean commented 1 year ago

I've tried to remove snapshots rm -rf /erigon/snapshots/* and then run again. Now it's passed :)

Andrew-Pohl commented 1 year ago

For those that want to test if your snapshot folder will fix the issue, here's what should fix the issue:

  1. make integration
  2. ./build/bin/integration stage_exec --datadir <your_datadir> --chain bsc --unwind 1000 # You might be able to get away with less blocks
  3. rm -rf <your_datadir>/snapshots/*
  4. cd <your_datadir>/snapshots && aws s3 --request-payer=requester sync s3://public-blockchain-snapshots/bsc/erigon-snapshots-folder-latest/ ./

    Note: You will need an AWS account configured on the computer it is running on, as your aws account will be billed for the download costs, which is about $50USD in data xfer costs unless you are running the instance in AWS's us-west-2 data center, which it'll be about $0.10USD.

This didn't seem to fix it for me still stuck at:

[2/16 Headers] No block headers to write in this log period block number=21499999

even after pulling your snapshot folder. Running on v2.29.0

allada commented 1 year ago

So I decided to start debugging this to see what is happening. It appears (but not 100% confirmed) that if the block headers make it into the snapshots and there are no recent headers in the mdbx database, erigon will never attach the recently downloaded blocks to previous blocks.

It looks erigon expects sentry to notify of new headers, but these new headers are staged, but never confirmed because it can't find the previous blocks to attach it to.

I believe this is why some users were able to delete the snapshots folder and have it work and some users could not. Snapshots don't appear to be considered persistent (or maybe they are not loaded/found).

I may dig into this deeper, but I am not very familiar with this area of the code.

nhojjohn commented 1 year ago

fwiw I just upgraded to v2.30.0 (from v2.29.1) and the bsc nodes previously stuck like this have sprung into life and have recommenced syncing.

lbadger commented 1 year ago

Having the same issue. I compiled v2.30.0 and it's still stuck. I had just downloaded the snapshot a couple of days ago, but I guess I'll try it again. 

Nov 29 04:37:32 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:37:32.838] [2/16 Headers] No block headers to write in this log period block number=22973999
Nov 29 04:37:32 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:37:32.838] Req/resp stats                           req=16 reqMin=23464264 reqMax=23464473 skel>
Nov 29 04:37:52 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:37:52.838] [2/16 Headers] No block headers to write in this log period block number=22973999
Nov 29 04:37:52 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:37:52.838] Req/resp stats                           req=11 reqMin=23464275 reqMax=23464473 skel>
Nov 29 04:38:12 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:38:12.838] [2/16 Headers] No block headers to write in this log period block number=22973999
Nov 29 04:38:12 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:38:12.838] Req/resp stats                           req=15 reqMin=23464275 reqMax=23464487 skel>
Nov 29 04:38:32 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:38:32.838] [2/16 Headers] No block headers to write in this log period block number=22973999
Nov 29 04:38:32 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:38:32.838] Req/resp stats                           req=851 reqMin=22973998 reqMax=23464491 ske>
Nov 29 04:38:52 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:38:52.839] [2/16 Headers] No block headers to write in this log period block number=22973999
Nov 29 04:38:52 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:38:52.839] Req/resp stats                           req=782 reqMin=22974574 reqMax=23463531 ske>
Nov 29 04:39:12 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:39:12.838] [2/16 Headers] No block headers to write in this log period block number=22973999
Nov 29 04:39:12 bsc-archive-one start_erigon_service.sh[1837]: [INFO] [11-29|04:39:12.838] Req/resp stats                           req=470 reqMin=2297
AskAlexSharov commented 1 year ago

@lbadger increase logs verbosity

egorFiNE commented 1 year ago

After BSC I'm now having this problem on Polygon as well. 

No block headers to write in this log period block number=30701206

This is a full node being synced from the beginning.

erigon version 2.30.0-stable-35f493c5

egorFiNE commented 1 year ago

--unwind did not help. Erigon starts with the same "broken" block immediately after unwind. 

$ integration stage_exec --datadir=/polygon/erigon --chain=bor-mainnet --unwind 1000
WARN[12-02|10:08:36.823] no log dir set, console logging only
INFO[12-02|10:08:39.114] [Snapshots] Blocks Stat                  blocks=29000k indices=29000k alloc=2.0GB sys=2.2GB
INFO[12-02|10:08:50.249] Stage                                    name=Execution progress=30698206
INFO[12-02|10:08:50.250] [7/16 Execution] Unwind Execution        from=30698206 to=30697206

Then: 

$ erigon --datadir=/polygon/erigon --chain=bor-mainnet  --port=40002 --torrent.port=42070 --private.api.addr=127.0.0.1:9002 --http=false --maxpeers 6000 --v5disc --prune htcr --prune.h.older 90000 --prune.r.older 90000 --prune.t.older 90000 --prune.c.older 90000 --nat extip:65.21.196.179 --db.pagesize=16k --bor.heimdall=http://localhost:1317 --torrent.maxpeers=2000 --torrent.upload.rate=32mb --torrent.download.rate=128mb
WARN[12-02|10:09:43.124] no log dir set, console logging only
WARN[12-02|10:09:43.124] no log dir set, console logging only
INFO[12-02|10:09:43.124] Build info                               git_branch=stable git_tag=v2.30.0 git_commit=35f493c5d021965f994bee615d441b2b35811f8f
INFO[12-02|10:09:43.124] Starting Erigon on Bor Mainnet...
INFO[12-02|10:09:43.124] Maximum peer count                       ETH=6000 total=6000
INFO[12-02|10:09:43.124] starting HTTP APIs                       APIs=eth,erigon,engine
INFO[12-02|10:09:43.124] torrent verbosity                        level=WRN
INFO[12-02|10:09:43.124] [torrent] Public IP                      ip=65.21.196.179
INFO[12-02|10:09:43.124] Set global gas cap                       cap=50000000
INFO[12-02|10:09:43.125] Opening Database                         label=chaindata path=/polygon/erigon/chaindata
INFO[12-02|10:09:43.127] Initialised chain configuration          config="{ChainID: 137, Homestead: 0, DAO: <nil>, DAO Support: true, Tangerine Whistle: 0, Spurious Dragon: 0, Byzantium: 0, Constantinople: 0, Petersburg: 0, Istanbul: 3395000, Muir Glacier: 3395000, Berlin: 14750000, London: 23850000, Arrow Glacier: <nil>, Gray Glacier: <nil>, Terminal Total Difficulty: <nil>, Merge Netsplit: <nil>, Shanghai: <nil>, Cancun: <nil>, Engine: bor}" genesis=0xa9c28ce2141b56c474f1dc504bee9b01eb1bd7d1a507580d5519d4437a97de1b
INFO[12-02|10:09:43.127] Effective                                prune_flags="--prune.h.older=90000 --prune.r.older=90000 --prune.t.older=90000 --prune.c.older=90000" snapshot_flags="--snapshots=true --snap.stop=true" history.v3=false
INFO[12-02|10:09:46.555] Initialising Ethereum protocol           network=137
INFO[12-02|10:09:58.233] Starting private RPC server              on=127.0.0.1:9002
INFO[12-02|10:09:58.233] new subscription to logs established
INFO[12-02|10:09:58.233] rpc filters: subscribing to Erigon events
INFO[12-02|10:09:58.233] new subscription to newHeaders established
INFO[12-02|10:09:58.233] New txs subscriber joined
INFO[12-02|10:09:58.233] Reading JWT secret                       path=/polygon/erigon/jwt.hex
INFO[12-02|10:09:58.233] HTTP endpoint opened for Engine API      url=localhost:8551 ws=true ws.compression=true
INFO[12-02|10:09:58.248] [1/16 Snapshots] Fetching torrent files metadata
INFO[12-02|10:09:58.249] Started P2P networking                   version=66 self=enode://4299749ab00d3ba1f72303c4778fd5038286148b188b1140ae16e65d2745b0a6dcf0cb8e90daf4ece94108aaf066c29d4d8ff6ce862c6a284c52347940d68da8@65.21.196.179:40002 name=erigon/v2.30.0-stable-35f493c5/linux-amd64/go1.19.3
INFO[12-02|10:09:58.251] [Snapshots] Blocks Stat                  blocks=29000k indices=29000k alloc=3.2GB sys=4.3GB
INFO[12-02|10:09:58.251] [2/16 Headers] Waiting for headers...    from=30701206
INFO[12-02|10:09:58.569] [txpool] Started
INFO[12-02|10:10:18.251] [2/16 Headers] No block headers to write in this log period block number=30701206
INFO[12-02|10:10:38.251] [2/16 Headers] No block headers to write in this log period block number=30701206
INFO[12-02|10:10:58.234] [txpool] stat                            block=30701206 pending=8532 baseFee=0 queued=21886 alloc=2.5GB sys=4.3GB
INFO[12-02|10:10:58.251] [2/16 Headers] No block headers to write in this log period block number=30701206

What could be done here to save a node that has been syncing 17 days up to this point?

egorFiNE commented 1 year ago

Oops: I have executed integration stage_exec again in a separate window on a running erigon and this is what happened:

INFO[12-02|10:12:38.252] [2/16 Headers] No block headers to write in this log period block number=30701206
INFO[12-02|10:12:38.252] Req/resp stats                           req=1180 reqMin=30702357 reqMax=36304654 skel=20 skelMin=30702742 skelMax=30997462 resp=5400 respMin=30702742 respMax=36330824 dups=118905
INFO[12-02|10:12:58.234] [txpool] stat                            block=30701206 pending=10000 baseFee=0 queued=27730 alloc=2.7GB sys=4.8GB
INFO[12-02|10:12:58.252] [2/16 Headers] Wrote block headers       number=30702742 blk/second=76.800 alloc=2.8GB sys=4.8GB
INFO[12-02|10:13:18.251] [2/16 Headers] Inserting headers         progress=30735449 queue=1
INFO[12-02|10:13:38.252] [2/16 Headers] Wrote block headers       number=30910102 blk/second=10368.000 alloc=3.6GB sys=5.9GB
INFO[12-02|10:13:46.555] [p2p] GoodPeers                          eth66=32
INFO[12-02|10:13:58.239] [txpool] stat                            block=30701206 pending=10000 baseFee=0 queued=30000 alloc=3.5GB sys=5.9GB
INFO[12-02|10:13:58.251] [2/16 Headers] No block headers to write in this log period block number=30910102
INFO[12-02|10:13:58.251] Req/resp stats                           req=1406 reqMin=30910101 reqMax=36243982 skel=20 skelMin=30911638 skelMax=31206358 resp=7195 respMin=23057663 respMax=36330864 dups=221643
INFO[12-02|10:14:18.251] [2/16 Headers] Wrote block headers       number=30943894 blk/second=1689.600 alloc=5.8GB sys=6.3GB
INFO[12-02|10:14:38.255] [2/16 Headers] Inserting headers         progress=31041008 queue=1
INFO[12-02|10:14:58.252] [2/16 Headers] Wrote block headers       number=31160470 blk/second=10828.800 alloc=3.8GB sys=7.7GB
INFO[12-02|10:15:03.025] [txpool] stat                            block=30701206 pending=10000 baseFee=0 queued=30000 alloc=4.2GB sys=7.7GB
INFO[12-02|10:15:18.251] [2/16 Headers] Wrote block headers       number=31238806 blk/second=3916.800 alloc=6.5GB sys=7.7GB

I guess it started catching up?

egorFiNE commented 1 year ago

And we're back: 

INFO[12-03|08:42:44.984] [2/16 Headers] No block headers to write in this log period block number=30697206
INFO[12-03|08:42:44.984] Req/resp stats                           req=3604 reqMin=30633959 reqMax=36368155 skel=20 skelMin=30698742 skelMax=30993462 resp=24252 respMin=30634139 respMax=36368157 dups=3324591

@allada @AskAlexSharov welp?

lbadger commented 1 year ago

@lbadger increase logs verbosity

I redownloaded the snapshot again. Increased verbosity. I'm back to the same problem. 

Dec 04 17:21:50 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:50.519] [Downloader] Request skeleton            anchors=2 top seen height=23621041 highestInDb=22973999
Dec 04 17:21:51 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:51.666] [Downloader] Request skeleton            anchors=2 top seen height=23621041 highestInDb=22973999
Dec 04 17:21:52 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:52.814] [Downloader] Request skeleton            anchors=2 top seen height=23621041 highestInDb=22973999
Dec 04 17:21:53 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:53.960] [Downloader] Invalidating anchor         height=23621031 hash=0x3876d862e5d5cda43ec338cbd659b234ffdca4f23b7820ddd7c30a56985a1722 reason="suspected unavailability"
Dec 04 17:21:53 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:53.960] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:21:54 bsc-archive-one start_erigon_service.sh[14365]: [INFO] [12-04|17:21:54.506] [2/16 Headers] No block headers to write in this log period block number=22973999
Dec 04 17:21:54 bsc-archive-one start_erigon_service.sh[14365]: [INFO] [12-04|17:21:54.506] Req/resp stats                           req=7 reqMin=23620838 reqMax=23621040 skel=17 skelMin=22975535 skelMax=23270255 resp=48 respMin=0 respMax=0 dups=0
Dec 04 17:21:54 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:54.506] [Downloader] Queue sizes                 anchors=1 links=1 persisted=65536
Dec 04 17:21:54 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:54.506] {23621041-23621041 links=1 (23621041)} => 2d6e46e4afee06c591605639e5f23c67b762fd2ee497562fb6c223ae1aac3960, anchorQueue.idx=0, next retry in 3.306935366s
Dec 04 17:21:55 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:55.353] Sentry peer did Disconnect               peer=e48df979dfaa3fe2ba99fd027701178710dcffdc68c3e8efd0808168488a85b50abab79710b08e3bde97ad7913e25786c1372d59995bede6578a511344599600
Dec 04 17:21:55 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:55.507] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:21:56 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:56.654] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:21:57 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:57.802] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:21:59 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:21:59.096] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:22:00 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:00.244] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:22:01 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:01.390] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:22:02 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:02.537] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:22:03 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:03.685] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:22:04 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:04.832] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:22:05 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:05.979] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:22:07 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:07.126] [Downloader] Request skeleton            anchors=1 top seen height=23621041 highestInDb=22973999
Dec 04 17:22:07 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:07.977] Sentry peer did Disconnect               peer=5ae095cccf16d8e2a27135059d932d1ea713281e6d84338361161a670dd9dc00e46e0630ca0032764a141a62479f65c54dc369ef62f477743c52733459d08d00
Dec 04 17:22:08 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:08.155] Sentry peer did Connect                  peer=5ae095cccf16d8e2a27135059d932d1ea713281e6d84338361161a670dd9dc00e46e0630ca0032764a141a62479f65c54dc369ef62f477743c52733459d08d00
Dec 04 17:22:08 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:08.214] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:09 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:09.361] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:10 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:10.508] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:11 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:11.656] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:12 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:12.803] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:13 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:13.951] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:14 bsc-archive-one start_erigon_service.sh[14365]: [INFO] [12-04|17:22:14.505] [2/16 Headers] No block headers to write in this log period block number=22973999
Dec 04 17:22:14 bsc-archive-one start_erigon_service.sh[14365]: [INFO] [12-04|17:22:14.505] Req/resp stats                           req=5 reqMin=23620848 reqMax=23621053 skel=17 skelMin=22975535 skelMax=23270255 resp=25 respMin=23621054 respMax=23621054 dups=0
Dec 04 17:22:14 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:14.505] [Downloader] Queue sizes                 anchors=2 links=2 persisted=65536
Dec 04 17:22:14 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:14.505] {23621041-23621041 links=1 (23621041)} => 2d6e46e4afee06c591605639e5f23c67b762fd2ee497562fb6c223ae1aac3960, anchorQueue.idx=0, next retry in -144.971198ms
Dec 04 17:22:14 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:14.505] {23621054-23621054 links=1 (23621054)} => fb00d67ec6946f0890314956c21c4995941c68e8b8c8a22ad0962d8b7ebef58d, anchorQueue.idx=1, next retry in 4.444835016s
Dec 04 17:22:15 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:15.653] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:16 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:16.799] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:17 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:17.947] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:18 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:18.770] Sentry peer did Disconnect               peer=e12e142cb0767b6dd452a9380edfc74eb5d8a4fd661b68443810ed34d52c77319cecd1db34bb2fadabf7c7a1b5dafd9d19f6d40773f249ee6ba7e8d1141d4b00
Dec 04 17:22:19 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:19.095] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:20 bsc-archive-one start_erigon_service.sh[14365]: [INFO] [12-04|17:22:20.214] [p2p] GoodPeers                          eth66=606
Dec 04 17:22:20 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:20.242] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:21 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:21.389] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:22 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:22.536] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:23 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:23.683] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:24 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:24.831] [Downloader] Request skeleton            anchors=2 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:25 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:25.977] [Downloader] Invalidating anchor         height=23621041 hash=0x2d6e46e4afee06c591605639e5f23c67b762fd2ee497562fb6c223ae1aac3960 reason="suspected unavailability"
Dec 04 17:22:25 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:25.978] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:26 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:26.979] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:27 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:27.980] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:28 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:28.982] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:29 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:29.984] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:30 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:30.986] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:31 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:31.987] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:32 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:32.990] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:33 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:33.373] QuerySeeds read nodes from the node DB   count=30
Dec 04 17:22:33 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:33.992] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:34 bsc-archive-one start_erigon_service.sh[14365]: [INFO] [12-04|17:22:34.506] [2/16 Headers] No block headers to write in this log period block number=22973999
Dec 04 17:22:34 bsc-archive-one start_erigon_service.sh[14365]: [INFO] [12-04|17:22:34.506] Req/resp stats                           req=5 reqMin=23620848 reqMax=23621053 skel=18 skelMin=22975535 skelMax=23270255 resp=13 respMin=0 respMax=0 dups=0
Dec 04 17:22:34 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:34.506] [Downloader] Queue sizes                 anchors=1 links=1 persisted=65536
Dec 04 17:22:34 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:34.506] {23621054-23621054 links=1 (23621054)} => fb00d67ec6946f0890314956c21c4995941c68e8b8c8a22ad0962d8b7ebef58d, anchorQueue.idx=0, next retry in 477.133981ms
Dec 04 17:22:35 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:35.508] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:36 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:36.509] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:37 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:37.510] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:38 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:38.512] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:39 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:39.513] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:40 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:40.514] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:41 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:41.515] [Downloader] Request skeleton            anchors=1 top seen height=23621054 highestInDb=22973999
Dec 04 17:22:42 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:42.318] Sentry peer did Disconnect               peer=ff3517dad358517ca0743fb20ed8a12f357fea93948a70c1f6344649e4e6055aced093e0b35af532804926eb18fe61502b3028ff69767a47cfd99bdc4527b500
Dec 04 17:22:42 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:42.497] Sentry peer did Connect                  peer=ff3517dad358517ca0743fb20ed8a12f357fea93948a70c1f6344649e4e6055aced093e0b35af532804926eb18fe61502b3028ff69767a47cfd99bdc4527b500
Dec 04 17:22:42 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:42.556] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:43 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:43.557] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:44 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:44.558] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:45 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:45.560] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:46 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:46.562] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:47 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:47.564] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:48 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:48.565] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:49 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:49.567] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:50 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:50.568] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:51 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:51.569] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:52 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:52.571] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:53 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:53.573] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:54 bsc-archive-one start_erigon_service.sh[14365]: [INFO] [12-04|17:22:54.505] [2/16 Headers] No block headers to write in this log period block number=22973999
Dec 04 17:22:54 bsc-archive-one start_erigon_service.sh[14365]: [INFO] [12-04|17:22:54.505] Req/resp stats                           req=7 reqMin=23620861 reqMax=23621065 skel=19 skelMin=22975535 skelMax=23270255 resp=2 respMin=23621066 respMax=23621066 dups=0
Dec 04 17:22:54 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:54.505] [Downloader] Queue sizes                 anchors=2 links=2 persisted=65536
Dec 04 17:22:54 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:54.506] {23621054-23621054 links=1 (23621054)} => fb00d67ec6946f0890314956c21c4995941c68e8b8c8a22ad0962d8b7ebef58d, anchorQueue.idx=0, next retry in 1.062188024s
Dec 04 17:22:54 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:54.506] {23621066-23621066 links=1 (23621066)} => 94981463ee79ee7253c1feb72b747734bdface1621aeec46f057b429af184c07, anchorQueue.idx=1, next retry in 3.064957074s
Dec 04 17:22:55 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:55.507] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
Dec 04 17:22:56 bsc-archive-one start_erigon_service.sh[14365]: [DBUG] [12-04|17:22:56.509] [Downloader] Request skeleton            anchors=2 top seen height=23621066 highestInDb=22973999
dwjorgeb commented 1 year ago

I have the same issue in Polygon. Tried to unwind 1000 blocks and deleted the snapshot folder, after rebooted the node and got this:

[INFO] [12-07|00:44:28.917] [9/16 IntermediateHashes] Unwinding      from=36507181 to=36506224 csbucket=AccountChangeSet
[INFO] [12-07|00:44:28.917] [9/16 IntermediateHashes] Unwinding      from=36507181 to=36506224 csbucket=StorageChangeSet
[EROR] [12-07|00:44:28.917] Staged Sync                              err="[9/16 IntermediateHashes] wrong trie root: 19782a6618bf07c20f140d3988b517d2983827852782382b5d3d9c8176c506ac, expected (from header): ea1853731da32226b4806cd4a87a17936eef19fc3a0794267b738a0cdbfcd2c6"
egorFiNE commented 1 year ago

And again today at block 23700523.

naviocean commented 1 year ago

Got same issue

 [2/16 Headers] No block headers to write in this log period block number=23700523
breezytm commented 1 year ago

The issue still exists on a newly deployed node running version 2.31.0

[INFO] [12-10|05:09:04.095] [p2p] GoodPeers                          eth66=43 eth67=20
[INFO] [12-10|05:09:04.121] [txpool] stat                            block=0 pending=1 baseFee=0 queued=1667 alloc=202.0GB sys=239.4GB
[INFO] [12-10|05:09:09.084] [2/16 Headers] No block headers to write in this log period block number=22999999
[INFO] [12-10|05:09:09.084] Req/resp stats                           req=0 reqMin=0 reqMax=0 skel=19 skelMin=23001535 skelMax=23296255 resp=107 respMin=0 respMax=0 dups=0