tast: Validate control message ordering.
Make the tast command validate the ordering of control
messages that it receives from the test executable.
BUG=chromium:778389
TEST=added unit tests
Change-Id: Ie225738896b0784d8803f742feb7fe8c0d9f918f
Reviewed-on: https://chromium-review.googlesource.com/769107
Commit-Ready: Dan Erat <derat@chromium.org>
Tested-by: Dan Erat <derat@chromium.org>
Reviewed-by: Jason Clinton <jclinton@chromium.org>
diff --git a/src/chromiumos/tast/cmd/run/results.go b/src/chromiumos/tast/cmd/run/results.go
index 0586102..8f6f695 100644
--- a/src/chromiumos/tast/cmd/run/results.go
+++ b/src/chromiumos/tast/cmd/run/results.go
@@ -63,11 +63,12 @@
ctx context.Context
cfg *Config
- numTests int // total number of tests that are expected to run
- results []testResult // information about completed tests
- res *testResult // information about the currently-running test
- stage *timing.Stage // current test's timing stage
- crf copyAndRemoveFunc // function used to copy and remove files from DUT
+ runStart, runEnd time.Time // test-binary-reported times at which run started and ended
+ numTests int // total number of tests that are expected to run
+ results []testResult // information about completed tests
+ res *testResult // information about the currently-running test
+ stage *timing.Stage // current test's timing stage
+ crf copyAndRemoveFunc // function used to copy and remove files from DUT
}
func (r *resultsHandler) close() {
@@ -88,6 +89,10 @@
// handleRunStart handles RunStart control messages from test executables.
func (r *resultsHandler) handleRunStart(msg *control.RunStart) error {
+ if !r.runStart.IsZero() {
+ return errors.New("multiple RunStart messages")
+ }
+ r.runStart = msg.Time
r.numTests = msg.NumTests
r.setProgress("Starting testing")
return nil
@@ -107,6 +112,17 @@
// handleRunEnd handles RunEnd control messages from test executables.
func (r *resultsHandler) handleRunEnd(msg *control.RunEnd) error {
+ if r.runStart.IsZero() {
+ return errors.New("no RunStart message before RunEnd")
+ }
+ if r.res != nil {
+ return fmt.Errorf("got RunEnd message while %s still running", r.res.Name)
+ }
+ if !r.runEnd.IsZero() {
+ return errors.New("multiple RunEnd messages")
+ }
+ r.runEnd = msg.Time
+
if len(msg.LogDir) != 0 {
r.setProgress("Copying system logs")
if err := r.crf(msg.LogDir, filepath.Join(r.cfg.ResDir, systemLogsDir)); err != nil {
@@ -135,8 +151,11 @@
msg.Test.Name = msg.Name
}
+ if r.runStart.IsZero() {
+ return errors.New("no RunStart message before TestStart")
+ }
if r.res != nil {
- return fmt.Errorf("notified about start of %s while %s still running",
+ return fmt.Errorf("got TestStart message for %s while %s still running",
msg.Test.Name, r.res.Name)
}
if tl, ok := timing.FromContext(r.ctx); ok {
@@ -176,7 +195,7 @@
// handleTestError handles TestError control messages from test executables.
func (r *resultsHandler) handleTestError(msg *control.TestError) error {
if r.res == nil {
- return errors.New("notified about test error while no test was running")
+ return errors.New("got TestError message while no test was running")
}
te := msg.Error
@@ -195,7 +214,7 @@
// handleTestEnd handles TestEnd control messages from test executables.
func (r *resultsHandler) handleTestEnd(msg *control.TestEnd) error {
if r.res == nil || msg.Name != r.res.Name {
- return fmt.Errorf("notified about completion of not-started test %s", msg.Name)
+ return fmt.Errorf("got TestEnd message for not-started test %s", msg.Name)
}
if r.stage != nil {
r.stage.End()
@@ -413,7 +432,12 @@
return err
}
- // TODO(derat): Check that RunStart and RunEnd messages were received and that the
- // number of TestStart/TestEnd pairs matched the number specified in RunStart.
+ if rh.runEnd.IsZero() {
+ return errors.New("no RunEnd message")
+ }
+ if len(rh.results) != rh.numTests {
+ return fmt.Errorf("got results for %v test(s); expected %v", len(rh.results), rh.numTests)
+ }
+
return nil
}
diff --git a/src/chromiumos/tast/cmd/run/results_test.go b/src/chromiumos/tast/cmd/run/results_test.go
index 0bdd185..e816fc3 100644
--- a/src/chromiumos/tast/cmd/run/results_test.go
+++ b/src/chromiumos/tast/cmd/run/results_test.go
@@ -123,6 +123,81 @@
// TODO(derat): Check more output, including run errors.
}
+func TestValidateMessages(t *gotesting.T) {
+ tempDir := testutil.TempDir(t, "results_test.")
+ defer os.RemoveAll(tempDir)
+
+ for _, tc := range []struct {
+ desc string
+ msgs []interface{}
+ }{
+ {"no RunStart", []interface{}{
+ &control.RunEnd{time.Unix(1, 0), "", ""},
+ }},
+ {"multiple RunStart", []interface{}{
+ &control.RunStart{time.Unix(1, 0), 0},
+ &control.RunStart{time.Unix(2, 0), 0},
+ &control.RunEnd{time.Unix(3, 0), "", ""},
+ }},
+ {"no RunEnd", []interface{}{
+ &control.RunStart{time.Unix(1, 0), 0},
+ }},
+ {"multiple RunEnd", []interface{}{
+ &control.RunStart{time.Unix(1, 0), 0},
+ &control.RunEnd{time.Unix(2, 0), "", ""},
+ &control.RunEnd{time.Unix(3, 0), "", ""},
+ }},
+ {"num tests mismatch", []interface{}{
+ &control.RunStart{time.Unix(1, 0), 1},
+ &control.RunEnd{time.Unix(2, 0), "", ""},
+ }},
+ {"unfinished test", []interface{}{
+ &control.RunStart{time.Unix(1, 0), 1},
+ &control.TestStart{time.Unix(2, 0), "test1", testing.Test{Name: "test1"}},
+ &control.TestEnd{time.Unix(3, 0), "test1"},
+ &control.TestStart{time.Unix(4, 0), "test2", testing.Test{Name: "test2"}},
+ &control.RunEnd{time.Unix(5, 0), "", ""},
+ }},
+ {"TestStart before RunStart", []interface{}{
+ &control.TestStart{time.Unix(1, 0), "test1", testing.Test{Name: "test1"}},
+ &control.RunStart{time.Unix(2, 0), 1},
+ &control.TestEnd{time.Unix(3, 0), "test1"},
+ &control.RunEnd{time.Unix(4, 0), "", ""},
+ }},
+ {"TestError without TestStart", []interface{}{
+ &control.RunStart{time.Unix(1, 0), 0},
+ &control.TestError{time.Unix(2, 0), testing.Error{}},
+ &control.RunEnd{time.Unix(3, 0), "", ""},
+ }},
+ {"wrong TestEnd", []interface{}{
+ &control.RunStart{time.Unix(1, 0), 0},
+ &control.TestStart{time.Unix(2, 0), "test1", testing.Test{Name: "test1"}},
+ &control.TestEnd{time.Unix(3, 0), "test2"},
+ &control.RunEnd{time.Unix(3, 0), "", ""},
+ }},
+ {"no TestEnd", []interface{}{
+ &control.RunStart{time.Unix(1, 0), 2},
+ &control.TestStart{time.Unix(2, 0), "test1", testing.Test{Name: "test1"}},
+ &control.TestStart{time.Unix(3, 0), "test2", testing.Test{Name: "test2"}},
+ &control.TestEnd{time.Unix(4, 0), "test2"},
+ &control.RunEnd{time.Unix(5, 0), "", ""},
+ }},
+ } {
+ b := bytes.Buffer{}
+ mw := control.NewMessageWriter(&b)
+ for _, msg := range tc.msgs {
+ mw.WriteMessage(msg)
+ }
+ cfg := Config{
+ Logger: logging.NewSimple(&bytes.Buffer{}, 0, false),
+ ResDir: filepath.Join(tempDir, tc.desc),
+ }
+ if err := readTestOutput(context.Background(), &cfg, &b, noOpCopyAndRemove); err == nil {
+ t.Errorf("readTestOutput() didn't fail for %s", tc.desc)
+ }
+ }
+}
+
func TestReadTestOutputTimeout(t *gotesting.T) {
tempDir := testutil.TempDir(t, "results_test.")
defer os.RemoveAll(tempDir)
