tokio-runtime-worker' panicked at 'supplied instant is later than self #600

stakeworks · 2021-01-15T10:10:10Z

Jan 15 09:23:04
Thread 'tokio-runtime-worker' panicked at 'supplied instant is later than self', library/std/src/time.rs:275
  30: __clone
  29: start_thread
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/std/src/sys/unix/thread.rs:87:17
      std::sys::unix::thread::Thread::new::thread_start
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/alloc/src/boxed.rs:1042:9
      <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/alloc/src/boxed.rs:1042:9
  28: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
  27: core::ops::function::FnOnce::call_once{{vtable.shim}}
  26: std::sys_common::backtrace::__rust_begin_short_backtrace
  25: tokio::runtime::context::enter
  24: tokio::runtime::blocking::pool::Inner::run
  23: tokio::runtime::task::raw::poll
  22: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
  21: tokio::runtime::task::core::Core<T,S>::poll
  20: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
  19: tokio::runtime::thread_pool::worker::run
  18: tokio::macros::scoped_tls::ScopedKey<T>::set
  17: tokio::runtime::thread_pool::worker::Context::run
  16: tokio::runtime::thread_pool::worker::Context::run_task
  15: std::thread::local::LocalKey<T>::with
  14: tokio::runtime::task::harness::Harness<T,S>::poll
  13: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
  12: tokio::runtime::task::core::Core<T,S>::poll
  11: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll
  10: <futures_util::future::select::Select<A,B> as core::future::future::Future>::poll
   9: <futures_util::future::future::catch_unwind::CatchUnwind<Fut> as core::future::future::Future>::poll
   8: <prometheus::histogram::HistogramTimer as core::ops::drop::Drop>::drop
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/std/src/time.rs:339:9
      std::time::Instant::elapsed
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/std/src/time.rs:400:9
      <std::time::Instant as core::ops::arith::Sub>::sub
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/std/src/time.rs:275:9
      std::time::Instant::duration_since
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/core/src/option.rs:346:21
   7: core::option::Option<T>::expect
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/core/src/option.rs:1226:5
   6: core::option::expect_failed
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/core/src/panicking.rs:85:14
   5: core::panicking::panic_fmt
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/std/src/panicking.rs:483:5
   4: rust_begin_unwind
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/std/src/sys_common/backtrace.rs:153:18
   3: std::sys_common::backtrace::__rust_end_short_backtrace
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/std/src/panicking.rs:484:9
   2: std::panicking::begin_panic_handler::{{closure}}
             at rustc/a1dfd2490a6cb456b92e469fa550dc217e20ad6d/library/std/src/panicking.rs:581:17
   1: std::panicking::rust_panic_with_hook
   0: sp_panic_handler::set::{{closure}}
Version: 0.8.8-97a8c44-x86_64-linux-gnu

Linux vmi424166.contaboserver.net 4.15.0-122-generic #124-Ubuntu SMP Thu Oct 15 13:03:05 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

AurevoirXavier · 2021-01-15T10:12:04Z

Where did you get this error?

How to reproduce it?

stakeworks · 2021-01-15T10:43:37Z

I noticed that one of my nodes had restarted and checked the journalctl. That's where I saw the error. The same error happened on the same server with a Plasm node. I don't know how to reproduce. Could a low open file descriptor limit be the cause, although it's same on others servers (4096)?

AurevoirXavier · 2021-01-15T11:06:51Z

I noticed that one of my nodes had restarted and checked the journalctl. That's where I saw the error. The same error happened on the same server with a Plasm node. I don't know how to reproduce. Could a low open file descriptor limit be the cause, although it's same on others servers (4096)?

Similar to #560?

stakeworks · 2021-01-15T11:20:15Z

I've set limit at 65535 and rebooted the server. Let's see what happens.

LimitNOFILE=65535

root soft nofile 65535
root hard nofile 65535

soft nofile 65535
hard nofile 65535

AurevoirXavier · 2021-01-16T05:56:01Z

Which binary are you using?

Self-compiled or download from the release?

stakeworks · 2021-01-16T06:49:16Z

