Warp Sync testing on Moonbase, Moonriver and Moonbeam

[ahmadkaouk]

This issue aims to provide an analysis of the Warp Sync feature and its current state across Moonbase, Moonriver, and Moonbeam. The tests were conducted using a node running version moonbeam 0.34.0-b08aa999f1c.

Test Environment

• Node Version: moonbeam 0.34.0-b08aa999f1c
• Database: ParityDB
• Sync Method: Warp Sync
• Computer: MacBook Pro M2 Max 64Gb of RAM.

Moonbase

Test Command

.moonbeam \
  --chain=alphanet \
  --database=paritydb \
  --sync=warp \
  -- \
  --chain=westend_moonbase_relay_testnet \
  --sync=warp \
  --database=paritydb

Observations

The Moonbase network experienced issues with the Warp Sync feature. Specifically, the node failed to download the finality proofs, preventing the warp sync from continuing.

# Snippet showing failure in downloading finality proofs
2023-09-25 10:06:28 [Relaychain] ⏩ Warping, Downloading finality proofs, 0.00 Mib (4 peers), best: #0 (0xe1ea…9443), finalized #0 (0xe1ea…9443), ⬇ 117.6kiB/s ⬆ 58.4kiB/s
2023-09-25 10:06:28 [🌗] ⚙️  Syncing, target=#5175154 (3 peers), best: #16744 (0xe1f3…5906), finalized #0 (0x91bc…9527), ⬇ 1006.2kiB/s ⬆ 10.3kiB/s
...
2023-09-25 10:06:33 [Relaychain] ⏩ Warping, Downloading finality proofs, 0.00 Mib (6 peers), best: #0 (0xe1ea…9443), finalized #0 (0xe1ea…9443), ⬇ 105.5kiB/s ⬆ 14.8kiB/s
2023-09-25 10:06:33 [🌗] ⚙️  Syncing 246.8 bps, target=#5175155 (4 peers), best: #17978 (0x8654…d81a), finalized #0 (0x91bc…9527), ⬇ 644.9kiB/s ⬆ 1.6kiB/s
...
2023-09-25 10:06:38 [Relaychain] ⏩ Warping, Downloading finality proofs, 0.00 Mib (5 peers), best: #0 (0xe1ea…9443), finalized #0 (0xe1ea…9443), ⬇ 2.0MiB/s ⬆ 65.6kiB/s
2023-09-25 10:06:38 [🌗] ⚙️  Syncing 244.6 bps, target=#5175155 (3 peers), best: #19201 (0x08e0…6845), finalized #0 (0x91bc…9527), ⬇ 602.3kiB/s ⬆ 21.1kiB/s
...
2023-09-25 10:06:43 [🌗] ⚙️  Syncing 244.5 bps, target=#5175155 (3 peers), best: #20424 (0x4bf4…d338), finalized #0 (0x91bc…9527), ⬇ 486.8kiB/s ⬆ 11.9kiB/s
2023-09-25 10:06:43 [Relaychain] ⏩ Warping, Downloading finality proofs, 0.00 Mib (1 peers), best: #0 (0xe1ea…9443), finalized #0 (0xe1ea…9443), ⬇ 6.7MiB/s ⬆ 22.1kiB/s

Bad warp proof response

Enabling debug logs exposed an issue with bad justification for header, as can be seen below:

# Debug log indicating bad justification for header
2023-09-25 10:12:22.199 DEBUG tokio-runtime-worker sync: [Relaychain] Importing warp proof data from 12D3KooWAWgGHUu8tFcCBmyWbNVGWScB5P53g5T1nNCezZ7R11HX, 8386867 bytes.
2023-09-25 10:12:22.399 DEBUG tokio-runtime-worker sync: [Relaychain] Bad warp proof response: bad justification for header: invalid commit in grandpa justification
2023-09-25 10:12:22.399 DEBUG tokio-runtime-worker sync: [Relaychain] Bad proof data received from 12D3KooWAWgGHUu8tFcCBmyWbNVGWScB5P53g5T1nNCezZ7R11HX

---

Moonriver

Test Command

.moonbeam \
  --chain=moonriver \
  --database=paritydb \
  --sync=warp \
  -- \
  --chain=kusama \
  --sync=warp \
  --database=paritydb

Observations

Moonriver successfully completed the Warp Sync process in approximately 55 minutes. The resulting state size was 6.68 GiB. However, despite updating the best block, there seems to be a problem with the finalized block as it remains at 0.

Log Excerpts

