`.with_idle_connection_timeout(Duration::from_secs(u64::MAX))` still a bug. #4641

zrus · 2023-10-13T07:46:47Z

Summary

Simply set idle timeout connection for swarm to Duration::from_secs(u64) or Duration::MAX still cause overflow when adding duration to instant.

Expected behavior

As the examples, I want to keep connections forever.

Actual behavior

thread 'tokio-runtime-worker' panicked at library/std/src/time.rs:419:33:
overflow when adding duration to instant

Relevant log output

[2023-10-13T07:28:54Z INFO  libp2p_mdns::behaviour::iface] creating instance on iface 192.168.1.14
[2023-10-13T07:28:54Z INFO  p2p_actor_sdk::node] Listening on /ip4/127.0.0.1/udp/64103/quic-v1
[2023-10-13T07:28:54Z INFO  p2p_actor_sdk::node] Listening on /ip4/192.168.1.14/udp/64103/quic-v1
[2023-10-13T07:28:55Z INFO  p2p_actor_sdk::behaviours::gossip_bhv] Subscribing `test`..
[2023-10-13T07:28:56Z INFO  libp2p_mdns::behaviour] discovered: 12D3KooWPCA2Nf518t7TN3sQn5Wf4fKjTxEchX841DcJgwnvBCGU /ip4/192.168.1.14/udp/64356/quic-v1
thread 'tokio-runtime-worker' panicked at library/std/src/time.rs:419:33:
overflow when adding duration to instant
stack backtrace:
   0: rust_begin_unwind
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/std/src/panicking.rs:597:5
   1: core::panicking::panic_fmt
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/core/src/panicking.rs:72:14
   2: core::panicking::panic_display
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/core/src/panicking.rs:178:5
   3: core::panicking::panic_str
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/core/src/panicking.rs:152:5
   4: core::option::expect_failed
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/core/src/option.rs:1978:5
   5: core::option::Option<T>::expect
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/core/src/option.rs:888:21
   6: <std::time::Instant as core::ops::arith::Add<core::time::Duration>>::add
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/std/src/time.rs:419:33
   7: futures_timer::native::delay::Delay::_reset
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-timer-3.0.2/src/native/delay.rs:95:46
   8: futures_timer::native::delay::Delay::reset
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-timer-3.0.2/src/native/delay.rs:72:12
   9: libp2p_swarm::connection::Connection<THandler>::poll
             at /Users/zrus/.cargo/git/checkouts/rust-libp2p-98135dbcf5b63918/d6351ee/swarm/src/connection.rs:358:29
  10: libp2p_swarm::connection::pool::task::new_for_established_connection::{{closure}}::{{closure}}
             at /Users/zrus/.cargo/git/checkouts/rust-libp2p-98135dbcf5b63918/d6351ee/swarm/src/connection/pool/task.rs:182:26
  11: <futures_util::future::poll_fn::PollFn<F> as core::future::future::Future>::poll
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/future/poll_fn.rs:56:9
  12: futures_util::future::future::FutureExt::poll_unpin
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/future/future/mod.rs:562:9
  13: <futures_util::future::select::Select<A,B> as core::future::future::Future>::poll
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/future/select.rs:118:35
  14: libp2p_swarm::connection::pool::task::new_for_established_connection::{{closure}}
             at /Users/zrus/.cargo/git/checkouts/rust-libp2p-98135dbcf5b63918/d6351ee/swarm/src/connection/pool/task.rs:184:10
  15: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/core/src/future/future.rs:125:9
  16: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/core.rs:328:17
  17: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/loom/std/unsafe_cell.rs:16:9
  18: tokio::runtime::task::core::Core<T,S>::poll
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/core.rs:317:13
  19: tokio::runtime::task::harness::poll_future::{{closure}}
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/harness.rs:485:19
  20: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/core/src/panic/unwind_safe.rs:271:9
  21: std::panicking::try::do_call
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/std/src/panicking.rs:504:40
  22: ___rust_try
  23: std::panicking::try
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/std/src/panicking.rs:468:19
  24: std::panic::catch_unwind
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/std/src/panic.rs:142:14
  25: tokio::runtime::task::harness::poll_future
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/harness.rs:473:18
  26: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/harness.rs:208:27
  27: tokio::runtime::task::harness::Harness<T,S>::poll
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/harness.rs:153:15
  28: tokio::runtime::task::raw::poll
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/raw.rs:276:5
  29: tokio::runtime::task::raw::RawTask::poll
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/raw.rs:200:18
  30: tokio::runtime::task::LocalNotified<S>::run
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/mod.rs:408:9
  31: tokio::runtime::scheduler::multi_thread::worker::Context::run_task::{{closure}}
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/scheduler/multi_thread/worker.rs:639:17
  32: tokio::runtime::coop::with_budget
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/coop.rs:107:5
  33: tokio::runtime::coop::budget
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/coop.rs:73:5
  34: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/scheduler/multi_thread/worker.rs:575:9
  35: tokio::runtime::scheduler::multi_thread::worker::Context::run
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/scheduler/multi_thread/worker.rs:526:24
  36: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}::{{closure}}
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/scheduler/multi_thread/worker.rs:491:21
  37: tokio::runtime::context::scoped::Scoped<T>::set
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/context/scoped.rs:40:9
  38: tokio::runtime::context::set_scheduler::{{closure}}
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/context.rs:176:26
  39: std::thread::local::LocalKey<T>::try_with
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/std/src/thread/local.rs:270:16
  40: std::thread::local::LocalKey<T>::with
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/std/src/thread/local.rs:246:9
  41: tokio::runtime::context::set_scheduler
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/context.rs:176:9
  42: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/scheduler/multi_thread/worker.rs:486:9
  43: tokio::runtime::context::runtime::enter_runtime
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/context/runtime.rs:65:16
  44: tokio::runtime::scheduler::multi_thread::worker::run
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/scheduler/multi_thread/worker.rs:478:5
  45: tokio::runtime::scheduler::multi_thread::worker::Launch::launch::{{closure}}
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/scheduler/multi_thread/worker.rs:447:45
  46: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/blocking/task.rs:42:21
  47: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/core.rs:328:17
  48: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/loom/std/unsafe_cell.rs:16:9
  49: tokio::runtime::task::core::Core<T,S>::poll
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/core.rs:317:13
  50: tokio::runtime::task::harness::poll_future::{{closure}}
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/harness.rs:485:19
  51: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/core/src/panic/unwind_safe.rs:271:9
  52: std::panicking::try::do_call
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/std/src/panicking.rs:504:40
  53: ___rust_try
  54: std::panicking::try
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/std/src/panicking.rs:468:19
  55: std::panic::catch_unwind
             at /rustc/d627cf07ce46d230a93732a4714d16f00df9466b/library/std/src/panic.rs:142:14
  56: tokio::runtime::task::harness::poll_future
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/harness.rs:473:18
  57: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/harness.rs:208:27
  58: tokio::runtime::task::harness::Harness<T,S>::poll
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/harness.rs:153:15
  59: tokio::runtime::task::raw::poll
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/raw.rs:276:5
  60: tokio::runtime::task::raw::RawTask::poll
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/raw.rs:200:18
  61: tokio::runtime::task::UnownedTask<S>::run
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/task/mod.rs:445:9
  62: tokio::runtime::blocking::pool::Task::run
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/blocking/pool.rs:159:9
  63: tokio::runtime::blocking::pool::Inner::run
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/blocking/pool.rs:513:17
  64: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
             at /Users/zrus/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/blocking/pool.rs:471:13
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

