TestExecInTTY: execin_test.go:351: unexpected carriage-return in output

[kolyshkin]

During the course of CI for #2411 I saw a single failure from Fedora32 on Vagrant (logs here):

=== RUN   TestExecInTTY
    TestExecInTTY: execin_test.go:351: unexpected carriage-return in output
--- FAIL: TestExecInTTY (0.14s)

It only happened once, and so I suspect some race in the code or in the test. The test code comes from #1146.

@cyphar maybe you could take a look?

[XiaodongLoong]

I also meet this issue:
https://travis-ci.org/github/opencontainers/runc/jobs/708255866

[kolyshkin]

Got it one more time here: https://travis-ci.org/github/opencontainers/runc/jobs/740066484 (#2658 (comment))

[kolyshkin]

Another occurrence: #2682 (comment)

[kolyshkin]

Seems that github actions is faster so we'll see this one more and more now since #2690 is in

[kolyshkin]

OK, finally got the output (from https://github.com/opencontainers/runc/runs/1659399228?check_suite_focus=true):

=== RUN   TestExecInTTY
832
    execin_test.go:349: unexpected carriage-return in output "PID   USER     TIME  COMMAND\r\n    1 root      0:00 cat\n    6 root      0:00 ps\n"
833
--- FAIL: TestExecInTTY (0.14s)

Note the first line ends with \r\n, while the subsequent ones only have \n. This looks like a race between running ps and setting terminal.

[kolyshkin]

Easy to repro locally:

$ cd libcontainer/integration
$ go test -c .
$ $ sudo ./integration.test -test.run TestExecInT -test.count 1000
--- FAIL: TestExecInTTY (0.02s)
    execin_test.go:332: unexpected carriage-return in output "PID   USER     TIME  COMMAND\r\n    1 root      0:00 cat\r\n    8 root      0:00 ps\r\n"
--- FAIL: TestExecInTTY (0.03s)
    execin_test.go:332: unexpected carriage-return in output "PID   USER     TIME  COMMAND\r\n    1 root      0:00 cat\r\n    7 root      0:00 ps\r\n"
FAIL

[kolyshkin]

Definitely a race:

sudo ./integration.test -test.run TestExecInT -test.count 1000
...
execin_test.go:332: unexpected carriage-return in output "PID USER TIME COMMAND\r\n 1 root 0:00 cat\r\n 7 root 0:00 ps\r\n"
execin_test.go:332: unexpected carriage-return in output "PID USER TIME COMMAND\r\n 1 root 0:00 cat\n 7 root 0:00 ps\n"
execin_test.go:332: unexpected carriage-return in output "PID USER TIME COMMAND\r\n 1 root 0:00 cat\r\n 8 root 0:00 ps\r\n"

Most of the times it passes, sometimes it's \r\n in the first line only, sometimes it's \r\n in all lines.

[kolyshkin]

Reopened by #2749

[kolyshkin]

This is not fixed, thus reopening.

[kolyshkin]

One more manifestation of the same race is #4029 in which we use a very short-lived container which produces a single line of output. Sometimes it's with CR, sometimes without 😕

[kolyshkin]

Yet another manifestation of the same race is #4074.