golang / go

The Go programming language
https://go.dev
BSD 3-Clause "New" or "Revised" License
124.12k stars 17.68k forks source link

os/signal: TestTerminalSignal is flaky due to GNU readline #55903

Closed ZekeLu closed 2 years ago

ZekeLu commented 2 years ago

What version of Go are you using (go version)?

$ go version
go version devel go1.20-9aa7107cb5 Wed Sep 28 03:17:13 2022 +0000 linux/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/zeke/.cache/go-build"
GOENV="/home/zeke/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/zeke/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/zeke/go"
GOPRIVATE=""
GOPROXY="https://goproxy.cn,direct"
GOROOT="/snap/go/9951"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/snap/go/9951/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.19"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/zeke/src/golang/gotip/src/go.mod"
GOWORK=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build1116265555=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I have ~/.inputrc with this content:

set editing-mode vi
set keymap vi-command
set show-mode-in-prompt on
set vi-ins-mode-string \1\e[5 q\2
set vi-cmd-mode-string \1\e[1 q\2

And run the test on tip:

./run.bash go_test:os/signal

Note: I don't find an easy way to disable the test cache. I ended up add "-v", "-count=1" to args (the -v option helps revealing the abnormal behavior of the GNU readline library in the later section):

https://github.com/golang/go/blob/a48fc816e703989b54845c5ce557c54a45cbfe9c/src/cmd/dist/test.go#L402-L407

What did you expect to see?

The tests pass.

What did you see instead?

##### Building packages and commands.

##### Test execution environment.
# GOARCH: amd64
# CPU: Intel(R) Core(TM) i7-9700 CPU @ 3.00GHz
# GOOS: linux
# OS Version: Linux 5.15.0-47-generic #51-Ubuntu SMP Thu Aug 11 07:51:15 UTC 2022 x86_64

##### Testing packages.
--- FAIL: TestTerminalSignal (10.01s)
    signal_cgo_test.go:145: "PS1='prompt> '\r\n"
    signal_cgo_test.go:145: "\x1b[5 qbash-5.1$ PS1='prompt> '\r\n"
    signal_cgo_test.go:145: "\x1b[5 qprompt>                                                                        \r\x1b[5 qprompt> \r<41870/b001/signal.test -test.run=TestTerminalSignal\r\n"
    signal_cgo_test.go:145: "test program entering read\r\n"
    signal_cgo_test.go:145: "^Zfg\r\n"
    signal_cgo_test.go:145: "\r\n"
    signal_cgo_test.go:145: "[1]+  Stopped                 GO_TEST_TERMINAL_SIGNALS=1 /tmp/go-build1885841870/b001/signal.test -test.run=TestTerminalSignal\r\n"
    signal_cgo_test.go:145: "\x1b[5 qprompt>                                                                        \r\x1b[5 qprompt> g\r\n"
    signal_cgo_test.go:145: "bash: g: command not found\r\n"
    signal_cgo_test.go:145: "\x1b[5 qprompt>                                                                        \r\x1b[5 qprompt> \r\n"
    signal_cgo_test.go:145: "\x1b[5 qprompt> exit $?\r\n"
    signal_cgo_test.go:145: "exit\r\n"
    signal_cgo_test.go:145: "There are stopped jobs.\r\n"
    signal_cgo_test.go:237: subprogram failed: signal: killed
    signal_cgo_test.go:145: "\x1b[5 qprompt>                                                                        \r\x1b[5 qprompt> read 1 byte: \"f\"\r\n"
FAIL
FAIL    os/signal   11.879s
FAIL
go tool dist: Failed: exit status 1

What's wrong?

Now remove ~/.inputrc and run gotip tool dist test go_test:os/signal (which ./run.bash calls):

 === CONT  TestTerminalSignal
     signal_cgo_test.go:145: "PS1='prompt> '\r\n"
     signal_cgo_test.go:145: "bash-5.1$ PS1='prompt> '\r\n"
-    signal_cgo_test.go:145: "prompt> \r<49327/b001/signal.test -test.run=TestTerminalSignal\r\n"
     signal_cgo_test.go:145: "test program entering read\r\n"
     signal_cgo_test.go:145: "^Z\r\n"
     signal_cgo_test.go:145: "[1]+  Stopped                 GO_TEST_TERMINAL_SIGNALS=1 /tmp/go-build2200749327/b001/signal.test -test.run=TestTerminalSignal\r\n"
     signal_cgo_test.go:145: "prompt> fg\r\n"
     signal_cgo_test.go:145: "GO_TEST_TERMINAL_SIGNALS=1 /tmp/go-build2200749327/b001/signal.test -test.run=TestTerminalSignal\r\n"
     signal_cgo_test.go:145: "\r\n"
     signal_cgo_test.go:145: "read newline\r\n"
     signal_cgo_test.go:145: "prompt> exit $?\r\n"
     signal_cgo_test.go:145: "exit\r\n"
 --- PASS: TestTerminalSignal (0.13s)

Comparing to the output of gotip test ./os/signal -v -count 1 -run ^TestTerminalSignal$:

 === CONT  TestTerminalSignal
     signal_cgo_test.go:145: "PS1='prompt> '\r\n"
     signal_cgo_test.go:145: "\x1b[?2004hbash-5.1$ PS1='prompt> '\r\n"
+    signal_cgo_test.go:145: "\x1b[?2004l\r\x1b[?2004hprompt> GO_TEST_TERMINAL_SIGNALS=1 /tmp/go-build1103848064/b001/signal.test -test.run=TestTerminalSignal\r\n"
     signal_cgo_test.go:145: "\x1b[?2004l\rtest program entering read\r\n"
     signal_cgo_test.go:145: "^Z\r\n"
     signal_cgo_test.go:145: "[1]+  Stopped                 GO_TEST_TERMINAL_SIGNALS=1 /tmp/go-build1103848064/b001/signal.test -test.run=TestTerminalSignal\r\n"
     signal_cgo_test.go:145: "\x1b[?2004hprompt> fg\r\n"
     signal_cgo_test.go:145: "\x1b[?2004l\rGO_TEST_TERMINAL_SIGNALS=1 /tmp/go-build1103848064/b001/signal.test -test.run=TestTerminalSignal\r\n"
     signal_cgo_test.go:145: "\r\n"
     signal_cgo_test.go:145: "read newline\r\n"
     signal_cgo_test.go:145: "\x1b[?2004hprompt> exit $?\r\n"
     signal_cgo_test.go:145: "\x1b[?2004l\rexit\r\n"
 --- PASS: TestTerminalSignal (0.12s)

Even though both tests passed, the first one has shown something abnormal (see the highlighted lines in the output). Since go tool dist test does not pass -v to go test, we haven't noticed that. And when a special ~/.inputrc file is used, the abnormal behavior of readline finally fails the test.

I still don't understand why the GNU readline library works correctly when TestTerminalSignal is run by go test directly, but behaves abnormally when go test is called by go tool dist test. But the fix is easy, we just need to disable it with the bash option --noediting. CL coming soon.

gopherbot commented 2 years ago

Change https://go.dev/cl/435735 mentions this issue: os/signal: disable GUN readline to deflake TestTerminalSignal

ZekeLu commented 2 years ago

@gopherbot, please add labels Testing and remove label compiler/runtime

dmitshur commented 2 years ago

CC @golang/runtime.

prattmic commented 2 years ago

Is this the same cause as #37329 (and thus the CL fixes that)?

ZekeLu commented 2 years ago

It's unlikely that this CL will fix #37329. I will comment there.