Skip to content

Commit ad38705

Browse files
committed
feat: add instrumentation to extract round times
1 parent cdf6658 commit ad38705

File tree

2 files changed

+130
-15
lines changed

2 files changed

+130
-15
lines changed

testing/testing/benchmark.go

Lines changed: 127 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -6,11 +6,15 @@ package testing
66

77
import (
88
"context"
9+
"crypto/rand"
10+
"encoding/hex"
11+
"encoding/json"
912
"flag"
1013
"fmt"
1114
"io"
1215
"math"
1316
"os"
17+
"path/filepath"
1418
"runtime"
1519
"slices"
1620
"strconv"
@@ -138,26 +142,27 @@ type B struct {
138142
// a call to [B.StopTimer].
139143
func (b *B) StartTimer() {
140144
if !b.timerOn {
141-
runtime.ReadMemStats(&memStats)
142-
b.startAllocs = memStats.Mallocs
143-
b.startBytes = memStats.TotalAlloc
145+
// runtime.ReadMemStats(&memStats)
146+
// b.startAllocs = memStats.Mallocs
147+
// b.startBytes = memStats.TotalAlloc
144148
b.start = highPrecisionTimeNow()
145149
b.timerOn = true
146-
b.loop.i &^= loopPoisonTimer
150+
// b.loop.i &^= loopPoisonTimer
147151
}
148152
}
149153

150154
// StopTimer stops timing a test. This can be used to pause the timer
151155
// while performing steps that you don't want to measure.
152156
func (b *B) StopTimer() {
153157
if b.timerOn {
158+
b.codspeedTimePerRoundNs = append(b.codspeedTimePerRoundNs, highPrecisionTimeSince(b.start))
154159
b.duration += highPrecisionTimeSince(b.start)
155-
runtime.ReadMemStats(&memStats)
156-
b.netAllocs += memStats.Mallocs - b.startAllocs
157-
b.netBytes += memStats.TotalAlloc - b.startBytes
160+
// runtime.ReadMemStats(&memStats)
161+
// b.netAllocs += memStats.Mallocs - b.startAllocs
162+
// b.netBytes += memStats.TotalAlloc - b.startBytes
158163
b.timerOn = false
159164
// If we hit B.Loop with the timer stopped, fail.
160-
b.loop.i |= loopPoisonTimer
165+
// b.loop.i |= loopPoisonTimer
161166
}
162167
}
163168

@@ -222,6 +227,8 @@ func (b *B) runN(n int) {
222227
b.previousN = n
223228
b.previousDuration = b.duration
224229

230+
b.codspeedItersPerRound = append(b.codspeedItersPerRound, int64(n))
231+
225232
if b.loop.n > 0 && !b.loop.done && !b.failed {
226233
b.Error("benchmark function returned without B.Loop() == false (break or return in loop?)")
227234
}
@@ -275,6 +282,8 @@ var labelsOnce sync.Once
275282
// subbenchmarks. b must not have subbenchmarks.
276283
func (b *B) run() {
277284
labelsOnce.Do(func() {
285+
fmt.Fprintf(b.w, "Running with CodSpeed instrumentation\n")
286+
278287
fmt.Fprintf(b.w, "goos: %s\n", runtime.GOOS)
279288
fmt.Fprintf(b.w, "goarch: %s\n", runtime.GOARCH)
280289
if b.importPath != "" {
@@ -345,18 +354,34 @@ func (b *B) launch() {
345354
b.runN(b.benchTime.n)
346355
}
347356
} else {
348-
d := b.benchTime.d
349-
for n := int64(1); !b.failed && b.duration < d && n < 1e9; {
357+
warmupD := time.Millisecond * 500
358+
warmupN := int64(1)
359+
for n := int64(1); !b.failed && b.duration < warmupD && n < 1e9; {
350360
last := n
351361
// Predict required iterations.
352-
goalns := d.Nanoseconds()
362+
goalns := warmupD.Nanoseconds()
353363
prevIters := int64(b.N)
354364
n = int64(predictN(goalns, prevIters, b.duration.Nanoseconds(), last))
355365
b.runN(int(n))
366+
warmupN = n
367+
}
368+
369+
// Reset the fields from the warmup run
370+
b.codspeedItersPerRound = make([]int64, 0)
371+
b.codspeedTimePerRoundNs = make([]time.Duration, 0)
372+
373+
// Final run:
374+
benchD := time.Second * b.benchTime.d
375+
benchN := predictN(benchD.Nanoseconds(), int64(b.N), b.duration.Nanoseconds(), warmupN)
376+
rounds := 100 // TODO: Compute the rounds in a better way
377+
roundN := benchN / int(rounds)
378+
379+
for range rounds {
380+
b.runN(int(roundN))
356381
}
357382
}
358383
}
359-
b.result = BenchmarkResult{b.N, b.duration, b.bytes, b.netAllocs, b.netBytes, b.extra}
384+
b.result = BenchmarkResult{b.N, b.duration, b.bytes, b.netAllocs, b.netBytes, b.codspeedTimePerRoundNs, b.codspeedItersPerRound, b.extra}
360385
}
361386

362387
// Elapsed returns the measured elapsed time of the benchmark.
@@ -409,14 +434,16 @@ func (b *B) stopOrScaleBLoop() bool {
409434
panic("loop iteration target overflow")
410435
}
411436
b.loop.i++
437+
438+
b.StartTimer()
412439
return true
413440
}
414441

415442
func (b *B) loopSlowPath() bool {
416443
// Consistency checks
417-
if !b.timerOn {
418-
b.Fatal("B.Loop called with timer stopped")
419-
}
444+
// if !b.timerOn {
445+
// b.Fatal("B.Loop called with timer stopped")
446+
// }
420447
if b.loop.i&loopPoisonMask != 0 {
421448
panic(fmt.Sprintf("unknown loop stop condition: %#x", b.loop.i))
422449
}
@@ -429,14 +456,21 @@ func (b *B) loopSlowPath() bool {
429456
// Within a b.Loop loop, we don't use b.N (to avoid confusion).
430457
b.N = 0
431458
b.loop.i++
459+
460+
b.codspeedItersPerRound = make([]int64, 0)
461+
b.codspeedTimePerRoundNs = make([]time.Duration, 0)
462+
432463
b.ResetTimer()
464+
b.StartTimer()
433465
return true
434466
}
435467
// Handles fixed iterations case
436468
if b.benchTime.n > 0 {
437469
if b.loop.n < uint64(b.benchTime.n) {
438470
b.loop.n = uint64(b.benchTime.n)
439471
b.loop.i++
472+
b.ResetTimer()
473+
b.StartTimer()
440474
return true
441475
}
442476
b.StopTimer()
@@ -483,6 +517,7 @@ func (b *B) loopSlowPath() bool {
483517
// whereas b.N-based benchmarks must run the benchmark function (and any
484518
// associated setup and cleanup) several times.
485519
func (b *B) Loop() bool {
520+
b.StopTimer()
486521
// This is written such that the fast path is as fast as possible and can be
487522
// inlined.
488523
//
@@ -497,6 +532,7 @@ func (b *B) Loop() bool {
497532
// path can do consistency checks and fail.
498533
if b.loop.i < b.loop.n {
499534
b.loop.i++
535+
b.StartTimer()
500536
return true
501537
}
502538
return b.loopSlowPath()
@@ -523,6 +559,9 @@ type BenchmarkResult struct {
523559
MemAllocs uint64 // The total number of memory allocations.
524560
MemBytes uint64 // The total number of bytes allocated.
525561

562+
CodspeedTimePerRoundNs []time.Duration
563+
CodspeedItersPerRound []int64
564+
526565
// Extra records additional metrics reported by ReportMetric.
527566
Extra map[string]float64
528567
}
@@ -754,6 +793,79 @@ func (s *benchState) processBench(b *B) {
754793
continue
755794
}
756795
results := r.String()
796+
797+
// ############################################################################################
798+
// START CODSPEED
799+
type RawResults struct {
800+
BenchmarkName string `json:"benchmark_name"`
801+
Pid int `json:"pid"`
802+
CodspeedTimePerRoundNs []time.Duration `json:"codspeed_time_per_round_ns"`
803+
CodspeedItersPerRound []int64 `json:"codspeed_iters_per_round"`
804+
}
805+
806+
// Build custom bench name with :: separator
807+
var nameParts []string
808+
current := &b.common
809+
for current.parent != nil {
810+
// Extract the sub-benchmark part by removing parent prefix
811+
parentName := current.parent.name
812+
if strings.HasPrefix(current.name, parentName+"/") {
813+
subName := strings.TrimPrefix(current.name, parentName+"/")
814+
nameParts = append([]string{subName}, nameParts...)
815+
} else {
816+
nameParts = append([]string{current.name}, nameParts...)
817+
}
818+
819+
if current.parent.name == "Main" {
820+
break
821+
}
822+
current = current.parent
823+
}
824+
customBenchName := strings.Join(nameParts, "::")
825+
826+
rawResults := RawResults{
827+
BenchmarkName: customBenchName,
828+
Pid: os.Getpid(),
829+
CodspeedTimePerRoundNs: r.CodspeedTimePerRoundNs,
830+
CodspeedItersPerRound: r.CodspeedItersPerRound,
831+
}
832+
833+
codspeedProfileFolder := os.Getenv("CODSPEED_PROFILE_FOLDER")
834+
if codspeedProfileFolder == "" {
835+
panic("CODSPEED_PROFILE_FOLDER environment variable is not set")
836+
}
837+
if err := os.MkdirAll(filepath.Join(codspeedProfileFolder, "raw_results"), 0755); err != nil {
838+
fmt.Fprintf(os.Stderr, "failed to create raw results directory: %v\n", err)
839+
continue
840+
}
841+
// Generate random filename to avoid any overwrites
842+
randomBytes := make([]byte, 16)
843+
if _, err := rand.Read(randomBytes); err != nil {
844+
fmt.Fprintf(os.Stderr, "failed to generate random filename: %v\n", err)
845+
continue
846+
}
847+
rawResultsFile := filepath.Join(codspeedProfileFolder, "raw_results", fmt.Sprintf("%s.json", hex.EncodeToString(randomBytes)))
848+
file, err := os.Create(rawResultsFile)
849+
if err != nil {
850+
fmt.Fprintf(os.Stderr, "failed to create raw results file: %v\n", err)
851+
continue
852+
}
853+
output, err := json.MarshalIndent(rawResults, "", " ")
854+
if err != nil {
855+
fmt.Fprintf(os.Stderr, "failed to marshal raw results: %v\n", err)
856+
file.Close()
857+
continue
858+
}
859+
// FIXME: Don't overwrite the file if it already exists
860+
if _, err := file.Write(output); err != nil {
861+
fmt.Fprintf(os.Stderr, "failed to write raw results: %v\n", err)
862+
file.Close()
863+
continue
864+
}
865+
defer file.Close()
866+
// END CODSPEED
867+
// ############################################################################################
868+
757869
if b.chatty != nil {
758870
fmt.Fprintf(b.w, "%-*s\t", s.maxLen, benchName)
759871
}

testing/testing/testing.go

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -666,6 +666,9 @@ type common struct {
666666

667667
ctx context.Context
668668
cancelCtx context.CancelFunc
669+
670+
codspeedTimePerRoundNs []time.Duration
671+
codspeedItersPerRound []int64
669672
}
670673

671674
// Short reports whether the -test.short flag is set.

0 commit comments

Comments
 (0)