nextest icon indicating copy to clipboard operation
nextest copied to clipboard

[windows] tests that send ctrl-c to themselves can hang until the next message is printed

Open eval-exec opened this issue 2 years ago • 5 comments

I write a unit test for windows platform: https://github.com/eval-exec/playground/blob/main/signal/src/lib.rs

It will register a signal handler, send Ctrl-C signal to itself after 2 seconds.

When I run the unit test by cargo test -- --nocapture, it's output is as my expectation:

PS C:\Users\vagrant\playground\signal> cargo test -- --nocapture
   Compiling signal v0.1.0 (C:\Users\vagrant\playground\signal)
    Finished test [unoptimized + debuginfo] target(s) in 1.33s
     Running unittests src\lib.rs (target\debug\deps\signal-01159ef0fca3f908.exe)

running 1 test
Waiting for Ctrl-C...
send CTRL_C event to myself on windows platform
test tests::basic ... ok

But, when I execute the unit test by cargo nextest run --hide-progress-bar --success-output immediate --failure-output immediate, its behaviour is weird:

PS C:\Users\vagrant\playground\signal> cargo nextest run --hide-progress-bar --success-output immediate --failure-output immediate
    Finished test [unoptimized + debuginfo] target(s) in 0.04s
    Starting 1 test across 1 binary
        SLOW [> 60.000s] signal tests::basic
   Canceling due to interrupt: 1 tests still running
        PASS [  60.023s] signal tests::basic
------------
     Summary [  60.025s] 1 test run: 1 passed (1 slow), 0 skipped

It cost 60s, it seems that the unit test didn't catch Ctrl-C signal. Why?

eval-exec avatar Jul 18 '23 14:07 eval-exec

Thanks, it looks like the ctrl-c needs to be forwarded from nextest to child test processes, similar to how signals are forwarded on Unix. The code for that just hasn't been written yet. Would you like to contribute a patch?

sunshowers avatar Jul 18 '23 16:07 sunshowers

Thanks, it looks like the ctrl-c needs to be forwarded from nextest to child test processes, similar to how signals are forwarded on Unix. The code for that just hasn't been written yet. Would you like to contribute a patch?

How to contribute a patch to this? I don't have much knowledge on windows system programming. What Windows APIs do I need to solve this? Thank you.

eval-exec avatar Jul 19 '23 08:07 eval-exec

So looking at your test further, I'm now less sure of what's going on. It looks like the test sends ctrl-c to itself (which is fine) but for some reason nextest doesn't pick up on the test exiting until 60 seconds pass. I'm not actually sure what's going on. This is going to require some debugging.

I don't have time to do this for at least the next few weeks, so any assistance would be appreciated. It's worth just digging into whether https://github.com/nextest-rs/nextest/blob/e815305fe4daec906969cb969e489f57d1027a8f/nextest-runner/src/runner.rs#L744-L746 fires after 2 seconds. Also why does it take almost exactly 60 seconds? (I wonder if what's happening is that the timer firing is causing an explicit poll to happen on whether the child process has exited, when it's not being automatically woken up by the exit happening -- would be easy to verify by setting the slow timeout to something else like 30s and seeing if the test takes 30 seconds to exit).

sunshowers avatar Jul 19 '23 19:07 sunshowers

I encountered the same problem. After investigation, I found that this has nothing to do with nextest.

Create a sample project:

src/main.rs:

use std::time::Duration;
use windows_sys::Win32::{
    Foundation::GetLastError,
    System::Console::{GenerateConsoleCtrlEvent, CTRL_C_EVENT},
};

fn send_ctrlc_later(duration: Duration) {
    std::thread::spawn(move || {
        std::thread::sleep(duration);

        // send CTRL_C event to myself on windows platform
        let pid = std::process::id();
        println!("send CTRL_C event to myself({}) on windows platform", pid);
        unsafe {
            GenerateConsoleCtrlEvent(CTRL_C_EVENT, pid);
            println!("GetLastError: {}", GetLastError());
        }
    });
}

fn main() {
    let (sender, receiver) = std::sync::mpsc::channel();
    ctrlc::set_handler(move || sender.send(()).unwrap()).expect("Error setting Ctrl-C handler");

    send_ctrlc_later(Duration::from_secs(2));

    let pid = std::process::id();
    println!("Waiting for Ctrl-C: {}", pid);
    receiver.recv().unwrap();
}

Cargo.toml:

[dependencies]
ctrlc = "3.4.2"
no-panic = "0.1"
windows-sys = { version = "0.52", features = ["Win32_Foundation"] }

Run cargo test, you will see:

Waiting for Ctrl-C: 12672
send CTRL_C event to myself(12672) on windows platform
GetLastError: 0

Run cargo test > emm.txt, cargo will hang forever. You will see this in emm.txt:

Waiting for Ctrl-C: 30380
send CTRL_C event to myself(30380) on windows platform
GetLastError: 6

GetLastError returns 6, which means GenerateConsoleCtrlEvent returns ERROR_INVALID_HANDLE error. However, sending a key storke (e.g. space) in console unblocks the hang.

This is very obscure and I didn't find anything useful by googling :-(

Though GenerateConsoleCtrlEvent returns error, ctrl c signal seems to be pushed into some kind of buffer. After stdio is activated(by typing in my case, by generating slow test message in nextest case), the ctrl c signal takes effect.

ldm0 avatar Mar 02 '24 21:03 ldm0

Huh, that's really strange. So it's specifically the fact that nextest redirects standard output that causes it? I don't quite understand, to be honest! It may be worth spending some time in Process Explorer to see what's going on.

I found this thread on StackOverflow which might be related, though I'm not sure.

I am wondering if nextest can do anything here. A few things that come to mind that might, but are not guaranteed, to help:

  • create a process group on Windows
  • poke at the console in some way, maybe? I'm way out of my Windows depth here.

sunshowers avatar Mar 03 '24 01:03 sunshowers