...
Run Format

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

View as plain text