Warp sync fails on 0.9.22

[bkchr]

With 0.9.12 warp sync fails on the switch to full sync.

2022-05-18 21:47:47 Warp sync is complete (822 MiB), restarting block sync.    
2022-05-18 21:47:48 💔 Verification failed for block 0xd41085dc00275edf4775b227508811ed39ccbb2f30b199281a27d11597370dbb received from peer: 12D3KooWG1iazkoWvqjpZ9gCgkrimwN6BKsPGRTc7stC4VukSoZh, "Client error: UnknownBlock: Header was not found in the database: 0x1b3088fbb37e3d049b9b29181db2e42b16878beb984f1657131359b16dbceaad"    
2022-05-18 21:47:48 💔 Verification failed for block 0xd41085dc00275edf4775b227508811ed39ccbb2f30b199281a27d11597370dbb received from peer: 12D3KooWRkYVdebCb7EsNzxWzdtp8prAJHqiHkgJuMPvP4Eoa7wb, "Client error: UnknownBlock: Header was not found in the database: 0x1b3088fbb37e3d049b9b29181db2e42b16878beb984f1657131359b16dbceaad"    
2022-05-18 21:47:48 💔 Verification failed for block 0xd41085dc00275edf4775b227508811ed39ccbb2f30b199281a27d11597370dbb received from peer: 12D3KooWJh3gscumgHKM9s2eBmaQ1XcQXFU8T7qsQEAZ16M3Qe9s, "Client error: UnknownBlock: Header was not found in the database: 0x1b3088fbb37e3d049b9b29181db2e42b16878beb984f1657131359b16dbceaad"    
2022-05-18 21:47:50 Error while polling for next slot: UnknownBlock: 0x1b3088fbb37e3d049b9b29181db2e42b16878beb984f1657131359b16dbceaad   

The actual missing block changes always, but is one around the tip of the chain. I tried this twice.

CC @arkpar

[hitchhooker]

i think warpsync is completely broken atm. after sync is ready, keeps crashing for essential task failed(babe).

