Skip to content

Commit

Permalink
feat(zapslog): implement stack trace handling (#1339)
Browse files Browse the repository at this point in the history
fix: #1329

As discussed in the issue, replacing the `HandlersOptions` with
functional options, i also renamed `addSource` to `addCaller` to
properly match the `zap` semantic.

---------

Co-authored-by: Abhinav Gupta <mail@abhinavg.net>
  • Loading branch information
zekth and abhinav committed Sep 1, 2023
1 parent e9f4bda commit b900128
Show file tree
Hide file tree
Showing 6 changed files with 123 additions and 42 deletions.
3 changes: 2 additions & 1 deletion exp/go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,8 @@ require (
require (
github.com/davecgh/go-spew v1.1.1 // indirect
github.com/pmezard/go-difflib v1.0.0 // indirect
go.uber.org/atomic v1.10.0 // indirect
go.uber.org/multierr v1.10.0 // indirect
gopkg.in/yaml.v3 v3.0.1 // indirect
)

replace go.uber.org/zap => ../
9 changes: 2 additions & 7 deletions exp/go.sum
Original file line number Diff line number Diff line change
@@ -1,8 +1,7 @@
github.com/benbjohnson/clock v1.1.0 h1:Q92kusRqC1XV2MjkWETPvjJVqKetz1OzxZB7mHJLju8=
github.com/benbjohnson/clock v1.3.0 h1:ip6w0uFQkncKQ979AypyG0ER7mqUSBdKLOgAle/AT8A=
github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/pkg/errors v0.8.1 h1:iURUrRGxPUNPdy5/HRSm+Yj6okJ6UtLINN0Q9M4+h3I=
github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
Expand All @@ -12,13 +11,9 @@ github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/
github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU=
github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk=
github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4=
go.uber.org/atomic v1.10.0 h1:9qC72Qh0+3MqyJbAn8YU5xVq1frD8bn3JtD2oXtafVQ=
go.uber.org/atomic v1.10.0/go.mod h1:LUxbIzbOniOlMKjJjyPfpl4v+PKK2cNJn91OQbhoJI0=
go.uber.org/goleak v1.1.11 h1:wy28qYRKZgnJTxGxvye5/wgWr1EKjmUDGYox5mGlRlI=
go.uber.org/goleak v1.2.0 h1:xqgm/S+aQvhWFTtR0XK3Jvg7z8kGV8P4X14IzwN3Eqk=
go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ=
go.uber.org/multierr v1.10.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=
go.uber.org/zap v1.24.0 h1:FiJd5l1UOLj0wCgbSE0rwwXHzEdAZS6hiiSnxJN/D60=
go.uber.org/zap v1.24.0/go.mod h1:2kMP+WWQ8aoFoedH3T2sq6iJ2yDWpHbP0f6MQbS9Gkg=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
Expand Down
2 changes: 1 addition & 1 deletion exp/zapslog/example_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,7 @@ func Example_slog() {
logger := zap.NewExample(zap.IncreaseLevel(zap.InfoLevel))
defer logger.Sync()

sl := slog.New(zapslog.NewHandler(logger.Core(), nil /* options */))
sl := slog.New(zapslog.NewHandler(logger.Core()))
ctx := context.Background()

sl.Info("user", "name", "Al", "secret", Password("secret"))
Expand Down
51 changes: 23 additions & 28 deletions exp/zapslog/handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -28,41 +28,30 @@ import (
"runtime"

"go.uber.org/zap"
"go.uber.org/zap/internal/stacktrace"
"go.uber.org/zap/zapcore"
)

// Handler implements the slog.Handler by writing to a zap Core.
type Handler struct {
core zapcore.Core
name string // logger name
addSource bool
}

// HandlerOptions are options for a Zap-based [slog.Handler].
type HandlerOptions struct {
// LoggerName is used for log entries received from slog.
//
// Defaults to empty.
LoggerName string

// AddSource configures the handler to annotate each message with the filename,
// line number, and function name.
// AddSource is false by default to skip the cost of computing
// this information.
AddSource bool
core zapcore.Core
name string // logger name
addCaller bool
addStackAt slog.Level
callerSkip int
}

// NewHandler builds a [Handler] that writes to the supplied [zapcore.Core]
// with the default options.
func NewHandler(core zapcore.Core, opts *HandlerOptions) *Handler {
if opts == nil {
opts = &HandlerOptions{}
// with options.
func NewHandler(core zapcore.Core, opts ...Option) *Handler {
h := &Handler{
core: core,
addStackAt: slog.LevelError,
}
return &Handler{
core: core,
name: opts.LoggerName,
addSource: opts.AddSource,
for _, v := range opts {
v.apply(h)
}
return h
}

var _ slog.Handler = (*Handler)(nil)
Expand Down Expand Up @@ -136,15 +125,13 @@ func (h *Handler) Handle(ctx context.Context, record slog.Record) error {
Time: record.Time,
Message: record.Message,
LoggerName: h.name,
// TODO: do we need to set the following fields?
// Stack:
}
ce := h.core.Check(ent, nil)
if ce == nil {
return nil
}

if h.addSource && record.PC != 0 {
if h.addCaller && record.PC != 0 {
frame, _ := runtime.CallersFrames([]uintptr{record.PC}).Next()
if frame.PC != 0 {
ce.Caller = zapcore.EntryCaller{
Expand All @@ -157,6 +144,14 @@ func (h *Handler) Handle(ctx context.Context, record slog.Record) error {
}
}

if record.Level >= h.addStackAt {
// Skipping 3:
// zapslog/handler log/slog.(*Logger).log
// slog/logger log/slog.(*Logger).log
// slog/logger log/slog.(*Logger).<level>
ce.Stack = stacktrace.Take(3 + h.callerSkip)
}

fields := make([]zapcore.Field, 0, record.NumAttrs())
record.Attrs(func(attr slog.Attr) bool {
if attr.Equal(slog.Attr{}) {
Expand Down
28 changes: 23 additions & 5 deletions exp/zapslog/handler_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -32,13 +32,11 @@ import (
"go.uber.org/zap/zaptest/observer"
)

func TestAddSource(t *testing.T) {
func TestAddCaller(t *testing.T) {
t.Parallel()

fac, logs := observer.New(zapcore.DebugLevel)
sl := slog.New(NewHandler(fac, &HandlerOptions{
AddSource: true,
}))
sl := slog.New(NewHandler(fac, WithCaller(true)))
sl.Info("msg")

require.Len(t, logs.AllUntimed(), 1, "Expected exactly one entry to be logged")
Expand All @@ -51,11 +49,31 @@ func TestAddSource(t *testing.T) {
)
}

func TestAddStack(t *testing.T) {
fac, logs := observer.New(zapcore.DebugLevel)
sl := slog.New(NewHandler(fac, AddStacktraceAt(slog.LevelDebug)))
sl.Info("msg")

require.Len(t, logs.AllUntimed(), 1, "Expected exactly one entry to be logged")
entry := logs.AllUntimed()[0]
require.Equal(t, "msg", entry.Message, "Unexpected message")
assert.Regexp(t,
`^go.uber.org/zap/exp/zapslog.TestAddStack`,
entry.Stack,
"Unexpected stack trace annotation.",
)
assert.Regexp(t,
`/zapslog/handler_test.go:\d+`,
entry.Stack,
"Unexpected stack trace annotation.",
)
}

func TestEmptyAttr(t *testing.T) {
t.Parallel()

fac, observedLogs := observer.New(zapcore.DebugLevel)
sl := slog.New(NewHandler(fac, nil))
sl := slog.New(NewHandler(fac))

t.Run("Handle", func(t *testing.T) {
sl.Info(
Expand Down
72 changes: 72 additions & 0 deletions exp/zapslog/options.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,72 @@
// Copyright (c) 2023 Uber Technologies, Inc.
//
// Permission is hereby granted, free of charge, to any person obtaining a copy
// of this software and associated documentation files (the "Software"), to deal
// in the Software without restriction, including without limitation the rights
// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
// copies of the Software, and to permit persons to whom the Software is
// furnished to do so, subject to the following conditions:
//
// The above copyright notice and this permission notice shall be included in
// all copies or substantial portions of the Software.
//
// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
// THE SOFTWARE.

//go:build go1.21

package zapslog

import "log/slog"

// An Option configures a slog Handler.
type Option interface {
apply(*Handler)
}

// optionFunc wraps a func so it satisfies the Option interface.
type optionFunc func(*Handler)

func (f optionFunc) apply(handler *Handler) {
f(handler)
}

// WithName configures the Logger to annotate each message with the logger name.
func WithName(name string) Option {
return optionFunc(func(h *Handler) {
h.name = name
})
}

// WithCaller configures the Logger to include the filename and line number
// of the caller in log messages--if available.
func WithCaller(enabled bool) Option {
return optionFunc(func(handler *Handler) {
handler.addCaller = enabled
})
}

// WithCallerSkip increases the number of callers skipped by caller annotation
// (as enabled by the [WithCaller] option).
//
// When building wrappers around the Logger,
// supplying this Option prevents Zap from always reporting
// the wrapper code as the caller.
func WithCallerSkip(skip int) Option {
return optionFunc(func(log *Handler) {
log.callerSkip += skip
})
}

// AddStacktraceAt configures the Logger to record a stack trace
// for all messages at or above a given level.
func AddStacktraceAt(lvl slog.Level) Option {
return optionFunc(func(log *Handler) {
log.addStackAt = lvl
})
}

0 comments on commit b900128

Please sign in to comment.