diff --git a/pkg/app/app.go b/pkg/app/app.go index 4c85e740..f2080075 100644 --- a/pkg/app/app.go +++ b/pkg/app/app.go @@ -6,7 +6,9 @@ package app import ( + "context" "fmt" + "log/slog" "os" "runtime/debug" "strings" @@ -197,3 +199,45 @@ func (d *Data) MarshalLog(addField func(key string, v interface{})) { addField("deployment.namespace", d.Namespace) } } + +// LogValue implements the log/slog package's LogValuer interface (found +// here: https://pkg.go.dev/log/slog#LogValuer). Returns a subset of the +// App.Info data as a map. +func (d *Data) LogValue() slog.Value { + d.mu.Lock() + defer d.mu.Unlock() + + attrs := make([]slog.Attr, 0, 4) + + // App prefixes are removed as AppInfo func nests data under app key + // already. + if d.Name != "unknown" { + attrs = append(attrs, slog.String("name", d.Name)) + attrs = append(attrs, slog.String("service_name", d.Name)) + } + if d.Version != "" { + attrs = append(attrs, slog.String("version", d.Version)) + } + if d.Namespace != "" { + attrs = append(attrs, slog.String("deployment.namespace", d.Namespace)) + } + + return slog.GroupValue(attrs...) +} + +// LogHook provides an olog compatible hook func which extracts and returns +// the app Data as a nested attribute on log record. +// nolint:gocritic // Why: this signature is inline with the olog pkg hook type +func LogHook(ctx context.Context, r slog.Record) ([]slog.Attr, error) { + info := Info() + if info == nil { + return []slog.Attr{}, nil + } + + return []slog.Attr{ + // Manually assign the LogValue to an attribute. The slog.Group + // func doesn't really take an already existing GroupValue as + // Values are more meant to be used directly in log calls. + {Key: "app", Value: info.LogValue()}, + }, nil +} diff --git a/pkg/olog/README.md b/pkg/olog/README.md index f805d195..5065f6cd 100755 --- a/pkg/olog/README.md +++ b/pkg/olog/README.md @@ -12,6 +12,7 @@ This package does not provide the ability to ship logs to a remote server, inste - [Usage](<#usage>) - [Migrating from gobox/pkg/log](<#migrating-from-goboxpkglog>) +- [Logger Hooks](<#logger-hooks>) - [func New() *slog.Logger](<#func-new>) - [func NewWithHandler(h slog.Handler) *slog.Logger](<#func-newwithhandler>) - [func SetDefaultHandler(ht DefaultHandlerType)](<#func-setdefaulthandler>) @@ -279,6 +280,37 @@ func doSomething(ctx context.Context, t *Thing) { } ``` +## Logger Hooks + +To provide a mechanism with which to automatically add attributes to all logs (with access to context), loggers can also be created with hook functions. This package exposes a `NewWithHooks` func which wraps the default olog handler and allows for hook functions to be provided by the caller. These hooks funcs may return any number of `slog` attributes which will then be added to the final log record before it is written. + +```go +import ( + "context" + "log/slog" + + "github.com/getoutreach/gobox/pkg/app" + "github.com/getoutreach/gobox/pkg/olog" + "github.com/getoutreach/gobox/pkg/trace" +) + +var logger *slog.Logger + +func init() { + // Create custom hook func + traceHook := olog.LogHookFunc(func(ctx context.Context, r slog.Record) ([]slog.Attr, error) { + return []slog.Attr{slog.String("traceId", trace.ID(ctx))}, nil + }) + + // Create a hooks logger with the provided AppInfo hook as well as + // the custom traceHook, assigning to our package logger instance. + logger = olog.NewWithHooks( + app.LogHook, + traceHook, + ) +} +``` + ## func [New]() ```go @@ -286,9 +318,7 @@ func New() *slog.Logger ``` New creates a new slog instance that can be used for logging. The provided logger use the global handler provided by this package. See the documentation on the 'handler' global for more information. - The logger will be automatically associated with the module and package that it was instantiated in. This is done by looking at the call stack. - Note: As mentioned above, this logger is associated with the module and package that created it. So, if you pass this logger to another module or package, the association will NOT be changed. This includes the caller metadata added to every log line as well as log\-level management. If a type has a common logging format that the other module or package should use, then a slog.LogValuer should be implemented on that type instead of passing a logger around. If trying to set attributes the be logged by default, this is not supported without retaining the original association. ## func [NewWithHandler]() @@ -298,7 +328,6 @@ func NewWithHandler(h slog.Handler) *slog.Logger ``` NewWithHandler returns a new slog.Logger with the provided handler. - Note: A logger created with this function will not be controlled by the global log level and will not have any of the features provided by this package. This is primarily meant to be used only by tests or other special cases. ## func [SetDefaultHandler]() diff --git a/pkg/olog/hook_handler.go b/pkg/olog/hook_handler.go new file mode 100644 index 00000000..9da196d4 --- /dev/null +++ b/pkg/olog/hook_handler.go @@ -0,0 +1,35 @@ +package olog + +import ( + "context" + "log/slog" +) + +// LogHookFunc defines a function which can be called prior to a log being +// emitted, allowing the caller to augment the attributes on a log by +// returning a slice of slog.Attr which will appended to the record. The +// caller may also return an error, which will be handled by the underlying +// log handler (slog.TextHandler or slog.JSONHandler). +// nolint:gocritic // Why: this is the signature require by the slog handler interface +type LogHookFunc func(context.Context, slog.Record) ([]slog.Attr, error) + +type hookHandler struct { + hooks []LogHookFunc + slog.Handler +} + +// Handle performs the required Handle operation of the log handler interface, +// calling any provided hooks before calling the underlying embedded handler. +// nolint:gocritic // Why: this is the signature require by the slog handler interface +func (h *hookHandler) Handle(ctx context.Context, r slog.Record) error { + for _, hook := range h.hooks { + attrs, err := hook(ctx, r) + if err != nil { + return err + } + + r.AddAttrs(attrs...) + } + + return h.Handler.Handle(ctx, r) +} diff --git a/pkg/olog/olog.go b/pkg/olog/olog.go index dfe0b2f0..a1863186 100644 --- a/pkg/olog/olog.go +++ b/pkg/olog/olog.go @@ -114,3 +114,16 @@ func getMetadata() (metadata, error) { func NewWithHandler(h slog.Handler) *slog.Logger { return slog.New(h) } + +// NewWithHooks returns a new slog.Logger, allowing hooks to be provided +// by the caller in order to automatically augment the attributes on the +// log record before it writes. +// +// All hooks provided will be executed in the order in which they are provided +// and will overwrite any attributes written by the previous hook when a +// duplicate key is provided. +func NewWithHooks(hooks ...LogHookFunc) *slog.Logger { + defaultHandler := New().Handler() + hookedHandler := &hookHandler{Handler: defaultHandler, hooks: hooks} + return slog.New(hookedHandler) +} diff --git a/pkg/olog/olog_test.go b/pkg/olog/olog_test.go index 96c5e972..3d661a68 100644 --- a/pkg/olog/olog_test.go +++ b/pkg/olog/olog_test.go @@ -1,9 +1,11 @@ package olog import ( + "context" "log/slog" "testing" + "github.com/getoutreach/gobox/pkg/app" "github.com/google/go-cmp/cmp" ) @@ -34,3 +36,69 @@ func TestLogLevelByModule(t *testing.T) { t.Fatalf("unexpected log output (-want +got):\n%s", diff) } } + +func TestLogWithHook(t *testing.T) { + // Force JSON handler for valid unmarshaling used in the TestCapturer + SetDefaultHandler(JSONHandler) + + logCapture := NewTestCapturer(t) + + // Create logger with test hook + logger := NewWithHooks(func(context.Context, slog.Record) ([]slog.Attr, error) { + return []slog.Attr{slog.Any("data", map[string]string{"foo": "bar"})}, nil + }) + + logger.Info("should appear") + + // Verify the right messages were logged. + expected := []TestLogLine{ + { + Message: "should appear", + Level: slog.LevelInfo, + Attrs: map[string]any{ + "module": "github.com/getoutreach/gobox", + "modulever": "", + "data": map[string]any{"foo": "bar"}, + }, + }, + } + + if diff := cmp.Diff(expected, logCapture.GetLogs()); diff != "" { + t.Fatalf("unexpected log output (-want +got):\n%s", diff) + } +} + +func TestLogWithAppInfoHook(t *testing.T) { + // Force JSON handler for valid unmarshaling used in the TestCapturer + SetDefaultHandler(JSONHandler) + + logCapture := NewTestCapturer(t) + + // Initialize test app info + app.SetName("ologHooksTest") + + // Create logger with test hook + logger := NewWithHooks(app.LogHook) + + logger.Info("should appear") + + // Verify the right messages were logged. + expected := []TestLogLine{ + { + Message: "should appear", + Level: slog.LevelInfo, + Attrs: map[string]any{ + "module": "github.com/getoutreach/gobox", + "modulever": "", + "app": map[string]any{ + "name": "ologHooksTest", + "service_name": "ologHooksTest", + }, + }, + }, + } + + if diff := cmp.Diff(expected, logCapture.GetLogs()); diff != "" { + t.Fatalf("unexpected log output (-want +got):\n%s", diff) + } +}