Originally created by: MonsieurNicolas
Originally owned by: marta-lokhova
It looks like the code in our catchup logic does not handle failures properly:
VERIFY_STATUS_ERR_BAD_LEDGER_VERSION is probably done too early. If we were going to make this "fatal", we first need to establish trust of the ledger header based off latest SCP.xdr::xdr_bad_message_size), should implement some sort of exponential back-offWhen running into errors that don't allow the node to make progress, catchup retries right away and downloads more and more checkpoints with each retry as it tries to verify the ledger chain between latest ledger and last closed ledger on the node. This causes a lot of unnecessary downloads to history archives.
2023-09-20T15:00:04.391 GCT2W [Ledger INFO] Got consensus: [seq=1615422, prev=fa5ab2, txs=5, ops=5, sv: [ SIGNED@sdf2 txH: 16f9cb, ct: 1695222004, upgrades: [ ] ]]
2023-09-20T15:00:04.392 GCT2W [Tx INFO] applying ledger 1615422 (txs:5, ops:5, base_fee:100)
2023-09-20T15:00:04.396 GCT2W [Ledger INFO] Closed ledger: [seq=1615422, hash=80e056]
2023-09-20T15:42:06.378 GCT2W [History ERROR] Catchup material failed verification - unsupported ledger version, propagating failure
2023-09-20T23:59:37.070 GBWBL [History ERROR] Catchup material failed verification - unsupported ledger version, propagating failure
2023-09-20T23:59:37.070 GBWBL [History ERROR] Catchup material failed verification - unsupported ledger version, propagating failure
2023-09-20T23:59:37.070 GBWBL [History ERROR] Upgrade this stellar-core installation to newest version
2023-09-20T23:59:37.070 GBWBL [History INFO] Verifying ledgers [1615423,1620736)
2023-09-20T23:59:37.070 GBWBL [History INFO] Catching up to ledger 1620735: Failed: verify-ledger-chain
2023-09-20T23:59:37.070 GBWBL [History INFO] Catching up to ledger 1620735: Succeeded: batch-download-ledger-0018a63f-0018bb3f : 252/252 children completed
2023-09-20T23:59:38.594 GBWBL [Herder INFO] Quorum information for 1620784 : {"agree":3,"cost":19192,"delayed":0,"disagree":0,"fail_at":2,"hash":"59d361","lag_ms":13,"ledger":1620784,"missi
ng":0,"phase":"EXTERNALIZE"}
2023-09-20T23:59:38.595 GBWBL [Ledger INFO] Got consensus: [seq=1620786, prev=000000, txs=0, ops=0, sv: [ SIGNED@sdf2 txH: aa6308, ct: 1695254378, upgrades: [ ] ]]
2023-09-20T23:59:38.595 GBWBL [Ledger INFO] Close of ledger 1620786 buffered. mSyncingLedgers has 51 ledgers
2023-09-20T23:59:41.070 GBWBL [History INFO] Catching up to ledger 1620735: downloading ledger files 17/84 (20%)
...
2023-09-21T00:06:18.222 GBWBL [History INFO] Catching up to ledger 1620799: downloading ledger files 85/85 (100%)
2023-09-21T00:06:18.246 GBWBL [History INFO] Catching up to ledger 1620799: Succeeded: batch-download-ledger-0018a63f-0018bb7f : 170/170 children completed
2023-09-21T00:06:18.246 GBWBL [History INFO] Verifying ledgers [1615423,1620800)
2023-09-21T00:06:18.246 GBWBL [History ERROR] Catchup material failed verification - unsupported ledger version, propagating failure
2023-09-21T00:06:18.246 GBWBL [History ERROR] Upgrade this stellar-core installation to newest version
2023-09-21T00:06:18.246 GBWBL [History INFO] Verifying ledgers [1615423,1620800)
2023-09-21T00:06:18.246 GBWBL [History INFO] Catching up to ledger 1620799: Failed: verify-ledger-chain
2023-09-21T00:06:18.246 GBWBL [History INFO] Catching up to ledger 1620799: Succeeded: batch-download-ledger-0018a63f-0018bb7f : 170/170 children completed
2023-09-21T00:06:20.247 GBWBL [History INFO] Catching up to ledger 1620799: downloading ledger files 17/85 (20%)
...
2023-10-10T10:27:52.064 GBWBL [History INFO] Catching up to ledger 1940223: downloading ledger files 3673/5076 (72%)
In this example, state was corrupted by bug [#3958]
2023-10-10T23:59:30.394 GA4V2 [History INFO] Catching up to ledger 1949503: downloading ledger files 118/118 (100%)
2023-10-10T23:59:30.417 GA4V2 [History INFO] Catching up to ledger 1949503: Succeeded: batch-download-ledger-001da1ff-001dbf7f : 708/708 children completed
2023-10-10T23:59:30.417 GA4V2 [History INFO] Verifying ledgers [1941982,1949504)
2023-10-10T23:59:30.418 GA4V2 [History INFO] Verifying ledger [seq=1949503, hash=19421f] against SCP hash
2023-10-10T23:59:30.418 GA4V2 [History INFO] Catching up to ledger 1949503: verifying checkpoint 1/118 (0%)
2023-10-10T23:59:30.440 GA4V2 [History ERROR] Bad ledger-header history entry: claimed ledger [seq=1941981, hash=6d207f] does not agree with LCL [seq=1941981, hash=a5777e]
2023-10-10T23:59:30.441 GA4V2 [History ERROR] Catchup material failed verification - hash mismatch, propagating failure
2023-10-10T23:59:30.441 GA4V2 [History ERROR] One or more of history archives may be corrupted. Update HISTORY configuration entry to only contain valid ones
2023-10-10T23:59:30.441 GA4V2 [History INFO] Verifying ledgers [1941982,1949504)
2023-10-10T23:59:30.441 GA4V2 [History INFO] Catching up to ledger 1949503: Failed: verify-ledger-chain
2023-10-10T23:59:30.441 GA4V2 [History INFO] Catching up to ledger 1949503: Failed: download-verify-ledgers-seq
2023-10-10T23:59:30.441 GA4V2 [History WARNING] Catchup failed
2023-10-10T23:59:34.886 GA4V2 [Herder INFO] Quorum information for 1949572 : {"agree":3,"cost":14772,"delayed":0,"disagree":0,"fail_at":2,"hash":"59d361","lag_ms":16,"ledger":1949572,"missi
ng":0,"phase":"EXTERNALIZE"}
2023-10-10T23:59:34.887 GA4V2 [Ledger INFO] Got consensus: [seq=1949574, prev=3747c0, txs=0, ops=0, sv: [ SIGNED@sdf2 txH: 80e32c, ct: 1696982374, upgrades: [ ] ]]
2023-10-10T23:59:34.887 GA4V2 [Ledger INFO] Close of ledger 1949574 buffered. mSyncingLedgers has 7 ledgers
2023-10-10T23:59:34.887 GA4V2 [History INFO] Starting catchup after ensuring checkpoint ledger 1949574 was closed on network
2023-10-10T23:59:34.890 GA4V2 [History INFO] Starting catchup with configuration:
lastClosedLedger: 1941981
toLedger: 1949567
count: 18000
2023-10-10T23:59:34.890 GA4V2 [History INFO] Catching up to ledger 1949567: Downloading state file history/00/1d/bf/history-001dbf7f.json for ledger 1949567
2023-10-10T23:59:34.890 GA4V2 [History INFO] Downloading history archive state: history/00/1d/bf/history-001dbf7f.json
2023-10-10T23:59:35.081 GA4V2 [History INFO] Catching up to ledger 1949567: downloading ledger files 1/119 (0%)
