]> Cypherpunks.ru repositories - gostls13.git/blob - src/testing/benchmark.go
testing: always ReadMemStats before first benchmark run
[gostls13.git] / src / testing / benchmark.go
1 // Copyright 2009 The Go Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style
3 // license that can be found in the LICENSE file.
4
5 package testing
6
7 import (
8         "flag"
9         "fmt"
10         "internal/race"
11         "os"
12         "runtime"
13         "sync"
14         "sync/atomic"
15         "time"
16 )
17
18 var matchBenchmarks = flag.String("test.bench", "", "run only benchmarks matching `regexp`")
19 var benchTime = flag.Duration("test.benchtime", 1*time.Second, "run each benchmark for duration `d`")
20 var benchmarkMemory = flag.Bool("test.benchmem", false, "print memory allocations for benchmarks")
21
22 // Global lock to ensure only one benchmark runs at a time.
23 var benchmarkLock sync.Mutex
24
25 // Used for every benchmark for measuring memory.
26 var memStats runtime.MemStats
27
28 // An internal type but exported because it is cross-package; part of the implementation
29 // of the "go test" command.
30 type InternalBenchmark struct {
31         Name string
32         F    func(b *B)
33 }
34
35 // B is a type passed to Benchmark functions to manage benchmark
36 // timing and to specify the number of iterations to run.
37 //
38 // A benchmark ends when its Benchmark function returns or calls any of the methods
39 // FailNow, Fatal, Fatalf, SkipNow, Skip, or Skipf. Those methods must be called
40 // only from the goroutine running the Benchmark function.
41 // The other reporting methods, such as the variations of Log and Error,
42 // may be called simultaneously from multiple goroutines.
43 //
44 // Like in tests, benchmark logs are accumulated during execution
45 // and dumped to standard error when done. Unlike in tests, benchmark logs
46 // are always printed, so as not to hide output whose existence may be
47 // affecting benchmark results.
48 type B struct {
49         common
50         importPath       string // import path of the package containing the benchmark
51         context          *benchContext
52         N                int
53         previousN        int           // number of iterations in the previous run
54         previousDuration time.Duration // total duration of the previous run
55         benchFunc        func(b *B)
56         benchTime        time.Duration
57         bytes            int64
58         missingBytes     bool // one of the subbenchmarks does not have bytes set.
59         timerOn          bool
60         showAllocResult  bool
61         result           BenchmarkResult
62         parallelism      int // RunParallel creates parallelism*GOMAXPROCS goroutines
63         // The initial states of memStats.Mallocs and memStats.TotalAlloc.
64         startAllocs uint64
65         startBytes  uint64
66         // The net total of this test after being run.
67         netAllocs uint64
68         netBytes  uint64
69 }
70
71 // StartTimer starts timing a test. This function is called automatically
72 // before a benchmark starts, but it can also used to resume timing after
73 // a call to StopTimer.
74 func (b *B) StartTimer() {
75         if !b.timerOn {
76                 runtime.ReadMemStats(&memStats)
77                 b.startAllocs = memStats.Mallocs
78                 b.startBytes = memStats.TotalAlloc
79                 b.start = time.Now()
80                 b.timerOn = true
81         }
82 }
83
84 // StopTimer stops timing a test. This can be used to pause the timer
85 // while performing complex initialization that you don't
86 // want to measure.
87 func (b *B) StopTimer() {
88         if b.timerOn {
89                 b.duration += time.Now().Sub(b.start)
90                 if *benchmarkMemory || b.showAllocResult {
91                         runtime.ReadMemStats(&memStats)
92                         b.netAllocs += memStats.Mallocs - b.startAllocs
93                         b.netBytes += memStats.TotalAlloc - b.startBytes
94                 }
95                 b.timerOn = false
96         }
97 }
98
99 // ResetTimer zeros the elapsed benchmark time and memory allocation counters.
100 // It does not affect whether the timer is running.
101 func (b *B) ResetTimer() {
102         if b.timerOn {
103                 if *benchmarkMemory || b.showAllocResult {
104                         runtime.ReadMemStats(&memStats)
105                         b.startAllocs = memStats.Mallocs
106                         b.startBytes = memStats.TotalAlloc
107                 }
108                 b.start = time.Now()
109         }
110         b.duration = 0
111         b.netAllocs = 0
112         b.netBytes = 0
113 }
114
115 // SetBytes records the number of bytes processed in a single operation.
116 // If this is called, the benchmark will report ns/op and MB/s.
117 func (b *B) SetBytes(n int64) { b.bytes = n }
118
119 // ReportAllocs enables malloc statistics for this benchmark.
120 // It is equivalent to setting -test.benchmem, but it only affects the
121 // benchmark function that calls ReportAllocs.
122 func (b *B) ReportAllocs() {
123         b.showAllocResult = true
124 }
125
126 func (b *B) nsPerOp() int64 {
127         if b.N <= 0 {
128                 return 0
129         }
130         return b.duration.Nanoseconds() / int64(b.N)
131 }
132
133 // runN runs a single benchmark for the specified number of iterations.
134 func (b *B) runN(n int) {
135         benchmarkLock.Lock()
136         defer benchmarkLock.Unlock()
137         // Try to get a comparable environment for each run
138         // by clearing garbage from previous runs.
139         runtime.GC()
140         b.raceErrors = -race.Errors()
141         b.N = n
142         b.parallelism = 1
143         b.ResetTimer()
144         b.StartTimer()
145         b.benchFunc(b)
146         b.StopTimer()
147         b.previousN = n
148         b.previousDuration = b.duration
149         b.raceErrors += race.Errors()
150         if b.raceErrors > 0 {
151                 b.Errorf("race detected during execution of benchmark")
152         }
153 }
154
155 func min(x, y int) int {
156         if x > y {
157                 return y
158         }
159         return x
160 }
161
162 func max(x, y int) int {
163         if x < y {
164                 return y
165         }
166         return x
167 }
168
169 // roundDown10 rounds a number down to the nearest power of 10.
170 func roundDown10(n int) int {
171         var tens = 0
172         // tens = floor(log_10(n))
173         for n >= 10 {
174                 n = n / 10
175                 tens++
176         }
177         // result = 10^tens
178         result := 1
179         for i := 0; i < tens; i++ {
180                 result *= 10
181         }
182         return result
183 }
184
185 // roundUp rounds x up to a number of the form [1eX, 2eX, 3eX, 5eX].
186 func roundUp(n int) int {
187         base := roundDown10(n)
188         switch {
189         case n <= base:
190                 return base
191         case n <= (2 * base):
192                 return 2 * base
193         case n <= (3 * base):
194                 return 3 * base
195         case n <= (5 * base):
196                 return 5 * base
197         default:
198                 return 10 * base
199         }
200 }
201
202 // run1 runs the first iteration of benchFunc. It returns whether more
203 // iterations of this benchmarks should be run.
204 func (b *B) run1() bool {
205         if ctx := b.context; ctx != nil {
206                 // Extend maxLen, if needed.
207                 if n := len(b.name) + ctx.extLen + 1; n > ctx.maxLen {
208                         ctx.maxLen = n + 8 // Add additional slack to avoid too many jumps in size.
209                 }
210         }
211         go func() {
212                 // Signal that we're done whether we return normally
213                 // or by FailNow's runtime.Goexit.
214                 defer func() {
215                         b.signal <- true
216                 }()
217
218                 b.runN(1)
219         }()
220         <-b.signal
221         if b.failed {
222                 fmt.Fprintf(b.w, "--- FAIL: %s\n%s", b.name, b.output)
223                 return false
224         }
225         // Only print the output if we know we are not going to proceed.
226         // Otherwise it is printed in processBench.
227         if atomic.LoadInt32(&b.hasSub) != 0 || b.finished {
228                 tag := "BENCH"
229                 if b.skipped {
230                         tag = "SKIP"
231                 }
232                 if b.chatty && (len(b.output) > 0 || b.finished) {
233                         b.trimOutput()
234                         fmt.Fprintf(b.w, "--- %s: %s\n%s", tag, b.name, b.output)
235                 }
236                 return false
237         }
238         return true
239 }
240
241 var labelsOnce sync.Once
242
243 // run executes the benchmark in a separate goroutine, including all of its
244 // subbenchmarks. b must not have subbenchmarks.
245 func (b *B) run() BenchmarkResult {
246         labelsOnce.Do(func() {
247                 fmt.Fprintf(b.w, "goos: %s\n", runtime.GOOS)
248                 fmt.Fprintf(b.w, "goarch: %s\n", runtime.GOARCH)
249                 if b.importPath != "" {
250                         fmt.Fprintf(b.w, "pkg: %s\n", b.importPath)
251                 }
252         })
253         if b.context != nil {
254                 // Running go test --test.bench
255                 b.context.processBench(b) // Must call doBench.
256         } else {
257                 // Running func Benchmark.
258                 b.doBench()
259         }
260         return b.result
261 }
262
263 func (b *B) doBench() BenchmarkResult {
264         go b.launch()
265         <-b.signal
266         return b.result
267 }
268
269 // launch launches the benchmark function. It gradually increases the number
270 // of benchmark iterations until the benchmark runs for the requested benchtime.
271 // launch is run by the doBench function as a separate goroutine.
272 // run1 must have been called on b.
273 func (b *B) launch() {
274         // Signal that we're done whether we return normally
275         // or by FailNow's runtime.Goexit.
276         defer func() {
277                 b.signal <- true
278         }()
279
280         // Run the benchmark for at least the specified amount of time.
281         d := b.benchTime
282         for n := 1; !b.failed && b.duration < d && n < 1e9; {
283                 last := n
284                 // Predict required iterations.
285                 n = int(d.Nanoseconds())
286                 if nsop := b.nsPerOp(); nsop != 0 {
287                         n /= int(nsop)
288                 }
289                 // Run more iterations than we think we'll need (1.2x).
290                 // Don't grow too fast in case we had timing errors previously.
291                 // Be sure to run at least one more than last time.
292                 n = max(min(n+n/5, 100*last), last+1)
293                 // Round up to something easy to read.
294                 n = roundUp(n)
295                 b.runN(n)
296         }
297         b.result = BenchmarkResult{b.N, b.duration, b.bytes, b.netAllocs, b.netBytes}
298 }
299
300 // The results of a benchmark run.
301 // MemAllocs and MemBytes may be zero if memory benchmarking is not requested
302 // using B.ReportAllocs or the -benchmem command line flag.
303 type BenchmarkResult struct {
304         N         int           // The number of iterations.
305         T         time.Duration // The total time taken.
306         Bytes     int64         // Bytes processed in one iteration.
307         MemAllocs uint64        // The total number of memory allocations.
308         MemBytes  uint64        // The total number of bytes allocated.
309 }
310
311 func (r BenchmarkResult) NsPerOp() int64 {
312         if r.N <= 0 {
313                 return 0
314         }
315         return r.T.Nanoseconds() / int64(r.N)
316 }
317
318 func (r BenchmarkResult) mbPerSec() float64 {
319         if r.Bytes <= 0 || r.T <= 0 || r.N <= 0 {
320                 return 0
321         }
322         return (float64(r.Bytes) * float64(r.N) / 1e6) / r.T.Seconds()
323 }
324
325 // AllocsPerOp returns r.MemAllocs / r.N.
326 func (r BenchmarkResult) AllocsPerOp() int64 {
327         if r.N <= 0 {
328                 return 0
329         }
330         return int64(r.MemAllocs) / int64(r.N)
331 }
332
333 // AllocedBytesPerOp returns r.MemBytes / r.N.
334 func (r BenchmarkResult) AllocedBytesPerOp() int64 {
335         if r.N <= 0 {
336                 return 0
337         }
338         return int64(r.MemBytes) / int64(r.N)
339 }
340
341 func (r BenchmarkResult) String() string {
342         mbs := r.mbPerSec()
343         mb := ""
344         if mbs != 0 {
345                 mb = fmt.Sprintf("\t%7.2f MB/s", mbs)
346         }
347         nsop := r.NsPerOp()
348         ns := fmt.Sprintf("%10d ns/op", nsop)
349         if r.N > 0 && nsop < 100 {
350                 // The format specifiers here make sure that
351                 // the ones digits line up for all three possible formats.
352                 if nsop < 10 {
353                         ns = fmt.Sprintf("%13.2f ns/op", float64(r.T.Nanoseconds())/float64(r.N))
354                 } else {
355                         ns = fmt.Sprintf("%12.1f ns/op", float64(r.T.Nanoseconds())/float64(r.N))
356                 }
357         }
358         return fmt.Sprintf("%8d\t%s%s", r.N, ns, mb)
359 }
360
361 // MemString returns r.AllocedBytesPerOp and r.AllocsPerOp in the same format as 'go test'.
362 func (r BenchmarkResult) MemString() string {
363         return fmt.Sprintf("%8d B/op\t%8d allocs/op",
364                 r.AllocedBytesPerOp(), r.AllocsPerOp())
365 }
366
367 // benchmarkName returns full name of benchmark including procs suffix.
368 func benchmarkName(name string, n int) string {
369         if n != 1 {
370                 return fmt.Sprintf("%s-%d", name, n)
371         }
372         return name
373 }
374
375 type benchContext struct {
376         match *matcher
377
378         maxLen int // The largest recorded benchmark name.
379         extLen int // Maximum extension length.
380 }
381
382 // An internal function but exported because it is cross-package; part of the implementation
383 // of the "go test" command.
384 func RunBenchmarks(matchString func(pat, str string) (bool, error), benchmarks []InternalBenchmark) {
385         runBenchmarks("", matchString, benchmarks)
386 }
387
388 func runBenchmarks(importPath string, matchString func(pat, str string) (bool, error), benchmarks []InternalBenchmark) bool {
389         // If no flag was specified, don't run benchmarks.
390         if len(*matchBenchmarks) == 0 {
391                 return true
392         }
393         // Collect matching benchmarks and determine longest name.
394         maxprocs := 1
395         for _, procs := range cpuList {
396                 if procs > maxprocs {
397                         maxprocs = procs
398                 }
399         }
400         ctx := &benchContext{
401                 match:  newMatcher(matchString, *matchBenchmarks, "-test.bench"),
402                 extLen: len(benchmarkName("", maxprocs)),
403         }
404         var bs []InternalBenchmark
405         for _, Benchmark := range benchmarks {
406                 if _, matched, _ := ctx.match.fullName(nil, Benchmark.Name); matched {
407                         bs = append(bs, Benchmark)
408                         benchName := benchmarkName(Benchmark.Name, maxprocs)
409                         if l := len(benchName) + ctx.extLen + 1; l > ctx.maxLen {
410                                 ctx.maxLen = l
411                         }
412                 }
413         }
414         main := &B{
415                 common: common{
416                         name:   "Main",
417                         w:      os.Stdout,
418                         chatty: *chatty,
419                 },
420                 importPath: importPath,
421                 benchFunc: func(b *B) {
422                         for _, Benchmark := range bs {
423                                 b.Run(Benchmark.Name, Benchmark.F)
424                         }
425                 },
426                 benchTime: *benchTime,
427                 context:   ctx,
428         }
429         main.runN(1)
430         return !main.failed
431 }
432
433 // processBench runs bench b for the configured CPU counts and prints the results.
434 func (ctx *benchContext) processBench(b *B) {
435         for i, procs := range cpuList {
436                 runtime.GOMAXPROCS(procs)
437                 benchName := benchmarkName(b.name, procs)
438                 fmt.Fprintf(b.w, "%-*s\t", ctx.maxLen, benchName)
439                 // Recompute the running time for all but the first iteration.
440                 if i > 0 {
441                         b = &B{
442                                 common: common{
443                                         signal: make(chan bool),
444                                         name:   b.name,
445                                         w:      b.w,
446                                         chatty: b.chatty,
447                                 },
448                                 benchFunc: b.benchFunc,
449                                 benchTime: b.benchTime,
450                         }
451                         b.run1()
452                 }
453                 r := b.doBench()
454                 if b.failed {
455                         // The output could be very long here, but probably isn't.
456                         // We print it all, regardless, because we don't want to trim the reason
457                         // the benchmark failed.
458                         fmt.Fprintf(b.w, "--- FAIL: %s\n%s", benchName, b.output)
459                         continue
460                 }
461                 results := r.String()
462                 if *benchmarkMemory || b.showAllocResult {
463                         results += "\t" + r.MemString()
464                 }
465                 fmt.Fprintln(b.w, results)
466                 // Unlike with tests, we ignore the -chatty flag and always print output for
467                 // benchmarks since the output generation time will skew the results.
468                 if len(b.output) > 0 {
469                         b.trimOutput()
470                         fmt.Fprintf(b.w, "--- BENCH: %s\n%s", benchName, b.output)
471                 }
472                 if p := runtime.GOMAXPROCS(-1); p != procs {
473                         fmt.Fprintf(os.Stderr, "testing: %s left GOMAXPROCS set to %d\n", benchName, p)
474                 }
475         }
476 }
477
478 // Run benchmarks f as a subbenchmark with the given name. It reports
479 // whether there were any failures.
480 //
481 // A subbenchmark is like any other benchmark. A benchmark that calls Run at
482 // least once will not be measured itself and will be called once with N=1.
483 //
484 // Run may be called simultaneously from multiple goroutines, but all such
485 // calls must happen before the outer benchmark function for b returns.
486 func (b *B) Run(name string, f func(b *B)) bool {
487         // Since b has subbenchmarks, we will no longer run it as a benchmark itself.
488         // Release the lock and acquire it on exit to ensure locks stay paired.
489         atomic.StoreInt32(&b.hasSub, 1)
490         benchmarkLock.Unlock()
491         defer benchmarkLock.Lock()
492
493         benchName, ok, partial := b.name, true, false
494         if b.context != nil {
495                 benchName, ok, partial = b.context.match.fullName(&b.common, name)
496         }
497         if !ok {
498                 return true
499         }
500         sub := &B{
501                 common: common{
502                         signal: make(chan bool),
503                         name:   benchName,
504                         parent: &b.common,
505                         level:  b.level + 1,
506                         w:      b.w,
507                         chatty: b.chatty,
508                 },
509                 importPath: b.importPath,
510                 benchFunc:  f,
511                 benchTime:  b.benchTime,
512                 context:    b.context,
513         }
514         if partial {
515                 // Partial name match, like -bench=X/Y matching BenchmarkX.
516                 // Only process sub-benchmarks, if any.
517                 atomic.StoreInt32(&sub.hasSub, 1)
518         }
519         if sub.run1() {
520                 sub.run()
521         }
522         b.add(sub.result)
523         return !sub.failed
524 }
525
526 // add simulates running benchmarks in sequence in a single iteration. It is
527 // used to give some meaningful results in case func Benchmark is used in
528 // combination with Run.
529 func (b *B) add(other BenchmarkResult) {
530         r := &b.result
531         // The aggregated BenchmarkResults resemble running all subbenchmarks as
532         // in sequence in a single benchmark.
533         r.N = 1
534         r.T += time.Duration(other.NsPerOp())
535         if other.Bytes == 0 {
536                 // Summing Bytes is meaningless in aggregate if not all subbenchmarks
537                 // set it.
538                 b.missingBytes = true
539                 r.Bytes = 0
540         }
541         if !b.missingBytes {
542                 r.Bytes += other.Bytes
543         }
544         r.MemAllocs += uint64(other.AllocsPerOp())
545         r.MemBytes += uint64(other.AllocedBytesPerOp())
546 }
547
548 // trimOutput shortens the output from a benchmark, which can be very long.
549 func (b *B) trimOutput() {
550         // The output is likely to appear multiple times because the benchmark
551         // is run multiple times, but at least it will be seen. This is not a big deal
552         // because benchmarks rarely print, but just in case, we trim it if it's too long.
553         const maxNewlines = 10
554         for nlCount, j := 0, 0; j < len(b.output); j++ {
555                 if b.output[j] == '\n' {
556                         nlCount++
557                         if nlCount >= maxNewlines {
558                                 b.output = append(b.output[:j], "\n\t... [output truncated]\n"...)
559                                 break
560                         }
561                 }
562         }
563 }
564
565 // A PB is used by RunParallel for running parallel benchmarks.
566 type PB struct {
567         globalN *uint64 // shared between all worker goroutines iteration counter
568         grain   uint64  // acquire that many iterations from globalN at once
569         cache   uint64  // local cache of acquired iterations
570         bN      uint64  // total number of iterations to execute (b.N)
571 }
572
573 // Next reports whether there are more iterations to execute.
574 func (pb *PB) Next() bool {
575         if pb.cache == 0 {
576                 n := atomic.AddUint64(pb.globalN, pb.grain)
577                 if n <= pb.bN {
578                         pb.cache = pb.grain
579                 } else if n < pb.bN+pb.grain {
580                         pb.cache = pb.bN + pb.grain - n
581                 } else {
582                         return false
583                 }
584         }
585         pb.cache--
586         return true
587 }
588
589 // RunParallel runs a benchmark in parallel.
590 // It creates multiple goroutines and distributes b.N iterations among them.
591 // The number of goroutines defaults to GOMAXPROCS. To increase parallelism for
592 // non-CPU-bound benchmarks, call SetParallelism before RunParallel.
593 // RunParallel is usually used with the go test -cpu flag.
594 //
595 // The body function will be run in each goroutine. It should set up any
596 // goroutine-local state and then iterate until pb.Next returns false.
597 // It should not use the StartTimer, StopTimer, or ResetTimer functions,
598 // because they have global effect. It should also not call Run.
599 func (b *B) RunParallel(body func(*PB)) {
600         if b.N == 0 {
601                 return // Nothing to do when probing.
602         }
603         // Calculate grain size as number of iterations that take ~100µs.
604         // 100µs is enough to amortize the overhead and provide sufficient
605         // dynamic load balancing.
606         grain := uint64(0)
607         if b.previousN > 0 && b.previousDuration > 0 {
608                 grain = 1e5 * uint64(b.previousN) / uint64(b.previousDuration)
609         }
610         if grain < 1 {
611                 grain = 1
612         }
613         // We expect the inner loop and function call to take at least 10ns,
614         // so do not do more than 100µs/10ns=1e4 iterations.
615         if grain > 1e4 {
616                 grain = 1e4
617         }
618
619         n := uint64(0)
620         numProcs := b.parallelism * runtime.GOMAXPROCS(0)
621         var wg sync.WaitGroup
622         wg.Add(numProcs)
623         for p := 0; p < numProcs; p++ {
624                 go func() {
625                         defer wg.Done()
626                         pb := &PB{
627                                 globalN: &n,
628                                 grain:   grain,
629                                 bN:      uint64(b.N),
630                         }
631                         body(pb)
632                 }()
633         }
634         wg.Wait()
635         if n <= uint64(b.N) && !b.Failed() {
636                 b.Fatal("RunParallel: body exited without pb.Next() == false")
637         }
638 }
639
640 // SetParallelism sets the number of goroutines used by RunParallel to p*GOMAXPROCS.
641 // There is usually no need to call SetParallelism for CPU-bound benchmarks.
642 // If p is less than 1, this call will have no effect.
643 func (b *B) SetParallelism(p int) {
644         if p >= 1 {
645                 b.parallelism = p
646         }
647 }
648
649 // Benchmark benchmarks a single function. Useful for creating
650 // custom benchmarks that do not use the "go test" command.
651 //
652 // If f calls Run, the result will be an estimate of running all its
653 // subbenchmarks that don't call Run in sequence in a single benchmark.
654 func Benchmark(f func(b *B)) BenchmarkResult {
655         b := &B{
656                 common: common{
657                         signal: make(chan bool),
658                         w:      discard{},
659                 },
660                 benchFunc: f,
661                 benchTime: *benchTime,
662         }
663         if b.run1() {
664                 b.run()
665         }
666         return b.result
667 }
668
669 type discard struct{}
670
671 func (discard) Write(b []byte) (n int, err error) { return len(b), nil }