paritytech / subport

Parity Substrate(-based) chains usage and development support
https://docs.substrate.io
Apache License 2.0
83 stars 13 forks source link

[Parachain] panicked at 'set_validation_data inherent needs to be present in every block!' #565

Closed jasl closed 8 months ago

jasl commented 1 year ago

Hi, I'm from Phala team, and I'm ops that help run our test chain on Rococo.

Recently our Rococo parachain (id 2004) has reset, but when I reset our collators, I see

2023-05-19 07:44:30 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
2023-05-19 07:44:30 [Parachain] ❗️ Inherent extrinsic returned unexpected error: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
WASM backtrace:
error while executing at wasm backtrace:
    0: 0xdb58 - <unknown>!rust_begin_unwind
    1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
    2: 0x48a9 - <unknown>!core::panicking::assert_failed_inner::h1a6ac086000721c4
    3: 0x2def62 - <unknown>!core::panicking::assert_failed::hec18c5791ee19ff1
    4: 0x2d7a64 - <unknown>!frame_support::storage::transactional::with_storage_layer::{{closure}}::h2a1bbe9a54d2b22a
    5: 0xda13c - <unknown>!<cumulus_pallet_parachain_system::pallet::Call<T> as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::{{closure}}::hd33d9c7e55085077
    6: 0xbb5d6 - <unknown>!frame_support::dispatch_context::run_in_context::h64566a6420d6e18d
    7: 0xb8281 - <unknown>!<rhala_parachain_runtime::RuntimeCall as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::h51488b29e1dbf71a
    8: 0xb7e4c - <unknown>!<rhala_parachain_runtime::RuntimeCall as sp_runtime::traits::Dispatchable>::dispatch::h4a761d7252db175b
    9: 0x3dff2d - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::apply_extrinsic::h1033aef8f6a2d819
   10: 0x40911d - <unknown>!BlockBuilder_apply_extrinsic. Dropping.
2023-05-19 07:44:30 [Parachain] panicked at 'set_validation_data inherent needs to be present in every block!', /Users/jasl/.cargo/git/checkouts/cumulus-59522f43471fa161/ae4e75b/pallets/parachain-system/src/lib.rs:208:13
2023-05-19 07:44:30 [Parachain] Proposing failed: Import failed: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
WASM backtrace:
error while executing at wasm backtrace:
    0: 0xdb58 - <unknown>!rust_begin_unwind
    1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
    2: 0x3e12b3 - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::idle_and_finalize_hook::hfd60303e0a5d5a18
    3: 0x409665 - <unknown>!BlockBuilder_finalize_block

Collators are unable to produce any block.

I've searched StackExchange, I see https://substrate.stackexchange.com/questions/5400/failure-on-hrmp-channel-creation the error pointed to HRMP, I've checked our artifact, and I can confirm the parachain config in genesis is correct.

I wonder if the previously retired chain configurations on Rococo were not cleaned properly.

Could you help?

al3mart commented 1 year ago

We can definitely help, could you please add some more info from those logs ? It seems to be the very same issue than the one you have linked, but I would like to see some previous messages from that log to confirm.

jasl commented 1 year ago

We can definitely help, could you please add some more info from those logs ? It seems to be the very same issue than the one you have linked, but I would like to see some previous messages from that log to confirm.

Sorry, I missed the message.

the full story is we requested to reset our parachain, I wiped out and ran our collators using new chain spec, after the new parachain was onboarded, the collators are starting to produce new blocks as expected, but they keep failing with that panic.

The full log

