Panic: pidfd is ready to read, the process should have exited

[jeromegn]

Version

TL;DR: 1.42.0

cargo tree

❯ cargo tree | grep tokio
└── tokio v1.42.0
    └── tokio-macros v2.4.0 (proc-macro)
│   │   │   └── tokio v1.42.0 (*)
│   │   └── tokio v1.42.0 (*)
│   │   ├── tokio v1.42.0 (*)
│   │   │   │   ├── tokio v1.42.0 (*)
│   │   │   │   ├── tokio-util v0.7.11
│   │   │   │   │   └── tokio v1.42.0 (*)
│   │   │   ├── tokio v1.42.0 (*)
│   │   ├── tokio v1.42.0 (*)
│   │   ├── tokio v1.42.0 (*)
│   │   │   ├── tokio v1.42.0 (*)
│   │   │   ├── tokio-util v0.7.11 (*)
│   │   ├── tokio v1.42.0 (*)
│   │   │   └── tokio v1.42.0 (*)
│   │   └── tokio v1.42.0 (*)
│   ├── tokio v1.42.0 (*)
│   ├── tokio-stream v0.1.15
│   │   ├── tokio v1.42.0 (*)
│   │   └── tokio-util v0.7.11 (*)
│   ├── tokio-util v0.7.11 (*)
│   ├── tokio-vsock v0.5.0
│   │   ├── tokio v1.42.0 (*)
│       ├── tokio v1.42.0 (*)
│       ├── tokio-tungstenite v0.21.0
│       │   ├── tokio v1.42.0 (*)
│       ├── tokio-util v0.7.11 (*)
├── tokio v1.42.0 (*)
├── tokio-vsock v0.5.0 (*)
│   ├── tokio v1.42.0 (*)
│   └── tokio v1.42.0 (*)
│   │   ├── tokio v1.42.0 (*)
│   │   ├── tokio-rustls v0.25.0
│   │   │   └── tokio v1.42.0 (*)
│   ├── tokio v1.42.0 (*)
│   ├── tokio-stream v0.1.15 (*)
│   ├── tokio-util v0.7.11 (*)
│   ├── tokio-vsock v0.5.0 (*)
├── tokio v1.42.0 (*)
├── tokio-stream v0.1.15 (*)
├── tokio-util v0.7.11 (*)
├── tokio-vsock v0.5.0 (*)
│   ├── tokio v1.42.0 (*)
│   ├── tokio v1.42.0 (*)
│   ├── tokio-util v0.7.11 (*)
│   │   │       │   ├── tokio v1.42.0 (*)
│   │   │       │   └── tokio-io-timeout v1.2.0
│   │   │       │       └── tokio v1.42.0 (*)
│   │   │       ├── tokio v1.42.0 (*)
│   │   │       ├── tokio-stream v0.1.15 (*)
│   │   │   ├── tokio v1.42.0 (*)
│   │   ├── tokio v1.42.0 (*)
│   │   ├── tokio-util v0.7.11 (*)
│   │   │   └── tokio v1.42.0 (*)
│   │   ├── tokio v1.42.0 (*)
│   │   ├── tokio-stream v0.1.15 (*)
│   ├── tokio v1.42.0 (*)
│   ├── tokio-fd v0.3.0
│   │   └── tokio v1.42.0 (*)
│   ├── tokio-stream v0.1.15 (*)
│   ├── tokio-tar v0.3.1
│   │   ├── tokio v1.42.0 (*)
│   │   ├── tokio-stream v0.1.15 (*)
│   ├── tokio-util v0.7.11 (*)
│   ├── tokio-vsock v0.5.0 (*)
│   │   ├── tokio v1.42.0 (*)
│   │   └── tokio-util v0.7.11 (*)
├── tokio v1.42.0 (*)
├── tokio-util v0.7.11 (*)

Platform

Linux version 5.15.98

Description

I'm launching crun run ... commands with tokio::process::Command and using Child::wait.

stack backtrace:
   0: rust_begin_unwind
             at ./rustc/f6e511eec7342f59a25f7c0534f1dbea00d01b14/library/std/src/panicking.rs:662:5
   1: core::panicking::panic_fmt
             at ./rustc/f6e511eec7342f59a25f7c0534f1dbea00d01b14/library/core/src/panicking.rs:74:14
   2: core::panicking::panic_display
             at ./rustc/f6e511eec7342f59a25f7c0534f1dbea00d01b14/library/core/src/panicking.rs:264:5
   3: core::option::expect_failed
             at ./rustc/f6e511eec7342f59a25f7c0534f1dbea00d01b14/library/core/src/option.rs:2025:5
   4: core::option::Option<T>::expect
             at ./rustc/f6e511eec7342f59a25f7c0534f1dbea00d01b14/library/core/src/option.rs:928:21
   5: <tokio::process::imp::pidfd_reaper::PidfdReaperInner<W> as core::future::future::Future>::poll
             at ./usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.42.0/src/process/unix/pidfd_reaper.rs:127:24
   6: <tokio::process::imp::pidfd_reaper::PidfdReaper<W,Q> as core::future::future::Future>::poll
             at ./usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.42.0/src/process/unix/pidfd_reaper.rs:188:9
   7: <tokio::process::imp::Child as core::future::future::Future>::poll
             at ./usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.42.0/src/process/unix/mod.rs:183:48
   8: <tokio::process::ChildDropGuard<F> as core::future::future::Future>::poll
             at ./usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.42.0/src/process/mod.rs:1023:19
   9: <&mut F as core::future::future::Future>::poll
             at ./rustc/f6e511eec7342f59a25f7c0534f1dbea00d01b14/library/core/src/future/future.rs:111:9
  10: tokio::process::Child::wait::{{closure}}
             at ./usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.42.0/src/process/mod.rs:1223:33

# ...

I am using a FutureMap (implementation) and spawning children on it like:

self.reaper.insert(name.clone(), Box::pin(async move { child.wait().await }));

Then I'm polling it in tokio::select!.

Is it because my FutureMap is not cancel safe?

[jeromegn]

I just noticed that it only seems to happen while I am strace-ing the program after the fact (strace -fp <pid>). Very weird.

[Darksonn]

I'm not sure, but can we eliminate your map from the equation? E.g., could you instead do

let send = send.clone();
tokio::spawn(async move { send.send((key, child.wait().await)) });

with send being a sender for an unbounded mpsc channel. The receiver can go in your select!.

[jeromegn]

@Darksonn best I could do was to use a StreamMap<String, Once<ChildWait>> since I needed to be able to remove a ChildWait in some circumstances and changing that would mean changing a lot more code.

I was still able to trigger the issue with a StreamMap (which I believe should be cancel safe?)

Only when strace-ing the process AND it doesn't happen consistently, but usually 50% of the time if not a bit more.

[jeromegn]

strace significantly slows down syscalls in a process. I wonder if there's a timing issue.

[Darksonn]

cc @ipetkov

Ideas? I guess the pidfd sometimes becomes ready when stracing?

[jeromegn]

To clarify, this happens while stracing and the child exits during that time.