cmd/go: support background processes in TestScript

This will be used to test fixes for bugs in concurrent 'go' command
invocations, such as #26794.

See the README changes for a description of the semantics.

Updates #26794

Change-Id: I897e7b2d11ff4549a4711002eadd6a54f033ce0b
Reviewed-on: https://go-review.googlesource.com/c/141218
Run-TryBot: Bryan C. Mills <bcmills@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Ian Lance Taylor <iant@golang.org>
Reviewed-by: Russ Cox <rsc@golang.org>

src/cmd/go/go_test.go

@@ -7,6 +7,7 @@ package main_test
 import (
  "bytes"
  "cmd/internal/sys"
+ "context"
  "debug/elf"
  "debug/macho"
  "flag"
@@ -108,6 +109,12 @@ var testGo string
 var testTmpDir string
 var testBin string
 
+// testCtx is canceled when the test binary is about to time out.
+//
+// If https://golang.org/issue/28135 is accepted, uses of this variable in test
+// functions should be replaced by t.Context().
+var testCtx = context.Background()
+
 // The TestMain function creates a go command for testing purposes and
 // deletes it after the tests have been run.
 func TestMain(m *testing.M) {
@@ -120,6 +127,20 @@ func TestMain(m *testing.M) {
  os.Unsetenv("GOROOT_FINAL")
 
  flag.Parse()
+
+ timeoutFlag := flag.Lookup("test.timeout")
+ if timeoutFlag != nil {
+ // TODO(golang.org/issue/28147): The go command does not pass the
+ // test.timeout flag unless either -timeout or -test.timeout is explicitly
+ // set on the command line.
+ if d := timeoutFlag.Value.(flag.Getter).Get().(time.Duration); d != 0 {
+ aBitShorter := d * 95 / 100
+ var cancel context.CancelFunc
+ testCtx, cancel = context.WithTimeout(testCtx, aBitShorter)
+ defer cancel()
+ }
+ }
+
  if *proxyAddr != "" {
  StartProxy()
  select {}

src/cmd/go/script_test.go

@@ -9,6 +9,7 @@ package main_test
 
 import (
  "bytes"
+ "context"
  "fmt"
  "internal/testenv"
  "io/ioutil"
@@ -55,21 +56,28 @@ func TestScript(t *testing.T) {
 
 // A testScript holds execution state for a single test script.
 type testScript struct {
- t *testing.T
- workdir string // temporary work dir ($WORK)
- log bytes.Buffer // test execution log (printed at end of test)
- mark int // offset of next log truncation
- cd string // current directory during test execution; initially $WORK/gopath/src
- name string // short name of test ("foo")
- file string // full file name ("testdata/script/foo.txt")
- lineno int // line number currently executing
- line string // line currently executing
- env []string // environment list (for os/exec)
- envMap map[string]string // environment mapping (matches env)
- stdout string // standard output from last 'go' command; for 'stdout' command
- stderr string // standard error from last 'go' command; for 'stderr' command
- stopped bool // test wants to stop early
- start time.Time // time phase started
+ t *testing.T
+ workdir string // temporary work dir ($WORK)
+ log bytes.Buffer // test execution log (printed at end of test)
+ mark int // offset of next log truncation
+ cd string // current directory during test execution; initially $WORK/gopath/src
+ name string // short name of test ("foo")
+ file string // full file name ("testdata/script/foo.txt")
+ lineno int // line number currently executing
+ line string // line currently executing
+ env []string // environment list (for os/exec)
+ envMap map[string]string // environment mapping (matches env)
+ stdout string // standard output from last 'go' command; for 'stdout' command
+ stderr string // standard error from last 'go' command; for 'stderr' command
+ stopped bool // test wants to stop early
+ start time.Time // time phase started
+ background []backgroundCmd // backgrounded 'exec' and 'go' commands
+}
+
+type backgroundCmd struct {
+ cmd *exec.Cmd
+ wait <-chan struct{}
+ neg bool // if true, cmd should fail
 }
 
 var extraEnvKeys = []string{
@@ -146,6 +154,17 @@ func (ts *testScript) run() {
  }
 
  defer func() {
+ // On a normal exit from the test loop, background processes are cleaned up
+ // before we print PASS. If we return early (e.g., due to a test failure),
+ // don't print anything about the processes that were still running.
+ for _, bg := range ts.background {
+ interruptProcess(bg.cmd.Process)
+ }
+ for _, bg := range ts.background {
+ <-bg.wait
+ }
+ ts.background = nil
+
  markTime()
  // Flush testScript log to testing.T log.
  ts.t.Log("\n" + ts.abbrev(ts.log.String()))
@@ -284,14 +303,23 @@ Script:
 
  // Command can ask script to stop early.
  if ts.stopped {
- return
+ // Break instead of returning, so that we check the status of any
+ // background processes and print PASS.
+ break
  }
  }
 
+ for _, bg := range ts.background {
+ interruptProcess(bg.cmd.Process)
+ }
+ ts.cmdWait(false, nil)
+
  // Final phase ended.
  rewind()
  markTime()
- fmt.Fprintf(&ts.log, "PASS\n")
+ if !ts.stopped {
+ fmt.Fprintf(&ts.log, "PASS\n")
+ }
 }
 
 // scriptCmds are the script command implementations.
@@ -317,6 +345,7 @@ var scriptCmds = map[string]func(*testScript, bool, []string){
  "stdout": (*testScript).cmdStdout,
  "stop": (*testScript).cmdStop,
  "symlink": (*testScript).cmdSymlink,
+ "wait": (*testScript).cmdWait,
 }
 
 // addcrlf adds CRLF line endings to the named files.
@@ -451,26 +480,43 @@ func (ts *testScript) cmdEnv(neg bool, args []string) {
 
 // exec runs the given command.
 func (ts *testScript) cmdExec(neg bool, args []string) {
- if len(args) < 1 {
- ts.fatalf("usage: exec program [args...]")
+ if len(args) < 1 || (len(args) == 1 && args[0] == "&") {
+ ts.fatalf("usage: exec program [args...] [&]")
  }
+
  var err error
- ts.stdout, ts.stderr, err = ts.exec(args[0], args[1:]...)
- if ts.stdout != "" {
- fmt.Fprintf(&ts.log, "[stdout]\n%s", ts.stdout)
- }
- if ts.stderr != "" {
- fmt.Fprintf(&ts.log, "[stderr]\n%s", ts.stderr)
+ if len(args) > 0 && args[len(args)-1] == "&" {
+ var cmd *exec.Cmd
+ cmd, err = ts.execBackground(args[0], args[1:len(args)-1]...)
+ if err == nil {
+ wait := make(chan struct{})
+ go func() {
+ ctxWait(testCtx, cmd)
+ close(wait)
+ }()
+ ts.background = append(ts.background, backgroundCmd{cmd, wait, neg})
+ }
+ ts.stdout, ts.stderr = "", ""
+ } else {
+ ts.stdout, ts.stderr, err = ts.exec(args[0], args[1:]...)
+ if ts.stdout != "" {
+ fmt.Fprintf(&ts.log, "[stdout]\n%s", ts.stdout)
+ }
+ if ts.stderr != "" {
+ fmt.Fprintf(&ts.log, "[stderr]\n%s", ts.stderr)
+ }
+ if err == nil && neg {
+ ts.fatalf("unexpected command success")
+ }
  }
+
  if err != nil {
  fmt.Fprintf(&ts.log, "[%v]\n", err)
- if !neg {
+ if testCtx.Err() != nil {
+ ts.fatalf("test timed out while running command")
+ } else if !neg {
  ts.fatalf("unexpected command failure")
  }
- } else {
- if neg {
- ts.fatalf("unexpected command success")
- }
  }
 }
 
@@ -545,6 +591,14 @@ func (ts *testScript) cmdSkip(neg bool, args []string) {
  if neg {
  ts.fatalf("unsupported: ! skip")
  }
+
+ // Before we mark the test as skipped, shut down any background processes and
+ // make sure they have returned the correct status.
+ for _, bg := range ts.background {
+ interruptProcess(bg.cmd.Process)
+ }
+ ts.cmdWait(false, nil)
+
  if len(args) == 1 {
  ts.t.Skip(args[0])
  }
@@ -687,6 +741,52 @@ func (ts *testScript) cmdSymlink(neg bool, args []string) {
  ts.check(os.Symlink(args[2], ts.mkabs(args[0])))
 }
 
+// wait waits for background commands to exit, setting stderr and stdout to their result.
+func (ts *testScript) cmdWait(neg bool, args []string) {
+ if neg {
+ ts.fatalf("unsupported: ! wait")
+ }
+ if len(args) > 0 {
+ ts.fatalf("usage: wait")
+ }
+
+ var stdouts, stderrs []string
+ for _, bg := range ts.background {
+ <-bg.wait
+
+ args := append([]string{filepath.Base(bg.cmd.Args[0])}, bg.cmd.Args[1:]...)
+ fmt.Fprintf(&ts.log, "[background] %s: %v\n", strings.Join(args, " "), bg.cmd.ProcessState)
+
+ cmdStdout := bg.cmd.Stdout.(*strings.Builder).String()
+ if cmdStdout != "" {
+ fmt.Fprintf(&ts.log, "[stdout]\n%s", cmdStdout)
+ stdouts = append(stdouts, cmdStdout)
+ }
+
+ cmdStderr := bg.cmd.Stderr.(*strings.Builder).String()
+ if cmdStderr != "" {
+ fmt.Fprintf(&ts.log, "[stderr]\n%s", cmdStderr)
+ stderrs = append(stderrs, cmdStderr)
+ }
+
+ if bg.cmd.ProcessState.Success() {
+ if bg.neg {
+ ts.fatalf("unexpected command success")
+ }
+ } else {
+ if testCtx.Err() != nil {
+ ts.fatalf("test timed out while running command")
+ } else if !bg.neg {
+ ts.fatalf("unexpected command failure")
+ }
+ }
+ }
+
+ ts.stdout = strings.Join(stdouts, "")
+ ts.stderr = strings.Join(stderrs, "")
+ ts.background = nil
+}
+
 // Helpers for command implementations.
 
 // abbrev abbreviates the actual work directory in the string s to the literal string "$WORK".
@@ -716,10 +816,51 @@ func (ts *testScript) exec(command string, args ...string) (stdout, stderr strin
  var stdoutBuf, stderrBuf strings.Builder
  cmd.Stdout = &stdoutBuf
  cmd.Stderr = &stderrBuf
- err = cmd.Run()
+ if err = cmd.Start(); err == nil {
+ err = ctxWait(testCtx, cmd)
+ }
  return stdoutBuf.String(), stderrBuf.String(), err
 }
 
+// execBackground starts the given command line (an actual subprocess, not simulated)
+// in ts.cd with environment ts.env.
+func (ts *testScript) execBackground(command string, args ...string) (*exec.Cmd, error) {
+ cmd := exec.Command(command, args...)
+ cmd.Dir = ts.cd
+ cmd.Env = append(ts.env, "PWD="+ts.cd)
+ var stdoutBuf, stderrBuf strings.Builder
+ cmd.Stdout = &stdoutBuf
+ cmd.Stderr = &stderrBuf
+ return cmd, cmd.Start()
+}
+
+// ctxWait is like cmd.Wait, but terminates cmd with os.Interrupt if ctx becomes done.
+//
+// This differs from exec.CommandContext in that it prefers os.Interrupt over os.Kill.
+// (See https://golang.org/issue/21135.)
+func ctxWait(ctx context.Context, cmd *exec.Cmd) error {
+ errc := make(chan error, 1)
+ go func() { errc <- cmd.Wait() }()
+
+ select {
+ case err := <-errc:
+ return err
+ case <-ctx.Done():
+ interruptProcess(cmd.Process)
+ return <-errc
+ }
+}
+
+// interruptProcess sends os.Interrupt to p if supported, or os.Kill otherwise.
+func interruptProcess(p *os.Process) {
+ if err := p.Signal(os.Interrupt); err != nil {
+ // Per https://golang.org/pkg/os/#Signal, “Interrupt is not implemented on
+ // Windows; using it with os.Process.Signal will return an error.”
+ // Fall back to Kill instead.
+ p.Kill()
+ }
+}
+
 // expand applies environment variable expansion to the string s.
 func (ts *testScript) expand(s string) string {
  return os.Expand(s, func(key string) string { return ts.envMap[key] })

src/cmd/go/testdata/script/README

@@ -99,16 +99,23 @@ The commands are:
  With no arguments, print the environment (useful for debugging).
  Otherwise add the listed key=value pairs to the environment.
 
-- [!] exec program [args...]
+- [!] exec program [args...] [&]
  Run the given executable program with the arguments.
  It must (or must not) succeed.
  Note that 'exec' does not terminate the script (unlike in Unix shells).
 
+ If the last token is '&', the program executes in the background. The standard
+ output and standard error of the previous command is cleared, but the output
+ of the background process is buffered — and checking of its exit status is
+ delayed — until the next call to 'wait', 'skip', or 'stop' or the end of the
+ test. At the end of the test, any remaining background processes are
+ terminated using os.Interrupt (if supported) or os.Kill.
+
 - [!] exists [-readonly] file...
  Each of the listed files or directories must (or must not) exist.
  If -readonly is given, the files or directories must be unwritable.
 
-- [!] go args...
+- [!] go args... [&]
  Run the (test copy of the) go command with the given arguments.
  It must (or must not) succeed.
 
@@ -131,18 +138,25 @@ The commands are:
 
 - [!] stderr [-count=N] pattern
  Apply the grep command (see above) to the standard error
- from the most recent exec or go command.
+ from the most recent exec, go, or wait command.
 
 - [!] stdout [-count=N] pattern
  Apply the grep command (see above) to the standard output
- from the most recent exec or go command.
+ from the most recent exec, go, or wait command.
 
 - stop [message]
  Stop the test early (marking it as passing), including the message if given.
 
 - symlink file -> target
  Create file as a symlink to target. The -> (like in ls -l output) is required.
 
+- wait
+ Wait for all 'exec' and 'go' commands started in the background (with the '&'
+ token) to exit, and display success or failure status for them.
+ After a call to wait, the 'stderr' and 'stdout' commands will apply to the
+ concatenation of the corresponding streams of the background commands,
+ in the order in which those commands were started.
+
 When TestScript runs a script and the script fails, by default TestScript shows
 the execution of the most recent phase of the script (since the last # comment)
 and only shows the # comments for earlier phases. For example, here is a