[TESTNET BUG] block inventory sync does not complete (exponential time required)

[eduisterwinkel]

Describe the bug

When firing up stacks-node on xenon testnet the block synchronization goes smooth until around block 1933420, after that it seems to take exponentially longer to progress. Where blocks sync in 1 to 2 seconds before this point, it takes for example well above 100 seconds to sync blocks 1933620 to 1933670.

INFO [1612816905.418496] [src/burnchains/burnchain.rs:1284] [main] Syncing Bitcoin blocks: 53.4% (1933220 to 1933270 out of 1934708)
INFO [1612816949.810039] [src/burnchains/burnchain.rs:1284] [main] Syncing Bitcoin blocks: 55.1% (1933270 to 1933320 out of 1934708)
INFO [1612817045.228242] [src/burnchains/burnchain.rs:1284] [main] Syncing Bitcoin blocks: 56.7% (1933320 to 1933370 out of 1934708)
INFO [1612817151.540376] [src/burnchains/burnchain.rs:1284] [main] Syncing Bitcoin blocks: 58.3% (1933370 to 1933420 out of 1934708)
INFO [1612820785.603245] [src/burnchains/burnchain.rs:1284] [main] Syncing Bitcoin blocks: 59.9% (1933420 to 1933470 out of 1934708)
INFO [1612828022.070480] [src/burnchains/burnchain.rs:1284] [main] Syncing Bitcoin blocks: 61.4% (1933470 to 1933520 out of 1934715)
INFO [1612835259.341440] [src/burnchains/burnchain.rs:1284] [main] Syncing Bitcoin blocks: 62.3% (1933520 to 1933570 out of 1934751)
INFO [1612842496.219037] [src/burnchains/burnchain.rs:1284] [main] Syncing Bitcoin blocks: 63.3% (1933570 to 1933620 out of 1934780)
INFO [1612849733.030261] [src/burnchains/burnchain.rs:1284] [main] Syncing Bitcoin blocks: 64.5% (1933620 to 1933670 out of 1934800)

Steps To Reproduce

This happens with the default stacks-node xenon as well as with any own follower or miner configuration.

Expected behavior

It shouldn't take forever to sync blocks.

Environment

• OS: Ubuntu
• Rust version rustc 1.49.0 (e1884a8e3 2020-12-29)
• Output of `stacks-node version: 2.0.4 (aslo reported with 2.0.3 by other user)

Additional context

Part of debug when taking long to sync attached
syncblockinv.log

[jcnelson]

Hey, thanks for reporting! It's not exponential time; it's quadratic time. It has to do with the fact that the node needs the PoX state for reward cycle n - 1 in order to process reward cycle n. Currently, the heuristic the node uses to determine that it is safe to proceed to cycle n's blocks is overly-pessimistic, and requires the node to synchronize all block inventory logic for the past n reward cycles before proceeding (note that this is different from synchronizing the Bitcoin block headers). Fixing this is going to ship with #1805.

[eduisterwinkel]

The 'exponential' I didnt check beforehand. Thanks for explanation.

Looking a bit closer at the log I see the 50 blocks sync increments skip from a regular 50-100 seconds suddenly to 1 hour, then to two hours and stays around 2 hours per 50 blocks until I killed it. Doesnt seem to follow your description.

Any advice on how to test anything related to running your own node and mining? Or are the only options to wait several days for the node to sync each time you change a config setting and gigabytes of debug log; do it on mainnet; or wait for #1805 to ship?

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[PUN-app]

I have an issue where it halts after syncing 2100 bitcoin header blocks. I have to restart it to get it to continue. Based on progress, if it continued, I could of completed the syncing in hours. But, cuz I have to manually restart it every 2100 blocks, which corresponds to about 2.1% progress, it is taking day. Should I open a new issue or is this related to this one?

I'm doing this with dev of stacks-blockstack-api using the docker compose:

npm run devenv:deploy

Considered opening the issue in stacks-blockstack-api, but this is more likely originating in the dockers of stacks-node.

stacks-blockchain_1 | INFO [1633767946.029813] [src/burnchains/burnchain.rs:1265] [main] Syncing Bitcoin blocks: 85.4% (2082951 to 2084001 out of 2098344)
...
stacks-blockchain_1 | INFO [1633768772.789600] [src/burnchains/burnchain.rs:1265] [main] Syncing Bitcoin blocks: 87.5% (2085051 to 2086101 out of 2098345)

2086101 - 2084001 = 2100

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[stale]

This issue has been automatically closed. Please reopen if needed.

[blockstack-devops]

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.