diff --git a/v2/examples_test.go b/v2/examples_test.go index 4f76b57..10a44af 100644 --- a/v2/examples_test.go +++ b/v2/examples_test.go @@ -5,27 +5,42 @@ import ( "log/slog" "os" "runtime/pprof" + "slices" "go.opentelemetry.io/otel/baggage" ) -var ExampleOpts = Options{ +var ExampleOptions = Options{ + Level: LevelEverything, OmitTime: true, OmitSource: true, + ContextKey: SetAttrs, + LevelKey: SetLevel, } +type ctxkey int + +// Context key variables for the examples. +const ( + _ ctxkey = iota + SetAttrs + SetLevel +) + func Example() { - h := NewHandler(os.Stdout, &ExampleOpts) + h := NewHandler(os.Stdout, &ExampleOptions) slog.New(h).With("a", "b").Info("test", "c", "d") // Output: // {"level":"INFO","msg":"test","a":"b","c":"d"} } +// In this example, some values are extracted from the pprof labels and inserted +// into the record. func Example_pprof() { ctx := pprof.WithLabels(context.Background(), pprof.Labels("test_kind", "example")) pprof.SetGoroutineLabels(ctx) - h := NewHandler(os.Stdout, &ExampleOpts) + h := NewHandler(os.Stdout, &ExampleOptions) slog.New(h).InfoContext(ctx, "test") // Output: @@ -39,72 +54,119 @@ func must[T any](t T, err error) T { return t } +// In this example, some values are extracted from the OpenTelemetry baggage and +// inserted into the record. func Example_baggage() { - BaggageOpts := Options{ - OmitTime: true, - OmitSource: true, - Baggage: func(_ string) bool { return true }, - } + opts := ExampleOptions + opts.Baggage = func(_ string) bool { return true } b := must(baggage.New( must(baggage.NewMember("test_kind", "example")), )) ctx := baggage.ContextWithBaggage(context.Background(), b) - h := NewHandler(os.Stdout, &BaggageOpts) + h := NewHandler(os.Stdout, &opts) slog.New(h).InfoContext(ctx, "test") // Output: // {"level":"INFO","msg":"test","baggage":{"test_kind":"example"}} } -func ExampleWithLevel() { - opts := Options{ - OmitTime: true, - OmitSource: true, +// In this example, the handler is configured with a very high minimum level, so +// without the per-record level filtering there would be no log messages. +func Example_with_Level() { + // Per-record filter levels. + filters := []slog.Level{slog.LevelDebug, slog.LevelInfo, slog.LevelWarn, slog.LevelError} + // Levels of records to emit. + levels := []slog.Level{slog.LevelDebug - 4, slog.LevelDebug, slog.LevelInfo, slog.LevelWarn, slog.LevelError} + // With is a helper function to add the log level to the Context at the known key. + // + // Typically, a module would provide a helper to do this. + with := func(ctx context.Context, l slog.Level) context.Context { + return context.WithValue(ctx, SetLevel, l) } - levels := []slog.Level{slog.LevelDebug, slog.LevelInfo, slog.LevelWarn, slog.LevelError} + + // Setup: ctx := context.Background() + opts := ExampleOptions + opts.Level = slog.Level(100) h := NewHandler(os.Stdout, &opts) + log := slog.New(h) + + // Usage: + a := slog.String("filter", "NONE") for _, l := range levels { - ctx := WithLevel(ctx, l) - for i, l := range levels { - slog.New(h).LogAttrs(ctx, l, "normal log message", slog.Int("i", i)) + log.LogAttrs(ctx, l, "", a) + } + for _, l := range filters { + a = slog.String("filter", l.String()) + ctx := with(ctx, l) + for _, l := range levels { + log.LogAttrs(ctx, l, "", a) } } // Output: - // {"level":"DEBUG","msg":"normal log message","i":0} - // {"level":"INFO","msg":"normal log message","i":1} - // {"level":"WARN","msg":"normal log message","i":2} - // {"level":"ERROR","msg":"normal log message","i":3} - // {"level":"INFO","msg":"normal log message","i":1} - // {"level":"WARN","msg":"normal log message","i":2} - // {"level":"ERROR","msg":"normal log message","i":3} - // {"level":"WARN","msg":"normal log message","i":2} - // {"level":"ERROR","msg":"normal log message","i":3} - // {"level":"ERROR","msg":"normal log message","i":3} + // {"level":"DEBUG","msg":"","filter":"DEBUG"} + // {"level":"INFO","msg":"","filter":"DEBUG"} + // {"level":"WARN","msg":"","filter":"DEBUG"} + // {"level":"ERROR","msg":"","filter":"DEBUG"} + // {"level":"INFO","msg":"","filter":"INFO"} + // {"level":"WARN","msg":"","filter":"INFO"} + // {"level":"ERROR","msg":"","filter":"INFO"} + // {"level":"WARN","msg":"","filter":"WARN"} + // {"level":"ERROR","msg":"","filter":"WARN"} + // {"level":"ERROR","msg":"","filter":"ERROR"} } -func ExampleWithAttrs() { - opts := Options{ - OmitTime: true, - OmitSource: true, +// In this example, there are values stored in the Context at a known key and +// then automatically retrieved and integrated into the record by the handler. +func Example_with_Attrs() { + // With is a helper function to add values to the Context at the known key. + // + // Typically, a module would provide a helper to do this, and do it with + // less garbage. Any ordering or replacement semantics need to happen here; + // this example does not implement being able to remove keys from the + // Context. + with := func(ctx context.Context, args ...any) context.Context { + var s []slog.Attr + if v, ok := ctx.Value(SetAttrs).(slog.Value); ok { + s = v.Group() + } + s = append(s, slog.Group("", args...).Value.Group()...) + seen := make(map[string]struct{}, len(s)) + del := func(a slog.Attr) bool { + _, ok := seen[a.Key] + seen[a.Key] = struct{}{} + return ok + } + slices.Reverse(s) + s = slices.DeleteFunc(s, del) + slices.Reverse(s) + return context.WithValue(ctx, SetAttrs, slog.GroupValue(s...)) } + // Setup: ctx := context.Background() - h := NewHandler(os.Stdout, &opts) + h := NewHandler(os.Stdout, &ExampleOptions) l := slog.New(h) + + // Usage: l.InfoContext(ctx, "without ctx attrs", "a", "b") - ctx = WithAttrs(ctx, "contextual", "value") - l.InfoContext(ctx, "with ctx attrs", "a", "b") { - ctx := WithLevel(ctx, slog.LevelDebug) - l.DebugContext(ctx, "with ctx attrs", "a", "b") + ctx := with(ctx, "contextual", "value") + l.InfoContext(ctx, "with ctx attrs", "a", "b") + { + ctx := context.WithValue(ctx, SetLevel, slog.LevelDebug) + ctx = with(ctx, "contextual", "level") + l.DebugContext(ctx, "with ctx attrs", "a", "b") + } + ctx = with(ctx, "appended", "value") + l.InfoContext(ctx, "with more ctx attrs") } - ctx = WithAttrs(ctx, "contextual", slog.GroupValue()) - l.InfoContext(ctx, "removed ctx attrs", "a", "b") + l.InfoContext(ctx, "without ctx attrs", "a", "b") // Output: // {"level":"INFO","msg":"without ctx attrs","a":"b"} // {"level":"INFO","msg":"with ctx attrs","contextual":"value","a":"b"} - // {"level":"DEBUG","msg":"with ctx attrs","contextual":"value","a":"b"} - // {"level":"INFO","msg":"removed ctx attrs","a":"b"} + // {"level":"DEBUG","msg":"with ctx attrs","contextual":"level","a":"b"} + // {"level":"INFO","msg":"with more ctx attrs","contextual":"value","appended":"value"} + // {"level":"INFO","msg":"without ctx attrs","a":"b"} } diff --git a/v2/handler.go b/v2/handler.go index 6e13871..0779de0 100644 --- a/v2/handler.go +++ b/v2/handler.go @@ -73,93 +73,11 @@ import ( "log/slog" "runtime" "runtime/pprof" - "slices" - "strings" "go.opentelemetry.io/otel/baggage" "go.opentelemetry.io/otel/trace" ) -type ( - ctxLevelKey struct{} - ctxAttrKey struct{} -) - -var ( - // CtxLevel is for per-Context log levels. - ctxLevel ctxLevelKey - // CtxAttr is for per-Context slog.Attr elements. - ctxAttr ctxAttrKey -) - -// WithLevel overrides the minimum log level for all records created with the -// returned context. -func WithLevel(ctx context.Context, l slog.Level) context.Context { - return context.WithValue(ctx, &ctxLevel, l) -} - -// WithAttrs records the provided arguments to be added as additional -// [slog.Attr] elements to any records created with the returned context. -// -// Adding Attrs for a previously added Key replaces that Attr in the returned -// Context. To remove an Attr, use an empty [slog.Group] as the value. -// -// This is more expensive than adding Attrs via [slog.Logger.With], which should -// be preferred when function signatures allow. -func WithAttrs(ctx context.Context, args ...any) context.Context { - // This is based roughly on how the [slog.Record.Add] method is implemented. - if len(args) == 0 { - return ctx - } - - var cur []slog.Attr - if prev, ok := ctx.Value(&ctxAttr).(*[]slog.Attr); ok { - cur = make([]slog.Attr, len(*prev), len(*prev)+(len(args)/2)) - copy(cur, *prev) - } else { - cur = make([]slog.Attr, 0, len(args)/2) - } - - var a slog.Attr - for len(args) > 0 { - a, args = argsToAttr(args) - cur = append(cur, a) - } - slices.SortStableFunc(cur, func(a, b slog.Attr) int { - return strings.Compare(a.Key, b.Key) - }) - // We want to keep only the last instance of a key, so this needs two - // [slices.Reverse] calls. - slices.Reverse(cur) - cur = slices.CompactFunc(cur, func(a, b slog.Attr) bool { - return a.Key == b.Key - }) - cur = slices.DeleteFunc(cur, func(a slog.Attr) bool { - v := a.Value - return v.Kind() == slog.KindGroup && len(v.Group()) == 0 - }) - cur = slices.Clip(cur) - slices.Reverse(cur) - - return context.WithValue(ctx, &ctxAttr, &cur) -} - -// ArgsToAttr slices off up to two elements to construct a [slog.Attr] and -// returns it along with a slice of the remaining elements. -func argsToAttr(args []any) (slog.Attr, []any) { - switch x := args[0].(type) { - case string: - if len(args) == 1 { - return slog.Group(x), nil - } - return slog.Any(x, args[1]), args[2:] - case slog.Attr: - return x, args[1:] - default: - return slog.Any(`!BADKEY`, x), args[1:] - } -} - // Some extra [slog.Level] aliases and syslog(3) compatible levels (as // implemented in this package). // @@ -235,16 +153,14 @@ type Options struct { // Level is the minimum level that a log message must have to be processed // by the Handler. // - // This can be overridden on a per-message basis by [WithLevel]. + // This can be overridden on a per-message basis by storing a [slog.Level] + // at [LevelKey]. Level slog.Leveler // Baggage is a selection function for keys in the OpenTelemetry Baggage // contained in the [context.Context] used with a log message. Baggage func(key string) bool // WriteError is a hook for receiving errors that occurred while attempting // to write the log message. - // - // The [slog] logging methods current do not have any means of reporting the - // errors that Handler implementations return. WriteError func(context.Context, error) // OmitSource controls whether source position information should be // emitted. @@ -256,6 +172,18 @@ type Options struct { // // When connected to the Journal, this setting has no effect. ProseFormat bool + // ContextKey is a value to be used with [context.Context.Value] to retrieve a + // [slog.Value] Group. + // + // Setting this to a value that results in retrieving any other type will + // panic the program. + ContextKey any + // LevelKey is a value to be used with [context.Context.Value] to retrieve a + // [slog.Leveler] to use on a per-record basis. + // + // Setting this to a value that results in retrieving any other type will + // panic the program. + LevelKey any // ForceANSI is a hook for testing to force ANSI color output. forceANSI bool @@ -267,8 +195,10 @@ func (h *handler[S]) Enabled(ctx context.Context, l slog.Level) bool { if h.opts.Level != nil { min = h.opts.Level.Level() } - if cl, ok := ctx.Value(&ctxLevel).(slog.Level); ok { - min = cl + if h.opts.LevelKey != nil { + if cl, ok := ctx.Value(h.opts.LevelKey).(slog.Leveler); ok { + min = cl.Level() + } } return l >= min } @@ -351,9 +281,11 @@ func (h *handler[S]) Handle(ctx context.Context, r slog.Record) (err error) { if h.prefmt != nil { b.Write(*h.prefmt) } - if p, ok := ctx.Value(&ctxAttr).(*[]slog.Attr); ok { - for _, a := range *p { - h.appendAttr(b, s, a) + if h.opts.ContextKey != nil { + if v, ok := ctx.Value(h.opts.ContextKey).(slog.Value); ok { + for _, a := range v.Group() { + h.appendAttr(b, s, a) + } } } r.Attrs(func(a slog.Attr) bool { diff --git a/v2/handler_test.go b/v2/handler_test.go index 3e467c7..f685535 100644 --- a/v2/handler_test.go +++ b/v2/handler_test.go @@ -210,7 +210,7 @@ func init() { func exerciseFormatter(t *testing.T, h slog.Handler) { t.Helper() - ctx := WithLevel(context.Background(), slog.LevelDebug) + ctx := context.Background() log := slog.New(h) for _, l := range exerciseLevels { for _, c := range exerciseCalls { @@ -242,11 +242,14 @@ func TestExercise(t *testing.T) { } lines = append(lines, cur) } + opts := Options{ + Level: LevelEverything, + } // Generate all the lines: t.Run("JSON", func(t *testing.T) { var buf bytes.Buffer - h := NewHandler(&buf, nil) + h := NewHandler(&buf, &opts) exerciseFormatter(t, h) splitBuf(buf.Bytes()) }) @@ -258,7 +261,7 @@ func TestExercise(t *testing.T) { emu.Capture(&out) h := &handler[*stateJournal]{ out: emu, - opts: &Options{}, + opts: &opts, fmt: &formatterJournal, pool: getPool[*stateJournal](), } @@ -267,12 +270,14 @@ func TestExercise(t *testing.T) { }) t.Run("Prose", func(t *testing.T) { var buf bytes.Buffer - h := proseHandler(&buf, &Options{}) + h := proseHandler(&buf, &opts) exerciseFormatter(t, h) splitBuf(buf.Bytes()) t.Run("Color", func(t *testing.T) { var buf bytes.Buffer - h := proseHandler(&buf, &Options{forceANSI: true}) + opts := opts + opts.forceANSI = true + h := proseHandler(&buf, &opts) exerciseFormatter(t, h) splitBuf(buf.Bytes()) }) diff --git a/v2/journal_test.go b/v2/journal_test.go index 8c5a474..c6bacd0 100644 --- a/v2/journal_test.go +++ b/v2/journal_test.go @@ -160,6 +160,7 @@ var expected = []journalMsg{ func emitJournaldLogs(t *testing.T) { t.Log("hello from inside systemd-run") h := NewHandler(os.Stderr, &Options{ + Level: LevelEverything, OmitTime: true, OmitSource: true, }) @@ -173,7 +174,7 @@ func emitJournaldLogs(t *testing.T) { exerciseFormatter(t, h) // Sweep the syslog priorities: pri := slog.New(h).With("TEST_PRIORITY", true) - ctx := WithLevel(context.Background(), LevelEverything) + ctx := context.Background() for i := int64(-8); i < 21; i++ { pri.Log(ctx, slog.Level(i), "test", "SLOG_LEVEL", i) }