2023-09-26 09:22:40 [Relaychain] ⏩ Warping, Downloading state, 1381.35 Mib (11 peers), best: #0 (0xb0a8…dafe), finalized #0 (0xb0a8…dafe), ⬇ 2.5MiB/s ⬆ 1.6kiB/s
2023-09-26 09:22:42 [🌗] ⏩ Waiting for pending target block (12 peers), best: #0 (0x401a…474b), finalized #0 (0x401a…474b), ⬇ 4.1kiB/s ⬆ 0.6kiB/s
2023-09-26 09:22:45 [Relaychain] ⏩ Warping, Importing state, 1387.26 Mib (11 peers), best: #0 (0xb0a8…dafe), finalized #0 (0xb0a8…dafe), ⬇ 1.1MiB/s ⬆ 0.3kiB/s
2023-09-26 09:22:47 [🌗] ⏩ Waiting for pending target block (12 peers), best: #0 (0x401a…474b), finalized #0 (0x401a…474b), ⬇ 3.8kiB/s ⬆ 0.1kiB/s
2023-09-26 09:22:49 [Relaychain] Warp sync is complete (1387 MiB), restarting block sync.
2023-09-26 09:22:50 [Relaychain] ⏩ Block history, #4544 (11 peers), best: #19845410 (0xdace…3b47), finalized #19845381 (0xb16b…dabf), ⬇ 624.8kiB/s ⬆ 2.8kiB/s
2023-09-26 09:22:52 [🌗] ⏩ Waiting for pending target block (12 peers), best: #0 (0x401a…474b), finalized #0 (0x401a…474b), ⬇ 4.7kiB/s ⬆ 19 B/s
...
2023-09-26 10:11:23 [🌗] ⏩ Warping, Importing state, 6860.34 Mib (18 peers), best: #0 (0x401a…474b), finalized #0 (0x401a…474b), ⬇ 5.8kiB/s ⬆ 0.4kiB/s
2023-09-26 10:11:26 [Relaychain] ✨ Imported #19845895 (0x8506…bfe3)
2023-09-26 10:11:26 [Relaychain] ⏩ Block history, #8794304 (14 peers), best: #19845895 (0x8506…bfe3), finalized #19845892 (0x1651…ebe8), ⬇ 13.2MiB/s ⬆ 713.7kiB/s
2023-09-26 10:11:27 [🌗] Warp sync is complete (6860 MiB), restarting block sync.
2023-09-26 10:11:28 [🌗] ⚙️  Syncing 1037046.1 bps, target=#5192733 (13 peers), best: #5192490 (0x27e9…bc06), finalized #0 (0x401a…474b), ⬇ 774.2kiB/s ⬆ 2.3kiB/s
2023-09-26 10:11:28 [🌗] Logic error: Unexpected underflow in reducing consumer
2023-09-26 10:11:30 [Relaychain] ✨ Imported #19845896 (0x915c…3417)
2023-09-26 10:11:30 [🌗] Trying to disconnect unknown peer 12D3KooWAMEcsQTCvcWKDJaRHwvaX1DHSjxFjCWpLWYYVEaWS2cc from SetId(0).
2023-09-26 10:11:30 [🌗] Trying to disconnect unknown peer 12D3KooWAMEcsQTCvcWKDJaRHwvaX1DHSjxFjCWpLWYYVEaWS2cc from SetId(1).
2023-09-26 10:11:31 [Relaychain] ⏩ Block history, #8798592 (14 peers), best: #19845896 (0x915c…3417), finalized #19845893 (0x19d8…aad8), ⬇ 15.8MiB/s ⬆ 394.2kiB/s
2023-09-26 10:11:33 [🌗] ⚙️  Preparing 40.4 bps, target=#5192734 (12 peers), best: #5192692 (0x676e…72c4), finalized #0 (0x401a…474b), ⬇ 1.1MiB/s ⬆ 1.7kiB/s
2023-09-26 10:11:36 [Relaychain] ⏩ Block history, #8805056 (14 peers), best: #19845896 (0x915c…3417), finalized #19845894 (0xee91…d669), ⬇ 20.1MiB/s ⬆ 583.6kiB/s
2023-09-26 10:11:37 [Relaychain] ✨ Imported #19845897 (0xe89b…a415)
2023-09-26 10:11:38 [🌗] ⚙️  Preparing  0.0 bps, target=#5192734 (12 peers), best: #5192692 (0x676e…72c4), finalized #0 (0x401a…474b), ⬇ 0.2kiB/s ⬆ 0.2kiB/s
2023-09-26 10:11:41 [Relaychain] ⏩ Block history, #8812544 (14 peers), best: #19845897 (0xe89b…a415), finalized #19845894 (0xee91…d669), ⬇ 26.7MiB/s ⬆ 582.5kiB/s
2023-09-26 10:11:42 [Relaychain] ✨ Imported #19845898 (0xafa4…4284)
2023-09-26 10:11:43 [🌗] ✨ Imported #5192735 (0xf0a2…ab27)
2023-09-26 10:11:43 [🌗] ✨ Imported #5192734 (0x5ddb…ae8c)
2023-09-26 10:11:43 [🌗] ⏩ Block history, #2752 (12 peers), best: #5192734 (0x5ddb…ae8c), finalized #0 (0x401a…474b), ⬇ 366.9kiB/s ⬆ 2.8kiB/s
...
2023-09-26 10:16:41 [Relaychain] ⏩ Block history, #9065856 (14 peers), best: #19845947 (0x8d98…6542), finalized #19845945 (0xb385…7a6b), ⬇ 12.5MiB/s ⬆ 640.3kiB/s
2023-09-26 10:16:42 [Relaychain] ✨ Imported #19845948 (0x96a7…ed3c)
2023-09-26 10:16:43 [🌗] ✨ Imported #5192760 (0x2f20…7484)
2023-09-26 10:16:43 [🌗] ⏩ Block history, #398912 (12 peers), best: #5192759 (0xe0cc…dbad), finalized #0 (0x401a…474b), ⬇ 5.1MiB/s ⬆ 27.1kiB/s
2023-09-26 10:16:46 [Relaychain] ⏩ Block history, #9068480 (14 peers), best: #19845948 (0x96a7…ed3c), finalized #19845945 (0xb385…7a6b), ⬇ 5.0MiB/s ⬆ 369.3kiB/s
2023-09-26 10:16:48 [🌗] ⏩ Block history, #400064 (13 peers), best: #5192759 (0xe0cc…dbad), finalized #0 (0x401a…474b), ⬇ 541.8kiB/s ⬆ 4.8kiB/s
2023-09-26 10:16:49 [🌗] Trying to disconnect unknown peer 12D3KooWGVVKS2zYxxWUQxTgpvodiDSPKGeJDPe1NMiB8zkotLKp from SetId(0).
2023-09-26 10:16:49 [🌗] Trying to disconnect unknown peer 12D3KooWGVVKS2zYxxWUQxTgpvodiDSPKGeJDPe1NMiB8zkotLKp from SetId(1).
2023-09-26 10:16:49 [Relaychain] ✨ Imported #19845949 (0x7e3d…c9bb)
2023-09-26 10:16:51 [Relaychain] ⏩ Block history, #9068544 (14 peers), best: #19845949 (0x7e3d…c9bb), finalized #19845946 (0x0134…5a42), ⬇ 4.4MiB/s ⬆ 670.8kiB/s
2023-09-26 10:16:53 [🌗] ⏩ Block history, #411520 (12 peers), best: #5192759 (0xe0cc…dbad), finalized #0 (0x401a…474b), ⬇ 7.4MiB/s ⬆ 7.5kiB/s

