Server Cannot Run Because of NotFoundErr

[garyyu]

Tried multiple times by clean the whole chain_data folder, and eventually the testnet synced with latest 5.0.0-beta.2 release. but after a quit and it can not run again because of a not found error:

20201211 10:16:29.485 INFO grin_servers::grin::server - Starting server, genesis block: edc758c1370d
20201211 10:16:31.892 ERROR grin_util::logger -
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Chain(Error { inner: NotFoundErr("Block with hash: 0e29ee5b51f1")

Store Error: NotFoundErr("Block with hash: 0e29ee5b51f1"), reason: DB Not Found Error: Block with hash: 0e29ee5b51f1 })': src/bin/cmd/server.rs:58   0: grin_util::logger::send_panic_to_log::{{closure}}
   1: std::panicking::rust_panic_with_hook
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:573
   2: std::panicking::begin_panic_handler::{{closure}}
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:476
   3: std::sys_common::backtrace::__rust_end_short_backtrace
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/sys_common/backtrace.rs:153
   4: rust_begin_unwind
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:475
   5: core::panicking::panic_fmt
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/panicking.rs:85
   6: core::option::expect_none_failed
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/option.rs:1221
   7: grin::cmd::server::start_server_tui
   8: grin::cmd::server::server_command
   9: grin::real_main
  10: grin::main

[tromp]

That block should be available. I can see it here at pre-fork height 641520:

https://floonet.grinscan.net/block/641520

Is this NotFoundErr also reproducible across removal of chain data and restart?

[garyyu]

Yes, reproducible.

I have to remove the whole chain_data folder and restart the sync, after a lot of times trying (because of #3515), it eventually synced, but again, this NotFoundErr comes and I cannot start the server.

[garyyu]

Tried again with a cleaned chain_data, again :-(

20201212 10:05:22.342 WARN grin::cmd::server - Starting GRIN in UI mode...
20201212 10:05:22.342 INFO grin_servers::grin::server - Starting server, genesis block: edc758c1370d
20201212 10:05:24.689 ERROR grin_util::logger -
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Chain(Error { inner: NotFoundErr("Block with hash: ad25696f7950")

Store Error: NotFoundErr("Block with hash: ad25696f7950"), reason: DB Not Found Error: Block with hash: ad25696f7950 })': src/bin/cmd/server.rs:58   0: grin_util::logger::send_panic_to_log::{{closure}}

[antiochp]

Its hard to really know what's happening here.
Do your logs show a clean shutdown? (Prior to the first NotFoundErr).

This is normally an indication of data corruption locally, likely during shutdown.

[tromp]

Clean shutdown doesn't matter if you move the whole ~/.grin/test directory aside before starting grin --testnet.
I'm trying one right now.

It synced slowly but without any issues and is now running.

What can cause Gary's NotFoundErr("Block with hash: ad25696f7950") ?

[antiochp]

What can cause Gary's NotFoundErr("Block with hash: ad25696f7950") ?

Pretty sure this can only be caused by data corruption during shutdown.

If we see -

20201212 10:05:22.342 WARN grin::cmd::server - Starting GRIN in UI mode...
20201212 10:05:22.342 INFO grin_servers::grin::server - Starting server, genesis block: edc758c1370d

Followed by something that indicates a local db lookup -

thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Chain(Error { inner: NotFoundErr("Block with hash: ad25696f7950")

Then the db is non-empty (we are looking that data up for some reason).

[antiochp]

@garyyu Is it possible you are not clearing out the right chain_data dir here? (Just to rule this out).

[garyyu]

Do your logs show a clean shutdown? (Prior to the first NotFoundErr).

20201212 10:05:07.434 WARN grin::tui::ui - Shutdown in progress, please wait
20201212 10:05:07.867 INFO grin_servers::grin::server - connect_and_monitor thread stopped
20201212 10:05:07.948 INFO grin_servers::grin::server - sync thread stopped
20201212 10:05:07.948 INFO grin_servers::grin::server - dandelion_monitor thread stopped
20201212 10:05:08.636 WARN grin_servers::grin::server - Shutdown complete
20201212 10:05:22.342 INFO grin_util::logger - log4rs is initialized, file level: Info, stdout level: Warn, min. level: Info
20201212 10:05:22.342 INFO grin - Using configuration file at /home/garyyu/.grin/test/grin-server.toml
20201212 10:05:22.342 INFO grin - This is Grin version 5.0.0-beta.2 (git v5.0.0-beta.2), built for x86_64-unknown-linux-gnu by rustc 1.47.0 (18bf6b4f0 2020-10-07).
20201212 10:05:22.342 INFO grin - Chain: Testnet
20201212 10:05:22.342 INFO grin - Accept Fee Base: 500000
20201212 10:05:22.342 INFO grin - Future Time Limit: 300
20201212 10:05:22.342 INFO grin - Feature: NRD kernel enabled: true
20201212 10:05:22.342 WARN grin::cmd::server - Starting GRIN in UI mode...
20201212 10:05:22.342 INFO grin_servers::grin::server - Starting server, genesis block: edc758c1370d
20201212 10:05:24.689 ERROR grin_util::logger -
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Chain(Error { inner: NotFoundErr("Block with hash: ad25696f7950")

Store Error: NotFoundErr("Block with hash: ad25696f7950"), reason: DB Not Found Error: Block with hash: ad25696f7950 })': src/bin/cmd/server.rs:58   0: grin_util::logger::send_panic_to_log::{{closure}}
   1: std::panicking::rust_panic_with_hook
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:573
   2: std::panicking::begin_panic_handler::{{closure}}
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:476
   3: std::sys_common::backtrace::__rust_end_short_backtrace
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/sys_common/backtrace.rs:153
   4: rust_begin_unwind
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:475
   5: core::panicking::panic_fmt
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/panicking.rs:85
   6: core::option::expect_none_failed
             at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/option.rs:1221
   7: grin::cmd::server::start_server_tui
   8: grin::cmd::server::server_command
   9: grin::real_main
  10: grin::main

[tromp]

I also ran into this issue once recently on testnet. Quit the server by hitting q and a few days later when restarting, I got the NotFoundErr. I ended up moving the whole ~/.grin/test dir aside and do a fresh sync to avoid it.