From 822dca4b383611335385ef05c2882d23f6f89d88 Mon Sep 17 00:00:00 2001 From: Michael Matloob Date: Wed, 15 Jul 2020 17:38:36 -0400 Subject: [PATCH] cmd/go: add tracing for querying and downloading from the proxy This CL adds tracing spans for modload.queryPattern, modload.queryProxy, modload.QueryPattern, modload.QueryPattern.queryModule, modload.queryPrefixModules and modfetch.Download. Updates #38714 Change-Id: I91af3f022a6e18ab8d9c1d9b0ccf4928b6c236bd Reviewed-on: https://go-review.googlesource.com/c/go/+/249022 Run-TryBot: Michael Matloob TryBot-Result: Gobot Gobot Reviewed-by: Jay Conrod --- src/cmd/go/internal/modcmd/download.go | 2 +- src/cmd/go/internal/modfetch/fetch.go | 21 +++++++++++++----- .../modfetch/zip_sum_test/zip_sum_test.go | 3 ++- src/cmd/go/internal/modload/query.go | 22 +++++++++++++++---- 4 files changed, 36 insertions(+), 12 deletions(-) diff --git a/src/cmd/go/internal/modcmd/download.go b/src/cmd/go/internal/modcmd/download.go index 6c4ec572fc498..d4c161fca1c67 100644 --- a/src/cmd/go/internal/modcmd/download.go +++ b/src/cmd/go/internal/modcmd/download.go @@ -120,7 +120,7 @@ func runDownload(ctx context.Context, cmd *base.Command, args []string) { return } mod := module.Version{Path: m.Path, Version: m.Version} - m.Zip, err = modfetch.DownloadZip(mod) + m.Zip, err = modfetch.DownloadZip(ctx, mod) if err != nil { m.Error = err.Error() return diff --git a/src/cmd/go/internal/modfetch/fetch.go b/src/cmd/go/internal/modfetch/fetch.go index 66066126588cb..e29eb0a94205c 100644 --- a/src/cmd/go/internal/modfetch/fetch.go +++ b/src/cmd/go/internal/modfetch/fetch.go @@ -24,6 +24,7 @@ import ( "cmd/go/internal/par" "cmd/go/internal/renameio" "cmd/go/internal/robustio" + "cmd/go/internal/trace" "golang.org/x/mod/module" "golang.org/x/mod/sumdb/dirhash" @@ -48,7 +49,7 @@ func Download(ctx context.Context, mod module.Version) (dir string, err error) { err error } c := downloadCache.Do(mod, func() interface{} { - dir, err := download(mod) + dir, err := download(ctx, mod) if err != nil { return cached{"", err} } @@ -58,7 +59,10 @@ func Download(ctx context.Context, mod module.Version) (dir string, err error) { return c.dir, c.err } -func download(mod module.Version) (dir string, err error) { +func download(ctx context.Context, mod module.Version) (dir string, err error) { + ctx, span := trace.StartSpan(ctx, "modfetch.download "+mod.String()) + defer span.Done() + // If the directory exists, and no .partial file exists, the module has // already been completely extracted. .partial files may be created when a // module zip directory is extracted in place instead of being extracted to a @@ -73,7 +77,7 @@ func download(mod module.Version) (dir string, err error) { // To avoid cluttering the cache with extraneous files, // DownloadZip uses the same lockfile as Download. // Invoke DownloadZip before locking the file. - zipfile, err := DownloadZip(mod) + zipfile, err := DownloadZip(ctx, mod) if err != nil { return "", err } @@ -143,6 +147,7 @@ func download(mod module.Version) (dir string, err error) { return "", err } + ctx, span = trace.StartSpan(ctx, "unzip "+zipfile) if unzipInPlace { if err := ioutil.WriteFile(partialPath, nil, 0666); err != nil { return "", err @@ -172,6 +177,7 @@ func download(mod module.Version) (dir string, err error) { return "", err } } + defer span.Done() if !cfg.ModCacheRW { // Make dir read-only only *after* renaming it. @@ -196,7 +202,7 @@ var downloadZipCache par.Cache // DownloadZip downloads the specific module version to the // local zip cache and returns the name of the zip file. -func DownloadZip(mod module.Version) (zipfile string, err error) { +func DownloadZip(ctx context.Context, mod module.Version) (zipfile string, err error) { // The par.Cache here avoids duplicate work. type cached struct { zipfile string @@ -231,7 +237,7 @@ func DownloadZip(mod module.Version) (zipfile string, err error) { if err := os.MkdirAll(filepath.Dir(zipfile), 0777); err != nil { return cached{"", err} } - if err := downloadZip(mod, zipfile); err != nil { + if err := downloadZip(ctx, mod, zipfile); err != nil { return cached{"", err} } return cached{zipfile, nil} @@ -239,7 +245,10 @@ func DownloadZip(mod module.Version) (zipfile string, err error) { return c.zipfile, c.err } -func downloadZip(mod module.Version, zipfile string) (err error) { +func downloadZip(ctx context.Context, mod module.Version, zipfile string) (err error) { + ctx, span := trace.StartSpan(ctx, "modfetch.downloadZip "+zipfile) + defer span.Done() + // Clean up any remaining tempfiles from previous runs. // This is only safe to do because the lock file ensures that their // writers are no longer active. diff --git a/src/cmd/go/internal/modfetch/zip_sum_test/zip_sum_test.go b/src/cmd/go/internal/modfetch/zip_sum_test/zip_sum_test.go index eac9b32fa855e..82398ebfed230 100644 --- a/src/cmd/go/internal/modfetch/zip_sum_test/zip_sum_test.go +++ b/src/cmd/go/internal/modfetch/zip_sum_test/zip_sum_test.go @@ -16,6 +16,7 @@ package zip_sum_test import ( + "context" "crypto/sha256" "encoding/csv" "encoding/hex" @@ -119,7 +120,7 @@ func TestZipSums(t *testing.T) { name := fmt.Sprintf("%s@%s", strings.ReplaceAll(test.m.Path, "/", "_"), test.m.Version) t.Run(name, func(t *testing.T) { t.Parallel() - zipPath, err := modfetch.DownloadZip(test.m) + zipPath, err := modfetch.DownloadZip(context.Background(), test.m) if err != nil { if *updateTestData { t.Logf("%s: could not download module: %s (will remove from testdata)", test.m, err) diff --git a/src/cmd/go/internal/modload/query.go b/src/cmd/go/internal/modload/query.go index 39a813447c7ac..e82eb1506febf 100644 --- a/src/cmd/go/internal/modload/query.go +++ b/src/cmd/go/internal/modload/query.go @@ -19,6 +19,7 @@ import ( "cmd/go/internal/modfetch" "cmd/go/internal/search" "cmd/go/internal/str" + "cmd/go/internal/trace" "golang.org/x/mod/module" "golang.org/x/mod/semver" @@ -77,6 +78,9 @@ func (queryDisabledError) Error() string { } func queryProxy(ctx context.Context, proxy, path, query, current string, allowed func(module.Version) bool) (*modfetch.RevInfo, error) { + ctx, span := trace.StartSpan(ctx, "modload.queryProxy "+path+" "+query) + defer span.Done() + if current != "" && !semver.IsValid(current) { return nil, fmt.Errorf("invalid previous version %q", current) } @@ -403,6 +407,9 @@ func QueryPackage(ctx context.Context, path, query string, allowed func(module.V // the main module and only the version "latest", without checking for other // possible modules. func QueryPattern(ctx context.Context, pattern, query string, allowed func(module.Version) bool) ([]QueryResult, error) { + ctx, span := trace.StartSpan(ctx, "modload.QueryPattern "+pattern+" "+query) + defer span.Done() + base := pattern firstError := func(m *search.Match) error { @@ -470,7 +477,10 @@ func QueryPattern(ctx context.Context, pattern, query string, allowed func(modul } err := modfetch.TryProxies(func(proxy string) error { - queryModule := func(path string) (r QueryResult, err error) { + queryModule := func(ctx context.Context, path string) (r QueryResult, err error) { + ctx, span := trace.StartSpan(ctx, "modload.QueryPattern.queryModule ["+proxy+"] "+path) + defer span.Done() + current := findCurrentVersion(path) r.Mod.Path = path r.Rev, err = queryProxy(ctx, proxy, path, query, current, allowed) @@ -499,7 +509,7 @@ func QueryPattern(ctx context.Context, pattern, query string, allowed func(modul } var err error - results, err = queryPrefixModules(candidateModules, queryModule) + results, err = queryPrefixModules(ctx, candidateModules, queryModule) return err }) @@ -543,7 +553,10 @@ type prefixResult struct { err error } -func queryPrefixModules(candidateModules []string, queryModule func(path string) (QueryResult, error)) (found []QueryResult, err error) { +func queryPrefixModules(ctx context.Context, candidateModules []string, queryModule func(ctx context.Context, path string) (QueryResult, error)) (found []QueryResult, err error) { + ctx, span := trace.StartSpan(ctx, "modload.queryPrefixModules") + defer span.Done() + // If the path we're attempting is not in the module cache and we don't have a // fetch result cached either, we'll end up making a (potentially slow) // request to the proxy or (often even slower) the origin server. @@ -556,8 +569,9 @@ func queryPrefixModules(candidateModules []string, queryModule func(path string) var wg sync.WaitGroup wg.Add(len(candidateModules)) for i, p := range candidateModules { + ctx := trace.StartGoroutine(ctx) go func(p string, r *result) { - r.QueryResult, r.err = queryModule(p) + r.QueryResult, r.err = queryModule(ctx, p) wg.Done() }(p, &results[i]) }