2023-05-19 07:43:30 [Parachain] 🏷  Local node identity is: 12D3KooWBWRKL8ynHrP3gBnXYDVJHjECGyb5sRfY1bECymVKJ88c
2023-05-19 07:43:30 [Parachain] 💻 Operating system: linux
2023-05-19 07:43:30 [Parachain] 💻 CPU architecture: x86_64
2023-05-19 07:43:30 [Parachain] 💻 Target environment: gnu
2023-05-19 07:43:30 [Parachain] 💻 CPU: Intel(R) Xeon(R) CPU @ 2.20GHz
2023-05-19 07:43:30 [Parachain] 💻 CPU cores: 4
2023-05-19 07:43:30 [Parachain] 💻 Memory: 15997MB
2023-05-19 07:43:30 [Parachain] 💻 Kernel: 5.15.0-1032-gcp
2023-05-19 07:43:30 [Parachain] 💻 Linux distribution: Ubuntu 20.04.6 LTS
2023-05-19 07:43:30 [Parachain] 💻 Virtual machine: yes
2023-05-19 07:43:30 [Parachain] 📦 Highest known block at #0
2023-05-19 07:43:30 [Parachain] Running JSON-RPC HTTP server: addr=127.0.0.1:9133, allowed origins=["*"]
2023-05-19 07:43:30 [Parachain] Running JSON-RPC WS server: addr=127.0.0.1:9144, allowed origins=["*"]
2023-05-19 07:43:30 [Parachain] 🏁 CPU score: 834.35 MiBs
2023-05-19 07:43:30 [Parachain] 🏁 Memory score: 4.19 GiBs
2023-05-19 07:43:30 [Parachain] 🏁 Disk score (seq. writes): 443.26 MiBs
2023-05-19 07:43:30 [Parachain] 🏁 Disk score (rand. writes): 104.63 MiBs
2023-05-19 07:43:30 [Parachain] 〽️ Prometheus exporter started at 0.0.0.0:19615
2023-05-19 07:43:30 [Relaychain] discovered: 12D3KooWGQYQijhLZNAqDggmJJH41qhbcfnqQSsJbWD6EeFkmaUa /ip4/10.172.0.6/tcp/30334/ws
2023-05-19 07:43:30 [Relaychain] discovered: 12D3KooWBWRKL8ynHrP3gBnXYDVJHjECGyb5sRfY1bECymVKJ88c /ip4/10.172.0.6/tcp/31333
2023-05-19 07:43:30 [Parachain] discovered: 12D3KooWGQYQijhLZNAqDggmJJH41qhbcfnqQSsJbWD6EeFkmaUa /ip4/10.172.0.6/tcp/30334/ws
2023-05-19 07:43:31 [Parachain] discovered: 12D3KooWEadQGT1cpnLz36SKuBCcdx3U3VJULbuWb5idAHJYqXkH /ip4/10.172.0.6/tcp/32333
2023-05-19 07:43:31 [Relaychain] discovered: 12D3KooWEadQGT1cpnLz36SKuBCcdx3U3VJULbuWb5idAHJYqXkH /ip4/10.172.0.6/tcp/32333
2023-05-19 07:43:32 [Parachain] discovered: 12D3KooWEymQcYHWgaZxctn7oZPWPfVyAesCqPmFNGgGV6WFB77W /ip4/10.172.0.6/tcp/33333
2023-05-19 07:43:32 [Relaychain] discovered: 12D3KooWEymQcYHWgaZxctn7oZPWPfVyAesCqPmFNGgGV6WFB77W /ip4/10.172.0.6/tcp/33333
2023-05-19 07:43:34 [Relaychain] Received finalized block via RPC: #5454500 (0x4962…26e6 -> 0x920d…1e56)
2023-05-19 07:43:35 [Parachain] 💤 Idle (2 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 2.6kiB/s ⬆ 2.4kiB/s
2023-05-19 07:43:36 [Relaychain] Received imported block via RPC: #5454503 (0x6d7c…94c4 -> 0x8ede…8bd7)
2023-05-19 07:43:36 [Parachain] Starting collation. relay_parent=0x8ede90d58402ed210e9e20cc6f10a3fa40244d295431c4d32ddb24f5d25f8bd7 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:43:38 [Relaychain] Received finalized block via RPC: #5454501 (0x920d…1e56 -> 0x0dfe…12f6)
2023-05-19 07:43:40 [Parachain] 💤 Idle (2 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0.3kiB/s ⬆ 0.4kiB/s
2023-05-19 07:43:42 [Relaychain] Received imported block via RPC: #5454504 (0x8ede…8bd7 -> 0xc3b9…763e)
2023-05-19 07:43:42 [Parachain] Starting collation. relay_parent=0xc3b95cf7785de82e16be03e0374601ba5c0d772b1e89de637e8b168fd424763e at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:43:45 [Parachain] 💤 Idle (2 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0 ⬆ 0
2023-05-19 07:43:46 [Relaychain] Received finalized block via RPC: #5454502 (0x0dfe…12f6 -> 0x6d7c…94c4)
2023-05-19 07:43:48 [Relaychain] Received imported block via RPC: #5454505 (0xc3b9…763e -> 0x35f1…6080)
2023-05-19 07:43:48 [Parachain] Starting collation. relay_parent=0x35f155622d1f0a332305c07c5a9b5f504192cae43d0e03d9f48b081c44866080 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:43:48 [Relaychain] Received imported block via RPC: #5454505 (0xc3b9…763e -> 0x83f9…c956)
2023-05-19 07:43:48 [Parachain] Starting collation. relay_parent=0x83f916b9bcecdb08f27e674a84086d2d40111546d47eaaea45dca3a211d8c956 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:43:50 [Parachain] 💤 Idle (2 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0.4kiB/s ⬆ 0.4kiB/s
2023-05-19 07:43:50 [Relaychain] Received finalized block via RPC: #5454503 (0x6d7c…94c4 -> 0x8ede…8bd7)
2023-05-19 07:43:54 [Relaychain] Received imported block via RPC: #5454506 (0x35f1…6080 -> 0x770b…7ceb)
2023-05-19 07:43:54 [Parachain] Starting collation. relay_parent=0x770baba6d3c6cf18a6cfe8342da75888aa9914c82c7252c72a1e6fa205aa7ceb at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:43:55 [Parachain] 💤 Idle (2 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0 ⬆ 0
2023-05-19 07:43:58 [Relaychain] Received finalized block via RPC: #5454504 (0x8ede…8bd7 -> 0xc3b9…763e)
2023-05-19 07:44:00 [Relaychain] Received imported block via RPC: #5454507 (0x770b…7ceb -> 0x1d04…8deb)
2023-05-19 07:44:00 [Parachain] Starting collation. relay_parent=0x1d04048200aa697511ed54ba92d2efe538178cd9c4f7f550bff3218184d38deb at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:00 [Relaychain] Received imported block via RPC: #5454507 (0x770b…7ceb -> 0x8500…ce00)
2023-05-19 07:44:00 [Parachain] Starting collation. relay_parent=0x85001c922a532165cacf6acf103204d509949ca163c90d505bc44dd617aace00 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:00 [Parachain] 💤 Idle (2 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0 ⬆ 0
2023-05-19 07:44:02 [Relaychain] Received finalized block via RPC: #5454505 (0xc3b9…763e -> 0x35f1…6080)
2023-05-19 07:44:05 [Parachain] 💤 Idle (1 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0.5kiB/s ⬆ 0.5kiB/s
2023-05-19 07:44:06 [Relaychain] Received imported block via RPC: #5454508 (0x8500…ce00 -> 0x6c0d…76d6)
2023-05-19 07:44:06 [Parachain] Starting collation. relay_parent=0x6c0ded4632ea2b7bda2d3b9d6c50b38e90b134c4a6b0ef66e9dd3378a6c476d6 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:10 [Parachain] 💤 Idle (2 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0.4kiB/s ⬆ 0.4kiB/s
2023-05-19 07:44:10 [Relaychain] Received finalized block via RPC: #5454506 (0x35f1…6080 -> 0x770b…7ceb)
2023-05-19 07:44:12 [Relaychain] Received imported block via RPC: #5454509 (0x6c0d…76d6 -> 0x7844…f770)
2023-05-19 07:44:12 [Parachain] Starting collation. relay_parent=0x784443222f1686c5e2acc444a10494c2c2e71991e9bb5ac0e5b1dbd6d324f770 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:12 [Relaychain] Received imported block via RPC: #5454509 (0x6c0d…76d6 -> 0x4640…25d5)
2023-05-19 07:44:12 [Parachain] Starting collation. relay_parent=0x4640595a224ff331649abad0c603676920b897f2503e47a0e7c646a98f1325d5 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:14 [Relaychain] Received finalized block via RPC: #5454507 (0x770b…7ceb -> 0x8500…ce00)
2023-05-19 07:44:15 [Parachain] 💤 Idle (2 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0 ⬆ 0
2023-05-19 07:44:18 [Relaychain] Received imported block via RPC: #5454510 (0x7844…f770 -> 0x69cb…d586)
2023-05-19 07:44:18 [Parachain] Starting collation. relay_parent=0x69cbaba10ce3c837a5328e064cd737cc593a902eecb8a8210f2f0a3c6a84d586 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:20 [Parachain] 💤 Idle (2 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0.1kiB/s ⬆ 0.1kiB/s
2023-05-19 07:44:22 Accepting new connection 1/100
2023-05-19 07:44:22 [Relaychain] Received finalized block via RPC: #5454508 (0x8500…ce00 -> 0x6c0d…76d6)
2023-05-19 07:44:24 [Relaychain] Received imported block via RPC: #5454511 (0x69cb…d586 -> 0xda71…3157)
2023-05-19 07:44:24 [Parachain] Starting collation. relay_parent=0xda71de02d68e5e9380bd9d7e5a3953be440da08f7a4b02532aee591b06df3157 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:24 [Parachain] 🙌 Starting consensus session on top of parent 0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:24 [Parachain] panicked at 'assertion failed: `(left == right)`
  left: `0x0000000000000000000000000000000000000000000000000000000000000000`,
 right: `0x9855a7552b177d2fee219570facc5301b731258f98083d27afa9e4db681ac82b`', /Users/jasl/.cargo/git/checkouts/cumulus-59522f43471fa161/ae4e75b/pallets/parachain-system/src/lib.rs:861:9
2023-05-19 07:44:24 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
2023-05-19 07:44:24 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
2023-05-19 07:44:24 [Parachain] ❗️ Inherent extrinsic returned unexpected error: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
WASM backtrace:
error while executing at wasm backtrace:
    0: 0xdb58 - <unknown>!rust_begin_unwind
    1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
    2: 0x48a9 - <unknown>!core::panicking::assert_failed_inner::h1a6ac086000721c4
    3: 0x2def62 - <unknown>!core::panicking::assert_failed::hec18c5791ee19ff1
    4: 0x2d7a64 - <unknown>!frame_support::storage::transactional::with_storage_layer::{{closure}}::h2a1bbe9a54d2b22a
    5: 0xda13c - <unknown>!<cumulus_pallet_parachain_system::pallet::Call<T> as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::{{closure}}::hd33d9c7e55085077
    6: 0xbb5d6 - <unknown>!frame_support::dispatch_context::run_in_context::h64566a6420d6e18d
    7: 0xb8281 - <unknown>!<rhala_parachain_runtime::RuntimeCall as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::h51488b29e1dbf71a
    8: 0xb7e4c - <unknown>!<rhala_parachain_runtime::RuntimeCall as sp_runtime::traits::Dispatchable>::dispatch::h4a761d7252db175b
    9: 0x3dff2d - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::apply_extrinsic::h1033aef8f6a2d819
   10: 0x40911d - <unknown>!BlockBuilder_apply_extrinsic. Dropping.
2023-05-19 07:44:24 [Parachain] panicked at 'set_validation_data inherent needs to be present in every block!', /Users/jasl/.cargo/git/checkouts/cumulus-59522f43471fa161/ae4e75b/pallets/parachain-system/src/lib.rs:208:13
2023-05-19 07:44:24 [Parachain] Proposing failed: Import failed: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
WASM backtrace:
error while executing at wasm backtrace:
    0: 0xdb58 - <unknown>!rust_begin_unwind
    1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
    2: 0x3e12b3 - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::idle_and_finalize_hook::hfd60303e0a5d5a18
    3: 0x409665 - <unknown>!BlockBuilder_finalize_block
2023-05-19 07:44:24 [Relaychain] Received imported block via RPC: #5454511 (0x69cb…d586 -> 0x9e9a…a947)
2023-05-19 07:44:24 [Parachain] Starting collation. relay_parent=0x9e9a3b4bde8f9879106b5e55261174a7a5f60df9fd554c66575ce62089c1a947 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:24 [Parachain] 🙌 Starting consensus session on top of parent 0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:24 [Parachain] panicked at 'assertion failed: `(left == right)`
  left: `0x0000000000000000000000000000000000000000000000000000000000000000`,
 right: `0x9855a7552b177d2fee219570facc5301b731258f98083d27afa9e4db681ac82b`', /Users/jasl/.cargo/git/checkouts/cumulus-59522f43471fa161/ae4e75b/pallets/parachain-system/src/lib.rs:861:9
2023-05-19 07:44:24 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
2023-05-19 07:44:24 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
2023-05-19 07:44:24 [Parachain] ❗️ Inherent extrinsic returned unexpected error: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
WASM backtrace:
error while executing at wasm backtrace:
    0: 0xdb58 - <unknown>!rust_begin_unwind
    1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
    2: 0x48a9 - <unknown>!core::panicking::assert_failed_inner::h1a6ac086000721c4
    3: 0x2def62 - <unknown>!core::panicking::assert_failed::hec18c5791ee19ff1
    4: 0x2d7a64 - <unknown>!frame_support::storage::transactional::with_storage_layer::{{closure}}::h2a1bbe9a54d2b22a
    5: 0xda13c - <unknown>!<cumulus_pallet_parachain_system::pallet::Call<T> as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::{{closure}}::hd33d9c7e55085077
    6: 0xbb5d6 - <unknown>!frame_support::dispatch_context::run_in_context::h64566a6420d6e18d
    7: 0xb8281 - <unknown>!<rhala_parachain_runtime::RuntimeCall as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::h51488b29e1dbf71a
    8: 0xb7e4c - <unknown>!<rhala_parachain_runtime::RuntimeCall as sp_runtime::traits::Dispatchable>::dispatch::h4a761d7252db175b
    9: 0x3dff2d - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::apply_extrinsic::h1033aef8f6a2d819
   10: 0x40911d - <unknown>!BlockBuilder_apply_extrinsic. Dropping.
2023-05-19 07:44:24 [Parachain] panicked at 'set_validation_data inherent needs to be present in every block!', /Users/jasl/.cargo/git/checkouts/cumulus-59522f43471fa161/ae4e75b/pallets/parachain-system/src/lib.rs:208:13
2023-05-19 07:44:24 [Parachain] Proposing failed: Import failed: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
WASM backtrace:
error while executing at wasm backtrace:
    0: 0xdb58 - <unknown>!rust_begin_unwind
    1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
    2: 0x3e12b3 - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::idle_and_finalize_hook::hfd60303e0a5d5a18
    3: 0x409665 - <unknown>!BlockBuilder_finalize_block
2023-05-19 07:44:25 [Parachain] 💤 Idle (2 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0 ⬆ 0
2023-05-19 07:44:26 [Relaychain] Received finalized block via RPC: #5454509 (0x6c0d…76d6 -> 0x7844…f770)
2023-05-19 07:44:30 [Relaychain] Received imported block via RPC: #5454512 (0xda71…3157 -> 0xd19f…2aa1)
2023-05-19 07:44:30 [Parachain] Starting collation. relay_parent=0xd19f1f37c42752a89e9c062771ddc5f290af77dd0bd245268233386ea1e52aa1 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:30 [Parachain] 🙌 Starting consensus session on top of parent 0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:30 [Parachain] panicked at 'assertion failed: `(left == right)`
  left: `0x0000000000000000000000000000000000000000000000000000000000000000`,
 right: `0x9855a7552b177d2fee219570facc5301b731258f98083d27afa9e4db681ac82b`', /Users/jasl/.cargo/git/checkouts/cumulus-59522f43471fa161/ae4e75b/pallets/parachain-system/src/lib.rs:861:9
2023-05-19 07:44:30 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
2023-05-19 07:44:30 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
2023-05-19 07:44:30 [Parachain] ❗️ Inherent extrinsic returned unexpected error: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
WASM backtrace:
error while executing at wasm backtrace:
    0: 0xdb58 - <unknown>!rust_begin_unwind
    1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
    2: 0x48a9 - <unknown>!core::panicking::assert_failed_inner::h1a6ac086000721c4
    3: 0x2def62 - <unknown>!core::panicking::assert_failed::hec18c5791ee19ff1
    4: 0x2d7a64 - <unknown>!frame_support::storage::transactional::with_storage_layer::{{closure}}::h2a1bbe9a54d2b22a
    5: 0xda13c - <unknown>!<cumulus_pallet_parachain_system::pallet::Call<T> as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::{{closure}}::hd33d9c7e55085077
    6: 0xbb5d6 - <unknown>!frame_support::dispatch_context::run_in_context::h64566a6420d6e18d
    7: 0xb8281 - <unknown>!<rhala_parachain_runtime::RuntimeCall as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::h51488b29e1dbf71a
    8: 0xb7e4c - <unknown>!<rhala_parachain_runtime::RuntimeCall as sp_runtime::traits::Dispatchable>::dispatch::h4a761d7252db175b
    9: 0x3dff2d - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::apply_extrinsic::h1033aef8f6a2d819
   10: 0x40911d - <unknown>!BlockBuilder_apply_extrinsic. Dropping.
2023-05-19 07:44:30 [Parachain] panicked at 'set_validation_data inherent needs to be present in every block!', /Users/jasl/.cargo/git/checkouts/cumulus-59522f43471fa161/ae4e75b/pallets/parachain-system/src/lib.rs:208:13
2023-05-19 07:44:30 [Parachain] Proposing failed: Import failed: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
WASM backtrace:
error while executing at wasm backtrace:
    0: 0xdb58 - <unknown>!rust_begin_unwind
    1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
    2: 0x3e12b3 - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::idle_and_finalize_hook::hfd60303e0a5d5a18
    3: 0x409665 - <unknown>!BlockBuilder_finalize_block
2023-05-19 07:44:30 [Relaychain] Received imported block via RPC: #5454512 (0xda71…3157 -> 0xeee6…84ac)
2023-05-19 07:44:30 [Parachain] Starting collation. relay_parent=0xeee63f8f8a79f7088e6d97a9b920fc3a446514442000e6737858481ebc7984ac at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:30 [Parachain] 🙌 Starting consensus session on top of parent 0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
2023-05-19 07:44:30 [Parachain] panicked at 'assertion failed: `(left == right)`
  left: `0x0000000000000000000000000000000000000000000000000000000000000000`,
 right: `0x9855a7552b177d2fee219570facc5301b731258f98083d27afa9e4db681ac82b`', /Users/jasl/.cargo/git/checkouts/cumulus-59522f43471fa161/ae4e75b/pallets/parachain-system/src/lib.rs:861:9
2023-05-19 07:44:30 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
2023-05-19 07:44:30 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
2023-05-19 07:44:30 [Parachain] ❗️ Inherent extrinsic returned unexpected error: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
WASM backtrace:
error while executing at wasm backtrace:
    0: 0xdb58 - <unknown>!rust_begin_unwind
    1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
    2: 0x48a9 - <unknown>!core::panicking::assert_failed_inner::h1a6ac086000721c4
    3: 0x2def62 - <unknown>!core::panicking::assert_failed::hec18c5791ee19ff1
    4: 0x2d7a64 - <unknown>!frame_support::storage::transactional::with_storage_layer::{{closure}}::h2a1bbe9a54d2b22a
    5: 0xda13c - <unknown>!<cumulus_pallet_parachain_system::pallet::Call<T> as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::{{closure}}::hd33d9c7e55085077
    6: 0xbb5d6 - <unknown>!frame_support::dispatch_context::run_in_context::h64566a6420d6e18d
    7: 0xb8281 - <unknown>!<rhala_parachain_runtime::RuntimeCall as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::h51488b29e1dbf71a
    8: 0xb7e4c - <unknown>!<rhala_parachain_runtime::RuntimeCall as sp_runtime::traits::Dispatchable>::dispatch::h4a761d7252db175b
    9: 0x3dff2d - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::apply_extrinsic::h1033aef8f6a2d819
   10: 0x40911d - <unknown>!BlockBuilder_apply_extrinsic. Dropping.
2023-05-19 07:44:30 [Parachain] panicked at 'set_validation_data inherent needs to be present in every block!', /Users/jasl/.cargo/git/checkouts/cumulus-59522f43471fa161/ae4e75b/pallets/parachain-system/src/lib.rs:208:13
2023-05-19 07:44:30 [Parachain] Proposing failed: Import failed: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
WASM backtrace:
error while executing at wasm backtrace:
    0: 0xdb58 - <unknown>!rust_begin_unwind
    1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
    2: 0x3e12b3 - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::idle_and_finalize_hook::hfd60303e0a5d5a18
    3: 0x409665 - <unknown>!BlockBuilder_finalize_block
2023-05-19 07:44:30 [Parachain] 💤 Idle (2 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0 ⬆ 0
2023-05-19 07:44:34 [Relaychain] Received finalized block via RPC: #5454510 (0x7844…f770 -> 0x69cb…d586)
2023-05-19 07:44:35 [Parachain] 💤 Idle (1 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 0.3kiB/s ⬆ 0.3kiB/s
2023-05-19 07:44:36 [Relaychain] Received imported block via RPC: #5454513 (0xeee6…84ac -> 0x0182…c516)
2023-05-19 07:44:36 [Parachain] Starting collation. relay_parent=0x01822755b51813a6f464e545c8b5d2b359d1d9d1da803fbe5e58b0a53f0bc516 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
tolak commented 1 year ago

Hey @al3mart, can you help take a look

al3mart commented 1 year ago

I have now addressed this, let me know how is this looking on your end.

jasl commented 1 year ago

I have now addressed this, let me know how is this looking on your end.

Thank you for your help!

image

it seems we're upgrading, I'll check later

jasl commented 1 year ago

I have now addressed this, let me know how is this looking on your end.

Sorry, it sill not working

Jun 06 23:16:11 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:11 [Relaychain] Received finalized block via RPC: #5722545 (0x5999…9708 -> 0xa62e…35b1)
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:12 [Relaychain] Received imported block via RPC: #5722548 (0xce65…4693 -> 0x8c6b…d961)
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:12 [Parachain] Starting collation. relay_parent=0x8c6b9cd0d3244e48bb2f6311fba95795b1f34c466ce98a7dcf4f64df4af1d961 at=0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:12 [Parachain] 🙌 Starting consensus session on top of parent 0x2c0c4eaa199decaf7410c4764a7f88e17eaa04a188b0d025397a15839cb4b6bf
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:12 [Parachain] panicked at 'assertion failed: cur_head == target_head', /Users/jasl/.cargo/git/checkouts/cumulus-59522f43471fa161/ae4e75b/pallets/parachain-system/src/lib.rs:951:13
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:12 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:12 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:12 [Parachain] ❗️ Inherent extrinsic returned unexpected error: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: WASM backtrace:
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: error while executing at wasm backtrace:
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     0: 0xdb58 - <unknown>!rust_begin_unwind
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     2: 0x5176 - <unknown>!core::panicking::panic::h9d83f98931297560
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     3: 0x2d72a8 - <unknown>!frame_support::storage::transactional::with_storage_layer::{{closure}}::h2a1bbe9a54d2b22a
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     4: 0xda13c - <unknown>!<cumulus_pallet_parachain_system::pallet::Call<T> as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::{{closure}}::hd33d9c7e55085077
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     5: 0xbb5d6 - <unknown>!frame_support::dispatch_context::run_in_context::h64566a6420d6e18d
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     6: 0xb8281 - <unknown>!<rhala_parachain_runtime::RuntimeCall as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::h51488b29e1dbf71a
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     7: 0xb7e4c - <unknown>!<rhala_parachain_runtime::RuntimeCall as sp_runtime::traits::Dispatchable>::dispatch::h4a761d7252db175b
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     8: 0x3dff2d - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::apply_extrinsic::h1033aef8f6a2d819
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     9: 0x40911d - <unknown>!BlockBuilder_apply_extrinsic. Dropping.
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:12 [Parachain] panicked at 'set_validation_data inherent needs to be present in every block!', /Users/jasl/.cargo/git/checkouts/cumulus-59522f43471fa161/ae4e75b/pallets/parachain-system/src/lib.rs:208:13
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:12 [Parachain] Proposing failed: Import failed: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: WASM backtrace:
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]: error while executing at wasm backtrace:
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     0: 0xdb58 - <unknown>!rust_begin_unwind
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     1: 0x24f8 - <unknown>!core::panicking::panic_fmt::h7092d1cb502f4977
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     2: 0x3e12b3 - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::idle_and_finalize_hook::hfd60303e0a5d5a18
Jun 06 23:16:12 rhala-collators-eu collator_1.sh[546671]:     3: 0x409665 - <unknown>!BlockBuilder_finalize_block
Jun 06 23:16:14 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:14 [Parachain] 💤 Idle (3 peers), best: #0 (0x2c0c…b6bf), finalized #0 (0x2c0c…b6bf), ⬇ 5.6kiB/s ⬆ 5.2kiB/s
Jun 06 23:16:15 rhala-collators-eu collator_1.sh[546671]: 2023-06-06 23:16:15 [Relaychain] Received finalized block via RPC: #5722546 (0xa62e…35b1 -> 0x6b58…295d)
decentration commented 1 year ago

I am having the same issue.

I ran paras > forceScheduleCodeUpgrade(para, newCode, relayParentNumber) from the Rococo relay (polkadot-v0.9.38) the parachain is a statemine fork (polkadot-v0.9.37). The collator stopped, then after restarting:

Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]: 2023-06-30 08:36:06 [Parachain] panicked at 'No new validation function found in storage, GoAhead signal is not expected', /root/cumulus/pallets/parachain-system/src/lib.rs:380:21
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]: 2023-06-30 08:36:06 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]: 2023-06-30 08:36:06 [Parachain] 1 storage transactions are left open by the runtime. Those will be rolled back.
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]: 2023-06-30 08:36:06 [Parachain] ❗️ Inherent extrinsic returned unexpected error: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]: WASM backtrace:
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]:     0: 0x3bb60 - <unknown>!rust_begin_unwind
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]:     1: 0x4167 - <unknown>!core::panicking::panic_fmt::hca80ede79c2b9c5b
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]:     2: 0x255f28 - <unknown>!frame_support::storage::transactional::with_storage_layer::h8b26525a68f96a54
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]:     3: 0xa10a2 - <unknown>!<cumulus_pallet_parachain_system::pallet::Call<T> as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::h577c4e23c817381d
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]:     4: 0x94ab1 - <unknown>!<statemine_runtime::RuntimeCall as frame_support::traits::dispatch::UnfilteredDispatchable>::dispatch_bypass_filter::h986c9db5d2845126
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]:     5: 0x94928 - <unknown>!<statemine_runtime::RuntimeCall as sp_runtime::traits::Dispatchable>::dispatch::hb2c67c0915dcebf5
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]:     6: 0x14f5de - <unknown>!<sp_runtime::generic::checked_extrinsic::CheckedExtrinsic<AccountId,Call,Extra> as sp_runtime::traits::Applyable>::apply::h8d14f3200225f9f3
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]:     7: 0xa8c99 - <unknown>!frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::apply_extrinsic::hea3645bbf9812dac
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]:     8: 0x187da7 - <unknown>!BlockBuilder_apply_extrinsic
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]: . Dropping.
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]: 2023-06-30 08:36:06 [Parachain] panicked at 'set_validation_data inherent needs to be present in every block!', /root/cumulus/pallets/parachain-system/src/lib.rs:192:13
Jun 30 08:36:06 ubuntu-s-kabocha-01-1627404188468-s-2vcpu-4gb-intel-lon1-01 polkadot-parachain[2402338]: 2023-06-30 08:36:06 [Parachain] Proposing failed: Import failed: Error at calling runtime api: Execution failed: Execution aborted due to trap: wasm trap: wasm `unreachable` instruction executed
decentration commented 1 year ago

