Jormungandr: not yet implemented: method to load a Ref from the storage is not yet there

Created on 17 Sep 2019  路  29Comments  路  Source: input-output-hk/jormungandr

Describe the bug
When restarting a node with trusted peer this happen:

Sep 17 21:20:44.134 INFO Starting jormungandr 0.3.3 (, release, linux [x86_64]) - [rustc 1.36.0 (a53f9df32 2019-07-03)], task: init
Sep 17 21:20:44.134 INFO storing blockchain in '"./storage/blocks.sqlite"', task: init
Sep 17 21:20:44.151 INFO connecting to bootstrap peer 3.122.73.200:3000, peer: /ip4/3.122.73.200/tcp/3000, network: bootstrap, task: bootstrap
thread 'main' panicked at 'not yet implemented: method to load a Ref from the storage is not yet there', jormungandr/src/blockchain/chain.rs:259:37
stack backtrace:
   0: std::sys::unix::backtrace::tracing::imp::unwind_backtrace
   1: std::sys_common::backtrace::_print
   2: std::panicking::default_hook::{{closure}}
   3: std::panicking::default_hook
   4: std::panicking::rust_panic_with_hook
   5: std::panicking::continue_panic_fmt
   6: std::panicking::begin_panic_fmt
   7: futures::future::chain::Chain<A,B,C>::poll
   8: futures::future::chain::Chain<A,B,C>::poll
   9: futures::future::chain::Chain<A,B,C>::poll
  10: futures::future::chain::Chain<A,B,C>::poll
  11: futures::future::chain::Chain<A,B,C>::poll
  12: futures::future::chain::Chain<A,B,C>::poll
  13: futures::future::chain::Chain<A,B,C>::poll
  14: <futures::stream::fold::Fold<S,F,Fut,T> as futures::future::Future>::poll
  15: futures::future::chain::Chain<A,B,C>::poll
  16: futures::future::chain::Chain<A,B,C>::poll
  17: futures::future::chain::Chain<A,B,C>::poll
  18: futures::task_impl::std::set
  19: std::thread::local::LocalKey<T>::with
  20: tokio_current_thread::Entered<P>::block_on
  21: std::thread::local::LocalKey<T>::with
  22: std::thread::local::LocalKey<T>::with
  23: std::thread::local::LocalKey<T>::with
  24: std::thread::local::LocalKey<T>::with
  25: tokio::runtime::current_thread::runtime::Runtime::block_on
  26: tokio::runtime::current_thread::block_on_all
  27: jormungandr::network::bootstrap::bootstrap_from_peer
  28: jormungandr::network::bootstrap
  29: jormungandr::main
  30: std::rt::lang_start::{{closure}}
  31: std::panicking::try::do_call
  32: __rust_maybe_catch_panic
  33: std::rt::lang_start_internal
  34: main
  35: __libc_start_main
  36: _start

Mandatory Information
running revision 646b07116e2f40be66aee51df5e353c56b4fdd9e.

To Reproduce
Steps to reproduce the behavior:
1.
nix-shell https://github.com/input-output-hk/jormungandr-nix/archive/listen-address.tar.gz --argstr trusted_peers /ip4/3.122.73.200/tcp/3000
2.
mkdir storage
3.
uncompress/copy attached sqlite db into the storage folder
4.
RUST_BACKTRACE=1 run-jormungandr

Expected behavior
the node start correctly.

Additional context
the genesis block of the cluster was generated using the following command:
nix-shell https://github.com/input-output-hk/jormungandr-nix/archive/listen-address.tar.gz --arg numberOfStakePools 7 --arg faucetAmounts '[ 1000000000 1000000000 1000000000 1000000000 1000000000 1000000000 1000000000 100000000 100000000 100000000 ]' --arg slots_per_epoch 21600 --arg slot_duration 20 --arg consensus_genesis_praos_active_slot_coeff 0.1 --arg kes_update_speed 86400 --arg numberOfLeaders 7

blocks.zip

bug subsys-network subsys-block Priority - High

Most helpful comment

This still exists on 0.5.6

All 29 comments

This seems linked to #783 (or at least relates to)

Getting this error again on jormungandr 0.5.2 (, release, linux [x86_64]) - [rustc 1.37.0 (eae3437df 2019-08-13)]:

Sep 30 11:54:34.432 INFO incoming P2P connection on 172.31.32.144:3000, peer_addr: 172.105.197.118:53602, task: network
thread 'block0' panicked at 'not yet implemented: method to load a Ref from the storage is not yet there', jormungandr/src/blockchain/chain.rs:259:37
stack backtrace:
   0: std::panicking::default_hook::{{closure}}
   1: std::panicking::default_hook
   2: std::panicking::rust_panic_with_hook
   3: std::panicking::continue_panic_fmt
   4: std::panicking::begin_panic_fmt
   5: futures::future::chain::Chain<A,B,C>::poll
   6: futures::future::chain::Chain<A,B,C>::poll
   7: futures::future::chain::Chain<A,B,C>::poll
   8: futures::future::chain::Chain<A,B,C>::poll
   9: futures::future::chain::Chain<A,B,C>::poll
  10: futures::future::chain::Chain<A,B,C>::poll
  11: futures::task_impl::std::set
  12: std::thread::local::LocalKey<T>::with
  13: futures::future::Future::wait
  14: jormungandr::blockchain::process::handle_input
  15: <futures::stream::for_each::ForEach<S,F,U> as futures::future::Future>::poll
  16: futures::task_impl::std::set
  17: std::panicking::try::do_call
  18: __rust_maybe_catch_panic
  19: tokio_threadpool::task::Task::run
  20: tokio_threadpool::worker::Worker::run_task
  21: tokio_threadpool::worker::Worker::run
  22: std::thread::local::LocalKey<T>::with
  23: std::thread::local::LocalKey<T>::with
  24: tokio_reactor::with_default
  25: tokio::runtime::threadpool::builder::Builder::build::{{closure}}
  26: std::thread::local::LocalKey<T>::with
  27: std::thread::local::LocalKey<T>::with
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