Download from the release, just updated to Darwinia 0.8.9

AurevoirXavier · 2021-01-16T07:14:41Z

I think this error is caused by the rustc version. But not sure.

stakeworks · 2021-01-16T08:24:40Z

rustc is not installed,

AurevoirXavier · 2021-01-25T02:31:37Z

I've set limit at 65535 and rebooted the server. Let's see what happens.

LimitNOFILE=65535

root soft nofile 65535
root hard nofile 65535

soft nofile 65535

hard nofile 65535

Did this work?

stakeworks · 2021-01-25T06:49:40Z

Correction: I've only set "LimitNOFILE=65535" in the service file. I don't see this error anymore, but I've restarted serveral times the last week because of updates, now running 0.9.0.

I do see these errors in the log in CVN0601:
Error importing block 0x1a3995f4678afb645b0681c077e19dfaab96501956eb7ce6a628880bafe8f26f: Err(UnknownParent)

Error importing block 0x0c7dab88a7603bb267cce0be0cd6a430a984a84afab5093d9514c6844bc2254d: Err(Other(ClientImport("Import failed: Potential long-range attack: block not in finalized chain.")))

ERROR Handler initialization process is too long with PeerId("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx")

WARN Polling the telemetry took more than 200ms

In CVN0301:
Error importing block 0x0ae3e3cff7529f413af6dc8f04698432e696fff7d09cda6d689fa65d0c92c0c0: Err(Other(ClientImport("Invalid operation in the pending changes tree: Tried to import or finalize node that is an ancestor of a previously finalized node")))

Error importing block 0x6badf3edfd5caa2c63e1d5942024678b1b726e788fe345115df28018a26aaf75:
Err(Other(ClientImport("Import failed: Potential long-range attack: block not in finalized chain.")))

Error importing block 0xe2f72da2e90239e2cbd15bd690ef1e8186d09e99fc80f1d49fc700ccd59e3bbf: Err(UnknownParent)

AurevoirXavier · 2021-04-12T05:28:37Z

Correction: I've only set "LimitNOFILE=65535" in the service file. I don't see this error anymore, but I've restarted serveral times the last week because of updates, now running 0.9.0.

I do see these errors in the log in CVN0601:
Error importing block 0x1a3995f4678afb645b0681c077e19dfaab96501956eb7ce6a628880bafe8f26f: Err(UnknownParent)

Error importing block 0x0c7dab88a7603bb267cce0be0cd6a430a984a84afab5093d9514c6844bc2254d: Err(Other(ClientImport("Import failed: Potential long-range attack: block not in finalized chain.")))

ERROR Handler initialization process is too long with PeerId("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx")

WARN Polling the telemetry took more than 200ms

In CVN0301:
Error importing block 0x0ae3e3cff7529f413af6dc8f04698432e696fff7d09cda6d689fa65d0c92c0c0: Err(Other(ClientImport("Invalid operation in the pending changes tree: Tried to import or finalize node that is an ancestor of a previously finalized node")))

Error importing block 0x6badf3edfd5caa2c63e1d5942024678b1b726e788fe345115df28018a26aaf75:
Err(Other(ClientImport("Import failed: Potential long-range attack: block not in finalized chain.")))

Error importing block 0xe2f72da2e90239e2cbd15bd690ef1e8186d09e99fc80f1d49fc700ccd59e3bbf: Err(UnknownParent)

Could be closed now?

stakeworks · 2021-04-12T08:14:22Z

Version both my validators: darwinia 0.9.5-e73932d-x86_64-linux-gnu
Ubuntu 18.04.5 LTS

I still see these errors occasionally.