Memory Usage

Moonbeam

Test Command

.moonbeam \
  --chain=moonbeam \
  --database=paritydb \
  --sync=warp \
  -- \
  --chain=polkadot \
  --sync=warp \
  --database=paritydb

Observations

During the testing of the Warp Sync feature on Moonbeam, it was observed that the node was experiencing crashes at the moment of importing the state. As a result, the Warp Sync process on Moonbeam was not successful.

Crash Log

The log indicated a crash with importing the state:

2023-09-25 17:53:01 [🌗] ⏩ Warping, Importing state, 25618.16 Mib (22 peers), best: #0 (0xfe58…b76d), finalized #0 (0xfe58…b76d), ⬇ 20.1kiB/s ⬆ 57 B/s
2023-09-25 17:53:04 [Relaychain] ⏩ Block history, #13637952 (16 peers), best: #17447288 (0xc7d8…c490), finalized #17447284 (0x4ff8…776a), ⬇ 25.3MiB/s ⬆ 548.8kiB/s
2023-09-25 17:53:06 [🌗] ⏩ Warping, Importing state, 25618.16 Mib (22 peers), best: #0 (0xfe58…b76d), finalized #0 (0xfe58…b76d), ⬇ 24.4kiB/s ⬆ 25 B/s
2023-09-25 17:53:06 [Relaychain] ✨ Imported #17447289 (0x8253…39b3)
2023-09-25 17:53:09 [Relaychain] ⏩ Block history, #13640512 (15 peers), best: #17447289 (0x8253…39b3), finalized #17447284 (0x4ff8…776a), ⬇ 18.4MiB/s ⬆ 149.5kiB/s
2023-09-25 17:53:11 [🌗] ⏩ Warping, Importing state, 25618.16 Mib (22 peers), best: #0 (0xfe58…b76d), finalized #0 (0xfe58…b76d), ⬇ 11.6kiB/s ⬆ 0.2kiB/s
2023-09-25 17:53:12 [Relaychain] ✨ Imported #17447290 (0xf080…6978)
2023-09-25 17:53:12 [Relaychain] ♻️  Reorg on #17447290,0xf080…6978 to #17447290,0xfb69…acb0, common ancestor #17447289,0x8253…39b3
2023-09-25 17:53:12 [Relaychain] ✨ Imported #17447290 (0xfb69…acb0)
2023-09-25 17:53:13 [Relaychain] ✨ Imported #17447290 (0x28cd…dfec)
2023-09-25 17:53:14 [Relaychain] ⏩ Block history, #13645056 (11 peers), best: #17447290 (0xfb69…acb0), finalized #17447287 (0xa69c…b49f), ⬇ 18.4MiB/s ⬆ 794.9kiB/s
2023-09-25 17:53:16 [🌗] ⏩ Warping, Importing state, 25618.16 Mib (22 peers), best: #0 (0xfe58…b76d), finalized #0 (0xfe58…b76d), ⬇ 55.4kiB/s ⬆ 57 B/s
2023-09-25 17:53:18 [Relaychain] ✨ Imported #17447291 (0x56d6…df74)
2023-09-25 17:53:19 [Relaychain] ⏩ Block history, #13647680 (10 peers), best: #17447291 (0x56d6…df74), finalized #17447287 (0xa69c…b49f), ⬇ 17.4MiB/s ⬆ 472.5kiB/s
2023-09-25 17:53:21 [🌗] ⏩ Warping, Importing state, 25618.16 Mib (22 peers), best: #0 (0xfe58…b76d), finalized #0 (0xfe58…b76d), ⬇ 1.2kiB/s ⬆ 25 B/s
2023-09-25 17:53:24 [Relaychain] ⏩ Block history, #13649792 (17 peers), best: #17447291 (0x56d6…df74), finalized #17447289 (0x8253…39b3), ⬇ 18.2MiB/s ⬆ 79.1kiB/s
2023-09-25 17:53:26 [Relaychain] ✨ Imported #17447292 (0x79d4…1627)
2023-09-25 17:53:26 [🌗] ⏩ Warping, Importing state, 25618.16 Mib (22 peers), best: #0 (0xfe58…b76d), finalized #0 (0xfe58…b76d), ⬇ 25.9kiB/s ⬆ 0.2kiB/s
2023-09-25 17:53:29 [Relaychain] ⏩ Block history, #13649792 (14 peers), best: #17447292 (0x79d4…1627), finalized #17447289 (0x8253…39b3), ⬇ 2.2MiB/s ⬆ 358.9kiB/s
2023-09-25 17:53:30 [Relaychain] ✨ Imported #17447293 (0xc9eb…3802)
2023-09-25 17:53:31 [🌗] ⏩ Warping, Importing state, 25618.16 Mib (22 peers), best: #0 (0xfe58…b76d), finalized #0 (0xfe58…b76d), ⬇ 28.6kiB/s ⬆ 51 B/s
2023-09-25 17:53:34 [Relaychain] ⏩ Block history, #13656512 (14 peers), best: #17447293 (0xc9eb…3802), finalized #17447289 (0x8253…39b3), ⬇ 29.5MiB/s ⬆ 74.3kiB/s
2023-09-25 17:53:36 [🌗] ⏩ Warping, Importing state, 25618.16 Mib (22 peers), best: #0 (0xfe58…b76d), finalized #0 (0xfe58…b76d), ⬇ 38.6kiB/s ⬆ 32 B/s
2023-09-25 17:53:36 [Relaychain] ✨ Imported #17447294 (0xa87c…dfcf)
2023-09-25 17:53:39 [Relaychain] ⏩ Block history, #13662720 (15 peers), best: #17447294 (0xa87c…dfcf), finalized #17447289 (0x8253…39b3), ⬇ 39.7MiB/s ⬆ 333.3kiB/s
zsh: killed     ./target/release/moonbeam --base-path=/tmp/moonbeam-warp-test --chain moonbea

As a result of this issue, the Warp Sync process on Moonbeam could not be completed successfully.

Memory Usage