So it looks like this error arise when a node try to bootstrap from a trusted peer that is offering a shorter blockchain that what the node already has in local storage.
@NicolasDP do you confirm that this is a plausible scenario for this error?

@NicolasDP this is a problem as restarting nodes panics if it tries to bootstrap from a machine with an older chain. Can we have the priority increased?

This just happend to me as well, here are my logs:
node_log.log
strace.log

run with:
trace -o strace.log -f -t -e trace='%desc' -e '!read,recvfrom,write,writev,epoll_wait,lseek,fcntl,futex,sched_yield,getrandom' jormungandr ...

Sam and Priyank told me this error could be related to #788 and to post the output here. I am using Mac OSX 10.14.6 and Jormungandr 0.5.5 on a node that normally runs many hours without a crash. This is not a Nix build but built from jormungandr-v0.5.5-x86_64-apple-darwin.tar

Oct 02 21:16:38.642 WARN UploadBlocks request failed: Error { code: Internal, source: Status { code: Internal, message: "h2 protocol error: protocol error: unexpected internal error encountered" } }, node_id: 15250992350008249921, peer_addr: 3.115.57.216:3000, task: network
thread 'block1' panicked at 'not yet implemented: method to load a Ref from the storage is not yet there', jormungandr/src/blockchain/chain.rs:259:37
note: run with RUST_BACKTRACE=1 environment variable to display a backtrace.
not yet implemented: method to load a Ref from the storage is not yet there
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1166:5

@NicolasDP, @mzabaluev I believe that what is @rickymac68 reporting is still happening. I'm on source build jormungandr 0.5.5 (master-4f66dddc+, release, linux [x86_64]) and I'm experiencing this issue as well.

Oct 06 19:38:25.956 INFO client P2P connection closed, node_id: 16378372149886300164, peer_addr: 45.32.227.174:3000, task: network
Oct 06 19:38:28.453 INFO error connecting to peer, reason: No route to host (os error 113), peer_addr: 98.127.116.122:6969, task: network
Oct 06 19:38:28.453 INFO client P2P connection closed, node_id: 17277467795327450089, peer_addr: 98.127.116.122:6969, task: network
thread 'block0' panicked at 'not yet implemented: method to load a Ref from the storage is not yet there', jormungandr/src/blockchain/chain.rs:259:37
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace.
not yet implemented: method to load a Ref from the storage is not yet there
thread 'Oct 06 19:38:29.286leadership0' panicked at 'Expect the event to not close ', src/libcore/option.rs:WARN1166: 5

This still exists on 0.5.6

This just occured to me on v0.5.6:

