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

Honor CallerSkip when taking stack traces & add the StackSkip field #843

Merged
merged 8 commits into from Aug 18, 2020
Merged
15 changes: 14 additions & 1 deletion field.go
Expand Up @@ -368,7 +368,20 @@ func Stack(key string) Field {
// from expanding the zapcore.Field union struct to include a byte slice. Since
// taking a stacktrace is already so expensive (~10us), the extra allocation
// is okay.
return String(key, takeStacktrace())
return String(key, takeStacktrace(nil))
}

// StackSkip constructs a field that stores a stacktrace of the current
segevfiner marked this conversation as resolved.
Show resolved Hide resolved
// goroutine under provided key, skipping the given number of frames from the
// top of the stacktrace. Keep in mind that taking a stacktrace is eager and
// expensive (relatively speaking); this function both makes an allocation and
// takes about two microseconds.
func StackSkip(key string, skip int) Field {
// Returning the stacktrace as a string costs an allocation, but saves us
// from expanding the zapcore.Field union struct to include a byte slice. Since
// taking a stacktrace is already so expensive (~10us), the extra allocation
// is okay.
return String(key, takeStacktrace(&skip))
}

// Duration constructs a field with the given key and value. The encoder
Expand Down
2 changes: 1 addition & 1 deletion field_test.go
Expand Up @@ -259,6 +259,6 @@ func TestStackField(t *testing.T) {
f := Stack("stacktrace")
assert.Equal(t, "stacktrace", f.Key, "Unexpected field key.")
assert.Equal(t, zapcore.StringType, f.Type, "Unexpected field type.")
assert.Equal(t, takeStacktrace(), f.String, "Unexpected stack trace")
assert.Equal(t, takeStacktrace(nil), f.String, "Unexpected stack trace")
assertCanBeReused(t, f)
}
9 changes: 7 additions & 2 deletions logger.go
Expand Up @@ -48,7 +48,8 @@ type Logger struct {
addCaller bool
addStack zapcore.LevelEnabler

callerSkip int
callerSkip int
useCallerSkipForStack bool
}

// New constructs a new Logger from the provided zapcore.Core and Options. If
Expand Down Expand Up @@ -304,7 +305,11 @@ func (log *Logger) check(lvl zapcore.Level, msg string) *zapcore.CheckedEntry {
}
}
if log.addStack.Enabled(ce.Entry.Level) {
ce.Entry.Stack = Stack("").String
if log.useCallerSkipForStack {
ce.Entry.Stack = StackSkip("", log.callerSkip).String
} else {
ce.Entry.Stack = Stack("").String
}
}

return ce
Expand Down
8 changes: 8 additions & 0 deletions options.go
Expand Up @@ -119,6 +119,14 @@ func AddStacktrace(lvl zapcore.LevelEnabler) Option {
})
}

// UseCallerSkipForStacktrace configures the logger to use the number of frames
// that should be skipped for caller (CallerSkip) annotation when taking stacktraces.
func UseCallerSkipForStacktrace(enabled bool) Option {
return optionFunc(func(log *Logger) {
log.useCallerSkipForStack = enabled
})
}

// IncreaseLevel increase the level of the logger. It has no effect if
// the passed in level tries to decrease the level of the logger.
func IncreaseLevel(lvl zapcore.LevelEnabler) Option {
Expand Down
11 changes: 10 additions & 1 deletion stacktrace.go
Expand Up @@ -43,7 +43,7 @@ var (
_zapStacktraceVendorContains = addPrefix("/vendor/", _zapStacktracePrefixes...)
)

func takeStacktrace() string {
func takeStacktrace(skip *int) string {
segevfiner marked this conversation as resolved.
Show resolved Hide resolved
buffer := bufferpool.Get()
defer buffer.Free()
programCounters := _stacktracePool.Get().(*programCounters)
Expand All @@ -69,13 +69,22 @@ func takeStacktrace() string {
// Note: On the last iteration, frames.Next() returns false, with a valid
// frame, but we ignore this frame. The last frame is a a runtime frame which
// adds noise, since it's only either runtime.main or runtime.goexit.
toSkip := 0
if skip != nil {
toSkip = *skip
}
for frame, more := frames.Next(); more; frame, more = frames.Next() {
if skipZapFrames && isZapFrame(frame.Function) {
continue
} else {
skipZapFrames = false
}

if toSkip > 0 {
toSkip--
continue
}

if i != 0 {
buffer.AppendByte('\n')
}
Expand Down
4 changes: 2 additions & 2 deletions stacktrace_test.go
Expand Up @@ -29,7 +29,7 @@ import (
)

func TestTakeStacktrace(t *testing.T) {
trace := takeStacktrace()
trace := takeStacktrace(nil)
lines := strings.Split(trace, "\n")
require.True(t, len(lines) > 0, "Expected stacktrace to have at least one frame.")
Copy link
Collaborator

Choose a reason for hiding this comment

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

minor: Can use NotEmpty.

Suggested change
require.True(t, len(lines) > 0, "Expected stacktrace to have at least one frame.")
require.NotEmpty(t, lines, "Expected stacktrace to have at least one frame.")

assert.Contains(
Expand Down Expand Up @@ -70,6 +70,6 @@ func TestIsZapFrame(t *testing.T) {

func BenchmarkTakeStacktrace(b *testing.B) {
for i := 0; i < b.N; i++ {
takeStacktrace()
takeStacktrace(nil)
}
}