search

webb-tools / dkg-substrate

Multy-party threshold ECDSA (GG20) Substrate node
https://tangle.webb.tools/
GNU General Public License v3.0
59 stars 15 forks source link

[BUG] Panic!!! `bad gamma_i decommit` #356

Closed shekohex closed 1 year ago

shekohex commented 2 years ago

Describe the bug

DKG Collator Node panics with the following log:

2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(5)))
2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec
2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg_gadget::async_protocols::state_machine_wrapper: Trying to proceed: round 1, blame: (0, [])

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

Version: 3.0.0-43e26320a02

   0: sp_panic_handler::set::{{closure}}
   1: std::panicking::rust_panic_with_hook
             at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/std/src/panicking.rs:702:17
   2: std::panicking::begin_panic_handler::{{closure}}
             at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/std/src/panicking.rs:588:13
   3: std::sys_common::backtrace::__rust_end_short_backtrace
             at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/std/src/sys_common/backtrace.rs:138:18
   4: rust_begin_unwind
             at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/std/src/panicking.rs:584:5
   5: core::panicking::panic_fmt
             at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/core/src/panicking.rs:142:14
   6: core::result::unwrap_failed
             at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/core/src/result.rs:1785:5
   7: multi_party_ecdsa::protocols::multi_party_ecdsa::gg_2020::state_machine::sign::rounds::Round4::proceed
   8: multi_party_ecdsa::protocols::multi_party_ecdsa::gg_2020::state_machine::sign::OfflineStage::proceed_round
   9: multi_party_ecdsa::protocols::multi_party_ecdsa::gg_2020::state_machine::sign::OfflineStage::proceed_round
  10: multi_party_ecdsa::protocols::multi_party_ecdsa::gg_2020::state_machine::sign::OfflineStage::proceed_round
  11: multi_party_ecdsa::protocols::multi_party_ecdsa::gg_2020::state_machine::sign::OfflineStage::proceed_round
  12: <multi_party_ecdsa::protocols::multi_party_ecdsa::gg_2020::state_machine::sign::OfflineStage as round_based::sm::StateMachine>::proceed
  13: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
  14: tokio::runtime::task::core::CoreStage<T>::poll
  15: tokio::runtime::task::harness::Harness<T,S>::poll
  16: tokio::runtime::blocking::pool::Inner::run
  17: std::sys_common::backtrace::__rust_begin_short_backtrace
  18: core::ops::function::FnOnce::call_once{{vtable.shim}}
  19: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/alloc/src/boxed.rs:1866:9
      <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/alloc/src/boxed.rs:1866:9
      std::sys::unix::thread::Thread::new::thread_start
             at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/std/src/sys/unix/thread.rs:108:17
  20: <unknown>
  21: clone

Thread 'tokio-runtime-worker' panicked at ': ErrorType { error_type: "bad gamma_i decommit", bad_actors: [1], data: [] }', /home/shady/.cargo/git/checkouts/multi-party-ecdsa-7313a766cbf184c8/90bba30/src/protocols/multi_party_ecdsa/gg_2020/state_machine/sign/rounds.rs:423

To Reproduce Steps to reproduce the behavior:

  1. Run the Parachain following the docs we have, or using the scripts (scripts/run-parachain.ts)
  2. Wait until first session ends, and after the first rotation it looks like it fails around block 160

Log output

Log Output ```log 2022-08-29 13:14:48.312 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #158 (0xbf7f…e33c) 2022-08-29 13:14:48.312 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Import notification 2022-08-29 13:14:48.312 DEBUG tokio-runtime-worker dkg: [Parachain] 🕸️ Processing block notification for block 158 2022-08-29 13:14:48.312 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is now: 158 2022-08-29 13:14:48.313 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Status: Atomic(Terminated), Now: 158, Started At: 40, Timeout length: 10 2022-08-29 13:14:48.313 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ QUEUED DKG STALLED: round 2 2022-08-29 13:14:48.313 ERROR tokio-runtime-worker dkg_gadget::worker: [Parachain] Received error: KeygenTimeout { bad_actors: [2] } 2022-08-29 13:14:48.313 INFO tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ DKG Keygen misbehaviour by KWCeb4NPQGSgNZVaumUCh1Rdui1xXPJjRhamMBpmaMqHSuBei 2022-08-29 13:14:48.313 INFO tokio-runtime-worker dkg: [Parachain] [drop code] MetaAsyncProtocol is ending: Terminated 2022-08-29 13:14:48.313 INFO tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ IN THE SET OF BEST AUTHORITIES: round 1 2022-08-29 13:14:48.949 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #157 (0xe55c…e3fc), finalized #155 (0xd7ff…aeef), ⬇ 0.9kiB/s ⬆ 0.2kiB/s 2022-08-29 13:14:48.965 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #361 (0x8d9d…94a9), finalized #358 (0x556e…2b6e), ⬇ 1.6kiB/s ⬆ 0.7kiB/s 2022-08-29 13:14:53.949 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #157 (0xe55c…e3fc), finalized #155 (0xd7ff…aeef), ⬇ 0 ⬆ 0 2022-08-29 13:14:53.966 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #361 (0x8d9d…94a9), finalized #358 (0x556e…2b6e), ⬇ 0.3kiB/s ⬆ 0.2kiB/s 2022-08-29 13:14:54.014 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #362 (0x52cb…0bac) 2022-08-29 13:14:54.015 INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0x52cb58b9d6eea4a1127c51b2b1143281c7da9a82e0f2715161401caaca380bac at=0xe55c4508015a5058b6931cde40b2a4ac4fd20c86de552c6cdb5edec4a816e3fc 2022-08-29 13:14:54.309 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Import notification 2022-08-29 13:14:54.309 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #158 (0x874b…9aed) 2022-08-29 13:14:54.309 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is greater than or equal to current header, returning... 2022-08-29 13:14:56.619 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Finality notification 2022-08-29 13:14:56.619 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is greater than or equal to current header, returning... 2022-08-29 13:14:58.950 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #157 (0xe55c…e3fc), finalized #156 (0x1aa4…809d), ⬇ 0.9kiB/s ⬆ 0.2kiB/s 2022-08-29 13:14:58.967 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #362 (0x52cb…0bac), finalized #359 (0x7dd3…64f9), ⬇ 1.0kiB/s ⬆ 0.5kiB/s 2022-08-29 13:15:00.015 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #363 (0x0a40…048f) 2022-08-29 13:15:03.950 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #157 (0xe55c…e3fc), finalized #156 (0x1aa4…809d), ⬇ 0.2kiB/s ⬆ 84 B/s 2022-08-29 13:15:03.968 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #363 (0x0a40…048f), finalized #359 (0x7dd3…64f9), ⬇ 0.8kiB/s ⬆ 0.3kiB/s 2022-08-29 13:15:04.620 INFO tokio-runtime-worker afg: [Relaychain] 👴 Applying authority set change scheduled at block #361 2022-08-29 13:15:04.620 INFO tokio-runtime-worker afg: [Relaychain] 👴 Applying GRANDPA set change to new set [(Public(88dc3417d5058ec4b4503e0c12ea1a0a89be200fe98922423d4334014fa6b0ee (5FA9nQDV...)), 1), (Public(d17c2d7823ebf260fd138f2d7e27d114c0145d968b5ff5006125f2414fadae69 (5GoNkf6W...)), 1)] 2022-08-29 13:15:04.622 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Finality notification 2022-08-29 13:15:04.622 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is greater than or equal to current header, returning... 2022-08-29 13:15:06.013 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #364 (0x6d25…198b) 2022-08-29 13:15:06.014 INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0x6d25217b3e856c2e9e201211672e24b2826ff9ccabd2cec30baa98946fa8198b at=0x874bc01a319fc8847bf311c8b249e295ea31defbaffbdd84b24733cc64039aed 2022-08-29 13:15:06.014 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Import notification 2022-08-29 13:15:06.014 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is greater than or equal to current header, returning... 2022-08-29 13:15:06.015 INFO offchain-worker pallet_dkg_metadata::pallet: DKG Metadata : Hello World from offchain workers! 2022-08-29 13:15:06.015 DEBUG offchain-worker runtime::dkg_metadata: offchain worker triggered 2022-08-29 13:15:06.015 DEBUG offchain-worker runtime::dkg_metadata: submit_genesis_public_key_onchain : Err("Already submitted a key in this session") 2022-08-29 13:15:06.015 DEBUG offchain-worker runtime::dkg_metadata: agg_keys is None 2022-08-29 13:15:06.015 DEBUG offchain-worker runtime::dkg_metadata: submit_next_public_key_onchain : Ok(()) 2022-08-29 13:15:06.015 DEBUG offchain-worker runtime::dkg_metadata: submit_public_key_signature_onchain : Ok(()) 2022-08-29 13:15:06.015 DEBUG offchain-worker runtime::dkg_metadata: submit_misbehaviour_reports_onchain : Ok(()) 2022-08-29 13:15:06.015 INFO offchain-worker pallet_dkg_proposal_handler::pallet: DKG Proposal Handler : Hello World from offchain workers! 2022-08-29 13:15:06.015 DEBUG offchain-worker runtime::dkg_proposal_handler: Offchain signed proposals: [] 2022-08-29 13:15:06.015 DEBUG offchain-worker runtime::dkg_proposal_handler: Offchain signed proposals left: 0 2022-08-29 13:15:06.015 WARN offchain-worker runtime::dkg_proposal_handler: Failed to get next signed proposal: Unable to get next proposal batch 2022-08-29 13:15:06.015 DEBUG offchain-worker runtime::dkg_proposal_handler: offchain worker result: Ok(()) 2022-08-29 13:15:06.306 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #159 (0x8941…f99b) 2022-08-29 13:15:06.306 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Import notification 2022-08-29 13:15:06.306 DEBUG tokio-runtime-worker dkg: [Parachain] 🕸️ Processing block notification for block 159 2022-08-29 13:15:06.306 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is now: 159 2022-08-29 13:15:06.307 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Status: Atomic(Terminated), Now: 159, Started At: 40, Timeout length: 10 2022-08-29 13:15:06.307 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ QUEUED DKG STALLED: round 2 2022-08-29 13:15:06.307 ERROR tokio-runtime-worker dkg_gadget::worker: [Parachain] Received error: KeygenTimeout { bad_actors: [2] } 2022-08-29 13:15:06.307 INFO tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ DKG Keygen misbehaviour by KWCeb4NPQGSgNZVaumUCh1Rdui1xXPJjRhamMBpmaMqHSuBei 2022-08-29 13:15:06.307 INFO tokio-runtime-worker dkg: [Parachain] [drop code] MetaAsyncProtocol is ending: Terminated 2022-08-29 13:15:06.307 INFO tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ IN THE SET OF BEST AUTHORITIES: round 1 2022-08-29 13:15:08.951 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #158 (0x874b…9aed), finalized #157 (0xe55c…e3fc), ⬇ 0.8kiB/s ⬆ 0.2kiB/s 2022-08-29 13:15:08.969 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #364 (0x6d25…198b), finalized #361 (0x8d9d…94a9), ⬇ 0.7kiB/s ⬆ 0.4kiB/s 2022-08-29 13:15:12.015 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #365 (0xb6a0…fe99) 2022-08-29 13:15:13.952 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #158 (0x874b…9aed), finalized #157 (0xe55c…e3fc), ⬇ 54 B/s ⬆ 94 B/s 2022-08-29 13:15:13.970 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #365 (0xb6a0…fe99), finalized #362 (0x52cb…0bac), ⬇ 0.7kiB/s ⬆ 0.3kiB/s 2022-08-29 13:15:18.014 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #366 (0xd38a…e262) 2022-08-29 13:15:18.015 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Import notification 2022-08-29 13:15:18.015 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is greater than or equal to current header, returning... 2022-08-29 13:15:18.015 INFO offchain-worker pallet_dkg_metadata::pallet: DKG Metadata : Hello World from offchain workers! 2022-08-29 13:15:18.015 DEBUG offchain-worker runtime::dkg_metadata: offchain worker triggered 2022-08-29 13:15:18.015 DEBUG offchain-worker runtime::dkg_metadata: submit_genesis_public_key_onchain : Err("Already submitted a key in this session") 2022-08-29 13:15:18.015 DEBUG offchain-worker runtime::dkg_metadata: agg_keys is None 2022-08-29 13:15:18.015 DEBUG offchain-worker runtime::dkg_metadata: submit_next_public_key_onchain : Ok(()) 2022-08-29 13:15:18.015 DEBUG offchain-worker runtime::dkg_metadata: submit_public_key_signature_onchain : Ok(()) 2022-08-29 13:15:18.015 DEBUG offchain-worker runtime::dkg_metadata: submit_misbehaviour_reports_onchain : Ok(()) 2022-08-29 13:15:18.015 INFO offchain-worker pallet_dkg_proposal_handler::pallet: DKG Proposal Handler : Hello World from offchain workers! 2022-08-29 13:15:18.016 DEBUG offchain-worker runtime::dkg_proposal_handler: Offchain signed proposals: [] 2022-08-29 13:15:18.016 DEBUG offchain-worker runtime::dkg_proposal_handler: Offchain signed proposals left: 0 2022-08-29 13:15:18.016 WARN offchain-worker runtime::dkg_proposal_handler: Failed to get next signed proposal: Unable to get next proposal batch 2022-08-29 13:15:18.016 DEBUG offchain-worker runtime::dkg_proposal_handler: offchain worker result: Ok(()) 2022-08-29 13:15:18.952 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #159 (0x8941…f99b), finalized #157 (0xe55c…e3fc), ⬇ 24 B/s ⬆ 21 B/s 2022-08-29 13:15:18.970 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #366 (0xd38a…e262), finalized #362 (0x52cb…0bac), ⬇ 0.7kiB/s ⬆ 0.3kiB/s 2022-08-29 13:15:23.953 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #159 (0x8941…f99b), finalized #157 (0xe55c…e3fc), ⬇ 0 ⬆ 0 2022-08-29 13:15:23.971 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #366 (0xd38a…e262), finalized #363 (0x0a40…048f), ⬇ 0.3kiB/s ⬆ 0.2kiB/s 2022-08-29 13:15:24.014 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #367 (0xda7a…e76b) 2022-08-29 13:15:24.016 INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0xda7a5c64ffe32de8dd716068b7ba2d8b979435107be86725fafdf97c5483e76b at=0x8941de9f356653ea550a80311f4dc29355ca2ddde61220a86aac3dfd83d5f99b 2022-08-29 13:15:24.071 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 from gossiping 2022-08-29 13:15:24.071 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 @ block 159, 2022-08-29 13:15:24.071 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: NEW DKG MESSAGE FROM 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 2022-08-29 13:15:24.071 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Message sent to 1 DKG controller listeners 2022-08-29 13:15:24.071 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: [Parachain] Streaming message from the Gossip Engine (is okay? true) 2022-08-29 13:15:24.071 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle dkg message for round 1 2022-08-29 13:15:24.071 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er from gossiping 2022-08-29 13:15:24.071 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er @ block 159, 2022-08-29 13:15:24.071 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: OLD DKG MESSAGE FROM 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er 2022-08-29 13:15:24.071 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(4))) 2022-08-29 13:15:24.071 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec 2022-08-29 13:15:24.321 INFO tokio-runtime-worker pallet_collator_selection::pallet: [Parachain] assembling new collators for new session 5 at #160 2022-08-29 13:15:24.323 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #160 (0xb33f…e1b3) 2022-08-29 13:15:24.323 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Import notification 2022-08-29 13:15:24.323 DEBUG tokio-runtime-worker dkg: [Parachain] 🕸️ Processing block notification for block 160 2022-08-29 13:15:24.323 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is now: 160 2022-08-29 13:15:24.323 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Status: Atomic(Terminated), Now: 160, Started At: 40, Timeout length: 10 2022-08-29 13:15:24.323 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ QUEUED DKG STALLED: round 2 2022-08-29 13:15:24.323 ERROR tokio-runtime-worker dkg_gadget::worker: [Parachain] Received error: KeygenTimeout { bad_actors: [2] } 2022-08-29 13:15:24.324 INFO tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ DKG Keygen misbehaviour by KWCeb4NPQGSgNZVaumUCh1Rdui1xXPJjRhamMBpmaMqHSuBei 2022-08-29 13:15:24.324 INFO tokio-runtime-worker dkg: [Parachain] [drop code] MetaAsyncProtocol is ending: Terminated 2022-08-29 13:15:24.324 INFO tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ IN THE SET OF BEST AUTHORITIES: round 1 2022-08-29 13:15:24.324 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Got unsigned proposals count 1 2022-08-29 13:15:24.328 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Generating 1 signing sets 2022-08-29 13:15:24.328 INFO tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Round Id 1 | Async index 0 | 1-out-of-2 signers: ({1, 2}) 2022-08-29 13:15:24.331 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Starting signing protocol 2022-08-29 13:15:24.331 INFO tokio-runtime-worker dkg: [Parachain] [drop code] MetaAsyncProtocol is ending: OfflineAndVoting 2022-08-29 13:15:24.331 INFO tokio-runtime-worker dkg: [drop code] MetaAsyncProtocol is ending: Terminated 2022-08-29 13:15:24.331 INFO tokio-runtime-worker dkg: Stopper has been called Some(()) 2022-08-29 13:15:24.331 INFO tokio-runtime-worker dkg_gadget::worker: The meta handler has executed successfully 2022-08-29 13:15:24.331 INFO tokio-runtime-worker dkg_gadget::worker: *** SUCCESSFULLY EXECUTED meta signing protocol 0 *** 2022-08-29 13:15:24.331 DEBUG tokio-runtime-worker dkg: Got unsigned proposals count 1 2022-08-29 13:15:24.331 INFO tokio-runtime-worker dkg: Offline stage index: 1 2022-08-29 13:15:24.332 DEBUG tokio-runtime-worker dkg_gadget::async_protocols::state_machine_wrapper: Trying to proceed: round 0, blame: (0, []) 2022-08-29 13:15:24.370 DEBUG tokio-runtime-worker dkg_gadget::async_protocols::state_machine_wrapper: Proceeded Offline: (i, proposal) = (1, Unsigned { kind: ProposerSetUpdate, data: [51, 1, 163, 50, 177, 50, 37, 128, 239, 37, 96, 128, 236, 199, 139, 186, 245, 237, 135, 107, 7, 109, 93, 9, 191, 26, 98, 220, 243, 12, 205, 43, 0, 0, 0, 0, 0, 3, 169, 128, 0, 0, 0, 3, 0, 0, 0, 5] }): round 1, blame: (1, [2]) 2022-08-29 13:15:24.370 INFO tokio-runtime-worker dkg: Async proto sent outbound request on node=1 to: None |(ty: Offline: (i, proposal) = (1, Unsigned { kind: ProposerSetUpdate, data: [51, 1, 163, 50, 177, 50, 37, 128, 239, 37, 96, 128, 236, 199, 139, 186, 245, 237, 135, 107, 7, 109, 93, 9, 191, 26, 98, 220, 243, 12, 205, 43, 0, 0, 0, 0, 0, 3, 169, 128, 0, 0, 0, 3, 0, 0, 0, 5] })) 2022-08-29 13:15:24.370 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(5))) 2022-08-29 13:15:24.370 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec 2022-08-29 13:15:24.371 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Sending message to all peers 2022-08-29 13:15:24.371 INFO tokio-runtime-worker dkg: 🕸️ Async proto sent outbound message: Offline: (i, proposal) = (1, Unsigned { kind: ProposerSetUpdate, data: [51, 1, 163, 50, 177, 50, 37, 128, 239, 37, 96, 128, 236, 199, 139, 186, 245, 237, 135, 107, 7, 109, 93, 9, 191, 26, 98, 220, 243, 12, 205, 43, 0, 0, 0, 0, 0, 3, 169, 128, 0, 0, 0, 3, 0, 0, 0, 5] }) 2022-08-29 13:15:24.472 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 from gossiping 2022-08-29 13:15:24.472 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 @ block 160, 2022-08-29 13:15:24.472 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: NEW DKG MESSAGE FROM 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 2022-08-29 13:15:24.472 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Message sent to 1 DKG controller listeners 2022-08-29 13:15:24.472 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: [Parachain] Streaming message from the Gossip Engine (is okay? true) 2022-08-29 13:15:24.472 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle dkg message for round 1 2022-08-29 13:15:24.472 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er from gossiping 2022-08-29 13:15:24.472 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er @ block 160, 2022-08-29 13:15:24.472 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: OLD DKG MESSAGE FROM 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er 2022-08-29 13:15:24.472 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(5))) 2022-08-29 13:15:24.472 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec 2022-08-29 13:15:28.632 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Finality notification 2022-08-29 13:15:28.632 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is greater than or equal to current header, returning... 2022-08-29 13:15:28.954 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #159 (0x8941…f99b), finalized #158 (0x874b…9aed), ⬇ 6.9kiB/s ⬆ 6.7kiB/s 2022-08-29 13:15:28.972 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #367 (0xda7a…e76b), finalized #365 (0xb6a0…fe99), ⬇ 0.7kiB/s ⬆ 0.5kiB/s 2022-08-29 13:15:30.016 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #368 (0x6217…5c16) 2022-08-29 13:15:33.954 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #159 (0x8941…f99b), finalized #158 (0x874b…9aed), ⬇ 24 B/s ⬆ 24 B/s 2022-08-29 13:15:33.973 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #368 (0x6217…5c16), finalized #365 (0xb6a0…fe99), ⬇ 0.8kiB/s ⬆ 0.4kiB/s 2022-08-29 13:15:36.014 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #369 (0xe390…c220) 2022-08-29 13:15:36.015 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Import notification 2022-08-29 13:15:36.015 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is greater than or equal to current header, returning... 2022-08-29 13:15:36.016 INFO offchain-worker pallet_dkg_metadata::pallet: DKG Metadata : Hello World from offchain workers! 2022-08-29 13:15:36.016 DEBUG offchain-worker runtime::dkg_metadata: offchain worker triggered 2022-08-29 13:15:36.016 DEBUG offchain-worker runtime::dkg_metadata: submit_genesis_public_key_onchain : Err("Already submitted a key in this session") 2022-08-29 13:15:36.016 DEBUG offchain-worker runtime::dkg_metadata: agg_keys is None 2022-08-29 13:15:36.016 DEBUG offchain-worker runtime::dkg_metadata: submit_next_public_key_onchain : Ok(()) 2022-08-29 13:15:36.016 DEBUG offchain-worker runtime::dkg_metadata: submit_public_key_signature_onchain : Ok(()) 2022-08-29 13:15:36.016 DEBUG offchain-worker runtime::dkg_metadata: submit_misbehaviour_reports_onchain : Ok(()) 2022-08-29 13:15:36.016 INFO offchain-worker pallet_dkg_proposal_handler::pallet: DKG Proposal Handler : Hello World from offchain workers! 2022-08-29 13:15:36.016 DEBUG offchain-worker runtime::dkg_proposal_handler: Offchain signed proposals: [] 2022-08-29 13:15:36.016 DEBUG offchain-worker runtime::dkg_proposal_handler: Offchain signed proposals left: 0 2022-08-29 13:15:36.016 WARN offchain-worker runtime::dkg_proposal_handler: Failed to get next signed proposal: Unable to get next proposal batch 2022-08-29 13:15:36.016 DEBUG offchain-worker runtime::dkg_proposal_handler: offchain worker result: Ok(()) 2022-08-29 13:15:36.634 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Finality notification 2022-08-29 13:15:36.634 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is greater than or equal to current header, returning... 2022-08-29 13:15:38.955 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #160 (0xb33f…e1b3), finalized #159 (0x8941…f99b), ⬇ 29 B/s ⬆ 69 B/s 2022-08-29 13:15:38.973 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #369 (0xe390…c220), finalized #366 (0xd38a…e262), ⬇ 0.7kiB/s ⬆ 0.4kiB/s 2022-08-29 13:15:42.013 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #370 (0xfe1b…c41b) 2022-08-29 13:15:42.015 INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0xfe1bf3a71fb6752f39d7b2d42967c9230bea8529f6a11d129ddd501b77eec41b at=0xb33f493ac8af5d83f5eac680d74c5590fddb7df8607ed7245fa9827b9f0be1b3 2022-08-29 13:15:42.089 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 from gossiping 2022-08-29 13:15:42.089 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 @ block 160, 2022-08-29 13:15:42.089 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: NEW DKG MESSAGE FROM 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 2022-08-29 13:15:42.089 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Message sent to 1 DKG controller listeners 2022-08-29 13:15:42.089 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: [Parachain] Streaming message from the Gossip Engine (is okay? true) 2022-08-29 13:15:42.089 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle dkg message for round 1 2022-08-29 13:15:42.090 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er from gossiping 2022-08-29 13:15:42.090 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er @ block 160, 2022-08-29 13:15:42.090 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: OLD DKG MESSAGE FROM 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er 2022-08-29 13:15:42.090 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(5))) 2022-08-29 13:15:42.090 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec 2022-08-29 13:15:42.090 DEBUG tokio-runtime-worker dkg_gadget::async_protocols::state_machine_wrapper: Trying to proceed: round 1, blame: (0, []) 2022-08-29 13:15:42.185 DEBUG tokio-runtime-worker dkg_gadget::async_protocols::state_machine_wrapper: Proceeded Offline: (i, proposal) = (1, Unsigned { kind: ProposerSetUpdate, data: [51, 1, 163, 50, 177, 50, 37, 128, 239, 37, 96, 128, 236, 199, 139, 186, 245, 237, 135, 107, 7, 109, 93, 9, 191, 26, 98, 220, 243, 12, 205, 43, 0, 0, 0, 0, 0, 3, 169, 128, 0, 0, 0, 3, 0, 0, 0, 5] }): round 3, blame: (1, [2]) 2022-08-29 13:15:42.185 INFO tokio-runtime-worker dkg: Async proto sent outbound request on node=1 to: Some(2) |(ty: Offline: (i, proposal) = (1, Unsigned { kind: ProposerSetUpdate, data: [51, 1, 163, 50, 177, 50, 37, 128, 239, 37, 96, 128, 236, 199, 139, 186, 245, 237, 135, 107, 7, 109, 93, 9, 191, 26, 98, 220, 243, 12, 205, 43, 0, 0, 0, 0, 0, 3, 169, 128, 0, 0, 0, 3, 0, 0, 0, 5] })) 2022-08-29 13:15:42.185 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(5))) 2022-08-29 13:15:42.185 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec 2022-08-29 13:15:42.187 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Sending message to all peers 2022-08-29 13:15:42.187 INFO tokio-runtime-worker dkg: 🕸️ Async proto sent outbound message: Offline: (i, proposal) = (1, Unsigned { kind: ProposerSetUpdate, data: [51, 1, 163, 50, 177, 50, 37, 128, 239, 37, 96, 128, 236, 199, 139, 186, 245, 237, 135, 107, 7, 109, 93, 9, 191, 26, 98, 220, 243, 12, 205, 43, 0, 0, 0, 0, 0, 3, 169, 128, 0, 0, 0, 3, 0, 0, 0, 5] }) 2022-08-29 13:15:42.187 INFO tokio-runtime-worker dkg: Async proto sent outbound request on node=1 to: None |(ty: Offline: (i, proposal) = (1, Unsigned { kind: ProposerSetUpdate, data: [51, 1, 163, 50, 177, 50, 37, 128, 239, 37, 96, 128, 236, 199, 139, 186, 245, 237, 135, 107, 7, 109, 93, 9, 191, 26, 98, 220, 243, 12, 205, 43, 0, 0, 0, 0, 0, 3, 169, 128, 0, 0, 0, 3, 0, 0, 0, 5] })) 2022-08-29 13:15:42.187 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(5))) 2022-08-29 13:15:42.187 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec 2022-08-29 13:15:42.188 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Sending message to all peers 2022-08-29 13:15:42.188 INFO tokio-runtime-worker dkg: 🕸️ Async proto sent outbound message: Offline: (i, proposal) = (1, Unsigned { kind: ProposerSetUpdate, data: [51, 1, 163, 50, 177, 50, 37, 128, 239, 37, 96, 128, 236, 199, 139, 186, 245, 237, 135, 107, 7, 109, 93, 9, 191, 26, 98, 220, 243, 12, 205, 43, 0, 0, 0, 0, 0, 3, 169, 128, 0, 0, 0, 3, 0, 0, 0, 5] }) 2022-08-29 13:15:42.315 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #161 (0x52c4…c2e2) 2022-08-29 13:15:42.315 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Import notification 2022-08-29 13:15:42.315 DEBUG tokio-runtime-worker dkg: [Parachain] 🕸️ Processing block notification for block 161 2022-08-29 13:15:42.315 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is now: 161 2022-08-29 13:15:42.315 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Status: Atomic(Terminated), Now: 161, Started At: 40, Timeout length: 10 2022-08-29 13:15:42.315 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ QUEUED DKG STALLED: round 2 2022-08-29 13:15:42.315 ERROR tokio-runtime-worker dkg_gadget::worker: [Parachain] Received error: KeygenTimeout { bad_actors: [2] } 2022-08-29 13:15:42.315 INFO tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ DKG Keygen misbehaviour by KWCeb4NPQGSgNZVaumUCh1Rdui1xXPJjRhamMBpmaMqHSuBei 2022-08-29 13:15:42.315 INFO tokio-runtime-worker dkg: [Parachain] [drop code] MetaAsyncProtocol is ending: Terminated 2022-08-29 13:15:42.316 INFO tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ IN THE SET OF BEST AUTHORITIES: round 1 2022-08-29 13:15:42.316 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Got unsigned proposals count 1 2022-08-29 13:15:42.319 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Generating 1 signing sets 2022-08-29 13:15:42.319 INFO tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Round Id 1 | Async index 0 | 1-out-of-2 signers: ({1, 2}) 2022-08-29 13:15:42.323 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Starting signing protocol 2022-08-29 13:15:42.323 INFO tokio-runtime-worker dkg: [Parachain] [drop code] MetaAsyncProtocol is ending: OfflineAndVoting 2022-08-29 13:15:42.323 INFO tokio-runtime-worker dkg: [drop code] MetaAsyncProtocol is ending: Terminated 2022-08-29 13:15:42.323 INFO tokio-runtime-worker dkg: Stopper has been called Some(()) 2022-08-29 13:15:42.323 INFO tokio-runtime-worker dkg_gadget::worker: The meta handler has executed successfully 2022-08-29 13:15:42.323 INFO tokio-runtime-worker dkg_gadget::worker: *** SUCCESSFULLY EXECUTED meta signing protocol 0 *** 2022-08-29 13:15:42.323 DEBUG tokio-runtime-worker dkg: Got unsigned proposals count 1 2022-08-29 13:15:42.323 INFO tokio-runtime-worker dkg: Offline stage index: 1 2022-08-29 13:15:42.323 DEBUG tokio-runtime-worker dkg_gadget::async_protocols::state_machine_wrapper: Trying to proceed: round 0, blame: (0, []) 2022-08-29 13:15:42.383 DEBUG tokio-runtime-worker dkg_gadget::async_protocols::state_machine_wrapper: Proceeded Offline: (i, proposal) = (1, Unsigned { kind: ProposerSetUpdate, data: [51, 1, 163, 50, 177, 50, 37, 128, 239, 37, 96, 128, 236, 199, 139, 186, 245, 237, 135, 107, 7, 109, 93, 9, 191, 26, 98, 220, 243, 12, 205, 43, 0, 0, 0, 0, 0, 3, 169, 128, 0, 0, 0, 3, 0, 0, 0, 5] }): round 1, blame: (1, [2]) 2022-08-29 13:15:42.383 INFO tokio-runtime-worker dkg: Async proto sent outbound request on node=1 to: None |(ty: Offline: (i, proposal) = (1, Unsigned { kind: ProposerSetUpdate, data: [51, 1, 163, 50, 177, 50, 37, 128, 239, 37, 96, 128, 236, 199, 139, 186, 245, 237, 135, 107, 7, 109, 93, 9, 191, 26, 98, 220, 243, 12, 205, 43, 0, 0, 0, 0, 0, 3, 169, 128, 0, 0, 0, 3, 0, 0, 0, 5] })) 2022-08-29 13:15:42.383 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(5))) 2022-08-29 13:15:42.383 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec 2022-08-29 13:15:42.385 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Sending message to all peers 2022-08-29 13:15:42.385 INFO tokio-runtime-worker dkg: 🕸️ Async proto sent outbound message: Offline: (i, proposal) = (1, Unsigned { kind: ProposerSetUpdate, data: [51, 1, 163, 50, 177, 50, 37, 128, 239, 37, 96, 128, 236, 199, 139, 186, 245, 237, 135, 107, 7, 109, 93, 9, 191, 26, 98, 220, 243, 12, 205, 43, 0, 0, 0, 0, 0, 3, 169, 128, 0, 0, 0, 3, 0, 0, 0, 5] }) 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 from gossiping 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 @ block 161, 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: NEW DKG MESSAGE FROM 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Message sent to 1 DKG controller listeners 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 from gossiping 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 @ block 161, 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: NEW DKG MESSAGE FROM 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Message sent to 1 DKG controller listeners 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: [Parachain] Streaming message from the Gossip Engine (is okay? true) 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle dkg message for round 1 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 from gossiping 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: [Parachain] Streaming message from the Gossip Engine (is okay? true) 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle dkg message for round 1 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 @ block 161, 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: NEW DKG MESSAGE FROM 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Message sent to 1 DKG controller listeners 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: [Parachain] Streaming message from the Gossip Engine (is okay? true) 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle dkg message for round 1 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er from gossiping 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er @ block 161, 2022-08-29 13:15:42.479 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: OLD DKG MESSAGE FROM 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er from gossiping 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er @ block 161, 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: OLD DKG MESSAGE FROM 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er from gossiping 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er @ block 161, 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: OLD DKG MESSAGE FROM 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(5))) 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(5))) 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(5))) 2022-08-29 13:15:42.480 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec 2022-08-29 13:15:43.956 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #160 (0xb33f…e1b3), finalized #159 (0x8941…f99b), ⬇ 7.5kiB/s ⬆ 10.1kiB/s 2022-08-29 13:15:43.974 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #370 (0xfe1b…c41b), finalized #366 (0xd38a…e262), ⬇ 0.5kiB/s ⬆ 0.3kiB/s 2022-08-29 13:15:48.014 INFO tokio-runtime-worker babe: [Relaychain] 👶 New epoch 37 launching at block 0xb195…0a51 (block slot 276961958 >= start slot 276961958). 2022-08-29 13:15:48.014 INFO tokio-runtime-worker babe: [Relaychain] 👶 Next epoch starts at slot 276961968 2022-08-29 13:15:48.018 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #371 (0xb195…0a51) 2022-08-29 13:15:48.019 INFO tokio-runtime-worker parachain::approval-voting: [Relaychain] Advanced session window for approvals update=Advanced { prev_window_start: 31, prev_window_end: 36, new_window_start: 32, new_window_end: 37 } 2022-08-29 13:15:48.019 INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0xb1958077a2567d85cee78c37ecb8addef8ec59ebe246a3073cc6136592f70a51 at=0xb33f493ac8af5d83f5eac680d74c5590fddb7df8607ed7245fa9827b9f0be1b3 2022-08-29 13:15:48.324 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Import notification 2022-08-29 13:15:48.324 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #161 (0x4d02…549b) 2022-08-29 13:15:48.324 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is greater than or equal to current header, returning... 2022-08-29 13:15:48.956 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #160 (0xb33f…e1b3), finalized #159 (0x8941…f99b), ⬇ 0.9kiB/s ⬆ 0.2kiB/s 2022-08-29 13:15:48.975 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #371 (0xb195…0a51), finalized #367 (0xda7a…e76b), ⬇ 1.0kiB/s ⬆ 0.6kiB/s 2022-08-29 13:15:52.640 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Finality notification 2022-08-29 13:15:52.640 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is greater than or equal to current header, returning... 2022-08-29 13:15:53.957 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #160 (0xb33f…e1b3), finalized #160 (0xb33f…e1b3), ⬇ 0 ⬆ 0 2022-08-29 13:15:53.976 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #371 (0xb195…0a51), finalized #369 (0xe390…c220), ⬇ 0.2kiB/s ⬆ 0.2kiB/s 2022-08-29 13:15:54.014 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #372 (0xb7a2…95f2) 2022-08-29 13:15:54.018 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #372 (0x6b88…b359) 2022-08-29 13:15:58.957 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (2 peers), best: #160 (0xb33f…e1b3), finalized #160 (0xb33f…e1b3), ⬇ 24 B/s ⬆ 24 B/s 2022-08-29 13:15:58.976 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (2 peers), best: #372 (0xb7a2…95f2), finalized #369 (0xe390…c220), ⬇ 1.6kiB/s ⬆ 0.6kiB/s 2022-08-29 13:16:00.014 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #373 (0xce9e…8e9c) 2022-08-29 13:16:00.015 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle Import notification 2022-08-29 13:16:00.015 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] 🕸️ Latest header is greater than or equal to current header, returning... 2022-08-29 13:16:00.015 INFO offchain-worker pallet_dkg_metadata::pallet: DKG Metadata : Hello World from offchain workers! 2022-08-29 13:16:00.015 DEBUG offchain-worker runtime::dkg_metadata: offchain worker triggered 2022-08-29 13:16:00.015 INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0xce9e5b3cfb7043f98966fdd636b143e962113cfffe455a2d58fc5d64da698e9c at=0x4d029acf77d0d6649482ba79963d24b3953d37f6d23c3ea81be363a06c0a549b 2022-08-29 13:16:00.015 DEBUG offchain-worker runtime::dkg_metadata: submit_genesis_public_key_onchain : Err("Already submitted a key in this session") 2022-08-29 13:16:00.015 DEBUG offchain-worker runtime::dkg_metadata: agg_keys is None 2022-08-29 13:16:00.015 DEBUG offchain-worker runtime::dkg_metadata: submit_next_public_key_onchain : Ok(()) 2022-08-29 13:16:00.015 DEBUG offchain-worker runtime::dkg_metadata: submit_public_key_signature_onchain : Ok(()) 2022-08-29 13:16:00.015 DEBUG offchain-worker runtime::dkg_metadata: submit_misbehaviour_reports_onchain : Ok(()) 2022-08-29 13:16:00.015 INFO offchain-worker pallet_dkg_proposal_handler::pallet: DKG Proposal Handler : Hello World from offchain workers! 2022-08-29 13:16:00.015 DEBUG offchain-worker runtime::dkg_proposal_handler: Offchain signed proposals: [] 2022-08-29 13:16:00.015 DEBUG offchain-worker runtime::dkg_proposal_handler: Offchain signed proposals left: 0 2022-08-29 13:16:00.015 WARN offchain-worker runtime::dkg_proposal_handler: Failed to get next signed proposal: Unable to get next proposal batch 2022-08-29 13:16:00.015 DEBUG offchain-worker runtime::dkg_proposal_handler: offchain worker result: Ok(()) 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 from gossiping 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 @ block 161, 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: NEW DKG MESSAGE FROM 12D3KooWB8qBpGL55ngAAMS5dZvpSkZaKcbxX6in5StehVofx1k7 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Message sent to 1 DKG controller listeners 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: [Parachain] Streaming message from the Gossip Engine (is okay? true) 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg_gadget::worker: [Parachain] Going to handle dkg message for round 1 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: Received message from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er from gossiping 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg: ACTIVE round 1 | Received a signed DKG messages from 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er @ block 161, 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg_gadget::gossip_engine::network: OLD DKG MESSAGE FROM 12D3KooWC9ZBrwfVCZkj2mgEgBfgRgnDM5PsehksPF6wTPZEA1er 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg: Got unsigned proposal with key = (None, ProposerSetUpdateProposal(Nonce(5))) 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg: Adding unsigned proposal to hash vec 2022-08-29 13:16:00.080 DEBUG tokio-runtime-worker dkg_gadget::async_protocols::state_machine_wrapper: Trying to proceed: round 1, blame: (0, []) ==================== Version: 3.0.0-43e26320a02 0: sp_panic_handler::set::{{closure}} 1: std::panicking::rust_panic_with_hook at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/std/src/panicking.rs:702:17 2: std::panicking::begin_panic_handler::{{closure}} at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/std/src/panicking.rs:588:13 3: std::sys_common::backtrace::__rust_end_short_backtrace at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/std/src/sys_common/backtrace.rs:138:18 4: rust_begin_unwind at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/std/src/panicking.rs:584:5 5: core::panicking::panic_fmt at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/core/src/panicking.rs:142:14 6: core::result::unwrap_failed at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/core/src/result.rs:1785:5 7: multi_party_ecdsa::protocols::multi_party_ecdsa::gg_2020::state_machine::sign::rounds::Round4::proceed 8: multi_party_ecdsa::protocols::multi_party_ecdsa::gg_2020::state_machine::sign::OfflineStage::proceed_round 9: multi_party_ecdsa::protocols::multi_party_ecdsa::gg_2020::state_machine::sign::OfflineStage::proceed_round 10: multi_party_ecdsa::protocols::multi_party_ecdsa::gg_2020::state_machine::sign::OfflineStage::proceed_round 11: multi_party_ecdsa::protocols::multi_party_ecdsa::gg_2020::state_machine::sign::OfflineStage::proceed_round 12: ::proceed 13: as core::future::future::Future>::poll 14: tokio::runtime::task::core::CoreStage::poll 15: tokio::runtime::task::harness::Harness::poll 16: tokio::runtime::blocking::pool::Inner::run 17: std::sys_common::backtrace::__rust_begin_short_backtrace 18: core::ops::function::FnOnce::call_once{{vtable.shim}} 19: as core::ops::function::FnOnce>::call_once at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/alloc/src/boxed.rs:1866:9 as core::ops::function::FnOnce>::call_once at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/alloc/src/boxed.rs:1866:9 std::sys::unix::thread::Thread::new::thread_start at /rustc/4ca19e09d302a4cbde14f9cb1bc109179dc824cd/library/std/src/sys/unix/thread.rs:108:17 20: 21: clone Thread 'tokio-runtime-worker' panicked at ': ErrorType { error_type: "bad gamma_i decommit", bad_actors: [1], data: [] }', /home/shady/.cargo/git/checkouts/multi-party-ecdsa-7313a766cbf184c8/90bba30/src/protocols/multi_party_ecdsa/gg_2020/state_machine/sign/rounds.rs:423 This is a bug. Please report it at: https://github.com/paritytech/cumulus/issues/new ```

Expected behaviour To work without any issues.

Screenshots

image

Environment (please complete the following information):

Other information and links

drewstone commented 2 years ago

This has to do with mixing up the signing protocol executions or the ordering of messages IIRC. Perhaps, we're mixing up how we are sending messages for concurrent signing protocols and sending some messages through the wrong path.