Test function `with_memory_addr_external` is flaky

[MatthiasvB]

Summary

I'm running libp2p tests where I create multiple swarms and connect them together with the in-memory connector. These tests are flaky.

Here is the relevant part of the test

#[tokio::test(flavor = "multi_thread")]
pub async fn test_reject_oversized_file() {
    let (keypair, peer_id, mut swarm) = get_local_network_swarm();
    let (_, _, mut swarm2) = get_local_network_swarm();
    let temp_dir = TempDir::new().expect("failed to create tempdir");
    let out_dir = temp_dir.path().to_path_buf();
    let (brain_sender, mut brain_receiver) = mpsc::channel(10);
    swarm.listen().with_memory_addr_external().await;
    // ...
}

fn get_local_network_swarm() -> (Keypair, PeerId, Swarm<LocalNetworkBehaviour>) {
    let mut maybe_kp = None;
    let swarm = Swarm::new_ephemeral_tokio(|kp| {
        maybe_kp = Some(kp.clone());
        LocalNetworkBehaviour::new(&kp)
    });
    let peer_id = *swarm.local_peer_id();
    (maybe_kp.unwrap(), peer_id, swarm)
}

I realize this isn't something that can be immediately used to reproduce the issue, but maybe it is enough to point to it. If you need more information, please let me know

Expected behavior

Setting up a test harness like this should work reliable, unexpected events should be fine to ignore, no?!

Actual behavior

Sometimes it works, sometimes it doesn't.

Relevant log output

thread 'library::p2p_node::tests::check_file_size::test_reject_oversized_file' panicked at /myproject/rust_libp2p/swarm-test/src/lib.rs:465:25:
Unexpected event while waiting for `NewListenAddr`: Behaviour(LocalNetworkBehaviourEvent: Discovered([(PeerId("12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2"), /ip4/192.168.56.1/tcp/32813/p2p/12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2), (PeerId("12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2"), /ip4/172.20.0.1/tcp/32813/p2p/12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2), (PeerId("12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2"), /ip4/172.18.0.1/tcp/32813/p2p/12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2), (PeerId("12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2"), /ip4/172.23.0.1/tcp/32813/p2p/12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2), (PeerId("12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2"), /ip4/172.17.0.1/tcp/32813/p2p/12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2), (PeerId("12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2"), /ip4/172.19.0.1/tcp/32813/p2p/12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2), (PeerId("12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2"), /ip4/10.10.42.90/tcp/32813/p2p/12D3KooWAgQc8rmiACPVTxcjf3kiLsMeQ85AJ4RdvgYA2GrA1La2)]))
stack backtrace:
   0: rust_begin_unwind
             at /rustc/05f9846f893b09a1be1fc8560e33fc3c815cfecb/library/std/src/panicking.rs:695:5
   1: core::panicking::panic_fmt
             at /rustc/05f9846f893b09a1be1fc8560e33fc3c815cfecb/library/core/src/panicking.rs:75:14
   2: <libp2p_swarm_test::ListenFuture<&mut libp2p_swarm::Swarm<B>> as core::future::into_future::IntoFuture>::into_future::{{closure}}::{{closure}}
             at ./rust_libp2p/swarm-test/src/lib.rs:465:25
   3: <libp2p_swarm::Swarm<B> as libp2p_swarm_test::SwarmExt>::wait::{{closure}}
             at ./rust_libp2p/swarm-test/src/lib.rs:350:30
   4: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /nix/store/xvfdmy4ra4f140gglsjfwdlc1cni85l0-rust-default-1.86.0/lib/rustlib/src/rust/library/core/src/future/future.rs:124:9
   5: <libp2p_swarm_test::ListenFuture<&mut libp2p_swarm::Swarm<B>> as core::future::into_future::IntoFuture>::into_future::{{closure}}
             at ./rust_libp2p/swarm-test/src/lib.rs:468:18
   6: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /nix/store/xvfdmy4ra4f140gglsjfwdlc1cni85l0-rust-default-1.86.0/lib/rustlib/src/rust/library/core/src/future/future.rs:124:9
   7: filerequest_be_rust::library::p2p_node::tests::check_file_size::test_reject_oversized_file::{{closure}}
             at ./src/library/p2p_node/tests/check_file_size.rs:68:48
   8: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /nix/store/xvfdmy4ra4f140gglsjfwdlc1cni85l0-rust-default-1.86.0/lib/rustlib/src/rust/library/core/src/future/future.rs:124:9
   9: tokio::runtime::park::CachedParkThread::block_on::{{closure}}
             at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/park.rs:284:63
  10: tokio::runtime::coop::with_budget
             at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/coop.rs:107:5
  11: tokio::runtime::coop::budget
             at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/coop.rs:73:5
  12: tokio::runtime::park::CachedParkThread::block_on
             at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/park.rs:284:31
  13: tokio::runtime::context::blocking::BlockingRegionGuard::block_on
             at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/context/blocking.rs:66:9
  14: tokio::runtime::scheduler::multi_thread::MultiThread::block_on::{{closure}}
             at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/scheduler/multi_thread/mod.rs:87:13
  15: tokio::runtime::context::runtime::enter_runtime
             at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/context/runtime.rs:65:16
  16: tokio::runtime::scheduler::multi_thread::MultiThread::block_on
             at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/scheduler/multi_thread/mod.rs:86:9
  17: tokio::runtime::runtime::Runtime::block_on_inner
             at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/runtime.rs:370:45
  18: tokio::runtime::runtime::Runtime::block_on
             at /home/me/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.43.0/src/runtime/runtime.rs:342:13
  19: filerequest_be_rust::library::p2p_node::tests::check_file_size::test_reject_oversized_file
             at ./src/library/p2p_node/tests/check_file_size.rs:159:5
  20: filerequest_be_rust::library::p2p_node::tests::check_file_size::test_reject_oversized_file::{{closure}}
             at ./src/library/p2p_node/tests/check_file_size.rs:61:42
  21: core::ops::function::FnOnce::call_once
             at /nix/store/xvfdmy4ra4f140gglsjfwdlc1cni85l0-rust-default-1.86.0/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5
  22: core::ops::function::FnOnce::call_once
             at /rustc/05f9846f893b09a1be1fc8560e33fc3c815cfecb/library/core/src/ops/function.rs:250:5

