Peer handling thread paniced

[terassyi]

thread 'main' panicked at 'assertion failed: self.remaining() >= dst.len()', /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/bytes-1.4.0/src/buf/buf_impl.rs:254:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
2023-07-02T19:56:17.953317Z ERROR bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established error=Peer(FailedToSendMessage)
2023-07-02T19:56:27.962879Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established event=Connection::TcpConnectionConfirmed
2023-07-02T19:56:27.962968Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:handle_tcp_connect:handle_connection: sartd::bgp::peer::peer: initialize the connection local_addr="172.18.0.3" passive=true
2023-07-02T19:56:27.963027Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:handle_tcp_connect:build_open_msg: sartd::bgp::peer::peer: build open message local.asn=65000 local.id=172.18.0.3
2023-07-02T19:56:27.963270Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Idle event=Message::BGPOpen
2023-07-02T19:56:27.963375Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Idle event=Message::KeepAliveMsg
2023-07-02T19:56:27.963444Z  WARN bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:keepalive_msg:release: sartd::bgp::peer::peer: release session state=Idle
2023-07-02T19:56:27.963712Z  WARN bgp: sartd::bgp::peer::peer: drop one connection
2023-07-02T19:56:33.597797Z  INFO bgp: sartd::bgp::server: restart peer peer.addr="172.18.0.6" peer.asn=65000

[terassyi]

