benchmarks_test.go

     1  // Copyright 2022 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 benchmarks
     6  
     7  import (
     8  	"context"
     9  	"flag"
    10  	"internal/race"
    11  	"io"
    12  	"log/slog"
    13  	"log/slog/internal"
    14  	"testing"
    15  )
    16  
    17  func init() {
    18  	flag.BoolVar(&internal.IgnorePC, "nopc", false, "do not invoke runtime.Callers")
    19  }
    20  
    21  // We pass Attrs inline because it affects allocations: building
    22  // up a list outside of the benchmarked code and passing it in with "..."
    23  // reduces measured allocations.
    24  
    25  func BenchmarkAttrs(b *testing.B) {
    26  	ctx := context.Background()
    27  	for _, handler := range []struct {
    28  		name     string
    29  		h        slog.Handler
    30  		skipRace bool
    31  	}{
    32  		{"disabled", disabledHandler{}, false},
    33  		{"async discard", newAsyncHandler(), true},
    34  		{"fastText discard", newFastTextHandler(io.Discard), false},
    35  		{"Text discard", slog.NewTextHandler(io.Discard, nil), false},
    36  		{"JSON discard", slog.NewJSONHandler(io.Discard, nil), false},
    37  	} {
    38  		logger := slog.New(handler.h)
    39  		b.Run(handler.name, func(b *testing.B) {
    40  			if handler.skipRace && race.Enabled {
    41  				b.Skip("skipping benchmark in race mode")
    42  			}
    43  			for _, call := range []struct {
    44  				name string
    45  				f    func()
    46  			}{
    47  				{
    48  					// The number should match nAttrsInline in slog/record.go.
    49  					// This should exercise the code path where no allocations
    50  					// happen in Record or Attr. If there are allocations, they
    51  					// should only be from Duration.String and Time.String.
    52  					"5 args",
    53  					func() {
    54  						logger.LogAttrs(nil, slog.LevelInfo, testMessage,
    55  							slog.String("string", testString),
    56  							slog.Int("status", testInt),
    57  							slog.Duration("duration", testDuration),
    58  							slog.Time("time", testTime),
    59  							slog.Any("error", testError),
    60  						)
    61  					},
    62  				},
    63  				{
    64  					"5 args ctx",
    65  					func() {
    66  						logger.LogAttrs(ctx, slog.LevelInfo, testMessage,
    67  							slog.String("string", testString),
    68  							slog.Int("status", testInt),
    69  							slog.Duration("duration", testDuration),
    70  							slog.Time("time", testTime),
    71  							slog.Any("error", testError),
    72  						)
    73  					},
    74  				},
    75  				{
    76  					"10 args",
    77  					func() {
    78  						logger.LogAttrs(nil, slog.LevelInfo, testMessage,
    79  							slog.String("string", testString),
    80  							slog.Int("status", testInt),
    81  							slog.Duration("duration", testDuration),
    82  							slog.Time("time", testTime),
    83  							slog.Any("error", testError),
    84  							slog.String("string", testString),
    85  							slog.Int("status", testInt),
    86  							slog.Duration("duration", testDuration),
    87  							slog.Time("time", testTime),
    88  							slog.Any("error", testError),
    89  						)
    90  					},
    91  				},
    92  				{
    93  					// Try an extreme value to see if the results are reasonable.
    94  					"40 args",
    95  					func() {
    96  						logger.LogAttrs(nil, slog.LevelInfo, testMessage,
    97  							slog.String("string", testString),
    98  							slog.Int("status", testInt),
    99  							slog.Duration("duration", testDuration),
   100  							slog.Time("time", testTime),
   101  							slog.Any("error", testError),
   102  							slog.String("string", testString),
   103  							slog.Int("status", testInt),
   104  							slog.Duration("duration", testDuration),
   105  							slog.Time("time", testTime),
   106  							slog.Any("error", testError),
   107  							slog.String("string", testString),
   108  							slog.Int("status", testInt),
   109  							slog.Duration("duration", testDuration),
   110  							slog.Time("time", testTime),
   111  							slog.Any("error", testError),
   112  							slog.String("string", testString),
   113  							slog.Int("status", testInt),
   114  							slog.Duration("duration", testDuration),
   115  							slog.Time("time", testTime),
   116  							slog.Any("error", testError),
   117  							slog.String("string", testString),
   118  							slog.Int("status", testInt),
   119  							slog.Duration("duration", testDuration),
   120  							slog.Time("time", testTime),
   121  							slog.Any("error", testError),
   122  							slog.String("string", testString),
   123  							slog.Int("status", testInt),
   124  							slog.Duration("duration", testDuration),
   125  							slog.Time("time", testTime),
   126  							slog.Any("error", testError),
   127  							slog.String("string", testString),
   128  							slog.Int("status", testInt),
   129  							slog.Duration("duration", testDuration),
   130  							slog.Time("time", testTime),
   131  							slog.Any("error", testError),
   132  							slog.String("string", testString),
   133  							slog.Int("status", testInt),
   134  							slog.Duration("duration", testDuration),
   135  							slog.Time("time", testTime),
   136  							slog.Any("error", testError),
   137  						)
   138  					},
   139  				},
   140  			} {
   141  				b.Run(call.name, func(b *testing.B) {
   142  					b.ReportAllocs()
   143  					b.RunParallel(func(pb *testing.PB) {
   144  						for pb.Next() {
   145  							call.f()
   146  						}
   147  					})
   148  				})
   149  			}
   150  		})
   151  	}
   152  }
   153
View as plain text