diff --git a/funcr/funcr.go b/funcr/funcr.go index fb2f866..30568e7 100644 --- a/funcr/funcr.go +++ b/funcr/funcr.go @@ -236,15 +236,14 @@ func newFormatter(opts Options, outfmt outputFormat) Formatter { // implementation. It should be constructed with NewFormatter. Some of // its methods directly implement logr.LogSink. type Formatter struct { - outputFormat outputFormat - prefix string - values []any - valuesStr string - parentValuesStr string - depth int - opts *Options - group string // for slog groups - groupDepth int + outputFormat outputFormat + prefix string + values []any + valuesStr string + depth int + opts *Options + groupName string // for slog groups + groups []groupDef } // outputFormat indicates which outputFormat to use. @@ -257,6 +256,13 @@ const ( outputJSON ) +// groupDef represents a saved group. The values may be empty, but we don't +// know if we need to render the group until the final record is rendered. +type groupDef struct { + name string + values string +} + // PseudoStruct is a list of key-value pairs that gets logged as a struct. type PseudoStruct []any @@ -264,76 +270,102 @@ type PseudoStruct []any func (f Formatter) render(builtins, args []any) string { // Empirically bytes.Buffer is faster than strings.Builder for this. buf := bytes.NewBuffer(make([]byte, 0, 1024)) + if f.outputFormat == outputJSON { - buf.WriteByte('{') // for the whole line + buf.WriteByte('{') // for the whole record } + // Render builtins vals := builtins if hook := f.opts.RenderBuiltinsHook; hook != nil { vals = hook(f.sanitize(vals)) } - f.flatten(buf, vals, false, false) // keys are ours, no need to escape + f.flatten(buf, vals, false) // keys are ours, no need to escape continuing := len(builtins) > 0 - if f.parentValuesStr != "" { - if continuing { - buf.WriteByte(f.comma()) + // Turn the inner-most group into a string + argsStr := func() string { + buf := bytes.NewBuffer(make([]byte, 0, 1024)) + + vals = args + if hook := f.opts.RenderArgsHook; hook != nil { + vals = hook(f.sanitize(vals)) } - buf.WriteString(f.parentValuesStr) - continuing = true - } + f.flatten(buf, vals, true) // escape user-provided keys - groupDepth := f.groupDepth - if f.group != "" { - if f.valuesStr != "" || len(args) != 0 { - if continuing { - buf.WriteByte(f.comma()) - } - buf.WriteString(f.quoted(f.group, true)) // escape user-provided keys - buf.WriteByte(f.colon()) - buf.WriteByte('{') // for the group - continuing = false - } else { - // The group was empty - groupDepth-- + return buf.String() + }() + + // Render the stack of groups from the inside out. + bodyStr := f.renderGroup(f.groupName, f.valuesStr, argsStr) + for i := len(f.groups) - 1; i >= 0; i-- { + grp := &f.groups[i] + if grp.values == "" && bodyStr == "" { + // no contents, so we must elide the whole group + continue } + bodyStr = f.renderGroup(grp.name, grp.values, bodyStr) } - if f.valuesStr != "" { + if bodyStr != "" { if continuing { buf.WriteByte(f.comma()) } - buf.WriteString(f.valuesStr) - continuing = true + buf.WriteString(bodyStr) } - vals = args - if hook := f.opts.RenderArgsHook; hook != nil { - vals = hook(f.sanitize(vals)) + if f.outputFormat == outputJSON { + buf.WriteByte('}') // for the whole record } - f.flatten(buf, vals, continuing, true) // escape user-provided keys - for i := 0; i < groupDepth; i++ { - buf.WriteByte('}') // for the groups + return buf.String() +} + +// renderGroup returns a string representation of the named group with rendered +// values and args. If the name is empty, this will return the values and args, +// joined. If the name is not empty, this will return a single key-value pair, +// where the value is a grouping of the values and args. If the values and +// args are both empty, this will return an empty string, even if the name was +// specified. +func (f Formatter) renderGroup(name string, values string, args string) string { + buf := bytes.NewBuffer(make([]byte, 0, 1024)) + + needClosingBrace := false + if name != "" && (values != "" || args != "") { + buf.WriteString(f.quoted(name, true)) // escape user-provided keys + buf.WriteByte(f.colon()) + buf.WriteByte('{') + needClosingBrace = true } - if f.outputFormat == outputJSON { - buf.WriteByte('}') // for the whole line + continuing := false + if values != "" { + buf.WriteString(values) + continuing = true + } + + if args != "" { + if continuing { + buf.WriteByte(f.comma()) + } + buf.WriteString(args) + } + + if needClosingBrace { + buf.WriteByte('}') } return buf.String() } -// flatten renders a list of key-value pairs into a buffer. If continuing is -// true, it assumes that the buffer has previous values and will emit a -// separator (which depends on the output format) before the first pair it -// writes. If escapeKeys is true, the keys are assumed to have -// non-JSON-compatible characters in them and must be evaluated for escapes. +// flatten renders a list of key-value pairs into a buffer. If escapeKeys is +// true, the keys are assumed to have non-JSON-compatible characters in them +// and must be evaluated for escapes. // // This function returns a potentially modified version of kvList, which // ensures that there is a value for every key (adding a value if needed) and // that each key is a string (substituting a key if needed). -func (f Formatter) flatten(buf *bytes.Buffer, kvList []any, continuing bool, escapeKeys bool) []any { +func (f Formatter) flatten(buf *bytes.Buffer, kvList []any, escapeKeys bool) []any { // This logic overlaps with sanitize() but saves one type-cast per key, // which can be measurable. if len(kvList)%2 != 0 { @@ -354,7 +386,7 @@ func (f Formatter) flatten(buf *bytes.Buffer, kvList []any, continuing bool, esc } v := kvList[i+1] - if i > 0 || continuing { + if i > 0 { if f.outputFormat == outputJSON { buf.WriteByte(f.comma()) } else { @@ -766,46 +798,17 @@ func (f Formatter) sanitize(kvList []any) []any { // startGroup opens a new group scope (basically a sub-struct), which locks all // the current saved values and starts them anew. This is needed to satisfy // slog. -func (f *Formatter) startGroup(group string) { +func (f *Formatter) startGroup(name string) { // Unnamed groups are just inlined. - if group == "" { + if name == "" { return } - // Any saved values can no longer be changed. - buf := bytes.NewBuffer(make([]byte, 0, 1024)) - continuing := false - - if f.parentValuesStr != "" { - buf.WriteString(f.parentValuesStr) - continuing = true - } - - if f.group != "" && f.valuesStr != "" { - if continuing { - buf.WriteByte(f.comma()) - } - buf.WriteString(f.quoted(f.group, true)) // escape user-provided keys - buf.WriteByte(f.colon()) - buf.WriteByte('{') // for the group - continuing = false - } - - if f.valuesStr != "" { - if continuing { - buf.WriteByte(f.comma()) - } - buf.WriteString(f.valuesStr) - } - - // NOTE: We don't close the scope here - that's done later, when a log line - // is actually rendered (because we have N scopes to close). - - f.parentValuesStr = buf.String() + n := len(f.groups) + f.groups = append(f.groups[:n:n], groupDef{f.groupName, f.valuesStr}) // Start collecting new values. - f.group = group - f.groupDepth++ + f.groupName = name f.valuesStr = "" f.values = nil } @@ -900,7 +903,7 @@ func (f *Formatter) AddValues(kvList []any) { // Pre-render values, so we don't have to do it on each Info/Error call. buf := bytes.NewBuffer(make([]byte, 0, 1024)) - f.flatten(buf, vals, false, true) // escape user-provided keys + f.flatten(buf, vals, true) // escape user-provided keys f.valuesStr = buf.String() } diff --git a/funcr/slogsink_test.go b/funcr/slogsink_test.go index 9fbe55a..8fb8467 100644 --- a/funcr/slogsink_test.go +++ b/funcr/slogsink_test.go @@ -83,19 +83,100 @@ func TestSlogSink(t *testing.T) { } } -func TestSlogSinkNestedGroups(t *testing.T) { - capt := &capture{} - logger := logr.New(newSink(capt.Func, NewFormatterJSON(Options{}))) - slogger := slog.New(logr.ToSlogHandler(logger)) - slogger = slogger.With("out", 0) - slogger = slogger.WithGroup("g1").With("mid1", 1) - slogger = slogger.WithGroup("g2").With("mid2", 2) - slogger = slogger.WithGroup("g3").With("in", 3) - slogger.Info("msg", "k", "v") +func TestSlogSinkGroups(t *testing.T) { + testCases := []struct { + name string + fn func(slogger *slog.Logger) + expect string + }{{ + name: "no group", + fn: func(slogger *slog.Logger) { + slogger. + Info("msg", "k", "v") + }, + expect: `{"logger":"","level":0,"msg":"msg","k":"v"}`, + }, { + name: "1 group with leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1"). + Info("msg", "k", "v") + }, + expect: `{"logger":"","level":0,"msg":"msg","g1":{"k":"v"}}`, + }, { + name: "1 group without leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1"). + Info("msg") + }, + expect: `{"logger":"","level":0,"msg":"msg"}`, + }, { + name: "1 group with value without leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1").With("k1", 1). + Info("msg") + }, + expect: `{"logger":"","level":0,"msg":"msg","g1":{"k1":1}}`, + }, { + name: "2 groups with values no leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1").With("k1", 1). + WithGroup("g2").With("k2", 2). + Info("msg") + }, + expect: `{"logger":"","level":0,"msg":"msg","g1":{"k1":1,"g2":{"k2":2}}}`, + }, { + name: "3 empty groups with no values or leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1"). + WithGroup("g2"). + WithGroup("g3"). + Info("msg") + }, + expect: `{"logger":"","level":0,"msg":"msg"}`, + }, { + name: "3 empty groups with no values but with leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1"). + WithGroup("g2"). + WithGroup("g3"). + Info("msg", "k", "v") + }, + expect: `{"logger":"","level":0,"msg":"msg","g1":{"g2":{"g3":{"k":"v"}}}}`, + }, { + name: "multiple groups with and without values", + fn: func(slogger *slog.Logger) { + slogger. + With("k0", 0). + WithGroup("g1"). + WithGroup("g2"). + WithGroup("g3").With("k3", 3). + WithGroup("g4"). + WithGroup("g5"). + WithGroup("g6").With("k6", 6). + WithGroup("g7"). + WithGroup("g8"). + WithGroup("g9"). + Info("msg") + }, + expect: `{"logger":"","level":0,"msg":"msg","k0":0,"g1":{"g2":{"g3":{"k3":3,"g4":{"g5":{"g6":{"k6":6}}}}}}}`, + }} - expect := `{"logger":"","level":0,"msg":"msg","out":0,"g1":{"mid1":1,"g2":{"mid2":2,"g3":{"in":3,"k":"v"}}}}` - if capt.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, capt.log) + for _, tc := range testCases { + t.Run(tc.name, func(t *testing.T) { + capt := &capture{} + logger := logr.New(newSink(capt.Func, NewFormatterJSON(Options{}))) + slogger := slog.New(logr.ToSlogHandler(logger)) + tc.fn(slogger) + if capt.log != tc.expect { + t.Errorf("\nexpected: `%s`\n got: `%s`", tc.expect, capt.log) + } + }) } } diff --git a/slogr_test.go b/slogr_test.go index 077bfbe..91b8302 100644 --- a/slogr_test.go +++ b/slogr_test.go @@ -127,6 +127,7 @@ func TestRunSlogTestsOnSlogHandlerLogSink(t *testing.T) { "a Handler should handle the WithGroup method", "a Handler should handle multiple WithGroup and WithAttr calls", "a Handler should not output groups for an empty Record", + "a Handler should not output groups if there are no attributes", "a Handler should call Resolve on attribute values in groups", "a Handler should call Resolve on attribute values in groups from WithAttrs", }