internal/lsp: add additional instrumentation around package loading
Add some additional logging to help debug golang/go#53586
For golang/go#53586
Change-Id: I0574fb01be47b265cd6e412855794bc2cb836dff
Reviewed-on: https://go-review.googlesource.com/c/tools/+/414854
gopls-CI: kokoro <noreply+kokoro@google.com>
Reviewed-by: Alan Donovan <adonovan@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Run-TryBot: Robert Findley <rfindley@google.com>
Auto-Submit: Robert Findley <rfindley@google.com>
diff --git a/internal/lsp/cache/load.go b/internal/lsp/cache/load.go
index db9a06d..da0b246 100644
--- a/internal/lsp/cache/load.go
+++ b/internal/lsp/cache/load.go
@@ -15,6 +15,7 @@
"path/filepath"
"sort"
"strings"
+ "sync/atomic"
"time"
"golang.org/x/tools/go/packages"
@@ -28,12 +29,17 @@
"golang.org/x/tools/internal/span"
)
+var loadID uint64 // atomic identifier for loads
+
// load calls packages.Load for the given scopes, updating package metadata,
// import graph, and mapped files with the result.
//
// The resulting error may wrap the moduleErrorMap error type, representing
// errors associated with specific modules.
func (s *snapshot) load(ctx context.Context, allowNetwork bool, scopes ...interface{}) (err error) {
+ id := atomic.AddUint64(&loadID, 1)
+ eventName := fmt.Sprintf("go/packages.Load #%d", id) // unique name for logging
+
var query []string
var containsDir bool // for logging
@@ -138,9 +144,9 @@
return ctx.Err()
}
if err != nil {
- event.Error(ctx, "go/packages.Load", err, tag.Snapshot.Of(s.ID()), tag.Directory.Of(cfg.Dir), tag.Query.Of(query), tag.PackageCount.Of(len(pkgs)))
+ event.Error(ctx, eventName, err, tag.Snapshot.Of(s.ID()), tag.Directory.Of(cfg.Dir), tag.Query.Of(query), tag.PackageCount.Of(len(pkgs)))
} else {
- event.Log(ctx, "go/packages.Load", tag.Snapshot.Of(s.ID()), tag.Directory.Of(cfg.Dir), tag.Query.Of(query), tag.PackageCount.Of(len(pkgs)))
+ event.Log(ctx, eventName, tag.Snapshot.Of(s.ID()), tag.Directory.Of(cfg.Dir), tag.Query.Of(query), tag.PackageCount.Of(len(pkgs)))
}
if len(pkgs) == 0 {
if err == nil {
@@ -168,7 +174,7 @@
}
if !containsDir || s.view.Options().VerboseOutput {
- event.Log(ctx, "go/packages.Load",
+ event.Log(ctx, eventName,
tag.Snapshot.Of(s.ID()),
tag.Package.Of(pkg.ID),
tag.Files.Of(pkg.CompiledGoFiles))
@@ -209,6 +215,8 @@
loadedIDs = append(loadedIDs, id)
}
+ event.Log(ctx, fmt.Sprintf("%s: updating metadata for %d packages", eventName, len(updates)))
+
s.mu.Lock()
// invalidate the reverse transitive closure of packages that have changed.
diff --git a/internal/lsp/source/completion/completion.go b/internal/lsp/source/completion/completion.go
index bb1c68d..0c1ff3f 100644
--- a/internal/lsp/source/completion/completion.go
+++ b/internal/lsp/source/completion/completion.go
@@ -441,7 +441,7 @@
items, surrounding, innerErr := packageClauseCompletions(ctx, snapshot, fh, protoPos)
if innerErr != nil {
// return the error for GetParsedFile since it's more relevant in this situation.
- return nil, nil, fmt.Errorf("getting file for Completion: %w (package completions: %v)", err, innerErr)
+ return nil, nil, fmt.Errorf("getting file %s for Completion: %w (package completions: %v)", fh.URI(), err, innerErr)
}
return items, surrounding, nil
}