cuelang.org/go@v0.10.1/internal/golangorgx/tools/gocommand/invoke.go

// Copyright 2020 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.

// Package gocommand is a helper for calling the go command.
package gocommand

import (
	"bytes"
	"context"
	"errors"
	"fmt"
	"io"
	"log"
	"os"
	"os/exec"
	"reflect"
	"regexp"
	"runtime"
	"strconv"
	"strings"
	"sync"
	"time"

	"cuelang.org/go/internal/golangorgx/tools/event"
	"cuelang.org/go/internal/golangorgx/tools/event/keys"
	"cuelang.org/go/internal/golangorgx/tools/event/label"
	"cuelang.org/go/internal/golangorgx/tools/event/tag"
)

// An Runner will run go command invocations and serialize
// them if it sees a concurrency error.
type Runner struct {
	// once guards the runner initialization.
	once sync.Once

	// inFlight tracks available workers.
	inFlight chan struct{}

	// serialized guards the ability to run a go command serially,
	// to avoid deadlocks when claiming workers.
	serialized chan struct{}
}

const maxInFlight = 10

func (runner *Runner) initialize() {
	runner.once.Do(func() {
		runner.inFlight = make(chan struct{}, maxInFlight)
		runner.serialized = make(chan struct{}, 1)
	})
}

// 1.13: go: updates to go.mod needed, but contents have changed
// 1.14: go: updating go.mod: existing contents have changed since last read
var modConcurrencyError = regexp.MustCompile(`go:.*go.mod.*contents have changed`)

// verb is an event label for the go command verb.
var verb = keys.NewString("verb", "go command verb")

func invLabels(inv Invocation) []label.Label {
	return []label.Label{verb.Of(inv.Verb), tag.Directory.Of(inv.WorkingDir)}
}

// Run is a convenience wrapper around RunRaw.
// It returns only stdout and a "friendly" error.
func (runner *Runner) Run(ctx context.Context, inv Invocation) (*bytes.Buffer, error) {
	ctx, done := event.Start(ctx, "gocommand.Runner.Run", invLabels(inv)...)
	defer done()

	stdout, _, friendly, _ := runner.RunRaw(ctx, inv)
	return stdout, friendly
}

// RunPiped runs the invocation serially, always waiting for any concurrent
// invocations to complete first.
func (runner *Runner) RunPiped(ctx context.Context, inv Invocation, stdout, stderr io.Writer) error {
	ctx, done := event.Start(ctx, "gocommand.Runner.RunPiped", invLabels(inv)...)
	defer done()

	_, err := runner.runPiped(ctx, inv, stdout, stderr)
	return err
}

// RunRaw runs the invocation, serializing requests only if they fight over
// go.mod changes.
// Postcondition: both error results have same nilness.
func (runner *Runner) RunRaw(ctx context.Context, inv Invocation) (*bytes.Buffer, *bytes.Buffer, error, error) {
	ctx, done := event.Start(ctx, "gocommand.Runner.RunRaw", invLabels(inv)...)
	defer done()
	// Make sure the runner is always initialized.
	runner.initialize()

	// First, try to run the go command concurrently.
	stdout, stderr, friendlyErr, err := runner.runConcurrent(ctx, inv)

	// If we encounter a load concurrency error, we need to retry serially.
	if friendlyErr != nil && modConcurrencyError.MatchString(friendlyErr.Error()) {
		event.Error(ctx, "Load concurrency error, will retry serially", err)

		// Run serially by calling runPiped.
		stdout.Reset()
		stderr.Reset()
		friendlyErr, err = runner.runPiped(ctx, inv, stdout, stderr)
	}

	return stdout, stderr, friendlyErr, err
}

// Postcondition: both error results have same nilness.
func (runner *Runner) runConcurrent(ctx context.Context, inv Invocation) (*bytes.Buffer, *bytes.Buffer, error, error) {
	// Wait for 1 worker to become available.
	select {
	case <-ctx.Done():
		return nil, nil, ctx.Err(), ctx.Err()
	case runner.inFlight <- struct{}{}:
		defer func() { <-runner.inFlight }()
	}

	stdout, stderr := &bytes.Buffer{}, &bytes.Buffer{}
	friendlyErr, err := inv.runWithFriendlyError(ctx, stdout, stderr)
	return stdout, stderr, friendlyErr, err
}

