1// Command benchrec turns `go test -bench` output into run records, one2// JSON line per benchmark, appended to a results file that DuckDB (and3// ClickHouse) read; see scripts/stress and docs/contributing/observability.md. It also4// prints a compact table of the run.5//6// go test -bench . -benchmem ./... | go run ./internal/stress/benchrec -out runs.jsonl7//8// GIT_SHA and GIT_DIRTY describe the code measured; the rest is read9// from the output and the machine.10package main1112import (13 "bufio"14 "cmp"15 "encoding/json"16 "flag"17 "fmt"18 "io"19 "maps"20 "os"21 "regexp"22 "runtime"23 "slices"24 "strconv"25 "strings"26 "text/tabwriter"27 "time"28)2930// Record is one benchmark result of one run. The same columns are the31// stress_results table in ClickHouse (deploy/observability).32type Record struct {33 RunID string `json:"run_id"`34 TS string `json:"ts"`35 GitSHA string `json:"git_sha"`36 GitDirty bool `json:"git_dirty"`37 GoVersion string `json:"go_version"`38 GOOS string `json:"goos"`39 GOARCH string `json:"goarch"`40 CPU string `json:"cpu"`41 Host string `json:"host"`42 Pkg string `json:"pkg"`43 Name string `json:"name"` // without the -GOMAXPROCS suffix44 Procs int `json:"procs"`45 N int64 `json:"n"`46 NsOp float64 `json:"ns_op"`47 BOp float64 `json:"b_op"`48 AllocsOp float64 `json:"allocs_op"`49 MBs float64 `json:"mb_s"`50 Metrics map[string]float64 `json:"metrics"` // custom b.ReportMetric units51}5253func main() {54 out := flag.String("out", "", "append records to this JSONL file")55 flag.Parse()56 recs, err := parse(os.Stdin, meta())57 if err != nil {58 fmt.Fprintln(os.Stderr, "benchrec:", err)59 os.Exit(1)60 }61 if len(recs) == 0 {62 fmt.Fprintln(os.Stderr, "benchrec: no benchmark results in the input")63 os.Exit(1)64 }65 if *out != "" {66 if err := appendJSONL(*out, recs); err != nil {67 fmt.Fprintln(os.Stderr, "benchrec:", err)68 os.Exit(1)69 }70 }71 summary(os.Stdout, recs)72 if *out != "" {73 fmt.Printf("\n%d results of run %s appended to %s\n", len(recs), recs[0].RunID, *out)74 }75}7677// meta describes the run: when, which code, which machine.78func meta() Record {79 now := time.Now().UTC()80 host, _ := os.Hostname()81 sha := os.Getenv("GIT_SHA")82 r := Record{83 TS: now.Format(time.RFC3339), GitSHA: sha, GitDirty: os.Getenv("GIT_DIRTY") == "1",84 GoVersion: runtime.Version(), GOOS: runtime.GOOS, GOARCH: runtime.GOARCH, Host: host,85 }86 r.RunID = now.Format("20060102T150405Z") + "-" + cmp.Or(sha, "unknown")87 return r88}8990var benchLine = regexp.MustCompile(`^(Benchmark\S+?)(?:-(\d+))?\s+(\d+)\s+(.*)$`)9192// parse reads benchmark output: "pkg:" and "cpu:" headers, then result93// lines of an iteration count and value-unit pairs.94func parse(r io.Reader, base Record) ([]Record, error) {95 var out []Record96 pkg, cpu := "", ""97 sc := bufio.NewScanner(r)98 sc.Buffer(make([]byte, 1<<20), 1<<20)99 for sc.Scan() {100 line := sc.Text()101 switch {102 case strings.HasPrefix(line, "pkg: "):103 pkg = strings.TrimPrefix(line, "pkg: ")104 continue105 case strings.HasPrefix(line, "cpu: "):106 cpu = strings.TrimPrefix(line, "cpu: ")107 continue108 }109 m := benchLine.FindStringSubmatch(line)110 if m == nil {111 continue112 }113 rec := base114 rec.Pkg, rec.CPU, rec.Name = pkg, cpu, strings.TrimPrefix(m[1], "Benchmark")115 rec.Procs, _ = strconv.Atoi(m[2])116 rec.N, _ = strconv.ParseInt(m[3], 10, 64)117 rec.Metrics = map[string]float64{}118 f := strings.Fields(m[4])119 for i := 0; i+1 < len(f); i += 2 {120 v, err := strconv.ParseFloat(f[i], 64)121 if err != nil {122 return nil, fmt.Errorf("%s: value %q", line, f[i])123 }124 switch unit := f[i+1]; unit {125 case "ns/op":126 rec.NsOp = v127 case "B/op":128 rec.BOp = v129 case "allocs/op":130 rec.AllocsOp = v131 case "MB/s":132 rec.MBs = v133 default:134 rec.Metrics[unit] = v135 }136 }137 out = append(out, rec)138 }139 return out, sc.Err()140}141142func appendJSONL(path string, recs []Record) error {143 f, err := os.OpenFile(path, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0o644)144 if err != nil {145 return err146 }147 enc := json.NewEncoder(f)148 for _, r := range recs {149 if err := enc.Encode(r); err != nil {150 f.Close()151 return err152 }153 }154 return f.Close()155}156157// summary prints one line per benchmark: time per op in readable units,158// allocations, and custom metrics.159func summary(w io.Writer, recs []Record) {160 tw := tabwriter.NewWriter(w, 0, 0, 2, ' ', 0)161 fmt.Fprintf(tw, "benchmark\ttime/op\tallocs/op\tmem/op\tother\t\n")162 pkg := ""163 for _, r := range recs {164 if r.Pkg != pkg {165 pkg = r.Pkg166 fmt.Fprintf(tw, "%s\t\t\t\t\t\n", pkg)167 }168 var other []string169 if r.MBs > 0 {170 other = append(other, fmt.Sprintf("%.1f MB/s", r.MBs))171 }172 for _, k := range slices.Sorted(maps.Keys(r.Metrics)) {173 other = append(other, fmt.Sprintf("%s %s", num(r.Metrics[k]), k))174 }175 fmt.Fprintf(tw, " %s\t%s\t%s\t%s\t%s\t\n", r.Name, duration(r.NsOp), num(r.AllocsOp), bytes(r.BOp), strings.Join(other, ", "))176 }177 tw.Flush()178}179180func duration(ns float64) string {181 switch {182 case ns >= 1e9:183 return fmt.Sprintf("%.2f s", ns/1e9)184 case ns >= 1e6:185 return fmt.Sprintf("%.2f ms", ns/1e6)186 case ns >= 1e3:187 return fmt.Sprintf("%.1f us", ns/1e3)188 }189 return fmt.Sprintf("%.0f ns", ns)190}191192func bytes(b float64) string {193 switch {194 case b >= 1<<30:195 return fmt.Sprintf("%.1f GB", b/(1<<30))196 case b >= 1<<20:197 return fmt.Sprintf("%.1f MB", b/(1<<20))198 case b >= 1<<10:199 return fmt.Sprintf("%.1f KB", b/(1<<10))200 }201 return fmt.Sprintf("%.0f B", b)202}203204func num(v float64) string {205 switch {206 case v >= 1e6:207 return fmt.Sprintf("%.1fM", v/1e6)208 case v >= 1e4:209 return fmt.Sprintf("%.0fk", v/1e3)210 case v == float64(int64(v)):211 return strconv.FormatInt(int64(v), 10)212 }213 return strconv.FormatFloat(v, 'f', 1, 64)214}