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

cmd/dist: GOMAXPROCS=2 runtime -cpu=1,2,4 -quick makes poor use of CPU resources, increasing all.bat latency #65164

Closed
qiulaidongfeng opened this issue Jan 19, 2024 · 14 comments
Closed

cmd/dist: GOMAXPROCS=2 runtime -cpu=1,2,4 -quick makes poor use of CPU resources, increasing all.bat latency #65164

qiulaidongfeng opened this issue Jan 19, 2024 · 14 comments
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsFix The path to resolution is known, but the work has not been done. Performance Testing An issue that has been verified to require only test changes, not just a test failure.
Milestone
Go1.23

Comments

@qiulaidongfeng
Copy link
Contributor

qiulaidongfeng commented Jan 19, 2024 •
edited

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:

set GO111MODULE=auto
set GOARCH=amd64
set GOBIN=
set GOCACHE=C:\Users\26454\AppData\Local\go-build
set GOENV=C:\Users\26454\AppData\Roaming\go\env
set GOEXE=.exe
set GOEXPERIMENT=
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GOMODCACHE=D:\file\gofile\pkg\mod
set GONOPROXY=
set GONOSUMDB=
set GOOS=windows
set GOPATH=D:\file\gofile
set GOPRIVATE=
set GOPROXY=https://goproxy.cn,direct
set GOROOT=D:\file\gofile\gogit\go1
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLCHAIN=local
set GOTOOLDIR=D:\file\gofile\gogit\go1\pkg\tool\windows_amd64
set GOVCS=
set GOVERSION=devel go1.22-66d34c7d08d Thu Jan 18 19:08:14 2024 +0000
set GCCGO=gccgo
set GOAMD64=v3
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=D:\file\gofile\gogit\go1\src\go.mod
set GOWORK=
set CGO_CFLAGS=-O2 -g
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-O2 -g
set CGO_FFLAGS=-O2 -g
set CGO_LDFLAGS=-O2 -g
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -mthreads -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=D:\tmp\go-build3525285322=/tmp/go-build -gno-record-gcc-switches

What did you do?

in cmd
cd src
all