// Postcondition: both error results have same nilness.
func (runner *Runner) runPiped(ctx context.Context, inv Invocation, stdout, stderr io.Writer) (error, error) {
	// Make sure the runner is always initialized.
	runner.initialize()

	// Acquire the serialization lock. This avoids deadlocks between two
	// runPiped commands.
	select {
	case <-ctx.Done():
		return ctx.Err(), ctx.Err()
	case runner.serialized <- struct{}{}:
		defer func() { <-runner.serialized }()
	}

	// Wait for all in-progress go commands to return before proceeding,
	// to avoid load concurrency errors.
	for i := 0; i < maxInFlight; i++ {
		select {
		case <-ctx.Done():
			return ctx.Err(), ctx.Err()
		case runner.inFlight <- struct{}{}:
			// Make sure we always "return" any workers we took.
			defer func() { <-runner.inFlight }()
		}
	}

	return inv.runWithFriendlyError(ctx, stdout, stderr)
}

// An Invocation represents a call to the go command.
type Invocation struct {
	Verb       string
	Args       []string
	BuildFlags []string

	// If ModFlag is set, the go command is invoked with -mod=ModFlag.
	ModFlag string

	// If ModFile is set, the go command is invoked with -modfile=ModFile.
	ModFile string

	// If Overlay is set, the go command is invoked with -overlay=Overlay.
	Overlay string

	// If CleanEnv is set, the invocation will run only with the environment
	// in Env, not starting with os.Environ.
	CleanEnv   bool
	Env        []string
	WorkingDir string
	Logf       func(format string, args ...interface{})
}

// Postcondition: both error results have same nilness.
func (i *Invocation) runWithFriendlyError(ctx context.Context, stdout, stderr io.Writer) (friendlyError error, rawError error) {
	rawError = i.run(ctx, stdout, stderr)
	if rawError != nil {
		friendlyError = rawError
		// Check for 'go' executable not being found.
		if ee, ok := rawError.(*exec.Error); ok && ee.Err == exec.ErrNotFound {
			friendlyError = fmt.Errorf("go command required, not found: %v", ee)
		}
		if ctx.Err() != nil {
			friendlyError = ctx.Err()
		}
		friendlyError = fmt.Errorf("err: %v: stderr: %s", friendlyError, stderr)
	}
	return
}

func (i *Invocation) run(ctx context.Context, stdout, stderr io.Writer) error {
	log := i.Logf
	if log == nil {
		log = func(string, ...interface{}) {}
	}

	goArgs := []string{i.Verb}

	appendModFile := func() {
		if i.ModFile != "" {
			goArgs = append(goArgs, "-modfile="+i.ModFile)
		}
	}
	appendModFlag := func() {
		if i.ModFlag != "" {
			goArgs = append(goArgs, "-mod="+i.ModFlag)
		}
	}
	appendOverlayFlag := func() {
		if i.Overlay != "" {
			goArgs = append(goArgs, "-overlay="+i.Overlay)
		}
	}

	switch i.Verb {
	case "env", "version":
		goArgs = append(goArgs, i.Args...)
	case "mod":
		// mod needs the sub-verb before flags.
		goArgs = append(goArgs, i.Args[0])
		appendModFile()
		goArgs = append(goArgs, i.Args[1:]...)
	case "get":
		goArgs = append(goArgs, i.BuildFlags...)
		appendModFile()
		goArgs = append(goArgs, i.Args...)

	default: // notably list and build.
		goArgs = append(goArgs, i.BuildFlags...)
		appendModFile()
		appendModFlag()
		appendOverlayFlag()
		goArgs = append(goArgs, i.Args...)
	}
	cmd := exec.Command("go", goArgs...)
	cmd.Stdout = stdout
	cmd.Stderr = stderr

	// cmd.WaitDelay was added only in go1.20 (see #50436).
	if waitDelay := reflect.ValueOf(cmd).Elem().FieldByName("WaitDelay"); waitDelay.IsValid() {
		// https://go.dev/issue/59541: don't wait forever copying stderr
		// after the command has exited.
		// After CL 484741 we copy stdout manually, so we we'll stop reading that as
		// soon as ctx is done. However, we also don't want to wait around forever
		// for stderr. Give a much-longer-than-reasonable delay and then assume that
		// something has wedged in the kernel or runtime.
		waitDelay.Set(reflect.ValueOf(30 * time.Second))
	}

	// On darwin the cwd gets resolved to the real path, which breaks anything that
	// expects the working directory to keep the original path, including the
	// go command when dealing with modules.
	// The Go stdlib has a special feature where if the cwd and the PWD are the
	// same node then it trusts the PWD, so by setting it in the env for the child
	// process we fix up all the paths returned by the go command.
	if !i.CleanEnv {
		cmd.Env = os.Environ()
	}
	cmd.Env = append(cmd.Env, i.Env...)
	if i.WorkingDir != "" {
		cmd.Env = append(cmd.Env, "PWD="+i.WorkingDir)
		cmd.Dir = i.WorkingDir
	}

	defer func(start time.Time) { log("%s for %v", time.Since(start), cmdDebugStr(cmd)) }(time.Now())

	return runCmdContext(ctx, cmd)
}

