Source file src/log/slog/json_handler_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 slog
     6  
     7  import (
     8  	"bytes"
     9  	"context"
    10  	"encoding/json"
    11  	"errors"
    12  	"fmt"
    13  	"io"
    14  	"log/slog/internal/buffer"
    15  	"math"
    16  	"os"
    17  	"path/filepath"
    18  	"strings"
    19  	"testing"
    20  	"time"
    21  )
    22  
    23  func TestJSONHandler(t *testing.T) {
    24  	for _, test := range []struct {
    25  		name string
    26  		opts HandlerOptions
    27  		want string
    28  	}{
    29  		{
    30  			"none",
    31  			HandlerOptions{},
    32  			`{"time":"2000-01-02T03:04:05Z","level":"INFO","msg":"m","a":1,"m":{"b":2}}`,
    33  		},
    34  		{
    35  			"replace",
    36  			HandlerOptions{ReplaceAttr: upperCaseKey},
    37  			`{"TIME":"2000-01-02T03:04:05Z","LEVEL":"INFO","MSG":"m","A":1,"M":{"b":2}}`,
    38  		},
    39  	} {
    40  		t.Run(test.name, func(t *testing.T) {
    41  			var buf bytes.Buffer
    42  			h := NewJSONHandler(&buf, &test.opts)
    43  			r := NewRecord(testTime, LevelInfo, "m", 0)
    44  			r.AddAttrs(Int("a", 1), Any("m", map[string]int{"b": 2}))
    45  			if err := h.Handle(context.Background(), r); err != nil {
    46  				t.Fatal(err)
    47  			}
    48  			got := strings.TrimSuffix(buf.String(), "\n")
    49  			if got != test.want {
    50  				t.Errorf("\ngot  %s\nwant %s", got, test.want)
    51  			}
    52  		})
    53  	}
    54  }
    55  
    56  // for testing json.Marshaler
    57  type jsonMarshaler struct {
    58  	s string
    59  }
    60  
    61  func (j jsonMarshaler) String() string { return j.s } // should be ignored
    62  
    63  func (j jsonMarshaler) MarshalJSON() ([]byte, error) {
    64  	if j.s == "" {
    65  		return nil, errors.New("json: empty string")
    66  	}
    67  	return []byte(fmt.Sprintf(`[%q]`, j.s)), nil
    68  }
    69  
    70  type jsonMarshalerError struct {
    71  	jsonMarshaler
    72  }
    73  
    74  func (jsonMarshalerError) Error() string { return "oops" }
    75  
    76  func TestAppendJSONValue(t *testing.T) {
    77  	// jsonAppendAttrValue should always agree with json.Marshal.
    78  	for _, value := range []any{
    79  		"hello\r\n\t\a",
    80  		`"[{escape}]"`,
    81  		"<escapeHTML&>",
    82  		// \u2028\u2029 is an edge case in JavaScript vs JSON.
    83  		// \xF6 is an incomplete encoding.
    84  		"\u03B8\u2028\u2029\uFFFF\xF6",
    85  		`-123`,
    86  		int64(-9_200_123_456_789_123_456),
    87  		uint64(9_200_123_456_789_123_456),
    88  		-12.75,
    89  		1.23e-9,
    90  		false,
    91  		time.Minute,
    92  		testTime,
    93  		jsonMarshaler{"xyz"},
    94  		jsonMarshalerError{jsonMarshaler{"pqr"}},
    95  		LevelWarn,
    96  	} {
    97  		got := jsonValueString(AnyValue(value))
    98  		want, err := marshalJSON(value)
    99  		if err != nil {
   100  			t.Fatal(err)
   101  		}
   102  		if got != want {
   103  			t.Errorf("%v: got %s, want %s", value, got, want)
   104  		}
   105  	}
   106  }
   107  
   108  func marshalJSON(x any) (string, error) {
   109  	var buf bytes.Buffer
   110  	enc := json.NewEncoder(&buf)
   111  	enc.SetEscapeHTML(false)
   112  	if err := enc.Encode(x); err != nil {
   113  		return "", err
   114  	}
   115  	return strings.TrimSpace(buf.String()), nil
   116  }
   117  
   118  func TestJSONAppendAttrValueSpecial(t *testing.T) {
   119  	// Attr values that render differently from json.Marshal.
   120  	for _, test := range []struct {
   121  		value any
   122  		want  string
   123  	}{
   124  		{math.NaN(), `"!ERROR:json: unsupported value: NaN"`},
   125  		{math.Inf(+1), `"!ERROR:json: unsupported value: +Inf"`},
   126  		{math.Inf(-1), `"!ERROR:json: unsupported value: -Inf"`},
   127  		{io.EOF, `"EOF"`},
   128  	} {
   129  		got := jsonValueString(AnyValue(test.value))
   130  		if got != test.want {
   131  			t.Errorf("%v: got %s, want %s", test.value, got, test.want)
   132  		}
   133  	}
   134  }
   135  
   136  func jsonValueString(v Value) string {
   137  	var buf []byte
   138  	s := &handleState{h: &commonHandler{json: true}, buf: (*buffer.Buffer)(&buf)}
   139  	if err := appendJSONValue(s, v); err != nil {
   140  		s.appendError(err)
   141  	}
   142  	return string(buf)
   143  }
   144  
   145  func BenchmarkJSONHandler(b *testing.B) {
   146  	for _, bench := range []struct {
   147  		name string
   148  		opts HandlerOptions
   149  	}{
   150  		{"defaults", HandlerOptions{}},
   151  		{"time format", HandlerOptions{
   152  			ReplaceAttr: func(_ []string, a Attr) Attr {
   153  				v := a.Value
   154  				if v.Kind() == KindTime {
   155  					return String(a.Key, v.Time().Format(rfc3339Millis))
   156  				}
   157  				if a.Key == "level" {
   158  					return Attr{"severity", a.Value}
   159  				}
   160  				return a
   161  			},
   162  		}},
   163  		{"time unix", HandlerOptions{
   164  			ReplaceAttr: func(_ []string, a Attr) Attr {
   165  				v := a.Value
   166  				if v.Kind() == KindTime {
   167  					return Int64(a.Key, v.Time().UnixNano())
   168  				}
   169  				if a.Key == "level" {
   170  					return Attr{"severity", a.Value}
   171  				}
   172  				return a
   173  			},
   174  		}},
   175  	} {
   176  		b.Run(bench.name, func(b *testing.B) {
   177  			ctx := context.Background()
   178  			l := New(NewJSONHandler(io.Discard, &bench.opts)).With(
   179  				String("program", "my-test-program"),
   180  				String("package", "log/slog"),
   181  				String("traceID", "2039232309232309"),
   182  				String("URL", "https://pkg.go.dev/golang.org/x/log/slog"))
   183  			b.ReportAllocs()
   184  			b.ResetTimer()
   185  			for i := 0; i < b.N; i++ {
   186  				l.LogAttrs(ctx, LevelInfo, "this is a typical log message",
   187  					String("module", "github.com/google/go-cmp"),
   188  					String("version", "v1.23.4"),
   189  					Int("count", 23),
   190  					Int("number", 123456),
   191  				)
   192  			}
   193  		})
   194  	}
   195  }
   196  
   197  func BenchmarkPreformatting(b *testing.B) {
   198  	type req struct {
   199  		Method  string
   200  		URL     string
   201  		TraceID string
   202  		Addr    string
   203  	}
   204  
   205  	structAttrs := []any{
   206  		String("program", "my-test-program"),
   207  		String("package", "log/slog"),
   208  		Any("request", &req{
   209  			Method:  "GET",
   210  			URL:     "https://pkg.go.dev/golang.org/x/log/slog",
   211  			TraceID: "2039232309232309",
   212  			Addr:    "127.0.0.1:8080",
   213  		}),
   214  	}
   215  
   216  	outFile, err := os.Create(filepath.Join(b.TempDir(), "bench.log"))
   217  	if err != nil {
   218  		b.Fatal(err)
   219  	}
   220  	defer func() {
   221  		if err := outFile.Close(); err != nil {
   222  			b.Fatal(err)
   223  		}
   224  	}()
   225  
   226  	for _, bench := range []struct {
   227  		name  string
   228  		wc    io.Writer
   229  		attrs []any
   230  	}{
   231  		{"separate", io.Discard, []any{
   232  			String("program", "my-test-program"),
   233  			String("package", "log/slog"),
   234  			String("method", "GET"),
   235  			String("URL", "https://pkg.go.dev/golang.org/x/log/slog"),
   236  			String("traceID", "2039232309232309"),
   237  			String("addr", "127.0.0.1:8080"),
   238  		}},
   239  		{"struct", io.Discard, structAttrs},
   240  		{"struct file", outFile, structAttrs},
   241  	} {
   242  		ctx := context.Background()
   243  		b.Run(bench.name, func(b *testing.B) {
   244  			l := New(NewJSONHandler(bench.wc, nil)).With(bench.attrs...)
   245  			b.ReportAllocs()
   246  			b.ResetTimer()
   247  			for i := 0; i < b.N; i++ {
   248  				l.LogAttrs(ctx, LevelInfo, "this is a typical log message",
   249  					String("module", "github.com/google/go-cmp"),
   250  					String("version", "v1.23.4"),
   251  					Int("count", 23),
   252  					Int("number", 123456),
   253  				)
   254  			}
   255  		})
   256  	}
   257  }
   258  
   259  func BenchmarkJSONEncoding(b *testing.B) {
   260  	value := 3.14
   261  	buf := buffer.New()
   262  	defer buf.Free()
   263  	b.Run("json.Marshal", func(b *testing.B) {
   264  		b.ReportAllocs()
   265  		for i := 0; i < b.N; i++ {
   266  			by, err := json.Marshal(value)
   267  			if err != nil {
   268  				b.Fatal(err)
   269  			}
   270  			buf.Write(by)
   271  			*buf = (*buf)[:0]
   272  		}
   273  	})
   274  	b.Run("Encoder.Encode", func(b *testing.B) {
   275  		b.ReportAllocs()
   276  		for i := 0; i < b.N; i++ {
   277  			if err := json.NewEncoder(buf).Encode(value); err != nil {
   278  				b.Fatal(err)
   279  			}
   280  			*buf = (*buf)[:0]
   281  		}
   282  	})
   283  	_ = buf
   284  }
   285  

View as plain text