Describe the bug
After starting a clean node , the node panics during bootstrap phase (initial bootstrap completes ok).
Mandatory Information
jcli 0.5.5 (master-aec29a1c, debug, linux [x86_64]) - [rustc 1.38.0 (625451e37 2019-09-23)]jormungandr 0.5.5 (master-aec29a1c, debug, linux [x86_64]) - [rustc 1.38.0 (625451e37 2019-09-23)]To Reproduce
It in not easily reproducible. The stack backtrace is:
Oct 02 07:43:30.980 INFO Starting jormungandr 0.5.5 (master-aec29a1c, debug, linux [x86_64]) - [rustc 1.38.0 (625451e37 2019-09-23)], task: init
Oct 02 07:43:31.033 WARN Node started without path to the stored secret keys (not a stake pool or a BFT leader), task: init
Oct 02 07:43:31.050 INFO storing blockchain in '"jnode_storage/blocks.sqlite"', task: init
Oct 02 07:43:31.511 INFO fetching block adbdd5ede31637f6c9bad5c271eec0bc3d0cb9efb86a5b913bb55cba549d0770, peer_address: 104.248.88.251:3008, block: adbdd5ede31637f6c9bad5c271eec0bc3d0cb9efb86a5b913bb55cba549d0770, task: init
Oct 02 07:43:31.720 WARN error downloading block, reason: connection to peer failed, peer_address: 104.248.88.251:3008, block: adbdd5ede31637f6c9bad5c271eec0bc3d0cb9efb86a5b913bb55cba549d0770, task: init
Oct 02 07:43:31.720 INFO fetching block adbdd5ede31637f6c9bad5c271eec0bc3d0cb9efb86a5b913bb55cba549d0770, peer_address: 3.123.177.192:3000, block: adbdd5ede31637f6c9bad5c271eec0bc3d0cb9efb86a5b913bb55cba549d0770, task: init
Oct 02 07:43:32.008 INFO initial bootstrap completed, peer_address: 3.123.177.192:3000, block: adbdd5ede31637f6c9bad5c271eec0bc3d0cb9efb86a5b913bb55cba549d0770, task: init
Oct 02 07:43:32.222 INFO connecting to bootstrap peer 18.140.134.230:3000, peer_addr: 18.140.134.230:3000, task: bootstrap
Oct 02 07:49:09 <----- time of panic
thread 'main' panicked at 'assertion failed: self.slab.is_empty()', /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/h2-0.1.26/src/proto/streams/store.rs:218:13
stack backtrace:
0: 0x55881bc470eb - backtrace::backtrace::libunwind::trace::h89fcc71e59e3bc5b
at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/libunwind.rs:88
1: 0x55881bc470eb - backtrace::backtrace::trace_unsynchronized::h0bad9be1379e729a
at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/mod.rs:66
2: 0x55881bc470eb - std::sys_common::backtrace::_print::hd3382a1f33c473da
at src/libstd/sys_common/backtrace.rs:47
3: 0x55881bc470eb - std::sys_common::backtrace::print::h0ec6f03cfb8e76a6
at src/libstd/sys_common/backtrace.rs:36
4: 0x55881bc470eb - std::panicking::default_hook::{{closure}}::h96cbf7b454e3f557
at src/libstd/panicking.rs:200
5: 0x55881bc46dc6 - std::panicking::default_hook::h95a8f00337383d83
at src/libstd/panicking.rs:214
6: 0x55881bc4785d - std::panicking::rust_panic_with_hook::h92f98b46e22f14ed
at src/libstd/panicking.rs:477
7: 0x55881bc30385 - std::panicking::begin_panic::h191a31865b200d66
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/panicking.rs:411
8: 0x55881b4f69d0 - <h2::proto::streams::store::Store as core::ops::drop::Drop>::drop::h440b448e5d8542b5
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/h2-0.1.26/src/proto/streams/store.rs:218
9: 0x55881b518a45 - core::ptr::real_drop_in_place::h7ade7d603e33e67b
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
10: 0x55881b517abe - core::ptr::real_drop_in_place::h345a45ac9ab893a9
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
11: 0x55881b519b31 - core::ptr::real_drop_in_place::he32a4bdfeb463f93
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
12: 0x55881b51999c - core::ptr::real_drop_in_place::hcb140325282b971b
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
13: 0x55881b545954 - core::ptr::drop_in_place::hd84c172334735b94
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:165
14: 0x55881b545954 - alloc::sync::Arc<T>::drop_slow::h4ef6a04653915684
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/liballoc/sync.rs:564
15: 0x55881b545e68 - <alloc::sync::Arc<T> as core::ops::drop::Drop>::drop::h7e6a3623b725b8b7
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/liballoc/sync.rs:1053
16: 0x55881a061c7f - core::ptr::real_drop_in_place::h853d77acb2b564cd
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
17: 0x55881a05f692 - core::ptr::real_drop_in_place::h7f93e10c4e4068f7
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
18: 0x55881a047431 - core::ptr::real_drop_in_place::h4450a60665047473
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
19: 0x55881a051ae2 - core::ptr::real_drop_in_place::h5deb07e4de4d161c
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
20: 0x55881a07111d - core::ptr::real_drop_in_place::ha9ae538cad463716
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
21: 0x55881a091c91 - core::ptr::real_drop_in_place::hf8bada2400a2446b
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
22: 0x55881a0683b1 - core::ptr::real_drop_in_place::h95200bb8dd80c856
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
23: 0x55881a0546f1 - core::ptr::real_drop_in_place::h650ef5029d56aa73
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
24: 0x55881a073d01 - core::ptr::real_drop_in_place::haf4f25000c13dc7c
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
25: 0x55881a0835c1 - core::ptr::real_drop_in_place::hd3d5c53b6ff4de0a
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
26: 0x55881a0854bb - core::ptr::real_drop_in_place::hd904f19aae386dd5
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
27: 0x55881a02e061 - core::ptr::real_drop_in_place::h054ec3da695af5f7
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
28: 0x55881a05407b - core::ptr::real_drop_in_place::h6442bd2706eb474d
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
29: 0x55881a03d181 - core::ptr::real_drop_in_place::h2b46e807f2d5dfbf
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libcore/ptr/mod.rs:175
30: 0x55881a8c5d57 - futures::future::chain::Chain<A,B,C>::poll::haa3cae4f9bcb53ac
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/future/chain.rs:38
31: 0x55881a9e2e5d - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::h82b9ce9765c0df64
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/future/and_then.rs:32
32: 0x55881a88b755 - futures::future::chain::Chain<A,B,C>::poll::h1bee07dee2f31c32
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/future/chain.rs:26
33: 0x55881a9e2bed - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::h7070d49f6e328ad1
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/future/and_then.rs:32
34: 0x55881a9b67aa - futures::task_impl::Spawn<T>::poll_future_notify::{{closure}}::h90444c0e8b3c3f24
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/task_impl/mod.rs:329
35: 0x55881a9b896a - futures::task_impl::Spawn<T>::enter::{{closure}}::h6b4d030db7eda867
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/task_impl/mod.rs:399
36: 0x55881a01cfdc - futures::task_impl::std::set::h2ea56082f57284e3
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/task_impl/std/mod.rs:83
37: 0x55881a9b79b3 - futures::task_impl::Spawn<T>::enter::h8d0189b18f54b35d
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/task_impl/mod.rs:399
38: 0x55881a9b4a55 - futures::task_impl::Spawn<T>::poll_fn_notify::h467a210c7cb0c05f
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/task_impl/mod.rs:291
39: 0x55881a9b63ce - futures::task_impl::Spawn<T>::poll_future_notify::he883805e82e3d6c7
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/task_impl/mod.rs:329
40: 0x55881a3b5666 - tokio_current_thread::Entered<P>::block_on::{{closure}}::hc9f079d856da8056
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-current-thread-0.1.6/src/lib.rs:494
41: 0x55881a3b4ac5 - tokio_current_thread::Borrow<U>::enter::{{closure}}::{{closure}}::h26b5a7d5266ea203
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-current-thread-0.1.6/src/lib.rs:788
42: 0x55881a3b47de - tokio_current_thread::CurrentRunner::set_spawn::he7515b0ef7c88907
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-current-thread-0.1.6/src/lib.rs:825
43: 0x55881a3b4985 - tokio_current_thread::Borrow<U>::enter::{{closure}}::h4db6d51e4b1d7b78
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-current-thread-0.1.6/src/lib.rs:788
44: 0x55881a84dd65 - std::thread::local::LocalKey<T>::try_with::h63e4e5d7785af222
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/thread/local.rs:262
45: 0x55881a84c5c5 - std::thread::local::LocalKey<T>::with::he6f81d9372d27642
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/thread/local.rs:239
46: 0x55881a3b48cf - tokio_current_thread::Borrow<U>::enter::h7e41f1f1514ca366
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-current-thread-0.1.6/src/lib.rs:786
47: 0x55881a3b51e2 - tokio_current_thread::Entered<P>::block_on::hde6d2cfde94c8756
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-current-thread-0.1.6/src/lib.rs:491
48: 0x55881a570ba8 - tokio::runtime::current_thread::runtime::Runtime::block_on::{{closure}}::hbb0a98b5d0e5fdea
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.1.22/src/runtime/current_thread/runtime.rs:200
49: 0x55881a5708dc - tokio::runtime::current_thread::runtime::Runtime::enter::{{closure}}::{{closure}}::{{closure}}::{{closure}}::hbb72fe45666cfd28
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.1.22/src/runtime/current_thread/runtime.rs:241
50: 0x55881a01ad3c - tokio_executor::global::with_default::{{closure}}::h4902d53165149e4f
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-executor-0.1.8/src/global.rs:209
51: 0x55881a84ed1d - std::thread::local::LocalKey<T>::try_with::hb2b45a52a4638784
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/thread/local.rs:262
52: 0x55881a84b7d7 - std::thread::local::LocalKey<T>::with::h17cb72c0eb2e9139
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/thread/local.rs:239
53: 0x55881a01a9b1 - tokio_executor::global::with_default::hd307591e0bc7028a
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-executor-0.1.8/src/global.rs:178
54: 0x55881a5706ac - tokio::runtime::current_thread::runtime::Runtime::enter::{{closure}}::{{closure}}::{{closure}}::h50ef844dda95fc14
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.1.22/src/runtime/current_thread/runtime.rs:239
55: 0x55881aa7cb79 - tokio_timer::timer::handle::with_default::{{closure}}::hb835421b1cf4ef5d
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.11/src/timer/handle.rs:101
56: 0x55881a84eb7d - std::thread::local::LocalKey<T>::try_with::hb2517ad7c54d4801
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/thread/local.rs:262
57: 0x55881a84bb97 - std::thread::local::LocalKey<T>::with::h68a7b43153c4752c
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/thread/local.rs:239
58: 0x55881aa7c663 - tokio_timer::timer::handle::with_default::hd08e192c3bb13c7d
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.11/src/timer/handle.rs:84
59: 0x55881a57056c - tokio::runtime::current_thread::runtime::Runtime::enter::{{closure}}::{{closure}}::h533f67e059c43e10
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.1.22/src/runtime/current_thread/runtime.rs:232
60: 0x55881a5ce64a - tokio_timer::clock::clock::with_default::{{closure}}::h57d511ae1105f0ee
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.11/src/clock/clock.rs:137
61: 0x55881a84c929 - std::thread::local::LocalKey<T>::try_with::h0a7de7cbd180f199
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/thread/local.rs:262
62: 0x55881a84c645 - std::thread::local::LocalKey<T>::with::hee27759bc2009b49
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/thread/local.rs:239
63: 0x55881a5ce322 - tokio_timer::clock::clock::with_default::hfade4dcb6823d1b8
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.11/src/clock/clock.rs:117
64: 0x55881a570453 - tokio::runtime::current_thread::runtime::Runtime::enter::{{closure}}::h2a526e1bc7d7bf89
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.1.22/src/runtime/current_thread/runtime.rs:231
65: 0x55881a0fd3c8 - tokio_reactor::with_default::{{closure}}::hdce692d89c56e924
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-reactor-0.1.10/src/lib.rs:237
66: 0x55881a84f19d - std::thread::local::LocalKey<T>::try_with::hc1ac066573435cbe
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/thread/local.rs:262
67: 0x55881a84ba47 - std::thread::local::LocalKey<T>::with::h42f90e6bc0be8c41
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/thread/local.rs:239
68: 0x55881a0fce33 - tokio_reactor::with_default::hde5fffeef69534b4
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-reactor-0.1.10/src/lib.rs:217
69: 0x55881a5701cc - tokio::runtime::current_thread::runtime::Runtime::enter::h2a464fbd626524b8
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.1.22/src/runtime/current_thread/runtime.rs:230
70: 0x55881a570b34 - tokio::runtime::current_thread::runtime::Runtime::block_on::hbe5d0a93fec01154
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.1.22/src/runtime/current_thread/runtime.rs:198
71: 0x55881a2b05fb - tokio::runtime::current_thread::block_on_all::h689aa641651ef9f9
at /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.1.22/src/runtime/current_thread/mod.rs:92
72: 0x55881a2b44d1 - jormungandr::network::bootstrap::bootstrap_from_peer::h60211fa290a32962
at jormungandr/src/network/bootstrap.rs:108
73: 0x55881a909bf5 - jormungandr::network::bootstrap::h1aa1cc9c4561d44c
at jormungandr/src/network/mod.rs:405
74: 0x55881a417110 - jormungandr::bootstrap::h5aabac36ee047fcb
at jormungandr/src/main.rs:325
75: 0x55881a41368d - jormungandr::start::h6d4f370f950b1a3c
at jormungandr/src/main.rs:88
76: 0x55881a418de1 - jormungandr::main::h12b3c5d5542f7c91
at jormungandr/src/main.rs:411
77: 0x55881a1717a0 - std::rt::lang_start::{{closure}}::h2c6c573715cfb24d
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/rt.rs:64
78: 0x55881bc47263 - std::rt::lang_start_internal::{{closure}}::h4e93c1949c7a1955
at src/libstd/rt.rs:49
79: 0x55881bc47263 - std::panicking::try::do_call::h9440ccd4dc467eaa
at src/libstd/panicking.rs:296
80: 0x55881bc4b83a - __rust_maybe_catch_panic
at src/libpanic_unwind/lib.rs:80
81: 0x55881bc47e2d - std::panicking::try::hc046e7ee42ee744f
at src/libstd/panicking.rs:275
82: 0x55881bc47e2d - std::panic::catch_unwind::h27dfc457c200aee0
at src/libstd/panic.rs:394
83: 0x55881bc47e2d - std::rt::lang_start_internal::hea1b49a567afe309
at src/libstd/rt.rs:48
84: 0x55881a171779 - std::rt::lang_start::h98a444bb784dae28
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/libstd/rt.rs:64
85: 0x55881a4190da - main
86: 0x7f829ad2809b - __libc_start_main
87: 0x558819ebd30a - _start
88: 0x0 - <unknown>
Expected behavior
No panic or at least some error information.
Additional context
Filed an upstream issue: hyperium/h2#417.
Do we still experience this issue?
Do we still experience this issue?
@NicolasDP - I will check and try again to reproduce it. However based on the conversation @mzabaluev had with h2 dev it looks like not much can be done on jormungandr side. I've checked from time to time if there is any development/commit/mention regarding the reported issue upstream, but found nothing.
Just happened to me again with ddddfb558a1e7356691d406ee8cbb59886e26f3e.
based in @mzabaluev 's investigation it seems that this is the root cause for the QA testnet being down at this moment - using v0.7.2
Update: jormungandr 0.8.0-rc9+1https://github.com/input-output-hk/jormungandr/commit/41380a3afcaa3ca7b3410a3f7eac730b5a3c2f72
This has evolved a bit in the latest master. Now is the network thread that panics.
thread 'network1' panicked at 'assertion failed: self.slab.is_empty()', /home/rinor/.cargo/registry/src/github.com-1ecc6299db9ec823/h2-0.1.26/src/proto/streams/store.rs:218:13
Dec 08 16:46:45.882 WARN request timed out or failed unexpectedly, error: Error(Elapsed), request: GetHeadersRange, task: client-query
...
Dec 08 17:12:25.672 WARN blockchain is not moving up, the last block was 1841 seconds ago, task: stuck_notifier
Dec 08 17:13:25.669 WARN blockchain is not moving up, the last block was 1901 seconds ago, task: stuck_notifier
After that it appears that nothing is processed (network wise).
Furthermore also jcli rest v0 network stats get times out, while other rest requests do get replied.
jcli rest v0 network stats get --host "http://127.0.0.11:8001/api"
failed to make a REST request
|-> connection with node timed out
|-> http://127.0.0.11:8001/api/v0/network/stats: timed out
Naive Question: Since there is no new info on h2 side, is there any workaround that we can do here? Since now the node does not stop/crash, but only the network thread is affected, is it possible to recover from that panic by reloading/restarting the network? Anything (that does not require full node restart) would be better than stalling.
These should not bother us since h2 has been updated to 0.2.5 (https://github.com/hyperium/h2/issues/417).