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.

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

runtime/pprof: TestCPUProfileWithFork is flaky #18349

Closed
bcmills opened this issue Dec 16, 2016 · 8 comments
Closed

runtime/pprof: TestCPUProfileWithFork is flaky #18349

bcmills opened this issue Dec 16, 2016 · 8 comments
Labels
FrozenDueToAge WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Milestone
Go1.10

Comments

@bcmills
Copy link
Contributor

bcmills commented Dec 16, 2016 •
edited

(Extracted from a comment on #18332.)

TestCPUProfileWithFork is flaky for me using all.bash.

$ go version
go version devel +0cd2bf4 Thu Dec 15 22:43:28 2016 +0000 linux/amd64

$ $(go env CC) --version
gcc (Ubuntu 4.8.4-2ubuntu1~14.04.3) 4.8.4

SIGQUIT: quit
PC=0x466343 m=0 sigcode=0

goroutine 16 [running]:
syscall.RawSyscall6(0x38, 0x11, 0x0, 0x0, 0x0, 0x0, 0x0, 0x125, 0xc4204f8a50, 0x80000)
	/home/bcmills/src/go/src/syscall/asm_linux_amd64.s:100 +0x23 fp=0xc4204f89a0 sp=0xc4204f8998
syscall.forkAndExecInChild(0xc420016840, 0xc4204d8560, 0x3, 0x3, 0xc4202c21e0, 0x3c, 0x3c, 0x0, 0x0, 0xc4204f8cc0, ...)
	/home/bcmills/src/go/src/syscall/exec_linux.go:101 +0x210 fp=0xc4204f8ab0 sp=0xc4204f89a0
syscall.forkExec(0x7ffc81cdb688, 0x35, 0xc4204d8000, 0x2, 0x2, 0xc4204f8cc0, 0x0, 0x0, 0x0)
	/home/bcmills/src/go/src/syscall/exec_unix.go:193 +0x368 fp=0xc4204f8bd8 sp=0xc4204f8ab0
syscall.StartProcess(0x7ffc81cdb688, 0x35, 0xc4204d8000, 0x2, 0x2, 0xc4204f8cc0, 0x2, 0x4, 0xc4204e20f0, 0xc4204f8c90)
	/home/bcmills/src/go/src/syscall/exec_unix.go:240 +0x64 fp=0xc4204f8c30 sp=0xc4204f8bd8
os.startProcess(0x7ffc81cdb688, 0x35, 0xc4204d8000, 0x2, 0x2, 0xc4204f8e68, 0xc4204d6800, 0x3b, 0x3b)
	/home/bcmills/src/go/src/os/exec_posix.go:45 +0x1a3 fp=0xc4204f8d18 sp=0xc4204f8c30
os.StartProcess(0x7ffc81cdb688, 0x35, 0xc4204d8000, 0x2, 0x2, 0xc4204f8e68, 0x0, 0x0, 0x4512d0)
	/home/bcmills/src/go/src/os/exec.go:94 +0x64 fp=0xc4204f8d70 sp=0xc4204f8d18
os/exec.(*Cmd).Start(0xc4200b8000, 0xc4200fd701, 0xc4200ba1c0)
	/home/bcmills/src/go/src/os/exec/exec.go:359 +0x3d2 fp=0xc4204f8ec0 sp=0xc4204f8d70
os/exec.(*Cmd).Run(0xc4200b8000, 0xc4200ba1c0, 0xc4200b8000)
	/home/bcmills/src/go/src/os/exec/exec.go:277 +0x2b fp=0xc4204f8ee8 sp=0xc4204f8ec0
os/exec.(*Cmd).CombinedOutput(0xc4200b8000, 0x35, 0xc4200fd778, 0x1, 0x1, 0xc4200b8000)
	/home/bcmills/src/go/src/os/exec/exec.go:495 +0x127 fp=0xc4204f8f20 sp=0xc4204f8ee8
runtime/pprof_test.TestCPUProfileWithFork(0xc420070270)
	/home/bcmills/src/go/src/runtime/pprof/pprof_test.go:271 +0x228 fp=0xc4204f8fa8 sp=0xc4204f8f20
testing.tRunner(0xc420070270, 0x5bf5b8)
	/home/bcmills/src/go/src/testing/testing.go:656 +0x93 fp=0xc4204f8fd0 sp=0xc4204f8fa8
runtime.goexit()
	/home/bcmills/src/go/src/runtime/asm_amd64.s:2184 +0x1 fp=0xc4204f8fd8 sp=0xc4204f8fd0
created by testing.(*T).Run
	/home/bcmills/src/go/src/testing/testing.go:693 +0x2c4

goroutine 1 [chan receive, 3 minutes]:
testing.(*T).Run(0xc4200704e0, 0x5b7328, 0x16, 0x5bf5b8, 0xc420043d01)
	/home/bcmills/src/go/src/testing/testing.go:694 +0x2ee
testing.runTests.func1(0xc4200704e0)
	/home/bcmills/src/go/src/testing/testing.go:877 +0x67
testing.tRunner(0xc4200704e0, 0xc420043de0)
	/home/bcmills/src/go/src/testing/testing.go:656 +0x93
testing.runTests(0xc42000ab60, 0x69b100, 0xa, 0xa, 0x5b3376)
	/home/bcmills/src/go/src/testing/testing.go:883 +0x29d
testing.(*M).Run(0xc420043f20, 0xc420043f20)
	/home/bcmills/src/go/src/testing/testing.go:818 +0xfc
main.main()
runtime/pprof/_test/_testmain.go:60 +0xf7

goroutine 36 [syscall]:
runtime.CPUProfile(0x59a540, 0xc4200a8000, 0x69d620)
	/home/bcmills/src/go/src/runtime/cpuprof.go:448 +0x2d
runtime/pprof.profileWriter(0x6843a0, 0xc4200ba0e0)
	/home/bcmills/src/go/src/runtime/pprof/pprof.go:701 +0x63
created by runtime/pprof.StartCPUProfile
	/home/bcmills/src/go/src/runtime/pprof/pprof.go:688 +0x122

rax    0x38
rbx    0x69ddc0
rcx    0xffffffffffffffff
rdx    0x0
rdi    0x11
rsi    0x0
rbp    0xc4204f8aa0
rsp    0xc4204f8998
r8     0x0
r9     0x0
r10    0x0
r11    0x206
r12    0x0
r13    0xffffffee
r14    0x740
r15    0x100
rip    0x466343
rflags 0x206
cs     0x33
fs     0x0
gs     0x0
*** Test killed with quit: ran too long (4m0s).
FAIL    runtime/pprof   240.059s
@ianlancetaylor ianlancetaylor added this to the Go1.8 milestone Dec 16, 2016
@ianlancetaylor
Copy link
Contributor

Thanks for pulling this out of the other issue. I'm not sure what is happening here. The test was killed because it ran for more than 4 minutes. When I run the test with -test.short, which is how all.bash runs it, it takes around 1.3 seconds. The interrupt occurred while the syscall package was calling the clone syscall. It appears that that somehow hung. I can not think of anything that would cause that to happen.

Can you recreate this at all? Do you have any FUSE file systems mounted (I'm looking at #11155)?

@bcmills
Copy link
Contributor Author

bcmills commented Dec 16, 2016 •
edited

I do indeed have a FUSE filesystem mounted, but I don't think the all.bash test environment includes any FUSE-mounted paths on my system.

I saw several flakes yesterday, but am unable to reproduce one today.

Pardon my ignorance, but I can't seem to figure out how to run individual standard-library tests in the correct environment. (go test runtime/pprof/pprof_test.go -test.short fails for me every time in an unrelated way, so I'm assuming I'm invoking it incorrectly.) Could you share the command-line you're using to run it?

@bradfitz
Copy link
Contributor

go test generally takes a package, not a file. The file support is very limited and weird, and probably doesn't work for the standard library.

$ go test -short runtime/pprof
$ go test -short -run=RegexpFilter runtime/pprof

@bcmills
Copy link
Contributor Author

bcmills commented Dec 16, 2016

Found a command-line that seems to run the test, but it's not reproducing the failure:

$ GOPATH="$GOROOT/src" go test runtime/pprof -test.short

@bradfitz
Copy link
Contributor

GOPATH="$GOROOT/src" is bogus. The GOPATH and GOROOT can't overlap. Some commands throw errors if they do. Probably "go test" should also.

@bcmills
Copy link
Contributor Author

bcmills commented Dec 16, 2016

Ok, I think I've got my workspace in a more sane state: go test runtime/pprof -test.short works out of the box now. Still trying to reproduce the failure.

@bradfitz bradfitz modified the milestones: Go1.9Maybe, Go1.8 Dec 19, 2016
@bradfitz bradfitz added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Dec 19, 2016
@bradfitz
Copy link
Contributor

bradfitz commented Jan 4, 2017

@bcmills, any update?

@bcmills
Copy link
Contributor Author

bcmills commented Jan 10, 2017

I still haven't been able to reproduce the flakes I was seeing.

@bradfitz bradfitz modified the milestones: Go1.9Maybe, Go1.10 Jul 20, 2017
@rsc rsc closed this as completed Nov 29, 2017
@golang golang locked and limited conversation to collaborators Nov 29, 2018
@rsc rsc unassigned bcmills Jun 23, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
None yet
Milestone
Go1.10
Development

No branches or pull requests
5 participants
@bradfitz @rsc @ianlancetaylor @bcmills @gopherbot