go/packages: add debug logging via the packages.Config

This change adds a Logf field to the packages.Config.

Change-Id: I144a9a1e1181585bbe621898c4a3e6a007a38322
Reviewed-on: https://go-review.googlesource.com/c/tools/+/185993
Run-TryBot: Rebecca Stambler <rstambler@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Michael Matloob <matloob@golang.org>
diff --git a/go/packages/golist.go b/go/packages/golist.go
index 00e21a7..44df821 100644
--- a/go/packages/golist.go
+++ b/go/packages/golist.go
@@ -316,9 +316,7 @@
 
 	startWalk := time.Now()
 	gopathwalk.Walk(roots, add, gopathwalk.Options{ModulesEnabled: modRoot != "", Debug: debug})
-	if debug {
-		log.Printf("%v for walk", time.Since(startWalk))
-	}
+	cfg.Logf("%v for walk", time.Since(startWalk))
 
 	// Weird special case: the top-level package in a module will be in
 	// whatever directory the user checked the repository out into. It's
@@ -759,11 +757,9 @@
 	cmd.Dir = cfg.Dir
 	cmd.Stdout = stdout
 	cmd.Stderr = stderr
-	if debug {
-		defer func(start time.Time) {
-			log.Printf("%s for %v, stderr: <<%s>>\n", time.Since(start), cmdDebugStr(cmd, args...), stderr)
-		}(time.Now())
-	}
+	defer func(start time.Time) {
+		cfg.Logf("%s for %v, stderr: <<%s>>\n", time.Since(start), cmdDebugStr(cmd, args...), stderr)
+	}(time.Now())
 
 	if err := cmd.Run(); err != nil {
 		// Check for 'go' executable not being found.
diff --git a/go/packages/packages.go b/go/packages/packages.go
index f20e444..f1fe568 100644
--- a/go/packages/packages.go
+++ b/go/packages/packages.go
@@ -103,6 +103,12 @@
 	// If Context is nil, the load cannot be cancelled.
 	Context context.Context
 
+	// Logf is the logger for the config.
+	// If the user provides a logger, debug logging is enabled.
+	// If the GOPACKAGESDEBUG environment variable is set to true,
+	// but the logger is nil, default to log.Printf.
+	Logf func(format string, args ...interface{})
+
 	// Dir is the directory in which to run the build system's query tool
 	// that provides information about the packages.
 	// If Dir is empty, the tool is run in the current directory.
@@ -429,6 +435,17 @@
 	}
 	if cfg != nil {
 		ld.Config = *cfg
+		// If the user has provided a logger, use it.
+		ld.Config.Logf = cfg.Logf
+	}
+	if ld.Config.Logf == nil {
+		// If the GOPACKAGESDEBUG environment variable is set to true,
+		// but the user has not provided a logger, default to log.Printf.
+		if debug {
+			ld.Config.Logf = log.Printf
+		} else {
+			ld.Config.Logf = func(format string, args ...interface{}) {}
+		}
 	}
 	if ld.Config.Mode == 0 {
 		ld.Config.Mode = NeedName | NeedFiles | NeedCompiledGoFiles // Preserve zero behavior of Mode for backwards compatibility.
diff --git a/internal/lsp/cache/load.go b/internal/lsp/cache/load.go
index fd5f532..30d2b69 100644
--- a/internal/lsp/cache/load.go
+++ b/internal/lsp/cache/load.go
@@ -85,7 +85,7 @@
 		return nil, nil, ctx.Err()
 	}
 
