-
Notifications
You must be signed in to change notification settings - Fork 18k
cmd/dist: GOMAXPROCS=2 runtime -cpu=1,2,4 -quick
makes poor use of CPU resources, increasing all.bat
latency
#65164
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
Comments
See also: It's kind of related. I'm under the impression that all.bash and all.bat implement the same functionality, so their speed goals probably shouldn't be different depending on the system Fixing this should change the speed of running all.bat on my windows laptop to about 8 minutes. |
I looked into the problem today.
Building Go cmd/dist using C:\Users\26454\.go\current. (devel go1.22-b2dbfbfc Fri Jan 12 00:56:20 2024 +0000 windows/amd64)
Building Go toolchain1 using C:\Users\26454\.go\current.
Building Go bootstrap cmd/go (go_bootstrap) using Go toolchain1.
Building Go toolchain2 using go_bootstrap and Go toolchain1.
Building Go toolchain3 using go_bootstrap and Go toolchain2.
Building packages and commands for windows/amd64.
##### Test execution environment.
# GOARCH: amd64
# CPU: AMD Ryzen 7 7840HS w/ Radeon 780M Graphics
# GOOS: windows
# OS Version: 10.0.22631
##### Testing packages.
ok archive/tar 0.147s
ok archive/zip 0.157s
ok bufio 0.063s
ok bytes 0.158s
ok cmp 0.021s
ok compress/bzip2 0.080s
ok compress/flate 0.564s
ok compress/gzip 0.936s
ok compress/lzw 0.025s
ok compress/zlib 0.050s
ok container/heap 0.024s
ok container/list 0.027s
ok container/ring 0.024s
ok context 0.302s
ok crypto 0.022s
ok crypto/aes 0.033s
ok crypto/cipher 0.029s
ok crypto/des 0.024s
ok crypto/dsa 0.023s
ok crypto/ecdh 0.051s
ok crypto/ecdsa 0.052s
ok crypto/ed25519 0.066s
ok crypto/elliptic 0.037s
ok crypto/hmac 0.024s
ok crypto/internal/alias 0.024s
ok crypto/internal/bigmod 0.067s
ok crypto/internal/boring 0.026s
ok crypto/internal/boring/bcache 0.099s
ok crypto/internal/edwards25519 0.081s
ok crypto/internal/edwards25519/field 0.032s
ok crypto/internal/nistec 0.123s
ok crypto/internal/nistec/fiat 0.023s [no tests to run]
ok crypto/md5 0.034s
ok crypto/rand 0.041s
ok crypto/rc4 0.043s
ok crypto/rsa 0.218s
ok crypto/sha1 0.028s
ok crypto/sha256 0.026s
ok crypto/sha512 0.027s
ok crypto/subtle 0.075s
ok crypto/tls 0.659s
ok crypto/x509 0.308s
ok database/sql 0.692s
ok database/sql/driver 0.022s
ok debug/buildinfo 0.027s
ok debug/dwarf 0.047s
ok debug/elf 0.138s
ok debug/gosym 0.064s
ok debug/macho 0.027s
ok debug/pe 9.161s
ok debug/plan9obj 0.024s
ok embed 0.022s [no tests to run]
ok embed/internal/embedtest 0.025s
ok encoding/ascii85 0.023s
ok encoding/asn1 0.045s
ok encoding/base32 0.034s
ok encoding/base64 0.024s
ok encoding/binary 0.027s
ok encoding/csv 0.031s
ok encoding/gob 1.098s
ok encoding/hex 0.037s
ok encoding/json 0.290s
ok encoding/pem 0.510s
ok encoding/xml 0.183s
ok errors 0.070s
ok expvar 0.072s
ok flag 0.166s
ok fmt 0.119s
ok go/ast 0.045s
ok go/build 1.917s
ok go/build/constraint 0.027s
ok go/constant 0.030s
ok go/doc 0.088s
ok go/doc/comment 1.712s
ok go/format 0.032s
ok go/importer 1.404s
ok go/internal/gccgoimporter 0.076s
ok go/internal/gcimporter 8.320s
ok go/internal/srcimporter 41.852s
ok go/parser 0.288s
ok go/printer 0.178s
ok go/scanner 0.038s
ok go/token 0.042s
ok go/types 58.111s
ok go/version 0.095s
ok hash 0.091s
ok hash/adler32 0.086s
ok hash/crc32 0.090s
ok hash/crc64 0.085s
ok hash/fnv 0.037s
ok hash/maphash 0.115s
ok html 0.028s
ok html/template 0.105s
ok image 0.080s
ok image/color 0.041s
ok image/draw 0.089s
ok image/gif 0.145s
ok image/jpeg 0.154s
ok image/png 0.272s
ok index/suffixarray 0.208s
ok internal/abi 0.356s
ok internal/buildcfg 0.027s
ok internal/chacha8rand 0.079s
ok internal/coverage/cformat 0.059s
ok internal/coverage/cmerge 0.025s
ok internal/coverage/pods 0.035s
ok internal/coverage/slicereader 0.023s
ok internal/coverage/slicewriter 0.078s
ok internal/coverage/test 0.032s
ok internal/cpu 0.025s
ok internal/dag 0.021s
ok internal/diff 0.025s
ok internal/fmtsort 0.023s
ok internal/fuzz 0.030s
ok internal/godebug 1.788s
ok internal/godebugs 0.023s
ok internal/gover 0.028s
ok internal/intern 0.226s
ok internal/itoa 0.024s
ok internal/platform 0.880s
ok internal/poll 0.052s
ok internal/profile 0.034s
ok internal/reflectlite 0.034s
ok internal/safefilepath 0.040s
ok internal/saferio 0.081s
ok internal/singleflight 0.055s
ok internal/syscall/windows 0.068s
ok internal/syscall/windows/registry 0.065s
ok internal/testenv 0.737s
ok internal/trace 0.078s
ok internal/trace/v2 11.501s
ok internal/types/errors 1.936s
ok internal/unsafeheader 0.023s
ok internal/xcoff 0.039s
ok internal/zstd 0.109s
ok io 0.230s
ok io/fs 0.221s
ok io/ioutil 0.032s
ok log 0.056s
ok log/slog 0.097s
ok log/slog/internal/benchmarks 0.048s
ok log/slog/internal/buffer 0.023s
ok maps 0.021s
ok math 0.047s
ok math/big 0.795s
ok math/bits 0.034s
ok math/cmplx 0.035s
ok math/rand 0.115s
ok math/rand/v2 0.247s
ok mime 0.211s
ok mime/multipart 0.800s
ok mime/quotedprintable 0.116s
ok net 6.742s
ok net/http 3.552s
ok net/http/cgi 0.552s
ok net/http/cookiejar 0.030s
ok net/http/fcgi 0.243s
ok net/http/httptest 0.065s
ok net/http/httptrace 0.025s
ok net/http/httputil 0.719s
ok net/http/internal 0.171s
ok net/http/internal/ascii 0.032s
ok net/http/pprof 5.185s
ok net/mail 0.050s
ok net/netip 0.442s
ok net/rpc 0.084s
ok net/rpc/jsonrpc 0.033s
ok net/smtp 0.040s
ok net/textproto 0.161s
ok net/url 0.027s
ok os 4.926s
ok os/exec 2.254s
ok os/exec/internal/fdtest 0.023s
ok os/signal 2.369s
ok os/user 0.042s
ok path 0.024s
ok path/filepath 1.306s
ok plugin 0.085s
ok reflect 0.448s
ok regexp 0.486s
ok regexp/syntax 0.748s
ok runtime 87.763s
ok runtime/cgo 0.040s
ok runtime/coverage 0.100s
ok runtime/debug 0.224s
ok runtime/internal/atomic 0.127s
ok runtime/internal/math 0.083s
ok runtime/internal/sys 0.057s
ok runtime/internal/wasitest 0.031s
ok runtime/metrics 0.030s
ok runtime/pprof 12.839s
ok runtime/trace 0.229s
ok slices 0.090s
ok sort 0.056s
ok strconv 0.235s
ok strings 0.087s
ok sync 0.863s
ok sync/atomic 1.926s
ok syscall 6.955s
ok testing 2.182s
ok testing/fstest 0.136s
ok testing/iotest 0.122s
ok testing/quick 0.123s
ok testing/slogtest 0.066s
ok text/scanner 0.041s
ok text/tabwriter 0.031s
ok text/template 0.051s
ok text/template/parse 0.025s
ok time 2.273s
ok unicode 0.031s
ok unicode/utf16 0.025s
ok unicode/utf8 0.023s
ok cmd/addr2line 1.399s
ok cmd/api 88.753s
ok cmd/asm/internal/asm 0.578s
ok cmd/asm/internal/lex 0.034s
ok cmd/cgo/internal/swig 0.159s
ok cmd/cgo/internal/test 0.400s
ok cmd/cgo/internal/testcarchive 0.032s
ok cmd/cgo/internal/testcshared 0.026s
ok cmd/cgo/internal/testerrors 42.482s
ok cmd/cgo/internal/testfortran 2.067s
ok cmd/cgo/internal/testgodefs 3.612s
ok cmd/cgo/internal/testlife 3.058s
ok cmd/cgo/internal/testnocgo 0.028s
ok cmd/cgo/internal/testplugin 0.024s
ok cmd/cgo/internal/testsanitizers 0.022s [no tests to run]
ok cmd/cgo/internal/testshared 0.089s
ok cmd/cgo/internal/testso 8.302s
ok cmd/cgo/internal/teststdio 11.616s
ok cmd/cgo/internal/testtls 0.028s
ok cmd/compile/internal/abt 0.023s
ok cmd/compile/internal/amd64 0.028s
ok cmd/compile/internal/base 0.023s
ok cmd/compile/internal/compare 0.026s
ok cmd/compile/internal/devirtualize 0.024s
ok cmd/compile/internal/dwarfgen 0.891s
ok cmd/compile/internal/importer 16.907s
ok cmd/compile/internal/inline/inlheur 2.735s
ok cmd/compile/internal/ir 0.030s
ok cmd/compile/internal/logopt 1.280s
ok cmd/compile/internal/loopvar 0.039s
ok cmd/compile/internal/noder 0.028s
ok cmd/compile/internal/reflectdata 0.025s [no tests to run]
ok cmd/compile/internal/ssa 4.930s
ok cmd/compile/internal/syntax 0.176s
ok cmd/compile/internal/test 23.460s
ok cmd/compile/internal/typecheck 1.413s
ok cmd/compile/internal/types 0.031s
ok cmd/compile/internal/types2 72.025s
ok cmd/covdata 0.112s
ok cmd/cover 10.790s
ok cmd/dist 0.041s
ok cmd/distpack 0.049s
ok cmd/doc 0.622s
ok cmd/fix 7.509s
ok cmd/go 76.559s
ok cmd/go/internal/auth 0.073s
ok cmd/go/internal/cache 3.614s
ok cmd/go/internal/cfg 0.033s [no tests to run]
ok cmd/go/internal/envcmd 0.178s
ok cmd/go/internal/fsys 2.015s
ok cmd/go/internal/generate 0.093s
ok cmd/go/internal/gover 0.084s
ok cmd/go/internal/imports 0.187s
ok cmd/go/internal/load 0.048s
ok cmd/go/internal/lockedfile 0.243s
ok cmd/go/internal/lockedfile/internal/filelock 0.226s
ok cmd/go/internal/modfetch 0.121s
ok cmd/go/internal/modfetch/codehost 20.148s
ok cmd/go/internal/modfetch/zip_sum_test 0.069s
ok cmd/go/internal/modindex 1.432s
ok cmd/go/internal/modload 0.068s
ok cmd/go/internal/mvs 0.046s
ok cmd/go/internal/par 0.071s
ok cmd/go/internal/str 0.046s
ok cmd/go/internal/test 0.161s
ok cmd/go/internal/toolchain 0.084s
ok cmd/go/internal/vcs 0.130s
ok cmd/go/internal/vcweb 0.137s
ok cmd/go/internal/vcweb/vcstest 17.711s
ok cmd/go/internal/web 0.097s
ok cmd/go/internal/work 0.203s
ok cmd/gofmt 0.416s
ok cmd/internal/archive 9.679s
ok cmd/internal/bootstrap_test 0.065s
ok cmd/internal/buildid 0.236s
ok cmd/internal/cov 4.735s
ok cmd/internal/dwarf 0.075s
ok cmd/internal/edit 0.069s
ok cmd/internal/goobj 0.075s
ok cmd/internal/moddeps 29.660s
ok cmd/internal/notsha256 0.059s
ok cmd/internal/obj 3.277s
ok cmd/internal/obj/ppc64 0.750s
ok cmd/internal/obj/riscv 0.380s
ok cmd/internal/obj/s390x 0.032s
ok cmd/internal/obj/x86 2.984s
ok cmd/internal/objabi 4.126s
ok cmd/internal/pkgpath 0.167s
ok cmd/internal/pkgpattern 0.039s
ok cmd/internal/quoted 0.039s
ok cmd/internal/src 0.060s
ok cmd/internal/test2json 0.163s
ok cmd/link 26.557s
ok cmd/link/internal/benchmark 0.087s
ok cmd/link/internal/ld 20.857s
ok cmd/link/internal/loader 0.052s
ok cmd/nm 7.886s
ok cmd/objdump 17.046s
ok cmd/pack 6.513s
ok cmd/pprof 5.395s
ok cmd/trace 0.050s
ok cmd/trace/v2 0.088s
ok cmd/vet 10.690s
##### os/user with tag osusergo
ok os/user 0.019s
It seems like it's really hard to get windows to run all.bat without running other CPU-heavy processes. But this time the output is still GOMAXPROCS=2 runtime -cpu=1,2,4 -quick took more than two minutes. It CPU usage is low and no other packages are being test at the same time. This means that if this test does not prevent other package tests, and it itself uses the CPU more efficiently, it is possible that contributors could run all.bat on windows in more than 5 minutes or less. It seems there are two things to be done here.
|
In triage, we think this seems like this issue is more for |
GOMAXPROCS=2 runtime -cpu=1,2,4 -quick
makes poor use of CPU resources, increasing all.bat
latency
FWIW this test takes ~25s on my machine (linux-amd64, 12 cores). I wonder whether I just have a faster machine, or the tests are particularly slow on Windows. |
The R7 7840hs is now amd's strongest CPU in the notebook computer market. The most important thing isNow this test does not take advantage of multi-core on windows. This means that now this test which CPU single-core performance is stronger, which test finished faster. |
@prattmic What is the CPU usage rate of this test on your machine? Is it like on my Windows machine that most of the time is 2-4%? If the CPU usage is also the same, it indicates that this test is really running particularly slow on Windows. |
in wsl2
When this test was run on the same laptop I had, it was much slower in windows (2+ minutes) than wsl2 (20+ seconds), and I determined through Task Manager that it wasn't antivirus or other software effects that were causing it, it didn't seem to be just a cmd/dist issue. |
In the github codespace
|
After In triage |
For golang#65164 Change-Id: Id797a402fffd70643ebaae74f4450dacfa2b6dd3
Change https://go.dev/cl/560597 mentions this issue: |
For golang#65164 Change-Id: Id797a402fffd70643ebaae74f4450dacfa2b6dd3
After use https://go.dev/cl/560597 , this test is faster because three runtime.test.exe are running simultaneously. |
Fixes golang#65164 Change-Id: Ia10952f50a3c2a7868e30dcdba333927947b3ac3
Change https://go.dev/cl/563916 mentions this issue: |
Fixes golang#65164 Change-Id: Ia10952f50a3c2a7868e30dcdba333927947b3ac3
For #65164 Change-Id: Ied19cebd113ef91c34f613cafbeb92a335d6420d GitHub-Last-Rev: 8118be6 GitHub-Pull-Request: #65444 Reviewed-on: https://go-review.googlesource.com/c/go/+/560597 Commit-Queue: Ian Lance Taylor <[email protected]> Reviewed-by: Keith Randall <[email protected]> LUCI-TryBot-Result: Go LUCI <[email protected]> Reviewed-by: Keith Randall <[email protected]> Reviewed-by: Than McIntosh <[email protected]> Auto-Submit: Ian Lance Taylor <[email protected]>
Fixes golang#65164 Change-Id: Ia10952f50a3c2a7868e30dcdba333927947b3ac3
Fixes golang#65164 Change-Id: Ia10952f50a3c2a7868e30dcdba333927947b3ac3
Go version
go version devel go1.22-66d34c7d08d Thu Jan 18 19:08:14 2024 +0000 windows/amd64
Output of
go env
in your module/workspace:What did you do?
in cmd
cd src
all
What did you see happen?
Running all.bat took 8 minutes and 41 seconds.
What did you expect to see?
GOMAXPROCS=2 runtime -cpu=1,2,4 -quick
I hope this doesn't cause all.bat to run only one runtime package test on the CPU for close to three minutes, and the CPU usage is very low (2-4% most of the time) and only changes to around 20% when using the C toolchain.
The text was updated successfully, but these errors were encountered: