slog-handler-guide: WithXXX methods without pre-formatting Change-Id: Ia95d8ddd50eb72bef057768d88b216d7b9809c58 Reviewed-on: https://go-review.googlesource.com/c/example/+/511576 TryBot-Result: Gopher Robot <gobot@golang.org> Run-TryBot: Jonathan Amsterdam <jba@google.com> Reviewed-by: Ian Cottrell <iancottrell@google.com>
diff --git a/slog-handler-guide/README.md b/slog-handler-guide/README.md index db36fad..4dc72d1 100644 --- a/slog-handler-guide/README.md +++ b/slog-handler-guide/README.md
@@ -325,13 +325,13 @@ ignored. Then it switches on the attribute kind to determine what format to use. For most -(the default case of the switch), it relies on `slog.Value`'s `String` method to +kinds (the default case of the switch), it relies on `slog.Value`'s `String` method to produce something reasonable. It handles strings and times specially: strings by quoting them, and times by formatting them in a standard way. When `appendAttr` sees a `Group`, it calls itself recursively on the group's attributes, after applying two more handler rules. -First, a group with no attributes is ignored&emdash;not even its key is displayed. +First, a group with no attributes is ignored—not even its key is displayed. Second, a group with an empty key is inlined: the group boundary isn't marked in any way. In our case, that means the group's attributes aren't indented. @@ -360,8 +360,7 @@ creates a new logger, `logger2`, with an additional attribute, but has no effect on `logger1`. - -We will show an example implementation of `WithAttrs` below, when we discuss `WithGroup`. +We will show example implementations of `WithAttrs` below, when we discuss `WithGroup`. ## The `WithGroup` method @@ -390,7 +389,128 @@ We will look at two implementations of `WithGroup` and `WithAttrs`, one that pre-formats and one that doesn't. -TODO(jba): add IndentHandler examples +### Without pre-formatting + +Our first implementation will collect the information from `WithGroup` and +`WithAttrs` calls to build up a slice of group names and attribute lists, +and loop over that slice in `Handle`. We start with a struct that can hold +either a group name or some attributes: + +``` +// groupOrAttrs holds either a group name or a list of slog.Attrs. +type groupOrAttrs struct { + group string // group name if non-empty + attrs []slog.Attr // attrs if non-empty +} +``` + +Then we add a slice of `groupOrAttrs` to our handler: + +``` +type IndentHandler struct { + opts Options + goas []groupOrAttrs + mu *sync.Mutex + out io.Writer +} +``` + +As stated above, The `WithGroup` and `WithAttrs` methods should not modify their +receiver. +To that end, we define a method that will copy our handler struct +and append one `groupOrAttrs` to the copy: + +``` +func (h *IndentHandler) withGroupOrAttrs(goa groupOrAttrs) *IndentHandler { + h2 := *h + h2.goas = make([]groupOrAttrs, len(h.goas)+1) + copy(h2.goas, h.goas) + h2.goas[len(h2.goas)-1] = goa + return &h2 +} +``` + +Most of the fields of `IndentHandler` can be copied shallowly, but the slice of +`groupOrAttrs` requires a deep copy, or the clone and the original will point to +the same underlying array. If we used `append` instead of making an explicit +copy, we would introduce that subtle aliasing bug. + +Using `withGroupOrAttrs`, the `With` methods are easy: + +``` +func (h *IndentHandler) WithGroup(name string) slog.Handler { + if name == "" { + return h + } + return h.withGroupOrAttrs(groupOrAttrs{group: name}) +} + +func (h *IndentHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + if len(attrs) == 0 { + return h + } + return h.withGroupOrAttrs(groupOrAttrs{attrs: attrs}) +} +``` + +The `Handle` method can now process the groupOrAttrs slice after +the built-in attributes and before the ones in the record: + +``` +func (h *IndentHandler) Handle(ctx context.Context, r slog.Record) error { + buf := make([]byte, 0, 1024) + if !r.Time.IsZero() { + buf = h.appendAttr(buf, slog.Time(slog.TimeKey, r.Time), 0) + } + buf = h.appendAttr(buf, slog.Any(slog.LevelKey, r.Level), 0) + if r.PC != 0 { + fs := runtime.CallersFrames([]uintptr{r.PC}) + f, _ := fs.Next() + buf = h.appendAttr(buf, slog.String(slog.SourceKey, fmt.Sprintf("%s:%d", f.File, f.Line)), 0) + } + buf = h.appendAttr(buf, slog.String(slog.MessageKey, r.Message), 0) + indentLevel := 0 + // Handle state from WithGroup and WithAttrs. + goas := h.goas + if r.NumAttrs() == 0 { + // If the record has no Attrs, remove groups at the end of the list; they are empty. + for len(goas) > 0 && goas[len(goas)-1].group != "" { + goas = goas[:len(goas)-1] + } + } + for _, goa := range goas { + if goa.group != "" { + buf = fmt.Appendf(buf, "%*s%s:\n", indentLevel*4, "", goa.group) + indentLevel++ + } else { + for _, a := range goa.attrs { + buf = h.appendAttr(buf, a, indentLevel) + } + } + } + r.Attrs(func(a slog.Attr) bool { + buf = h.appendAttr(buf, a, indentLevel) + return true + }) + buf = append(buf, "---\n"...) + h.mu.Lock() + defer h.mu.Unlock() + _, err := h.out.Write(buf) + return err +} +``` + +You may have noticed that our algorithm for +recording `WithGroup` and `WithAttrs` information is quadratic in the +number of calls to those methods, because of the repeated copying. +That is unlikely to matter in practice, but if it bothers you, +you can use a linked list instead, +which `Handle` will have to reverse or visit recursively. +See [github.com/jba/slog/withsupport](https://github.com/jba/slog/withsupport) for an implementation. + +### With pre-formatting + +TODO(jba): write ## Testing @@ -465,7 +585,7 @@ What should happen in the default case, when the handler encounters a `Kind` that it doesn't know about? The built-in handlers try to muddle through by using the result of the value's -`String` method. +`String` method, as our example handler does. They do not panic or return an error. Your own handlers might in addition want to report the problem through your production monitoring or error-tracking telemetry system.
diff --git a/slog-handler-guide/guide.md b/slog-handler-guide/guide.md index a87ebc8..922cdd7 100644 --- a/slog-handler-guide/guide.md +++ b/slog-handler-guide/guide.md
@@ -228,7 +228,7 @@ When `appendAttr` sees a `Group`, it calls itself recursively on the group's attributes, after applying two more handler rules. -First, a group with no attributes is ignored&emdash;not even its key is displayed. +First, a group with no attributes is ignored—not even its key is displayed. Second, a group with an empty key is inlined: the group boundary isn't marked in any way. In our case, that means the group's attributes aren't indented. @@ -257,8 +257,7 @@ creates a new logger, `logger2`, with an additional attribute, but has no effect on `logger1`. - -We will show an example implementation of `WithAttrs` below, when we discuss `WithGroup`. +We will show example implementations of `WithAttrs` below, when we discuss `WithGroup`. ## The `WithGroup` method @@ -287,7 +286,51 @@ We will look at two implementations of `WithGroup` and `WithAttrs`, one that pre-formats and one that doesn't. -TODO(jba): add IndentHandler examples +### Without pre-formatting + +Our first implementation will collect the information from `WithGroup` and +`WithAttrs` calls to build up a slice of group names and attribute lists, +and loop over that slice in `Handle`. We start with a struct that can hold +either a group name or some attributes: + +%include indenthandler2/indent_handler.go gora - + +Then we add a slice of `groupOrAttrs` to our handler: + +%include indenthandler2/indent_handler.go IndentHandler - + +As stated above, The `WithGroup` and `WithAttrs` methods should not modify their +receiver. +To that end, we define a method that will copy our handler struct +and append one `groupOrAttrs` to the copy: + +%include indenthandler2/indent_handler.go withgora - + +Most of the fields of `IndentHandler` can be copied shallowly, but the slice of +`groupOrAttrs` requires a deep copy, or the clone and the original will point to +the same underlying array. If we used `append` instead of making an explicit +copy, we would introduce that subtle aliasing bug. + +Using `withGroupOrAttrs`, the `With` methods are easy: + +%include indenthandler2/indent_handler.go withs - + +The `Handle` method can now process the groupOrAttrs slice after +the built-in attributes and before the ones in the record: + +%include indenthandler2/indent_handler.go handle - + +You may have noticed that our algorithm for +recording `WithGroup` and `WithAttrs` information is quadratic in the +number of calls to those methods, because of the repeated copying. +That is unlikely to matter in practice, but if it bothers you, +you can use a linked list instead, +which `Handle` will have to reverse or visit recursively. +See [github.com/jba/slog/withsupport](https://github.com/jba/slog/withsupport) for an implementation. + +### With pre-formatting + +TODO(jba): write ## Testing @@ -362,7 +405,7 @@ What should happen in the default case, when the handler encounters a `Kind` that it doesn't know about? The built-in handlers try to muddle through by using the result of the value's -`String` method. +`String` method, as our example handler does. They do not panic or return an error. Your own handlers might in addition want to report the problem through your production monitoring or error-tracking telemetry system.
diff --git a/slog-handler-guide/indenthandler2/indent_handler.go b/slog-handler-guide/indenthandler2/indent_handler.go new file mode 100644 index 0000000..459ed46 --- /dev/null +++ b/slog-handler-guide/indenthandler2/indent_handler.go
@@ -0,0 +1,164 @@ +//go:build go1.21 + +package indenthandler + +import ( + "context" + "fmt" + "io" + "log/slog" + "runtime" + "sync" + "time" +) + +// !+IndentHandler +type IndentHandler struct { + opts Options + goas []groupOrAttrs + mu *sync.Mutex + out io.Writer +} + +//!-IndentHandler + +type Options struct { + // Level reports the minimum level to log. + // Levels with lower levels are discarded. + // If nil, the Handler uses [slog.LevelInfo]. + Level slog.Leveler +} + +// !+gora +// groupOrAttrs holds either a group name or a list of slog.Attrs. +type groupOrAttrs struct { + group string // group name if non-empty + attrs []slog.Attr // attrs if non-empty +} + +//!-gora + +func New(out io.Writer, opts *Options) *IndentHandler { + h := &IndentHandler{out: out, mu: &sync.Mutex{}} + if opts != nil { + h.opts = *opts + } + if h.opts.Level == nil { + h.opts.Level = slog.LevelInfo + } + return h +} + +func (h *IndentHandler) Enabled(ctx context.Context, level slog.Level) bool { + return level >= h.opts.Level.Level() +} + +// !+withs +func (h *IndentHandler) WithGroup(name string) slog.Handler { + if name == "" { + return h + } + return h.withGroupOrAttrs(groupOrAttrs{group: name}) +} + +func (h *IndentHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + if len(attrs) == 0 { + return h + } + return h.withGroupOrAttrs(groupOrAttrs{attrs: attrs}) +} + +//!-withs + +// !+withgora +func (h *IndentHandler) withGroupOrAttrs(goa groupOrAttrs) *IndentHandler { + h2 := *h + h2.goas = make([]groupOrAttrs, len(h.goas)+1) + copy(h2.goas, h.goas) + h2.goas[len(h2.goas)-1] = goa + return &h2 +} + +//!-withgora + +// !+handle +func (h *IndentHandler) Handle(ctx context.Context, r slog.Record) error { + buf := make([]byte, 0, 1024) + if !r.Time.IsZero() { + buf = h.appendAttr(buf, slog.Time(slog.TimeKey, r.Time), 0) + } + buf = h.appendAttr(buf, slog.Any(slog.LevelKey, r.Level), 0) + if r.PC != 0 { + fs := runtime.CallersFrames([]uintptr{r.PC}) + f, _ := fs.Next() + buf = h.appendAttr(buf, slog.String(slog.SourceKey, fmt.Sprintf("%s:%d", f.File, f.Line)), 0) + } + buf = h.appendAttr(buf, slog.String(slog.MessageKey, r.Message), 0) + indentLevel := 0 + // Handle state from WithGroup and WithAttrs. + goas := h.goas + if r.NumAttrs() == 0 { + // If the record has no Attrs, remove groups at the end of the list; they are empty. + for len(goas) > 0 && goas[len(goas)-1].group != "" { + goas = goas[:len(goas)-1] + } + } + for _, goa := range goas { + if goa.group != "" { + buf = fmt.Appendf(buf, "%*s%s:\n", indentLevel*4, "", goa.group) + indentLevel++ + } else { + for _, a := range goa.attrs { + buf = h.appendAttr(buf, a, indentLevel) + } + } + } + r.Attrs(func(a slog.Attr) bool { + buf = h.appendAttr(buf, a, indentLevel) + return true + }) + buf = append(buf, "---\n"...) + h.mu.Lock() + defer h.mu.Unlock() + _, err := h.out.Write(buf) + return err +} + +//!-handle + +func (h *IndentHandler) appendAttr(buf []byte, a slog.Attr, indentLevel int) []byte { + // Resolve the Attr's value before doing anything else. + a.Value = a.Value.Resolve() + // Ignore empty Attrs. + if a.Equal(slog.Attr{}) { + return buf + } + // Indent 4 spaces per level. + buf = fmt.Appendf(buf, "%*s", indentLevel*4, "") + switch a.Value.Kind() { + case slog.KindString: + // Quote string values, to make them easy to parse. + buf = fmt.Appendf(buf, "%s: %q\n", a.Key, a.Value.String()) + case slog.KindTime: + // Write times in a standard way, without the monotonic time. + buf = fmt.Appendf(buf, "%s: %s\n", a.Key, a.Value.Time().Format(time.RFC3339Nano)) + case slog.KindGroup: + attrs := a.Value.Group() + // Ignore empty groups. + if len(attrs) == 0 { + return buf + } + // If the key is non-empty, write it out and indent the rest of the attrs. + // Otherwise, inline the attrs. + if a.Key != "" { + buf = fmt.Appendf(buf, "%s:\n", a.Key) + indentLevel++ + } + for _, ga := range attrs { + buf = h.appendAttr(buf, ga, indentLevel) + } + default: + buf = fmt.Appendf(buf, "%s: %s\n", a.Key, a.Value) + } + return buf +}
diff --git a/slog-handler-guide/indenthandler2/indent_handler_test.go b/slog-handler-guide/indenthandler2/indent_handler_test.go new file mode 100644 index 0000000..4063352 --- /dev/null +++ b/slog-handler-guide/indenthandler2/indent_handler_test.go
@@ -0,0 +1,157 @@ +//go:build go1.21 + +package indenthandler + +import ( + "bufio" + "bytes" + "fmt" + "reflect" + "regexp" + "strconv" + "strings" + "testing" + "unicode" + + "log/slog" + "testing/slogtest" +) + +func TestSlogtest(t *testing.T) { + var buf bytes.Buffer + err := slogtest.TestHandler(New(&buf, nil), func() []map[string]any { + return parseLogEntries(buf.String()) + }) + if err != nil { + t.Error(err) + } +} + +func Test(t *testing.T) { + var buf bytes.Buffer + l := slog.New(New(&buf, nil)) + l.Info("hello", "a", 1, "b", true, "c", 3.14, slog.Group("g", "h", 1, "i", 2), "d", "NO") + got := buf.String() + wantre := `time: [-0-9T:.]+Z? +level: INFO +source: ".*/indent_handler_test.go:\d+" +msg: "hello" +a: 1 +b: true +c: 3.14 +g: + h: 1 + i: 2 +d: "NO" +` + re := regexp.MustCompile(wantre) + if !re.MatchString(got) { + t.Errorf("\ngot:\n%q\nwant:\n%q", got, wantre) + } + + buf.Reset() + l.Debug("test") + if got := buf.Len(); got != 0 { + t.Errorf("got buf.Len() = %d, want 0", got) + } +} + +func parseLogEntries(s string) []map[string]any { + var ms []map[string]any + scan := bufio.NewScanner(strings.NewReader(s)) + for scan.Scan() { + m := parseGroup(scan) + ms = append(ms, m) + } + if scan.Err() != nil { + panic(scan.Err()) + } + return ms +} + +func parseGroup(scan *bufio.Scanner) map[string]any { + m := map[string]any{} + groupIndent := -1 + for { + line := scan.Text() + if line == "---" { // end of entry + break + } + k, v, found := strings.Cut(line, ":") + if !found { + panic(fmt.Sprintf("no ':' in line %q", line)) + } + indent := strings.IndexFunc(k, func(r rune) bool { + return !unicode.IsSpace(r) + }) + if indent < 0 { + panic("blank line") + } + if groupIndent < 0 { + // First line in group; remember the indent. + groupIndent = indent + } else if indent < groupIndent { + // End of group + break + } else if indent > groupIndent { + panic(fmt.Sprintf("indent increased on line %q", line)) + } + + key := strings.TrimSpace(k) + if v == "" { + // Just a key: start of a group. + if !scan.Scan() { + panic("empty group") + } + m[key] = parseGroup(scan) + } else { + v = strings.TrimSpace(v) + if len(v) > 0 && v[0] == '"' { + var err error + v, err = strconv.Unquote(v) + if err != nil { + panic(err) + } + } + m[key] = v + if !scan.Scan() { + break + } + } + } + return m +} + +func TestParseLogEntries(t *testing.T) { + in := ` +a: 1 +b: 2 +c: 3 +g: + h: 4 + i: 5 +d: 6 +--- +e: 7 +--- +` + want := []map[string]any{ + { + "a": "1", + "b": "2", + "c": "3", + "g": map[string]any{ + "h": "4", + "i": "5", + }, + "d": "6", + }, + { + "e": "7", + }, + } + got := parseLogEntries(in[1:]) + if !reflect.DeepEqual(got, want) { + t.Errorf("\ngot:\n%v\nwant:\n%v", got, want) + } +}