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: Test killed with quit: ran too long #21128

Closed
easonyzwang opened this issue Jul 22, 2017 · 11 comments
Closed

runtime/pprof: Test killed with quit: ran too long #21128

easonyzwang opened this issue Jul 22, 2017 · 11 comments
Labels
FrozenDueToAge help wanted NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Testing An issue that has been verified to require only test changes, not just a test failure.
Milestone
Go1.10

Comments

@easonyzwang
Copy link

easonyzwang commented Jul 22, 2017 •
edited

Please answer these questions before submitting your issue. Thanks!

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

1.7.5 and 1.8.3

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

linux, amd64

What did you do?

I am using go1.7 to bootstrap go1.8, install from source, since my system RHEL 5.x not supported by Go distribution

All my go env setting:

GOROOT=${golang_dir}/go
GOROOT_BOOTSTRAP="/opt/elasticbeanstalk/lib/go"
GOROOT_FINAL="/opt/elasticbeanstalk/lib/go"
GOOS="linux"
GOARCH="amd64"
# GO_TEST_TIMEOUT_SCALE=10
# CONFIG_HIGH_RES_TIMERS=y
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOPATH="/root/go"
GORACE=""
GOTOOLDIR="/opt/elasticbeanstalk/lib/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build933756113=/tmp/go-build -gno-record-gcc-switches"
CXX="g++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"

I think those env-variables are correct since it could be successfully installed. But in my install-golang-script, it will roughly 30% fail, after I run ./all.bash.

All of the fail is in testing packages stage due to

 *** Test killed with quit: ran too long (4m0s).
FAIL	runtime/pprof	240.050s

I tried to set timeout longer, like this:
export GO_TEST_TIMEOUT_SCALE=10,
but the result is it will stuck at this stage, and it will not exit even more than 10 minutes.

I also tried to set high resolution timer, but still didn't work.
export CONFIG_HIGH_RES_TIMERS=y

I used top to check the running process information like this:

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
31799 root      20   0  119m 110m 2488 S 100.7  0.4   5:51.92 pprof.test

I set a cronjob to install every 10mins for testing, and it needs around 7mins to build. If it is successful, there will be a time-stamp in my log file.
The results are shown as follow.

Sat Jul 22 02:46:22 UTC 2017
Sat Jul 22 03:27:20 UTC 2017
Sat Jul 22 03:46:55 UTC 2017
Sat Jul 22 03:56:44 UTC 2017
Sat Jul 22 04:06:32 UTC 2017
Sat Jul 22 04:16:13 UTC 2017
Sat Jul 22 04:26:16 UTC 2017
Sat Jul 22 04:46:47 UTC 2017
Sat Jul 22 04:56:49 UTC 2017
Sat Jul 22 05:16:45 UTC 2017
Sat Jul 22 05:26:50 UTC 2017
Sat Jul 22 05:57:17 UTC 2017
Sat Jul 22 06:27:19 UTC 2017
Sat Jul 22 06:37:02 UTC 2017
Sat Jul 22 07:07:15 UTC 2017
Sat Jul 22 07:17:00 UTC 2017
Sat Jul 22 07:36:48 UTC 2017

Anyone know how to fix it?

Update: when I use a new amazon ec2 instance, and the first-time install go from source will always success. So does I restart the instance (considering as running new one).
Fail will randomly occur since the 1st time install, no mater it is running using my own script in crontab or manually run it.

UpdateUpdate Using at command to set scheduled task to install it will always Failed: exit status 1 due to the same reason.
@ALTree
Copy link
Member

ALTree commented Jul 22, 2017 •
edited

