Fix flaky zombienet test `zombienet-cumulus-0002-pov_recovery` #6573

pepoviola · 2024-11-21T10:04:40Z

Some examples from Tuesday

Fail to start (node three)
https://gitlab.parity.io/parity/mirrors/polkadot-sdk/-/jobs/7786180
https://gitlab.parity.io/parity/mirrors/polkadot-sdk/-/jobs/7785532
https://gitlab.parity.io/parity/mirrors/polkadot-sdk/-/jobs/7784688
https://gitlab.parity.io/parity/mirrors/polkadot-sdk/-/jobs/7784356
https://gitlab.parity.io/parity/mirrors/polkadot-sdk/-/jobs/7784158
https://gitlab.parity.io/parity/mirrors/polkadot-sdk/-/jobs/7778904
https://gitlab.parity.io/parity/mirrors/polkadot-sdk/-/jobs/7778369

https://grafana.teleport.parity.io/goto/YZ5Wuv7Ng?orgId=1


2024-11-19 23:27:57.675 | 0: rust_begin_unwind |  
-- | -- | --
  |   | 2024-11-19 23:27:57.676 | 1: core::panicking::panic_fmt |  
  |   | 2024-11-19 23:27:57.676 | 2: core::panicking::panic |  
  |   | 2024-11-19 23:27:57.676 | 3: futures_util::future::future::FutureExt::poll_unpin |  
  |   | 2024-11-19 23:27:57.677 | 4: <futures_util::future::select::Select<A,B> as core::future::future::Future>::poll |  
  |   | 2024-11-19 23:27:57.682 | 5: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll |  
  |   | 2024-11-19 23:27:57.683 | 6: <futures_util::future::try_future::MapErr<Fut,F> as core::future::future::Future>::poll |  
  |   | 2024-11-19 23:27:57.683 | 7: polkadot_overseer::spawn::{{closure}} |  
  |   | 2024-11-19 23:27:57.684 | 8: <sc_service::task_manager::prometheus_future::PrometheusFuture<T> as core::future::future::Future>::poll |  
  |   | 2024-11-19 23:27:57.684 | 9: <futures_util::future::select::Select<A,B> as core::future::future::Future>::poll |  
  |   | 2024-11-19 23:27:57.685 | 10: <tracing_futures::Instrumented<T> as core::future::future::Future>::poll |  
  |   | 2024-11-19 23:27:57.691 | 11: tokio::runtime::context::runtime::enter_runtime |  
  |   | 2024-11-19 23:27:57.694 | 12: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll |  
  |   | 2024-11-19 23:27:57.695 | 13: tokio::runtime::task::core::Core<T,S>::poll |  
  |   | 2024-11-19 23:27:57.695 | 14: tokio::runtime::task::harness::Harness<T,S>::poll |  
  |   | 2024-11-19 23:27:57.696 | 15: tokio::runtime::blocking::pool::Inner::run |  
  |   | 2024-11-19 23:27:57.696 | note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace. |  
  |   | 2024-11-19 23:27:57.697 | 2024-11-19 22:27:57.697  WARN tokio-runtime-worker polkadot_overseer: [Relaychain] Terminating due to subsystem exit subsystem="network-bridge-rx" |  
  |   | 2024-11-19 23:27:57.697 | 2024-11-19 22:27:57.697  WARN tokio-runtime-worker polkadot_overseer: [Relaychain] termination error detected, dropping but terminating the execution subsystem="network-bridge-rx" err=Canceled |  
  |   | 2024-11-19 23:27:57.697 | 2024-11-19 22:27:57.697 ERROR tokio-runtime-worker overseer: [Relaychain] subsystem finished unexpectedly subsystem=Ok(())

cc: @paritytech/sdk-node

The text was updated successfully, but these errors were encountered:

pepoviola · 2024-12-05T15:20:14Z

Failures from yesterday

cc: @paritytech/sdk-node

skunert · 2024-12-16T11:04:59Z

This zombienet test also fails locally consistently at registering the parachain. The tx sent here is not finalized.

polkadot-sdk/cumulus/zombienet/tests/0002-pov_recovery.zndsl

Line 9 in 482bf08

validator-0: js-script ./register-para.js with "2000" within 240 seconds

This is really strange. I found the issue was introduced with #6400. Not sure why removing the network starter causes grandpa issue. Reverting that PR makes the test pass again.

@paritytech/networking Please take a deeper look into this.

bkchr · 2024-12-16T11:11:28Z

@skunert can you please more logs? What you mean by the "tx is not finalized"? Only the tx never makes it into a block or does finality doesn't work at all?

pepoviola · 2024-12-16T11:15:03Z

Finalization doesn't work at all when we use the reserved flags
#6773 (comment)

Thx!

skunert · 2024-12-16T11:21:36Z

@bkchr assembled some more logs:

logs from validator-0 with grandpa=trace with Remove network starter that is no longer needed #6400 in place:
validator-0_broken.log
No blocks getting finalized.
logs from validator-0 with grandpa=trace with Remove network starter that is no longer needed #6400 reverted:
validator-0_working_6400_reverted.log

All node logs:
working.zip

broken.zip

dmitry-markin · 2024-12-16T11:47:25Z

Let me clarify, the finalization is stalled if and only if both is true:

Remove network starter that is no longer needed #6400 is in place
--reserved-only is passed?

skunert · 2024-12-16T12:33:49Z

Let me clarify, the finalization is stalled if and only if both is true:

Remove network starter that is no longer needed #6400 is in place

--reserved-only is passed?

That is the working assumption. In my tests I focused on finding the commit that broke it. Did not verify the involvement of the reserved only flag.

pepoviola · 2024-12-16T13:09:21Z