I have now addressed this, let me know how is this looking on your end.

hey @al3mart can you explain how you addressed it? Cheers.

jasl commented 1 year ago

For our team, I'm working on upgrading to polkadot-v0.9.43 and planning to rebuild a new runtime

al3mart commented 1 year ago

Hey @jasl your last issue should be solved now, could you please check and report back what does the state look like now ? Thanks

al3mart commented 1 year ago

@decentration Heyo, so Jasl scenario was that they had some mismatching state between the relaychain and what the collators were expecting due to these changes of validation function and state that we do on the fly in Rococo using forceSetCurrentCode and forceSetCurrentHead extrinsics.

panicked at 'No new validation function found in storage, GoAhead signal is not expected', /root/cumulus/pallets/parachain-system/src/lib.rs:380:21

Based on this line of your logs you might have hit something similar to this issue: https://github.com/paritytech/polkadot-sdk/issues/641

jasl commented 1 year ago

Hey @jasl your last issue should be solved now, could you please check and report back what does the state look like now ? Thanks

I restart collators, and it shows

[Relaychain] Collation wasn't advertised to any validator. candidate_hash=0xc5324c68c228171424e982815475cfd21305230caf0db48c8f85a2a1e0debaec pov_hash=0xe1379f8e2245ed76c07149102c8d6519fdb6cedb33f189951824fe47c8b093ec traceID=262119079775502505278069161933902565330

Do I need to delete the collators data and re-start them?

al3mart commented 1 year ago

This shouldn't be related to the previous issues. Do you have peers on the relay side ? Maybe some trace logs for parachain::collator-protocol and parachain::validator-discovery could give us some hints.

jasl commented 1 year ago

This shouldn't be related to the previous issues. Do you have peers on the relay side ? Maybe some trace logs for parachain::collator-protocol and parachain::validator-discovery could give us some hints.

Thank you! I'll dig into it later.

I'm working on polkadot-v0.9.43. If it's hard to resolve, I'll regenerate a new runtime for onboard

al3mart commented 8 months ago

@jasl Can we close this ?