Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: Add hooks log handler wrapper for olog package #441

Merged
merged 9 commits into from
Feb 5, 2024
44 changes: 44 additions & 0 deletions pkg/app/app.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,9 @@
package app

import (
"context"
"fmt"
"log/slog"
"os"
"runtime/debug"
"strings"
Expand Down Expand Up @@ -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
}
35 changes: 32 additions & 3 deletions pkg/olog/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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>)
Expand Down Expand Up @@ -279,16 +280,45 @@ 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](<https://github.com/getoutreach/gobox/blob/main/pkg/olog/olog.go#L39>)

```go
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](<https://github.com/getoutreach/gobox/blob/main/pkg/olog/olog.go#L114>)
Expand All @@ -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](<https://github.com/getoutreach/gobox/blob/main/pkg/olog/default_handler.go#L90>)
Expand Down
35 changes: 35 additions & 0 deletions pkg/olog/hook_handler.go
Original file line number Diff line number Diff line change
@@ -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)
}
13 changes: 13 additions & 0 deletions pkg/olog/olog.go
Original file line number Diff line number Diff line change
Expand Up @@ -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)
}
68 changes: 68 additions & 0 deletions pkg/olog/olog_test.go
Original file line number Diff line number Diff line change
@@ -1,9 +1,11 @@
package olog

import (
"context"
"log/slog"
"testing"

"github.com/getoutreach/gobox/pkg/app"
"github.com/google/go-cmp/cmp"
)

Expand Down Expand Up @@ -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)
}
}