I just deployed to networks ( from latest image of master), with --reserved-only the finalization doesn't work at all, here are the logs https://grafana.teleport.parity.io/goto/S1zBJdIHR?orgId=1

And without the flag finalization works as expected, here are the logs https://grafana.teleport.parity.io/goto/ss2DJdIHg?orgId=1

I will deploy other networks (without #6400) to check if the behavior is the same.

Thx!

pepoviola · 2024-12-16T18:54:56Z

Small update, I deployed the same config with the previous commit from master (05ad5475dec748a8a30685bc29a7caba6e63c7ab) and both cases works as expected. Here are the losg:
With reserved https://grafana.teleport.parity.io/goto/rF45nFINg?orgId=1
Without https://grafana.teleport.parity.io/goto/bvu5nKINR?orgId=1

Thx!

dmitry-markin · 2024-12-24T13:58:22Z

Why are we passing --reserved-only in the first place? Even with the network starter present finalization is lagging behind. On average only every second/third block is finalized: #0, #3, #5, #8, #10, and so on. This is likely because the validators are only syncing blocks through the bootnode, because they are only connected to it on the sync protocol.

Without --reserved-only all the 14 nodes (bootnode + 13 validators) are connected to each other on the sync protocol, and in this case every block is finalized: #0, #1, #2, #3, #4, #5, #6, #7, #8, #9, #10, and so on.

dmitry-markin · 2024-12-26T20:49:08Z

What happens here is that due to removed network starter networking starts first and connects to reserved peers on default (sync) protocol before grandpa-voter task finishes initialization, and the latter misses SyncEvent::PeerConnected(peer_id) event.

Because we abuse the reserved nodes mechanism on non-default protocols to track sync peers, GossipEngine in grandpa listens to SyncEvent::PeerConnected(peer_id) events to add such peers as reserved on /grandpa/1 notifications protocol. And because grandpa-voter task is not ready yet to receive sync events, it misses this event and does not add the peer as reserved effectively never connecting to it on /grandpa/1 notifications protocol.

When --reserved-only is not specified, networking also discovers peers later via Kademlia, and for those peers grandpa's GossipEngine is ready to receive sync events.

This issue can potentially manifest in the wild if a node is configured to connect only to --reserved-nodes, and connections are established fast enough for additional tasks to not finish the initialization.

dmitry-markin · 2024-12-27T16:57:50Z

The issue is fixed by #7011.

To simplify debugging of peerset related issues like #6573 (comment). --------- Co-authored-by: command-bot <>

Introduce `SyncEvent::InitialPeers` message sent to new subscribers to allow them correctly tracking sync peers. This resolves a race condition described in #6573 (comment). Fixes #6573. --------- Co-authored-by: command-bot <> Co-authored-by: Bastian Köcher <[email protected]>

pepoviola added the T10-tests This PR/Issue is related to tests. label Nov 21, 2024

pepoviola mentioned this issue Nov 21, 2024

Zombienet flaky tests #5852

Open

16 tasks

pepoviola mentioned this issue Dec 5, 2024

Disable flaky test zombienet-cumulus-0002-pov_recovery #6773

Open

skunert self-assigned this Dec 5, 2024

This was referenced Dec 27, 2024

Log peerset set ID -> protocol name mapping #7005

Merged

Introduce proper mechanism for tracking other protocols peer sets #7006

Open

Reintroduce network starter #7007

Closed

sync: Send already connected peers to new subscribers #7011

Merged

github-merge-queue bot pushed a commit that referenced this issue Dec 30, 2024

Log peerset set ID -> protocol name mapping (#7005)

f19640b

To simplify debugging of peerset related issues like #6573 (comment). --------- Co-authored-by: command-bot <>

dmitry-markin closed this as completed in #7011 Dec 30, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix flaky zombienet test `zombienet-cumulus-0002-pov_recovery` #6573

Fix flaky zombienet test `zombienet-cumulus-0002-pov_recovery` #6573

pepoviola commented Nov 21, 2024 •

edited

Loading

pepoviola commented Dec 5, 2024 •

edited

Loading

skunert commented Dec 16, 2024

bkchr commented Dec 16, 2024

pepoviola commented Dec 16, 2024

skunert commented Dec 16, 2024

dmitry-markin commented Dec 16, 2024

skunert commented Dec 16, 2024

pepoviola commented Dec 16, 2024 •

edited

Loading

pepoviola commented Dec 16, 2024

dmitry-markin commented Dec 24, 2024 •

edited

Loading

dmitry-markin commented Dec 26, 2024

dmitry-markin commented Dec 27, 2024

Fix flaky zombienet test zombienet-cumulus-0002-pov_recovery #6573

Fix flaky zombienet test zombienet-cumulus-0002-pov_recovery #6573

Comments

pepoviola commented Nov 21, 2024 • edited Loading

pepoviola commented Dec 5, 2024 • edited Loading

skunert commented Dec 16, 2024

bkchr commented Dec 16, 2024

pepoviola commented Dec 16, 2024

skunert commented Dec 16, 2024

dmitry-markin commented Dec 16, 2024

skunert commented Dec 16, 2024

pepoviola commented Dec 16, 2024 • edited Loading

pepoviola commented Dec 16, 2024

dmitry-markin commented Dec 24, 2024 • edited Loading

dmitry-markin commented Dec 26, 2024

dmitry-markin commented Dec 27, 2024

Fix flaky zombienet test `zombienet-cumulus-0002-pov_recovery` #6573

Fix flaky zombienet test `zombienet-cumulus-0002-pov_recovery` #6573

pepoviola commented Nov 21, 2024 •

edited

Loading

pepoviola commented Dec 5, 2024 •

edited

Loading

pepoviola commented Dec 16, 2024 •

edited

Loading

dmitry-markin commented Dec 24, 2024 •

edited

Loading