// DebugHangingGoCommands may be set by tests to enable additional
// instrumentation (including panics) for debugging hanging Go commands.
//
// See golang/go#54461 for details.
var DebugHangingGoCommands = false

// runCmdContext is like exec.CommandContext except it sends os.Interrupt
// before os.Kill.
func runCmdContext(ctx context.Context, cmd *exec.Cmd) (err error) {
	// If cmd.Stdout is not an *os.File, the exec package will create a pipe and
	// copy it to the Writer in a goroutine until the process has finished and
	// either the pipe reaches EOF or command's WaitDelay expires.
	//
	// However, the output from 'go list' can be quite large, and we don't want to
	// keep reading (and allocating buffers) if we've already decided we don't
	// care about the output. We don't want to wait for the process to finish, and
	// we don't wait to wait for the WaitDelay to expire either.
	//
	// Instead, if cmd.Stdout requires a copying goroutine we explicitly replace
	// it with a pipe (which is an *os.File), which we can close in order to stop
	// copying output as soon as we realize we don't care about it.
	var stdoutW *os.File
	if cmd.Stdout != nil {
		if _, ok := cmd.Stdout.(*os.File); !ok {
			var stdoutR *os.File
			stdoutR, stdoutW, err = os.Pipe()
			if err != nil {
				return err
			}
			prevStdout := cmd.Stdout
			cmd.Stdout = stdoutW

			stdoutErr := make(chan error, 1)
			go func() {
				_, err := io.Copy(prevStdout, stdoutR)
				if err != nil {
					err = fmt.Errorf("copying stdout: %w", err)
				}
				stdoutErr <- err
			}()
			defer func() {
				// We started a goroutine to copy a stdout pipe.
				// Wait for it to finish, or terminate it if need be.
				var err2 error
				select {
				case err2 = <-stdoutErr:
					stdoutR.Close()
				case <-ctx.Done():
					stdoutR.Close()
					// Per https://pkg.go.dev/os#File.Close, the call to stdoutR.Close
					// should cause the Read call in io.Copy to unblock and return
					// immediately, but we still need to receive from stdoutErr to confirm
					// that it has happened.
					<-stdoutErr
					err2 = ctx.Err()
				}
				if err == nil {
					err = err2
				}
			}()

			// Per https://pkg.go.dev/os/exec#Cmd, “If Stdout and Stderr are the
			// same writer, and have a type that can be compared with ==, at most
			// one goroutine at a time will call Write.”
			//
			// Since we're starting a goroutine that writes to cmd.Stdout, we must
			// also update cmd.Stderr so that it still holds.
			func() {
				defer func() { recover() }()
				if cmd.Stderr == prevStdout {
					cmd.Stderr = cmd.Stdout
				}
			}()
		}
	}

	err = cmd.Start()
	if stdoutW != nil {
		// The child process has inherited the pipe file,
		// so close the copy held in this process.
		stdoutW.Close()
		stdoutW = nil
	}
	if err != nil {
		return err
	}

	resChan := make(chan error, 1)
	go func() {
		resChan <- cmd.Wait()
	}()

	// If we're interested in debugging hanging Go commands, stop waiting after a
	// minute and panic with interesting information.
	debug := DebugHangingGoCommands
	if debug {
		timer := time.NewTimer(1 * time.Minute)
		defer timer.Stop()
		select {
		case err := <-resChan:
			return err
		case <-timer.C:
			HandleHangingGoCommand(cmd.Process)
		case <-ctx.Done():
		}
	} else {
		select {
		case err := <-resChan:
			return err
		case <-ctx.Done():
		}
	}

	// Cancelled. Interrupt and see if it ends voluntarily.
	if err := cmd.Process.Signal(os.Interrupt); err == nil {
		// (We used to wait only 1s but this proved
		// fragile on loaded builder machines.)
		timer := time.NewTimer(5 * time.Second)
		defer timer.Stop()
		select {
		case err := <-resChan:
			return err
		case <-timer.C:
		}
	}

	// Didn't shut down in response to interrupt. Kill it hard.
	// TODO(rfindley): per advice from bcmills@, it may be better to send SIGQUIT
	// on certain platforms, such as unix.
	if err := cmd.Process.Kill(); err != nil && !errors.Is(err, os.ErrProcessDone) && debug {
		log.Printf("error killing the Go command: %v", err)
	}

	return <-resChan
}

