mimblewimble / grin

Minimal implementation of the Mimblewimble protocol.
https://grin.mw/
Apache License 2.0
5.04k stars 990 forks source link

Grin crashes with unwrap on a None value #1585

Closed quentinlesceller closed 6 years ago

quentinlesceller commented 6 years ago
Sep 24 03:17:20.488 DEBG broadcast_compact_block: 125d6d80, 47091659 at 108764, to 4 peers, done.
Sep 24 03:17:20.490 WARN (Server ID: StratumServer) Solution Found for block 108764 - Yay!!!
Sep 24 03:17:20.490 INFO (Server ID: StratumServer) Got share for block: hash 125d6d80, height 108764, nonce 5060267201443065681, difficulty 377/282, submitted by white
Sep 24 03:17:20.602 DEBG Client 95.216.163.175:13414 connection lost: Connection(Custom { kind: ConnectionAborted, error: StringError("read_exact") })
Sep 24 03:17:20.781 DEBG monitor_peers: on 0.0.0.0:13414, 3 connected (3 most_work). all 594 = 4 healthy + 0 banned + 590 defunct
Sep 24 03:17:20.782 DEBG clean_peers V4(95.216.163.175:13414), not connected
Sep 24 03:17:20.783 DEBG monitor_peers: 0.0.0.0:13414 ask 198.245.50.26:13414 for more peers
Sep 24 03:17:20.784 DEBG Asking 198.245.50.26:13414 for more peers.
Sep 24 03:17:20.785 DEBG monitor_peers: 0.0.0.0:13414 ask 109.74.202.16:13414 for more peers
Sep 24 03:17:20.785 DEBG Asking 109.74.202.16:13414 for more peers.
Sep 24 03:17:20.785 DEBG monitor_peers: 0.0.0.0:13414 ask 8.6.8.66:13414 for more peers
Sep 24 03:17:20.785 DEBG Asking 8.6.8.66:13414 for more peers.
Sep 24 03:17:20.785 DEBG monitor_peers: no preferred peers
Sep 24 03:17:20.785 DEBG monitor_peers: on 0.0.0.0:13414, queue to soon try 95.216.163.175:13414
Sep 24 03:17:21.001 DEBG Connected! Cumulative 40605549 offered from V4(95.216.163.175:13414) "MW/Grin 0.3.0" FULL_HIST | TXHASHSET_HIST | PEER_LIST | FAST_SYNC_NODE | FULL_NODE
Sep 24 03:17:21.002 DEBG Saving newly connected peer 95.216.163.175:13414.
Sep 24 03:17:21.003 DEBG save_peer: V4(95.216.163.175:13414) marked Healthy
Sep 24 03:17:21.005 DEBG Asking 95.216.163.175:13414 for more peers.
Sep 24 03:17:21.101 DEBG get_coinbase: BlockFees { fees: 0, height: 108765, key_id: Some(Identifier(a3df7f5bd87ef1dfce7a)) }
Sep 24 03:17:21.102 DEBG lru_verifier_cache: rangeproofs: 1, not cached (must verify): 1
Sep 24 03:17:21.106 DEBG lru_verifier_cache: kernel sigs: 1, not cached (must verify): 1
Sep 24 03:17:21.109 DEBG Built new block with 0 inputs and 1 outputs, network difficulty: 282, cumulative difficulty 47091941
Sep 24 03:17:21.110 DEBG (Server ID: StratumServer) sending block 108765 with id 0 to stratum clients
Sep 24 03:17:26.173 INFO (Server ID: StratumServer) Got share for block: hash 67027123, height 108765, nonce 16113152869612639768, difficulty 58/282, submitted by white
Sep 24 03:17:30.258 DEBG Received block header 073dc630 at 108764 from 8.6.8.66:13414, going to process.
Sep 24 03:17:30.259 DEBG pipe: process_block_header at 108764 [073dc630]
Sep 24 03:17:30.260 DEBG Requesting compact block 073dc630 from 8.6.8.66:13414
Sep 24 03:17:30.324 DEBG handle_payload: received block: msg_len: 1260
Sep 24 03:17:30.325 DEBG Received block 073dc630 at 108764 from 8.6.8.66:13414, inputs: 0, outputs: 1, kernels: 1, going to process.
Sep 24 03:17:30.326 DEBG pipe: process_block 073dc630 at 108764 with 0 inputs, 1 outputs, 1 kernels
Sep 24 03:17:30.326 DEBG lru_verifier_cache: rangeproofs: 1, not cached (must verify): 1
Sep 24 03:17:30.332 DEBG lru_verifier_cache: kernel sigs: 1, not cached (must verify): 1
Sep 24 03:17:30.338 DEBG adapter: block_accepted: 073dc630
Sep 24 03:17:30.339 DEBG Send header 073dc630 to 198.245.50.26:13414
Sep 24 03:17:30.340 DEBG Send header 073dc630 to 109.74.202.16:13414
Sep 24 03:17:30.341 DEBG Send header 073dc630 to 95.216.163.175:13414
Sep 24 03:17:30.458 DEBG Client 95.216.163.175:13414 connection lost: Connection(Custom { kind: ConnectionAborted, error: StringError("read_exact") })
Sep 24 03:17:36.600 DEBG get_coinbase: BlockFees { fees: 0, height: 108765, key_id: Some(Identifier(a3df7f5bd87ef1dfce7a)) }
Sep 24 03:17:36.601 DEBG lru_verifier_cache: rangeproofs: 1, not cached (must verify): 0
Sep 24 03:17:36.602 DEBG lru_verifier_cache: kernel sigs: 1, not cached (must verify): 1
Sep 24 03:17:36.604 DEBG Built new block with 0 inputs and 1 outputs, network difficulty: 282, cumulative difficulty 47091941
Sep 24 03:17:36.605 DEBG (Server ID: StratumServer) sending block 108765 with id 1 to stratum clients
Sep 24 03:17:40.784 DEBG monitor_peers: on 0.0.0.0:13414, 3 connected (3 most_work). all 594 = 4 healthy + 0 banned + 590 defunct
Sep 24 03:17:40.785 DEBG clean_peers V4(95.216.163.175:13414), not connected
Sep 24 03:17:40.786 DEBG monitor_peers: 0.0.0.0:13414 ask 109.74.202.16:13414 for more peers
Sep 24 03:17:40.787 DEBG Asking 109.74.202.16:13414 for more peers.
Sep 24 03:17:40.788 DEBG monitor_peers: 0.0.0.0:13414 ask 8.6.8.66:13414 for more peers
Sep 24 03:17:40.789 DEBG Asking 8.6.8.66:13414 for more peers.
Sep 24 03:17:40.789 DEBG monitor_peers: 0.0.0.0:13414 ask 198.245.50.26:13414 for more peers
Sep 24 03:17:40.789 DEBG Asking 198.245.50.26:13414 for more peers.
Sep 24 03:17:40.789 DEBG monitor_peers: no preferred peers
Sep 24 03:17:40.789 DEBG monitor_peers: on 0.0.0.0:13414, queue to soon try 95.216.163.175:13414
Sep 24 03:17:41.005 DEBG Connected! Cumulative 40605549 offered from V4(95.216.163.175:13414) "MW/Grin 0.3.0" FULL_HIST | TXHASHSET_HIST | PEER_LIST | FAST_SYNC_NODE | FULL_NODE
Sep 24 03:17:41.006 DEBG Saving newly connected peer 95.216.163.175:13414.
Sep 24 03:17:41.007 DEBG save_peer: V4(95.216.163.175:13414) marked Healthy
Sep 24 03:17:41.080 ERRO 
thread 'sync' panicked at 'called `Option::unwrap()` on a `None` value': libcore/option.rs:345stack backtrace:
   0:     0x560e6d60de1c - backtrace::backtrace::trace::haeeda11cb0a18d0d
   1:     0x560e6d60cdd2 - <backtrace::capture::Backtrace as core::default::Default>::default::h58375e4d637b5237
   2:     0x560e6d60ce48 - backtrace::capture::Backtrace::new::h77ff1d6eb80d3fec
   3:     0x560e6d5a5b2e - grin_util::logger::send_panic_to_log::{{closure}}::hb080dc8158128e7a
   4:     0x560e6d71adf3 - std::panicking::rust_panic_with_hook::he4c3a67f6258a8f9
                        at libstd/panicking.rs:515
   5:     0x560e6d71ab49 - std::panicking::continue_panic_fmt::h156c04b2aea348c7
                        at libstd/panicking.rs:426
   6:     0x560e6d71a865 - rust_begin_unwind
                        at libstd/panicking.rs:337
   7:     0x560e6d7783fb - core::panicking::panic_fmt::h0e6d5c6fb2a34dd6
                        at libcore/panicking.rs:92
   8:     0x560e6d77832a - core::panicking::panic::hfbb77505dc622acd
                        at libcore/panicking.rs:53
   9:     0x560e6d457803 - grin_p2p::peer::Peer::is_connected::hf0eaaab5ea597898
  10:     0x560e6d48dd64 - <core::iter::Cloned<I> as core::iter::iterator::Iterator>::next::hd63e66a68b97b163
  11:     0x560e6d48c228 - <alloc::vec::Vec<T> as alloc::vec::SpecExtend<T, I>>::from_iter::ha6eaef685cdbdb48
  12:     0x560e6d467f97 - grin_p2p::peers::Peers::connected_peers::h4b3aed308854efe3
  13:     0x560e6d468bb9 - grin_p2p::peers::Peers::most_work_peers::he5d1b341c4d3bb70
  14:     0x560e6d468e5c - grin_p2p::peers::Peers::most_work_peer::h21eaa649cad20f0f
  15:     0x560e6d23ed49 - grin_servers::grin::sync::needs_syncing::hb928963c7742d445
  16:     0x560e6d1ad76f - std::sys_common::backtrace::__rust_begin_short_backtrace::h9a2f3d587e4e8cb7
  17:     0x560e6d203b84 - std::panicking::try::do_call::hb6f1fd8f38e7f518
  18:     0x560e6d73ff89 - __rust_maybe_catch_panic
                        at libpanic_unwind/lib.rs:105
  19:     0x560e6d2072f4 - <F as alloc::boxed::FnBox<A>>::call_box::h72eb92d01528792f
  20:     0x560e6d71823a - <alloc::boxed::Box<alloc::boxed::FnBox<A, Output=R> + 'a> as core::ops::function::FnOnce<A>>::call_once::h75e539106a648d39
                        at /checkout/src/liballoc/boxed.rs:650
                         - std::sys_common::thread::start_thread::h88a639c99862a9f5
                        at libstd/sys_common/thread.rs:24
  21:     0x560e6d71b8a5 - std::sys::unix::thread::Thread::new::thread_start::h7d7a420a78cfa84d
                        at libstd/sys/unix/thread.rs:90
  22:     0x7f834fbc66b9 - start_thread
  23:     0x7f834f6e641c - clone
  24:                0x0 - <unknown>

