Skip to content

Commit

Permalink
Add test stats to GHA summary
Browse files Browse the repository at this point in the history
Signed-off-by: Brian Goff <[email protected]>
  • Loading branch information
cpuguy83 committed Nov 4, 2024
1 parent ea065c3 commit 4754f3b
Show file tree
Hide file tree
Showing 7 changed files with 205 additions and 53 deletions.
3 changes: 1 addition & 2 deletions .github/workflows/ci.yml
Original file line number Diff line number Diff line change
Expand Up @@ -96,12 +96,11 @@ jobs:
- name: Precache base images
run: go run ./cmd/ci-precache
- name: Run integration tests
run: go test -v -json ./test | go run ./cmd/test2json2gha
run: go test -v -json ./test | go run ./cmd/test2json2gha --slow 5s
- name: dump logs
if: failure()
run: sudo journalctl -u docker


unit:
runs-on: ubuntu-22.04
steps:
Expand Down
56 changes: 56 additions & 0 deletions cmd/test2json2gha/event.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,56 @@
package main

import (
"os"
"time"

"github.com/pkg/errors"
)

// TestEvent is the go test2json event data structure we receive from `go test`
// This is defined in https://pkg.go.dev/cmd/test2json#hdr-Output_Format
type TestEvent struct {
Time time.Time
Action string
Package string
Test string
Elapsed float64 // seconds
Output string
}

// TestResult is where we collect all the data about a test
type TestResult struct {
output *os.File
failed bool
pkg string
name string
elapsed float64
skipped bool
}

func (r *TestResult) Close() {
r.output.Close()
}