-	pkgs, err := packages.Load(v.Config(), fmt.Sprintf("file=%s", f.filename()))
+	pkgs, err := packages.Load(v.Config(ctx), fmt.Sprintf("file=%s", f.filename()))
 	if len(pkgs) == 0 {
 		if err == nil {
 			err = fmt.Errorf("go/packages.Load: no packages found for %s", f.filename())
diff --git a/internal/lsp/cache/session.go b/internal/lsp/cache/session.go
index d746c34..ecd87e3 100644
--- a/internal/lsp/cache/session.go
+++ b/internal/lsp/cache/session.go
@@ -91,7 +91,7 @@
 	}
 	// Preemptively build the builtin package,
 	// so we immediately add builtin.go to the list of ignored files.
-	v.buildBuiltinPkg()
+	v.buildBuiltinPkg(ctx)
 
 	s.views = append(s.views, v)
 	// we always need to drop the view map
diff --git a/internal/lsp/cache/view.go b/internal/lsp/cache/view.go
index 8496b15..8f59aed 100644
--- a/internal/lsp/cache/view.go
+++ b/internal/lsp/cache/view.go
@@ -118,7 +118,7 @@
 
 // Config returns the configuration used for the view's interaction with the
 // go/packages API. It is shared across all views.
-func (v *view) Config() *packages.Config {
+func (v *view) Config(ctx context.Context) *packages.Config {
 	// TODO: Should we cache the config and/or overlay somewhere?
 	return &packages.Config{
 		Dir:        v.folder.Filename(),
@@ -135,22 +135,25 @@
 		ParseFile: func(*token.FileSet, string, []byte) (*ast.File, error) {
 			panic("go/packages must not be used to parse files")
 		},
+		Logf: func(format string, args ...interface{}) {
+			xlog.Infof(ctx, format, args...)
+		},
 		Tests: true,
 	}
 }
 
-func (v *view) ProcessEnv() *imports.ProcessEnv {
+func (v *view) ProcessEnv(ctx context.Context) *imports.ProcessEnv {
 	v.mu.Lock()
 	defer v.mu.Unlock()
 
 	if v.processEnv == nil {
-		v.processEnv = v.buildProcessEnv()
+		v.processEnv = v.buildProcessEnv(ctx)
 	}
 	return v.processEnv
 }
 
-func (v *view) buildProcessEnv() *imports.ProcessEnv {
-	cfg := v.Config()
+func (v *view) buildProcessEnv(ctx context.Context) *imports.ProcessEnv {
+	cfg := v.Config(ctx)
 	env := &imports.ProcessEnv{
 		WorkingDir: cfg.Dir,
 		Logf: func(format string, u ...interface{}) {
@@ -235,9 +238,12 @@
 // buildBuiltinPkg builds the view's builtin package.
 // It assumes that the view is not active yet,
 // i.e. it has not been added to the session's list of views.
-func (v *view) buildBuiltinPkg() {
-	cfg := *v.Config()
-	pkgs, _ := packages.Load(&cfg, "builtin")
+func (v *view) buildBuiltinPkg(ctx context.Context) {
+	cfg := *v.Config(ctx)
+	pkgs, err := packages.Load(&cfg, "builtin")
+	if err != nil {
+		xlog.Errorf(ctx, "error getting package metadata for \"builtin\" package: %v", err)
+	}
 	if len(pkgs) != 1 {
 		v.builtinPkg, _ = ast.NewPackage(cfg.Fset, nil, nil, nil)
 		return
diff --git a/internal/lsp/source/format.go b/internal/lsp/source/format.go
index 145ad0a..dbbb467 100644
--- a/internal/lsp/source/format.go
+++ b/internal/lsp/source/format.go
@@ -68,7 +68,7 @@
 		return nil, fmt.Errorf("%s has list errors, not running goimports", f.URI())
 	}
 
-	if resolver, ok := view.ProcessEnv().GetResolver().(*imports.ModuleResolver); ok && resolver.Initialized {
+	if resolver, ok := view.ProcessEnv(ctx).GetResolver().(*imports.ModuleResolver); ok && resolver.Initialized {
 		// TODO(suzmue): only reset this state when necessary (eg when the go.mod files of this
 		// module or modules with replace directive changes).
 		resolver.Initialized = false
@@ -77,7 +77,7 @@
 		resolver.ModsByDir = nil
 	}
 	options := &imports.Options{
-		Env: view.ProcessEnv(),
+		Env: view.ProcessEnv(ctx),
 		// Defaults.
 		AllErrors:  true,
 		Comments:   true,
diff --git a/internal/lsp/source/view.go b/internal/lsp/source/view.go
index 2ed1887..622794d 100644
--- a/internal/lsp/source/view.go
+++ b/internal/lsp/source/view.go
@@ -208,7 +208,7 @@
 	// Ignore returns true if this file should be ignored by this view.
 	Ignore(span.URI) bool
 
-	Config() *packages.Config
+	Config(ctx context.Context) *packages.Config
 
 	// Process returns the process for this view.
 	// Note: this contains cached module and filesystem state, which must
@@ -217,7 +217,7 @@
 	// TODO(suzmue): the state cached in the process env is specific to each view,
 	// however, there is state that can be shared between views that is not currently
 	// cached, like the module cache.
-	ProcessEnv() *imports.ProcessEnv
+	ProcessEnv(ctx context.Context) *imports.ProcessEnv
 }
 
 // File represents a source file of any type.