What did you see happen?

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.223s
ok      archive/zip     0.195s
ok      bufio   0.113s
ok      bytes   0.212s
ok      cmp     0.060s
ok      compress/bzip2  0.120s
ok      compress/flate  0.534s
ok      compress/gzip   1.185s
ok      compress/lzw    0.046s
ok      compress/zlib   0.145s
ok      container/heap  0.061s
ok      container/list  0.052s
ok      container/ring  0.035s
ok      context 0.341s
ok      crypto  0.040s
ok      crypto/aes      0.058s
ok      crypto/cipher   0.056s
ok      crypto/des      0.073s
ok      crypto/dsa      0.082s
ok      crypto/ecdh     0.096s
ok      crypto/ecdsa    0.086s
ok      crypto/ed25519  0.103s
ok      crypto/elliptic 0.048s
ok      crypto/hmac     0.047s
ok      crypto/internal/alias   0.062s
ok      crypto/internal/bigmod  0.098s
ok      crypto/internal/boring  0.033s
ok      crypto/internal/boring/bcache   0.204s
ok      crypto/internal/edwards25519    0.165s
ok      crypto/internal/edwards25519/field      0.063s
ok      crypto/internal/nistec  0.193s
ok      crypto/internal/nistec/fiat     0.062s [no tests to run]
ok      crypto/md5      0.115s
ok      crypto/rand     0.058s
ok      crypto/rc4      0.091s
ok      crypto/rsa      0.529s
ok      crypto/sha1     0.068s
ok      crypto/sha256   0.059s
ok      crypto/sha512   0.059s
ok      crypto/subtle   0.073s
ok      crypto/tls      1.519s
ok      crypto/x509     0.521s
ok      database/sql    0.901s
ok      database/sql/driver     0.057s
ok      debug/buildinfo 0.067s
ok      debug/dwarf     0.152s
ok      debug/elf       0.322s
ok      debug/gosym     0.099s
ok      debug/macho     0.086s
ok      debug/pe        11.081s
ok      debug/plan9obj  0.055s
ok      embed   0.059s [no tests to run]
ok      embed/internal/embedtest        0.054s
ok      encoding/ascii85        0.066s
ok      encoding/asn1   0.078s
ok      encoding/base32 0.148s
ok      encoding/base64 0.026s
ok      encoding/binary 0.053s
ok      encoding/csv    0.056s
ok      encoding/gob    1.765s
ok      encoding/hex    0.050s
ok      encoding/json   0.795s
ok      encoding/pem    1.006s
ok      encoding/xml    0.177s
ok      errors  0.089s
ok      expvar  0.081s
ok      flag    0.209s
ok      fmt     0.068s
ok      go/ast  0.106s
ok      go/build        2.298s
ok      go/build/constraint     0.075s
ok      go/constant     0.053s
ok      go/doc  0.238s
ok      go/doc/comment  2.640s
ok      go/format       0.079s
ok      go/importer     2.139s
ok      go/internal/gccgoimporter       0.085s
ok      go/internal/gcimporter  8.743s
ok      go/internal/srcimporter 28.659s
ok      go/parser       0.322s
ok      go/printer      0.195s
ok      go/scanner      0.025s
ok      go/token        0.035s
ok      go/types        27.728s
ok      go/version      0.067s
ok      hash    0.054s
ok      hash/adler32    0.124s
ok      hash/crc32      0.124s
ok      hash/crc64      0.080s
ok      hash/fnv        0.112s
ok      hash/maphash    0.222s
ok      html    0.124s
ok      html/template   0.167s
ok      image   0.120s
ok      image/color     0.031s
ok      image/draw      0.207s
ok      image/gif       0.418s
ok      image/jpeg      0.272s
ok      image/png       0.314s
ok      index/suffixarray       0.166s
ok      internal/abi    0.342s
ok      internal/buildcfg       0.023s
ok      internal/chacha8rand    0.076s
ok      internal/coverage/cformat       0.045s
ok      internal/coverage/cmerge        0.075s
ok      internal/coverage/pods  0.071s
ok      internal/coverage/slicereader   0.049s
ok      internal/coverage/slicewriter   0.051s
ok      internal/coverage/test  0.105s
ok      internal/cpu    0.067s
ok      internal/dag    0.092s
ok      internal/diff   0.082s
ok      internal/fmtsort        0.067s
ok      internal/fuzz   0.131s
ok      internal/godebug        2.846s
ok      internal/godebugs       0.128s
ok      internal/gover  0.110s
ok      internal/intern 1.865s
ok      internal/itoa   0.105s
ok      internal/platform       2.397s
ok      internal/poll   0.104s
ok      internal/profile        0.032s
ok      internal/reflectlite    0.033s
ok      internal/safefilepath   0.039s
ok      internal/saferio        0.110s
ok      internal/singleflight   0.082s
ok      internal/syscall/windows        0.072s
ok      internal/syscall/windows/registry       0.082s
ok      internal/testenv        1.215s
ok      internal/trace  0.158s
ok      internal/trace/v2       19.417s
ok      internal/types/errors   3.344s
ok      internal/unsafeheader   0.057s
ok      internal/xcoff  0.074s
ok      internal/zstd   0.101s
ok      io      0.395s
ok      io/fs   0.346s
ok      io/ioutil       0.155s
ok      log     0.102s
ok      log/slog        0.171s
ok      log/slog/internal/benchmarks    0.046s
ok      log/slog/internal/buffer        0.064s
ok      maps    0.063s
ok      math    0.032s
ok      math/big        0.963s
ok      math/bits       0.050s
ok      math/cmplx      0.052s
ok      math/rand       0.172s
ok      math/rand/v2    0.296s
ok      mime    0.235s
ok      mime/multipart  1.042s
ok      mime/quotedprintable    0.108s
ok      net     7.234s
ok      net/http        10.291s
ok      net/http/cgi    1.031s
ok      net/http/cookiejar      0.073s
ok      net/http/fcgi   0.274s
ok      net/http/httptest       0.109s
ok      net/http/httptrace      0.066s
ok      net/http/httputil       0.941s
ok      net/http/internal       0.242s
ok      net/http/internal/ascii 0.049s
ok      net/http/pprof  5.506s
ok      net/mail        0.125s
ok      net/netip       1.137s
ok      net/rpc 0.135s
ok      net/rpc/jsonrpc 0.047s
ok      net/smtp        0.078s
ok      net/textproto   0.463s
ok      net/url 0.034s
ok      os      7.472s
ok      os/exec 2.830s
ok      os/exec/internal/fdtest 0.052s
ok      os/signal       3.372s
ok      os/user 0.127s
ok      path    0.050s
ok      path/filepath   1.998s
ok      plugin  0.029s
ok      reflect 0.778s
ok      regexp  0.586s
ok      regexp/syntax   0.829s
ok      runtime 132.949s
ok      runtime/cgo     0.047s
ok      runtime/coverage        0.087s
ok      runtime/debug   0.230s
ok      runtime/internal/atomic 0.116s
ok      runtime/internal/math   0.045s
ok      runtime/internal/sys    0.070s
ok      runtime/internal/wasitest       0.075s
ok      runtime/metrics 0.061s
ok      runtime/pprof   12.095s
ok      runtime/trace   0.273s
ok      slices  0.226s
ok      sort    0.139s
ok      strconv 0.268s
ok      strings 0.201s
ok      sync    0.864s
ok      sync/atomic     2.293s
ok      syscall 7.149s
ok      testing 2.621s
ok      testing/fstest  0.109s
ok      testing/iotest  0.063s
ok      testing/quick   0.111s
ok      testing/slogtest        0.107s
ok      text/scanner    0.062s
ok      text/tabwriter  0.072s
ok      text/template   0.099s
ok      text/template/parse     0.036s
ok      time    2.359s
ok      unicode 0.047s
ok      unicode/utf16   0.026s
ok      unicode/utf8    0.027s
ok      cmd/addr2line   1.486s
ok      cmd/api 27.763s
ok      cmd/asm/internal/asm    0.682s
ok      cmd/asm/internal/lex    0.026s
ok      cmd/cgo/internal/swig   0.120s
ok      cmd/cgo/internal/test   0.596s
ok      cmd/cgo/internal/testcarchive   0.024s
ok      cmd/cgo/internal/testcshared    0.022s
ok      cmd/cgo/internal/testerrors     59.477s
ok      cmd/cgo/internal/testfortran    8.184s
ok      cmd/cgo/internal/testgodefs     3.394s
ok      cmd/cgo/internal/testlife       2.854s
ok      cmd/cgo/internal/testnocgo      0.022s
ok      cmd/cgo/internal/testplugin     0.023s
ok      cmd/cgo/internal/testsanitizers 0.033s [no tests to run]
ok      cmd/cgo/internal/testshared     0.030s
ok      cmd/cgo/internal/testso 6.885s
ok      cmd/cgo/internal/teststdio      7.648s
ok      cmd/cgo/internal/testtls        0.037s
ok      cmd/compile/internal/abt        0.102s
ok      cmd/compile/internal/amd64      0.039s
ok      cmd/compile/internal/base       0.034s
ok      cmd/compile/internal/compare    0.028s
ok      cmd/compile/internal/devirtualize       0.034s
ok      cmd/compile/internal/dwarfgen   1.414s
ok      cmd/compile/internal/importer   6.156s
ok      cmd/compile/internal/inline/inlheur     4.067s
ok      cmd/compile/internal/ir 0.076s
ok      cmd/compile/internal/logopt     1.414s
ok      cmd/compile/internal/loopvar    0.065s
ok      cmd/compile/internal/noder      0.026s
ok      cmd/compile/internal/reflectdata        0.025s [no tests to run]
ok      cmd/compile/internal/ssa        8.101s
ok      cmd/compile/internal/syntax     0.162s
ok      cmd/compile/internal/test       42.529s
ok      cmd/compile/internal/typecheck  2.214s
ok      cmd/compile/internal/types      0.029s
ok      cmd/compile/internal/types2     70.326s
ok      cmd/covdata     0.057s
ok      cmd/cover       18.006s
ok      cmd/dist        0.030s
ok      cmd/distpack    0.025s
ok      cmd/doc 0.310s
ok      cmd/fix 10.618s
ok      cmd/go  78.441s
ok      cmd/go/internal/auth    0.030s
ok      cmd/go/internal/cache   9.036s
ok      cmd/go/internal/cfg     0.222s [no tests to run]
ok      cmd/go/internal/envcmd  0.241s
ok      cmd/go/internal/fsys    2.319s
ok      cmd/go/internal/generate        0.169s
ok      cmd/go/internal/gover   0.058s
ok      cmd/go/internal/imports 0.340s
ok      cmd/go/internal/load    0.085s
ok      cmd/go/internal/lockedfile      0.222s
ok      cmd/go/internal/lockedfile/internal/filelock    0.177s
ok      cmd/go/internal/modfetch        0.173s
ok      cmd/go/internal/modfetch/codehost       24.865s
ok      cmd/go/internal/modfetch/zip_sum_test   0.083s
ok      cmd/go/internal/modindex        6.308s
ok      cmd/go/internal/modload 0.310s
ok      cmd/go/internal/mvs     0.077s
ok      cmd/go/internal/par     0.082s
ok      cmd/go/internal/str     0.228s
ok      cmd/go/internal/test    0.274s
ok      cmd/go/internal/toolchain       0.139s
ok      cmd/go/internal/vcs     0.238s
ok      cmd/go/internal/vcweb   0.434s
ok      cmd/go/internal/vcweb/vcstest   22.691s
ok      cmd/go/internal/web     0.113s
ok      cmd/go/internal/work    0.253s
ok      cmd/gofmt       0.645s
ok      cmd/internal/archive    12.673s
ok      cmd/internal/bootstrap_test     0.071s
ok      cmd/internal/buildid    0.247s
ok      cmd/internal/cov        5.303s
ok      cmd/internal/dwarf      0.068s
ok      cmd/internal/edit       0.065s
ok      cmd/internal/goobj      0.084s
ok      cmd/internal/moddeps    40.009s
ok      cmd/internal/notsha256  0.053s
ok      cmd/internal/obj        3.483s
ok      cmd/internal/obj/ppc64  0.860s
ok      cmd/internal/obj/riscv  0.441s
ok      cmd/internal/obj/s390x  0.051s
ok      cmd/internal/obj/x86    6.738s
ok      cmd/internal/objabi     3.385s
ok      cmd/internal/pkgpath    0.343s
ok      cmd/internal/pkgpattern 0.046s
ok      cmd/internal/quoted     0.064s
ok      cmd/internal/src        0.045s
ok      cmd/internal/test2json  0.186s
ok      cmd/link        35.472s
ok      cmd/link/internal/benchmark     0.086s
ok      cmd/link/internal/ld    28.982s
ok      cmd/link/internal/loader        0.073s
ok      cmd/nm  9.871s
ok      cmd/objdump     25.447s
ok      cmd/pack        7.744s
ok      cmd/pprof       6.090s
ok      cmd/trace       0.053s
ok      cmd/trace/v2    0.094s
ok      cmd/vet 20.430s