2021-04-11 05:29:43 💔 Error importing block 0x23f9f8db607897f25c51977d3f23252fc538c9107cd62f278544f72101e01296: Err(UnknownParent)
2021-04-10 10:24:30 💔 Error importing block 0xfff690bd6444a8b1fbc37242759095e5adc3e84200010e592694347eab748231: Err(Other(ClientImport("Invalid operation in the pending changes tree: Tried to import or finalize node that is an ancestor of a previously finalized node")))
2021-04-05 07:24:45 💔 Error importing block 0x72cc55a61efcf6e755f7eab7adcf16943f7b2257800e0b87b1439ae98e5ddba9: Err(Other(ClientImport("Import failed: Potential long-range attack: block not in finalized chain.")))
2021-04-05 06:02:34 Block prepare storage changes error:
2021-04-05 06:02:32 💔 Error importing block 0x9e00e1399a5cc38e7f8ad12a615f15477f1a93ed26674770eeb9b34ffe610436: Err(Other(ClientImport("Import failed: Potential long-range attack: block not in finalized chain.")))

AurevoirXavier · 2021-04-12T08:19:55Z

Version both my validators: darwinia 0.9.5-e73932d-x86_64-linux-gnu
Ubuntu 18.04.5 LTS

I still see these errors occasionally.

2021-04-11 05:29:43 💔 Error importing block 0x23f9f8db607897f25c51977d3f23252fc538c9107cd62f278544f72101e01296: Err(UnknownParent)
2021-04-10 10:24:30 💔 Error importing block 0xfff690bd6444a8b1fbc37242759095e5adc3e84200010e592694347eab748231: Err(Other(ClientImport("Invalid operation in the pending changes tree: Tried to import or finalize node that is an ancestor of a previously finalized node")))
2021-04-05 07:24:45 💔 Error importing block 0x72cc55a61efcf6e755f7eab7adcf16943f7b2257800e0b87b1439ae98e5ddba9: Err(Other(ClientImport("Import failed: Potential long-range attack: block not in finalized chain.")))
2021-04-05 06:02:34 Block prepare storage changes error:
2021-04-05 06:02:32 💔 Error importing block 0x9e00e1399a5cc38e7f8ad12a615f15477f1a93ed26674770eeb9b34ffe610436: Err(Other(ClientImport("Import failed: Potential long-range attack: block not in finalized chain.")))

Interesting. How about your Plasm node?

stakeworks · 2021-04-12T08:26:45Z

The Plasm nodes, on both servers, don't have these errors in the last 14 days.

AurevoirXavier · 2021-04-12T08:28:43Z

The Plasm nodes, on both servers, don't have these errors in the last 14 days.

We just release 0.9.6.

And 0.10.0 maybe come in next week.

I think one of them will solve this.

stakeworks · 2021-04-12T08:32:58Z

Will upgrade when available and let you know.

AurevoirXavier · 2021-04-12T08:36:28Z

Will upgrade when available and let you know.

I just ask @andresilva (the main developer of grandpa from paritytech)

So is this just a warning?
Actually, the node is still running. Can I ignore that?

---

yeah you can ignore that
the node should continue to still sync
there is kind of race condition between what you try to sync and what gets finalized (in particular depending on how little peers you have)
so probably the node tried to sync some fork, and by the time it got the blocks, they were already stale because something else got finalized
but it finalized the right thing and will keep syncing the main chain, so that is OK

AurevoirXavier · 2021-04-12T08:42:35Z

BTW, if the nodes got panic. Re-open this. @wwwAndries

Currently all my nodes look good.

stakeworks · 2021-04-12T08:51:58Z

In your last comment you mentioned “(in particular depending on how little peers you have)”, do you mean --in-peers and --out-peers? Default is 25 peers -in and -out, I’ve 34 and 36. Do I need to increase the peers? I’am running both nodes this way: /darwinia --base-path /.darw_MN01/ --name 'StakeWorks | CVN0301' --chain darwinia --validator --ws-port 9964 --rpc-port 9935 --rpc-cors all --listen-addr='/ip4/xxx.xxx.xxx.xxx/tcp/30335' --listen-addr='/ip6/xxxx:xxxx:xxxx:xxxx::4/tcp/30335' --listen-addr='/ip6/xxxx:xxxx:xxxx:xxxx::5/tcp/30335' --no-private-ipv4 --in-peers 34 --out-peers 36 --max-runtime-instances 16 --max-parallel-downloads 7

AurevoirXavier · 2021-04-12T09:34:52Z

In peers and I think more than 5 is safe.