Possible Solution

No response

Version

Directly from github on branch master

Would you like to work on fixing this bug ?

No

The text was updated successfully, but these errors were encountered:

mxinden · 2023-10-13T07:56:30Z

@zrus are you running on the latest patch? I.e. with #4559?

zrus · 2023-10-13T09:23:51Z

@zrus are you running on the latest patch? I.e. with #4559?

I just use directly from git with branch master. I see that pull has already been merged. Did I miss something?

[dependencies.libp2p]
git = "https://github.com/libp2p/rust-libp2p"
features = ["full"]

mxinden · 2023-10-13T10:04:22Z

Which rust-libp2p commit off of master are you using? You can find it in your Cargo.lock file.

zrus · 2023-10-13T10:18:25Z

It's d6351ee. I did try clean and delete Cargo.lock to fetch newest but still the same result.

mxinden · 2023-10-13T12:50:29Z

Thank you for the quick response. The panic seems to be here:

rust-libp2p/swarm/src/connection.rs

Lines 351 to 361 in 74c087d

    
           (Shutdown::Later(timer, deadline), KeepAlive::Until(t)) => { 
        
               if *deadline != t { 
        
                   *deadline = t; 
        
                   if let Some(new_duration) = deadline.checked_duration_since(Instant::now()) 
        
                   { 
        
                       let effective_keep_alive = max(new_duration, *idle_timeout); 
        
                       timer.reset(effective_keep_alive) 
        
                   } 
        
               } 
        
           }

