Merge pull request #274 from thockin/master

funcr: Handle nested empty groups properly

Author: pohly

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,83 +256,116 @@ 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
 
 // render produces a log line, ready to use.
 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()
 }
 

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)
+			}
+		})
 	}
 }
 

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",
 	}