stakeworks · 2021-04-12T09:47:59Z

Can you please remove the reference to my last message, my ip adresses are visible. My mistake, sorry.

AurevoirXavier · 2021-04-12T10:02:47Z

Can you please remove the reference to my last message, my ip adresses are visible. My mistake, sorry.

Removed

stakeworks · 2021-04-12T10:06:13Z

Thanks, updated to 0.9.6.

Bumps [url-parse](https://github.com/unshiftio/url-parse) from 1.5.7 to 1.5.10. - [Release notes](https://github.com/unshiftio/url-parse/releases) - [Commits](unshiftio/url-parse@1.5.7...1.5.10) --- updated-dependencies: - dependency-name: url-parse dependency-type: indirect ... Signed-off-by: dependabot[bot] <[email protected]> Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>

AurevoirXavier closed this as completed Apr 12, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

tokio-runtime-worker' panicked at 'supplied instant is later than self #600

tokio-runtime-worker' panicked at 'supplied instant is later than self #600

stakeworks commented Jan 15, 2021 •

edited by AurevoirXavier

Loading

AurevoirXavier commented Jan 15, 2021

stakeworks commented Jan 15, 2021

AurevoirXavier commented Jan 15, 2021

stakeworks commented Jan 15, 2021

AurevoirXavier commented Jan 16, 2021

stakeworks commented Jan 16, 2021

AurevoirXavier commented Jan 16, 2021

stakeworks commented Jan 16, 2021

AurevoirXavier commented Jan 25, 2021

stakeworks commented Jan 25, 2021 •

edited

Loading

AurevoirXavier commented Apr 12, 2021

stakeworks commented Apr 12, 2021

AurevoirXavier commented Apr 12, 2021

stakeworks commented Apr 12, 2021

AurevoirXavier commented Apr 12, 2021

stakeworks commented Apr 12, 2021

AurevoirXavier commented Apr 12, 2021 •

edited

Loading

AurevoirXavier commented Apr 12, 2021

stakeworks commented Apr 12, 2021 via email •

edited

Loading

AurevoirXavier commented Apr 12, 2021 •

edited

Loading

stakeworks commented Apr 12, 2021 •

edited

Loading

AurevoirXavier commented Apr 12, 2021

stakeworks commented Apr 12, 2021

tokio-runtime-worker' panicked at 'supplied instant is later than self #600

tokio-runtime-worker' panicked at 'supplied instant is later than self #600

Comments

stakeworks commented Jan 15, 2021 • edited by AurevoirXavier Loading

AurevoirXavier commented Jan 15, 2021

stakeworks commented Jan 15, 2021

AurevoirXavier commented Jan 15, 2021

stakeworks commented Jan 15, 2021

AurevoirXavier commented Jan 16, 2021

stakeworks commented Jan 16, 2021

AurevoirXavier commented Jan 16, 2021

stakeworks commented Jan 16, 2021

AurevoirXavier commented Jan 25, 2021

stakeworks commented Jan 25, 2021 • edited Loading

AurevoirXavier commented Apr 12, 2021

stakeworks commented Apr 12, 2021

AurevoirXavier commented Apr 12, 2021

stakeworks commented Apr 12, 2021

AurevoirXavier commented Apr 12, 2021

stakeworks commented Apr 12, 2021

AurevoirXavier commented Apr 12, 2021 • edited Loading

AurevoirXavier commented Apr 12, 2021

stakeworks commented Apr 12, 2021 via email • edited Loading

AurevoirXavier commented Apr 12, 2021 • edited Loading

stakeworks commented Apr 12, 2021 • edited Loading

AurevoirXavier commented Apr 12, 2021

stakeworks commented Apr 12, 2021

stakeworks commented Jan 15, 2021 •

edited by AurevoirXavier

Loading

stakeworks commented Jan 25, 2021 •

edited

Loading

AurevoirXavier commented Apr 12, 2021 •

edited

Loading

stakeworks commented Apr 12, 2021 via email •

edited

Loading

AurevoirXavier commented Apr 12, 2021 •

edited

Loading

stakeworks commented Apr 12, 2021 •

edited

Loading