Jormungandr: node crashed with invalid block during leader event

[disassembler]

Describe the bug

leader event starting
thread 'block0' panicked at 'called `Result::unwrap()` on an `Err` value: Error(BlockHeaderVerificationFailed("Invalid block message"), State { next_error: None, backtrace: InternalBacktrace { backtrace: Some(stack backtrace:
   0: error_chain::backtrace::imp::InternalBacktrace::new
   1: <error_chain::State as core::default::Default>::default
   2: jormungandr::blockchain::chain::Blockchain::post_check_header
   3: futures::future::chain::Chain<A,B,C>::poll
   4: futures::future::chain::Chain<A,B,C>::poll
   5: <futures::future::map::Map<A,F> as futures::future::Future>::poll
   6: futures::task_impl::std::set
   7: std::thread::local::LocalKey<T>::with
   8: futures::future::Future::wait
   9: jormungandr::blockchain::process::handle_input
  10: <futures::stream::for_each::ForEach<S,F,U> as futures::future::Future>::poll
  11: futures::task_impl::std::set
  12: std::panicking::try::do_call
  13: __rust_maybe_catch_panic
  14: tokio_threadpool::task::Task::run
  15: tokio_threadpool::worker::Worker::run_task
  16: tokio_threadpool::worker::Worker::run
  17: std::thread::local::LocalKey<T>::with
  18: std::thread::local::LocalKey<T>::with
  19: tokio_reactor::with_default
  20: tokio::runtime::threadpool::builder::Builder::build::{{closure}}
  21: std::thread::local::LocalKey<T>::with
  22: std::thread::local::LocalKey<T>::with
  23: std::sys_common::backtrace::__rust_begin_short_backtrace
  24: std::panicking::try::do_call
  25: __rust_maybe_catch_panic
  26: core::ops::function::FnOnce::call_once{{vtable.shim}}
  27: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
  28: std::sys::unix::thread::Thread::new::thread_start
  29: start_thread
  30: __GI___clone
) } })', src/libcore/result.rs:999:5
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: rust_begin_unwind
   5: core::panicking::panic_fmt
   6: core::result::unwrap_failed
   7: jormungandr::blockchain::process::handle_input
   8: <futures::stream::for_each::ForEach<S,F,U> as futures::future::Future>::poll
   9: futures::task_impl::std::set
  10: std::panicking::try::do_call
  11: __rust_maybe_catch_panic
  12: tokio_threadpool::task::Task::run
  13: tokio_threadpool::worker::Worker::run_task
  14: tokio_threadpool::worker::Worker::run
  15: std::thread::local::LocalKey<T>::with
  16: std::thread::local::LocalKey<T>::with
  17: tokio_reactor::with_default
  18: tokio::runtime::threadpool::builder::Builder::build::{{closure}}
  19: std::thread::local::LocalKey<T>::with
  20: std::thread::local::LocalKey<T>::with
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5
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: rust_begin_unwind
   5: core::panicking::panic_fmt
   6: core::option::expect_failed
   7: futures::future::chain::Chain<A,B,C>::poll
   8: <futures::future::loop_fn::LoopFn<A,F> as futures::future::Future>::poll
   9: <futures::future::map_err::MapErr<A,F> as futures::future::Future>::poll
  10: futures::task_impl::std::set
  11: std::panicking::try::do_call
  12: __rust_maybe_catch_panic
  13: tokio_threadpool::task::Task::run
  14: tokio_threadpool::worker::Worker::run_task
  15: tokio_threadpool::worker::Worker::run
  16: std::thread::local::LocalKey<T>::with
  17: std::thread::local::LocalKey<T>::with
  18: tokio_reactor::with_default
  19: tokio::runtime::threadpool::builder::Builder::build::{{closure}}
  20: std::thread::local::LocalKey<T>::with
  21: std::thread::local::LocalKey<T>::with
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

Mandatory Information

1. jcli --full-version output;
2. jormungandr --full-version output;
   jcli 0.5.2 (, release, linux [x86_64]) - [rustc 1.37.0 (eae3437df 2019-08-13)]
   jormungandr 0.5.2 (, release, linux [x86_64]) - [rustc 1.37.0 (eae3437df 2019-08-13)]

Expected behavior
Node should not crash

Additional context
Add any other context about the problem here.

[mmahut]

Seeing this as well, anytime my node is elected as leader.

Sep 27 14:00:22.002 INFO leader event starting, date: 217.7404, leader: 1, task: leadership
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5
Sep 27 14:24:04.003 INFO leader event starting, date: 217.8115, leader: 1, task: leadership
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5
Sep 27 15:06:34.003 INFO leader event starting, date: 217.9390, leader: 1, task: leadership
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5
Sep 27 15:30:46.003 INFO leader event starting, date: 217.10116, leader: 1, task: leadership
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5
Sep 27 15:50:20.003 INFO leader event starting, date: 217.10703, leader: 1, task: leadership
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5
Sep 27 17:09:36.005 INFO leader event starting, date: 217.13081, leader: 1, task: leadership
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5
Sep 27 18:08:06.005 INFO leader event starting, date: 217.14836, leader: 1, task: leadership
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5
Sep 27 18:20:46.003 INFO leader event starting, date: 217.15216, leader: 1, task: leadership
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5
Sep 27 18:27:34.004 INFO leader event starting, date: 217.15420, leader: 1, task: leadership
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5
Sep 27 18:50:18.003 INFO leader event starting, date: 217.16102, leader: 1, task: leadership
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5
Sep 27 19:17:10.003 INFO leader event starting, date: 217.16908, leader: 1, task: leadership
thread 'leadership0' panicked at 'Expect the event to not close', src/libcore/option.rs:1034:5

