ICE due to overflow when using a large timeout with futexes

[zjp-CN]

rustc version: 1.80.0-nightly (7c52d2db6 2024-06-03)
platform: x86_64-unknown-linux-gnu

[package]
name = "embassy-local"
version = "0.1.0"
edition = "2021"

[dependencies]
embassy-time = { version = "0.3", features = ["std"] }
embassy-executor = { version = "0.5", features = ["arch-std", "nightly", "executor-thread", "integrated-timers"] }
env_logger = "0.11"
log = "0.4"

#![feature(type_alias_impl_trait)]

#[embassy_executor::task]
async fn run1() {
    loop {
        log::info!("tick for 1 sec");
        embassy_time::Timer::after_secs(1).await;
    }
}

#[embassy_executor::main]
async fn main(spawner: embassy_executor::Spawner) {
    env_logger::builder()
        .filter_level(log::LevelFilter::Debug)
        .init();
    spawner.spawn(run1()).unwrap();
}

The code works fine with cargo run, but cargo miri run will always emit ice

error: the compiler unexpectedly panicked. this is a bug.
...
note: compiler flags: --crate-type bin -C embed-bitcode=no -C debuginfo=2 -C incremental=[REDACTED]
...

thread 'rustc' panicked at src/tools/miri/src/shims/unix/linux/sync.rs:111:79:
called `Option::unwrap()` on a `None` value
stack backtrace:
   0:     0x7fa4b1172df5 - std::backtrace_rs::backtrace::libunwind::trace::h3224993d900c0cad
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/std/src/../../backtrace/src/backtrace/libunwind.rs:116:5
   1:     0x7fa4b1172df5 - std::backtrace_rs::backtrace::trace_unsynchronized::h339a2100d311327b
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:     0x7fa4b1172df5 - std::backtrace::Backtrace::create::h48ea069eab343ac3
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/std/src/backtrace.rs:331:13
   3:     0x7fa4b1172d45 - std::backtrace::Backtrace::force_capture::h78ba1adb602f006f
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/std/src/backtrace.rs:312:9
   4:     0x7fa4b4343309 - std[2bbf5acf8f3ea057]::panicking::update_hook::<alloc[a6966830c706f2eb]::boxed::Box<rustc_driver_impl[6e330a514ad98cb0]::install_ice_hook::{closure#0}>>::{closure#0}
   5:     0x7fa4b118dc0b - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::he674eb098dfdb190
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/alloc/src/boxed.rs:2077:9
   6:     0x7fa4b118dc0b - std::panicking::rust_panic_with_hook::h44663117b2227ef3
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/std/src/panicking.rs:799:13
   7:     0x7fa4b118d94b - std::panicking::begin_panic_handler::{{closure}}::h29b7c5472018e4d4
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/std/src/panicking.rs:656:13
   8:     0x7fa4b118b189 - std::sys_common::backtrace::__rust_end_short_backtrace::h956714a7f55a4424
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/std/src/sys_common/backtrace.rs:171:18
   9:     0x7fa4b118d6b7 - rust_begin_unwind
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/std/src/panicking.rs:652:5
  10:     0x7fa4b11d7a03 - core::panicking::panic_fmt::h140c11e9043ee68a
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/core/src/panicking.rs:72:14
  11:     0x7fa4b11d7aac - core::panicking::panic::hc7a34b605a1cc311
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/core/src/panicking.rs:146:5
  12:     0x7fa4b11d7749 - core::option::unwrap_failed::h213faa99a0661424
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/core/src/option.rs:1987:5
  13:     0x564694118643 - miri[8a164ab9c19d9df3]::shims::unix::linux::sync::futex
  14:     0x56469411553a - <rustc_const_eval[a3385c3ffaf9923d]::interpret::eval_context::InterpCx<miri[8a164ab9c19d9df3]::machine::MiriMachine> as miri[8a164ab9c19d9df3]::shims::unix::linux::foreign_items::EvalContextExt>::emulate_foreign_item_inner
  15:     0x5646940f512b - <rustc_const_eval[a3385c3ffaf9923d]::interpret::eval_context::InterpCx<miri[8a164ab9c19d9df3]::machine::MiriMachine> as miri[8a164ab9c19d9df3]::shims::unix::foreign_items::EvalContextExt>::emulate_foreign_item_inner
  16:     0x564694159850 - <rustc_const_eval[a3385c3ffaf9923d]::interpret::eval_context::InterpCx<miri[8a164ab9c19d9df3]::machine::MiriMachine> as miri[8a164ab9c19d9df3]::shims::foreign_items::EvalContextExtPriv>::emulate_foreign_item_inner
  17:     0x564694156540 - <rustc_const_eval[a3385c3ffaf9923d]::interpret::eval_context::InterpCx<miri[8a164ab9c19d9df3]::machine::MiriMachine> as miri[8a164ab9c19d9df3]::shims::foreign_items::EvalContextExt>::emulate_foreign_item
  18:     0x56469404370b - <rustc_const_eval[a3385c3ffaf9923d]::interpret::eval_context::InterpCx<miri[8a164ab9c19d9df3]::machine::MiriMachine>>::eval_fn_call
  19:     0x5646940a3f48 - <rustc_const_eval[a3385c3ffaf9923d]::interpret::eval_context::InterpCx<miri[8a164ab9c19d9df3]::machine::MiriMachine> as miri[8a164ab9c19d9df3]::concurrency::thread::EvalContextExt>::run_threads
  20:     0x5646940b1f08 - miri[8a164ab9c19d9df3]::eval::eval_entry
  21:     0x564693f84d23 - <miri[d04eebc561510fb3]::MiriCompilerCalls as rustc_driver_impl[6e330a514ad98cb0]::Callbacks>::after_analysis
  22:     0x7fa4b63fe5a2 - rustc_interface[22273d60ef1f27c9]::interface::run_compiler::<core[23d3efa17a5150d7]::result::Result<(), rustc_span[201e2f423baf3f93]::ErrorGuaranteed>, rustc_driver_impl[6e330a514ad98cb0]::run_compiler::{closure#0}>::{closure#1}
  23:     0x7fa4b63f1309 - std[2bbf5acf8f3ea057]::sys_common::backtrace::__rust_begin_short_backtrace::<rustc_interface[22273d60ef1f27c9]::util::run_in_thread_with_globals<rustc_interface[22273d60ef1f27c9]::util::run_in_thread_pool_with_globals<rustc_interface[22273d60ef1f27c9]::interface::run_compiler<core[23d3efa17a5150d7]::result::Result<(), rustc_span[201e2f423baf3f93]::ErrorGuaranteed>, rustc_driver_impl[6e330a514ad98cb0]::run_compiler::{closure#0}>::{closure#1}, core[23d3efa17a5150d7]::result::Result<(), rustc_span[201e2f423baf3f93]::ErrorGuaranteed>>::{closure#0}, core[23d3efa17a5150d7]::result::Result<(), rustc_span[201e2f423baf3f93]::ErrorGuaranteed>>::{closure#0}::{closure#0}, core[23d3efa17a5150d7]::result::Result<(), rustc_span[201e2f423baf3f93]::ErrorGuaranteed>>
  24:     0x7fa4b63f10c0 - <<std[2bbf5acf8f3ea057]::thread::Builder>::spawn_unchecked_<rustc_interface[22273d60ef1f27c9]::util::run_in_thread_with_globals<rustc_interface[22273d60ef1f27c9]::util::run_in_thread_pool_with_globals<rustc_interface[22273d60ef1f27c9]::interface::run_compiler<core[23d3efa17a5150d7]::result::Result<(), rustc_span[201e2f423baf3f93]::ErrorGuaranteed>, rustc_driver_impl[6e330a514ad98cb0]::run_compiler::{closure#0}>::{closure#1}, core[23d3efa17a5150d7]::result::Result<(), rustc_span[201e2f423baf3f93]::ErrorGuaranteed>>::{closure#0}, core[23d3efa17a5150d7]::result::Result<(), rustc_span[201e2f423baf3f93]::ErrorGuaranteed>>::{closure#0}::{closure#0}, core[23d3efa17a5150d7]::result::Result<(), rustc_span[201e2f423baf3f93]::ErrorGuaranteed>>::{closure#2} as core[23d3efa17a5150d7]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
  25:     0x7fa4b1197bfb - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h4dd4540aca7d3356
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/alloc/src/boxed.rs:2063:9
  26:     0x7fa4b1197bfb - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::hdb5b905ec15315eb
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/alloc/src/boxed.rs:2063:9
  27:     0x7fa4b1197bfb - std::sys::pal::unix::thread::Thread::new::thread_start::he09b70746cae6bd3
                               at /rustc/7c52d2db6348b038276198e88a835125849f322e/library/std/src/sys/pal/unix/thread.rs:108:17
  28:     0x7fa4b0e58ac3 - <unknown>
  29:     0x7fa4b0eea850 - <unknown>
  30:                0x0 - <unknown>

rustc version: 1.80.0-nightly (7c52d2db6 2024-06-03)
platform: x86_64-unknown-linux-gnu

query stack during panic:
end of query stack

Miri caused an ICE during evaluation. Here's the interpreter backtrace at the time of the panic:
note: the place in the program where the ICE was triggered
  --> /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys/pal/unix/futex.rs:62:21
   |
62 | /                     libc::syscall(
63 | |                         libc::SYS_futex,
64 | |                         futex as *const AtomicU32,
65 | |                         libc::FUTEX_WAIT_BITSET | libc::FUTEX_PRIVATE_FLAG,
...  |
69 | |                         !0u32,         // A full bitmask, to make it behave like a regular FUTEX_WAIT.
70 | |                     )
   | |_____________________^
   |
   = note: BACKTRACE on thread `unnamed-1`:
   = note: inside `std::sys::pal::unix::futex::futex_wait` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys/pal/unix/futex.rs:62:21: 70:22
   = note: inside `std::sys::sync::condvar::futex::Condvar::wait_optional_timeout` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys/sync/condvar/futex.rs:49:17: 49:62
   = note: inside `std::sys::sync::condvar::futex::Condvar::wait_timeout` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys/sync/condvar/futex.rs:37:9: 37:57
   = note: inside `std::sync::Condvar::wait_timeout::<bool>` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sync/condvar.rs:385:27: 385:61
   = note: inside `embassy_time::driver_std::Signaler::wait_until` at /root/.cargo/registry/src/rsproxy.cn-0dccff568467c15b/embassy-time-0.3.0/src/driver_std.rs:184:40: 184:80
   = note: inside `embassy_time::driver_std::TimeDriver::alarm_thread` at /root/.cargo/registry/src/rsproxy.cn-0dccff568467c15b/embassy-time-0.3.0/src/driver_std.rs:110:13: 110:66
   = note: inside `<fn() {embassy_time::driver_std::TimeDriver::alarm_thread} as std::ops::FnOnce<()>>::call_once - shim(fn() {embassy_time::driver_std::TimeDriver::alarm_thread})` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5: 250:71
   = note: inside `std::sys_common::backtrace::__rust_begin_short_backtrace::<fn() {embassy_time::driver_std::TimeDriver::alarm_thread}, ()>` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys_common/backtrace.rs:155:18: 155:21
   = note: inside closure at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/thread/mod.rs:542:17: 542:78
   = note: inside `<std::panic::AssertUnwindSafe<{closure@std::thread::Builder::spawn_unchecked_<'_, '_, fn() {embassy_time::driver_std::TimeDriver::alarm_thread}, ()>::{closure#2}::{closure#0}}> as std::ops::FnOnce<()>>::call_once` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/panic/unwind_safe.rs:272:9: 272:19
   = note: inside `std::panicking::r#try::do_call::<std::panic::AssertUnwindSafe<{closure@std::thread::Builder::spawn_unchecked_<'_, '_, fn() {embassy_time::driver_std::TimeDriver::alarm_thread}, ()>::{closure#2}::{closure#0}}>, ()>` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:559:40: 559:43
   = note: inside `std::panicking::r#try::<(), std::panic::AssertUnwindSafe<{closure@std::thread::Builder::spawn_unchecked_<'_, '_, fn() {embassy_time::driver_std::TimeDriver::alarm_thread}, ()>::{closure#2}::{closure#0}}>>` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:523:19: 523:88
   = note: inside `std::panic::catch_unwind::<std::panic::AssertUnwindSafe<{closure@std::thread::Builder::spawn_unchecked_<'_, '_, fn() {embassy_time::driver_std::TimeDriver::alarm_thread}, ()>::{closure#2}::{closure#0}}>, ()>` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panic.rs:149:14: 149:33
   = note: inside closure at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/thread/mod.rs:541:30: 543:16
   = note: inside `<{closure@std::thread::Builder::spawn_unchecked_<'_, '_, fn() {embassy_time::driver_std::TimeDriver::alarm_thread}, ()>::{closure#2}} as std::ops::FnOnce<()>>::call_once - shim(vtable)` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5: 250:71
   = note: inside `<std::boxed::Box<dyn std::ops::FnOnce()> as std::ops::FnOnce<()>>::call_once` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/alloc/src/boxed.rs:2063:9: 2063:52
   = note: inside `<std::boxed::Box<std::boxed::Box<dyn std::ops::FnOnce()>> as std::ops::FnOnce<()>>::call_once` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/alloc/src/boxed.rs:2063:9: 2063:52
   = note: inside `std::sys::pal::unix::thread::Thread::new::thread_start` at /root/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys/pal/unix/thread.rs:108:17: 108:64

[saethlin]

I think the bug is that we're using a u64 of nanoseconds inside the virtual clock which is not capable of handling this totally legitimate futex call:

futex(0x55e3a92ffa4c, FUTEX_WAIT_BITSET_PRIVATE, 2, {tv_sec=18446744083902, tv_nsec=117558982}, FUTEX_BITSET_MATCH_ANY)

We're using u64 because Duration::from_nanos requires it but the function's documentation has a big warning https://doc.rust-lang.org/stable/std/time/struct.Duration.html#method.from_nanos:

Note: Using this on the return value of as_nanos() might cause unexpected behavior: as_nanos() returns a u128, and can return values that do not fit in u64, e.g. 585 years. Instead, consider using the pattern Duration::new(d.as_secs(), d.subsec_nanos()) if you cannot copy/clone the Duration directly.

We should be using Duration::new instead of Duration::from_nanos, then we should at least convert the virtual clock to a u128 of nanoseconds. Possibly we should match its internals to what is in the standard library types.

The changes are all in this file and look rather approachable to me: https://github.com/rust-lang/miri/blob/38e318ccd255a090eb57e19d2aac5ed2ec0e2b92/src/clock.rs

[RalfJung]

Yeah I guess that should either be u128 (and argue carefully why that cannot overflow) or use saturating arithmetic - waking up early is always fine.