2023-07-03T13:05:45.450055Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established event=Message::KeepAliveMsg
2023-07-03T13:05:45.450070Z DEBUG bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:keepalive_msg: sartd::bgp::peer::peer: received keepalive message state=Established
thread 'main' panicked at 'assertion failed: self.remaining() >= dst.len()', /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/bytes-1.4.0/src/buf/buf_impl.rs:254:9
stack backtrace:
   0: rust_begin_unwind
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/std/src/panicking.rs:575:5
   1: core::panicking::panic_fmt
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/core/src/panicking.rs:64:14
   2: core::panicking::panic
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/core/src/panicking.rs:114:5
   3: bytes::buf::buf_impl::Buf::copy_to_slice
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/bytes-1.4.0/src/buf/buf_impl.rs:254:9
   4: bytes::buf::buf_impl::Buf::get_u128
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/bytes-1.4.0/src/buf/buf_impl.rs:713:9
   5: sartd::bgp::packet::codec::decode_msg
             at ./home/sartd/src/bgp/packet/codec.rs:75:18
   6: <sartd::bgp::packet::codec::Codec as tokio_util::codec::decoder::Decoder>::decode
             at ./home/sartd/src/bgp/packet/codec.rs:61:23
   7: <tokio_util::codec::framed_impl::FramedImpl<T,U,R> as futures_core::stream::Stream>::poll_next
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-util-0.7.5/src/codec/framed_impl.rs:203:38
   8: <tokio_util::codec::framed::Framed<T,U> as futures_core::stream::Stream>::poll_next
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-util-0.7.5/src/codec/framed.rs:301:9
   9: <futures_util::stream::stream::split::SplitStream<S> as futures_core::stream::Stream>::poll_next
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.28/src/stream/stream/split.rs:34:9
  10: futures_util::stream::stream::StreamExt::poll_next_unpin
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.28/src/stream/stream/mod.rs:1632:9
  11: <futures_util::stream::stream::next::Next<St> as core::future::future::Future>::poll
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.28/src/stream/stream/next.rs:32:9
  12: <futures_util::future::future::fuse::Fuse<Fut> as core::future::future::Future>::poll
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.28/src/future/future/fuse.rs:84:26
  13: <core::pin::Pin<P> as core::future::future::Future>::poll
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/core/src/future/future.rs:125:9
  14: futures_util::future::future::FutureExt::poll_unpin
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.28/src/future/future/mod.rs:562:9
  15: sartd::bgp::peer::peer::Peer::handle_connection::{{closure}}::{{closure}}::{{closure}}
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.28/src/async_await/select_mod.rs:331:13
  16: core::ops::function::impls::<impl core::ops::function::FnMut<A> for &mut F>::call_mut
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/core/src/ops/function.rs:298:13
  17: sartd::bgp::peer::peer::Peer::handle_connection::{{closure}}::{{closure}}
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.28/src/async_await/select_mod.rs:331:13
  18: <futures_util::future::poll_fn::PollFn<F> as core::future::future::Future>::poll
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.28/src/future/poll_fn.rs:56:9
  19: sartd::bgp::peer::peer::Peer::handle_connection::{{closure}}
             at ./home/sartd/src/bgp/peer/peer.rs:392:17
  20: tokio::runtime::task::core::CoreStage<T>::poll::{{closure}}
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/task/core.rs:184:17
  21: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/loom/std/unsafe_cell.rs:14:9
  22: tokio::runtime::task::core::CoreStage<T>::poll
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/task/core.rs:174:13
  23: tokio::runtime::task::harness::poll_future::{{closure}}
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/task/harness.rs:480:19
  24: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/core/src/panic/unwind_safe.rs:271:9
  25: std::panicking::try::do_call
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/std/src/panicking.rs:483:40
  26: __rust_try
  27: std::panicking::try
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/std/src/panicking.rs:447:19
  28: std::panic::catch_unwind
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/std/src/panic.rs:140:14
  29: tokio::runtime::task::harness::poll_future
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/task/harness.rs:468:18
  30: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/task/harness.rs:104:27
  31: tokio::runtime::task::harness::Harness<T,S>::poll
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/task/harness.rs:57:15
  32: tokio::runtime::task::raw::poll
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/task/raw.rs:194:5
  33: tokio::runtime::task::raw::RawTask::poll
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/task/raw.rs:134:18
  34: tokio::runtime::task::LocalNotified<S>::run
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/task/mod.rs:385:9
  35: tokio::runtime::scheduler::current_thread::CoreGuard::block_on::{{closure}}::{{closure}}
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/scheduler/current_thread.rs:564:25
  36: tokio::coop::with_budget::{{closure}}
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/coop.rs:102:9
  37: std::thread::local::LocalKey<T>::try_with
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/std/src/thread/local.rs:446:16
  38: std::thread::local::LocalKey<T>::with
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/std/src/thread/local.rs:422:9
  39: tokio::coop::with_budget
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/coop.rs:95:5
  40: tokio::coop::budget
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/coop.rs:72:5
  41: tokio::runtime::scheduler::current_thread::Context::run_task::{{closure}}
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/scheduler/current_thread.rs:284:29
  42: tokio::runtime::scheduler::current_thread::Context::enter
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/scheduler/current_thread.rs:349:19
  43: tokio::runtime::scheduler::current_thread::Context::run_task
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/scheduler/current_thread.rs:284:9
  44: tokio::runtime::scheduler::current_thread::CoreGuard::block_on::{{closure}}
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/scheduler/current_thread.rs:563:34
  45: tokio::runtime::scheduler::current_thread::CoreGuard::enter::{{closure}}
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/scheduler/current_thread.rs:595:57
  46: tokio::macros::scoped_tls::ScopedKey<T>::set
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/macros/scoped_tls.rs:61:9
  47: tokio::runtime::scheduler::current_thread::CoreGuard::enter
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/scheduler/current_thread.rs:595:27
  48: tokio::runtime::scheduler::current_thread::CoreGuard::block_on
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/scheduler/current_thread.rs:515:19
  49: tokio::runtime::scheduler::current_thread::CurrentThread::block_on
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/scheduler/current_thread.rs:161:24
  50: tokio::runtime::Runtime::block_on
             at ./usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.21.1/src/runtime/mod.rs:490:46
  51: sartd::bgp::server::start
             at ./home/sartd/src/bgp/server.rs:538:5
  52: sartd::cmd::main
             at ./home/sartd/src/cmd.rs:99:13
  53: sartd::main
             at ./home/sartd/src/main.rs:9:5
  54: core::ops::function::FnOnce::call_once
             at ./rustc/2c8cc343237b8f7d5a3c3703e3a87f2eb2c54a74/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
