internal/lsp: extra telemetry tagging of files and packages

Change-Id: Ia9a8fb5dcfb74e86b9366849810dd3edc1f898dd
Reviewed-on: https://go-review.googlesource.com/c/tools/+/186918
Run-TryBot: Ian Cottrell <iancottrell@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Rebecca Stambler <rstambler@golang.org>
diff --git a/internal/lsp/cache/check.go b/internal/lsp/cache/check.go
index 67e29a9..f2f5a4c 100644
--- a/internal/lsp/cache/check.go
+++ b/internal/lsp/cache/check.go
@@ -95,7 +95,7 @@
 }
 
 func (imp *importer) typeCheck(ctx context.Context, id packageID) (*pkg, error) {
-	ctx, done := trace.StartSpan(ctx, "cache.importer.typeCheck")
+	ctx, done := trace.StartSpan(ctx, "cache.importer.typeCheck", telemetry.Package.Of(id))
 	defer done()
 	meta, ok := imp.view.mcache.packages[id]
 	if !ok {
diff --git a/internal/lsp/cache/external.go b/internal/lsp/cache/external.go
index 357a1da..b52899b 100644
--- a/internal/lsp/cache/external.go
+++ b/internal/lsp/cache/external.go
@@ -10,6 +10,7 @@
 	"os"
 
 	"golang.org/x/tools/internal/lsp/source"
+	"golang.org/x/tools/internal/lsp/telemetry"
 	"golang.org/x/tools/internal/lsp/telemetry/trace"
 	"golang.org/x/tools/internal/span"
 )
@@ -51,7 +52,7 @@
 }
 
 func (h *nativeFileHandle) Read(ctx context.Context) ([]byte, string, error) {
-	ctx, done := trace.StartSpan(ctx, "cache.nativeFileHandle.Read")
+	ctx, done := trace.StartSpan(ctx, "cache.nativeFileHandle.Read", telemetry.File.Of(h.identity.URI.Filename()))
 	defer done()
 	//TODO: this should fail if the version is not the same as the handle
 	data, err := ioutil.ReadFile(h.identity.URI.Filename())
diff --git a/internal/lsp/cache/load.go b/internal/lsp/cache/load.go
index 614c9d6..cde9e67 100644
--- a/internal/lsp/cache/load.go
+++ b/internal/lsp/cache/load.go
@@ -13,6 +13,7 @@
 	"golang.org/x/tools/internal/lsp/telemetry"
 	"golang.org/x/tools/internal/lsp/telemetry/log"
 	"golang.org/x/tools/internal/lsp/telemetry/tag"
+	"golang.org/x/tools/internal/lsp/telemetry/trace"
 	"golang.org/x/tools/internal/span"
 )
 
@@ -87,6 +88,8 @@
 		return nil, nil, ctx.Err()
 	}
 
+	ctx, done := trace.StartSpan(ctx, "packages.Load", telemetry.File.Of(f.filename()))
+	defer done()
 	pkgs, err := packages.Load(v.Config(ctx), fmt.Sprintf("file=%s", f.filename()))
 	if len(pkgs) == 0 {
 		if err == nil {
diff --git a/internal/lsp/cache/parse.go b/internal/lsp/cache/parse.go
index 6895ab6..5be9c55 100644
--- a/internal/lsp/cache/parse.go
+++ b/internal/lsp/cache/parse.go
@@ -13,6 +13,7 @@
 	"go/token"
 
 	"golang.org/x/tools/internal/lsp/source"
+	"golang.org/x/tools/internal/lsp/telemetry"
 	"golang.org/x/tools/internal/lsp/telemetry/trace"
 	"golang.org/x/tools/internal/memoize"
 )
@@ -74,7 +75,7 @@
 }
 
 func parseGo(ctx context.Context, c *cache, fh source.FileHandle, mode source.ParseMode) (*ast.File, error) {
-	ctx, done := trace.StartSpan(ctx, "cache.parseGo")
+	ctx, done := trace.StartSpan(ctx, "cache.parseGo", telemetry.File.Of(fh.Identity().URI.Filename()))
 	defer done()
 	buf, _, err := fh.Read(ctx)
 	if err != nil {
diff --git a/internal/lsp/cmd/serve.go b/internal/lsp/cmd/serve.go
index 39cf087..86739ed 100644
--- a/internal/lsp/cmd/serve.go
+++ b/internal/lsp/cmd/serve.go
@@ -124,12 +124,13 @@
 }
 
 type rpcStats struct {
-	method    string
-	direction jsonrpc2.Direction
-	id        *jsonrpc2.ID
-	payload   *json.RawMessage
-	start     time.Time
-	close     func()
+	method     string
+	direction  jsonrpc2.Direction
+	id         *jsonrpc2.ID
+	payload    *json.RawMessage
+	start      time.Time
+	delivering func()
+	close      func()
 }
 
 type statsKeyType int
@@ -137,6 +138,10 @@
 const statsKey = statsKeyType(0)
 
 func (h *handler) Deliver(ctx context.Context, r *jsonrpc2.Request, delivered bool) bool {
+	stats := h.getStats(ctx)
+	if stats != nil {
+		stats.delivering()
+	}
 	return false
 }
 
@@ -165,6 +170,7 @@
 		tag.Tag{Key: telemetry.RPCID, Value: r.ID},
 	)
 	telemetry.Started.Record(ctx, 1)
+	_, stats.delivering = trace.StartSpan(ctx, "queued")
 	return ctx
 }
 
diff --git a/internal/lsp/source/diagnostics.go b/internal/lsp/source/diagnostics.go
index befbf85..121d6c1 100644
--- a/internal/lsp/source/diagnostics.go
+++ b/internal/lsp/source/diagnostics.go
@@ -36,6 +36,7 @@
 	"golang.org/x/tools/go/packages"
 	"golang.org/x/tools/internal/lsp/telemetry"
 	"golang.org/x/tools/internal/lsp/telemetry/log"
+	"golang.org/x/tools/internal/lsp/telemetry/trace"
 	"golang.org/x/tools/internal/span"
 )
 
@@ -61,7 +62,8 @@
 )
 
 func Diagnostics(ctx context.Context, view View, f GoFile, disabledAnalyses map[string]struct{}) (map[span.URI][]Diagnostic, error) {
-	ctx = telemetry.File.With(ctx, f.URI())
+	ctx, done := trace.StartSpan(ctx, "source.Diagnostics", telemetry.File.Of(f.URI()))
+	defer done()
 	pkg := f.GetPackage(ctx)
 	if pkg == nil {
 		return singleDiagnostic(f.URI(), "%s is not part of a package", f.URI()), nil
@@ -107,6 +109,8 @@
 }
 
 func diagnostics(ctx context.Context, v View, pkg Package, reports map[span.URI][]Diagnostic) bool {
+	ctx, done := trace.StartSpan(ctx, "source.diagnostics", telemetry.Package.Of(pkg.ID()))
+	defer done()
 	diagSets := make(map[span.URI]*diagnosticSet)
 	for _, err := range pkg.GetErrors() {
 		diag := Diagnostic{