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

Sampling core doesn't seem to have any effect #1032

Closed
mholt opened this issue Dec 8, 2021 · 3 comments · Fixed by #1033
Closed

Sampling core doesn't seem to have any effect #1032

mholt opened this issue Dec 8, 2021 · 3 comments · Fixed by #1033

Comments

@mholt
Copy link

mholt commented Dec 8, 2021

I'm trying to limit the excessive output of some very active logs, the same two messages repeating (same logger) thousands of times per second.

I figured that wrapping my custom core in a NewSamplerWithOptions() would do the trick:

// ...

core := zapcore.NewTee(
	zapcore.NewCore(consoleEncoder, consoleOut, zap.DebugLevel),
	zapcore.NewCore(jsonEncoder, webOut, zap.InfoLevel),
)

core = zapcore.NewSamplerWithOptions(core, 5*time.Second, 1, 1)

logger := zap.New(core)

// ...

I thought I could expect about 2 log messages per 5 seconds with this configuration, but I'm still seeing a firehose of thousands of the same logs every second, completely obliterating the performance of the app (writing the logs to the outputs is slowing it down).

Am I using it wrong? 😅

@abhinav
Copy link
Collaborator

abhinav commented Dec 8, 2021

Hey there! Yes, your configuration of the Zap sampler is slightly incorrect.

If you do the following,

core := zapcore.NewSamplerWithOptions(core, interval, N, M)

Zap will log the first N messages in interval without sampling.
Following that, it will log every M-th message.

The code above sets M to 1: log every message, so it effectively disables sampling.
You can set M to a higher value to get it to sample messages.

// Allow every 100th duplicate message in a 5 second interval.
core := zapcore.NewSamplerWithOptons(core, 5*time.Second, 1, 100)

Unfortunately, the sampler does not yet support setting M to zero.
We can add support for that.

abhinav added a commit that referenced this issue Dec 8, 2021
The Zap sampling logger accepts three configuration parameters:
interval, first, and thereafter.

After we see `first` log with the same message in `interval`,
the sampler kicks in.
Following that, we let through every `thereafter`-th log.

So for example,

    NewSamplerWithOptions(core, time.Second, 100, 50)

This will allow 100 logs with the same message in a second,
and following that, every 50th message with that message.

In #1032, the user wanted the sampler to reject *all* duplicate messages
once the limit was reached, but our sampler panics
if `thereafter = 0`.

This change adds support for setting `thereafter` to 0,
dropping all messages in that interval once the limit is reached.
It also adds further explanation to the documentation to address the
misuse in #1032.

Resolves #1032
abhinav added a commit that referenced this issue Dec 8, 2021
The Zap sampling logger accepts three configuration parameters:
interval, first, and thereafter.

After we see `first` log with the same message in `interval`,
the sampler kicks in.
Following that, we let through every `thereafter`-th log.

So for example,

    NewSamplerWithOptions(core, time.Second, 100, 50)

This will allow 100 logs with the same message in a second,
and following that, every 50th message with that message.

In #1032, the user wanted the sampler to reject *all* duplicate messages
once the limit was reached, but our sampler panics
if `thereafter = 0`.

This change adds support for setting `thereafter` to 0,
dropping all messages in that interval once the limit is reached.
It also adds further explanation to the documentation to address the
misuse in #1032.

Resolves #1032
@abhinav
Copy link
Collaborator

abhinav commented Dec 8, 2021

@mholt We've added support for a zero value of M. It will let you do the following to log at most 2 messages per 5 second interval.

core = zapcore.NewSamplerWithOptions(core, 5*time.Second, 2, 0)

We won't release this until January, though.
You can temporarily pin to the current master branch with:

go mod edit -replace go.uber.org/zap=github.com/uber-go/zap@master

@mholt
Copy link
Author

mholt commented Dec 8, 2021

Ohh, thank you -- I was wondering what N and M were referring to, as I couldn't find them in the method signature. And I tiotally misunderstood M, I realize now it's part of a ratio. Really appreciate the update too, that'll be useful going forward. Thanks again!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging a pull request may close this issue.

2 participants