Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tail: tests with piped input are failing randomly with broken pipe on macos when no output is expected #3895

Closed
Joining7943 opened this issue Sep 3, 2022 · 3 comments · Fixed by #3910
Labels

Comments

@Joining7943
Copy link
Contributor

Joining7943 commented Sep 3, 2022

Here's the reference to the original discussion:

I did some more testing on macOS.
The failures will also sometimes (10-20% of the time) happen on the main branch.
However, they will only happen inside the test framework, i.e. this will never trigger a failure:

for i in {1..100}; do echo "a\nb\n" | target/debug/tail -n +3; done

but this will fail regularly:

let test_string = "a\nb\n";
new_ucmd!()
    .args(&["-n", "+3"])
    .pipe_in(test_string)
    .succeeds()
    .no_stdout()
    .no_stderr();

Originally posted by @jhscheer in #3874 (comment)

EDIT:
Here's the exact message from one of the failing tests during the CICD #8262 (https://github.com/uutils/coreutils/actions/runs/2939929799) run:

2022-08-27T20:38:23.8017460Z failures:
2022-08-27T20:38:23.8017780Z 
2022-08-27T20:38:23.8019590Z ---- test_tail::pipe_tests::test_pipe_when_negative_lines_option_given_no_newline_at_eof stdout ----
2022-08-27T20:38:23.8020010Z current_directory_resolved: 
2022-08-27T20:38:23.8021360Z run: /Users/runner/work/coreutils/coreutils/target/debug/coreutils tail -n 0
2022-08-27T20:38:23.8022960Z thread 'test_tail::pipe_tests::test_pipe_when_negative_lines_option_given_no_newline_at_eof' panicked at 'failed to write to stdin of child: Broken pi
pe (os error 32)', tests/common/util.rs:1115:21
2022-08-27T20:38:23.8023550Z 
2022-08-27T20:38:23.8023700Z 
2022-08-27T20:38:23.8023940Z failures:
2022-08-27T20:38:23.8024440Z     test_tail::pipe_tests::test_pipe_when_negative_lines_option_given_no_newline_at_eof
2022-08-27T20:38:23.8024840Z 
2022-08-27T20:38:23.8025270Z test result: FAILED. 1904 passed; 1 failed; 31 ignored; 0 measured; 0 filtered out; finished in 109.75s
2022-08-27T20:38:23.8025710Z 
2022-08-27T20:38:23.8097270Z error: test failed, to rerun pass '--test tests'
2022-08-27T20:38:23.8208890Z ##[error]The process '/Users/runner/.cargo/bin/cargo' failed with exit code 101

Looking at the code around tests/common/util.rs:1115 the child target/debug/coreutils tail -n 0 seams to have closed its stdin already when trying to write to its stdin. But maybe I'm wrong. Strange that it happens only on macos.

@Joining7943
Copy link
Contributor Author

Joining7943 commented Sep 8, 2022

I tried something to get to the root of the problem. To see, if tail is the cause or the test system and because tail and head have pretty similar options and structure without sharing common code (as far as I've seen), I ran this code in test_head and test_tail on my linux machine.

#[test]
fn test_force_broken_pipe() {
    for i in 0..10000 {
        dbg!(i);
        let test_string = "a\nb\n";
        new_ucmd!()
            .args(&["-n", "0"])
            .pipe_in(test_string)
            .succeeds()
            .no_stdout()
            .no_stderr();
    }
}

with the following result for head

$ cargo test test_force_broken_pipe --features "head" --no-default-features
...
[/home/lenny/workspace/external/uutils/uutils/tests/by-util/test_head.rs:367] i = 231
current_directory_resolved: 
run: /home/lenny/workspace/external/uutils/uutils/target/debug/coreutils head -n 0
thread 'test_head::test_force_broken_pipe' panicked at 'failed to write to stdin of child: Broken pipe (os error 32)', tests/common/util.rs:1117:21
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

and for tail

$ cargo test test_force_broken_pipe --features "tail" --no-default-features
...
[/home/lenny/workspace/external/uutils/uutils/tests/by-util/test_tail.rs:3139] i = 2335
current_directory_resolved: 
run: /home/lenny/workspace/external/uutils/uutils/target/debug/coreutils tail -n -0
thread 'test_tail::test_force_broken_pipe' panicked at 'failed to write to stdin of child: Broken pipe (os error 32)', tests/common/util.rs:1117:21
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

The broken pipe occurs far more often on macos, and I needed an upper limit of 10000 runs for the for loop on linux to provoke the broken pipe error reliably. I guess this can also at least partly explain why we're running into a todo() in tail.rs at random.

Joining7943 added a commit to Joining7943/uutil-coreutils that referenced this issue Sep 8, 2022
Joining7943 added a commit to Joining7943/uutil-coreutils that referenced this issue Sep 8, 2022
sylvestre pushed a commit to Joining7943/uutil-coreutils that referenced this issue Sep 9, 2022
sylvestre pushed a commit to Joining7943/uutil-coreutils that referenced this issue Sep 9, 2022
sylvestre pushed a commit to Joining7943/uutil-coreutils that referenced this issue Sep 10, 2022
@niyaznigmatullin
Copy link
Contributor

niyaznigmatullin commented Sep 12, 2022

Sorry to return back to this, but I explored it.

tail is calling std::process::exit(0) when it has 0 as input number of lines or bytes:

// Mimic GNU's tail for -[nc]0 without -f and exit immediately
if settings.follow.is_none() && !starts_with_plus && {
if let FilterMode::Lines(l, _) = settings.mode {
l == 0
} else {
settings.mode == FilterMode::Bytes(0)
}
} {
std::process::exit(0)
}

So add std::thread::sleep(Duration::from_secs(3)); after the child is spawned and before writing to stdin, and tail -n -0 or tail -n 0 will fail every time with Broken pipe. But tail -n +3 is not failing, it has different reason or issue.

head -n 0 is also failing because it reads 0 lines immediately returning 0 read lines, without actually reading anything, so it doesn't wait for data in the pipe:

fn read(&mut self, buf: &mut [u8]) -> std::io::Result<usize> {
if self.limit == 0 {
return Ok(0);
}

So what I wanted to say is tail -n -0, tail -n 0 and head -n 0 are expected to break the pipe. For these tests, I think, we need to use ignore_stdin_write_error(). But tail -n +3 is still strange.

@niyaznigmatullin
Copy link
Contributor

niyaznigmatullin commented Sep 12, 2022

I also have an idea, that because Broken pipe happens before we actually observe what the tail process results in, it could be some other reason that tail crashes, and after it crashed the pipe was closed by the OS, so we got Broken pipe, but didn't get the crash reason.

And also it could be that running into not implemented branch is the reason of these Broken pipes and not vice-versa.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants