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.

Sign up for GitHub

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

Jump to bottom

exec.Command().Run() hang on #37498

Closed
derentw opened this issue Feb 27, 2020 · 1 comment
Closed

exec.Command().Run() hang on #37498

derentw opened this issue Feb 27, 2020 · 1 comment
Labels
FrozenDueToAge

Comments

@derentw
Copy link

derentw commented Feb 27, 2020

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

$ go version
go version go1.13.3 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="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/root/go"
GOPRIVATE=""
GOPROXY="direct"
GOROOT="/usr/lib/golang"
GOSUMDB="off"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/golang/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
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 -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build872242136=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I develop a http server by go, it use fineuplader upload file to my fuse file system.

The fuse file system have a cache algorithm. If the cache is full, file write will wait cache available for 20 min. This make go http server io.copy() waiting...

And the go http server have a routine work check some Linux service is active. I use following

cmd := exec.Command("systemctl", "is-active", "--quiet", servicename)
err := cmd.Run()

I found this routine work hang on cmd.Run(). it not 100% hang on, but have a very high fail rate.

I do kill -SIGQUIT , and got following

SIGQUIT: quit

PC=0x466e61 m=0 sigcode=0

goroutine 0 [idle]:
runtime.futex(0x1130748, 0x80, 0x0, 0x0, 0x0, 0x440056, 0xc00003aa38, 0x40d364, 0x7ffcb1481d70, 0x40d7d7, ...)
    /usr/lib/golang/src/runtime/sys_linux_amd64.s:535 +0x21
runtime.futexsleep(0x1130748, 0x0, 0xffffffffffffffff)
    /usr/lib/golang/src/runtime/os_linux.go:44 +0x46
runtime.notesleep(0x1130748)
    /usr/lib/golang/src/runtime/lock_futex.go:151 +0xc7
runtime.stopm()
    /usr/lib/golang/src/runtime/proc.go:1928 +0xa8
runtime.findrunnable(0xc00003aa00, 0x0)
    /usr/lib/golang/src/runtime/proc.go:2391 +0x335
runtime.schedule()
    /usr/lib/golang/src/runtime/proc.go:2524 +0x25b
runtime.park_m(0xc000740780)
    /usr/lib/golang/src/runtime/proc.go:2610 +0x78
runtime.mcall(0x112fe60)
    /usr/lib/golang/src/runtime/asm_amd64.s:318 +0x5b

goroutine 1 [select (no cases)]:
main.main()
    /root/go/src/myproject/main.go:169 +0x10b1

goroutine 19 [syscall]:
os/signal.signal_recv(0x0)
    /usr/lib/golang/src/runtime/sigqueue.go:147 +0x9c
os/signal.loop()
    /usr/lib/golang/src/os/signal/signal_unix.go:23 +0x26
created by os/signal.init.0
    /usr/lib/golang/src/os/signal/signal_unix.go:29 +0x41
goroutine 436 [IO wait]:
internal/poll.runtime_pollWait(0x7f000770aeb0, 0x72, 0xb)
    /usr/lib/golang/src/runtime/netpoll.go:184 +0x5e
internal/poll.(*pollDesc).wait(0xc0001a7698, 0x72, 0xbdd700, 0x0, 0x0)
    /usr/lib/golang/src/internal/poll/fd_poll_runtime.go:87 +0x9b
internal/poll.(*pollDesc).waitRead(0xc0001a7698, 0xc00041b000, 0x0, 0x0)
    /usr/lib/golang/src/internal/poll/fd_poll_runtime.go:92 +0x45