Similar to what #4559 fixed, we need the same fix in timer.reset(effective_keep_alive).

Delay::reset panics when effective_keep_alive + now exceeds Duration.

@zrus would you mind proposing a patch in a new pull request using checked_add_fraction before timer.reset(effective_keep_alive)?

@thomaseizinger long term, I don't think representing the never timeout state with u64::MAX is the best approach, given the many potential panics. How about an Option<Duration> instead where None means to never timeout?

zrus · 2023-10-13T12:57:31Z

@zrus would you mind proposing a patch in a new pull request using checked_add_fraction before timer.reset(effective_keep_alive)?

Sure.

thomaseizinger · 2023-10-13T20:09:23Z

@thomaseizinger long term, I don't think representing the never timeout state with u64::MAX is the best approach, given the many potential panics. How about an Option<Duration> instead where None means to never timeout?

That doesn't solve the panics though right? We still need to properly deal with all cases where users give us a very long duration. What we could do is move away from Duration and have the user pass in either a u16 (max value 18 hours) or u32 (max value 136 years). I think both should be representable as instants on most operating systems.

mxinden · 2023-10-16T13:46:44Z

@thomaseizinger long term, I don't think representing the never timeout state with u64::MAX is the best approach, given the many potential panics. How about an Option<Duration> instead where None means to never timeout?

That doesn't solve the panics though right? We still need to properly deal with all cases where users give us a very long duration. What we could do is move away from Duration and have the user pass in either a u16 (max value 18 hours) or u32 (max value 136 years). I think both should be representable as instants on most operating systems.

I am fine with either:

Allowing a user to provide a Duration, expecting them to either use a small value, or a Duration::MAX, but not e.g. a Duration::MAX - 1. We can then treat Duration::MAX as always keep alive.
As you suggest above, restrict the user input to a u16 or u32, but also offer them to somehow specify always keep alive.

Add safe check to prevent `Delay::reset()` panic when duration overflow. Fixes: #4641. Pull-Request: #4644. Co-authored-by: Leonz <bellerophon00530@gmail.com> Co-authored-by: Max Inden <mail@max-inden.de>

zrus changed the title ~~.with_idle_connection_timeout(Duration::from_secs(u64::MAX) still a bug.~~ .with_idle_connection_timeout(Duration::from_secs(u64::MAX)) still a bug. Oct 13, 2023

zrus mentioned this issue Oct 13, 2023

fix(swarm): prevent overflow in keep-alive computation #4644

Merged

4 tasks

mergify bot closed this as completed in #4644 Oct 18, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

`.with_idle_connection_timeout(Duration::from_secs(u64::MAX))` still a bug. #4641

`.with_idle_connection_timeout(Duration::from_secs(u64::MAX))` still a bug. #4641

zrus commented Oct 13, 2023 •

edited

Loading

mxinden commented Oct 13, 2023

zrus commented Oct 13, 2023 •

edited

Loading

mxinden commented Oct 13, 2023

zrus commented Oct 13, 2023

mxinden commented Oct 13, 2023

zrus commented Oct 13, 2023

thomaseizinger commented Oct 13, 2023

mxinden commented Oct 16, 2023

.with_idle_connection_timeout(Duration::from_secs(u64::MAX)) still a bug. #4641

.with_idle_connection_timeout(Duration::from_secs(u64::MAX)) still a bug. #4641

Comments

zrus commented Oct 13, 2023 • edited Loading

Summary

Expected behavior

Actual behavior

Relevant log output

Possible Solution

Version

Would you like to work on fixing this bug ?

mxinden commented Oct 13, 2023

zrus commented Oct 13, 2023 • edited Loading

mxinden commented Oct 13, 2023

zrus commented Oct 13, 2023

mxinden commented Oct 13, 2023

zrus commented Oct 13, 2023

thomaseizinger commented Oct 13, 2023

mxinden commented Oct 16, 2023

`.with_idle_connection_timeout(Duration::from_secs(u64::MAX))` still a bug. #4641

`.with_idle_connection_timeout(Duration::from_secs(u64::MAX))` still a bug. #4641

zrus commented Oct 13, 2023 •

edited

Loading

zrus commented Oct 13, 2023 •

edited

Loading