##### os/user with tag osusergo
ok      os/user 0.023s

##### hash/maphash purego implementation
ok      hash/maphash    0.065s

##### GOMAXPROCS=2 runtime -cpu=1,2,4 -quick
ok      runtime 177.829s

##### GOEXPERIMENT=rangefunc go test iter
ok      iter    0.012s

##### Testing without libgcc.
ok      net     0.061s
ok      os/user 0.020s

##### internal linking of -buildmode=pie
ok      reflect 0.089s
ok      os/user 0.036s

##### sync -cpu=10
ok      sync    0.761s

##### Testing race detector
ok      runtime/race    12.048s
ok      flag    1.047s
ok      net     1.082s
ok      os      1.130s
ok      os/exec 2.117s
ok      encoding/gob    1.058s
ok      flag    1.041s
ok      os/exec 2.116s

##### Testing cgo
ok      cmd/cgo/internal/test   0.217s
ok      cmd/cgo/internal/test   0.264s
ok      cmd/cgo/internal/test   0.253s
ok      cmd/cgo/internal/test   0.245s
ok      cmd/cgo/internal/test   0.236s

##### ../test
ok      cmd/internal/testdir    48.931s

##### API check
ok      cmd/api 54.223s

ALL TESTS PASSED
---
Installed Go for windows/amd64 in D:\file\gofile\gogit\go1
Installed commands in D:\file\gofile\gogit\go1\bin
*** You need to add D:\file\gofile\gogit\go1\bin to your PATH.

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.
@gopherbot gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Jan 19, 2024
@cagedmantis cagedmantis added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jan 19, 2024
@cagedmantis cagedmantis added this to the Backlog milestone Jan 19, 2024
@cagedmantis
Copy link
Contributor

