libp2p / rust-libp2p

The Rust Implementation of the libp2p networking stack.
https://libp2p.io
MIT License
4.56k stars 949 forks source link

`unreachable` panic libp2p-swarm-0.44.2/src/handler/either.rs:106 #5412

Open joshuef opened 5 months ago

joshuef commented 5 months ago

Summary

Seemingly the unreachable code on a match in the swarm handler is panicking?!

This does not actually crash our app (I assume it's a spawned thread).

But it's not clear to me how this is even possible :|

Expected behavior

no panic

Actual behavior

panic

Relevant log output

May 20 07:07:36 node-1 safenode[23138]: The application panicked (crashed).
May 20 07:07:36 node-1 safenode[23138]: Message:  internal error: entered unreachable code
May 20 07:07:36 node-1 safenode[23138]: Location: /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/libp2p-swarm-0.44.2/src/handler/either.rs:106
May 20 07:07:36 node-1 safenode[23138]: Backtrace omitted. Run with RUST_BACKTRACE=1 environment variable to display it.
May 20 07:07:36 node-1 safenode[23138]: Run with RUST_BACKTRACE=full to include source snippets.

root@node-1:/# journalctl -u safenode7.service 
May 21 16:13:20 node-1 safenode[23146]: The application panicked (crashed).
May 21 16:13:20 node-1 safenode[23146]: Message:  internal error: entered unreachable code
May 21 16:13:20 node-1 safenode[23146]: Location: /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/libp2p-swarm-0.44.2/src/handler/either.rs:106

Possible Solution

No response

Version

No response

Would you like to work on fixing this bug ?

Maybe

dariusc93 commented 5 months ago

Thank you for the report. It looks like it happens when receiving an event from the behaviour.

https://github.com/libp2p/rust-libp2p/blob/ad7ad5b3fc5b4bc9a431ece90e9a5ce8c33ca0e2/swarm/src/handler/either.rs#L102-L108

Could you provide any code to reproduce it and any possible logs?

joshuef commented 5 months ago

it seems we had two relay events around the panic time:

[2024-05-20T07:07:36.488761Z INFO sn_networking::event::swarm] relay client event event=OutboundCircuitEstablished { relay_peer_id: PeerId("12D3KooWPQYu4GjLEEwxp1BmgneDDwajawjUhT9ZupTbp6LRT4Ra"), limit: None }```

```May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]: Location: /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/libp2p-swarm-0.44.2/src/handler/either.rs:106
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:   ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ BACKTRACE ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:                                 ⋮ 7 frames hidden ⋮                               
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:    8: core::panicking::panic::h584a128616e7fa9b
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:       at <unknown source file>:<unknown line>
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:    9: <libp2p_swarm::handler::select::ConnectionHandlerSelect<TProto1,TProto2> as libp2p_swarm::handler::ConnectionHandler>::on_behaviour_event::h75b996a885f09be9
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:       at <unknown source file>:<unknown line>
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:   10: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll::h0adc49c52e11e997
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:       at <unknown source file>:<unknown line>
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:   11: tokio::runtime::task::core::Core<T,S>::poll::h96755579c44ce1d6
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:       at <unknown source file>:<unknown line>
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:   12: tokio::runtime::task::raw::poll::h5bedef3875a2cdb8
May 22 20:41:19 ShuNetV3-node-4 safenode[3790806]:       at <unknown source file>:<unknown line>

trying to gather more logs (it's not super frequent, but we are seeing it often ish, we've restarted nodes with debugger attached just now)