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

cmd/go: VCS stamping is slow #49582

Closed
dominikh opened this issue Nov 14, 2021 · 5 comments
Closed

cmd/go: VCS stamping is slow #49582

dominikh opened this issue Nov 14, 2021 · 5 comments
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. release-blocker ToolSpeed
Milestone

Comments

@dominikh
Copy link
Member

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

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/dominikh/.cache/go-build"
GOENV="/home/dominikh/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/dominikh/prj/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/dominikh/prj"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/dominikh/prj/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/dominikh/prj/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="devel go1.18-c49627e81b Thu Nov 11 11:47:33 2021 +0000"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/dev/null"
GOWORK=""
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-build2629688203=/tmp/go-build -gno-record-gcc-switches"

What did you do?

$ git clone https://github.com/kubernetes/kubernetes
$ cd kubernetes

# Go 1.17
$ time go list ./...
go list ./...  5.45s user 0.60s system 414% cpu 1.459 total

# a37bebc042672d20837ea348d45e39740568cb77
$ time go list ./...
go list ./...  6.42s user 3.52s system 253% cpu 3.924 total

# 76cef81bcff371c88d277f17c712ecf22b8c83e7
$ time go list ./...
go list ./...  9.13s user 3.96s system 196% cpu 6.665 total

The two commits were found via bisection and make up for virtually all of the increase in runtime. The underlying storage is fast NVMe, which makes the slowdown more impressive, even for a repository the size of Kubernetes.

/cc @jayconrod @bcmills

@dominikh dominikh added this to the Go1.18 milestone Nov 14, 2021
@seankhliao
Copy link
Member

cc @matloob

@seankhliao seankhliao added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Nov 14, 2021
@mvdan
Copy link
Member

mvdan commented Nov 15, 2021

I can reproduce; the problem seems to be that we run two git commands to get the build information for every package:

$ go list -x ./... |& grep '^git' | sort | uniq -c
     51 git show -s --format=%H:%ct
     51 git status --porcelain

We're not even running those commands in different directories:

$ go list -x ./...
cd /home/mvdan/git/kubernetes
git status --porcelain
cd /home/mvdan/git/kubernetes
git show -s --format=%H:%ct
cd /home/mvdan/git/kubernetes
git status --porcelain
cd /home/mvdan/git/kubernetes
git show -s --format=%H:%ct
cd /home/mvdan/git/kubernetes
git status --porcelain
[...]

The fix seems relatively simple: within a single build, if we've already queried the VCS information for a VCS root directory, cache that and avoid querying it again.

@dominikh
Copy link
Member Author

Indeed, these seem to account for the entire slowdown:

( repeat 51; do; git show -s --format=%H:%ct; git status --porcelain; done; )  3.64s user 2.98s system 131% cpu 5.022 total

@bcmills bcmills self-assigned this Nov 15, 2021
@bcmills
Copy link
Member

bcmills commented Nov 15, 2021

At least suppressing the repeated calls should be an easy fix.

(This also looks like another case where #29666 would really help.)

@bcmills bcmills added the NeedsFix The path to resolution is known, but the work has not been done. label Nov 15, 2021
@gopherbot gopherbot removed the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Nov 15, 2021
@gopherbot
Copy link

Change https://golang.org/cl/365394 mentions this issue: cmd/go: work out VCS information once per repository

@rsc rsc unassigned bcmills Jun 23, 2022
@golang golang locked and limited conversation to collaborators Jun 23, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. release-blocker ToolSpeed
Projects
None yet
Development

No branches or pull requests

5 participants