'tokio-runtime-worker' panicked at 'implicit issuance...after checking group membership of issuer'

[Anastasiia-Khab]

Is there an existing issue?

• I have searched the existing issues

Experiencing problems? Have you tried our Stack Exchange first?

• This is not a support question.

Description of bug

Noticed node failure at Kusama network with a Bug report:

Version: 1.15.1
0: sp_panic_handler::set::{{closure}}
1: std::panicking::rust_panic_with_hook
2: std::panicking::begin_panic_handler::{{closure}}
3: std::sys_common::backtrace::__rust_end_short_backtrace
4: rust_begin_unwind
5: core::panicking::panic_fmt
6: polkadot_statement_table::generic::Table::validity_vote
7: polkadot_node_core_backing::import_statement::{{closure}}
8: polkadot_node_core_backing::sign_import_and_distribute_statement::{{closure}}
9: polkadot_node_core_backing::run_iteration::{{closure}}
10: <polkadot_node_core_backing::CandidateBackingSubsystem as orchestra::Subsystem<Context,polkadot_node_subsystem_types::errors::SubsystemError>>::start::{{closure}}
11: polkadot_overseer::spawn::{{closure}}
12: <tracing_futures::Instrumented as core::future::future::Future>::poll
13: tokio::runtime::task::raw::poll
14: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
15: tokio::runtime::scheduler::multi_thread::worker::run
16: tokio::runtime::task::raw::poll
17: std::sys_common::backtrace::__rust_begin_short_backtrace
18: core::ops::function::FnOnce::call_once{{vtable.shim}}
19: std::sys::pal::unix::thread::Thread::new::thread_start
20: start_thread
21: __clone3
Thread 'tokio-runtime-worker' panicked at 'implicit issuance vote only cast from import_candidate after checking group membership of issuer; qed', /builds/polkadot/statement-table/src/generic.rs:480
This is a bug. Please report it at:
https://github.com/paritytech/polkadot-sdk/issues/new

Steps to reproduce

No response

[sandreim]

Thanks for the report @Anastasiia-Khab . Can you share more details ?

• logs
• does this happens repeatedly, or it happened only once ?

[eskimor]

Panic fixed here ... we should really not panic on this. Still to be investigated, why it triggered in the first place. My guess would be import of valid before seconded.

[Anastasiia-Khab]

@sandreim

• last logs before bug report :
  2024.08.20 16:27:54 👶 New epoch 41445 launching at block 0xeba5…00de (block slot 287360679 >= start slot 287360679).
  2024.08.20 16:27:54 👶 Next epoch starts at slot 287361279
  2024.08.20 16:27:55 🏆 Imported #24564481 (0x2ac6…0a7a → 0xeba5…00de)
  2024.08.20 16:27:55 Node uses the following topology indices XXX
  2024.08.20 16:27:55 💤 Idle (XX peers), best: #24564481 (0xeba5…00de), finalized #24564477 (0x83df…240c), ⬇ XXMiB/s ⬆ XXMiB/s

• does this happens repeatedly, or it happened only once ?
  happened only once

[alindima]

more logs would certainly help, but I see you weren't running with parachain=debug.

After some thought and research I think it's caused by this:

In statement distribution, we fetch a candidate and its statements via req-response.
After we get a response, we check that each statement is signed by a validator belonging to a group that is assigned to the paraid.
But there may be multiple groups assigned to the paraid (scheduled on multiple cores).
And we don't check that they're all the same. So when importing the statements in backing, we get some statements signed by validators in group A and some signed by validators in group B.
This would make sense to only happen on kusama as polkadot does not have coretime
see here:

polkadot-sdk/polkadot/node/network/statement-distribution/src/v2/mod.rs

Line 3144 in 717bbb2

expected_groups.iter().any(|g| g == &g_index)

and kusama has some parachains with multiple scheduled cores

This logic was added in #3879

I'll try to reproduce locally to see if this is indeed the root-cause