bee icon indicating copy to clipboard operation
bee copied to clipboard

auto-peering crash on W11 host

Open TeeVeeEss opened this issue 2 years ago • 0 comments

Bug description

After x hours the bee crashes, usually with a reference to one of the auto-peering features.

Rust version

Which version of Rust are you running?

  • Rust version: rustc 1.59.0 (9d1b2106e 2022-02-23)

Bee version: bee-node 0.3.0

Which version of Bee are you using?

  • Bee version (version number, commit, or branch): commit b98bd114e763a0cebe47ac4b8055873e8009e8e6 (HEAD -> mainnet-develop, tag: v0.3.0

Hardware specification

What hardware are you using?

  • Operating system: Windows 11 Prof
  • RAM: 32 GB
  • Cores: 24, AMD Threadripper 3960X
  • Device: baremetal

Steps To reproduce the bug

Explain how the maintainer can reproduce the bug.

  1. Start bee with autopeering: PS D:\github\bee\bee-node> ..\target\release\bee.exe --autopeering
  2. Let it run for a while.
  3. After X hours (last time 1 day) bee crashes with a stack-trace.

Expected behaviour

No crash, just keep on running

Actual behaviour

See zipped trace-log created with: autopeering.log..zip

{
        "name": "autopeering.log",
        "levelFilter": "trace",
        "targetFilters": ["bee_autopeering"],
        "targetExclusions": [],
        "colorEnabled": false
}

Errors

warn.log:

2022-04-01 04:56:32 (UTC) yamux::connection                          ERROR 09837558: socket error: decode error: i/o error: De software op uw hostcomputer heeft een verbinding verbroken. (os error 10053)
2022-04-02 11:35:09 (UTC) bee_node::shutdown                         WARN  Gracefully shutting down the node, this may take some time.
2022-04-02 11:37:38 (UTC) bee                                        ERROR Failed to build full node: storage backend operation failed: Unhealthy storage: Idle, remove storage folder and restart
2022-04-02 11:40:58 (UTC) warp::reject                               ERROR unhandled custom rejection, returning 500 response: InvalidJwt 
2022-04-02 13:09:42 (UTC) bee_node::plugins::dashboard::websocket    ERROR websocket error(uid=1): IO error: De externe host heeft een verbinding verbroken. (os error 10054)
2022-04-02 13:09:42 (UTC) bee_node::plugins::dashboard::websocket    ERROR websocket send error: IO error: De externe host heeft een verbinding verbroken. (os error 10054)
2022-04-02 21:34:44 (UTC) yamux::connection                          ERROR ae757852: socket error: decode error: i/o error: De software op uw hostcomputer heeft een verbinding verbroken. (os error 10053)
2022-04-02 22:44:24 (UTC) yamux::connection                          ERROR 172554f9: socket error: decode error: i/o error: De software op uw hostcomputer heeft een verbinding verbroken. (os error 10053)
2022-04-03 06:39:45 (UTC) yamux::connection                          ERROR cb332c55: socket error: decode error: i/o error: De software op uw hostcomputer heeft een verbinding verbroken. (os error 10053)
2022-04-03 07:00:54 (UTC) yamux::connection                          ERROR cf2085e3: socket error: decode error: i/o error: De software op uw hostcomputer heeft een verbinding verbroken. (os error 10053)

Stack trace on prompt:

2022-04-04 02:55:34 (UTC) bee_autopeering::discovery::manager        DEBUG Added unknown and unverified QeMNX7phqWUpadE8.
2022-04-04 02:55:34 (UTC) bee_autopeering::discovery::manager        DEBUG Verified QeMNX7phqWUpadE8. Peer offers 2 service/s: chrysalis-mainnet/tcp/15600;peering/udp/14626
2022-04-04 02:55:35 (UTC) bee_autopeering::peering::manager          DEBUG Peering accepted by QeMNX7phqWUpadE8.
2022-04-04 02:55:35 (UTC) bee_autopeering::peering::manager          DEBUG Peering with QeMNX7phqWUpadE8; status: true, direction: out, #out_nbh: 1, #in_nbh: 4
2022-04-04 02:55:36 (UTC) bee_autopeering::peering::manager          DEBUG Received invalid peering request from QBoLmbtmjY2ZpJ6A. Reason: PeerNotVerified
2022-04-04 02:55:37 (UTC) bee_autopeering::peering::manager          DEBUG Received invalid peering request from QBoLmbtmjY2ZpJ6A. Reason: PeerNotVerified
2022-04-04 02:55:39 (UTC) bee_autopeering::peering::manager          DEBUG Received invalid peering request from QBoLmbtmjY2ZpJ6A. Reason: PeerNotVerified
2022-04-04 02:55:40 (UTC) bee_autopeering::discovery::query          DEBUG Reverified S2WM6ecGHZwAwjSs. Peer offers 2 service/s: peering/udp/14626;chrysalis-mainnet/tcp/15600
2022-04-04 02:55:43 (UTC) bee_autopeering::peering::manager          DEBUG Peering dropped with QeMNX7phqWUpadE8; #out_nbh: 0 #in_nbh: 4
2022-04-04 02:55:50 (UTC) bee_autopeering::discovery::manager        DEBUG Verification response timeout for EfucJ2oRnWbfo7N1: deadline has elapsed
2022-04-04 02:55:50 (UTC) bee_autopeering::discovery::query          DEBUG Failed to reverify EfucJ2oRnWbfo7N1. Removing peer.
2022-04-04 02:55:50 (UTC) bee_autopeering::discovery::manager        DEBUG Received invalid verification response from EfucJ2oRnWbfo7N1. Reason: NoCorrespondingRequestOrTimeout
2022-04-04 02:56:00 (UTC) bee_autopeering::discovery::query          DEBUG Reverified Exn5as2Vk1UHfE56. Peer offers 2 service/s: peering/udp/14626;chrysalis-mainnet/tcp/15600
2022-04-04 02:56:02 (UTC) bee_autopeering::discovery::query          INFO  Querying 2 peer/s...
2022-04-04 02:56:02 (UTC) bee_autopeering::discovery::manager        DEBUG Added (unverified): KQPsmkChMMcdvjYW.
2022-04-04 02:56:02 (UTC) bee_autopeering::discovery::manager        DEBUG Added (unverified): DwDeyjoKdLnRVYcr.
2022-04-04 02:56:02 (UTC) bee_autopeering::discovery::query          DEBUG Query successful. Received 6 peers.
2022-04-04 02:56:02 (UTC) bee_autopeering::discovery::query          DEBUG Query successful. Received 6 peers.
2022-04-04 02:56:03 (UTC) bee_autopeering::discovery::manager        DEBUG Verified DwDeyjoKdLnRVYcr. Peer offers 2 service/s: peering/udp/14626;chrysalis-mainnet/tcp/15600
2022-04-04 02:56:10 (UTC) bee_autopeering::discovery::query          DEBUG Reverified FfmmA4KALPWXgjou. Peer offers 2 service/s: chrysalis-mainnet/tcp/15600;peering/udp/14626
2022-04-04 02:56:16 (UTC) bee_autopeering::peering::manager          DEBUG Received invalid peering request from GeG1ZWkM1g84qPau. Reason: PeerNotVerified
2022-04-04 02:56:17 (UTC) bee_autopeering::peering::manager          DEBUG Received invalid peering request from GeG1ZWkM1g84qPau. Reason: PeerNotVerified
2022-04-04 02:56:17 (UTC) bee_autopeering::peering::manager          DEBUG Received invalid peering request from GeG1ZWkM1g84qPau. Reason: PeerNotVerified
2022-04-04 02:56:19 (UTC) bee_autopeering::discovery::query          DEBUG Reverified ER6NqRCH3WwQXry8. Peer offers 2 service/s: peering/udp/14626;chrysalis-mainnet/tcp/15600
2022-04-04 02:56:30 (UTC) bee_autopeering::discovery::query          DEBUG Reverified DcXR2ujJUESRoj4J. Peer offers 2 service/s: chrysalis-mainnet/tcp/15600;peering/udp/14626
2022-04-04 02:56:39 (UTC) bee_autopeering::discovery::query          DEBUG Reverified LP7DC3SwJgegTMsn. Peer offers 2 service/s: chrysalis-mainnet/tcp/15600;peering/udp/14626
2022-04-04 02:56:50 (UTC) bee_autopeering::discovery::query          DEBUG Reverified SyQzxxq3rxqJ6W6j. Peer offers 2 service/s: peering/udp/14626;chrysalis-mainnet/tcp/15600
2022-04-04 02:56:59 (UTC) bee_autopeering::discovery::query          DEBUG Reverified BK6XvvFSzKaQpKTw. Peer offers 2 service/s: peering/udp/14626;chrysalis-mainnet/tcp/15600
2022-04-04 02:57:02 (UTC) bee_autopeering::discovery::query          INFO  Querying 2 peer/s...
2022-04-04 02:57:03 (UTC) bee_autopeering::discovery::manager        DEBUG Discovery response timeout: deadline has elapsed
2022-04-04 02:57:03 (UTC) bee_autopeering::discovery::manager        DEBUG Discovery response timeout: deadline has elapsed
2022-04-04 02:57:03 (UTC) bee_autopeering::discovery::manager        DEBUG Added (unverified): JUQPggBFtpPEHdxo.
2022-04-04 02:57:03 (UTC) bee_autopeering::discovery::query          DEBUG Query unsuccessful. Removing peer BK6XvvFSzKaQpKTw.
2022-04-04 02:57:03 (UTC) bee_autopeering::discovery::query          DEBUG Query unsuccessful. Removing peer F971ghuKvgMfGDme.
2022-04-04 02:57:03 (UTC) bee_autopeering::discovery::manager        DEBUG Added (unverified): QtdD3RnBcCT5rbyb.
thread 'tokio-runtime-worker' panicked at 'inconsistent active peers list', bee-network\bee-autopeering\src\discovery\manager.rs:735:10
stack backtrace:
   0:     0x7ff6488ee97f - std::backtrace_rs::backtrace::dbghelp::trace
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\..\..\backtrace\src\backtrace\dbghelp.rs:98
   1:     0x7ff6488ee97f - std::backtrace_rs::backtrace::trace_unsynchronized
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\..\..\backtrace\src\backtrace\mod.rs:66
   2:     0x7ff6488ee97f - std::sys_common::backtrace::_print_fmt
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\sys_common\backtrace.rs:67
   3:     0x7ff6488ee97f - std::sys_common::backtrace::_print::impl$0::fmt
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\sys_common\backtrace.rs:46
   4:     0x7ff648909d5a - core::fmt::write
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\core\src\fmt\mod.rs:1168
   5:     0x7ff6488e5e88 - std::io::Write::write_fmt<std::sys::windows::stdio::Stderr>
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\io\mod.rs:1660
   6:     0x7ff6488f0f9b - std::sys_common::backtrace::_print
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\sys_common\backtrace.rs:49
   7:     0x7ff6488f0f9b - std::sys_common::backtrace::print
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\sys_common\backtrace.rs:36
   8:     0x7ff6488f0f9b - std::panicking::default_hook::closure$1
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\panicking.rs:211
   9:     0x7ff6488f0a94 - std::panicking::default_hook
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\panicking.rs:228
  10:     0x7ff6488f149c - std::panicking::rust_panic_with_hook
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\panicking.rs:606
  11:     0x7ff6488f135b - std::panicking::begin_panic_handler::closure$0
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\panicking.rs:502
  12:     0x7ff6488ef2c7 - std::sys_common::backtrace::__rust_end_short_backtrace<std::panicking::begin_panic_handler::closure$0,never$>
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\sys_common\backtrace.rs:139
  13:     0x7ff6488f1059 - std::panicking::begin_panic_handler
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\panicking.rs:498
  14:     0x7ff648c0d760 - core::panicking::panic_fmt
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\core\src\panicking.rs:116
  15:     0x7ff648907bc0 - core::panicking::panic_display<str>
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\core\src\panicking.rs:72
  16:     0x7ff648907b6b - core::panicking::panic_str
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\core\src\panicking.rs:56
  17:     0x7ff648c0d659 - core::option::expect_failed
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\core\src\option.rs:1817
  18:     0x7ff6486ba4ac - bee_autopeering::discovery::manager::handle_discovery_response::h658a92e23f9b302c
  19:     0x7ff6486d4295 - <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll::hc210f0fb9e9f01fd
  20:     0x7ff648191f68 - tokio::runtime::task::core::CoreStage<T>::poll::hfdf179ebce7decb4
  21:     0x7ff64813c57e - tokio::runtime::task::harness::Harness<T,S>::complete::hffb45338ed20cc45
  22:     0x7ff648121214 - tokio::runtime::task::harness::Harness<T,S>::poll::he4c3fe6f0fbd83d9
  23:     0x7ff64881412c - std::thread::local::LocalKey<T>::with::h0be12a2373c7ffe0
  24:     0x7ff648826612 - tokio::runtime::thread_pool::worker::Context::run::hcb008923b1c05108
  25:     0x7ff648826075 - tokio::runtime::thread_pool::worker::Context::run::hcb008923b1c05108
  26:     0x7ff6488256c4 - tokio::runtime::thread_pool::worker::run::hfb1b7ba9d8cf47a8
  27:     0x7ff648824801 - tokio::runtime::task::core::CoreStage<T>::poll::h4af46a4368bfb80e
  28:     0x7ff648821b7a - tokio::runtime::task::harness::Harness<T,S>::poll::h057e348125901bcb
  29:     0x7ff64881346e - tokio::runtime::blocking::pool::Inner::run::h956e25c6e52065f6
  30:     0x7ff64881d71a - std::sys_common::backtrace::__rust_begin_short_backtrace::hdf91de245b37dc13
  31:     0x7ff648819ba3 - <tokio::util::slab::Ref<T> as core::ops::drop::Drop>::drop::h7450df57532a978d
  32:     0x7ff6488f60ac - alloc::boxed::impl$44::call_once
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\library\alloc\src\boxed.rs:1854
  33:     0x7ff6488f60ac - alloc::boxed::impl$44::call_once
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\library\alloc\src\boxed.rs:1854
  34:     0x7ff6488f60ac - std::sys::windows::thread::impl$0::new::thread_start
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a\/library\std\src\sys\windows\thread.rs:58
  35:     0x7ff8dccd54e0 - BaseThreadInitThunk
  36:     0x7ff8deda485b - RtlUserThreadStart
PS D:\github\bee\bee-node>

TeeVeeEss avatar Apr 04 '22 18:04 TeeVeeEss