@golang/runtime

@bcmills
Copy link
Contributor

bcmills commented Jan 19, 2024

See also:

@qiulaidongfeng
Copy link
Contributor Author

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 don't know if the speed of running all.bat should be changed to a few minutes now. Because this is the 2018 #26473 (comment)

@qiulaidongfeng
Copy link
Contributor Author

I looked into the problem today.
After shutting down my laptop for one night, I started all.bat during the day. I closed the browser and other user software that would be opened during normal development, and it took me 5 minutes and 59 seconds to run all.bat
I looked at the task manager the whole time and noticed that ntoskrnl.exe had around 10% CPU usage more than half the time.
The output this time is as follows:

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
hash/maphash purego implementation

ok hash/maphash 0.044s

GOMAXPROCS=2 runtime -cpu=1,2,4 -quick

ok runtime 143.107s

GOEXPERIMENT=rangefunc go test iter

ok iter 0.017s

Testing without libgcc.

ok net 0.043s
ok os/user 0.029s

internal linking of -buildmode=pie

ok reflect 0.090s
ok os/user 0.022s

sync -cpu=10

ok sync 0.715s

Testing race detector

ok runtime/race 11.015s
ok flag 1.041s
ok net 1.074s
ok os 1.135s
ok os/exec 2.074s
ok encoding/gob 1.052s
ok flag 1.035s
ok os/exec 2.076s

