slog-handler-guide: handler example: types

Begin discussing a running example of a slog.Handler implementation.

Initially we'll ignore the WithAttrs and WithGroup methods.
The implementation that does that is in indenthandler1.
This CL contains the complete implementation, but discusses
only the types and constructor function.

Change-Id: I3b635aee66a6d5df64bc13ce6bfb7ae4881606fe
Reviewed-on: https://go-review.googlesource.com/c/example/+/509955
Reviewed-by: Ian Cottrell <iancottrell@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Run-TryBot: Jonathan Amsterdam <jba@google.com>

Author: jba

slog-handler-guide/README.md

@@ -87,17 +87,74 @@ A logger's `WithGroup` method calls its handler's `WithGroup` method.
 # Implementing `Handler` methods
 
 We can now talk about the four `Handler` methods in detail.
-Along the way, we will write a handler that formats logs in YAML.
-It will display this log output call:
+Along the way, we will write a handler that formats logs using a format
+reminsicent of YAML. It will display this log output call:
 
     logger.Info("hello", "key", 23)
 
-as this YAML document:
+something like this:
 
     time: 2023-05-15T16:29:00
     level: INFO
-    message: hello
+    message: "hello"
     key: 23
+    ---
+
+Although this particular output is valid YAML,
+our implementation doesn't consider the subtleties of YAML syntax,
+so it will sometimes produce invalid YAML.
+For example, it doesn't quote keys that have colons in them.
+We'll call it `IndentHandler` to forestall disappointment.
+
+We begin with the `IndentHandler` type
+and the `New` function that constructs it from an `io.Writer` and options:
+
+```
+type IndentHandler struct {
+	opts Options
+	// TODO: state for WithGroup and WithAttrs
+	mu  *sync.Mutex
+	out io.Writer
+}
+
+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
+}
+
+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
+}
+```
+
+We'll support only one option, the ability to set a minimum level in order to
+supress detailed log output.
+Handlers should always use the `slog.Leveler` type for this option.
+`Leveler` is implemented by both `Level` and `LevelVar`.
+A `Level` value is easy for the user to provide,
+but changing the level of multiple handlers requires tracking them all.
+If the user instead passes a `LevelVar`, then a single change to that `LevelVar`
+will change the behavior of all handlers that contain it.
+Changes to `LevelVar`s are goroutine-safe.
+
+The mutex will be used to ensure that writes to the `io.Writer` happen atomically.
+Unusually, `IndentHandler` holds a pointer to a `sync.Mutex` rather than holding a
+`sync.Mutex` directly.
+But there is a good reason for that, which we'll explain later.
+
+TODO(jba): add link to that later explanation.
+
+Our handler will need additional state to track calls to `WithGroup` and `WithAttrs`.
+We will describe that state when we get to those methods.
 
 ## The `Enabled` method
 
@@ -116,23 +173,7 @@ A handler's `Enabled` method could report whether the argument level
 is greater than or equal to the context value, allowing the verbosity
 of the work done by each request to be controlled independently.
 
-Most implementations of `Enabled` will consult a configured minimum level
-instead. For maximum generality, use the `Leveler` type in the configuration of
-your handler, as the built-in `HandlerOptions` does.
-
-Our YAML handler's constructor will take a `Leveler`, along with an `io.Writer`
-for its output:
-
-TODO(jba): include func yamlhandler.New(w io.Writer, level slog.Leveler)
-
-`Leveler` is implemented by both `Level` and `LevelVar`.
-A `Level` value is easy for the user to provide,
-but changing the level of multiple handlers requires tracking them all.
-If the user instead passes a `LevelVar`, then a single change to that `LevelVar`
-will change the behavior of all handlers that contain it.
-Changes to `LevelVar`s are goroutine-safe.
-
-TODO(jba): example handler that implements a minimum level and delegates the other methods.
+TODO(jba): include Enabled example
 
 ## The `WithAttrs` method
 
@@ -189,7 +230,7 @@ the implementations of `Handler.WithGroup` and `Handler.WithAttrs`.
 We will look at two implementations of `WithGroup` and `WithAttrs`, one that pre-formats and
 one that doesn't.
 
-TODO(jba): add YAML handler examples
+TODO(jba): add IndentHandler examples
 
 ## The `Handle` method
 

slog-handler-guide/guide.md

@@ -76,17 +76,49 @@ A logger's `WithGroup` method calls its handler's `WithGroup` method.
 # Implementing `Handler` methods
 
 We can now talk about the four `Handler` methods in detail.
