1 // Copyright 2020 The Go Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style
3 // license that can be found in the LICENSE file.
4 5 // Package gocommand is a helper for calling the go command.
6 package gocommand
7 8 import (
9 "bytes"
10 "context"
11 "encoding/json"
12 "errors"
13 "fmt"
14 "io"
15 "log"
16 "os"
17 "os/exec"
18 "path/filepath"
19 "regexp"
20 "runtime"
21 "strconv"
22 "strings"
23 "sync"
24 "time"
25 26 "golang.org/x/tools/internal/event"
27 "golang.org/x/tools/internal/event/keys"
28 "golang.org/x/tools/internal/event/label"
29 )
30 31 // A Runner will run go command invocations and serialize
32 // them if it sees a concurrency error.
33 type Runner struct {
34 // once guards the runner initialization.
35 once sync.Once
36 37 // inFlight tracks available workers.
38 inFlight chan struct{}
39 40 // serialized guards the ability to run a go command serially,
41 // to avoid deadlocks when claiming workers.
42 serialized chan struct{}
43 }
44 45 const maxInFlight = 10
46 47 func (runner *Runner) initialize() {
48 runner.once.Do(func() {
49 runner.inFlight = make(chan struct{}, maxInFlight)
50 runner.serialized = make(chan struct{}, 1)
51 })
52 }
53 54 // 1.13: go: updates to go.mod needed, but contents have changed
55 // 1.14: go: updating go.mod: existing contents have changed since last read
56 var modConcurrencyError = regexp.MustCompile(`go:.*go.mod.*contents have changed`)
57 58 // event keys for go command invocations
59 var (
60 verb = keys.NewString("verb", "go command verb")
61 directory = keys.NewString("directory", "")
62 )
63 64 func invLabels(inv Invocation) []label.Label {
65 return []label.Label{verb.Of(inv.Verb), directory.Of(inv.WorkingDir)}
66 }
67 68 // Run is a convenience wrapper around RunRaw.
69 // It returns only stdout and a "friendly" error.
70 func (runner *Runner) Run(ctx context.Context, inv Invocation) (*bytes.Buffer, error) {
71 ctx, done := event.Start(ctx, "gocommand.Runner.Run", invLabels(inv)...)
72 defer done()
73 74 stdout, _, friendly, _ := runner.RunRaw(ctx, inv)
75 return stdout, friendly
76 }
77 78 // RunPiped runs the invocation serially, always waiting for any concurrent
79 // invocations to complete first.
80 func (runner *Runner) RunPiped(ctx context.Context, inv Invocation, stdout, stderr io.Writer) error {
81 ctx, done := event.Start(ctx, "gocommand.Runner.RunPiped", invLabels(inv)...)
82 defer done()
83 84 _, err := runner.runPiped(ctx, inv, stdout, stderr)
85 return err
86 }
87 88 // RunRaw runs the invocation, serializing requests only if they fight over
89 // go.mod changes.
90 // Postcondition: both error results have same nilness.
91 func (runner *Runner) RunRaw(ctx context.Context, inv Invocation) (*bytes.Buffer, *bytes.Buffer, error, error) {
92 ctx, done := event.Start(ctx, "gocommand.Runner.RunRaw", invLabels(inv)...)
93 defer done()
94 // Make sure the runner is always initialized.
95 runner.initialize()
96 97 // First, try to run the go command concurrently.
98 stdout, stderr, friendlyErr, err := runner.runConcurrent(ctx, inv)
99 100 // If we encounter a load concurrency error, we need to retry serially.
101 if friendlyErr != nil && modConcurrencyError.MatchString(friendlyErr.Error()) {
102 event.Error(ctx, "Load concurrency error, will retry serially", err)
103 104 // Run serially by calling runPiped.
105 stdout.Reset()
106 stderr.Reset()
107 friendlyErr, err = runner.runPiped(ctx, inv, stdout, stderr)
108 }
109 110 return stdout, stderr, friendlyErr, err
111 }
112 113 // Postcondition: both error results have same nilness.
114 func (runner *Runner) runConcurrent(ctx context.Context, inv Invocation) (*bytes.Buffer, *bytes.Buffer, error, error) {
115 // Wait for 1 worker to become available.
116 select {
117 case <-ctx.Done():
118 return nil, nil, ctx.Err(), ctx.Err()
119 case runner.inFlight <- struct{}{}:
120 defer func() { <-runner.inFlight }()
121 }
122 123 stdout, stderr := &bytes.Buffer{}, &bytes.Buffer{}
124 friendlyErr, err := inv.runWithFriendlyError(ctx, stdout, stderr)
125 return stdout, stderr, friendlyErr, err
126 }
127 128 // Postcondition: both error results have same nilness.
129 func (runner *Runner) runPiped(ctx context.Context, inv Invocation, stdout, stderr io.Writer) (error, error) {
130 // Make sure the runner is always initialized.
131 runner.initialize()
132 133 // Acquire the serialization lock. This avoids deadlocks between two
134 // runPiped commands.
135 select {
136 case <-ctx.Done():
137 return ctx.Err(), ctx.Err()
138 case runner.serialized <- struct{}{}:
139 defer func() { <-runner.serialized }()
140 }
141 142 // Wait for all in-progress go commands to return before proceeding,
143 // to avoid load concurrency errors.
144 for range maxInFlight {
145 select {
146 case <-ctx.Done():
147 return ctx.Err(), ctx.Err()
148 case runner.inFlight <- struct{}{}:
149 // Make sure we always "return" any workers we took.
150 defer func() { <-runner.inFlight }()
151 }
152 }
153 154 return inv.runWithFriendlyError(ctx, stdout, stderr)
155 }
156 157 // An Invocation represents a call to the go command.
158 type Invocation struct {
159 Verb string
160 Args []string
161 BuildFlags []string
162 163 // If ModFlag is set, the go command is invoked with -mod=ModFlag.
164 // TODO(rfindley): remove, in favor of Args.
165 ModFlag string
166 167 // If ModFile is set, the go command is invoked with -modfile=ModFile.
168 // TODO(rfindley): remove, in favor of Args.
169 ModFile string
170 171 // Overlay is the name of the JSON overlay file that describes
172 // unsaved editor buffers; see [WriteOverlays].
173 // If set, the go command is invoked with -overlay=Overlay.
174 // TODO(rfindley): remove, in favor of Args.
175 Overlay string
176 177 // If CleanEnv is set, the invocation will run only with the environment
178 // in Env, not starting with os.Environ.
179 CleanEnv bool
180 Env []string
181 WorkingDir string
182 Logf func(format string, args ...any)
183 }
184 185 // Postcondition: both error results have same nilness.
186 func (i *Invocation) runWithFriendlyError(ctx context.Context, stdout, stderr io.Writer) (friendlyError error, rawError error) {
187 rawError = i.run(ctx, stdout, stderr)
188 if rawError != nil {
189 friendlyError = rawError
190 // Check for 'go' executable not being found.
191 if ee, ok := rawError.(*exec.Error); ok && ee.Err == exec.ErrNotFound {
192 friendlyError = fmt.Errorf("go command required, not found: %v", ee)
193 }
194 if ctx.Err() != nil {
195 friendlyError = ctx.Err()
196 }
197 friendlyError = fmt.Errorf("err: %v: stderr: %s", friendlyError, stderr)
198 }
199 return
200 }
201 202 // logf logs if i.Logf is non-nil.
203 func (i *Invocation) logf(format string, args ...any) {
204 if i.Logf != nil {
205 i.Logf(format, args...)
206 }
207 }
208 209 func (i *Invocation) run(ctx context.Context, stdout, stderr io.Writer) error {
210 goArgs := []string{i.Verb}
211 212 appendModFile := func() {
213 if i.ModFile != "" {
214 goArgs = append(goArgs, "-modfile="+i.ModFile)
215 }
216 }
217 appendModFlag := func() {
218 if i.ModFlag != "" {
219 goArgs = append(goArgs, "-mod="+i.ModFlag)
220 }
221 }
222 appendOverlayFlag := func() {
223 if i.Overlay != "" {
224 goArgs = append(goArgs, "-overlay="+i.Overlay)
225 }
226 }
227 228 switch i.Verb {
229 case "env", "version":
230 goArgs = append(goArgs, i.Args...)
231 case "mod":
232 // mod needs the sub-verb before flags.
233 goArgs = append(goArgs, i.Args[0])
234 appendModFile()
235 goArgs = append(goArgs, i.Args[1:]...)
236 case "get":
237 goArgs = append(goArgs, i.BuildFlags...)
238 appendModFile()
239 goArgs = append(goArgs, i.Args...)
240 241 default: // notably list and build.
242 goArgs = append(goArgs, i.BuildFlags...)
243 appendModFile()
244 appendModFlag()
245 appendOverlayFlag()
246 goArgs = append(goArgs, i.Args...)
247 }
248 cmd := exec.Command("go", goArgs...)
249 cmd.Stdout = stdout
250 cmd.Stderr = stderr
251 252 // https://go.dev/issue/59541: don't wait forever copying stderr
253 // after the command has exited.
254 // After CL 484741 we copy stdout manually, so we we'll stop reading that as
255 // soon as ctx is done. However, we also don't want to wait around forever
256 // for stderr. Give a much-longer-than-reasonable delay and then assume that
257 // something has wedged in the kernel or runtime.
258 cmd.WaitDelay = 30 * time.Second
259 260 // The cwd gets resolved to the real path. On Darwin, where
261 // /tmp is a symlink, this breaks anything that expects the
262 // working directory to keep the original path, including the
263 // go command when dealing with modules.
264 //
265 // os.Getwd has a special feature where if the cwd and the PWD
266 // are the same node then it trusts the PWD, so by setting it
267 // in the env for the child process we fix up all the paths
268 // returned by the go command.
269 if !i.CleanEnv {
270 cmd.Env = os.Environ()
271 }
272 cmd.Env = append(cmd.Env, i.Env...)
273 if i.WorkingDir != "" {
274 cmd.Env = append(cmd.Env, "PWD="+i.WorkingDir)
275 cmd.Dir = i.WorkingDir
276 }
277 278 debugStr := cmdDebugStr(cmd)
279 i.logf("starting %v", debugStr)
280 start := time.Now()
281 defer func() {
282 i.logf("%s for %v", time.Since(start), debugStr)
283 }()
284 285 return runCmdContext(ctx, cmd)
286 }
287 288 // DebugHangingGoCommands may be set by tests to enable additional
289 // instrumentation (including panics) for debugging hanging Go commands.
290 //
291 // See golang/go#54461 for details.
292 var DebugHangingGoCommands = false
293 294 // runCmdContext is like exec.CommandContext except it sends os.Interrupt
295 // before os.Kill.
296 func runCmdContext(ctx context.Context, cmd *exec.Cmd) (err error) {
297 // If cmd.Stdout is not an *os.File, the exec package will create a pipe and
298 // copy it to the Writer in a goroutine until the process has finished and
299 // either the pipe reaches EOF or command's WaitDelay expires.
300 //
301 // However, the output from 'go list' can be quite large, and we don't want to
302 // keep reading (and allocating buffers) if we've already decided we don't
303 // care about the output. We don't want to wait for the process to finish, and
304 // we don't wait to wait for the WaitDelay to expire either.
305 //
306 // Instead, if cmd.Stdout requires a copying goroutine we explicitly replace
307 // it with a pipe (which is an *os.File), which we can close in order to stop
308 // copying output as soon as we realize we don't care about it.
309 var stdoutW *os.File
310 if cmd.Stdout != nil {
311 if _, ok := cmd.Stdout.(*os.File); !ok {
312 var stdoutR *os.File
313 stdoutR, stdoutW, err = os.Pipe()
314 if err != nil {
315 return err
316 }
317 prevStdout := cmd.Stdout
318 cmd.Stdout = stdoutW
319 320 stdoutErr := make(chan error, 1)
321 go func() {
322 _, err := io.Copy(prevStdout, stdoutR)
323 if err != nil {
324 err = fmt.Errorf("copying stdout: %w", err)
325 }
326 stdoutErr <- err
327 }()
328 defer func() {
329 // We started a goroutine to copy a stdout pipe.
330 // Wait for it to finish, or terminate it if need be.
331 var err2 error
332 select {
333 case err2 = <-stdoutErr:
334 stdoutR.Close()
335 case <-ctx.Done():
336 stdoutR.Close()
337 // Per https://pkg.go.dev/os#File.Close, the call to stdoutR.Close
338 // should cause the Read call in io.Copy to unblock and return
339 // immediately, but we still need to receive from stdoutErr to confirm
340 // that it has happened.
341 <-stdoutErr
342 err2 = ctx.Err()
343 }
344 if err == nil {
345 err = err2
346 }
347 }()
348 349 // Per https://pkg.go.dev/os/exec#Cmd, “If Stdout and Stderr are the
350 // same writer, and have a type that can be compared with ==, at most
351 // one goroutine at a time will call Write.”
352 //
353 // Since we're starting a goroutine that writes to cmd.Stdout, we must
354 // also update cmd.Stderr so that it still holds.
355 func() {
356 defer func() { recover() }()
357 if cmd.Stderr == prevStdout {
358 cmd.Stderr = cmd.Stdout
359 }
360 }()
361 }
362 }
363 364 startTime := time.Now()
365 err = cmd.Start()
366 if stdoutW != nil {
367 // The child process has inherited the pipe file,
368 // so close the copy held in this process.
369 stdoutW.Close()
370 stdoutW = nil
371 }
372 if err != nil {
373 return err
374 }
375 376 resChan := make(chan error, 1)
377 go func() {
378 resChan <- cmd.Wait()
379 }()
380 381 // If we're interested in debugging hanging Go commands, stop waiting after a
382 // minute and panic with interesting information.
383 debug := DebugHangingGoCommands
384 if debug {
385 timer := time.NewTimer(1 * time.Minute)
386 defer timer.Stop()
387 select {
388 case err := <-resChan:
389 return err
390 case <-timer.C:
391 // HandleHangingGoCommand terminates this process.
392 // Pass off resChan in case we can collect the command error.
393 handleHangingGoCommand(startTime, cmd, resChan)
394 case <-ctx.Done():
395 }
396 } else {
397 select {
398 case err := <-resChan:
399 return err
400 case <-ctx.Done():
401 }
402 }
403 404 // Cancelled. Interrupt and see if it ends voluntarily.
405 if err := cmd.Process.Signal(os.Interrupt); err == nil {
406 // (We used to wait only 1s but this proved
407 // fragile on loaded builder machines.)
408 timer := time.NewTimer(5 * time.Second)
409 defer timer.Stop()
410 select {
411 case err := <-resChan:
412 return err
413 case <-timer.C:
414 }
415 }
416 417 // Didn't shut down in response to interrupt. Kill it hard.
418 if err := cmd.Process.Kill(); err != nil && !errors.Is(err, os.ErrProcessDone) && debug {
419 log.Printf("error killing the Go command: %v", err)
420 }
421 422 return <-resChan
423 }
424 425 // handleHangingGoCommand outputs debugging information to help diagnose the
426 // cause of a hanging Go command, and then exits with log.Fatalf.
427 func handleHangingGoCommand(start time.Time, cmd *exec.Cmd, resChan chan error) {
428 switch runtime.GOOS {
429 case "linux", "darwin", "freebsd", "netbsd", "openbsd":
430 fmt.Fprintln(os.Stderr, `DETECTED A HANGING GO COMMAND
431 432 The gopls test runner has detected a hanging go command. In order to debug
433 this, the output of ps and lsof/fstat is printed below.
434 435 See golang/go#54461 for more details.`)
436 437 fmt.Fprintln(os.Stderr, "\nps axo ppid,pid,command:")
438 fmt.Fprintln(os.Stderr, "-------------------------")
439 psCmd := exec.Command("ps", "axo", "ppid,pid,command")
440 psCmd.Stdout = os.Stderr
441 psCmd.Stderr = os.Stderr
442 if err := psCmd.Run(); err != nil {
443 log.Printf("Handling hanging Go command: running ps: %v", err)
444 }
445 446 listFiles := "lsof"
447 if runtime.GOOS == "freebsd" || runtime.GOOS == "netbsd" {
448 listFiles = "fstat"
449 }
450 451 fmt.Fprintln(os.Stderr, "\n"+listFiles+":")
452 fmt.Fprintln(os.Stderr, "-----")
453 listFilesCmd := exec.Command(listFiles)
454 listFilesCmd.Stdout = os.Stderr
455 listFilesCmd.Stderr = os.Stderr
456 if err := listFilesCmd.Run(); err != nil {
457 log.Printf("Handling hanging Go command: running %s: %v", listFiles, err)
458 }
459 // Try to extract information about the slow go process by issuing a SIGQUIT.
460 if err := cmd.Process.Signal(sigStuckProcess); err == nil {
461 select {
462 case err := <-resChan:
463 stderr := "not a bytes.Buffer"
464 if buf, _ := cmd.Stderr.(*bytes.Buffer); buf != nil {
465 stderr = buf.String()
466 }
467 log.Printf("Quit hanging go command:\n\terr:%v\n\tstderr:\n%v\n\n", err, stderr)
468 case <-time.After(5 * time.Second):
469 }
470 } else {
471 log.Printf("Sending signal %d to hanging go command: %v", sigStuckProcess, err)
472 }
473 }
474 log.Fatalf("detected hanging go command (golang/go#54461); waited %s\n\tcommand:%s\n\tpid:%d", time.Since(start), cmd, cmd.Process.Pid)
475 }
476 477 func cmdDebugStr(cmd *exec.Cmd) string {
478 env := make(map[string]string)
479 for _, kv := range cmd.Env {
480 split := strings.SplitN(kv, "=", 2)
481 if len(split) == 2 {
482 k, v := split[0], split[1]
483 env[k] = v
484 }
485 }
486 487 var args []string
488 for _, arg := range cmd.Args {
489 quoted := strconv.Quote(arg)
490 if quoted[1:len(quoted)-1] != arg || strings.Contains(arg, " ") {
491 args = append(args, quoted)
492 } else {
493 args = append(args, arg)
494 }
495 }
496 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, " "))
497 }
498 499 // WriteOverlays writes each value in the overlay (see the Overlay
500 // field of go/packages.Config) to a temporary file and returns the name
501 // of a JSON file describing the mapping that is suitable for the "go
502 // list -overlay" flag.
503 //
504 // On success, the caller must call the cleanup function exactly once
505 // when the files are no longer needed.
506 func WriteOverlays(overlay map[string][]byte) (filename string, cleanup func(), err error) {
507 // Do nothing if there are no overlays in the config.
508 if len(overlay) == 0 {
509 return "", func() {}, nil
510 }
511 512 dir, err := os.MkdirTemp("", "gocommand-*")
513 if err != nil {
514 return "", nil, err
515 }
516 517 // The caller must clean up this directory,
518 // unless this function returns an error.
519 // (The cleanup operand of each return
520 // statement below is ignored.)
521 defer func() {
522 cleanup = func() {
523 os.RemoveAll(dir)
524 }
525 if err != nil {
526 cleanup()
527 cleanup = nil
528 }
529 }()
530 531 // Write each map entry to a temporary file.
532 overlays := make(map[string]string)
533 for k, v := range overlay {
534 // Use a unique basename for each file (001-foo.go),
535 // to avoid creating nested directories.
536 base := fmt.Sprintf("%d-%s", 1+len(overlays), filepath.Base(k))
537 filename := filepath.Join(dir, base)
538 err := os.WriteFile(filename, v, 0666)
539 if err != nil {
540 return "", nil, err
541 }
542 overlays[k] = filename
543 }
544 545 // Write the JSON overlay file that maps logical file names to temp files.
546 //
547 // OverlayJSON is the format overlay files are expected to be in.
548 // The Replace map maps from overlaid paths to replacement paths:
549 // the Go command will forward all reads trying to open
550 // each overlaid path to its replacement path, or consider the overlaid
551 // path not to exist if the replacement path is empty.
552 //
553 // From golang/go#39958.
554 type OverlayJSON struct {
555 Replace map[string]string `json:"replace,omitempty"`
556 }
557 b, err := json.Marshal(OverlayJSON{Replace: overlays})
558 if err != nil {
559 return "", nil, err
560 }
561 filename = filepath.Join(dir, "overlay.json")
562 if err := os.WriteFile(filename, b, 0666); err != nil {
563 return "", nil, err
564 }
565 566 return filename, nil, nil
567 }
568