thread '<unnamed>' panicked at 'supplied instant is later than self'

[messense]

In Jake-Shadle/xwin#30 after upgrading to 0.17.0-rc.5, cargo run -- splat panicked with the following backtrace:

thread '<unnamed>' panicked at 'supplied instant is later than self', library/std/src/time.rs:313:48
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
thread '<unnamed>' panicked at 'called `Result::unwrap()` on an `Err` value: PoisonError { .. }', /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/indicatif-0.17.0-rc.5/src/draw_target.rs:112:65
stack backtrace:
thread '<unnamed>' panicked at 'called `Result::unwrap()` on an `Err` value: PoisonError { .. }', /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/indicatif-0.17.0-rc.5/src/draw_target.rs:112:65
thread '<unnamed>' panicked at 'called `Result::unwrap()` on an `Err` value: PoisonError { .. }', /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/indicatif-0.17.0-rc.5/src/progress_bar.rs:457:27
   0:        0x1032cbb3c - std::backtrace_rs::backtrace::libunwind::trace::hbad44c2b21d61f40
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5
   1:        0x1032cbb3c - std::backtrace_rs::backtrace::trace_unsynchronized::h664423984da6366c
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:        0x1032cbb3c - std::sys_common::backtrace::_print_fmt::ha0bed729b1de74e6
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/sys_common/backtrace.rs:67:5
   3:        0x1032cbb3c - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h58c637f9e30d1b8a
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/sys_common/backtrace.rs:46:22
   4:        0x1032eb29c - core::fmt::write::hc16ca97d9f5e0acd
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/fmt/mod.rs:1168:17
   5:        0x1032c4da0 - std::io::Write::write_fmt::hd53dc7153ccce04d
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/io/mod.rs:1660:15
   6:        0x1032ce6a4 - std::sys_common::backtrace::_print::h52e9a34b49f28ab7
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/sys_common/backtrace.rs:49:5
   7:        0x1032ce6a4 - std::sys_common::backtrace::print::h0bf7306c450cdde6
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/sys_common/backtrace.rs:36:9
   8:        0x1032ce6a4 - std::panicking::default_hook::{{closure}}::ha41f2cf175ca93cf
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/panicking.rs:211:50
   9:        0x1032ce24c - std::panicking::default_hook::h838498b157804a1a
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/panicking.rs:228:9
  10:        0x1032cec68 - std::panicking::rust_panic_with_hook::h7722806c30430655
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/panicking.rs:606:17
  11:        0x1032ce9d8 - std::panicking::begin_panic_handler::{{closure}}::h265229fa7cad6de7
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/panicking.rs:502:13
  12:        0x1032cc008 - std::sys_common::backtrace::__rust_end_short_backtrace::hfa83d61d0ed14557
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/sys_common/backtrace.rs:139:18
  13:        0x1032ce740 - rust_begin_unwind
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/panicking.rs:498:5
  14:        0x103301cc8 - core::panicking::panic_fmt::hd3f68d55261c2af0
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/panicking.rs:116:14
  15:        0x103301d6c - core::result::unwrap_failed::hc1b85f369312af72
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/result.rs:1690:5
  16:        0x103142e2c - core::result::Result<T,E>::unwrap::h664412c17a2d8124
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/result.rs:1018:23
  17:        0x1031441b8 - indicatif::draw_target::ProgressDrawTarget::width::h90998dda67b9af7d
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/indicatif-0.17.0-rc.5/src/draw_target.rs:112:52
  18:        0x1031531cc - indicatif::state::BarState::draw::hf152348a8cfcf0ea
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/indicatif-0.17.0-rc.5/src/state.rs:153:21
  19:        0x103152c70 - indicatif::state::BarState::finish_using_style::h2011cdc87508a0e3
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/indicatif-0.17.0-rc.5/src/state.rs:50:17
  20:        0x103153464 - <indicatif::state::BarState as core::ops::drop::Drop>::drop::h23a1824fdbfed348
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/indicatif-0.17.0-rc.5/src/state.rs:181:9
  21:        0x10314f69c - core::ptr::drop_in_place<indicatif::state::BarState>::hb67ca066e54b2844
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/ptr/mod.rs:188:1
  22:        0x103150240 - core::ptr::drop_in_place<core::cell::UnsafeCell<indicatif::state::BarState>>::h3162b7a55f5d8d34
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/ptr/mod.rs:188:1
  23:        0x1031502b0 - core::ptr::drop_in_place<std::sync::mutex::Mutex<indicatif::state::BarState>>::h650c60c477c7815c
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/ptr/mod.rs:188:1
  24:        0x103141074 - alloc::sync::Arc<T>::drop_slow::hd2c87b235efea6bf
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/alloc/src/sync.rs:1079:18
  25:        0x1031413b4 - <alloc::sync::Arc<T> as core::ops::drop::Drop>::drop::haf4275e3ec608337
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/alloc/src/sync.rs:1640:13
  26:        0x10314f2a8 - core::ptr::drop_in_place<alloc::sync::Arc<std::sync::mutex::Mutex<indicatif::state::BarState>>>::h6f5e70207c11fd94
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/ptr/mod.rs:188:1
  27:        0x10314fcec - core::ptr::drop_in_place<indicatif::progress_bar::ProgressBar>::hfc5f5b3a814ebbbf
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/ptr/mod.rs:188:1
  28:        0x102922b88 - core::ptr::drop_in_place<xwin::WorkItem>::he0e5465bd53cd618
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/ptr/mod.rs:188:1
  29:        0x1028ae428 - xwin::ctx::Ctx::execute::{{closure}}::h393f4a208ecc18c9
                               at /Users/messense/Projects/xwin/src/ctx.rs:211:13
  30:        0x1028b4b10 - core::ops::function::impls::<impl core::ops::function::FnMut<A> for &F>::call_mut::h41396fe1a2384499
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/ops/function.rs:247:13
  31:        0x1028b4c5c - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &mut F>::call_once::hc453384e273aa03b
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/ops/function.rs:280:13
  32:        0x10288d300 - core::option::Option<T>::map::hb2169b6b05d42b50
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/option.rs:883:29
  33:        0x1028a500c - <core::iter::adapters::map::Map<I,F> as core::iter::traits::iterator::Iterator>::next::ha121dbea2fb0d28e
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/iter/adapters/map.rs:103:9
  34:        0x1028605d8 - rayon::iter::plumbing::Folder::consume_iter::hf8f8e39a1bd3686c
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-1.5.1/src/iter/plumbing/mod.rs:178:21
  35:        0x102935d44 - <rayon::iter::map::MapFolder<C,F> as rayon::iter::plumbing::Folder<T>>::consume_iter::hb7ac65b0b6dadf56
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-1.5.1/src/iter/map.rs:248:21
  36:        0x10285fe54 - rayon::iter::plumbing::Producer::fold_with::ha97e5d3cf5a73c63
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-1.5.1/src/iter/plumbing/mod.rs:110:9
  37:        0x1028b21d8 - rayon::iter::plumbing::bridge_producer_consumer::helper::he192cd243a90a1b7
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-1.5.1/src/iter/plumbing/mod.rs:438:13
  38:        0x1028b283c - rayon::iter::plumbing::bridge_producer_consumer::helper::{{closure}}::h1e18feb2ef09ab3d
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-1.5.1/src/iter/plumbing/mod.rs:427:21
  39:        0x1029549ec - rayon_core::join::join_context::call_b::{{closure}}::h9e69c4db8b289826
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-core-1.9.1/src/join/mod.rs:129:25
  40:        0x1028bd200 - <rayon_core::job::StackJob<L,F,R> as rayon_core::job::Job>::execute::call::{{closure}}::h1924118a456c7752
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-core-1.9.1/src/job.rs:113:21
  41:        0x1028f33ac - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h6b42520b8bcb6da1
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/panic/unwind_safe.rs:271:9
  42:        0x1028f4e50 - std::panicking::try::do_call::h9fc89520017bb28d
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/panicking.rs:406:40
  43:        0x1028f6b54 - <unknown>
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/fmt/mod.rs:2293:14
  44:        0x1028f44b4 - std::panicking::try::hdda7eed177d5ef10
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/panicking.rs:370:19
  45:        0x10288745c - std::panic::catch_unwind::hefaa829415145dbc
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/panic.rs:133:14
  46:        0x102868aa0 - rayon_core::unwind::halt_unwinding::h94001b2de49d3c0a
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-core-1.9.1/src/unwind.rs:17:5
  47:        0x1028bcc44 - <rayon_core::job::StackJob<L,F,R> as rayon_core::job::Job>::execute::hdc42c7b4adb4cdb9
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-core-1.9.1/src/job.rs:119:38
  48:        0x102eee100 - rayon_core::job::JobRef::execute::h0174e1388be90b77
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-core-1.9.1/src/job.rs:59:9
  49:        0x102f01c30 - rayon_core::registry::WorkerThread::execute::hf7eb79c39c6f8059
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-core-1.9.1/src/registry.rs:749:9
  50:        0x1032fa174 - rayon_core::registry::WorkerThread::wait_until_cold::hadcc5ed99cfd3ccf
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-core-1.9.1/src/registry.rs:726:17
  51:        0x102f01a74 - rayon_core::registry::WorkerThread::wait_until::h52d29bfbb0b0fa9b
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-core-1.9.1/src/registry.rs:700:13
  52:        0x102f022a8 - rayon_core::registry::main_loop::h5298c6ed59426169
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-core-1.9.1/src/registry.rs:833:5
  53:        0x102effdb0 - rayon_core::registry::ThreadBuilder::run::h94eae709989f1e9d
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-core-1.9.1/src/registry.rs:55:18
  54:        0x102f00164 - <rayon_core::registry::DefaultSpawn as rayon_core::registry::ThreadSpawn>::spawn::{{closure}}::h4fc7aad46666d83a
                               at /Users/messense/.cargo/registry/src/gh.neting.cc-1ecc6299db9ec823/rayon-core-1.9.1/src/registry.rs:100:20
  55:        0x102ef28f8 - std::sys_common::backtrace::__rust_begin_short_backtrace::he80d73fd789ab654
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/sys_common/backtrace.rs:123:18
  56:        0x102ed2450 - std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}}::h2edc2484814b1051
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/thread/mod.rs:477:17
  57:        0x102f08714 - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h70594236aab630e6
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/panic/unwind_safe.rs:271:9
  58:        0x102f08d9c - std::panicking::try::do_call::h34a85063bba4f0b0
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/panicking.rs:406:40
  59:        0x102f0a338 - <unknown>
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/fmt/mod.rs:2106:84
  60:        0x102f08838 - std::panicking::try::h03fb4a99d6f0b96e
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/panicking.rs:370:19
  61:        0x102eeda80 - std::panic::catch_unwind::h33f13feaf036e0f9
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/panic.rs:133:14
  62:        0x102ed1dc0 - std::thread::Builder::spawn_unchecked::{{closure}}::h7e27ba8f14d97408
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/thread/mod.rs:476:30
  63:        0x102ec5a68 - core::ops::function::FnOnce::call_once{{vtable.shim}}::hdd01740fb30fbfbe
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/core/src/ops/function.rs:227:5
  64:        0x1032d4fa0 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h07ee3f902de10aa5
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/alloc/src/boxed.rs:1854:9
  65:        0x1032d4fa0 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h6d89e7cd1fc674cd
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/alloc/src/boxed.rs:1854:9
  66:        0x1032d4fa0 - std::sys::unix::thread::Thread::new::thread_start::ha92b558f2b29b4cc
                               at /rustc/9d1b2106e23b1abd32fce1f17267604a5102f57a/library/std/src/sys/unix/thread.rs:108:17
  67:        0x19455d240 - __pthread_deallocate
thread panicked while panicking. aborting.
[1]    33060 trace trap  cargo run -- splat

[messense]

It seems that it's caused by this line of code:

indicatif/src/draw_target.rs

Line 331 in c2de802

let elapsed = now - self.prev;

[djc]

Seems pretty surprising that time appears to be running backwards here. Would be interesting if you can supply more information about in what scenario that might be happening. With rayon on the stack, you probably have some multi-threading going on? So I suppose what might happen is some thread (a) might be waiting for the Mutex for a while, meanwhile another thread (b) manages to draw (with a more recent timestamp than the thread (a)) and then when thread (a) grabs the lock and tries to draw it runs into this issue.

Anyway, I think 3395389 should take care of it.

[messense]

With rayon on the stack, you probably have some multi-threading going on?

That's right.

[messense]

@djc Could you please release a new rc to crates.io? Thanks a lot!

[djc]

Done.