CentOS 5 is not supported (see: https://github.com/golang/go/wiki/MinimumRequirements#linux).

Installing from source won't make any difference, unfortunately. Go is not guaranteed to work on CentOS 5 systems.

@bradfitz bradfitz changed the title Install golang from soure will ramdomly fail at runtime/pprof runtime/pprof: Test killed with quit: ran too long Jul 22, 2017
@bradfitz
Copy link
Contributor

Yes, sorry, CentOS 5 is too old and not supported, regardless of how it's built.

@easonyzwang
Copy link
Author

easonyzwang commented Jul 22, 2017 •
edited

@ALTree @bradfitz Actually I am using RHEL 5.x (on Amazon EC2 instance) to run it. I have modify my issue now, and there is no mention about RHEL. Besides, I think the go1.8.3 complier does work on RHEL5.x as my own using experience.

@bradfitz
Copy link
Contributor

What distro, version, and kernel version are you running?

@easonyzwang
Copy link
Author

@bradfitz I think it is amazon-customization linux...
NAME="Amazon Linux AMI"
VERSION="2017.03"
ID_LIKE="rhel fedora"
kernel: Linux 4.9.32-15.41.amzn1.x86_64 x86_64

@bradfitz bradfitz reopened this Jul 22, 2017
@bradfitz bradfitz added help wanted Testing An issue that has been verified to require only test changes, not just a test failure. labels Jul 22, 2017
@bradfitz bradfitz added this to the Unplanned milestone Jul 22, 2017
@bradfitz bradfitz added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jul 22, 2017
@ALTree
Copy link
Member

ALTree commented Jul 23, 2017

Which test is hanging? There's no stacktrace? Is this:

*** Test killed with quit: ran too long (4m0s).
FAIL	runtime/pprof	240.050s

the only thing you see? No stacktrace above?

@easonyzwang
Copy link
Author

easonyzwang commented Jul 24, 2017 •
edited

@ALTree
I tried again and got the more specific error information, hope it is useful:

##### cmd/go terminal test
PASS
ok  	_/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/cmd/go/testdata/testterminal18153	0.004s

##### Testing packages.
ok  	archive/tar	0.070s
ok  	archive/zip	1.758s
ok  	bufio	0.148s
ok  	bytes	0.224s
ok  	compress/bzip2	0.099s
ok  	compress/flate	1.127s
ok  	compress/gzip	0.060s
ok  	compress/lzw	0.014s
ok  	compress/zlib	0.158s
ok  	container/heap	0.078s
ok  	container/list	0.061s
ok  	container/ring	0.046s
ok  	context	1.046s
ok  	crypto/aes	0.051s
ok  	crypto/cipher	0.046s
ok  	crypto/des	0.024s
ok  	crypto/dsa	0.026s
ok  	crypto/ecdsa	0.133s
ok  	crypto/elliptic	0.047s
ok  	crypto/hmac	0.016s
ok  	crypto/md5	0.044s
ok  	crypto/rand	0.054s
ok  	crypto/rc4	0.140s
ok  	crypto/rsa	0.149s
ok  	crypto/sha1	0.073s
ok  	crypto/sha256	0.025s
ok  	crypto/sha512	0.051s
ok  	crypto/subtle	0.020s
ok  	crypto/tls	1.172s
ok  	crypto/x509	1.161s
ok  	database/sql	0.499s
ok  	database/sql/driver	0.017s
ok  	debug/dwarf	0.065s
ok  	debug/elf	0.049s
ok  	debug/gosym	0.496s
ok  	debug/macho	0.030s
ok  	debug/pe	0.031s
ok  	debug/plan9obj	0.014s
ok  	encoding/ascii85	0.032s
ok  	encoding/asn1	0.026s
ok  	encoding/base32	0.023s
ok  	encoding/base64	0.019s
ok  	encoding/binary	0.046s
ok  	encoding/csv	0.062s
ok  	encoding/gob	0.112s
ok  	encoding/hex	0.050s
ok  	encoding/json	0.729s
ok  	encoding/pem	0.053s
ok  	encoding/xml	0.055s
ok  	errors	0.057s
ok  	expvar	0.027s
ok  	flag	0.015s
ok  	fmt	0.145s
ok  	go/ast	0.043s
ok  	go/build	0.164s
ok  	go/constant	0.031s
ok  	go/doc	0.074s
ok  	go/format	0.025s
ok  	go/internal/gccgoimporter	0.021s
ok  	go/internal/gcimporter	0.884s
ok  	go/parser	0.059s
ok  	go/printer	0.494s
ok  	go/scanner	0.042s
ok  	go/token	0.050s
ok  	go/types	0.887s
ok  	hash/adler32	0.036s
ok  	hash/crc32	0.050s
ok  	hash/crc64	0.015s
ok  	hash/fnv	0.016s
ok  	html	0.014s
ok  	html/template	0.076s
ok  	image	0.223s
ok  	image/color	0.097s
ok  	image/draw	0.080s
ok  	image/gif	0.134s
ok  	image/jpeg	0.252s
ok  	image/png	0.119s
ok  	index/suffixarray	0.048s
ok  	internal/pprof/profile	0.049s
ok  	internal/singleflight	0.041s
ok  	internal/trace	0.585s
ok  	io	0.061s
ok  	io/ioutil	0.016s
ok  	log	0.026s
ok  	log/syslog	1.238s
ok  	math	0.029s
ok  	math/big	2.716s
ok  	math/cmplx	0.025s
ok  	math/rand	0.120s
ok  	mime	0.021s
ok  	mime/multipart	0.580s
ok  	mime/quotedprintable	0.272s
ok  	net	1.663s
ok  	net/http	2.691s
ok  	net/http/cgi	0.628s
ok  	net/http/cookiejar	0.063s
ok  	net/http/fcgi	0.031s
ok  	net/http/httptest	0.043s
ok  	net/http/httptrace	0.025s
ok  	net/http/httputil	0.137s
ok  	net/http/internal	0.063s
ok  	net/internal/socktest	0.025s
ok  	net/mail	0.020s
ok  	net/rpc	0.071s
ok  	net/rpc/jsonrpc	0.063s
ok  	net/smtp	0.056s
ok  	net/textproto	0.048s
ok  	net/url	0.054s
ok  	os	0.368s
ok  	os/exec	0.774s
ok  	os/signal	4.337s
ok  	os/user	0.092s
ok  	path	0.013s
ok  	path/filepath	0.021s
ok  	reflect	0.205s
ok  	regexp	0.162s
ok  	regexp/syntax	0.454s
ok  	runtime	35.817s
ok  	runtime/debug	0.016s
ok  	runtime/internal/atomic	0.159s
ok  	runtime/internal/sys	0.027s
SIGQUIT: quit
PC=0x458ab1 m=0 sigcode=0

goroutine 0 [idle]:
runtime.futex(0x689ed0, 0x0, 0x0, 0x0, 0x7fe500000000, 0xb1c0fe60, 0x0, 0x0, 0x7ffcb1c0fe90, 0x40dd0b, ...)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/runtime/sys_linux_amd64.s:425 +0x21
runtime.futexsleep(0x689ed0, 0x0, 0xffffffffffffffff)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/runtime/os_linux.go:45 +0x62
runtime.notesleep(0x689ed0)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/runtime/lock_futex.go:145 +0x6b
runtime.stopm()
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/runtime/proc.go:1650 +0xad
runtime.findrunnable(0xc420026000, 0x0)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/runtime/proc.go:2102 +0x2e4
runtime.schedule()
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/runtime/proc.go:2222 +0x14c
runtime.park_m(0xc420063a00)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/runtime/proc.go:2285 +0xab
runtime.mcall(0x7ffcb1c10020)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/runtime/asm_amd64.s:269 +0x5b

goroutine 1 [chan receive, 3 minutes]:
testing.(*T).Run(0xc42007e4e0, 0x5b7373, 0x16, 0x5bf630, 0xc420045d01)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/testing/testing.go:698 +0x2f4
testing.runTests.func1(0xc42007e4e0)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/testing/testing.go:882 +0x67
testing.tRunner(0xc42007e4e0, 0xc420045de0)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/testing/testing.go:657 +0x96
testing.runTests(0xc42008c9a0, 0x687100, 0xa, 0xa, 0x7fe5841b2130)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/testing/testing.go:888 +0x2c1
testing.(*M).Run(0xc420045f20, 0xc420045f20)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/testing/testing.go:822 +0xfc
main.main()
	runtime/pprof/_test/_testmain.go:62 +0xf7

goroutine 28 [running]:
	goroutine running on other thread; stack unavailable
created by testing.(*T).Run
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/testing/testing.go:697 +0x2ca

goroutine 12 [syscall]:
runtime.CPUProfile(0x59a560, 0xc4200c6000, 0x689620)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/runtime/cpuprof.go:448 +0x2d
runtime/pprof.profileWriter(0x6703a0, 0xc4200ca000)
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/runtime/pprof/pprof.go:701 +0x63
created by runtime/pprof.StartCPUProfile
	/opt/elasticbeanstalk/auto-udpate-factory/lib/go/src/runtime/pprof/pprof.go:688 +0x122

rax    0xca
rbx    0x0
rcx    0x458ab3
rdx    0x0
rdi    0x689ed0
rsi    0x0
rbp    0x7ffcb1c0fe60
rsp    0x7ffcb1c0fe18
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x42dac0
r13    0x689a60
r14    0x43dc70
r15    0x5f09a0
rip    0x458ab1
rflags 0x286
cs     0x33
fs     0x0
gs     0x0
*** Test killed with quit: ran too long (4m0s).
FAIL	runtime/pprof	240.056s
ok  	runtime/pprof/internal/protopprof	0.026s
ok  	runtime/trace	1.743s
ok  	sort	0.088s
ok  	strconv	0.591s
ok  	strings	0.193s
ok  	sync	0.304s
ok  	sync/atomic	0.074s
ok  	syscall	0.435s
ok  	testing	2.516s
ok  	testing/quick	0.103s
ok  	text/scanner	0.032s
ok  	text/tabwriter	0.018s
ok  	text/template	0.725s
ok  	text/template/parse	0.077s
ok  	time	2.629s
ok  	unicode	0.032s
ok  	unicode/utf16	0.074s
ok  	unicode/utf8	0.075s
ok  	vendor/golang_org/x/crypto/chacha20poly1305	0.063s
ok  	vendor/golang_org/x/crypto/chacha20poly1305/internal/chacha20	0.024s
ok  	vendor/golang_org/x/crypto/curve25519	0.035s
ok  	vendor/golang_org/x/crypto/poly1305	0.026s
ok  	vendor/golang_org/x/net/http2/hpack	0.041s
ok  	vendor/golang_org/x/net/idna	0.030s
ok  	vendor/golang_org/x/net/lex/httplex	0.016s
ok  	cmd/addr2line	0.948s
ok  	cmd/api	0.022s
ok  	cmd/asm/internal/asm	0.342s
ok  	cmd/asm/internal/lex	0.031s
ok  	cmd/compile	5.865s
ok  	cmd/compile/internal/gc	8.994s
ok  	cmd/compile/internal/ssa	0.541s
ok  	cmd/compile/internal/syntax	0.032s
ok  	cmd/compile/internal/test	0.033s [no tests to run]
ok  	cmd/cover	1.879s
ok  	cmd/doc	0.069s
ok  	cmd/fix	0.033s
ok  	cmd/go	65.903s
ok  	cmd/gofmt	0.093s
ok  	cmd/internal/goobj	0.017s
ok  	cmd/internal/obj	0.031s
ok  	cmd/internal/obj/arm64	0.014s
ok  	cmd/internal/obj/x86	0.037s
ok  	cmd/link	5.346s
ok  	cmd/nm	0.956s
ok  	cmd/objdump	2.276s
ok  	cmd/pack	2.405s
ok  	cmd/trace	0.032s
ok  	cmd/vendor/golang.org/x/arch/arm/armasm	0.022s
ok  	cmd/vendor/golang.org/x/arch/ppc64/ppc64asm	0.033s
ok  	cmd/vendor/golang.org/x/arch/x86/x86asm	0.579s
ok  	cmd/vet	3.453s
ok  	cmd/vet/internal/cfg	0.071s
2017/07/24 07:09:36 Failed: exit status 1

@ALTree
Copy link
Member

ALTree commented Jul 24, 2017 •
edited

Tangential, but why are you bootstrapping, exactly? You are on linux/amd64, you should be able to just download the Linux binaries here: https://golang.org/dl/#featured and then follow the instructions here: https://golang.org/doc/install.

If you are in a hurry, I suggest you do that while this issue is being triaged.

@easonyzwang
Copy link
Author

ok, I will turn to featured version, and I think the problem probably is due to Amazon Linux compatibility.

@ianlancetaylor ianlancetaylor modified the milestones: Go1.10, Unplanned Jul 25, 2017
@mvdan
Copy link
Member

mvdan commented Aug 16, 2017

I just ran into this over at https://go-review.googlesource.com/c/54150: https://storage.googleapis.com/go-build-log/d831da99/linux-arm_4aae68c0.log

@rsc
Copy link
Contributor

rsc commented Nov 29, 2017

RHEL 5.x is not supported, so I think we can close this again.

@mvdan it's very unlikely that the arm builder failure is related to the RHEL linux/amd64 failure. Feel free to file a separate issue if you keep seeing this but I'm willing to chalk that up to arm builder flakiness.

@rsc rsc closed this as completed Nov 29, 2017
@golang golang locked and limited conversation to collaborators Nov 29, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge help wanted NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Testing An issue that has been verified to require only test changes, not just a test failure.
Projects
None yet
Milestone
Go1.10
Development

No branches or pull requests
7 participants
@bradfitz @rsc @ianlancetaylor @mvdan @ALTree @gopherbot @easonyzwang