func handlEvent(te *TestEvent, tr *TestResult) error {
if te.Output != "" {
_, err := tr.output.Write([]byte(te.Output))
if err != nil {
return errors.Wrap(err, "error collecting test event output")
}
}

tr.pkg = te.Package
tr.name = te.Test
if te.Elapsed > 0 {
tr.elapsed = te.Elapsed
}

if te.Action == "fail" {
tr.failed = true
}
if te.Action == "skip" {
tr.skipped = true
}
return nil
}
134 changes: 83 additions & 51 deletions cmd/test2json2gha/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ import (
"bufio"
"bytes"
"encoding/json"
"flag"
"fmt"
"io"
"log/slog"
Expand All @@ -15,6 +16,7 @@ import (
"time"

"github.com/pkg/errors"
"github.com/vearutop/dynhist-go"
)

func main() {
Expand All @@ -23,6 +25,11 @@ func main() {
panic(err)
}

var slowThreshold time.Duration
flag.DurationVar(&slowThreshold, "slow", 500*time.Millisecond, "Threshold to mark test as slow")

flag.Parse()

logger := slog.New(slog.NewTextHandler(os.Stderr, nil))
slog.SetDefault(logger)

Expand All @@ -38,7 +45,7 @@ func main() {

cleanup := func() { os.RemoveAll(tmp) }

anyFail, err := do(os.Stdin, os.Stdout, mod)
anyFail, err := do(os.Stdin, os.Stdout, mod, slowThreshold)
if err != nil {
fmt.Fprintf(os.Stderr, "%+v", err)
cleanup()
Expand All @@ -53,31 +60,7 @@ func main() {
}
}

// TestEvent is the go test2json event data structure we receive from `go test`
// This is defined in https://pkg.go.dev/cmd/test2json#hdr-Output_Format
type TestEvent struct {
Time time.Time
Action string
Package string
Test string
Elapsed float64 // seconds
Output string
}

// TestResult is where we collect all the data about a test
type TestResult struct {
output *os.File
failed bool
pkg string
name string
elapsed float64
}

func (r *TestResult) Close() {
r.output.Close()
}

func do(in io.Reader, out io.Writer, modName string) (bool, error) {
func do(in io.Reader, out io.Writer, modName string, slowThreshold time.Duration) (bool, error) {
dec := json.NewDecoder(in)

te := &TestEvent{}
Expand Down Expand Up @@ -128,14 +111,36 @@ func do(in io.Reader, out io.Writer, modName string) (bool, error) {
}

buf := bufio.NewWriter(out)
var anyFail bool

summaryF := getSummaryFile()
defer summaryF.Close()

var failCount, skipCount int
var elapsed float64

failBuf := bytes.NewBuffer(nil)
hist := &dynhist.Collector{
PrintSum: true,
WeightFunc: dynhist.ExpWidth(1.2, 0.9),
BucketsLimit: 10,
}

slowBuf := bytes.NewBuffer(nil)
slow := slowThreshold.Seconds()

for _, tr := range outs {
if tr.skipped {
skipCount++
}

if tr.failed {
anyFail = true
failCount++
}

if err := writeResult(tr, buf, modName); err != nil {
hist.Add(tr.elapsed)
elapsed += tr.elapsed

if err := writeResult(tr, buf, failBuf, slowBuf, slow, modName); err != nil {
slog.Error("Error writing result", "error", err)
continue
}
Expand All @@ -145,28 +150,41 @@ func do(in io.Reader, out io.Writer, modName string) (bool, error) {
}
}

return anyFail, nil
}
fmt.Fprintln(summaryF, "## Test metrics")
fmt.Fprintln(summaryF, mdBold("Skipped:"), skipCount, "\t", mdBold("Failed:"), failCount, "\t", mdBold("Total:"), len(outs), "\t", mdBold("Elapsed:"), fmt.Sprintf("%.3fs", elapsed))

func handlEvent(te *TestEvent, tr *TestResult) error {
if te.Output != "" {
_, err := tr.output.Write([]byte(te.Output))
if err != nil {
return errors.Wrap(err, "error collecting test event output")
}
fmt.Fprintln(summaryF, mdPreformat(hist.String()))

if failBuf.Len() > 0 {
fmt.Fprintln(summaryF, "## Failures")
fmt.Fprintln(summaryF, failBuf.String())
}

if slowBuf.Len() > 0 {
fmt.Fprintln(summaryF, "## Slow Tests")
fmt.Fprintln(summaryF, slowBuf.String())
}

tr.pkg = te.Package
tr.name = te.Test
tr.elapsed = te.Elapsed
return failCount > 0, nil
}

func (c *nopWriteCloser) Close() error { return nil }

if te.Action == "fail" {
tr.failed = true
func getSummaryFile() io.WriteCloser {
v := os.Getenv("GITHUB_STEP_SUMMARY")
if v == "" {
return &nopWriteCloser{io.Discard}
}
return nil

f, err := os.OpenFile(v, os.O_WRONLY|os.O_APPEND, 0)
if err != nil {
slog.Error("Error opening step summary file", "error", err)
return &nopWriteCloser{io.Discard}
}
return f
}

func writeResult(tr *TestResult, out io.Writer, modName string) error {
func writeResult(tr *TestResult, out, summary, slowBuf io.Writer, slow float64, modName string) error {
if tr.name == "" {
return nil
}
Expand All @@ -190,31 +208,44 @@ func writeResult(tr *TestResult, out io.Writer, modName string) error {
prefix = "\u274c "
}

dur := time.Duration(tr.elapsed * float64(time.Second))
fmt.Fprintln(out, "::group::"+prefix+group, dur)
fmt.Fprintf(out, "::group::%s %.3fs\n", prefix+group, tr.elapsed)
defer func() {
fmt.Fprintln(out, "::endgroup::")
}()

dt, err := io.ReadAll(tr.output)
if err != nil {
return fmt.Errorf("error reading test output: %w", err)
var rdr io.Reader = tr.output

if tr.elapsed > slow {
buf := bytes.NewBuffer(nil)
rdr = io.TeeReader(rdr, buf)
defer func() {
if buf.Len() > 0 {
fmt.Fprintln(slowBuf, mdLog(fmt.Sprintf("%s %.3fs", tr.name, tr.elapsed), buf))
}
}()
}

if !tr.failed {
if _, err := out.Write(dt); err != nil {
if _, err := io.Copy(out, rdr); err != nil {
return fmt.Errorf("error writing test output to output stream: %w", err)
}
return nil
}

scanner := bufio.NewScanner(bytes.NewReader(dt))
failBuf := bytes.NewBuffer(nil)
rdr = io.TeeReader(rdr, failBuf)
defer func() {
fmt.Fprintln(summary, mdLog(tr.name+fmt.Sprintf(" %3.f", tr.elapsed), failBuf))
}()

scanner := bufio.NewScanner(rdr)

var (
file, line string
)

buf := bytes.NewBuffer(nil)

for scanner.Scan() {
txt := scanner.Text()
f, l, ok := getTestOutputLoc(txt)
Expand All @@ -235,6 +266,7 @@ func writeResult(tr *TestResult, out io.Writer, modName string) error {

file = filepath.Join(pkg, file)
fmt.Fprintf(out, "::error file=%s,line=%s::%s\n", file, line, buf)

return nil
}

Expand Down
26 changes: 26 additions & 0 deletions cmd/test2json2gha/main_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,26 @@
package main

import (
"testing"
"time"
)

func TestFail(t *testing.T) {
t.Log("This is for checking what a test failure looks like")
t.Fatal("This is a failure")

Check failure on line 10 in cmd/test2json2gha/main_test.go

View workflow job for this annotation

GitHub Actions / unit

=== RUN TestFail main_test.go:9: This is for checking what a test failure looks like main_test.go:10: This is a failure --- FAIL: TestFail (0.00s)
}

func TestAnotherFail(t *testing.T) {
t.Log("This is for checking what a test failure looks like")
t.Fatal("This is yet another failure!")

Check failure on line 15 in cmd/test2json2gha/main_test.go

View workflow job for this annotation

GitHub Actions / unit

=== RUN TestAnotherFail main_test.go:14: This is for checking what a test failure looks like main_test.go:15: This is yet another failure! --- FAIL: TestAnotherFail (0.00s)
}

func TestSlow(t *testing.T) {
time.Sleep(10 * time.Second)
t.Log("This is a slow test!")
}

func TestAnothrSlow(t *testing.T) {
time.Sleep(5 * time.Second)
t.Log("This is yet another slow test!")
}
34 changes: 34 additions & 0 deletions cmd/test2json2gha/markdown.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,34 @@
package main

import (
"fmt"
"io"
"strings"
)

func mdBold(v string) string {
return "**" + v + "**"
}

func mdDetails(s string) string {
return fmt.Sprintf("\n<details>\n%s\n</details>\n", s)
}

func mdSummary(s string) string {
return "<summary>" + s + "</summary>\n"
}

func mdPreformat(s string) string {
return fmt.Sprintf("\n```\n%s\n```\n", s)
}

type nopWriteCloser struct {
io.Writer
}

func mdLog(head string, content fmt.Stringer) string {
sb := &strings.Builder{}
sb.WriteString(mdSummary(head))
sb.WriteString(mdPreformat(content.String()))
return mdDetails(sb.String())
}
1 change: 1 addition & 0 deletions go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ require (
github.com/sirupsen/logrus v1.9.3
github.com/stretchr/testify v1.9.0
github.com/tonistiigi/fsutil v0.0.0-20240424095704-91a3fc46842c
github.com/vearutop/dynhist-go v1.2.3
go.opentelemetry.io/otel v1.21.0
go.opentelemetry.io/otel/sdk v1.21.0
golang.org/x/exp v0.0.0-20240909161429-701f63a606c0
Expand Down
4 changes: 4 additions & 0 deletions go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,8 @@ github.com/anchore/go-struct-converter v0.0.0-20221118182256-c68fdcfa2092 h1:aM1
github.com/anchore/go-struct-converter v0.0.0-20221118182256-c68fdcfa2092/go.mod h1:rYqSE9HbjzpHTI74vwPvae4ZVYZd1lue2ta6xHPdblA=
github.com/bahlo/generic-list-go v0.2.0 h1:5sz/EEAK+ls5wF+NeqDpk5+iNdMDXrh3z3nPnH1Wvgk=
github.com/bahlo/generic-list-go v0.2.0/go.mod h1:2KvAjgMlE5NNynlg/5iLrrCCZ2+5xWbdbCW3pNTGyYg=
github.com/bool64/dev v0.2.28 h1:6ayDfrB/jnNr2iQAZHI+uT3Qi6rErSbJYQs1y8rSrwM=
github.com/bool64/dev v0.2.28/go.mod h1:iJbh1y/HkunEPhgebWRNcs8wfGq7sjvJ6W5iabL8ACg=
github.com/buger/jsonparser v1.1.1 h1:2PnMjfWD7wBILjqQbt530v576A/cAbQvEW9gGIpYMUs=
github.com/buger/jsonparser v1.1.1/go.mod h1:6RYKKt7H4d4+iWqouImQ9R2FZql3VbhNgx27UK13J/0=
github.com/cenkalti/backoff/v4 v4.2.1 h1:y4OZtCnogmCPw98Zjyt5a6+QwPLGkiQsYW5oUqylYbM=
Expand Down Expand Up @@ -192,6 +194,8 @@ github.com/tonistiigi/vt100 v0.0.0-20240514184818-90bafcd6abab h1:H6aJ0yKQ0gF49Q
github.com/tonistiigi/vt100 v0.0.0-20240514184818-90bafcd6abab/go.mod h1:ulncasL3N9uLrVann0m+CDlJKWsIAP34MPcOJF6VRvc=
github.com/vbatts/tar-split v0.11.5 h1:3bHCTIheBm1qFTcgh9oPu+nNBtX+XJIupG/vacinCts=
github.com/vbatts/tar-split v0.11.5/go.mod h1:yZbwRsSeGjusneWgA781EKej9HF8vme8okylkAeNKLk=
github.com/vearutop/dynhist-go v1.2.3 h1:EIMWszSDm6b7zmqySgx8zW2qNctE3IXUJggGlDFwJBE=
github.com/vearutop/dynhist-go v1.2.3/go.mod h1:liiiYiwAi8ixC3DbkxooEhASTF6ysJSXy+piCrBtxEg=
github.com/wk8/go-ordered-map/v2 v2.1.8 h1:5h/BUHu93oj4gIdvHHHGsScSTMijfx5PeYkE/fJgbpc=
github.com/wk8/go-ordered-map/v2 v2.1.8/go.mod h1:5nJHM5DyteebpVlHnWMV0rPz6Zp7+xBAnxjb1X5vnTw=
github.com/yuin/goldmark v1.1.27/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74=
Expand Down

0 comments on commit 4754f3b

Please sign in to comment.