Sep 24 03:17:41.086 DEBG Asking 95.216.163.175:13414 for more peers.
Sep 24 03:17:41.201 ERRO 
thread 'peer' panicked at 'called `Result::unwrap()` on an `Err` value: "PoisonError { inner: .. }"': libcore/result.rs:945stack backtrace:
   0:     0x560e6d60de1c - backtrace::backtrace::trace::haeeda11cb0a18d0d
   1:     0x560e6d60cdd2 - <backtrace::capture::Backtrace as core::default::Default>::default::h58375e4d637b5237
   2:     0x560e6d60ce48 - backtrace::capture::Backtrace::new::h77ff1d6eb80d3fec
   3:     0x560e6d5a5b2e - grin_util::logger::send_panic_to_log::{{closure}}::hb080dc8158128e7a
   4:     0x560e6d71adf3 - std::panicking::rust_panic_with_hook::he4c3a67f6258a8f9
                        at libstd/panicking.rs:515
   5:     0x560e6d71ab49 - std::panicking::continue_panic_fmt::h156c04b2aea348c7
                        at libstd/panicking.rs:426
   6:     0x560e6d71a865 - rust_begin_unwind
                        at libstd/panicking.rs:337
   7:     0x560e6d7783fb - core::panicking::panic_fmt::h0e6d5c6fb2a34dd6
                        at libcore/panicking.rs:92
   8:     0x560e6d47489d - core::result::unwrap_failed::h0da2f30cbd388380
   9:     0x560e6d457985 - grin_p2p::peer::Peer::is_banned::he5bdf82459057295
  10:     0x560e6d46d492 - <grin_p2p::peers::Peers as grin_p2p::types::NetAdapter>::is_banned::h52e53f60776d8377
  11:     0x560e6d459d41 - <grin_p2p::peer::TrackingAdapter as grin_p2p::types::NetAdapter>::is_banned::h6f450ca740e71c49
  12:     0x560e6d491916 - <grin_p2p::protocol::Protocol as grin_p2p::conn::MessageHandler>::consume::hf99a31fdb0740981
  13:     0x560e6d4619c3 - std::sys_common::backtrace::__rust_begin_short_backtrace::h1bde35303db8c65a
  14:     0x560e6d462ea8 - std::panicking::try::do_call::h39bcc203a7fada48
  15:     0x560e6d73ff89 - __rust_maybe_catch_panic
                        at libpanic_unwind/lib.rs:105
  16:     0x560e6d479295 - <F as alloc::boxed::FnBox<A>>::call_box::h1c7ce09c7d72ded3
  17:     0x560e6d71823a - <alloc::boxed::Box<alloc::boxed::FnBox<A, Output=R> + 'a> as core::ops::function::FnOnce<A>>::call_once::h75e539106a648d39
                        at /checkout/src/liballoc/boxed.rs:650
                         - std::sys_common::thread::start_thread::h88a639c99862a9f5
                        at libstd/sys_common/thread.rs:24
  18:     0x560e6d71b8a5 - std::sys::unix::thread::Thread::new::thread_start::h7d7a420a78cfa84d
                        at libstd/sys/unix/thread.rs:90
  19:     0x7f834fbc66b9 - start_thread
  20:     0x7f834f6e641c - clone
  21:                0x0 - <unknown>