Testing cgo

ok cmd/cgo/internal/test 0.220s
ok cmd/cgo/internal/test 0.354s
ok cmd/cgo/internal/test 0.363s
ok cmd/cgo/internal/test 0.365s
ok cmd/cgo/internal/test 0.251s

../test

ok cmd/internal/testdir 46.913s

API check

ok cmd/api 51.461s

ALL TESTS PASSED

Installed Go for windows/amd64 in D:\file\gofile\gogit\go1
Installed commands in D:\file\gofile\gogit\go1\bin
*** You need to add D:\file\gofile\gogit\go1\bin to your PATH.

It seems like it's really hard to get windows to run all.bat without running other CPU-heavy processes.
This time I was 100% sure that no antivirus software or browser processes were running, but I did see the windows Update process (I clearly clicked the pause for update for 1 week).

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.

  1. Let GOMAXPROCS=2 runtime -cpu=1,2,4 -quick not prevent other package tests
  2. GOMAXPROCS=2 runtime -cpu=1,2,4 when running, it makes better use of the CPU

@mknyszek
Copy link
Contributor

In triage, we think this seems like this issue is more for cmd/dist and/or build. We could possibly make the runtime tests faster, as this step is running the runtime tests 3 times.

@mknyszek mknyszek changed the title runtime: GOMAXPROCS=2 runtime -cpu=1,2,4 -quick in all.bat , it CPU usage is low and no other packages are being test at the same time cmd/dist: GOMAXPROCS=2 runtime -cpu=1,2,4 -quick makes poor use of CPU resources, increasing all.bat latency Jan 24, 2024
@prattmic
Copy link
Member

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.

@qiulaidongfeng
Copy link
Contributor Author

qiulaidongfeng commented Jan 25, 2024 •
edited

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.
I saw some promotional video material, its multi-core performance is second only to the most powerful notebook computer CPU today, the Ultra 7 165H.
When I test, the minimum CPU frequency of the notebook computer was about 3.8Ghz.
And the CPU usage is 2-4% most of the time.

The most important thing is

Now 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.
It seems that this test is particularly slow on windows

@qiulaidongfeng
Copy link
Contributor Author

@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.

@qiulaidongfeng
Copy link
Contributor Author

qiulaidongfeng commented Jan 27, 2024 •
edited

in wsl2

##### GOMAXPROCS=2 runtime -cpu=1,2,4 -quick
ok      runtime 27.396s

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.

cc @golang/runtime

@qiulaidongfeng
Copy link
Contributor Author

qiulaidongfeng commented Jan 31, 2024 •
edited

In the github codespace
2-core linux

##### GOMAXPROCS=2 runtime -cpu=1,2,4 -quick
ok      runtime 35.445s

