tools: test-runner add TIME column

Shows the net time spent waiting for tint & validators to complete the test run
Helps identify the slow compilers

Change-Id: I3e915762fdb4dc56f02320d7f5e0e13f7cb83d78
Reviewed-on: https://dawn-review.googlesource.com/c/tint/+/60343
Kokoro: Kokoro <noreply+kokoro@google.com>
Auto-Submit: Ben Clayton <bclayton@google.com>
Reviewed-by: Antonio Maiorano <amaiorano@google.com>
Commit-Queue: Antonio Maiorano <amaiorano@google.com>

tools/src/cmd/test-runner/main.go

@@ -249,13 +249,13 @@ func run() error {
 
 	type stats struct {
 		numTests, numPass, numSkip, numFail int
+		timeTaken                           time.Duration
 	}
 
 	// Statistics per output format
 	statsByFmt := map[outputFormat]*stats{}
 	for _, format := range formats {
 		statsByFmt[format] = &stats{}
-
 	}
 
 	// Print the table of file x format and gather per-format stats
@@ -313,6 +313,7 @@ func run() error {
 			result := <-results[format]
 			stats := statsByFmt[format]
 			stats.numTests++
+			stats.timeTaken += result.timeTaken
 			if err := result.err; err != nil {
 				failures = append(failures, failure{
 					file: file, format: format, err: err,
@@ -386,6 +387,14 @@ func run() error {
 	printStat(green, "PASS", func(s *stats) int { return s.numPass })
 	printStat(yellow, "SKIP", func(s *stats) int { return s.numSkip })
 	printStat(red, "FAIL", func(s *stats) int { return s.numFail })
+
+	cyan.Printf(alignRight("TIME", filenameColumnWidth))
+	fmt.Printf(" ┃ ")
+	for _, format := range formats {
+		timeTaken := printDuration(statsByFmt[format].timeTaken)
+		cyan.Printf(alignLeft(timeTaken, formatWidth(format)))
+		fmt.Printf(" │ ")
+	}
 	fmt.Println()
 
 	for _, f := range failures {
@@ -456,8 +465,9 @@ const (
 )
 
 type status struct {
-	code statusCode
-	err  error
+	code      statusCode
+	err       error
+	timeTaken time.Duration
 }
 
 type job struct {
@@ -515,7 +525,10 @@ func (j job) run(wd, exe string, fxc bool, dxcPath, xcrunPath string, generateEx
 		}
 
 		// Invoke the compiler...
+		start := time.Now()
 		ok, out := invoke(wd, exe, args...)
+		timeTaken := time.Since(start)
+
 		out = strings.ReplaceAll(out, "\r\n", "\n")
 		matched := expected == "" || expected == out
 
@@ -527,7 +540,7 @@ func (j job) run(wd, exe string, fxc bool, dxcPath, xcrunPath string, generateEx
 		switch {
 		case ok && matched:
 			// Test passed
-			return status{code: pass}
+			return status{code: pass, timeTaken: timeTaken}
 
 			//       --- Below this point the test has failed ---
 
@@ -535,7 +548,7 @@ func (j job) run(wd, exe string, fxc bool, dxcPath, xcrunPath string, generateEx
 			if generateSkip {
 				saveExpectedFile(j.file, j.format, "SKIP: FAILED\n\n"+out)
 			}
-			return status{code: skip}
+			return status{code: skip, timeTaken: timeTaken}
 
 		case !ok:
 			// Compiler returned non-zero exit code
@@ -543,7 +556,7 @@ func (j job) run(wd, exe string, fxc bool, dxcPath, xcrunPath string, generateEx
 				saveExpectedFile(j.file, j.format, "SKIP: FAILED\n\n"+out)
 			}
 			err := fmt.Errorf("%s", out)
-			return status{code: fail, err: err}
+			return status{code: fail, err: err, timeTaken: timeTaken}
 
 		default:
 			// Compiler returned zero exit code, or output was not as expected
@@ -571,7 +584,7 @@ func (j job) run(wd, exe string, fxc bool, dxcPath, xcrunPath string, generateEx
 --------------------------------------------------------------------------------
 %s`,
 				expected, out, diff)
-			return status{code: fail, err: err}
+			return status{code: fail, err: err, timeTaken: timeTaken}
 		}
 	}()
 }
@@ -610,6 +623,9 @@ func indent(s string, n int) string {
 func alignLeft(val interface{}, width int) string {
 	s := fmt.Sprint(val)
 	padding := width - utf8.RuneCountInString(s)
+	if padding < 0 {
+		return s
+	}
 	return s + strings.Repeat(" ", padding)
 }
 
@@ -618,6 +634,9 @@ func alignLeft(val interface{}, width int) string {
 func alignCenter(val interface{}, width int) string {
 	s := fmt.Sprint(val)
 	padding := width - utf8.RuneCountInString(s)
+	if padding < 0 {
+		return s
+	}
 	return strings.Repeat(" ", padding/2) + s + strings.Repeat(" ", (padding+1)/2)
 }
 
@@ -626,6 +645,9 @@ func alignCenter(val interface{}, width int) string {
 func alignRight(val interface{}, width int) string {
 	s := fmt.Sprint(val)
 	padding := width - utf8.RuneCountInString(s)
+	if padding < 0 {
+		return s
+	}
 	return strings.Repeat(" ", padding) + s
 }
 
@@ -680,3 +702,22 @@ func invoke(wd, exe string, args ...string) (ok bool, output string) {
 	}
 	return true, str
 }
+
+func printDuration(d time.Duration) string {
+	sec := int(d.Seconds())
+	min := int(sec) / 60
+	hour := min / 60
+	min -= hour * 60
+	sec -= min * 60
+	sb := &strings.Builder{}
+	if hour > 0 {
+		fmt.Fprintf(sb, "%dh", hour)
+	}
+	if min > 0 {
+		fmt.Fprintf(sb, "%dm", min)
+	}
+	if sec > 0 {
+		fmt.Fprintf(sb, "%ds", sec)
+	}
+	return sb.String()
+}