jaspervdm commented 6 years ago

I just had the same panic appear when I shut down my server.

Sep 25 11:20:12.366 WARN Shutting down...
Sep 25 11:20:13Thread 'tokio-runtime-worker-0' panicked with message:
"called `Option::unwrap()` on a `None` value"
See grin.log for further details.
.160 ERRO
thread 'tokio-runtime-worker-0' panicked at 'called `Option::unwrap()` on a `None` value': libcore/option.rs:345stack backtrace:
   0:     0x55aa183149ac - backtrace::backtrace::trace::haeeda11cb0a18d0d
   1:     0x55aa18313962 - <backtrace::capture::Backtrace as core::default::Default>::default::h58375e4d637b5237
   2:     0x55aa183139d8 - backtrace::capture::Backtrace::new::h77ff1d6eb80d3fec
   3:     0x55aa182ac35e - grin_util::logger::send_panic_to_log::{{closure}}::hcd15255485b34255
   4:     0x55aa18420d73 - std::panicking::rust_panic_with_hook::he4c3a67f6258a8f9
                        at libstd/panicking.rs:515
   5:     0x55aa18420ac9 - std::panicking::continue_panic_fmt::h156c04b2aea348c7
                        at libstd/panicking.rs:426
   6:     0x55aa184207e5 - rust_begin_unwind
                        at libstd/panicking.rs:337
   7:     0x55aa1847e47b - core::panicking::panic_fmt::h0e6d5c6fb2a34dd6
                        at libcore/panicking.rs:92
   8:     0x55aa1847e3aa - core::panicking::panic::hfbb77505dc622acd
                        at libcore/panicking.rs:53
   9:     0x55aa17fe3ca4 - <grin_api::handlers::ChainHandler as grin_api::router::Handler>::get::ha99ca26f5fe96b48
  10:     0x55aa17febeb6 - grin_api::router::Handler::call::hf25e11fb784e6269
  11:     0x55aa17fcff5f - <grin_api::router::Router as hyper::service::service::Service>::call::hcda1d63bbe782a66
  12:     0x55aa18067fee - <hyper::proto::h1::dispatch::Server<S> as hyper::proto::h1::dispatch::Dispatch>::recv_msg::hc2fe53af10bad10d
  13:     0x55aa18074cef - <hyper::proto::h1::dispatch::Dispatcher<D, Bs, I, T>>::poll_catch::h61daee56b279c4fe
  14:     0x55aa1800b1ad - <hyper::server::conn::upgrades::UpgradeableConnection<I, S> as futures::future::Future>::poll::h60f5f6c96f4038f3
  15:     0x55aa18006896 - <futures::future::chain::Chain<A, B, C>>::poll::he7ac1a576648471a
  16:     0x55aa1803b556 - <futures::future::map_err::MapErr<A, F> as futures::future::Future>::poll::h972af48156569067
  17:     0x55aa180f158f - futures::task_impl::std::set::h63d16f3f6df5a415
  18:     0x55aa180f4571 - std::panicking::try::do_call::hb0ff339299363ec3
  19:     0x55aa18445fe9 - __rust_maybe_catch_panic
                        at libpanic_unwind/lib.rs:105
  20:     0x55aa180f3449 - tokio_threadpool::task::Task::run::h770f09d0fe198e92
  21:     0x55aa180ec605 - tokio_threadpool::worker::Worker::run_task::h314d09d10fee9da2
  22:     0x55aa180eb6ff - tokio_threadpool::worker::Worker::run::h0d7c48065b66b9fd
  23:     0x55aa180d53a1 - <std::thread::local::LocalKey<T>>::with::ha6bdab80b5c2cb07
  24:     0x55aa180d56d2 - <std::thread::local::LocalKey<T>>::with::he5f1a296d1bde3e0
  25:     0x55aa180d5588 - <std::thread::local::LocalKey<T>>::with::hd6e09257b99390e6
  26:     0x55aa180d8407 - tokio::runtime::builder::Builder::build::{{closure}}::h163f0ca09afe1868
  27:     0x55aa180f29ec - <std::thread::local::LocalKey<T>>::with::hd51a9856f8cd35fc
  28:     0x55aa180f22aa - <std::thread::local::LocalKey<T>>::with::h1e35416c090dec5d
  29:     0x55aa180f4e11 - std::sys_common::backtrace::__rust_begin_short_backtrace::he0e763f8840d02f2
  30:     0x55aa180f45bb - std::panicking::try::do_call::hd0bd292f12a4762e
  31:     0x55aa18445fe9 - __rust_maybe_catch_panic
                        at libpanic_unwind/lib.rs:105
  32:     0x55aa180ef81c - <F as alloc::boxed::FnBox<A>>::call_box::hd5fd027924ad99de
  33:     0x55aa1841e15a - <alloc::boxed::Box<alloc::boxed::FnBox<A, Output=R> + 'a> as core::ops::function::FnOnce<A>>::call_once::h75e539106a648d39
                        at /checkout/src/liballoc/boxed.rs:650
                         - std::sys_common::thread::start_thread::h88a639c99862a9f5
                        at libstd/sys_common/thread.rs:24
  34:     0x55aa184218e5 - std::sys::unix::thread::Thread::new::thread_start::h7d7a420a78cfa84d
                        at libstd/sys/unix/thread.rs:90
  35:     0x7fadc9c906d9 - start_thread
  36:     0x7fadc97b3d7e - __clone
  37:                0x0 - <unknown>

Sep 25 11:20:13.366 WARN Shutdown complete.