From: Bryan C. Mills Date: Wed, 10 Oct 2018 20:37:00 +0000 (-0400) Subject: cmd/go: support background processes in TestScript X-Git-Tag: go1.12beta1~602 X-Git-Url: http://www.git.cypherpunks.su/?a=commitdiff_plain;h=d76b1cdf286551a81fd4c1012cbf8686d344cc32;p=gostls13.git 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 TryBot-Result: Gobot Gobot Reviewed-by: Ian Lance Taylor Reviewed-by: Russ Cox --- diff --git a/src/cmd/go/go_test.go b/src/cmd/go/go_test.go index 139ee73ae0..aa6ce27ffc 100644 --- a/src/cmd/go/go_test.go +++ b/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 {} diff --git a/src/cmd/go/script_test.go b/src/cmd/go/script_test.go index 8708dacd41..f03d9840ca 100644 --- a/src/cmd/go/script_test.go +++ b/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] }) diff --git a/src/cmd/go/testdata/script/README b/src/cmd/go/testdata/script/README index a80233b8c3..f28f1b87ed 100644 --- a/src/cmd/go/testdata/script/README +++ b/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,11 +138,11 @@ 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. @@ -143,6 +150,13 @@ The commands are: - 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 diff --git a/src/cmd/go/testdata/script/script_wait.txt b/src/cmd/go/testdata/script/script_wait.txt new file mode 100644 index 0000000000..0770b39523 --- /dev/null +++ b/src/cmd/go/testdata/script/script_wait.txt @@ -0,0 +1,22 @@ +[!exec:echo] skip +[!exec:false] skip + +exec echo foo +stdout foo + +exec echo foo & +exec echo bar & +! exec false & + +# Starting a background process should clear previous output. +! stdout foo + +# Wait should set the output to the concatenated outputs of the background +# programs, in the order in which they were started. +wait +stdout 'foo\nbar' + +# The end of the test should interrupt or kill any remaining background +# programs. +[!exec:sleep] skip +! exec sleep 86400 &