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

Reduce allocations for disabled/sampled logs #45

Merged
merged 3 commits into from
May 27, 2016
Merged

Conversation

akshayjshah
Copy link
Contributor

@akshayjshah akshayjshah commented May 17, 2016

Even when a log level is disabled or heavily sampled, calling logger.Error(msg, someField, someOtherField) will make at least one allocation to hold the fields. Since we're going to discard the message anyways, this is wasted work. This PR introduces the logger.Check API, which allows particularly performance-sensitive applications to avoid these allocations by using a slightly wordier call pattern.

Using Check makes it virtually free to pass fields to a sampled logger or collect lots of debug logs:

BenchmarkZapDisabledLevelsAddingFields-4         3000000        439 ns/op             704 B/op          2 allocs/op
BenchmarkZapDisabledLevelsCheckAddingFields-4   200000000         5.74 ns/op            0 B/op          0 allocs/op

BenchmarkZapSampleWithoutFields-4       20000000                60.9 ns/op             0 B/op          0 allocs/op
BenchmarkZapSampleCheckWithoutFields-4  20000000                61.4 ns/op             0 B/op          0 allocs/op

BenchmarkZapSampleAddingFields-4         2000000               575 ns/op             704 B/op          2 allocs/op
BenchmarkZapSampleCheckAddingFields-4   20000000                65.2 ns/op             0 B/op          0 allocs/op

This fixes #56.

b.ResetTimer()
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
if m := logger.Check(zap.Info, "Should be discarded."); m != nil {
Copy link
Collaborator

Choose a reason for hiding this comment

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

optional: you could make the CheckedMessage type have a method (OK() bool, Log() bool, not sure), and that method could also support nil as well so you don't have to return a new object.

instead of m != nil, we could have m.OK()

Copy link
Contributor Author

Choose a reason for hiding this comment

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

done.

Even when a log level is disabled or heavily sampled, calling
`logger.Error(msg, someField, someOtherField)` will make at least one
allocation to hold the fields. If we're using the more expensive field
types, we may allocate even more, only to discard all that work.

This PR introduces the `logger.Check` API, which allows particularly
performance-sensitive applications to avoid these allocations by using
a slightly wordier call pattern.

Using `Check` makes it virtually free to pass fields to a sampled
logger:

```
BenchmarkZapDisabledLevelsAddingFields-4         3000000        439 ns/op             704 B/op          2 allocs/op
BenchmarkZapDisabledLevelsCheckAddingFields-4   200000000         5.74 ns/op            0 B/op          0 allocs/op

BenchmarkZapSampleWithoutFields-4       20000000                60.9 ns/op             0 B/op          0 allocs/op
BenchmarkZapSampleCheckWithoutFields-4  20000000                61.4 ns/op             0 B/op          0 allocs/op

BenchmarkZapSampleAddingFields-4         2000000               575 ns/op             704 B/op          2 allocs/op
BenchmarkZapSampleCheckAddingFields-4   20000000                65.2 ns/op             0 B/op          0 allocs/op
```
@coveralls
Copy link

coveralls commented May 27, 2016

Coverage Status

Coverage increased (+0.2%) to 96.502% when pulling 5526de0 on ajs-check into a649f67 on master.

@abhinav
Copy link
Collaborator

abhinav commented May 27, 2016

👍

// with the underlying logger's DFatal method.
func (m *CheckedMessage) Write(fields ...Field) {
if n := atomic.AddUint32(&m.used, 1); n > 1 {
m.logger.DFatal("Shouldn't re-use a CheckedMessage.")
Copy link
Collaborator

Choose a reason for hiding this comment

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

you probably want to return after this to avoid logging again in prod

Copy link
Contributor Author

Choose a reason for hiding this comment

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

yep, done.

// with the underlying logger's DFatal method.
func (m *CheckedMessage) Write(fields ...Field) {
if n := atomic.AddUint32(&m.used, 1); n > 1 {
if n == 2 {
Copy link
Collaborator

Choose a reason for hiding this comment

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

I really like this approach

@prashantv
Copy link
Collaborator

lgtm

@akshayjshah akshayjshah merged commit 1392e24 into master May 27, 2016
@akshayjshah akshayjshah deleted the ajs-check branch May 29, 2016 18:32
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

Add a way to sample without allocating a slice of fields
4 participants