-Along the way, we will write a handler that formats logs in YAML.
-It will display this log output call:
+Along the way, we will write a handler that formats logs using a format
+reminsicent of YAML. It will display this log output call:
 
     logger.Info("hello", "key", 23)
 
-as this YAML document:
+something like this:
 
     time: 2023-05-15T16:29:00
     level: INFO
-    message: hello
+    message: "hello"
     key: 23
+    ---
+
+Although this particular output is valid YAML,
+our implementation doesn't consider the subtleties of YAML syntax,
+so it will sometimes produce invalid YAML.
+For example, it doesn't quote keys that have colons in them.
+We'll call it `IndentHandler` to forestall disappointment.
+
+We begin with the `IndentHandler` type
+and the `New` function that constructs it from an `io.Writer` and options:
+
+%include indenthandler1/indent_handler.go types -
+
+We'll support only one option, the ability to set a minimum level in order to
+supress detailed log output.
+Handlers should always use the `slog.Leveler` type for this option.
+`Leveler` is implemented by both `Level` and `LevelVar`.
+A `Level` value is easy for the user to provide,
+but changing the level of multiple handlers requires tracking them all.
+If the user instead passes a `LevelVar`, then a single change to that `LevelVar`
+will change the behavior of all handlers that contain it.
+Changes to `LevelVar`s are goroutine-safe.
+
+The mutex will be used to ensure that writes to the `io.Writer` happen atomically.
+Unusually, `IndentHandler` holds a pointer to a `sync.Mutex` rather than holding a
+`sync.Mutex` directly.
+But there is a good reason for that, which we'll explain later.
+
+TODO(jba): add link to that later explanation.
+
+Our handler will need additional state to track calls to `WithGroup` and `WithAttrs`.
+We will describe that state when we get to those methods.
 
 ## The `Enabled` method
 
@@ -105,23 +137,7 @@ A handler's `Enabled` method could report whether the argument level
 is greater than or equal to the context value, allowing the verbosity
 of the work done by each request to be controlled independently.
 
-Most implementations of `Enabled` will consult a configured minimum level
-instead. For maximum generality, use the `Leveler` type in the configuration of
-your handler, as the built-in `HandlerOptions` does.
-
-Our YAML handler's constructor will take a `Leveler`, along with an `io.Writer`
-for its output:
-
-TODO(jba): include func yamlhandler.New(w io.Writer, level slog.Leveler)
-
-`Leveler` is implemented by both `Level` and `LevelVar`.
-A `Level` value is easy for the user to provide,
-but changing the level of multiple handlers requires tracking them all.
-If the user instead passes a `LevelVar`, then a single change to that `LevelVar`
-will change the behavior of all handlers that contain it.
-Changes to `LevelVar`s are goroutine-safe.
-
-TODO(jba): example handler that implements a minimum level and delegates the other methods.
+TODO(jba): include Enabled example
 
 ## The `WithAttrs` method
 
@@ -178,7 +194,7 @@ the implementations of `Handler.WithGroup` and `Handler.WithAttrs`.
 We will look at two implementations of `WithGroup` and `WithAttrs`, one that pre-formats and
 one that doesn't.
 
-TODO(jba): add YAML handler examples
+TODO(jba): add IndentHandler examples
 
 ## The `Handle` method
 

slog-handler-guide/indenthandler1/indent_handler.go

@@ -0,0 +1,117 @@
+//go:build go1.21
+
+package indenthandler
+
+import (
+	"context"
+	"fmt"
+	"io"
+	"log/slog"
+	"runtime"
+	"sync"
+	"time"
+)
+
+// !+types
+type IndentHandler struct {
+	opts Options
+	// TODO: state for WithGroup and WithAttrs
+	mu  *sync.Mutex
+	out io.Writer
+}
+
+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
+}
+
+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
+}
+
+//!-types
+
+func (h *IndentHandler) Enabled(ctx context.Context, level slog.Level) bool {
+	return level >= h.opts.Level.Level()
+}
+
+func (h *IndentHandler) WithGroup(name string) slog.Handler {
+	// TODO: implement.
+	return h
+}
+
+func (h *IndentHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
+	// TODO: implement.
+	return h
+}
+
+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
+	// TODO: output the Attrs and groups from WithAttrs and WithGroup.
+	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
+}
+
+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
+}

slog-handler-guide/indenthandler1/indent_handler_test.go

@@ -0,0 +1,40 @@
+//go:build go1.21
+
+package indenthandler
+
+import (
+	"bytes"
+	"regexp"
+	"testing"
+
+	"log/slog"
+)
+
+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)
+	}
+}