go os/exec: 可能存在竞态条件处理stdout&stderr管道

z4bn682m  于 4个月前  发布在  Go
关注(0)|答案(7)|浏览(68)

Go版本
go版本 go1.22.6 linux/amd64

go env 在你的模块/工作区中的输出：

GO111MODULE=''
GOARCH='amd64'
GOBIN=''
GOCACHE='/home/rgooch/.cache/go-build'
GOENV='/home/rgooch/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/home/rgooch/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/home/rgooch/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/usr/local/go1.22.6-amd64'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/usr/local/go1.22.6-amd64/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='go1.22.6'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/home/rgooch/git/Dominator/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build438858212=/tmp/go-build -gno-record-gcc-switches'

你做了什么？

stderr := &strings.Builder{}
stdout := &strings.Builder{}
cmd := exec.Command(path, args...)
cmd.Env = make([]string, 0)
cmd.Stderr = stderr
cmd.Stdout = stdout
if err := cmd.Start(); err != nil {
	return err
}
if err := cmd.Wait(); err != nil {
	return err
}

这捕捉了我启动进程时所做的精髓。请注意，还有其他goroutines,尤其是一个并发接受HTTP CONNECT请求的goroutine。
我还没有能够用最小的程序重现这个问题。
我查看了 os/exec 的实现，但还没有看到潜在的错误，但是考虑到我正在做的事情的核心如此简单，我不得不怀疑是否有一个隐藏在标准库中的错误。它可能是与其他并发创建的文件描述符之间的微妙交互。

你看到了什么发生？

Start() 成功了，但有时 Wait() 从未返回，尽管进程(及其所有子进程)已经退出。
当 Wait() 从未返回时，我可以在子进程退出之前捕获文件描述符：

lr-x------ 1 0 0 64 0 -> /dev/null
l-wx------ 1 0 0 64 1 -> pipe:[61465]
l-wx------ 1 0 0 64 2 -> pipe:[61466]
lr-x------ 1 0 0 64 10 -> /tmp/test.sh

如您所见，stdout和stderr各自具有自己的管道的写入端，这是意料之中的。子进程(及其任何依赖项)肯定不久后就会退出；它们不会出现在进程表中。
在父进程(使用 os/exec 的那个)中，这些是文件描述符：

lrwx------    1 0        0               64 Aug 25 03:41 0 -> /dev/console
lrwx------    1 0        0               64 Aug 25 03:41 1 -> /dev/console
lrwx------    1 0        0               64 Aug 25 03:42 10 -> /dev/pts/0
lrwx------    1 0        0               64 Aug 25 03:42 11 -> socket:[23564]=
lrwx------    1 0        0               64 Aug 25 03:41 2 -> /dev/console
lrwx------    1 0        0               64 Aug 25 03:41 3 -> socket:[15381]=
lrwx------    1 0        0               64 Aug 25 03:41 4 -> anon_inode:[eventpoll]
lr-x------    1 0        0               64 Aug 25 03:41 5 -> pipe:[61446]|
l-wx------    1 0        0               64 Aug 25 03:41 6 -> pipe:[61446]|
l-wx------    1 0        0               64 Aug 25 03:42 7 -> /tmp/log
lrwx------    1 0        0               64 Aug 25 03:42 8 -> socket:[61457]=
lrwx------    1 0        0               64 Aug 25 03:41 9 -> /dev/ptmx

stderr管道的读写侧都已打开，而stdout管道则找不到。

你期望看到什么？

Wait() 应该在进程存在时立即返回。
此外，父进程中的stdout和stderr管道的读侧应该已打开，但写侧不应该。

go

7条答案

按热度按时间
u4vypkhs

u4vypkhs1#

相关问题和文档

(如果觉得有帮助，请给表情投票；欢迎在 this discussion 中提供更详细的反馈。)

