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(zapslog): implement stack trace handling #1339

Merged
merged 18 commits into from
Sep 1, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
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)
Comment on lines +148 to +152
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for adding this. Much more obvious what's going on now.

}

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
})
}