May 19 03:03:30 localhost polkadot[540367]: 2022-05-19 03:03:30 ⏩ Warping, Importing state, 823.79 Mib (50 peers), best: #0 (0xb0a8…dafe), finalized #0 (0xb0a8…dafe), ⬇ 5.7kiB/s ⬆ 5.7kiB/s
May 19 03:03:35 localhost polkadot[540367]: 2022-05-19 03:03:35 ⏩ Warping, Importing state, 823.79 Mib (50 peers), best: #0 (0xb0a8…dafe), finalized #0 (0xb0a8…dafe), ⬇ 12.3kiB/s ⬆ 7.4kiB/s
May 19 03:03:36 localhost polkadot[540367]: 2022-05-19 03:03:36 failed to assemble or send inherent data err=Runtime(Execution { runtime_api_name: "availability_cores", source: Application(Execution(Other("Exported method ParachainHost_availability_cores is not found"))) })
May 19 03:03:40 localhost polkadot[540367]: 2022-05-19 03:03:40 ⏩ Warping, Importing state, 823.79 Mib (50 peers), best: #12745300 (0xb3aa…de4c), finalized #12745300 (0xb3aa…de4c), ⬇ 22.0kiB/s ⬆ 9.5kiB/s
May 19 03:03:42 localhost polkadot[540367]: 2022-05-19 03:03:42 Warp sync is complete (823 MiB), restarting block sync.
May 19 03:03:42 localhost polkadot[540367]: 2022-05-19 03:03:42 💔 Verification failed for block 0x49e21d13964a90b74d8c5cf41dbe023d9680f722e4a1c82cd54c8cdd60a4454d received from peer: 12D3KooWAEBJDqCdjW32qx5H8W4E1miCAz7UeNgbYBaCzhac8Lnb, "Client error: UnknownBlock: Header was not found in the database: 0x86700c903794e7d1c0242e8ede9d691bb4fdb5f85537e6241a1276663d347cd2"
May 19 03:03:42 localhost polkadot[540367]: 2022-05-19 03:03:42 💔 Verification failed for block 0x49e21d13964a90b74d8c5cf41dbe023d9680f722e4a1c82cd54c8cdd60a4454d received from peer: 12D3KooWD1cJvSTWaK19qhDBKvrUZZ84J3sKoTHQo7TyRmivE2xG, "Client error: UnknownBlock: Header was not found in the database: 0x86700c903794e7d1c0242e8ede9d691bb4fdb5f85537e6241a1276663d347cd2"
May 19 03:03:43 localhost polkadot[540367]: 2022-05-19 03:03:43 💔 Verification failed for block 0x49e21d13964a90b74d8c5cf41dbe023d9680f722e4a1c82cd54c8cdd60a4454d received from peer: 12D3KooWF8XTJ79fqcAG1VcMiQqGPQbLa6AeAaFJS82w4mj7ySEj, "Client error: UnknownBlock: Header was not found in the database: 0x86700c903794e7d1c0242e8ede9d691bb4fdb5f85537e6241a1276663d347cd2"
May 19 03:03:43 localhost polkadot[540367]: 2022-05-19 03:03:43 💔 Verification failed for block 0x49e21d13964a90b74d8c5cf41dbe023d9680f722e4a1c82cd54c8cdd60a4454d received from peer: 12D3KooWEpQm3pmEvoXAufUuRx1gDEYPfkaHJ7TNsHKBgH3xSazo, "Client error: UnknownBlock: Header was not found in the database: 0x86700c903794e7d1c0242e8ede9d691bb4fdb5f85537e6241a1276663d347cd2"
May 19 03:03:43 localhost polkadot[540367]: 2022-05-19 03:03:43 💔 Verification failed for block 0x49e21d13964a90b74d8c5cf41dbe023d9680f722e4a1c82cd54c8cdd60a4454d received from peer: 12D3KooWHk39pbRkkq9WUnX7g98mLEz7qEGKhs83uv2J1VCSfn2a, "Client error: UnknownBlock: Header was not found in the database: 0x86700c903794e7d1c0242e8ede9d691bb4fdb5f85537e6241a1276663d347cd2"
May 19 03:03:44 localhost polkadot[540367]: 2022-05-19 03:03:44 💔 Verification failed for block 0x49e21d13964a90b74d8c5cf41dbe023d9680f722e4a1c82cd54c8cdd60a4454d received from peer: 12D3KooWT2GnGxXYaAJSSeYJhDDqy93s2915yePz2kgh5VDs4Gh5, "Client error: UnknownBlock: Header was not found in the database: 0x86700c903794e7d1c0242e8ede9d691bb4fdb5f85537e6241a1276663d347cd2"
May 19 03:03:44 localhost polkadot[540367]: 2022-05-19 03:03:44 💔 Verification failed for block 0x49e21d13964a90b74d8c5cf41dbe023d9680f722e4a1c82cd54c8cdd60a4454d received from peer: 12D3KooWJHG2dZUf1s8tztFcXSNx1eCT5vsCc72bBiUCzKPn4X5H, "Client error: UnknownBlock: Header was not found in the database: 0x86700c903794e7d1c0242e8ede9d691bb4fdb5f85537e6241a1276663d347cd2"
May 19 03:03:44 localhost polkadot[540367]: 2022-05-19 03:03:44 Error while polling for next slot: UnknownBlock: 0x86700c903794e7d1c0242e8ede9d691bb4fdb5f85537e6241a1276663d347cd2
May 19 03:03:44 localhost polkadot[540367]: 2022-05-19 03:03:44 Essential task `babe` failed. Shutting down service.
May 19 03:03:44 localhost polkadot[540367]: Error:
May 19 03:03:44 localhost polkadot[540367]:   0: #033[91mOther: Essential task failed.#033[0m
May 19 03:03:44 localhost polkadot[540367]: Backtrace omitted. Run with RUST_BACKTRACE=1 environment variable to display it.
May 19 03:03:44 localhost polkadot[540367]: Run with RUST_BACKTRACE=full to include source snippets.

[arkpar]

I think the reason is ForkTree used to query headers in reverse order (depth first) when searching for nodes. So the target node was always found before tree traversal got to querying the parent node, that does not exist in the database.