jiri/runutil: clarify comments on output handing for sequence and add unit test
This change adds a test case to sequence_test to verify the various
combinations of stdout/stderr settings (there are three places where one
can set these for a given sequence, and each one is handled slightly
differently). Informed by the behavior observed in the test, updated
the comments on the Sequence to more precisely describe where the output
goes. Also fix the comments around Opts() since Opts also applies only
to the next Run/Last and not all subsequent Run/Lasts (there's even
logic in TestSequenceModifiers to verify this behavior).
Note, this CL doesn't change any actual behavior in the Sequence
package. However, I think a follow-up CL is due to actually simplify
things: for example, I think allowing Opts to specify stdout and stderr
is unnecessary and only adds complexity. Vast majority of use cases should
be handled by specifying stdout and stderr just once in NewSequence, and
then using Capture as needed.
Another change that's sensible is to always dump the command's stdout
and stderr to the sequence's stdout when in verbose mode or if the
command fails, even if Capture is used on the command.
Change-Id: Iac8fdf491b659ddf2ab79b593f70757551c6d99c
diff --git a/runutil/executor.go b/runutil/executor.go
index 44a18e9..31f2fff 100644
--- a/runutil/executor.go
+++ b/runutil/executor.go
@@ -204,13 +204,11 @@
}
fmt.Fprintf(e.opts.Stderr, "Waiting for command to exit: %q\n", command.Args)
// Give the process some time to shut down cleanly.
- for i := 0; i < 10; i++ {
- select {
- case <-time.After(time.Second):
- if err := syscall.Kill(pid, 0); err != nil {
- return
- }
+ for i := 0; i < 50; i++ {
+ if err := syscall.Kill(pid, 0); err != nil {
+ return
}
+ time.Sleep(200 * time.Millisecond)
}
// If it still exists, send SIGKILL to it.
if err := syscall.Kill(pid, 0); err == nil {
diff --git a/runutil/sequence.go b/runutil/sequence.go
index 34f0533..ab280bf 100644
--- a/runutil/sequence.go
+++ b/runutil/sequence.go
@@ -24,16 +24,17 @@
// methods and the result of that first error is returned by the
// Done method or any of the other 'terminating methods' (see below).
//
-// When not in verbose mode (set either via NewSequence or an Opt) output
-// from commands will be suppressed unless they return an error. When
-// verbose mode is set, all output is written to the supplied stdout
-// and stderr.
+// Unless directed to specific stdout and stderr io.Writers using Capture(), the
+// stdout and stderr output from the command is discarded, except in verbose
+// mode or upon error: when in verbose mode (set either via NewSequence or an
+// Opt) or when the command fails, all the command's output (stdout and stderr)
+// is written to the stdout io.Writer configured either via NewSequence or an
+// Opt. In addition, in verbose mode, command execution logging is written to
+// the stdout and stderr io.Writers configured via NewSequence.
//
// Modifier methods are provided that influence the behaviour of the
-// next invocation of the Run method to set timeouts (Timeout) and to
-// capture output (Capture), an additional modifier method (Opts) is
-// provided the set the options for the remaining methods and is generally
-// used to control logging.
+// next invocation of the Run method to set timeouts (Timeout), to
+// capture output (Capture), an set options (Opts).
// For example, the following will result in a timeout error.
//
// err := s.Timed(time.Second).Run("sleep","10").Done()
@@ -71,9 +72,9 @@
return &Sequence{r: NewRun(env, stdin, stdout, stderr, color, dryRun, verbose)}
}
-// Capture arranges for the next call to Run to write its stdout and stderr
-// output to the supplied io.Writers. This will be cleared and not used for
-// any calls to Run beyond the next one.
+// Capture arranges for the next call to Run or Last to write its stdout and
+// stderr output to the supplied io.Writers. This will be cleared and not used
+// for any calls to Run or Last beyond the next one.
func (s *Sequence) Capture(stdout, stderr io.Writer) *Sequence {
if s.err != nil {
return s
@@ -82,8 +83,9 @@
return s
}
-// Opts arranges for the next call to Run to use the supplied options.
-// They will be cleared and not used for any calls to Run beyond the next one.
+// Opts arranges for the next call to Run or Last to use the supplied options.
+// This will be cleared and not used for any calls to Run or Last beyond the
+// next one.
func (s *Sequence) Opts(opts Opts) *Sequence {
if s.err != nil {
return s
@@ -92,9 +94,9 @@
return s
}
-// Timeout arranges for the next call to Run to be subject to the specified
-// timeout. The timeout will be cleared and not used any calls to Run beyond
-// the next one.
+// Timeout arranges for the next call to Run or Last to be subject to the
+// specified timeout. The timeout will be cleared and not used any calls to Run
+// or Last beyond the next one.
func (s *Sequence) Timeout(timeout time.Duration) *Sequence {
if s.err != nil {
return s
diff --git a/runutil/sequence_test.go b/runutil/sequence_test.go
index 92f8b9d..d91294e 100644
--- a/runutil/sequence_test.go
+++ b/runutil/sequence_test.go
@@ -18,11 +18,16 @@
"v.io/jiri/runutil"
)
-func rmLineNumbers(pattern, s string) string {
- re := regexp.MustCompile("(.*.go):" + pattern + ":(.*)")
+func rmLineNumbers(s string) string {
+ re := regexp.MustCompile("(.*\\.go):\\d+:(.*)")
return re.ReplaceAllString(s, "$1:-:$2")
}
+func sanitizeTimestamps(s string) string {
+ re := regexp.MustCompile(`\[(\d\d:\d\d:\d\d.\d\d)\]`)
+ return re.ReplaceAllString(s, "[hh:mm:ss.xx]")
+}
+
func ExampleSequence() {
seq := runutil.NewSequence(nil, os.Stdin, ioutil.Discard, ioutil.Discard, false, false, true)
err := seq.
@@ -33,13 +38,147 @@
Run("xxxxxxx").
Capture(os.Stdout, nil).Last("echo", "d")
// Get rid of the line#s in the error output.
- fmt.Println(rmLineNumbers("3.", err.Error()))
+ fmt.Println(rmLineNumbers(err.Error()))
// Output:
// a
// b
// sequence_test.go:-: Run("xxxxxxx"): exec: "xxxxxxx": executable file not found in $PATH
}
+// TestStdoutStderr exercises the various possible configurations for stdout and
+// stderr (via NewSequence, Opts, or Capture) as well as the verbose flag.
+func TestStdoutStderr(t *testing.T) {
+ // Case 1: we only specify stdout/stderr at constructor time.
+ //
+ // Verbose mode: All the command's output and execution logging goes to
+ // stdout, execution error messages to stderr.
+ //
+ // Non-Verbose mode: No stdout output; execution error messages to
+ // stderr.
+ for _, verbose := range []bool{false, true} {
+ var cnstrStdout, cnstrStderr bytes.Buffer
+ seq := runutil.NewSequence(nil, os.Stdin, &cnstrStdout, &cnstrStderr, false, false, verbose)
+ seq.Run("bash", "-c", "echo a; echo b >&2").
+ Timeout(time.Microsecond).
+ Run("sleep", "10000")
+ want := ""
+ if verbose {
+ want = `[hh:mm:ss.xx] >> bash -c "echo a; echo b >&2"
+[hh:mm:ss.xx] >> OK
+a
+b
+[hh:mm:ss.xx] >> sleep 10000
+[hh:mm:ss.xx] >> TIMED OUT
+`
+ }
+ if got := sanitizeTimestamps(cnstrStdout.String()); want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ if got, want := cnstrStderr.String(), "Waiting for command to exit: [\"sleep\" \"10000\"]\n"; want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ }
+
+ // Case 2: we specify stdout/stderr at constructor time, and also via
+ // Opts. The verbose setting from opts takes precedence and controls
+ // the output that goes both to constructor stdout and to opts stdout.
+ //
+ // Verbose mode: The command execution logging goes to constructor
+ // stdout, command execution errors go to constructor stderr, and the
+ // actual command output goes to opts stdout. Nothing goes to opts
+ // stderr.
+ //
+ // Non-Verbose mode: No stdout output; execution error messages to
+ // constructor stderr.
+ for _, verbose := range []bool{false, true} {
+ var cnstrStdout, cnstrStderr, optsStdout, optsStderr bytes.Buffer
+ cstrVerbose := false // irellevant, the opts verbose flag takes precedence.
+ seq := runutil.NewSequence(nil, os.Stdin, &cnstrStdout, &cnstrStderr, false, false, cstrVerbose)
+ opts := runutil.Opts{Stdout: &optsStdout, Stderr: &optsStderr, Verbose: verbose}
+ seq.Opts(opts).
+ Run("bash", "-c", "echo a; echo b >&2").
+ Opts(opts).
+ Timeout(time.Microsecond).
+ Run("sleep", "10000")
+ want := ""
+ if verbose {
+ want = `[hh:mm:ss.xx] >> bash -c "echo a; echo b >&2"
+[hh:mm:ss.xx] >> OK
+[hh:mm:ss.xx] >> sleep 10000
+[hh:mm:ss.xx] >> TIMED OUT
+`
+ }
+ if got := sanitizeTimestamps(cnstrStdout.String()); want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ if got, want := cnstrStderr.String(), "Waiting for command to exit: [\"sleep\" \"10000\"]\n"; want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ want = ""
+ if verbose {
+ want = "a\nb\n"
+ }
+ if got := optsStdout.String(); want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ if got, want := optsStderr.String(), ""; want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ }
+
+ // Case 3: we specify stdout/stderr at constructor time, also via Opts,
+ // and also via Capture. The verbose setting from opts takes
+ // precedence.
+ //
+ // Verbose mode: The command execution log goes to constructor stdout,
+ // command execution errors go to constructor stderr, and the
+ // stdout/stderr output from the command goes to capture stdout/stderr
+ // respectively. Nothing goes to opts stdout/stderr.
+ //
+ // Non-Verbose mode: The stdout/stderr output from the command goes to
+ // capture stdout/stderr respectively. No command execution log, but
+ // the command execution errors go to constructor stderr. Nothing goes
+ // to opts stdout/stderr.
+ for _, verbose := range []bool{false, true} {
+ var cnstrStdout, cnstrStderr, optsStdout, optsStderr, captureStdout, captureStderr bytes.Buffer
+ cstrVerbose := false // irellevant, the opts verbose flag takes precedence.
+ seq := runutil.NewSequence(nil, os.Stdin, &cnstrStdout, &cnstrStderr, false, false, cstrVerbose)
+ opts := runutil.Opts{Stdout: &optsStdout, Stderr: &optsStderr, Verbose: verbose}
+ seq.Opts(opts).
+ Capture(&captureStdout, &captureStderr).
+ Run("bash", "-c", "echo a; echo b >&2").
+ Opts(opts).
+ Timeout(time.Microsecond).
+ Run("sleep", "10000")
+ want := ""
+ if verbose {
+ want = `[hh:mm:ss.xx] >> bash -c "echo a; echo b >&2"
+[hh:mm:ss.xx] >> OK
+[hh:mm:ss.xx] >> sleep 10000
+[hh:mm:ss.xx] >> TIMED OUT
+`
+ }
+ if got := sanitizeTimestamps(cnstrStdout.String()); want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ if got, want := cnstrStderr.String(), "Waiting for command to exit: [\"sleep\" \"10000\"]\n"; want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ if got, want := optsStdout.String(), ""; want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ if got, want := optsStderr.String(), ""; want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ if got, want := captureStdout.String(), "a\n"; want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ if got, want := captureStderr.String(), "b\n"; want != got {
+ t.Errorf("verbose: %t, got %v, want %v", verbose, got, want)
+ }
+ }
+}
+
func TestSequence(t *testing.T) {
seq := runutil.NewSequence(nil, os.Stdin, os.Stdout, os.Stderr, false, false, true)
if got, want := seq.Run("echo", "a").Done(), error(nil); got != want {
@@ -77,7 +216,7 @@
if err == nil {
t.Fatalf("should have experience an error")
}
- if got, want := rmLineNumbers("7.", err.Error()), "sequence_test.go:-: Run(\"./bound-to-fail\", \"fail\"): fork/exec ./bound-to-fail: no such file or directory"; got != want {
+ if got, want := rmLineNumbers(err.Error()), "sequence_test.go:-: Run(\"./bound-to-fail\", \"fail\"): fork/exec ./bound-to-fail: no such file or directory"; got != want {
t.Errorf("got %v, want %v", got, want)
}
err = seq.
@@ -90,7 +229,7 @@
}
out.Reset()
err = seq.Timeout(time.Second).Run("sleep", "10").Done()
- if got, want := rmLineNumbers("9.", err.Error()), "sequence_test.go:-: Run(\"sleep\", \"10\"): command timed out"; got != want {
+ if got, want := rmLineNumbers(err.Error()), "sequence_test.go:-: Run(\"sleep\", \"10\"): command timed out"; got != want {
t.Errorf("got %v, want %v", got, want)
}