2023-07-03T13:06:15.473453Z DEBUG bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established event=Timer::KeepaliveTimerExpire
2023-07-03T13:06:15.473534Z ERROR bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established error=Peer(FailedToSendMessage)
2023-07-03T13:06:27.478994Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established event=Connection::TcpConnectionConfirmed
2023-07-03T13:06:27.479070Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:handle_tcp_connect:handle_connection: sartd::bgp::peer::peer: initialize the connection local_addr="172.18.0.3" passive=true
2023-07-03T13:06:27.479109Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:handle_tcp_connect:build_open_msg: sartd::bgp::peer::peer: build open message local.asn=65000 local.id=172.18.0.3
2023-07-03T13:06:27.479264Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Idle event=Message::BGPOpen
2023-07-03T13:06:27.479285Z DEBUG bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:bgp_open{local_port=179 peer_port=40885 local.port=179 peer.port=40885}: sartd::bgp::peer::peer: state=Idle
2023-07-03T13:06:27.479318Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Idle event=Message::KeepAliveMsg
2023-07-03T13:06:27.479328Z DEBUG bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:keepalive_msg: sartd::bgp::peer::peer: received keepalive message state=Idle
2023-07-03T13:06:27.479363Z  WARN bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:keepalive_msg:release: sartd::bgp::peer::peer: release session state=Idle
2023-07-03T13:06:27.479444Z  WARN bgp: sartd::bgp::peer::peer: drop one connection
2023-07-03T13:06:31.152621Z  INFO bgp: sartd::bgp::server: restart peer peer.addr="172.18.0.6" peer.asn=65000

[terassyi]

2023-07-03T19:11:05.710974Z DEBUG bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:keepalive_msg: sartd::bgp::peer::peer: received keepalive message state=Established
2023-07-03T19:11:05.711014Z DEBUG bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established event=Timer::KeepaliveTimerExpire
2023-07-03T19:11:35.711021Z ERROR bgp:decode_msg{as4_enabled=true}: sartd::bgp::packet::codec: message is invalid buf=Bytes { inner: [255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255] } length=14
2023-07-03T19:11:35.711069Z DEBUG bgp: sartd::bgp::peer::peer: notify to close signal
2023-07-03T19:11:35.711149Z DEBUG bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established event=Timer::KeepaliveTimerExpire
2023-07-03T19:11:35.711181Z ERROR bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established error=Peer(FailedToSendMessage)
2023-07-03T19:11:35.711198Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established event=Message::BgpHeaderError
2023-07-03T19:11:35.711224Z ERROR bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established error=Peer(FailedToSendMessage)
2023-07-03T19:11:35.711242Z  WARN bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: connection closed actively local_port=179 conn_empty=true
2023-07-03T19:11:35.711270Z  WARN bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:release: sartd::bgp::peer::peer: release session state=Established
2023-07-03T19:11:44.784826Z  INFO bgp: sartd::bgp::server: restart peer peer.addr="172.18.0.6" peer.asn=65000

[terassyi]

2023-07-04T02:17:54.786994Z DEBUG bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established event=Timer::KeepaliveTimerExpire
2023-07-04T02:17:54.787486Z ERROR bgp:decode_msg{as4_enabled=true}: sartd::bgp::packet::codec: message is invalid buf=Bytes { inner: [255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255] } length=14
2023-07-04T02:17:54.787530Z DEBUG bgp: sartd::bgp::peer::peer: notify to close signal
2023-07-04T02:17:54.787614Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established event=Message::BgpHeaderError
2023-07-04T02:17:54.787690Z ERROR bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Established error=Peer(FailedToSendMessage)
2023-07-04T02:17:54.787730Z  WARN bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: connection closed actively local_port=36540 conn_empty=true
2023-07-04T02:17:54.787940Z  WARN bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:release: sartd::bgp::peer::peer: release session state=Established
2023-07-04T02:18:04.784304Z  INFO bgp: sartd::bgp::server: restart peer peer.addr="172.18.0.6" peer.asn=65000
2023-07-04T02:18:04.784384Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Idle event=Admin::ManualStart
2023-07-04T02:18:04.784406Z DEBUG bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle:manual_start: sartd::bgp::peer::peer: start to connect to peer
2023-07-04T02:18:04.784574Z  INFO bgp:peer{peer.asn=65000 peer.addr="172.18.0.6" peer.id="172.18.0.6"}:handle: sartd::bgp::peer::peer: state=Connect event=Connection::TcpCRAcked

[terassyi]

The received packet when sartd-bgp peer handler paniced.

It seems a valid keepalive message.

0000   02 42 ac 12 00 02 02 42 ac 12 00 06 08 00 45 00
0010   00 47 9a 75 40 00 ff 06 89 0e ac 12 00 06 ac 12
0020   00 02 00 b3 cb 20 8c 3f c3 37 45 05 e1 b0 80 18
0030   01 fe 58 66 00 00 01 01 08 0a b5 19 98 b9 36 dc
0040   aa 01 ff ff ff ff ff ff ff ff ff ff ff ff ff ff
0050   ff ff 00 13 04