-
Notifications
You must be signed in to change notification settings - Fork 18.4k
Description
Go version
go version go1.25.1 X:nodwarf5 linux/amd64
Output of go env in your module/workspace:
AR='ar'
CC='gcc'
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_ENABLED='1'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
CXX='g++'
GCCGO='gccgo'
GO111MODULE=''
GOAMD64='v3'
GOARCH='amd64'
GOAUTH='netrc'
GOBIN=''
GOCACHE='/home/carlo/.cache/go-build'
GOCACHEPROG=''
GODEBUG=''
GOENV='/home/carlo/.config/go/env'
GOEXE=''
GOEXPERIMENT='nodwarf5'
GOFIPS140='off'
GOFLAGS=''
GOGCCFLAGS='-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build3565487044=/tmp/go-build -gno-record-gcc-switches'
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMOD='/home/carlo/src/go-splice-bug/go.mod'
GOMODCACHE='/home/carlo/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/home/carlo/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/usr/lib/go'
GOSUMDB='sum.golang.org'
GOTELEMETRY='off'
GOTELEMETRYDIR='/home/carlo/.config/go/telemetry'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/usr/lib/go/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='go1.25.1 X:nodwarf5'
GOWORK=''
PKG_CONFIG='pkg-config'What did you do?
I compiled https://go.dev/play/p/ZdL0KON4woF as go-splice-bug and ran ./go-splice-bug server in one window. In another window, I ran ./go-splice-bug client | sleep inf.
What did you see happen?
As expected, the client does not print anything, since its output is being redirected to the sleep inf process, which does nothing (and in particular does not read its stdin).
At the same time, the client process CPU usage went up to 100%. This is unexpected.
What did you expect to see?
The client should not busy-loop just because it is being asked to write its output to a pipe whose reader isn't reading.
Analyzing what is happening, the relevant stacktrace is:
3 0x00000000004b64ee in syscall.Splice
at /usr/lib/go/src/syscall/zsyscall_linux_amd64.go:1340
4 0x00000000004d6a1c in internal/poll.splice
at /usr/lib/go/src/internal/poll/splice_linux.go:169
5 0x00000000004d6689 in internal/poll.splicePump
at /usr/lib/go/src/internal/poll/splice_linux.go:141
6 0x00000000004d5e38 in internal/poll.Splice
at /usr/lib/go/src/internal/poll/splice_linux.go:63
7 0x00000000004dd5f5 in os.(*File).spliceToFile
at /usr/lib/go/src/os/zero_copy_linux.go:80
8 0x00000000004dd2ee in os.(*File).readFrom
at /usr/lib/go/src/os/zero_copy_linux.go:56
9 0x00000000004d893b in os.(*File).ReadFrom
at /usr/lib/go/src/os/file.go:179
10 0x000000000054bf25 in main.client
at ./main.go:24
Based on looking at this with a debugger, the issue is that whenever splicePump calls splice here –
go/src/internal/poll/splice_linux.go
Line 141 in 56ebf80
| n, err := splice(sock.Sysfd, pipefd, inPipe, spliceNonblock) |
– it gets back
EAGAIN, because the output file descriptor (stdout) has nothing reading on it. It then gets to:go/src/internal/poll/splice_linux.go
Lines 155 to 159 in 56ebf80
| if sock.pd.pollable() { | |
| if err := sock.pd.waitWrite(sock.isFile); err != nil { | |
| return written, err | |
| } | |
| } |
Here
sock.pd.pollable() returns false, hence it skips calling sock.pd.waitWrite but carries on to the next loop iteration, where it calls splice again. Ad infinitum, leading to a hot busy-loop.
I don't know enough about this code to have an opinion on what the right fix for this could be. But here are some possible approaches that come to mind:
- In the
splicecall, can we avoid passingspliceNonblockand use a blocking call, at least in cases like this? - Is it correct that stdout is not pollable?
os.Stdoutis defined asNewFile(uintptr(syscall.Stdout), "/dev/stdout"), which by my reading creates it as non-pollable regardless of what the file descriptor refers to; perhaps that should be smarter? - Perhaps
os.File.ReadFromshould not use thesplice-based implementation if the file is not pollable?