internal/poll.(*FD).Read(0xc0001a7680, 0xc00041b000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/internal/poll/fd_unix.go:169 +0x3d0
net.(*netFD).Read(0xc0001a7680, 0xc00041b000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/net/fd_unix.go:202 +0x7c
net.(*conn).Read(0xc000010168, 0xc00041b000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/net/net.go:184 +0xb5
net/http.(*connReader).Read(0xc0003324e0, 0xc00041b000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/net/http/server.go:785 +0x2c2
bufio.(*Reader).fill(0xc0000d5c80)
    /usr/lib/golang/src/bufio/bufio.go:100 +0x2c9
bufio.(*Reader).ReadSlice(0xc0000d5c80, 0x7effb9974f0a, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/bufio/bufio.go:359 +0x399
bufio.(*Reader).ReadLine(0xc0000d5c80, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/bufio/bufio.go:388 +0x88
net/textproto.(*Reader).readLineSlice(0xc00e7ea2a0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/net/textproto/reader.go:57 +0xb7
net/textproto.(*Reader).ReadLine(0xc00e7ea2a0, 0x0, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/net/textproto/reader.go:38 +0x6f
net/http.readRequest(0xc0000d5c80, 0x101000, 0xc03a851600, 0x0, 0x0)
    /usr/lib/golang/src/net/http/request.go:1012 +0xb6
net/http.(*conn).readRequest(0xc00018ae60, 0xbe6c80, 0xc00024f180, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/net/http/server.go:965 +0x507
net/http.(*conn).serve(0xc00018ae60, 0xbe6c80, 0xc00024f180)
    /usr/lib/golang/src/net/http/server.go:1817 +0xd0a
created by net/http.(*Server).Serve
    /usr/lib/golang/src/net/http/server.go:2927 +0x911

goroutine 21 [select]:
database/sql.(*DB).connectionOpener(0xc0001640c0, 0xbe6c80, 0xc0000e8300)
    /usr/lib/golang/src/database/sql/sql.go:1052 +0xf1
created by database/sql.OpenDB
    /usr/lib/golang/src/database/sql/sql.go:722 +0x29c

goroutine 22 [select]:
database/sql.(*DB).connectionResetter(0xc0001640c0, 0xbe6c80, 0xc0000e8300)
    /usr/lib/golang/src/database/sql/sql.go:1065 +0x11f
created by database/sql.OpenDB
    /usr/lib/golang/src/database/sql/sql.go:723 +0x2d2

goroutine 42 [select]:
database/sql.(*DB).connectionOpener(0xc00018e180, 0xbe6c80, 0xc000192200)
    /usr/lib/golang/src/database/sql/sql.go:1052 +0xf1
created by database/sql.OpenDB
    /usr/lib/golang/src/database/sql/sql.go:722 +0x29c

goroutine 43 [select]:
database/sql.(*DB).connectionResetter(0xc00018e180, 0xbe6c80, 0xc000192200)
    /usr/lib/golang/src/database/sql/sql.go:1065 +0x11f
created by database/sql.OpenDB
    /usr/lib/golang/src/database/sql/sql.go:723 +0x2d2

goroutine 32 [select]:
myproject/ThirdParty/jasonlvhit/gocron.(*Scheduler).Start.func1(0xc0000da730, 0xc000384000, 0xc00014e0e0)
    /root/go/src/myproject/ThirdParty/jasonlvhit/gocron/gocron.go:487 +0xcd
created by myproject/ThirdParty/jasonlvhit/gocron.(*Scheduler).Start
    /root/go/src/myproject/ThirdParty/jasonlvhit/gocron/gocron.go:485 +0x95

goroutine 1224 [syscall]:
syscall.Syscall(0x1, 0xf, 0xc000302000, 0x8000, 0x0, 0x77, 0x0)
    /usr/lib/golang/src/syscall/asm_linux_amd64.s:18 +0x5
syscall.write(0xf, 0xc000302000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/syscall/zsyscall_linux_amd64.go:1005 +0xb9
syscall.Write(0xf, 0xc000302000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/syscall/syscall_unix.go:202 +0x6e
internal/poll.(*FD).Write(0xc0003aa060, 0xc000302000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/internal/poll/fd_unix.go:268 +0x2b7
os.(*File).write(0xc000198000, 0xc000302000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/os/file_unix.go:276 +0x81
os.(*File).Write(0xc000198000, 0xc000302000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/os/file.go:153 +0xe9
io.copyBuffer(0xbdca80, 0xc000198000, 0x7f00076021a0, 0xc000490030, 0xc000302000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/io/io.go:404 +0x441
io.Copy(0xbdca80, 0xc000198000, 0x7f00076021a0, 0xc000490030, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/io/io.go:364 +0x97
myproject/cmd/api/user.ChunkWriter(0xc0001f8070)
    /root/go/src/myproject/cmd/api/user/bucket-objects.go:414 +0x6a5
created by myproject/cmd/api/user.(*Env).FineUploadChunk
    /root/go/src/myproject/cmd/api/user/bucket-objects.go:585 +0x38cc

goroutine 8 [syscall]:
syscall.Syscall(0x0, 0x13, 0xc00032f498, 0x8, 0x14, 0x0, 0x0)
    /usr/lib/golang/src/syscall/asm_linux_amd64.s:18 +0x5
syscall.readlen(0x13, 0xc00032f498, 0x8, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/syscall/zsyscall_linux_amd64.go:1026 +0x70
syscall.forkExec(0xc00040a080, 0xe, 0xc0002c0040, 0x4, 0x4, 0xc00032f7e0, 0x3cef, 0x0, 0x0)
    /usr/lib/golang/src/syscall/exec_unix.go:210 +0x7bf
syscall.StartProcess(0xc00040a080, 0xe, 0xc0002c0040, 0x4, 0x4, 0xc00032f7e0, 0x0, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/syscall/exec_unix.go:248 +0x98
os.startProcess(0xc00040a080, 0xe, 0xc0002c0040, 0x4, 0x4, 0xc00032fbd8, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/os/exec_posix.go:51 +0x555
os.StartProcess(0xc00040a080, 0xe, 0xc0002c0040, 0x4, 0x4, 0xc00032fbd8, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/os/exec.go:102 +0xb9
os/exec.(*Cmd).Start(0xc000330000, 0x0, 0x0)
    /usr/lib/golang/src/os/exec/exec.go:416 +0xb88
os/exec.(*Cmd).Run(0xc000330000, 0x0, 0x0)
    /usr/lib/golang/src/os/exec/exec.go:338 +0x37
myproject/routine.mCheckIsActive(0xb1b58b, 0x3, 0xc0002c0000)
    /root/go/src/myproject/routine/routine.go:92 +0x1d3
myproject/routine.mCheckIfDaemonAlive(0xc0001640c0, 0xc0000da280, 0xc0000da2d0, 0xc00013e000)
    /root/go/src/myproject/routine/routine.go:133 +0x192
myproject/routine.RoutineCheckDaemonAliveStart.func1(0xc0001640c0, 0xc0000da280, 0xc0000da2d0, 0xc00013e000, 0xc0000a40c0)
    /root/go/src/myproject/routine/routine.go:180 +0x176
created by myproject/routine.RoutineCheckDaemonAliveStart
    /root/go/src/myproject/routine/routine.go:174 +0x69

goroutine 9 [chan receive]:
main.main.func3()
    /root/go/src/myproject/main.go:135 +0xc9
created by main.main
    /root/go/src/myproject/main.go:132 +0x1015

goroutine 58 [chan receive]:
main.main.func4(0xc00002e0c0, 0xc0002c0ec0, 0x4, 0x4)
    /root/go/src/myproject/main.go:142 +0x49
created by main.main
    /root/go/src/myproject/main.go:141 +0x10ac

goroutine 6 [chan receive]:
main.main.func1()
    /root/go/src/myproject/main.go:109 +0x602
created by main.main
    /root/go/src/myproject/main.go:99 +0x841

goroutine 7 [chan receive]:
main.main.func2()
    /root/go/src/myproject/main.go:116 +0x1fe
created by main.main
    /root/go/src/myproject/main.go:113 +0x859

goroutine 57 [IO wait]:
internal/poll.runtime_pollWait(0x7f000770b050, 0x72, 0x0)
    /usr/lib/golang/src/runtime/netpoll.go:184 +0x5e
internal/poll.(*pollDesc).wait(0xc0001a6218, 0x72, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/internal/poll/fd_poll_runtime.go:87 +0x9b
internal/poll.(*pollDesc).waitRead(0xc0001a6218, 0xffffffffffffff00, 0x0, 0x0)
    /usr/lib/golang/src/internal/poll/fd_poll_runtime.go:92 +0x45
internal/poll.(*FD).Accept(0xc0001a6200, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/internal/poll/fd_unix.go:384 +0x3c4
net.(*netFD).accept(0xc0001a6200, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/net/fd_unix.go:238 +0x82
net.(*TCPListener).accept(0xc0001dc140, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/net/tcpsock_posix.go:139 +0x61
net.(*TCPListener).Accept(0xc0001dc140, 0x0, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/net/tcpsock.go:261 +0x78
net/http.(*Server).Serve(0xc000382000, 0xbe5200, 0xc0001dc140, 0x0, 0x0)
    /usr/lib/golang/src/net/http/server.go:2896 +0x42b
net/http.(*Server).ListenAndServe(0xc000382000, 0x0, 0x0)
    /usr/lib/golang/src/net/http/server.go:2825 +0x1c1
myproject/httpServer.HttpServerStart.func1()
    /root/go/src/myproject/httpServer/httpServer.go:35 +0x38
created by myproject/httpServer.HttpServerStart
    /root/go/src/myproject/httpServer/httpServer.go:33 +0x3c9

goroutine 86 [select]:
myproject/ThirdParty/jasonlvhit/gocron.(*Scheduler).Start.func1(0xc0002a4ff0, 0xc000342000, 0xc0003262a0)
    /root/go/src/myproject/ThirdParty/jasonlvhit/gocron/gocron.go:487 +0xcd
created by myproject/ThirdParty/jasonlvhit/gocron.(*Scheduler).Start
    /root/go/src/myproject/ThirdParty/jasonlvhit/gocron/gocron.go:485 +0x95

goroutine 87 [select]:
myproject/ThirdParty/jasonlvhit/gocron.(*Scheduler).Start.func1(0xc0002a5040, 0xc000366000, 0xc000326310)
    /root/go/src/myproject/ThirdParty/jasonlvhit/gocron/gocron.go:487 +0xcd
created by myproject/ThirdParty/jasonlvhit/gocron.(*Scheduler).Start
    /root/go/src/myproject/ThirdParty/jasonlvhit/gocron/gocron.go:485 +0x95

goroutine 437 [sleep]:
time.Sleep(0x3b9aca00)
    /usr/lib/golang/src/runtime/time.go:105 +0x121
myproject/cmd/api/user.(*Env).FineUploadChunk(0x112f8e8, 0x7f0007682220, 0xc000333fb0, 0xc000432700)
    /root/go/src/myproject/cmd/api/user/bucket-objects.go:635 +0x1f9e
net/http.HandlerFunc.ServeHTTP(0xc000182b10, 0x7f0007682220, 0xc000333fb0, 0xc000432700)
    /usr/lib/golang/src/net/http/server.go:2007 +0x44
myproject/cmd/api/user.(*Env).Mw.func1(0x7f0007682220, 0xc000333fb0, 0xc000432700)
    /root/go/src/myproject/cmd/api/user/middleware.go:29 +0x30a
net/http.HandlerFunc.ServeHTTP(0xc00018d0e0, 0x7f0007682220, 0xc000333fb0, 0xc000432700)
    /usr/lib/golang/src/net/http/server.go:2007 +0x44
main.(*App).SystemInitApiMw.func1(0x7f0007682220, 0xc000333fb0, 0xc000432700)
    /root/go/src/myproject/app-api-router.go:32 +0x2de
net/http.HandlerFunc.ServeHTTP(0xc00018d100, 0x7f0007682220, 0xc000333fb0, 0xc000432700)
    /usr/lib/golang/src/net/http/server.go:2007 +0x44
myproject/ThirdParty/gorilla/mux.(*Router).ServeHTTP(0xc000164000, 0x7f0007682220, 0xc000333fb0, 0xc000432700)
    /root/go/src/myproject/ThirdParty/gorilla/mux/mux.go:212 +0x219
myproject/ThirdParty/gorilla/handlers.loggingHandler.ServeHTTP(0xbdca80, 0xc0001ae028, 0xbdc040, 0xc000164000, 0xb488c8, 0xbe54c0, 0xc0003821c0, 0xc000432400)
    /root/go/src/myproject/ThirdParty/gorilla/handlers/logging.go:45 +0x157
net/http.serverHandler.ServeHTTP(0xc000382000, 0xbe54c0, 0xc0003821c0, 0xc000432400)
    /usr/lib/golang/src/net/http/server.go:2802 +0x20f
net/http.(*conn).serve(0xc00018b040, 0xbe6c80, 0xc00024f2c0)
    /usr/lib/golang/src/net/http/server.go:1890 +0x1716
created by net/http.(*Server).Serve
    /usr/lib/golang/src/net/http/server.go:2927 +0x911

goroutine 1686 [IO wait]:
internal/poll.runtime_pollWait(0x7f000770ade0, 0x72, 0xb)
    /usr/lib/golang/src/runtime/netpoll.go:184 +0x5e
internal/poll.(*pollDesc).wait(0xc0001a7718, 0x72, 0xbdd700, 0x0, 0x0)
    /usr/lib/golang/src/internal/poll/fd_poll_runtime.go:87 +0x9b
internal/poll.(*pollDesc).waitRead(0xc0001a7718, 0xc000332500, 0x0, 0x0)
    /usr/lib/golang/src/internal/poll/fd_poll_runtime.go:92 +0x45
internal/poll.(*FD).Read(0xc0001a7700, 0xc0003325e1, 0x1, 0x1, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/internal/poll/fd_unix.go:169 +0x3d0
net.(*netFD).Read(0xc0001a7700, 0xc0003325e1, 0x1, 0x1, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/net/fd_unix.go:202 +0x7c
net.(*conn).Read(0xc000010170, 0xc0003325e1, 0x1, 0x1, 0x0, 0x0, 0x0)
    /usr/lib/golang/src/net/net.go:184 +0xb5
net/http.(*connReader).backgroundRead(0xc0003325d0)
    /usr/lib/golang/src/net/http/server.go:677 +0xb6
created by net/http.(*connReader).startBackgroundRead
    /usr/lib/golang/src/net/http/server.go:673 +0x12f

rax    0xca
rbx    0xc
rcx    0xffffffffffffffff
rdx    0x0
rdi    0x1130748
rsi    0x80
rbp    0x7ffcb1481d38
rsp    0x7ffcb1481cf0
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x5
r13    0x1
r14    0x0
r15    0x0
rip    0x466e61
rflags 0x286
cs     0x33
fs     0x0
gs     0x0

What did you expect to see?

cmd := exec.Command("systemctl", "is-active", "--quiet", servicename)
err := cmd.Run()

Do Not hang on cmd.Run()

What did you see instead?

no any instead...
@mvdan
Copy link
Member

mvdan commented Feb 27, 2020

The Go project doesn't use the issue tracker for questions. See https://golang.org/wiki/Questions.

@mvdan mvdan closed this as completed Feb 27, 2020
@golang golang locked and limited conversation to collaborators Feb 26, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@mvdan @gopherbot @derentw