go/packages: disable network, improve debug logging

When the name= query constructs the temporary module, it may find things
that don't resolve. In at least some cases (#28518), allowing go list
to access the network results in not just bad performance but actual
failures. Default GOPROXY to "off" when doing queries on the temporary
module to try to address that.

Also, add some more debug logging, including various environment
variables, so that it's easier to reproduce failing commands.

Change-Id: I1a6d3ffa5c845271ce48e9fe802a2491ccadcd7c
Reviewed-on: https://go-review.googlesource.com/c/146477
Run-TryBot: Heschi Kreinick <heschi@google.com>
Reviewed-by: Ian Cottrell <iancottrell@google.com>

go/packages/golist.go

@@ -16,11 +16,15 @@ import (
 	"regexp"
 	"strings"
 	"sync"
+	"time"
 
 	"golang.org/x/tools/internal/gopathwalk"
 	"golang.org/x/tools/internal/semver"
 )
 
+// debug controls verbose logging.
+const debug = false
+
 // A goTooOldError reports that the go command
 // found by exec.LookPath is too old to use the new go list behavior.
 type goTooOldError struct {
@@ -31,6 +35,9 @@ type goTooOldError struct {
 // the build system package structure.
 // See driver for more details.
 func goListDriver(cfg *Config, patterns ...string) (*driverResponse, error) {
+	if debug {
+		defer func(start time.Time, patterns []string) { log.Printf("%v for query %v", time.Since(start), patterns) }(time.Now(), patterns)
+	}
 	// Determine files requested in contains patterns
 	var containFiles []string
 	var packagesNamed []string
@@ -286,6 +293,12 @@ func runNamedQueries(cfg *Config, driver driver, addPkg func(*Package), queries
 		gomod.WriteString(")\n")
 
 		tmpCfg := *cfg
+
+		// We're only trying to look at stuff in the module cache, so
+		// disable the network. This should speed things up, and has
+		// prevented errors in at least one case, #28518.
+		tmpCfg.Env = append(append([]string{"GOPROXY=off"}, cfg.Env...))
+
 		var err error
 		tmpCfg.Dir, err = ioutil.TempDir("", "gopackages-modquery")
 		if err != nil {
@@ -591,6 +604,9 @@ func golistargs(cfg *Config, words []string) []string {
 
 // invokeGo returns the stdout of a go command invocation.
 func invokeGo(cfg *Config, args ...string) (*bytes.Buffer, error) {
+	if debug {
+		defer func(start time.Time) { log.Printf("%s for %v", time.Since(start), cmdDebugStr(cfg, args...)) }(time.Now())
+	}
 	stdout := new(bytes.Buffer)
 	stderr := new(bytes.Buffer)
 	cmd := exec.CommandContext(cfg.Context, "go", args...)
@@ -634,13 +650,24 @@ func invokeGo(cfg *Config, args ...string) (*bytes.Buffer, error) {
 	// be useful for debugging. Print them if $GOPACKAGESPRINTGOLISTERRORS
 	// is set.
 	if len(stderr.Bytes()) != 0 && os.Getenv("GOPACKAGESPRINTGOLISTERRORS") != "" {
-		fmt.Fprintf(os.Stderr, "go %v stderr: <<%s>>\n", args, stderr)
+		fmt.Fprintf(os.Stderr, "%s stderr: <<%s>>\n", cmdDebugStr(cfg, args...), stderr)
 	}
 
 	// debugging
 	if false {
-		fmt.Fprintf(os.Stderr, "go %v stdout: <<%s>>\n", args, stdout)
+		fmt.Fprintf(os.Stderr, "%s stdout: <<%s>>\n", cmdDebugStr(cfg, args...), stdout)
 	}
 
 	return stdout, nil
 }
+
+func cmdDebugStr(cfg *Config, args ...string) string {
+	env := make(map[string]string)
+	for _, kv := range cfg.Env {
+		split := strings.Split(kv, "=")
+		k, v := split[0], split[1]
+		env[k] = v
+	}
+
+	return fmt.Sprintf("GOROOT=%v GOPATH=%v GO111MODULE=%v PWD=%v go %v", env["GOROOT"], env["GOPATH"], env["GO111MODULE"], env["PWD"], args)
+}