From 6dbcc8b8651909442ff823231daba096f447a163 Mon Sep 17 00:00:00 2001 From: "Bryan C. Mills" Date: Tue, 7 Jan 2020 15:33:08 -0500 Subject: [PATCH] cmd/go: make "finding" logging deterministic MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit In CL 204777, I made the "finding" messages in cachingRepo only print after a “longish” delay, on the theory that they would help diagnose slow or stuck fetches. However, as I've been testing Go 1.14 beta 1, I've found that these messages are mostly just noise, and the fact that they are so nondeterministic causes both confusion and test flakes (#35539). Moreover, it currently triggers once for each candidate module, when what we're usually after is actually a specific package within the module. So let's log the package operation unconditionally instead of the module fetches nondeterministically. Fixes #35539 Updates #26152 Change-Id: I41a1c772465b2f0b357d3402bc372b6907773741 Reviewed-on: https://go-review.googlesource.com/c/go/+/213679 Run-TryBot: Bryan C. Mills TryBot-Result: Gobot Gobot Reviewed-by: Jay Conrod --- src/cmd/go/internal/modfetch/cache.go | 18 ------------------ src/cmd/go/internal/modload/import.go | 2 ++ .../go/testdata/script/mod_load_badchain.txt | 2 ++ 3 files changed, 4 insertions(+), 18 deletions(-) diff --git a/src/cmd/go/internal/modfetch/cache.go b/src/cmd/go/internal/modfetch/cache.go index 104fce86dda91b..947192bd83ee38 100644 --- a/src/cmd/go/internal/modfetch/cache.go +++ b/src/cmd/go/internal/modfetch/cache.go @@ -13,7 +13,6 @@ import ( "os" "path/filepath" "strings" - "time" "cmd/go/internal/base" "cmd/go/internal/cfg" @@ -28,8 +27,6 @@ import ( var PkgMod string // $GOPATH/pkg/mod; set by package modload -const logFindingDelay = 1 * time.Second - func cacheDir(path string) (string, error) { if PkgMod == "" { return "", fmt.Errorf("internal error: modfetch.PkgMod not set") @@ -140,11 +137,6 @@ func (r *cachingRepo) Versions(prefix string) ([]string, error) { err error } c := r.cache.Do("versions:"+prefix, func() interface{} { - logTimer := time.AfterFunc(logFindingDelay, func() { - fmt.Fprintf(os.Stderr, "go: finding versions for %s\n", r.path) - }) - defer logTimer.Stop() - list, err := r.r.Versions(prefix) return cached{list, err} }).(cached) @@ -167,11 +159,6 @@ func (r *cachingRepo) Stat(rev string) (*RevInfo, error) { return cachedInfo{info, nil} } - logTimer := time.AfterFunc(logFindingDelay, func() { - fmt.Fprintf(os.Stderr, "go: finding %s %s\n", r.path, rev) - }) - defer logTimer.Stop() - info, err = r.r.Stat(rev) if err == nil { // If we resolved, say, 1234abcde to v0.0.0-20180604122334-1234abcdef78, @@ -199,11 +186,6 @@ func (r *cachingRepo) Stat(rev string) (*RevInfo, error) { func (r *cachingRepo) Latest() (*RevInfo, error) { c := r.cache.Do("latest:", func() interface{} { - logTimer := time.AfterFunc(logFindingDelay, func() { - fmt.Fprintf(os.Stderr, "go: finding %s latest\n", r.path) - }) - defer logTimer.Stop() - info, err := r.r.Latest() // Save info for likely future Stat call. diff --git a/src/cmd/go/internal/modload/import.go b/src/cmd/go/internal/modload/import.go index 3170ffab8897fe..5906d648b49afd 100644 --- a/src/cmd/go/internal/modload/import.go +++ b/src/cmd/go/internal/modload/import.go @@ -269,6 +269,8 @@ func Import(path string) (m module.Version, dir string, err error) { return module.Version{}, "", &ImportMissingError{Path: path} } + fmt.Fprintf(os.Stderr, "go: finding module for package %s\n", path) + candidates, err := QueryPackage(path, "latest", Allowed) if err != nil { if errors.Is(err, os.ErrNotExist) { diff --git a/src/cmd/go/testdata/script/mod_load_badchain.txt b/src/cmd/go/testdata/script/mod_load_badchain.txt index 2c532f1fda33a6..67d9a1584f51f8 100644 --- a/src/cmd/go/testdata/script/mod_load_badchain.txt +++ b/src/cmd/go/testdata/script/mod_load_badchain.txt @@ -75,12 +75,14 @@ go: example.com/badchain/a@v1.1.0 requires module declares its path as: badchain.example.com/c but was required as: example.com/badchain/c -- list-missing-expected -- +go: finding module for package example.com/badchain/c go: found example.com/badchain/c in example.com/badchain/c v1.1.0 go: m/use imports example.com/badchain/c: example.com/badchain/c@v1.1.0: parsing go.mod: module declares its path as: badchain.example.com/c but was required as: example.com/badchain/c -- list-missing-test-expected -- +go: finding module for package example.com/badchain/c go: found example.com/badchain/c in example.com/badchain/c v1.1.0 go: m/testuse tested by m/testuse.test imports