func HandleHangingGoCommand(proc *os.Process) {
	switch runtime.GOOS {
	case "linux", "darwin", "freebsd", "netbsd":
		fmt.Fprintln(os.Stderr, `DETECTED A HANGING GO COMMAND

The gopls test runner has detected a hanging go command. In order to debug
this, the output of ps and lsof/fstat is printed below.

See golang/go#54461 for more details.`)

		fmt.Fprintln(os.Stderr, "\nps axo ppid,pid,command:")
		fmt.Fprintln(os.Stderr, "-------------------------")
		psCmd := exec.Command("ps", "axo", "ppid,pid,command")
		psCmd.Stdout = os.Stderr
		psCmd.Stderr = os.Stderr
		if err := psCmd.Run(); err != nil {
			panic(fmt.Sprintf("running ps: %v", err))
		}

		listFiles := "lsof"
		if runtime.GOOS == "freebsd" || runtime.GOOS == "netbsd" {
			listFiles = "fstat"
		}

		fmt.Fprintln(os.Stderr, "\n"+listFiles+":")
		fmt.Fprintln(os.Stderr, "-----")
		listFilesCmd := exec.Command(listFiles)
		listFilesCmd.Stdout = os.Stderr
		listFilesCmd.Stderr = os.Stderr
		if err := listFilesCmd.Run(); err != nil {
			panic(fmt.Sprintf("running %s: %v", listFiles, err))
		}
	}
	panic(fmt.Sprintf("detected hanging go command (pid %d): see golang/go#54461 for more details", proc.Pid))
}

func cmdDebugStr(cmd *exec.Cmd) string {
	env := make(map[string]string)
	for _, kv := range cmd.Env {
		split := strings.SplitN(kv, "=", 2)
		if len(split) == 2 {
			k, v := split[0], split[1]
			env[k] = v
		}
	}

	var args []string
	for _, arg := range cmd.Args {
		quoted := strconv.Quote(arg)
		if quoted[1:len(quoted)-1] != arg || strings.Contains(arg, " ") {
			args = append(args, quoted)
		} else {
			args = append(args, arg)
		}
	}
	return fmt.Sprintf("GOROOT=%v GOPATH=%v GO111MODULE=%v GOPROXY=%v PWD=%v %v", env["GOROOT"], env["GOPATH"], env["GO111MODULE"], env["GOPROXY"], env["PWD"], strings.Join(args, " "))
}