@qiulaidongfeng
Copy link
Contributor Author

After In triage
Discovering new information, this test is significantly slower at windos than linux.
cc @golang/runtime

qiulaidongfeng added a commit to qiulaidongfeng/go that referenced this issue Feb 2, 2024
@qiulaidongfeng
cmd/dist: let the three runtime -quick tests run simultaneously
68b204a 
For golang#65164

Change-Id: Id797a402fffd70643ebaae74f4450dacfa2b6dd3
@qiulaidongfeng qiulaidongfeng mentioned this issue Feb 2, 2024
Closed
@gopherbot
Copy link

Change https://go.dev/cl/560597 mentions this issue: cmd/dist: let the three runtime -quick tests run simultaneously

qiulaidongfeng added a commit to qiulaidongfeng/go that referenced this issue Feb 2, 2024
@qiulaidongfeng
cmd/dist: let the three runtime -quick tests run simultaneously
78be88c 
For golang#65164

Change-Id: Id797a402fffd70643ebaae74f4450dacfa2b6dd3
@qiulaidongfeng
Copy link
Contributor Author

After use https://go.dev/cl/560597 , this test is faster because three runtime.test.exe are running simultaneously.
But it still prevents other tests from running at the same time, resulting in low CPU utilization and slowing all.bat

qiulaidongfeng added a commit to qiulaidongfeng/go that referenced this issue Feb 14, 2024
@qiulaidongfeng
cmd/dist: increase test parallelism starting with GOMAXPROCS=2 runtime
5624a70 
Fixes golang#65164

Change-Id: Ia10952f50a3c2a7868e30dcdba333927947b3ac3
@qiulaidongfeng qiulaidongfeng mentioned this issue Feb 14, 2024
Closed
@gopherbot
Copy link

Change https://go.dev/cl/563916 mentions this issue: cmd/dist: increase test parallelism starting with GOMAXPROCS=2 runtime

qiulaidongfeng added a commit to qiulaidongfeng/go that referenced this issue Feb 14, 2024
@qiulaidongfeng
cmd/dist: increase test parallelism starting with GOMAXPROCS=2 runtime
cc5f615 
Fixes golang#65164

Change-Id: Ia10952f50a3c2a7868e30dcdba333927947b3ac3
gopherbot pushed a commit that referenced this issue Feb 28, 2024
@qiulaidongfeng @gopherbot
cmd/dist: let the three runtime -quick tests run simultaneously
1571c0b 
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 <iant@golang.org>
Reviewed-by: Keith Randall <khr@golang.org>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Reviewed-by: Keith Randall <khr@google.com>
Reviewed-by: Than McIntosh <thanm@google.com>
Auto-Submit: Ian Lance Taylor <iant@golang.org>
qiulaidongfeng added a commit to qiulaidongfeng/go that referenced this issue Mar 13, 2024
@qiulaidongfeng
cmd/dist: increase test parallelism starting with GOMAXPROCS=2 runtime
2049e17 
Fixes golang#65164

Change-Id: Ia10952f50a3c2a7868e30dcdba333927947b3ac3
qiulaidongfeng added a commit to qiulaidongfeng/go that referenced this issue Mar 16, 2024
@qiulaidongfeng
cmd/dist: increase test parallelism starting with GOMAXPROCS=2 runtime
12cfb00 
Fixes golang#65164

Change-Id: Ia10952f50a3c2a7868e30dcdba333927947b3ac3
@dmitshur dmitshur removed this from the Backlog milestone Mar 23, 2024
@dmitshur dmitshur added this to the Go1.23 milestone Mar 23, 2024
@dmitshur dmitshur added NeedsFix The path to resolution is known, but the work has not been done. Performance Testing An issue that has been verified to require only test changes, not just a test failure. and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Mar 23, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsFix The path to resolution is known, but the work has not been done. Performance Testing An issue that has been verified to require only test changes, not just a test failure.
Projects
Go Compiler / Runtime
Status: Done
Milestone
Go1.23
Development

Successfully merging a pull request may close this issue.

cmd/dist: avoid CPU underutilization starting from GOMAXPROCS=2 runtime qiulaidongfeng/go
7 participants
@cagedmantis @mknyszek @prattmic @dmitshur @bcmills @gopherbot @qiulaidongfeng