gopls/internal/cache: fix module resolver cache refreshing

An apparent bad merge in CL 561235 caused the critical component--
clearing the resolver for a new scan--to be dropped. Fix this, so that
the imports state is actually refreshed asynchronously.

It is surprising that this was not reported, though I see perhaps two
related comments in survey results. Most likely adding a new import is
infrequent enough that users were simply confused, or learned to restart
gopls (alas).

Also, add more instrumentation that would help debug golang/go#67289.

For golang/go#67289

Change-Id: I50d70a470eb393caf9e0b41856997942372b216f
Reviewed-on: https://go-review.googlesource.com/c/tools/+/590377
Auto-Submit: Robert Findley <[email protected]>
Reviewed-by: Alan Donovan <[email protected]>
LUCI-TryBot-Result: Go LUCI <[email protected]>

Author: findleyr

internal/gocommand/invoke.go

@@ -200,12 +200,14 @@ func (i *Invocation) runWithFriendlyError(ctx context.Context, stdout, stderr io
 	return
 }
 
-func (i *Invocation) run(ctx context.Context, stdout, stderr io.Writer) error {
-	log := i.Logf
-	if log == nil {
-		log = func(string, ...interface{}) {}
+// logf logs if i.Logf is non-nil.
+func (i *Invocation) logf(format string, args ...any) {
+	if i.Logf != nil {
+		i.Logf(format, args...)
 	}
+}
 
+func (i *Invocation) run(ctx context.Context, stdout, stderr io.Writer) error {
 	goArgs := []string{i.Verb}
 
 	appendModFile := func() {
@@ -277,7 +279,12 @@ func (i *Invocation) run(ctx context.Context, stdout, stderr io.Writer) error {
 		cmd.Dir = i.WorkingDir
 	}
 
-	defer func(start time.Time) { log("%s for %v", time.Since(start), cmdDebugStr(cmd)) }(time.Now())
+	debugStr := cmdDebugStr(cmd)
+	i.logf("starting %v", debugStr)
+	start := time.Now()
+	defer func() {
+		i.logf("%s for %v", time.Since(start), debugStr)
+	}()
 
 	return runCmdContext(ctx, cmd)
 }