gopls: Measure the efficacy of completions

This CL introduces code to count how often proposed completions are accepted.

The results of the latest completion request are stored and compared
with the next DidChange notification. If the change is at the same
position, more than one character long, and matches a completion
item, the code counts the completion as accepted.

If, for some reason, DidChange returns multiple changes, only the
first is checked.

If the whole file is replaced there is no check for using any
proposed completion.

The test does not exercise the multi-change counter.

Change-Id: I08e9e39f651e4975a86c2dda9f6f5ceab7787e53
Reviewed-on: https://go-review.googlesource.com/c/tools/+/562248
Reviewed-by: Robert Findley <[email protected]>
LUCI-TryBot-Result: Go LUCI <[email protected]>

Author: pjweinbgo

gopls/internal/server/completion.go

@@ -40,6 +40,7 @@ func (s *server) Completion(ctx context.Context, params *protocol.CompletionPara
 	var surrounding *completion.Selection
 	switch snapshot.FileKind(fh) {
 	case file.Go:
+		complCnt.Inc() // completion requests for Go programs
 		candidates, surrounding, err = completion.Completion(ctx, snapshot, fh, params.Position, params.Context)
 	case file.Mod:
 		candidates, surrounding = nil, nil
@@ -61,6 +62,7 @@ func (s *server) Completion(ctx context.Context, params *protocol.CompletionPara
 		event.Error(ctx, "no completions found", err, tag.Position.Of(params.Position))
 	}
 	if candidates == nil {
+		complEmpty.Inc()
 		return &protocol.CompletionList{
 			IsIncomplete: true,
 			Items:        []protocol.CompletionItem{},
@@ -78,13 +80,28 @@ func (s *server) Completion(ctx context.Context, params *protocol.CompletionPara
 	incompleteResults := options.DeepCompletion || options.Matcher == settings.Fuzzy
 
 	items := toProtocolCompletionItems(candidates, rng, options)
+	if snapshot.FileKind(fh) == file.Go {
+		s.saveLastCompletion(fh.URI(), fh.Version(), items, params.Position)
+	}
 
+	if len(items) > 10 {
+		// TODO(pjw): long completions are ok for field lists
+		complLong.Inc()
+	}
 	return &protocol.CompletionList{
 		IsIncomplete: incompleteResults,
 		Items:        items,
 	}, nil
 }
 
+func (s *server) saveLastCompletion(uri protocol.DocumentURI, version int32, items []protocol.CompletionItem, pos protocol.Position) {
+	s.efficacyMu.Lock()
+	defer s.efficacyMu.Unlock()
+	s.efficacyURI = uri
+	s.efficacyPos = pos
+	s.efficacyItems = items
+}
+
 func toProtocolCompletionItems(candidates []completion.CompletionItem, rng protocol.Range, options *settings.Options) []protocol.CompletionItem {
 	var (
 		items                  = make([]protocol.CompletionItem, 0, len(candidates))

gopls/internal/server/counters.go

@@ -0,0 +1,25 @@
+package server
+
+import "golang.org/x/telemetry/counter"
+
+// Proposed counters for evaluating gopls code completion.
+var (
+	complCnt   = counter.New("gopls/completion/cnt")   // for Go programs
+	complEmpty = counter.New("gopls/completion/empty") // count empty responses
+	complLong  = counter.New("gopls/completion/long")  // returning more than 10 items
+
+	changeMulti = counter.New("gopls/completion/multi-change") // multiple changes in didChange
+	changeFull  = counter.New("gopls/completion/full-change")  // full file change in didChange
+
+	complUsed = counter.New("gopls/completion/used") // used a completion
+
+	// exported so tests can verify that counters are incrementd
+	CompletionCounters = []*counter.Counter{
+		complCnt,
+		complEmpty,
+		complLong,
+		changeMulti,
+		changeFull,
+		complUsed,
+	}
+)

gopls/internal/server/server.go

@@ -115,6 +115,13 @@ type server struct {
 	optionsMu sync.Mutex
 	options   *settings.Options
 
+	// Track the most recent completion results, for measuring completion efficacy
+	efficacyMu      sync.Mutex
+	efficacyURI     protocol.DocumentURI
+	efficacyVersion int32
+	efficacyItems   []protocol.CompletionItem
+	efficacyPos     protocol.Position
+
 	// # Modification tracking and diagnostics
 	//
 	// For the purpose of tracking diagnostics, we need a monotonically

gopls/internal/server/text_synchronization.go

@@ -10,6 +10,7 @@ import (
 	"errors"
 	"fmt"
 	"path/filepath"
+	"strings"
 	"sync"
 
 	"golang.org/x/tools/gopls/internal/cache"
@@ -313,6 +314,7 @@ func (s *server) changedText(ctx context.Context, uri protocol.DocumentURI, chan
 	// Check if the client sent the full content of the file.
 	// We accept a full content change even if the server expected incremental changes.
 	if len(changes) == 1 && changes[0].Range == nil && changes[0].RangeLength == 0 {
+		changeFull.Inc()
 		return []byte(changes[0].Text), nil
 	}
 	return s.applyIncrementalChanges(ctx, uri, changes)
@@ -327,7 +329,10 @@ func (s *server) applyIncrementalChanges(ctx context.Context, uri protocol.Docum
 	if err != nil {
 		return nil, fmt.Errorf("%w: file not found (%v)", jsonrpc2.ErrInternal, err)
 	}
-	for _, change := range changes {
+	if len(changes) > 1 {
+		changeMulti.Inc()
+	}
+	for i, change := range changes {
 		// TODO(adonovan): refactor to use diff.Apply, which is robust w.r.t.
 		// out-of-order or overlapping changes---and much more efficient.
 
@@ -348,10 +353,51 @@ func (s *server) applyIncrementalChanges(ctx context.Context, uri protocol.Docum
 		buf.WriteString(change.Text)
 		buf.Write(content[end:])
 		content = buf.Bytes()
+		if i == 0 { // only look at the first change if there are seversl
+			// TODO(pjw): understand multi-change)
+			s.checkEfficacy(fh.URI(), fh.Version(), change)
+		}
 	}
 	return content, nil
 }
 
+// increment counters if any of the completions look like there were used
+func (s *server) checkEfficacy(uri protocol.DocumentURI, version int32, change protocol.TextDocumentContentChangePartial) {
+	s.efficacyMu.Lock()
+	defer s.efficacyMu.Unlock()
+	if s.efficacyURI != uri {
+		return
+	}
+	// gopls increments the version, the test client does not
+	if version != s.efficacyVersion && version != s.efficacyVersion+1 {
+		return
+	}
+	// does any change at pos match a proposed completion item?
+	for _, item := range s.efficacyItems {
+		if item.TextEdit == nil {
+			continue
+		}
+		if item.TextEdit.Range.Start == change.Range.Start {
+			// the change and the proposed completion start at the same
+			if change.RangeLength == 0 && len(change.Text) == 1 {
+				// a single character added it does not count as a completion
+				continue
+			}
+			ix := strings.Index(item.TextEdit.NewText, "$")
+			if ix < 0 && strings.HasPrefix(change.Text, item.TextEdit.NewText) {
+				// not a snippet, suggested completion is a prefix of the change
+				complUsed.Inc()
+				return
+			}
+			if ix > 1 && strings.HasPrefix(change.Text, item.TextEdit.NewText[:ix]) {
+				// a snippet, suggested completion up to $ marker is a prefix of the change
+				complUsed.Inc()
+				return
+			}
+		}
+	}
+}
+
 func changeTypeToFileAction(ct protocol.FileChangeType) file.Action {
 	switch ct {
 	case protocol.Changed:

gopls/internal/telemetry/telemetry_test.go

@@ -125,7 +125,7 @@ func addForwardedCounters(env *Env, names []string, values []int64) {
 	env.ExecuteCommand(&protocol.ExecuteCommandParams{
 		Command:   command.AddTelemetryCounters.ID(),
 		Arguments: args,
-	}, res)
+	}, &res)
 	if res != nil {
 		env.T.Errorf("%v failed - %v", command.AddTelemetryCounters.ID(), res)
 	}

gopls/internal/test/integration/completion/completion_test.go

@@ -6,14 +6,18 @@ package completion
 
 import (
 	"fmt"
+	"log"
 	"sort"
 	"strings"
 	"testing"
 	"time"
 
 	"github.com/google/go-cmp/cmp"
+	"golang.org/x/telemetry/counter"
+	"golang.org/x/telemetry/counter/countertest"
 	"golang.org/x/tools/gopls/internal/hooks"
 	"golang.org/x/tools/gopls/internal/protocol"
+	"golang.org/x/tools/gopls/internal/server"
 	. "golang.org/x/tools/gopls/internal/test/integration"
 	"golang.org/x/tools/gopls/internal/test/integration/fake"
 	"golang.org/x/tools/gopls/internal/util/bug"
@@ -256,6 +260,11 @@ func compareCompletionLabels(want []string, gotItems []protocol.CompletionItem)
 	return ""
 }
 
+func init() {
+	// useful while debugging
+	log.SetFlags(log.Lshortfile)
+}
+
 func TestUnimportedCompletion(t *testing.T) {
 	const mod = `
 -- go.mod --
@@ -999,3 +1008,59 @@ func Join() {}
 		}
 	})
 }
+
+func TestCounters(t *testing.T) {
+	const files = `
+-- go.mod --
+module foo
+go 1.21
+-- x.go --
+package foo
+
+func main() {
+}
+
+`
+	WithOptions(
+		Modes(Default),
+	).Run(t, files, func(t *testing.T, env *Env) {
+		cts := func() map[*counter.Counter]uint64 {
+			ans := make(map[*counter.Counter]uint64)
+			for _, c := range server.CompletionCounters {
+				ans[c], _ = countertest.ReadCounter(c)
+			}
+			return ans
+		}
+		env.OpenFile("x.go")
+		env.Await(env.DoneWithOpen())
+		saved := env.BufferText("x.go")
+		lines := strings.Split(saved, "\n")
+		loc := env.RegexpSearch("x.go", "p")
+		before := cts()
+		// all the action is after 4 characters on line 2 (counting from 0)
+		// (doing the whole file is too expensive)
+		for i := 2; i < len(lines); i++ {
+			l := lines[i]
+			loc.Range.Start.Line = uint32(i)
+			for j := 5; j < len(l); j++ {
+				loc.Range.Start.Character = uint32(j)
+				loc.Range.End = loc.Range.Start
+				res := env.Completion(loc)
+				for _, r := range res.Items {
+					env.AcceptCompletion(loc, r)
+					env.SetBufferContent("x.go", saved)
+				}
+			}
+		}
+		after := cts()
+		for c := range after {
+			if c.Name() == "gopls/completion/multi-change" {
+				// don't know how to force multi-change
+				continue
+			}
+			if after[c] <= before[c] {
+				t.Errorf("%s did not increase", c.Name())
+			}
+		}
+	})
+}