From f79636135d4e197cc6d78393efad122130a1d8e6 Mon Sep 17 00:00:00 2001 From: Robert Findley Date: Tue, 28 Mar 2023 21:34:10 -0400 Subject: [PATCH] gopls/internal/lsp: add tracing instrumentation for all Server methods While debugging the gopls/internal/lsp tests, I noticed that I was not seeing useful user defined tasks in the trace viewer. The reasons for this were that (1) we were disabling all instrumentation of the event package, and (2) we didn't have top-level tasks for each jsonrcp2 method, because the tests call into the Server directly. Fix this by re-enabling the exporter in gopls/internal/lsp tests (using a debug.Instance to suppress logging to stderr), and by instrumenting all server methods with a top-level span. Some were already instrumented, but it was inconsistent. Another advantage to instrumenting server methods in addition to jsonrpc2 methods, is that they can add labels specific to the request, such as the text document URI. Also add some instrumentation of key snapshot methods. Change-Id: I992a6a86b175b766e6cbff8c2f2c4a5a35b5d0cf Reviewed-on: https://go-review.googlesource.com/c/tools/+/480198 Reviewed-by: Peter Weinberger TryBot-Result: Gopher Robot Run-TryBot: Robert Findley --- gopls/internal/lsp/cache/check.go | 15 +++++++++++++++ gopls/internal/lsp/cache/load.go | 2 +- gopls/internal/lsp/cache/mod_tidy.go | 3 +++ gopls/internal/lsp/cache/parse.go | 6 +++--- gopls/internal/lsp/cache/parse_cache.go | 2 +- gopls/internal/lsp/cache/snapshot.go | 14 +++++++++++++- gopls/internal/lsp/call_hierarchy.go | 10 ++++++++++ gopls/internal/lsp/code_action.go | 3 +++ gopls/internal/lsp/code_lens.go | 4 ++++ gopls/internal/lsp/command.go | 3 +++ gopls/internal/lsp/completion.go | 3 +++ gopls/internal/lsp/definition.go | 8 ++++++++ gopls/internal/lsp/folding_range.go | 5 +++++ gopls/internal/lsp/format.go | 5 +++++ gopls/internal/lsp/general.go | 12 ++++++++++++ gopls/internal/lsp/highlight.go | 9 ++++++--- gopls/internal/lsp/hover.go | 5 +++++ gopls/internal/lsp/implementation.go | 5 +++++ gopls/internal/lsp/inlay_hint.go | 5 +++++ gopls/internal/lsp/link.go | 3 +++ gopls/internal/lsp/lsp_test.go | 16 ++++++++-------- gopls/internal/lsp/references.go | 5 +++++ gopls/internal/lsp/rename.go | 8 ++++++++ gopls/internal/lsp/selection_range.go | 2 +- gopls/internal/lsp/semantic.go | 22 ++++++++++------------ gopls/internal/lsp/server.go | 7 +++++++ gopls/internal/lsp/server_gen.go | 2 +- gopls/internal/lsp/signature_help.go | 3 +++ gopls/internal/lsp/symbols.go | 4 ++-- gopls/internal/lsp/text_synchronization.go | 17 +++++++++++++++++ gopls/internal/lsp/workspace.go | 4 ++++ 31 files changed, 179 insertions(+), 33 deletions(-) diff --git a/gopls/internal/lsp/cache/check.go b/gopls/internal/lsp/cache/check.go index 1e17613522b..9a696168503 100644 --- a/gopls/internal/lsp/cache/check.go +++ b/gopls/internal/lsp/cache/check.go @@ -188,6 +188,9 @@ func (s *snapshot) getImportGraph(ctx context.Context) *importGraph { // resolveImportGraph should only be called from getImportGraph. func (s *snapshot) resolveImportGraph() (*importGraph, error) { ctx := s.backgroundCtx + ctx, done := event.Start(event.Detach(ctx), "cache.resolveImportGraph") + defer done() + if err := s.awaitLoaded(ctx); err != nil { return nil, err } @@ -334,6 +337,9 @@ type ( // // Both pre and post may be called concurrently. func (s *snapshot) forEachPackage(ctx context.Context, ids []PackageID, pre preTypeCheck, post postTypeCheck) error { + ctx, done := event.Start(ctx, "cache.forEachPackage", tag.PackageCount.Of(len(ids))) + defer done() + if len(ids) == 0 { return nil // short cut: many call sites do not handle empty ids } @@ -534,6 +540,9 @@ func (b *typeCheckBatch) handleSyntaxPackage(ctx context.Context, i int, id Pack // importPackage loads the given package from its export data in p.exportData // (which must already be populated). func (b *typeCheckBatch) importPackage(ctx context.Context, m *source.Metadata, data []byte) (*types.Package, error) { + ctx, done := event.Start(ctx, "cache.typeCheckBatch.importPackage", tag.Package.Of(string(m.ID))) + defer done() + impMap := b.importMap(m.ID) var firstErr error // TODO(rfindley): unused: revisit or remove. @@ -580,6 +589,9 @@ func (b *typeCheckBatch) importPackage(ctx context.Context, m *source.Metadata, // checkPackageForImport type checks, but skips function bodies and does not // record syntax information. func (b *typeCheckBatch) checkPackageForImport(ctx context.Context, ph *packageHandle) (*types.Package, error) { + ctx, done := event.Start(ctx, "cache.typeCheckBatch.checkPackageForImport", tag.Package.Of(string(ph.m.ID))) + defer done() + onError := func(e error) { // Ignore errors for exporting. } @@ -627,6 +639,9 @@ func (b *typeCheckBatch) checkPackageForImport(ctx context.Context, ph *packageH // checkPackage "fully type checks" to produce a syntax package. func (b *typeCheckBatch) checkPackage(ctx context.Context, ph *packageHandle) (*Package, error) { + ctx, done := event.Start(ctx, "cache.typeCheckBatch.checkPackage", tag.Package.Of(string(ph.m.ID))) + defer done() + // TODO(rfindley): refactor to inline typeCheckImpl here. There is no need // for so many layers to build up the package // (checkPackage->typeCheckImpl->doTypeCheck). diff --git a/gopls/internal/lsp/cache/load.go b/gopls/internal/lsp/cache/load.go index f62ab4335a1..ce0269e830c 100644 --- a/gopls/internal/lsp/cache/load.go +++ b/gopls/internal/lsp/cache/load.go @@ -103,7 +103,7 @@ func (s *snapshot) load(ctx context.Context, allowNetwork bool, scopes ...loadSc } sort.Strings(query) // for determinism - ctx, done := event.Start(ctx, "cache.view.load", tag.Query.Of(query)) + ctx, done := event.Start(ctx, "cache.snapshot.load", tag.Query.Of(query)) defer done() flags := source.LoadWorkspace diff --git a/gopls/internal/lsp/cache/mod_tidy.go b/gopls/internal/lsp/cache/mod_tidy.go index 00e0e5c9881..0ba118837ef 100644 --- a/gopls/internal/lsp/cache/mod_tidy.go +++ b/gopls/internal/lsp/cache/mod_tidy.go @@ -29,6 +29,9 @@ import ( // ModTidy returns the go.mod file that would be obtained by running // "go mod tidy". Concurrent requests are combined into a single command. func (s *snapshot) ModTidy(ctx context.Context, pm *source.ParsedModule) (*source.TidiedModule, error) { + ctx, done := event.Start(ctx, "cache.snapshot.ModTidy") + defer done() + uri := pm.URI if pm.File == nil { return nil, fmt.Errorf("cannot tidy unparseable go.mod file: %v", uri) diff --git a/gopls/internal/lsp/cache/parse.go b/gopls/internal/lsp/cache/parse.go index 9f2918206d8..315d133cb38 100644 --- a/gopls/internal/lsp/cache/parse.go +++ b/gopls/internal/lsp/cache/parse.go @@ -36,9 +36,6 @@ func (s *snapshot) ParseGo(ctx context.Context, fh source.FileHandle, mode parse // parseGoImpl parses the Go source file whose content is provided by fh. func parseGoImpl(ctx context.Context, fset *token.FileSet, fh source.FileHandle, mode parser.Mode) (*source.ParsedGoFile, error) { - ctx, done := event.Start(ctx, "cache.parseGo", tag.File.Of(fh.URI().Filename())) - defer done() - ext := filepath.Ext(fh.URI().Filename()) if ext != ".go" && ext != "" { // files generated by cgo have no extension return nil, fmt.Errorf("cannot parse non-Go file %s", fh.URI()) @@ -59,6 +56,9 @@ func parseGoImpl(ctx context.Context, fset *token.FileSet, fh source.FileHandle, // // The provided ctx is used only for logging. func ParseGoSrc(ctx context.Context, fset *token.FileSet, uri span.URI, src []byte, mode parser.Mode) (res *source.ParsedGoFile, fixes []fixType) { + ctx, done := event.Start(ctx, "cache.ParseGoSrc", tag.File.Of(uri.Filename())) + defer done() + file, err := parser.ParseFile(fset, uri.Filename(), src, mode) var parseErr scanner.ErrorList if err != nil { diff --git a/gopls/internal/lsp/cache/parse_cache.go b/gopls/internal/lsp/cache/parse_cache.go index c562e8903fc..a7140831cf8 100644 --- a/gopls/internal/lsp/cache/parse_cache.go +++ b/gopls/internal/lsp/cache/parse_cache.go @@ -161,7 +161,7 @@ func (c *parseCache) startParse(mode parser.Mode, fhs ...source.FileHandle) ([]* } uri := fh.URI() - promise := memoize.NewPromise(fmt.Sprintf("parse(%s)", uri), func(ctx context.Context, _ interface{}) interface{} { + promise := memoize.NewPromise("parseCache.parse", func(ctx context.Context, _ interface{}) interface{} { // Allocate 2*len(content)+parsePadding to allow for re-parsing once // inside of parseGoSrc without exceeding the allocated space. base, nextBase := c.allocateSpace(2*len(content) + parsePadding) diff --git a/gopls/internal/lsp/cache/snapshot.go b/gopls/internal/lsp/cache/snapshot.go index 7771ce9e91b..5e63ed94a76 100644 --- a/gopls/internal/lsp/cache/snapshot.go +++ b/gopls/internal/lsp/cache/snapshot.go @@ -657,6 +657,9 @@ const ( ) func (s *snapshot) PackageDiagnostics(ctx context.Context, ids ...PackageID) (map[span.URI][]*source.Diagnostic, error) { + ctx, done := event.Start(ctx, "cache.snapshot.PackageDiagnostics") + defer done() + var mu sync.Mutex perFile := make(map[span.URI][]*source.Diagnostic) collect := func(diags []*source.Diagnostic) { @@ -685,6 +688,9 @@ func (s *snapshot) PackageDiagnostics(ctx context.Context, ids ...PackageID) (ma } func (s *snapshot) References(ctx context.Context, ids ...PackageID) ([]source.XrefIndex, error) { + ctx, done := event.Start(ctx, "cache.snapshot.References") + defer done() + indexes := make([]source.XrefIndex, len(ids)) pre := func(i int, ph *packageHandle) bool { data, err := filecache.Get(xrefsKind, ph.key) @@ -713,6 +719,9 @@ func (index XrefIndex) Lookup(targets map[PackagePath]map[objectpath.Path]struct } func (s *snapshot) MethodSets(ctx context.Context, ids ...PackageID) ([]*methodsets.Index, error) { + ctx, done := event.Start(ctx, "cache.snapshot.MethodSets") + defer done() + indexes := make([]*methodsets.Index, len(ids)) pre := func(i int, ph *packageHandle) bool { data, err := filecache.Get(methodSetsKind, ph.key) @@ -731,6 +740,9 @@ func (s *snapshot) MethodSets(ctx context.Context, ids ...PackageID) ([]*methods } func (s *snapshot) MetadataForFile(ctx context.Context, uri span.URI) ([]*source.Metadata, error) { + ctx, done := event.Start(ctx, "cache.snapshot.MetadataForFile") + defer done() + s.mu.Lock() // Start with the set of package associations derived from the last load. @@ -1689,7 +1701,7 @@ func (ac *unappliedChanges) ReadFile(ctx context.Context, uri span.URI) (source. } func (s *snapshot) clone(ctx, bgCtx context.Context, changes map[span.URI]*fileChange, forceReloadMetadata bool) (*snapshot, func()) { - ctx, done := event.Start(ctx, "snapshot.clone") + ctx, done := event.Start(ctx, "cache.snapshot.clone") defer done() reinit := false diff --git a/gopls/internal/lsp/call_hierarchy.go b/gopls/internal/lsp/call_hierarchy.go index 79eeb25cc15..fb916e94a7f 100644 --- a/gopls/internal/lsp/call_hierarchy.go +++ b/gopls/internal/lsp/call_hierarchy.go @@ -9,9 +9,13 @@ import ( "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" + "golang.org/x/tools/internal/event" ) func (s *Server) prepareCallHierarchy(ctx context.Context, params *protocol.CallHierarchyPrepareParams) ([]protocol.CallHierarchyItem, error) { + ctx, done := event.Start(ctx, "lsp.Server.prepareCallHierarchy") + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.Go) defer release() if !ok { @@ -22,6 +26,9 @@ func (s *Server) prepareCallHierarchy(ctx context.Context, params *protocol.Call } func (s *Server) incomingCalls(ctx context.Context, params *protocol.CallHierarchyIncomingCallsParams) ([]protocol.CallHierarchyIncomingCall, error) { + ctx, done := event.Start(ctx, "lsp.Server.incomingCalls") + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.Item.URI, source.Go) defer release() if !ok { @@ -32,6 +39,9 @@ func (s *Server) incomingCalls(ctx context.Context, params *protocol.CallHierarc } func (s *Server) outgoingCalls(ctx context.Context, params *protocol.CallHierarchyOutgoingCallsParams) ([]protocol.CallHierarchyOutgoingCall, error) { + ctx, done := event.Start(ctx, "lsp.Server.outgoingCalls") + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.Item.URI, source.Go) defer release() if !ok { diff --git a/gopls/internal/lsp/code_action.go b/gopls/internal/lsp/code_action.go index f7c1af67eda..cf05cd55d06 100644 --- a/gopls/internal/lsp/code_action.go +++ b/gopls/internal/lsp/code_action.go @@ -21,6 +21,9 @@ import ( ) func (s *Server) codeAction(ctx context.Context, params *protocol.CodeActionParams) ([]protocol.CodeAction, error) { + ctx, done := event.Start(ctx, "lsp.Server.codeAction") + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.UnknownKind) defer release() if !ok { diff --git a/gopls/internal/lsp/code_lens.go b/gopls/internal/lsp/code_lens.go index f554e798c3c..0167a78dc30 100644 --- a/gopls/internal/lsp/code_lens.go +++ b/gopls/internal/lsp/code_lens.go @@ -14,9 +14,13 @@ import ( "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" ) func (s *Server) codeLens(ctx context.Context, params *protocol.CodeLensParams) ([]protocol.CodeLens, error) { + ctx, done := event.Start(ctx, "lsp.Server.codeLens", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.UnknownKind) defer release() if !ok { diff --git a/gopls/internal/lsp/command.go b/gopls/internal/lsp/command.go index 850a6276db0..a5b0775cc9b 100644 --- a/gopls/internal/lsp/command.go +++ b/gopls/internal/lsp/command.go @@ -37,6 +37,9 @@ import ( ) func (s *Server) executeCommand(ctx context.Context, params *protocol.ExecuteCommandParams) (interface{}, error) { + ctx, done := event.Start(ctx, "lsp.Server.executeCommand") + defer done() + var found bool for _, name := range s.session.Options().SupportedCommands { if name == params.Command { diff --git a/gopls/internal/lsp/completion.go b/gopls/internal/lsp/completion.go index 3052a5cbfdc..7eeefa269a7 100644 --- a/gopls/internal/lsp/completion.go +++ b/gopls/internal/lsp/completion.go @@ -19,6 +19,9 @@ import ( ) func (s *Server) completion(ctx context.Context, params *protocol.CompletionParams) (*protocol.CompletionList, error) { + ctx, done := event.Start(ctx, "lsp.Server.completion", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.UnknownKind) defer release() if !ok { diff --git a/gopls/internal/lsp/definition.go b/gopls/internal/lsp/definition.go index 6259d4dbb84..89cf86efc05 100644 --- a/gopls/internal/lsp/definition.go +++ b/gopls/internal/lsp/definition.go @@ -12,9 +12,14 @@ import ( "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" "golang.org/x/tools/gopls/internal/lsp/template" + "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" ) func (s *Server) definition(ctx context.Context, params *protocol.DefinitionParams) ([]protocol.Location, error) { + ctx, done := event.Start(ctx, "lsp.Server.definition", tag.URI.Of(params.TextDocument.URI)) + defer done() + // TODO(rfindley): definition requests should be multiplexed across all views. snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.UnknownKind) defer release() @@ -37,6 +42,9 @@ func (s *Server) definition(ctx context.Context, params *protocol.DefinitionPara } func (s *Server) typeDefinition(ctx context.Context, params *protocol.TypeDefinitionParams) ([]protocol.Location, error) { + ctx, done := event.Start(ctx, "lsp.Server.typeDefinition", tag.URI.Of(params.TextDocument.URI)) + defer done() + // TODO(rfindley): type definition requests should be multiplexed across all views. snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.Go) defer release() diff --git a/gopls/internal/lsp/folding_range.go b/gopls/internal/lsp/folding_range.go index 3a29ce9927b..ecbe93f1d8d 100644 --- a/gopls/internal/lsp/folding_range.go +++ b/gopls/internal/lsp/folding_range.go @@ -9,9 +9,14 @@ import ( "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" + "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" ) func (s *Server) foldingRange(ctx context.Context, params *protocol.FoldingRangeParams) ([]protocol.FoldingRange, error) { + ctx, done := event.Start(ctx, "lsp.Server.foldingRange", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.Go) defer release() if !ok { diff --git a/gopls/internal/lsp/format.go b/gopls/internal/lsp/format.go index 773a4690e92..47659ba94a5 100644 --- a/gopls/internal/lsp/format.go +++ b/gopls/internal/lsp/format.go @@ -11,9 +11,14 @@ import ( "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" "golang.org/x/tools/gopls/internal/lsp/work" + "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" ) func (s *Server) formatting(ctx context.Context, params *protocol.DocumentFormattingParams) ([]protocol.TextEdit, error) { + ctx, done := event.Start(ctx, "lsp.Server.formatting", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.UnknownKind) defer release() if !ok { diff --git a/gopls/internal/lsp/general.go b/gopls/internal/lsp/general.go index 5ab063a041c..d8cec11f635 100644 --- a/gopls/internal/lsp/general.go +++ b/gopls/internal/lsp/general.go @@ -26,6 +26,9 @@ import ( ) func (s *Server) initialize(ctx context.Context, params *protocol.ParamInitialize) (*protocol.InitializeResult, error) { + ctx, done := event.Start(ctx, "lsp.Server.initialize") + defer done() + s.stateMu.Lock() if s.state >= serverInitializing { defer s.stateMu.Unlock() @@ -192,6 +195,9 @@ See https://github.com/golang/go/issues/45732 for more information.`, } func (s *Server) initialized(ctx context.Context, params *protocol.InitializedParams) error { + ctx, done := event.Start(ctx, "lsp.Server.initialized") + defer done() + s.stateMu.Lock() if s.state >= serverInitialized { defer s.stateMu.Unlock() @@ -585,6 +591,9 @@ func (s *Server) beginFileRequest(ctx context.Context, pURI protocol.DocumentURI // shutdown implements the 'shutdown' LSP handler. It releases resources // associated with the server and waits for all ongoing work to complete. func (s *Server) shutdown(ctx context.Context) error { + ctx, done := event.Start(ctx, "lsp.Server.shutdown") + defer done() + s.stateMu.Lock() defer s.stateMu.Unlock() if s.state < serverInitialized { @@ -604,6 +613,9 @@ func (s *Server) shutdown(ctx context.Context) error { } func (s *Server) exit(ctx context.Context) error { + ctx, done := event.Start(ctx, "lsp.Server.exit") + defer done() + s.stateMu.Lock() defer s.stateMu.Unlock() diff --git a/gopls/internal/lsp/highlight.go b/gopls/internal/lsp/highlight.go index 290444ec962..a3c898a0a77 100644 --- a/gopls/internal/lsp/highlight.go +++ b/gopls/internal/lsp/highlight.go @@ -7,14 +7,17 @@ package lsp import ( "context" - "golang.org/x/tools/internal/event" - "golang.org/x/tools/internal/event/tag" "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" "golang.org/x/tools/gopls/internal/lsp/template" + "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" ) func (s *Server) documentHighlight(ctx context.Context, params *protocol.DocumentHighlightParams) ([]protocol.DocumentHighlight, error) { + ctx, done := event.Start(ctx, "lsp.Server.documentHighlight", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.Go) defer release() if !ok { @@ -27,7 +30,7 @@ func (s *Server) documentHighlight(ctx context.Context, params *protocol.Documen rngs, err := source.Highlight(ctx, snapshot, fh, params.Position) if err != nil { - event.Error(ctx, "no highlight", err, tag.URI.Of(params.TextDocument.URI)) + event.Error(ctx, "no highlight", err) } return toProtocolHighlight(rngs), nil } diff --git a/gopls/internal/lsp/hover.go b/gopls/internal/lsp/hover.go index 2d1aae7d5b5..9c5bc0d308d 100644 --- a/gopls/internal/lsp/hover.go +++ b/gopls/internal/lsp/hover.go @@ -12,9 +12,14 @@ import ( "golang.org/x/tools/gopls/internal/lsp/source" "golang.org/x/tools/gopls/internal/lsp/template" "golang.org/x/tools/gopls/internal/lsp/work" + "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" ) func (s *Server) hover(ctx context.Context, params *protocol.HoverParams) (*protocol.Hover, error) { + ctx, done := event.Start(ctx, "lsp.Server.hover", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.UnknownKind) defer release() if !ok { diff --git a/gopls/internal/lsp/implementation.go b/gopls/internal/lsp/implementation.go index 0eb82652e9e..e231d96bccb 100644 --- a/gopls/internal/lsp/implementation.go +++ b/gopls/internal/lsp/implementation.go @@ -9,9 +9,14 @@ import ( "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" + "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" ) func (s *Server) implementation(ctx context.Context, params *protocol.ImplementationParams) ([]protocol.Location, error) { + ctx, done := event.Start(ctx, "lsp.Server.implementation", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.Go) defer release() if !ok { diff --git a/gopls/internal/lsp/inlay_hint.go b/gopls/internal/lsp/inlay_hint.go index 7efe98bdc66..67a6625c0e1 100644 --- a/gopls/internal/lsp/inlay_hint.go +++ b/gopls/internal/lsp/inlay_hint.go @@ -10,9 +10,14 @@ import ( "golang.org/x/tools/gopls/internal/lsp/mod" "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" + "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" ) func (s *Server) inlayHint(ctx context.Context, params *protocol.InlayHintParams) ([]protocol.InlayHint, error) { + ctx, done := event.Start(ctx, "lsp.Server.inlayHint", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.UnknownKind) defer release() if !ok { diff --git a/gopls/internal/lsp/link.go b/gopls/internal/lsp/link.go index 2713715cd64..d787b830729 100644 --- a/gopls/internal/lsp/link.go +++ b/gopls/internal/lsp/link.go @@ -24,6 +24,9 @@ import ( ) func (s *Server) documentLink(ctx context.Context, params *protocol.DocumentLinkParams) (links []protocol.DocumentLink, err error) { + ctx, done := event.Start(ctx, "lsp.Server.documentLink") + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.UnknownKind) defer release() if !ok { diff --git a/gopls/internal/lsp/lsp_test.go b/gopls/internal/lsp/lsp_test.go index a8d230ea29f..3bcc5c93612 100644 --- a/gopls/internal/lsp/lsp_test.go +++ b/gopls/internal/lsp/lsp_test.go @@ -18,13 +18,13 @@ import ( "github.com/google/go-cmp/cmp" "golang.org/x/tools/gopls/internal/lsp/cache" "golang.org/x/tools/gopls/internal/lsp/command" + "golang.org/x/tools/gopls/internal/lsp/debug" "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" "golang.org/x/tools/gopls/internal/lsp/tests" "golang.org/x/tools/gopls/internal/lsp/tests/compare" "golang.org/x/tools/gopls/internal/span" "golang.org/x/tools/internal/bug" - "golang.org/x/tools/internal/event" "golang.org/x/tools/internal/testenv" ) @@ -32,13 +32,6 @@ func TestMain(m *testing.M) { bug.PanicOnBugs = true testenv.ExitIfSmallMachine() - // Set the global exporter to nil so that we don't log to stderr. This avoids - // a lot of misleading noise in test output. - // - // TODO(rfindley): investigate whether we can/should capture logs scoped to - // individual tests by passing in a context with a local exporter. - event.SetExporter(nil) - os.Exit(m.Run()) } @@ -52,6 +45,13 @@ func TestLSP(t *testing.T) { func testLSP(t *testing.T, datum *tests.Data) { ctx := tests.Context(t) + // Setting a debug instance suppresses logging to stderr, but ensures that we + // still e.g. convert events into runtime/trace/instrumentation. + // + // Previously, we called event.SetExporter(nil), which turns off all + // instrumentation. + ctx = debug.WithInstance(ctx, "", "off") + session := cache.NewSession(ctx, cache.New(nil), nil) options := source.DefaultOptions().Clone() tests.DefaultOptions(options) diff --git a/gopls/internal/lsp/references.go b/gopls/internal/lsp/references.go index 190c1574150..09e1e6349a1 100644 --- a/gopls/internal/lsp/references.go +++ b/gopls/internal/lsp/references.go @@ -10,9 +10,14 @@ import ( "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" "golang.org/x/tools/gopls/internal/lsp/template" + "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" ) func (s *Server) references(ctx context.Context, params *protocol.ReferenceParams) ([]protocol.Location, error) { + ctx, done := event.Start(ctx, "lsp.Server.references", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.UnknownKind) defer release() if !ok { diff --git a/gopls/internal/lsp/rename.go b/gopls/internal/lsp/rename.go index 1a051df36ee..0c228cfe8a0 100644 --- a/gopls/internal/lsp/rename.go +++ b/gopls/internal/lsp/rename.go @@ -10,9 +10,14 @@ import ( "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" + "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" ) func (s *Server) rename(ctx context.Context, params *protocol.RenameParams) (*protocol.WorkspaceEdit, error) { + ctx, done := event.Start(ctx, "lsp.Server.rename", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.Go) defer release() if !ok { @@ -58,6 +63,9 @@ func (s *Server) rename(ctx context.Context, params *protocol.RenameParams) (*pr // TODO(rfindley): why wouldn't we want to show an error to the user, if the // user initiated a rename request at the cursor? func (s *Server) prepareRename(ctx context.Context, params *protocol.PrepareRenameParams) (*protocol.PrepareRename2Gn, error) { + ctx, done := event.Start(ctx, "lsp.Server.prepareRename", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.Go) defer release() if !ok { diff --git a/gopls/internal/lsp/selection_range.go b/gopls/internal/lsp/selection_range.go index 5b3fd31e9f1..1cfc0f2d8c1 100644 --- a/gopls/internal/lsp/selection_range.go +++ b/gopls/internal/lsp/selection_range.go @@ -25,7 +25,7 @@ import ( // returned for each cursor to avoid multiple round-trips when the user is // likely to issue this command multiple times in quick succession. func (s *Server) selectionRange(ctx context.Context, params *protocol.SelectionRangeParams) ([]protocol.SelectionRange, error) { - ctx, done := event.Start(ctx, "lsp.Server.documentSymbol") + ctx, done := event.Start(ctx, "lsp.Server.selectionRange") defer done() snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.UnknownKind) diff --git a/gopls/internal/lsp/semantic.go b/gopls/internal/lsp/semantic.go index 4d53747395b..108f01403fb 100644 --- a/gopls/internal/lsp/semantic.go +++ b/gopls/internal/lsp/semantic.go @@ -23,6 +23,7 @@ import ( "golang.org/x/tools/gopls/internal/lsp/source" "golang.org/x/tools/gopls/internal/lsp/template" "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" "golang.org/x/tools/internal/typeparams" ) @@ -37,25 +38,22 @@ const maxFullFileSize int = 100000 // semDebug should NEVER be true in checked-in code const semDebug = false -func (s *Server) semanticTokensFull(ctx context.Context, p *protocol.SemanticTokensParams) (*protocol.SemanticTokens, error) { - ret, err := s.computeSemanticTokens(ctx, p.TextDocument, nil) +func (s *Server) semanticTokensFull(ctx context.Context, params *protocol.SemanticTokensParams) (*protocol.SemanticTokens, error) { + ctx, done := event.Start(ctx, "lsp.Server.semanticTokensFull", tag.URI.Of(params.TextDocument.URI)) + defer done() + + ret, err := s.computeSemanticTokens(ctx, params.TextDocument, nil) return ret, err } -func (s *Server) semanticTokensFullDelta(ctx context.Context, p *protocol.SemanticTokensDeltaParams) (interface{}, error) { - return nil, fmt.Errorf("implement SemanticTokensFullDelta") -} +func (s *Server) semanticTokensRange(ctx context.Context, params *protocol.SemanticTokensRangeParams) (*protocol.SemanticTokens, error) { + ctx, done := event.Start(ctx, "lsp.Server.semanticTokensRange", tag.URI.Of(params.TextDocument.URI)) + defer done() -func (s *Server) semanticTokensRange(ctx context.Context, p *protocol.SemanticTokensRangeParams) (*protocol.SemanticTokens, error) { - ret, err := s.computeSemanticTokens(ctx, p.TextDocument, &p.Range) + ret, err := s.computeSemanticTokens(ctx, params.TextDocument, ¶ms.Range) return ret, err } -func (s *Server) semanticTokensRefresh(ctx context.Context) error { - // in the code, but not in the protocol spec - return fmt.Errorf("implement SemanticTokensRefresh") -} - func (s *Server) computeSemanticTokens(ctx context.Context, td protocol.TextDocumentIdentifier, rng *protocol.Range) (*protocol.SemanticTokens, error) { ans := protocol.SemanticTokens{ Data: []uint32{}, diff --git a/gopls/internal/lsp/server.go b/gopls/internal/lsp/server.go index 13441c40b73..33f251bd035 100644 --- a/gopls/internal/lsp/server.go +++ b/gopls/internal/lsp/server.go @@ -17,6 +17,7 @@ import ( "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" "golang.org/x/tools/gopls/internal/span" + "golang.org/x/tools/internal/event" "golang.org/x/tools/internal/jsonrpc2" ) @@ -114,10 +115,16 @@ type Server struct { } func (s *Server) workDoneProgressCancel(ctx context.Context, params *protocol.WorkDoneProgressCancelParams) error { + ctx, done := event.Start(ctx, "lsp.Server.workDoneProgressCancel") + defer done() + return s.progress.Cancel(params.Token) } func (s *Server) nonstandardRequest(ctx context.Context, method string, params interface{}) (interface{}, error) { + ctx, done := event.Start(ctx, "lsp.Server.nonstandardRequest") + defer done() + switch method { case "gopls/diagnoseFiles": paramMap := params.(map[string]interface{}) diff --git a/gopls/internal/lsp/server_gen.go b/gopls/internal/lsp/server_gen.go index 2c6e9954d23..3d736c6e5b0 100644 --- a/gopls/internal/lsp/server_gen.go +++ b/gopls/internal/lsp/server_gen.go @@ -241,7 +241,7 @@ func (s *Server) SemanticTokensFull(ctx context.Context, p *protocol.SemanticTok } func (s *Server) SemanticTokensFullDelta(ctx context.Context, p *protocol.SemanticTokensDeltaParams) (interface{}, error) { - return s.semanticTokensFullDelta(ctx, p) + return nil, notImplemented("SemanticTokensFullDelta") } func (s *Server) SemanticTokensRange(ctx context.Context, p *protocol.SemanticTokensRangeParams) (*protocol.SemanticTokens, error) { diff --git a/gopls/internal/lsp/signature_help.go b/gopls/internal/lsp/signature_help.go index b623f78ea74..b0249ebbc3f 100644 --- a/gopls/internal/lsp/signature_help.go +++ b/gopls/internal/lsp/signature_help.go @@ -14,6 +14,9 @@ import ( ) func (s *Server) signatureHelp(ctx context.Context, params *protocol.SignatureHelpParams) (*protocol.SignatureHelp, error) { + ctx, done := event.Start(ctx, "lsp.Server.signatureHelp", tag.URI.Of(params.TextDocument.URI)) + defer done() + snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.Go) defer release() if !ok { diff --git a/gopls/internal/lsp/symbols.go b/gopls/internal/lsp/symbols.go index 40fa0d05e11..b31d980484c 100644 --- a/gopls/internal/lsp/symbols.go +++ b/gopls/internal/lsp/symbols.go @@ -15,7 +15,7 @@ import ( ) func (s *Server) documentSymbol(ctx context.Context, params *protocol.DocumentSymbolParams) ([]interface{}, error) { - ctx, done := event.Start(ctx, "lsp.Server.documentSymbol") + ctx, done := event.Start(ctx, "lsp.Server.documentSymbol", tag.URI.Of(params.TextDocument.URI)) defer done() snapshot, fh, ok, release, err := s.beginFileRequest(ctx, params.TextDocument.URI, source.UnknownKind) @@ -33,7 +33,7 @@ func (s *Server) documentSymbol(ctx context.Context, params *protocol.DocumentSy return []interface{}{}, nil } if err != nil { - event.Error(ctx, "DocumentSymbols failed", err, tag.URI.Of(fh.URI())) + event.Error(ctx, "DocumentSymbols failed", err) return []interface{}{}, nil } // Convert the symbols to an interface array. diff --git a/gopls/internal/lsp/text_synchronization.go b/gopls/internal/lsp/text_synchronization.go index cba7ee2a310..5c6ebcc086b 100644 --- a/gopls/internal/lsp/text_synchronization.go +++ b/gopls/internal/lsp/text_synchronization.go @@ -15,6 +15,8 @@ import ( "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" "golang.org/x/tools/gopls/internal/span" + "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/tag" "golang.org/x/tools/internal/jsonrpc2" ) @@ -72,6 +74,9 @@ func (m ModificationSource) String() string { } func (s *Server) didOpen(ctx context.Context, params *protocol.DidOpenTextDocumentParams) error { + ctx, done := event.Start(ctx, "lsp.Server.didOpen", tag.URI.Of(params.TextDocument.URI)) + defer done() + uri := params.TextDocument.URI.SpanURI() if !uri.IsFile() { return nil @@ -102,6 +107,9 @@ func (s *Server) didOpen(ctx context.Context, params *protocol.DidOpenTextDocume } func (s *Server) didChange(ctx context.Context, params *protocol.DidChangeTextDocumentParams) error { + ctx, done := event.Start(ctx, "lsp.Server.didChange", tag.URI.Of(params.TextDocument.URI)) + defer done() + uri := params.TextDocument.URI.SpanURI() if !uri.IsFile() { return nil @@ -162,6 +170,9 @@ func (s *Server) warnAboutModifyingGeneratedFiles(ctx context.Context, uri span. } func (s *Server) didChangeWatchedFiles(ctx context.Context, params *protocol.DidChangeWatchedFilesParams) error { + ctx, done := event.Start(ctx, "lsp.Server.didChangeWatchedFiles") + defer done() + var modifications []source.FileModification for _, change := range params.Changes { uri := change.URI.SpanURI() @@ -179,6 +190,9 @@ func (s *Server) didChangeWatchedFiles(ctx context.Context, params *protocol.Did } func (s *Server) didSave(ctx context.Context, params *protocol.DidSaveTextDocumentParams) error { + ctx, done := event.Start(ctx, "lsp.Server.didSave", tag.URI.Of(params.TextDocument.URI)) + defer done() + uri := params.TextDocument.URI.SpanURI() if !uri.IsFile() { return nil @@ -194,6 +208,9 @@ func (s *Server) didSave(ctx context.Context, params *protocol.DidSaveTextDocume } func (s *Server) didClose(ctx context.Context, params *protocol.DidCloseTextDocumentParams) error { + ctx, done := event.Start(ctx, "lsp.Server.didClose", tag.URI.Of(params.TextDocument.URI)) + defer done() + uri := params.TextDocument.URI.SpanURI() if !uri.IsFile() { return nil diff --git a/gopls/internal/lsp/workspace.go b/gopls/internal/lsp/workspace.go index 7c02239e6ad..52e49176ce3 100644 --- a/gopls/internal/lsp/workspace.go +++ b/gopls/internal/lsp/workspace.go @@ -11,6 +11,7 @@ import ( "golang.org/x/tools/gopls/internal/lsp/protocol" "golang.org/x/tools/gopls/internal/lsp/source" "golang.org/x/tools/gopls/internal/span" + "golang.org/x/tools/internal/event" ) func (s *Server) didChangeWorkspaceFolders(ctx context.Context, params *protocol.DidChangeWorkspaceFoldersParams) error { @@ -44,6 +45,9 @@ func (s *Server) addView(ctx context.Context, name string, uri span.URI) (source } func (s *Server) didChangeConfiguration(ctx context.Context, _ *protocol.DidChangeConfigurationParams) error { + ctx, done := event.Start(ctx, "lsp.Server.didChangeConfiguration") + defer done() + // Apply any changes to the session-level settings. options := s.session.Options().Clone() if err := s.fetchConfig(ctx, "", "", options); err != nil {