Merge #143387

143387: roachtest: detect sysbench crashes when preparing workload r=srosenberg a=DarrylWong

Sysbench is known to flake with crashes. Previously, we would detect these crashes when running the workload and pass the run to avoid noise.

This change now does the same when preparing the workload as well. It also skips the test instead of passing the test. This makes it easier to identify tests that actually ran to completion and has consequences for test selection.

We also add a small helper to prefix sysbench output with timestamps, this should aid debugging.

Fixes: #141981
Informs: #140799
Release note: none

Co-authored-by: DarrylWong <[email protected]>

Author: craig[bot]

pkg/cmd/roachtest/roachtestutil/utils.go

@@ -279,3 +279,12 @@ func PortLatency(
 	}
 	return time.Duration(avgRTT * float64(time.Second)), nil
 }
+
+// PrefixCmdOutputWithTimestamp wraps a remote command such that it pipes
+// stdout and stderr through awk and prepends the timestamp. Can be used to aid
+// debugging long-running commands that don't already prefix output with timestamps.
+func PrefixCmdOutputWithTimestamp(cmd string) string {
+	// Don't prefix blank lines with timestamps.
+	awkCmd := `awk 'NF { cmd="date +\"%H:%M:%S\""; cmd | getline ts; close(cmd); print ts ":", $0; next } { print }'`
+	return fmt.Sprintf(`bash -c '%s' 2>&1 |`, cmd) + awkCmd
+}

pkg/cmd/roachtest/tests/sysbench.go

@@ -195,9 +195,11 @@ func runSysbench(ctx context.Context, t test.Test, c cluster.Cluster, opts sysbe
 		t.Status("preparing workload")
 		cmd := opts.cmd(useHAProxy /* haproxy */)
 		{
-			result, err := c.RunWithDetailsSingleNode(ctx, t.L(), option.WithNodes(c.WorkloadNode()), cmd+" prepare")
+			result, err := c.RunWithDetailsSingleNode(ctx, t.L(), option.WithNodes(c.WorkloadNode()), roachtestutil.PrefixCmdOutputWithTimestamp(cmd+" prepare"))
 			if err != nil {
 				return err
+			} else if msg, crashed := detectSysbenchCrash(result); crashed {
+				t.Skipf("%s; skipping test", msg)
 			} else if strings.Contains(result.Stdout, "FATAL") {
 				// sysbench prepare doesn't exit on errors for some reason, so we have
 				// to check that it didn't silently fail. We've seen it do so, causing
@@ -225,11 +227,10 @@ func runSysbench(ctx context.Context, t test.Test, c cluster.Cluster, opts sysbe
 
 		t.Status("running workload")
 		start = timeutil.Now()
-		result, err := c.RunWithDetailsSingleNode(ctx, t.L(), option.WithNodes(c.WorkloadNode()), cmd+" run")
+		result, err := c.RunWithDetailsSingleNode(ctx, t.L(), option.WithNodes(c.WorkloadNode()), roachtestutil.PrefixCmdOutputWithTimestamp(cmd+" run"))
 
 		if msg, crashed := detectSysbenchCrash(result); crashed {
-			t.L().Printf("%s; passing test anyway", msg)
-			return nil
+			t.Skipf("%s; skipping test", msg)
 		}
 
 		if err != nil {