search

OpenZeppelin / polkadot-runtime-templates

Runtime Templates for Polkadot Parachains
GNU General Public License v3.0
59 stars 17 forks source link

🐞 [Bug]: Aura panics with `Slot must increase` #134

Open ozgunozerk opened 5 months ago

ozgunozerk commented 5 months ago

What happened?

We bootstrapped a custom experimental relay chain, and then registered a new parachain to it.

Steps to reproduce for creating a new parachain can be found here: https://github.com/KitHat/sub0-oz-workshop/

When the nodes for parachain starts (Alice and Bob in this case) the following happens:

  1. starts syncing
  2. finishes syncing
  3. starts producing blocks
  4. Error is printed to CLI: Thread 'tokio-runtime-worker' panicked at 'Slot must increase', /Users/ozgunozerk/.cargo/git/checkouts/polkadot-sdk-cff69157b985ed76/2fe3145/substrate/frame/aura/src/lib.rs:139 (details can be found below)
  5. node does not crash, and continues to produce blocks, everything works as if nothing is wrong

Below is the detailed logs:

2024-03-07 15:21:00 [Parachain] 🎁 Prepared block for proposing at 1 (10 ms) [hash: 0x36cc7723f8596d0c7d71edec712333a885081489d945d1f6faf77963453df532; parent_hash: 0x6280…af9f; extrinsics (2): [0x3fe8…2e1c, 0x76e2…627e]
2024-03-07 15:21:00 [Parachain] 🔖 Pre-sealed block for proposal at 1. Hash now 0x85d8949ea424bb1851727c396b91864e212b46046e59997fa5f0b56cbd8edfff, previously 0x36cc7723f8596d0c7d71edec712333a885081489d945d1f6faf77963453df532.
2024-03-07 15:21:00 [Parachain] ✨ Imported #1 (0x85d8…dfff)
2024-03-07 15:21:00 [Parachain] PoV size { header: 0.2177734375kb, extrinsics: 3.1728515625kb, storage_proof: 2.2626953125kb }
2024-03-07 15:21:00 [Parachain] Compressed PoV size: 4.7470703125kb
2024-03-07 15:21:04 [Relaychain] 💤 Idle (3 peers), best: #177 (0xee41…7c56), finalized #175 (0xbe24…988e), ⬇ 1.8kiB/s ⬆ 2.4kiB/s
2024-03-07 15:21:04 [Parachain] 💤 Idle (1 peers), best: #1 (0x85d8…dfff), finalized #0 (0x6280…af9f), ⬇ 0.2kiB/s ⬆ 0.9kiB/s
2024-03-07 15:21:04 [Relaychain] Trying to remove unknown reserved node 12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm from SetId(3).
2024-03-07 15:21:06 [Relaychain] ✨ Imported #178 (0x2a01…73c6)
2024-03-07 15:21:06 [Parachain] 🙌 Starting consensus session on top of parent 0x85d8949ea424bb1851727c396b91864e212b46046e59997fa5f0b56cbd8edfff

====================

Version: 0.1.2-26778e090f2

   0: backtrace::capture::Backtrace::new
   1: sp_panic_handler::set::{{closure}}
   2: std::panicking::rust_panic_with_hook
   3: std::panicking::begin_panic_handler::{{closure}}
   4: std::sys_common::backtrace::__rust_end_short_backtrace
   5: _rust_begin_unwind
   6: core::panicking::panic_fmt
   7: <pallet_aura::pallet::Pallet<T> as frame_support::traits::hooks::OnInitialize<<<<T as frame_system::pallet::Config>::Block as sp_runtime::traits::HeaderProvider>::HeaderT as sp_runtime::traits::Header>::Number>>::on_initialize
   8: <(TupleElement0,TupleElement1,TupleElement2,TupleElement3,TupleElement4,TupleElement5,TupleElement6,TupleElement7,TupleElement8,TupleElement9,TupleElement10,TupleElement11,TupleElement12,TupleElement13,TupleElement14,TupleElement15,TupleElement16,TupleElement17,TupleElement18,TupleElement19,TupleElement20,TupleElement21,TupleElement22,TupleElement23,TupleElement24,TupleElement25,TupleElement26) as frame_support::traits::hooks::OnInitialize<BlockNumber>>::on_initialize
   9: frame_executive::Executive<System,Block,Context,UnsignedValidator,AllPalletsWithSystem,COnRuntimeUpgrade>::initialize_block
  10: parachain_template_runtime::api::dispatch
  11: environmental::using
  12: sc_executor::executor::WasmExecutor<H>::with_instance::{{closure}}
  13: sc_executor::wasm_runtime::RuntimeCache::with_instance
  14: <sc_executor::executor::NativeElseWasmExecutor<D> as sp_core::traits::CodeExecutor>::call
  15: sp_state_machine::execution::StateMachine<B,H,Exec>::execute
  16: <sc_service::client::call_executor::LocalCallExecutor<Block,B,E> as sc_client_api::call_executor::CallExecutor<Block>>::contextual_call
  17: <sc_service::client::client::Client<B,E,Block,RA> as sp_api::CallApiAt<Block>>::call_api_at
  18: <parachain_template_runtime::RuntimeApiImpl<__SrApiBlock__,RuntimeApiImplCall> as sp_api::Core<__SrApiBlock__>>::__runtime_api_internal_call_api_at::{{closure}}
  19: <parachain_template_runtime::RuntimeApiImpl<__SrApiBlock__,RuntimeApiImplCall> as sp_consensus_aura::AuraApi<__SrApiBlock__,sp_consensus_aura::sr25519::app_sr25519::Public>>::__runtime_api_internal_call_api_at
  20: sc_block_builder::BlockBuilderBuilderStage2<B,C>::build
  21: <sc_basic_authorship::basic_authorship::Proposer<Block,C,A,PR> as sp_consensus::Proposer<Block>>::propose::{{closure}}
  22: <sc_service::task_manager::prometheus_future::PrometheusFuture<T> as core::future::future::Future>::poll
  23: <tracing_futures::Instrumented<T> as core::future::future::Future>::poll
  24: tokio::runtime::park::CachedParkThread::block_on
  25: tokio::runtime::context::runtime::enter_runtime
  26: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
  27: tokio::runtime::task::core::Core<T,S>::poll
  28: tokio::runtime::task::harness::Harness<T,S>::poll
  29: tokio::runtime::blocking::pool::Inner::run
  30: std::sys_common::backtrace::__rust_begin_short_backtrace
  31: core::ops::function::FnOnce::call_once{{vtable.shim}}
  32: std::sys::pal::unix::thread::Thread::new::thread_start
  33: __pthread_joiner_wake

Thread 'tokio-runtime-worker' panicked at 'Slot must increase', /Users/ozgunozerk/.cargo/git/checkouts/polkadot-sdk-cff69157b985ed76/2fe3145/substrate/frame/aura/src/lib.rs:139

This is a bug. Please report it at:

    https://github.com/paritytech/polkadot-sdk/issues/new

2024-03-07 15:21:06 [Parachain] Evicting failed runtime instance error=Runtime panicked: Slot must increase
2024-03-07 15:21:06 [Parachain] err=Error { inner: Proposing

Caused by:
    0: Error at calling runtime api: Execution failed: Runtime panicked: Slot must increase
    1: Execution failed: Runtime panicked: Slot must increase }
2024-03-07 15:21:09 [Relaychain] 💤 Idle (3 peers), best: #178 (0x2a01…73c6), finalized #175 (0xbe24…988e), ⬇ 1.8kiB/s ⬆ 0.8kiB/s
2024-03-07 15:21:09 [Parachain] 💤 Idle (1 peers), best: #1 (0x85d8…dfff), finalized #0 (0x6280…af9f), ⬇ 0.2kiB/s ⬆ 0.2kiB/s
2024-03-07 15:21:13 [Relaychain] ✨ Imported #179 (0x6982…185c)
2024-03-07 15:21:14 [Relaychain] 💤 Idle (3 peers), best: #179 (0x6982…185c), finalized #177 (0xee41…7c56), ⬇ 1.4kiB/s ⬆ 1.0kiB/s
2024-03-07 15:21:14 [Parachain] 💤 Idle (1 peers), best: #1 (0x85d8…dfff), finalized #0 (0x6280…af9f), ⬇ 0.1kiB/s ⬆ 59 B/s

platform

Expected behavior

This error should not be present

Contribution Guidelines

ozgunozerk commented 5 months ago

As additional notes:

and the code piece that causes the error is from lib.rs of aura pallet:

#[pallet::hooks]
impl<T: Config> Hooks<BlockNumberFor<T>> for Pallet<T> {
fn on_initialize(_: BlockNumberFor<T>) -> Weight {
    if let Some(new_slot) = Self::current_slot_from_digests() {
        let current_slot = CurrentSlot::<T>::get();

        if T::AllowMultipleBlocksPerSlot::get() {
            assert!(current_slot <= new_slot, "Slot must not decrease");
        } else {
            assert!(current_slot < new_slot, "Slot must increase");  // THIS LINE CAUSES THE ERROR
        }

        CurrentSlot::<T>::put(new_slot);

        if let Some(n_authorities) = <Authorities<T>>::decode_len() {
            let authority_index = *new_slot % n_authorities as u64;
            if T::DisabledValidators::is_disabled(authority_index as u32) {
                panic!(
                    "Validator with index {:?} is disabled and should not be attempting to author blocks.",
                    authority_index,
                );
            }
        }

        // TODO [#3398] Generate offence report for all authorities that skipped their
        // slots.

        T::DbWeight::get().reads_writes(2, 1)
    } else {
        T::DbWeight::get().reads(1)
    }
}