<@U051221NF> Any idea what's going on with this er...
# development
w
@happy-kitchen-89482 Any idea what's going on with this error? I've seen it a few times over the last week or so 🧵
👀 1
Copy code
thread 'test_sandboxer_process' panicked at process_execution/sandboxer/tests/integration_test.rs:70:5:
assertion failed: !sandboxer.is_alive().await.unwrap()
stack backtrace:
   0: __rustc::rust_begin_unwind
             at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/panicking.rs:697:5
   1: core::panicking::panic_fmt
             at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/panicking.rs:75:14
   2: core::panicking::panic
             at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/panicking.rs:145:5
   3: integration_test::test_sandboxer_process::{{closure}}
             at ./tests/integration_test.rs:70:5
   4: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/future/future.rs:124:9
   5: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/future/future.rs:124:9
   6: tokio::runtime::scheduler::current_thread::CoreGuard::block_on::{{closure}}::{{closure}}::{{closure}}
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/current_thread/mod.rs:742:70
   7: tokio::task::coop::with_budget
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/task/coop/mod.rs:167:5
   8: tokio::task::coop::budget
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/task/coop/mod.rs:133:5
   9: tokio::runtime::scheduler::current_thread::CoreGuard::block_on::{{closure}}::{{closure}}
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/current_thread/mod.rs:742:25
  10: tokio::runtime::scheduler::current_thread::Context::enter
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/current_thread/mod.rs:432:19
  11: tokio::runtime::scheduler::current_thread::CoreGuard::block_on::{{closure}}
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/current_thread/mod.rs:741:44
  12: tokio::runtime::scheduler::current_thread::CoreGuard::enter::{{closure}}
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/current_thread/mod.rs:829:68
  13: tokio::runtime::context::scoped::Scoped<T>::set
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/context/scoped.rs:40:9
  14: tokio::runtime::context::set_scheduler::{{closure}}
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/context.rs:176:38
  15: std::thread::local::LocalKey<T>::try_with
             at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/thread/local.rs:315:12
  16: std::thread::local::LocalKey<T>::with
             at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/thread/local.rs:279:20
  17: tokio::runtime::context::set_scheduler
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/context.rs:176:17
  18: tokio::runtime::scheduler::current_thread::CoreGuard::enter
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/current_thread/mod.rs:829:27
  19: tokio::runtime::scheduler::current_thread::CoreGuard::block_on
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/current_thread/mod.rs:729:24
  20: tokio::runtime::scheduler::current_thread::CurrentThread::block_on::{{closure}}
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/current_thread/mod.rs:200:33
  21: tokio::runtime::context::runtime::enter_runtime
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/context/runtime.rs:65:16
  22: tokio::runtime::scheduler::current_thread::CurrentThread::block_on
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/current_thread/mod.rs:188:9
  23: tokio::runtime::runtime::Runtime::block_on_inner
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/runtime.rs:368:52
  24: tokio::runtime::runtime::Runtime::block_on
             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/runtime.rs:342:18
  25: integration_test::test_sandboxer_process
             at ./tests/integration_test.rs:70:50
  26: integration_test::test_sandboxer_process::{{closure}}
             at ./tests/integration_test.rs:21:34
  27: core::ops::function::FnOnce::call_once
             at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/ops/function.rs:250:5
  28: core::ops::function::FnOnce::call_once
             at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
test test_sandboxer_process ... FAILED
h
Hmm, might need to bump this sleep to be longer, or add a backoff or something.
w
While loop with a failure above X iterations, thread sleep in each? Also, should that fs::remove_file be a tokio awaited one? … edit… I guess this depends on whether we’re fine blocking the runtime, since it’s in a test, probably doesn’t matter.
Also, I think I’ve only seen this on arm64 failures, so is there something about how the deletions might get deferred or something?
h
Or just that those runners are more contended and so that sleep is insufficient
w
Does the socket need to be a persistent filepath? Or would something like an in-mem socket be good enough?
Man, this is like, the most precise race condition.
Copy code
let path = sandboxer.socket_path();
    fs::remove_file(path).unwrap();
    while fs::exists(path).unwrap() {
        thread::sleep(Duration::from_millis(1));
    }
    thread::sleep(SandboxerService::POLLING_INTERVAL * 2);

    assert!(!sandboxer.is_alive().await.unwrap());
That works... If I remove the multiplier from the POLLING_INTERVAL, I've never gotten it to succeed (20 attempts). Makes some sense, as you'd assume you need at least 1 polling interval (lower bound), but it's just one of those weird timing things
That's like, a hilarious case of stats. 50ms delay, never passes. The closer I get to 100ms, the more frequently it passes .... Damn, I love stupid stuff like this
h
It's a unix-domain socket, so it has to be a real path but it's not a real file
w
okay, so it is a domain socket - really weird that there would be latency in it's removal though. I assumed it was related to macos's filesystem shenanigans where nothing is truly deleted....... until it is
f
Schrodinger's file
redlol 1
f
Did you endup putting up a pr for this one? Just had it fail on my branch
h
Looks like no one did, I'll put one up now
This seems to only happen on macos, so it is likely related to the deletion not being synchronous
Merged. Thanks for the reminder @fresh-mechanic-68429!
🎉 1
f
thanks Benjy, I'll try rebasing my pr to see if that helps CI pass