{"msg":"error while streaming response: Error { code: Internal, cause: CannotIterate }","level":"WARN","ts":"2019-10-12T01:35:00.516697841+00:00","node_id":"11618830719927156519","peer_addr":"35.228.147.137:7681","task":"network"}
{"msg":"UploadBlocks request failed: Error { code: Internal, source: Status { code: Internal, message: \"h2 protocol error: protocol error: unexpected internal error encountered\" } }","level":"INFO","ts":"2019-10-12T01:35:00.516859513+00:00","node_id":"11618830719927156519","peer_addr":"35.228.147.137:7681","task":"network"}
{"msg":"PullBlocksToTip response stream failed: Error { code: Internal, source: Status { code: Internal, message: \"internal processing error\" } }","level":"INFO","ts":"2019-10-12T01:35:02.260891323+00:00","node_id":"14335234725810293289","peer_addr":"3.122.125.100:3000","task":"network鈥潁
0|start-no | thread 'block0' panicked at 'not yet implemented: method to load a Ref from the storage is not yet there', jormungandr/src/blockchain/chain.rs:259:37
0|start-no | note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace.
0|start-no | not yet implemented: method to load a Ref from the storage is not yet there
jormungandr 0.5.6 (master-3c613ee0, release, linux [x86_64]) - [rustc 1.38.0 (625451e37 2019-09-23)]

Still exists on 6.0.0
`
vel":"INFO","ts":"2019-10-15T11:42:21.301283723+02:00","peer_addr":"54.153.19.202:3000","task":"network","reason":"Connection refused (os error 111)"}
{"msg":"error connecting to peer","level":"INFO","ts":"2019-10-15T11:42:21.409964659+02:00","peer_addr":"3.115.194.22:3000","task":"network","reason":"Connection refused (os error 111)"}
thread 'block0' panicked at 'not yet implemented: method to load a Ref from the storage is not yet there', jormungandr/src/blockchain/chain.rs:259:37
stack backtrace:
0: 0x5635bc38302b - backtrace::backtrace::libunwind::trace::h89fcc71e59e3bc5b
at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/libunwind.rs:88
1: 0x5635bc38302b - backtrace::backtrace::trace_unsynchronized::h0bad9be1379e729a
at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/mod.rs:66
2: 0x5635bc38302b - std::sys_common::backtrace::_print::hd3382a1f33c473da
at src/libstd/sys_common/backtrace.rs:47
3: 0x5635bc38302b - std::sys_common::backtrace::print::h0ec6f03cfb8e76a6
at src/libstd/sys_common/backtrace.rs:36
4: 0x5635bc38302b - std::panicking::default_hook::{{closure}}::h96cbf7b454e3f557
at src/libstd/panicking.rs:200
5: 0x5635bc382d06 - std::panicking::default_hook::h95a8f00337383d83
at src/libstd/panicking.rs:214
6: 0x5635bc38379d - std::panicking::rust_panic_with_hook::h92f98b46e22f14ed
at src/libstd/panicking.rs:477
7: 0x5635bc383322 - std::panicking::continue_panic_fmt::h25abfbb4e5b7043a
at src/libstd/panicking.rs:384
8: 0x5635bc38326f - std::panicking::begin_panic_fmt::hc33ce01c7f7cd52d
at src/libstd/panicking.rs:339
9: 0x5635bbe4c10e - futures::future::chain::Chain::poll::hc802e0ce773405b3
10: 0x5635bbe5526e - futures::future::chain::Chain::poll::he659133cca523f13
11: 0x5635bbe60f79 - futures::future::chain::Chain::poll::hfe29b133f2cba25e
12: 0x5635bbe0b1a7 - futures::future::chain::Chain::poll::h37ad72e1de3867bb
13: 0x5635bbe29bdb - futures::future::chain::Chain::poll::h710c34a667e0c485
14: 0x5635bbd38594 - futures::task_impl::std::set::h36ea90f319e7575a
15: 0x5635bbb0c7fc - std::thread::local::LocalKey::with::h060bde5663561077
16: 0x5635bbbd664c - futures::future::Future::wait::hc3908246ab33172b
17: 0x5635bbf02fb9 - jormungandr::blockchain::process::run_handle_input::heaeb842bfda0817d
18: 0x5635bbeffdea - jormungandr::blockchain::process::handle_input::h79cb277ff6138b8a
19: 0x5635bbdfa22b - futures::future::catch_unwind::>::poll::hf463501d6d2c781f
20: 0x5635bba4783c - std::panicking::try::do_call::h8febcd1b74ac34eb
21: 0x5635bc38777a - __rust_maybe_catch_panic
at src/libpanic_unwind/lib.rs:80
22: 0x5635bbc245f6 - as futures::future::Future>::poll::he121ebf08418841a
23: 0x5635bbc204e5 - as futures::future::Future>::poll::hda03856537c5c49a
24: 0x5635bc360082 - futures::task_impl::std::set::h19287d092715b0c6
25: 0x5635bc35fcb2 - std::panicking::try::do_call::h95eda1c6d1780785
26: 0x5635bc38777a - __rust_maybe_catch_panic
at src/libpanic_unwind/lib.rs:80
27: 0x5635bc35f8d9 - tokio_threadpool::task::Task::run::h4390d3a630692d70
28: 0x5635bc35a556 - tokio_threadpool::worker::Worker::run_task::h69272c057f74a1be
29: 0x5635bc3599f0 - tokio_threadpool::worker::Worker::run::h12ae03ca77efb8aa
30: 0x5635bc3396b0 - std::thread::local::LocalKey::with::h2e60e1c599c2492c
31: 0x5635bc339d88 - std::thread::local::LocalKey::with::h8326b5dcd39e66cf
32: 0x5635bc339a9f - std::thread::local::LocalKey::with::h4c63294a8f2719ac
33: 0x5635bc33d69e - tokio::runtime::threadpool::builder::Builder::build::{{closure}}::h8c8fe1a41aecf62a
34: 0x5635bc35d17a - std::thread::local::LocalKey::with::hb16b02795dd0943a
35: 0x5635bc35cf69 - std::thread::local::LocalKey::with::h9c883615db26fc1d
36: 0x5635bc356cd8 - std::sys_common::backtrace::__rust_begin_short_backtrace::h4da395819657b52a
37: 0x5635bc35fcfc - std::panicking::try::do_call::ha774c1441d731aaf
38: 0x5635bc38777a - __rust_maybe_catch_panic
at src/libpanic_unwind/lib.rs:80
39: 0x5635bc357da0 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h1d2eaa2374bbdff4
40: 0x5635bc373fff - as core::ops::function::FnOnce>::call_once::h2877b2aefb0fd627
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/liballoc/boxed.rs:787
41: 0x5635bc386ac0 - as core::ops::function::FnOnce
>::call_once::h13f473dbcdaa0fef
at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/liballoc/boxed.rs:787
42: 0x5635bc386ac0 - std::sys_common::thread::start_thread::h562a7c4953cb1d31
at src/libstd/sys_common/thread.rs:13
43: 0x5635bc386ac0 - std::sys::unix::thread::Thread::new::thread_start::h382c6ae14181d163
at src/libstd/sys/unix/thread.rs:79
44: 0x7f3a3927e6db - start_thread
45: 0x7f3a38d8f88f - __clone
46: 0x0 -

`

I also experienced this twice today, using v0.6.0

Oct 15 12:15:20.788 INFO peer responded with different node id: 9ef1a86fb6d2a99567587853cd3118a68973cc4fb6fe1861f5f75b39fc31bf3b, node_id: 9ef1a86fb6d2a99567587853cd3118a68973cc4fb6fe1861f5f75b39fc31bf3b, peer_addr: 51.79.35.204:6666, task: network
Oct 15 12:15:21.182 INFO error connecting to peer, reason: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. (os error 10060), peer_addr: 85.218.89.33:50500, task: network
thread 'block0' panicked at 'not yet implemented: method to load a Ref from the storage is not yet there', jormungandr\src\blockchain\chain.rs:259:37
stack backtrace:
   0:           0x7d63e3 - backtrace::backtrace::dbghelp::trace::h5e9d2eba4720b7ac
                               at C:\Users\VssAdministrator\.cargo\registry\src\github.com-1ecc6299db9ec823\backtrace-0.3.34\src\backtrace/dbghelp.rs:88
   1:           0x7d63e3 - backtrace::backtrace::trace_unsynchronized::hd2d1bfb115460c6d
                               at C:\Users\VssAdministrator\.cargo\registry\src\github.com-1ecc6299db9ec823\backtrace-0.3.34\src\backtrace/mod.rs:66
   2:           0x7d63e3 - std::sys_common::backtrace::_print::hd03fe26089330b90
                               at src\libstd\sys_common/backtrace.rs:47
   3:           0x7d63e3 - std::sys_common::backtrace::print::h7a0ffa165d6e65e6
                               at src\libstd\sys_common/backtrace.rs:36
   4:           0x7d63e3 - std::panicking::default_hook::{{closure}}::hc4b8a134a08c99d0
                               at src\libstd/panicking.rs:200
   5:           0x7d55ea - std::panicking::default_hook::h555d420ce189cd9c
                               at src\libstd/panicking.rs:214
   6:           0x7d55ea - std::panicking::rust_panic_with_hook::h5ee54dc12c495453
                               at src\libstd/panicking.rs:477
   7:           0x7dba92 - std::panicking::continue_panic_fmt::h1dcf16bb2fdbf09c
                               at src\libstd/panicking.rs:384
   8:           0x7dba2c - std::panicking::begin_panic_fmt::h292c304c1aa64bdf
                               at src\libstd/panicking.rs:339
   9:           0xbb7375 - <futures::future::either::Either<A,B> as futures::future::Future>::poll::hd4af48b45cf7d8a2
  10:           0x98ea52 - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::h22378ee93316a717
  11:           0x9a93c4 - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::h754bd620ad490ac5
  12:           0x9fc5e7 - <futures::future::map_err::MapErr<A,F> as futures::future::Future>::poll::h59eb358f6e0cab6f
  13:           0xc2ad02 - jormungandr::blockchain::process::run_handle_input::h0efc7d94b3069f9a
  14:           0x9fba0b - <futures::future::map_err::MapErr<A,F> as futures::future::Future>::poll::h55fa288551134c46
  15:           0x7ba27c - <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::hc699b47f53ecf30d
  16:           0x7bdae3 - tokio_threadpool::worker::Worker::run_task::h24bc6af519f4b63f
  17:           0x7bbc48 - tokio_threadpool::worker::Worker::run::h4b45d7f219e2b4d8
  18:           0x79f846 - std::thread::local::LocalKey<T>::with::hd14c3674ec23e082
  19:           0x7a3041 - tokio::runtime::threadpool::builder::Builder::build::{{closure}}::h263ae8f4c9faa860
  20:           0x7b97e4 - std::sys_common::backtrace::__rust_begin_short_backtrace::h97585d8bad4ccb70
  21:           0x7ba692 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h1394d9cecf6e852c
  22:           0x7e7536 - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::he13a04fb600ff287
                               at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54\src\liballoc/boxed.rs:787
  23:           0x7e8b3c - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::hb8c868d75fab1423
                               at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54\src\liballoc/boxed.rs:787
  24:           0x7e8b3c - std::sys_common::thread::start_thread::h1d84a837f703e334
                               at src\libstd\sys_common/thread.rs:13
  25:           0x7e8b3c - std::sys::windows::thread::Thread::new::thread_start::h3eed3e0632115ee6
                               at src\libstd\sys\windows/thread.rs:47
  26:     0x7ffbc9137bd4 - _rbt_backtrace_dwarf_add.cold
  27:     0x7ffbcabaced1 - _rbt_backtrace_dwarf_add.cold
not yet implemented: method to load a Ref from the storage is not yet therethread '
leadership0' panicked at 'Oct 15 12:15:22.475
log:
  format: plain
  level: info
  output: stderr
rest:
  listen: "127.0.0.1:9000"
p2p:
  private_id: ed25519_sk10hl0n8fac5ls7ldmydmx6fk4rl7ejhjv66uyvkdtlxexsf39cyssxkmc6s
  trusted_peers:
explorer:
  enabled: true
storage: "./storage"

@dorin100 why do you need the explorer for?

Only playing with it..

ok, and why do you need a private id for?

it remained after deleting the public_address and listen_address. I am not sure yet on the influence ..

no it influence nothing here. it's ok. just curious as this is not needed at all unless you are a trusted peer.

aha. ok, this was also my logic...to start with the private id in order to be able to be a trusted peer for other nodes in the future...

This just happend for me as well, v0.6.0.
Here is my logs and strace capture:
block0_panic.zip

Just happened with v0.6.1
node logs and strace:
block8_panic.zip

Seemingly the same issue while running v0.6.5
Full logs

Oct 23 17:37:03.604 INFO incoming P2P connection on 172.17.0.3:3100, peer_addr: 62.116.182.4:37458, task: network
thread 'block0' panicked at 'not yet implemented: method to load a Ref from the storage is not yet there', jormungandr/src/blockchain/chain.rs:259:37
stack backtrace:
   0:     0x55f2fbde3518 - backtrace::backtrace::libunwind::trace::h89fcc71e59e3bc5b
                               at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/libunwind.rs:88
   1:     0x55f2fbde3518 - backtrace::backtrace::trace_unsynchronized::h0bad9be1379e729a
                               at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/mod.rs:66
   2:     0x55f2fbde3518 - std::sys_common::backtrace::_print::hd3382a1f33c473da
                               at src/libstd/sys_common/backtrace.rs:47
   3:     0x55f2fbde3518 - std::sys_common::backtrace::print::h0ec6f03cfb8e76a6
                               at src/libstd/sys_common/backtrace.rs:36
   4:     0x55f2fbde3518 - std::panicking::default_hook::{{closure}}::h96cbf7b454e3f557
                               at src/libstd/panicking.rs:200
   5:     0x55f2fbde2c67 - std::panicking::default_hook::h95a8f00337383d83
                               at src/libstd/panicking.rs:214
   6:     0x55f2fbde2c67 - std::panicking::rust_panic_with_hook::h92f98b46e22f14ed
                               at src/libstd/panicking.rs:477
   7:     0x55f2fbde278f - std::panicking::continue_panic_fmt::h25abfbb4e5b7043a
                               at src/libstd/panicking.rs:384
   8:     0x55f2fbde273c - std::panicking::begin_panic_fmt::hc33ce01c7f7cd52d
                               at src/libstd/panicking.rs:339
   9:     0x55f2fba78fc3 - <futures::future::either::Either<A,B> as futures::future::Future>::poll::hec8df210c9bc763e
  10:     0x55f2fbfe5dd8 - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::h4ae66aab19e74a70
  11:     0x55f2fbff17ed - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::h7dc622fa76e9384e
  12:     0x55f2fbfd8a6e - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::h2191bd5eb0dd47b5
  13:     0x55f2fbe6da65 - <futures::future::map_err::MapErr<A,F> as futures::future::Future>::poll::h71e70f8f1534c27f
  14:     0x55f2fbf228ea - futures::task_impl::Spawn<T>::poll_future_notify::h07d9e647e0859f07
  15:     0x55f2fbe1b02b - std::thread::local::LocalKey<T>::with::h25384ce8e5192d4a
  16:     0x55f2fbe2afa4 - futures::future::Future::wait::h08c2ff88d8ce99ac
  17:     0x55f2fc22b3c7 - jormungandr::blockchain::process::run_handle_input::h9b136cecf6a227a3
  18:     0x55f2fbeee6e5 - <futures::stream::for_each::ForEach<S,F,U> as futures::future::Future>::poll::h95f26d7a4116996b
  19:     0x55f2fbe63fa0 - <futures::future::map_err::MapErr<A,F> as futures::future::Future>::poll::h2dff7153ad89e6d4
  20:     0x55f2fbdd7eae - futures::task_impl::std::set::hc5af9ca7fb3d8e18
  21:     0x55f2fbdd3c69 - tokio_threadpool::worker::Worker::run_task::hb9adf17aea724148
  22:     0x55f2fbdd1fb0 - tokio_threadpool::worker::Worker::run::h1de540ce50609a82
  23:     0x55f2fbdba1fa - std::thread::local::LocalKey<T>::with::hf99a5b5fb783d300
  24:     0x55f2fbdbb6e5 - tokio::runtime::threadpool::builder::Builder::build::{{closure}}::hf0017246924db371
  25:     0x55f2fbdd026f - std::sys_common::backtrace::__rust_begin_short_backtrace::h4c7a5861bb9e17ad
  26:     0x55f2fbdd1671 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h87c80692d3694042
  27:     0x55f2fbdf10af - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::h2877b2aefb0fd627
                               at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/liballoc/boxed.rs:787
  28:     0x55f2fbdf254c - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::h13f473dbcdaa0fef
                               at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/liballoc/boxed.rs:787
  29:     0x55f2fbdf254c - std::sys_common::thread::start_thread::h562a7c4953cb1d31
                               at src/libstd/sys_common/thread.rs:13
  30:     0x55f2fbdf254c - std::sys::unix::thread::Thread::new::thread_start::h382c6ae14181d163
                               at src/libstd/sys/unix/thread.rs:79
  31:     0x7f3f53bc76db - start_thread
  32:     0x7f3f536d888f - __clone
  33:                0x0 - <unknown>
not yet implemented: method to load a Ref from the storage is not yet there
thread 'leadership1' panicked at 'Expect the event to not close', src/libcore/option.rs:1166

The same issue while running v0.7.0-rc1

Oct 26 13:01:24.138 INFO incoming connection closed, peer_addr: 207.148.73.212:38862, task: network
Oct 26 13:01:24.138 INFO incoming connection closed, peer_addr: 207.148.73.212:38866, task: network
Oct 26 13:01:24.138 INFO incoming connection closed, peer_addr: 207.148.73.212:38876, task: network
Oct 26 13:01:24.145 INFO incoming connection closed, peer_addr: 207.148.73.212:38868, task: network
Oct 26 13:01:24.165 INFO incoming connection on 172.31.17.34:3100, peer_addr: 3.123.99.232:60310, task: network
Oct 26 13:01:24.187 INFO disconnecting client, node_id: 02017916f2704a4a0eb8a51005fae25a6b53eaaa94f400ea236b404f4df25187, peer_addr: 47.144.235.58:3000, task: network
Oct 26 13:01:24.360 INFO incoming connection closed, peer_addr: 3.123.99.232:60288, task: network
thread 'block0' panicked at 'not yet implemented: method to load a Ref from the storage is not yet there', jormungandr/src/blockchain/chain.rs:259:37
stack backtrace:
   0: backtrace::backtrace::libunwind::trace
             at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/libunwind.rs:88
   1: backtrace::backtrace::trace_unsynchronized
             at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/mod.rs:66
   2: std::sys_common::backtrace::_print
             at src/libstd/sys_common/backtrace.rs:47
   3: std::sys_common::backtrace::print
             at src/libstd/sys_common/backtrace.rs:36
   4: std::panicking::default_hook::{{closure}}
             at src/libstd/panicking.rs:200
   5: std::panicking::default_hook
             at src/libstd/panicking.rs:214
   6: std::panicking::rust_panic_with_hook
             at src/libstd/panicking.rs:477
   7: std::panicking::continue_panic_fmt
             at src/libstd/panicking.rs:384
   8: std::panicking::begin_panic_fmt
             at src/libstd/panicking.rs:339
   9: <futures::future::either::Either<A,B> as futures::future::Future>::poll
  10: <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll
  11: <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll
  12: <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll
  13: futures::task_impl::Spawn<T>::poll_future_notify
  14: jormungandr::blockchain::process::run_handle_input
  15: <futures::stream::for_each::ForEach<S,F,U> as futures::future::Future>::poll
  16: <futures::future::map_err::MapErr<A,F> as futures::future::Future>::poll
  17: futures::task_impl::std::set
  18: tokio_threadpool::worker::Worker::run_task
  19: tokio_threadpool::worker::Worker::run
  20: std::thread::local::LocalKey<T>::with
  21: tokio::runtime::threadpool::builder::Builder::build::{{closure}}
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
Oct 26 13:01:24.579 WARN response canceled by the processing task, sub_task: server, task: network
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1166:5
stack backtrace:
   0: backtrace::backtrace::libunwind::trace
             at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/libunwind.rs:88
   1: backtrace::backtrace::trace_unsynchronized
             at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/mod.rs:66
   2: std::sys_common::backtrace::_print
             at src/libstd/sys_common/backtrace.rs:47
   3: std::sys_common::backtrace::print
             at src/libstd/sys_common/backtrace.rs:36
   4: std::panicking::default_hook::{{closure}}
             at src/libstd/panicking.rs:200
   5: std::panicking::default_hook
             at src/libstd/panicking.rs:214
   6: std::panicking::rust_panic_with_hook
             at src/libstd/panicking.rs:477
   7: std::panicking::continue_panic_fmt
             at src/libstd/panicking.rs:384
   8: rust_begin_unwind
             at src/libstd/panicking.rs:311
   9: core::panicking::panic_fmt
             at src/libcore/panicking.rs:85
  10: core::option::expect_failed
             at src/libcore/option.rs:1166
  11: futures::future::chain::Chain<A,B,C>::poll
  12: <futures::future::loop_fn::LoopFn<A,F> as futures::future::Future>::poll
  13: <futures::future::map_err::MapErr<A,F> as futures::future::Future>::poll
  14: futures::task_impl::std::set
  15: tokio_threadpool::worker::Worker::run_task
  16: tokio_threadpool::worker::Worker::run
  17: std::thread::local::LocalKey<T>::with
  18: tokio::runtime::threadpool::builder::Builder::build::{{closure}}
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
Expect the event to not close

Same issue here on 0.7.0-rc1, though my backtrace looks a bit different:

Oct 29 11:21:07.320 INFO incoming connection on 192.168.1.10:3100, peer_addr: 18.196.168.220:44644, task: network
Oct 29 11:21:08.077 INFO incoming connection closed, peer_addr: 18.196.168.220:44634, task: network
Oct 29 11:21:10.675 INFO incoming connection on 192.168.1.10:3100, peer_addr: 49.236.136.104:33786, task: network
thread 'block0' panicked at 'not yet implemented: method to load a Ref from the storage is not yet there', jormungandr/src/blockchain/chain.rs:259:37
stack backtrace:
   0:     0x560639a33458 - backtrace::backtrace::libunwind::trace::h89fcc71e59e3bc5b
                               at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/libunwind.rs:88
   1:     0x560639a33458 - backtrace::backtrace::trace_unsynchronized::h0bad9be1379e729a
                               at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/mod.rs:66
   2:     0x560639a33458 - std::sys_common::backtrace::_print::hd3382a1f33c473da
                               at src/libstd/sys_common/backtrace.rs:47
   3:     0x560639a33458 - std::sys_common::backtrace::print::h0ec6f03cfb8e76a6
                               at src/libstd/sys_common/backtrace.rs:36
   4:     0x560639a33458 - std::panicking::default_hook::{{closure}}::h96cbf7b454e3f557
                               at src/libstd/panicking.rs:200
   5:     0x560639a32ba7 - std::panicking::default_hook::h95a8f00337383d83
                               at src/libstd/panicking.rs:214
   6:     0x560639a32ba7 - std::panicking::rust_panic_with_hook::h92f98b46e22f14ed
                               at src/libstd/panicking.rs:477
   7:     0x560639a326cf - std::panicking::continue_panic_fmt::h25abfbb4e5b7043a
                               at src/libstd/panicking.rs:384
   8:     0x560639a3267c - std::panicking::begin_panic_fmt::hc33ce01c7f7cd52d
                               at src/libstd/panicking.rs:339
   9:     0x5606396b2bed - <futures::future::either::Either<A,B> as futures::future::Future>::poll::he102dfb6e5d38d31
  10:     0x560639c0919b - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::h6921bd3577887478
  11:     0x560639c236c0 - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::hcbd6bcd81367fa50
  12:     0x560639c2b889 - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::he794209865f5ad37
  13:     0x560639b606bc - futures::task_impl::Spawn<T>::poll_future_notify::h668e97ee924aaa95
  14:     0x560639e58859 - jormungandr::blockchain::process::run_handle_input::h9584c4829b513e32
  15:     0x560639baff22 - <futures::stream::for_each::ForEach<S,F,U> as futures::future::Future>::poll::h8dce3094951f824b
  16:     0x560639ac365c - <futures::future::map_err::MapErr<A,F> as futures::future::Future>::poll::hbebf5f9146558439
  17:     0x560639a27bd0 - futures::task_impl::std::set::hc57a64808c0074ab
  18:     0x560639a23879 - tokio_threadpool::worker::Worker::run_task::h09219a3b51cd0000
  19:     0x560639a21bb0 - tokio_threadpool::worker::Worker::run::h3164fb022e02a2bd
  20:     0x560639a09b7a - std::thread::local::LocalKey<T>::with::hefd1f8ce66265f80
  21:     0x560639a0b115 - tokio::runtime::threadpool::builder::Builder::build::{{closure}}::h88ea929780d37dfc
  22:     0x560639a1fe7f - std::sys_common::backtrace::__rust_begin_short_backtrace::h4a3ea5bc2d1bd2bf
  23:     0x560639a212c1 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h20de39492aeb55b3
  24:     0x560639a40d8f - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::h2877b2aefb0fd627
                               at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/liballoc/boxed.rs:787
  25:     0x560639a4222c - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::h13f473dbcdaa0fef
                               at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/liballoc/boxed.rs:787
  26:     0x560639a4222c - std::sys_common::thread::start_thread::h562a7c4953cb1d31
                               at src/libstd/sys_common/thread.rs:13
  27:     0x560639a4222c - std::sys::unix::thread::Thread::new::thread_start::h382c6ae14181d163
                               at src/libstd/sys/unix/thread.rs:79
  28:     0x7f6e6e3264cf - start_thread
  29:     0x7f6e6e23b2d3 - clone
  30:                0x0 - <unknown>
not yet implemented: method to load a Ref from the storage is not yet there
thread 'leadership1' panicked at 'Expect the event to not close', src/libcore/option.rsOct 29 11:21:13.484 

As this error is still there, I'm attaching my jormungandr folder along with the data it had in this link.

The data is in the storage folder.

Using that database, the node simply won't start and it will crash with the error originally reported in a matter of seconds. Erasing the database is a workaround for the issue and the node starts fine after that. Hope the attached database can help you guys to find out what went wrong.

jormungandr 0.7.0-rc1 (HEAD-5583e5e, release, linux [x86_64]) - [rustc 1.38.0 (625451e37 2019-09-23)]
jcli 0.7.0-rc1 (HEAD-5583e5e, release, linux [x86_64]) - [rustc 1.38.0 (625451e37 2019-09-23)]

Just attaching @jbax bug.zip as the original file is on GDrive and may get lost...

bug.zip

20191030181824.log < log of the complete run from start to crash

just happened on 0.7.0-rc2

thread 'block1' panicked at 'not yet implemented: method to load a Ref from the storage is not yet there', jormungandr/src/blockchain/chain.rs:259:37
stack backtrace:
Oct 30 18:40:38.785 INFO received block announcement, hash: 40d486238d7cbc438f95e4b12ee4e8af958fd45b7637401278a84d2afb079c98, direction: in, stream: block_events, node_id: 4d11002db1a64aeecedb102626617c50815db940ad044e76bc822664a4c197d9, sub_task: server, task: network
Oct 30 18:40:38.791 INFO received block announcement, hash: d677a4dddff2271b164e7cb111616ffb75a4666681f744533874e07d98065b07, direction: in, stream: block_events, node_id: 4d11002db1a64aeecedb102626617c50815db940ad044e76bc822664a4c197d9, sub_task: server, task: network
   0:     0x55d1336731f8 - backtrace::backtrace::libunwind::trace::h89fcc71e59e3bc5b
                               at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/libunwind.rs:88
   1:     0x55d1336731f8 - backtrace::backtrace::trace_unsynchronized::h0bad9be1379e729a
                               at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.34/src/backtrace/mod.rs:66
   2:     0x55d1336731f8 - std::sys_common::backtrace::_print::hd3382a1f33c473da
                               at src/libstd/sys_common/backtrace.rs:47
   3:     0x55d1336731f8 - std::sys_common::backtrace::print::h0ec6f03cfb8e76a6
                               at src/libstd/sys_common/backtrace.rs:36
   4:     0x55d1336731f8 - std::panicking::default_hook::{{closure}}::h96cbf7b454e3f557
                               at src/libstd/panicking.rs:200
   5:     0x55d133672947 - std::panicking::default_hook::h95a8f00337383d83
                               at src/libstd/panicking.rs:214
   6:     0x55d133672947 - std::panicking::rust_panic_with_hook::h92f98b46e22f14ed
                               at src/libstd/panicking.rs:477
   7:     0x55d13367246f - std::panicking::continue_panic_fmt::h25abfbb4e5b7043a
                               at src/libstd/panicking.rs:384
   8:     0x55d13367241c - std::panicking::begin_panic_fmt::hc33ce01c7f7cd52d
                               at src/libstd/panicking.rs:339
   9:     0x55d1332e775d - <futures::future::either::Either<A,B> as futures::future::Future>::poll::hd03ca72def44a8f5
  10:     0x55d1338383ab - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::h1bec60803c4d5e27
  11:     0x55d1332f3ce2 - <futures::future::either::Either<A,B> as futures::future::Future>::poll::hfe4f7b59cae46667
  12:     0x55d133864714 - <futures::future::and_then::AndThen<A,B,F> as futures::future::Future>::poll::hd823d9a98bf0e385
  13:     0x55d133700f85 - <futures::future::map_err::MapErr<A,F> as futures::future::Future>::poll::hbedd28f540c29e30
  14:     0x55d13379fdbc - futures::task_impl::Spawn<T>::poll_future_notify::h54a69e9e7edfdf53
  15:     0x55d1332acf9e - futures::task_impl::std::ThreadNotify::with_current::hc69e01ceac33957a
  16:     0x55d133a94308 - jormungandr::blockchain::process::run_handle_input::h47f13cc5952f6dfb
  17:     0x55d1337e6012 - <futures::stream::for_each::ForEach<S,F,U> as futures::future::Future>::poll::h164b51cedf9c80f9
  18:     0x55d13370047c - <futures::future::map_err::MapErr<A,F> as futures::future::Future>::poll::haede806e5e984d54
  19:     0x55d133667b90 - futures::task_impl::std::set::hc57a64808c0074ab
  20:     0x55d133663949 - tokio_threadpool::worker::Worker::run_task::h09219a3b51cd0000
  21:     0x55d133661c80 - tokio_threadpool::worker::Worker::run::h3164fb022e02a2bd
  22:     0x55d133649cca - std::thread::local::LocalKey<T>::with::hefd1f8ce66265f80
  23:     0x55d13364b265 - tokio::runtime::threadpool::builder::Builder::build::{{closure}}::h88ea929780d37dfc
  24:     0x55d13365ff4f - std::sys_common::backtrace::__rust_begin_short_backtrace::h4a3ea5bc2d1bd2bf
  25:     0x55d133661391 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h20de39492aeb55b3
  26:     0x55d133680b8f - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::h2877b2aefb0fd627
                               at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/liballoc/boxed.rs:787
  27:     0x55d13368202c - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::h13f473dbcdaa0fef
                               at /rustc/625451e376bb2e5283fc4741caa0a3e8a2ca4d54/src/liballoc/boxed.rs:787
  28:     0x55d13368202c - std::sys_common::thread::start_thread::h562a7c4953cb1d31
                               at src/libstd/sys_common/thread.rs:13
  29:     0x55d13368202c - std::sys::unix::thread::Thread::new::thread_start::h382c6ae14181d163
                               at src/libstd/sys/unix/thread.rs:79
  30:     0x7f43a735f6db - start_thread
  31:     0x7f43a6e7088f - __clone
  32:                0x0 - <unknown>
not yet implemented: method to load a Ref from the storage is not yet there
thread 'leadership3' panicked at 'Expect the event to not close', src/libcore/option.rs:1166:5
stack backtrace:
   0:     0x55d1336731f8 - backtrace::backtrace::libunwind::trace::h89fcc71e59e3bc5b

2019_10_31_13_54_36.log
still relevant on 0.7.0-rc3

I've also seen this in jormungandr 0.7.0-rc3 (HEAD-466c0fb, release, linux [x86_64]) - [rustc 1.38.0 (625451e37 2019-09-23)].

## Log Snip

ov 01 18:51:57.617 WARN error while streaming response: Error { code: Internal, cause: CannotIterate }, node_id: 9d9f3c9f22d69d4585483e178ed977904472e599221f946024fe677cacf19be0, peer_addr: 184.169.162.15:3000, task: network
Nov 01 18:51:57.618 INFO UploadBlocks request failed, error: Error { code: Internal, source: Status { code: Internal, message: "h2 protocol error: protocol error: unexpected internal error encountered" } }, node_id: 9d9f3c9f22d69d4585483e178ed977904472e599221f946024fe677cacf19be0, peer_addr: 184.169.162.15:3000, task: network
Nov 01 18:51:57.642 WARN error while streaming response: Error { code: Internal, cause: CannotIterate }, node_id: 9d9f3c9f22d69d4585483e178ed977904472e599221f946024fe677cacf19be0, peer_addr: 184.169.162.15:3000, task: network
Nov 01 18:51:57.642 INFO UploadBlocks request failed, error: Error { code: Internal, source: Status { code: Internal, message: "h2 protocol error: protocol error: unexpected internal error encountered" } }, node_id: 9d9f3c9f22d69d4585483e178ed977904472e599221f946024fe677cacf19be0, peer_addr: 184.169.162.15:3000, task: network

This bug just killed all the stake and trusted peer nodes on nightly this weekend. First we had explorer crash, then all the other nodes followed, and they've been all restarting repeatedly with this panic on every start since the weekend.

Was this page helpful?
0 / 5 - 0 ratings