Possible Solution

Ignore unexpected events

Version

0.55.0

Would you like to work on fixing this bug?

No

[MatthiasvB]

I realize that an important hint may be that my Behaviour is using mdns. I do not recognize the detected PeerId from the logged event, so I suspect this is the other swarm, actually live broadcasting mdns messages during the test

[elenaf9]

I realize that an important hint may be that my Behaviour is using mdns. I do not recognize the detected PeerId from the logged event, so I suspect this is the other swarm, actually live broadcasting mdns messages during the test

Yes exactly.
The listen function expects that the new swarm event is deterministically a NewListenAddr, but because the mdns behavior is running concurrently it can interleave with its Discovered event.

I guess we could change the ListenFuture to discard behavior events, but that could also end up being a footgun if users expect that behavior event to be reported afterwards.

Maybe add method ListenFuture::ignore_events(self, f(&SwarmEvent) -> bool) -> Self?

[MatthiasvB]

Hmm, I kind of see the point, but I do think it's generally necessary to ignore unexpected events. If you need to react to events occurring before the NewListenAddr, it seems to come down to the ability to run things in parallel in the test, something that likely people will have to figure out anyway. I tried refactoring the code to run with_memory_addr_external() before the second swarm is created, which, as I understand, should fix the test when it's running in isolation. But I still get the error, which I believe occurs because other tests run concurrently. And because everything wildly communicates over the real network, there are clashes. There would probably potentially also be clashes from real devices on the network.

I will probably be able to find a way to make the tests run sequentially, with the obvious downside of them taking longer, but the real device interference could only be circumvented by either ignoring unexpected events or make it so that the test swarm does not get access to the real network. Is the latter possible?