赞(0）分享  回复(0）举报  4个月前
vdzxcuhz

vdzxcuhz2#

我认为我们需要一个复制者来处理这份报告。

赞(0）分享  回复(0）举报  4个月前
pbpqsu0x

pbpqsu0x3#

你并没有真正说明子进程在做什么，尤其是它是否可能自己生成其他进程。
有关此问题的讨论，请参阅：https://pkg.go.dev/os/exec#Cmd.WaitDelay。这是否与此相关？

赞(0）分享  回复(0）举报  4个月前
s2j5cfk0

s2j5cfk04#

子进程非常简单：它是一个BusyBox shell(ash)脚本：

#! /tmp/bb/ash

set -eu

ls -Fl /proc/$$/fd > /tmp/test.fds

sleep 0.05

exit 0

我知道关于WaitDelay,但那不应该需要，因为进程和所有子进程都会立即退出。

赞(0）分享  回复(0）举报  4个月前
gev0vcfq

gev0vcfq5#

谢谢。
stderr管道的读写端都已打开，而stdout管道却找不到。
我可能误解了，但在我看来，子进程中的管道是61465和61466,而父进程中的管道是61446,这与两者都不同。也就是说，父进程似乎没有子进程中的任何一个管道，尽管它确实有一个不同的无关管道。
如果你向挂起的进程发送一个SIGQUIT,或者按下^\键，你会得到程序挂起的堆栈跟踪吗？了解确切哪个系统调用没有返回可能会有所帮助。谢谢。

赞(0）分享  回复(0）举报  4个月前
qv7cva1a

qv7cva1a6#

好的，我明白了。以下是相关堆栈跟踪的摘录：

goroutine 1 [chan receive, 1246 minutes]:
os/exec.(*Cmd).awaitGoroutines(0xc0003fc180, 0x0)
	/usr/local/go1.22.6-amd64/src/os/exec/exec.go:957 +0x3b1
os/exec.(*Cmd).Wait(0xc0003fc180)
	/usr/local/go1.22.6-amd64/src/os/exec/exec.go:924 +0x2d0

goroutine 181 [IO wait, 1246 minutes]:
internal/poll.runtime_pollWait(0x7fc1d4e7acc8, 0x72)
	/usr/local/go1.22.6-amd64/src/runtime/netpoll.go:345 +0x85
internal/poll.(*pollDesc).wait(0xc000690140, 0x72, 0x1)
	/usr/local/go1.22.6-amd64/src/internal/poll/fd_poll_runtime.go:84 +0xb1
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go1.22.6-amd64/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc000690120, {0xc00028c000, 0x8000, 0x8000})
	/usr/local/go1.22.6-amd64/src/internal/poll/fd_unix.go:164 +0x466
os.(*File).read(...)
	/usr/local/go1.22.6-amd64/src/os/file_posix.go:29
os.(*File).Read(0xc000398008, {0xc00028c000, 0x8000, 0x8000})
	/usr/local/go1.22.6-amd64/src/os/file.go:118 +0xad
io.copyBuffer({0xcde0a0, 0xc0000fa000}, {0xcde5c0, 0xc00048e010}, {0x0, 0x0, 0x0})
	/usr/local/go1.22.6-amd64/src/io/io.go:429 +0x29b
io.Copy(...)
	/usr/local/go1.22.6-amd64/src/io/io.go:388
os.genericWriteTo(0xc000398008, {0xcde0a0, 0xc0000fa000})
	/usr/local/go1.22.6-amd64/src/os/file.go:269 +0x70
os.(*File).WriteTo(0xc000398008, {0xcde0a0, 0xc0000fa000})
	/usr/local/go1.22.6-amd64/src/os/file.go:247 +0xd5
io.copyBuffer({0xcde0a0, 0xc0000fa000}, {0xcddf00, 0xc000398008}, {0x0, 0x0, 0x0})
	/usr/local/go1.22.6-amd64/src/io/io.go:411 +0xd4
io.Copy(...)
	/usr/local/go1.22.6-amd64/src/io/io.go:388
os/exec.(*Cmd).writerDescriptor.func1()
	/usr/local/go1.22.6-amd64/src/os/exec/exec.go:580 +0x5b
os/exec.(*Cmd).Start.func2(0xc0002640a0)
	/usr/local/go1.22.6-amd64/src/os/exec/exec.go:733 +0x3d
created by os/exec.(*Cmd).Start in goroutine 1
	/usr/local/go1.22.6-amd64/src/os/exec/exec.go:732 +0x11c5

goroutine 182 [IO wait, 1246 minutes]:
internal/poll.runtime_pollWait(0x7fc1d4e7aad8, 0x72)
	/usr/local/go1.22.6-amd64/src/runtime/netpoll.go:345 +0x85
internal/poll.(*pollDesc).wait(0xc000690200, 0x72, 0x1)
	/usr/local/go1.22.6-amd64/src/internal/poll/fd_poll_runtime.go:84 +0xb1
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go1.22.6-amd64/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc0006901e0, {0xc0001aa000, 0x8000, 0x8000})
	/usr/local/go1.22.6-amd64/src/internal/poll/fd_unix.go:164 +0x466
os.(*File).read(...)
	/usr/local/go1.22.6-amd64/src/os/file_posix.go:29
os.(*File).Read(0xc000398030, {0xc0001aa000, 0x8000, 0x8000})
	/usr/local/go1.22.6-amd64/src/os/file.go:118 +0xad
io.copyBuffer({0xcde0a0, 0xc0000fa160}, {0xcde5c0, 0xc000124000}, {0x0, 0x0, 0x0})
	/usr/local/go1.22.6-amd64/src/io/io.go:429 +0x29b
io.Copy(...)
	/usr/local/go1.22.6-amd64/src/io/io.go:388
os.genericWriteTo(0xc000398030, {0xcde0a0, 0xc0000fa160})
	/usr/local/go1.22.6-amd64/src/os/file.go:269 +0x70
os.(*File).WriteTo(0xc000398030, {0xcde0a0, 0xc0000fa160})
	/usr/local/go1.22.6-amd64/src/os/file.go:247 +0xd5
io.copyBuffer({0xcde0a0, 0xc0000fa160}, {0xcddf00, 0xc000398030}, {0x0, 0x0, 0x0})
	/usr/local/go1.22.6-amd64/src/io/io.go:411 +0xd4
io.Copy(...)
	/usr/local/go1.22.6-amd64/src/io/io.go:388
os/exec.(*Cmd).writerDescriptor.func1()
	/usr/local/go1.22.6-amd64/src/os/exec/exec.go:580 +0x5b
os/exec.(*Cmd).Start.func2(0xc0002640e0)
	/usr/local/go1.22.6-amd64/src/os/exec/exec.go:733 +0x3d
created by os/exec.(*Cmd).Start in goroutine 1
	/usr/local/go1.22.6-amd64/src/os/exec/exec.go:732 +0x11c5
赞(0）分享  回复(0）举报  4个月前
du7egjpx

du7egjpx7#

谢谢。这确实看起来像父进程正在等待子进程关闭管道。也就是说，这是受到WaitDelay影响的事情。不过，我还没有解释为什么父进程仍在等待。

赞(0）分享  回复(0）举报  4个月前
我来回答

相关问题

    查看更多

    热门标签

    更多
    JavaquerypythonNode开发语言requestUtil数据库Table后端算法LoggerMessageElementParser

    最新问答

    更多
    • 蜀ICP备13028337号-1 大数据知识库 https://www.saoniuhuo.com © All rights reserved
    • 本站内容来源互联网,如果侵犯您的权益请联系我们删除, 联系方式：448109455@qq.com