[mmahut]

Attaching full backtrace of the panic jormungandr-full-backtrace.log.

[disassembler]

psycomb reported this as well on telegram this morning.

[disassembler]

One additional request would be if a backtrace occurs, the node should terminate instead of the API continuing to run and report blocks are not increasing.

[mmahut]

One additional request would be if a backtrace occurs, the node should terminate instead of the API continuing to run and report blocks are not increasing.

Mine continues operations after panics. Can it be because I have set for a full backtrace?

[mmahut]

After we have been published to the stake/get list, the creation of blocks seems to be working.

Sep 29 10:12:42.002 INFO leader event starting, date: 219.574, leader: 1, task: leadership
Sep 29 10:12:42.010 INFO block from leader event successfully stored, date: 219.574, parent: 1f426fe95096a25e5ab7ae58e456d7e46a6b6d5944a639c6dedc72a3559a92dc, hash: a0e0fe3c8fdf3f6a2897a53f8d7f5c8a1327d4812870adfb57826c5101265cb6, task: block
Sep 29 10:16:22.002 INFO leader event starting, date: 219.684, leader: 1, task: leadership
Sep 29 10:16:22.011 INFO block from leader event successfully stored, date: 219.684, parent: 507a4ab03047cca812356d7483e3a99350a9c476240c54afa164b8425166dca8, hash: dabfb679144ce824eb2dab1831f049665becd48d502cfccaab3ca94b7422ba24, task: block
Sep 29 10:16:28.002 INFO leader event starting, date: 219.687, leader: 1, task: leadership
Sep 29 10:16:28.006 INFO block from leader event successfully stored, date: 219.687, parent: dabfb679144ce824eb2dab1831f049665becd48d502cfccaab3ca94b7422ba24, hash: ee3ec9244995f5ecdb5e50f79b510fff4725111df4a6584c90a8d35654bb3ea1, task: block
Sep 29 10:20:20.002 INFO leader event starting, date: 219.803, leader: 1, task: leadership
Sep 29 10:20:20.005 INFO block from leader event successfully stored, date: 219.803, parent: 3bd7c369460eaaf70fc9755a0158be51bab47f7de8e186af01f447d678ee5370, hash: acf04253efa1690a999d761d9245eb2145ebe623bfa2c35a51463d060203e090, task: block

# jcli rest v0 block a0e0fe3c8fdf3f6a2897a53f8d7f5c8a1327d4812870adfb57826c5101265cb6 get -h http://127.0.0.1:8443/api
02b6000200000000000000db0000023e000051150e5751c026e543b2e8ab2eb06099daa1d1e5df47778f7787faab45cdf12fe3a81f426fe95096a25e5ab7ae58e456d7e46a6b6d5944a639c6dedc72a3559a92dc969963a8b6cab96be257a37f2f27be6cc41c9561253b4da7c47704036024169ad61e853ef1e40b1d50ace554bb9ab1683e6b0ad8c91312a6d0fba2be850be65f31542321c50213a07029771c1fc15e6a4f35738090f041987342187f8179e30aafa748ac19abd8ef203a3ba1f728aa4a1a9d7c27ee0c0875fab5831f4ade8608000000001ca6cf4b3ecb9f4d8ef8c766e2a1d42740f741260a3529867874d65b4755a08c67774c0dc8e4afa53549d2b1cfb8703be9d7900493166450f5568b346cff5006f91ca73292f12a6e028dcf2c6ab8341e4f931c6f4f9f8e381d48b961b79d666b19b97b7008521a98b0ce0d92531f6d897b4ce8e51775f699abbae071a0c59bf3039e1e334cae363a109a499a4418f1842d115d20836b6b4c50b197803fe7d215bed8f1838493245d84873b0c4028883815bae2f824a66dfacd40a00dab2efd1c4384054d1dd65d225819162db8c5afb8a926958915c032490dc389e4e74c903ddbd6a75da879c766a512633c4849f96044ce99974ee623bab8055b76b01e160c783d84647f996915d1110322e8df9defa1a945e491cc43e66b1508fd230d57dfc0d9185021d825f3ad80028f87240d01cdfc3551d207cb0fd6a62196782830c30f777b08007b2259a3d65e8007f63cf540f2a2a608b1fea0ad448263c223a0d322555852c2d994ce92a7d426a41596d30e7ad92982944868cd39aa2b7078261769688a3c47d626ff6308e7f4b492cc7fdd2e7d7fadfc1203aee665b5935114fcc6b7699f6200451e864455ba7012edb4eb2e8e5ec3bbd9773e5174db9a15b91c4b608060882dbaa800ce13d8317cbc1304ccfc3113e2b89cce1b29dde2f04a26

[NicolasDP]

Thanks guys. All of this is useful information. You can look at your leaders logs to see your schedule and your past block creation. /api/v0/leaders/logs
It will show the current node schedules and past events.

[NicolasDP]

Good news is that this issue had a duplicate #1065 and has been fixed now