Why does Ctrl+C terminate tests with STATUS_STACK_BUFFER_OVERRUN?

[EliahKagan]

As Raymond Chen has explained in STATUS_STACK_BUFFER_OVERRUN doesn’t mean that there was a stack buffer overrun, this condition is misleading and often not nearly as serious as it may seem, because this way of terminating a process on Windows often does not designate any stack overflow, buffer overrun, or any kind of memory-related bug or error. Instead, it is widely used to terminate a program in any kind of critical immediate failure.

Nonetheless, I find it odd that I see this when I cancel gitoxide's test suite with Ctrl+C on Windows, since it does not happen when I cancel other Rust projects' tests when running them in the same way.

ek@Glub MINGW64 ~/source/repos/gitoxide (main)
$ cargo nextest run --all --no-fail-fast
warning: function `evaluate_target_dir` is never used
 --> gix-prompt\tests\prompt.rs:9:8
  |
9 |     fn evaluate_target_dir() -> String {
  |        ^^^^^^^^^^^^^^^^^^^
  |
  = note: `#[warn(dead_code)]` on by default

warning: `gix-prompt` (test "prompt") generated 1 warning
   Compiling gix-filter v0.11.2 (C:\Users\ek\source\repos\gitoxide\gix-filter)
    Finished `test` profile [unoptimized + debuginfo] target(s) in 4.67s
    Starting 2355 tests across 127 binaries (9 skipped; run ID: 8406b876-001a-41fa-a054-487ee2cf1f3f, nextest profile: default)
        PASS [   0.095s] gitoxide plumbing::main::tests::clap
        PASS [   0.090s] gitoxide shared::value_parser_tests::rename_fraction
        PASS [   0.085s] gix id::tests::size_of_oid
        PASS [   0.080s] gix open::tests::size_of_options
        PASS [   0.037s] gix remote::connection::fetch::refs::tests::update::unborn_remote_branches_can_be_created_locally_if_they_are_new
        PASS [   0.043s] gix remote::connection::fetch::refs::tests::update::remote_symbolic_refs_with_locally_unavailable_target_result_in_valid_peeled_branches
        PASS [   0.050s] gix remote::connection::fetch::refs::tests::update::remote_symbolic_refs_with_locally_unavailable_target_dont_overwrite_valid_local_branches
        PASS [   0.053s] gix remote::connection::fetch::refs::tests::update::unborn_remote_branches_can_update_local_unborn_branches
        PASS [   0.047s] gix remote::connection::fetch::refs::tests::update::unborn_remote_refs_dont_overwrite_valid_local_refs
        PASS [   0.281s] gix remote::connection::fetch::refs::tests::update::checked_out_branches_in_worktrees_are_rejected_with_additional_information
        PASS [   0.409s] gix::gix clone::blocking_io::fetch_and_checkout_specific_non_existing
        PASS [   0.469s] gix::gix clone::blocking_io::fetch_and_checkout_empty_remote_repo
        PASS [   0.809s] gix::gix clone::blocking_io::fetch_only_without_configuration
        PASS [   1.000s] gix::gix clone::blocking_io::fetch_and_checkout_specific_annotated_tag
        PASS [   1.047s] gix::gix clone::blocking_io::fetch_only_with_configuration
        PASS [   1.107s] gix::gix clone::blocking_io::fetch_and_checkout_specific_ref
        PASS [   1.168s] gix::gix clone::blocking_io::fetch_and_checkout
        PASS [   0.053s] gix::gix clone::clone_and_destination_must_be_empty
        PASS [   0.130s] gix::gix clone::clone_and_early_persist_without_receive
        PASS [   0.128s] gix::gix clone::clone_bare_into_empty_directory_and_early_drop
        PASS [   0.248s] gix::gix clone::blocking_io::from_shallow_prohibited_with_option
        PASS [   0.082s] gix::gix clone::clone_into_empty_directory_and_early_drop
        PASS [   0.069s] gix::gix commit::describe::lightweight_tags_are_sorted_lexicographically
        PASS [   0.068s] gix::gix commit::describe::tags_are_sorted_by_date_and_lexicographically
        PASS [   1.002s] gix::gix clone::blocking_io::fetch_shallow_no_checkout_then_unshallow
        PASS [   0.067s] gix::gix commit::describe::tags_are_sorted_by_priority
        PASS [   0.054s] gix::gix commit::describe::with_dirty_suffix::dirty_suffix_does_not_apply_if_not_dirty
        PASS [   0.068s] gix::gix commit::describe::with_dirty_suffix::dirty_suffix_applies_automatically_if_dirty
        PASS [   0.040s] gix::gix config::tree::branch::merge
        PASS [   0.998s] gix::gix clone::blocking_io::from_non_shallow_by_deepen_exclude_then_deepen_to_unshallow
        PASS [   0.041s] gix::gix config::tree::checkout::workers
        PASS [   0.048s] gix::gix config::tree::core::abbrev
        PASS [   0.039s] gix::gix config::tree::core::autocrlf
        PASS [   0.029s] gix::gix config::tree::core::check_round_trip_encoding
        PASS [   0.042s] gix::gix config::tree::core::check_stat
        PASS [   0.034s] gix::gix config::tree::core::delta_base_cache_limit
   Canceling due to interrupt: 15 tests still running
        PASS [   0.041s] gix::gix config::tree::core::disambiguate
        PASS [   0.033s] gix::gix config::tree::core::log_all_ref_updates
        PASS [   0.537s] gix::gix clone::blocking_io::from_shallow_allowed_by_default
        PASS [   0.040s] gix::gix config::tree::core::eol
        PASS [   0.030s] gix::gix config::tree::core::safecrlf
        PASS [   0.029s] gix::gix config::tree::diff::driver_binary
        PASS [   0.036s] gix::gix config::tree::diff::algorithm
        PASS [   0.051s] gix::gix config::tree::core::timeouts
        PASS [   0.030s] gix::gix config::tree::diff::renames
        PASS [   0.045s] gix::gix config::tree::extensions::object_format
        PASS [   0.037s] gix::gix config::tree::fetch::algorithm
        PASS [   0.031s] gix::gix config::tree::gitoxide::allow::protocol_from_user
        PASS [   0.039s] gix::gix config::tree::fetch::recurse_submodule
        PASS [   0.049s] gix::gix config::tree::gitoxide::author::name_and_email_fallback
        PASS [   0.042s] gix::gix config::tree::gitoxide::commit::author_and_committer_date
        PASS [   0.045s] gix::gix config::tree::gitoxide::committer::name_and_email_fallback
        PASS [   0.036s] gix::gix config::tree::gitoxide::http::connect_timeout
        PASS [   0.028s] gix::gix config::tree::http::extra_header
        PASS [   0.027s] gix::gix config::tree::http::follow_redirects
        PASS [   0.029s] gix::gix config::tree::http::http_version
       ABORT [   1.810s] gix remote::connection::fetch::refs::tests::update::remote_symbolic_refs_can_always_be_set_as_there_is_no_scenario_where_it_could_be_nonexisting_and_rejected
     Message [         ] code 0xc0000409: The system detected an overrun of a stack-based buffer in this application. This overrun could potentially allow a malicious user to gain control of this application. (os error 1282)
       ABORT [   1.765s] gix remote::connection::fetch::refs::tests::update::various_valid_updates
     Message [         ] code 0xc0000409: The system detected an overrun of a stack-based buffer in this application. This overrun could potentially allow a malicious user to gain control of this application. (os error 1282)
       ABORT [   0.801s] gix::gix clone::blocking_io::from_non_shallow_then_deepen_then_deepen_since_to_unshallow
     Message [         ] code 0xc0000409: The system detected an overrun of a stack-based buffer in this application. This overrun could potentially allow a malicious user to gain control of this application. (os error 1282)
       ABORT [   1.901s] gix remote::connection::fetch::refs::tests::update::remote_symbolic_refs_can_be_written_locally_and_point_to_tracking_branch
     Message [         ] code 0xc0000409: The system detected an overrun of a stack-based buffer in this application. This overrun could potentially allow a malicious user to gain control of this application. (os error 1282)
       ABORT [   2.001s] gix remote::connection::fetch::refs::tests::update::non_fast_forward_is_rejected_if_dry_run_is_disabled
     Message [         ] code 0xc0000409: The system detected an overrun of a stack-based buffer in this application. This overrun could potentially allow a malicious user to gain control of this application. (os error 1282)
       ABORT [   2.006s] gix remote::connection::fetch::refs::tests::update::remote_refs_cannot_map_to_local_head
     Message [         ] code 0xc0000409: The system detected an overrun of a stack-based buffer in this application. This overrun could potentially allow a malicious user to gain control of this application. (os error 1282)
       ABORT [   2.067s] gix remote::connection::fetch::refs::tests::update::fast_forwards_are_called_out_even_if_force_is_given
     Message [         ] code 0xc0000409: The system detected an overrun of a stack-based buffer in this application. This overrun could potentially allow a malicious user to gain control of this application. (os error 1282)
       ABORT [   2.062s] gix remote::connection::fetch::refs::tests::update::local_symbolic_refs_can_be_overwritten
     Message [         ] code 0xc0000409: The system detected an overrun of a stack-based buffer in this application. This overrun could potentially allow a malicious user to gain control of this application. (os error 1282)
       ABORT [   2.118s] gix remote::connection::fetch::refs::tests::update::local_direct_refs_are_written_with_symbolic_ones
     Message [         ] code 0xc0000409: The system detected an overrun of a stack-based buffer in this application. This overrun could potentially allow a malicious user to gain control of this application. (os error 1282)
       ABORT [   2.215s] gix remote::connection::fetch::refs::tests::update::non_fast_forward_is_rejected_but_appears_to_be_fast_forward_in_dryrun_mode
     Message [         ] code 0xc0000409: The system detected an overrun of a stack-based buffer in this application. This overrun could potentially allow a malicious user to gain control of this application. (os error 1282)
------------
     Summary [   2.264s] 66/2355 tests run: 56 passed, 10 failed, 0 skipped
error: test run failed

As noted in this Stack Overflow answer and that Microsoft documentation, 0xc0000409 designates a (user mode) STATUS_STACK_BUFFER_OVERRUN.

When this is produced by a call to the __fastfail intrinsic, there is a separate code that provides additional information. I don't know if that's relevant here or how to extract the information. The other error information shown in that test output is os error 1282 which seems to just mean "invalid operation."

For contrast, I have tried running cargo nextest --all --no-fail-fast and pressing Ctrl+C on that same Windows system for three other projects, all of which showed a more intuitive termination condition and none of which showed 0xc0000409.

ripgrep:

       ABORT [   0.047s] globset glob::tests::matchcasei1
     Message [         ] code 0xc000013a: {Application Exit by CTRL+C}
The application terminated as a result of a CTRL+C. (os error 572)

rust-bio:

       ABORT [   0.166s] bio data_structures::interval_tree::array_backed_interval_tree::tests::find_arbitrary
     Message [         ] code 0xc000013a: {Application Exit by CTRL+C}
The application terminated as a result of a CTRL+C. (os error 572)

(With various other interrupted tests, with the same message.)

crossbeam:

       ABORT [   1.046s] crossbeam-channel::after fairness
     Message [         ] code 0xc000013a: {Application Exit by CTRL+C}
The application terminated as a result of a CTRL+C. (os error 572)

(With many other interrupted tests, with the same message.)

"Application Exit by CTRL+C" is an intuitive effect of pressing Ctrl+C to cancel tests, while a request for immediate termination--even if not related to any actual memory errors--is less intuitive.

Full output from all four projects tested can be seen in this gist.

I do not assume this is a bug. But I don't want to assume it isn't, unless this can be explained.

The nextest documentation notes that it uses Windows job objects to terminate process trees "immediately," which I would be taken to think might explain this behavior if it always or usually happened, but does not explain it given that it seems only to happen with gitoxide.

The effect does not appear specific to when tests from any particular crate of gitoxide are running.

Although I believe no signal--in the usual POSIX-related sense--is being used here to terminate the processes. Nonetheless, maybe this has something to do with how gitoxide deals with signals?

I cannot produce this with cargo test commands but I don't know if that means it's related to nextest or instead if just cargo test does not show enough information about termination to reveal it. Likewise, I do not know if this can happen under any non-test circumstances when running applications that use gitoxide crates.

[Byron]

Thanks for bringing this up, it's an interesting issue for sure!

I wonder if this truly only happens when particular gix crates are interrupted during testing when nextest is involved, or if it's specific crates.

Signal handlers aren't setup by any test either.

I would find it interesting to see if a reduced test-run still shows this issue. I.e. if there was a worktree of gitoxide with only 5 crates whose tests nextest would run. It looks like cargo nextest can also run select tests only - with that it might be possible to test individual crates for their abort behaviour.

Ideally, that would make it possible to find a minimal reproduction, and maybe even the reason this happens.
But from my point of view, gitoxide crates don't do anything special at all.

[EliahKagan]

Yes, I can run individual tests with cargo nextest. When running just one test, or a small number of fast tests, there is sometimes a difficulty in getting Ctrl+C to interrupt the test while it is actually running the test case, rather than before or afterward. But it should be possible to overcome this and produce a simpler reproduction. My guess is that something about how the tests are set up is affecting this, so that it will happen with any test run individually that is able to receive SIGINT in the appropriate time window. But I have not yet verified that this is the case.

[Byron]

Maybe this is also something that could asked in the nextest discussions as well - it seems strongly related to how they do process management. Of course it would be interesting to hear what makes gitoxide special, but I wish I could imagine what that would be. Except that maybe, gitoxide spawn subprocesses itself, sometimes it's git, sometimes its shell-scripts to create fixtures (at least during the first run).