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

Avoid expensive log.Valuer evaluation for disallowed level #5297

Merged
merged 2 commits into from
May 10, 2023

Conversation

damnever
Copy link
Contributor

@damnever damnever commented Apr 28, 2023

A lot of failed operations in memcach_client.SetAsync will consume a lot of CPU:
image

goos: darwin
goarch: arm64
pkg: github.com/cortexproject/cortex/pkg/util/log
                      │   old.txt    │               new.txt               │
                      │    sec/op    │   sec/op     vs base                │
DisallowedLogLevel-10   1594.5n ± 6%   418.2n ± 1%  -73.77% (p=0.000 n=20)

                      │   old.txt   │              new.txt               │
                      │    B/op     │    B/op     vs base                │
DisallowedLogLevel-10   1567.0 ± 0%   623.0 ± 0%  -60.24% (p=0.000 n=20)

                      │  old.txt   │              new.txt               │
                      │ allocs/op  │ allocs/op   vs base                │
DisallowedLogLevel-10   23.00 ± 0%   13.00 ± 0%  -43.48% (p=0.000 n=20)

Checklist

  • Tests updated
  • Documentation added
  • CHANGELOG.md updated - the order of entries should be [CHANGE], [FEATURE], [ENHANCEMENT], [BUGFIX]

@@ -72,24 +69,32 @@ type PrometheusLogger struct {
// NewPrometheusLogger creates a new instance of PrometheusLogger which exposes
// Prometheus counters for various log levels.
func NewPrometheusLogger(l logging.Level, format logging.Format) (log.Logger, error) {
Copy link
Member

Choose a reason for hiding this comment

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

This is not being used anymore?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

This is used by other packages.

@alanprot
Copy link
Member

alanprot commented May 3, 2023

Can you explain what is the functional change here? are we missing/changing something?

@damnever
Copy link
Contributor Author

damnever commented May 4, 2023

@alanprot I agree, the change is simple but not easy to understand, the old code is like this:

logger0 := NewXXXLogger(...)
logger1 := level.NewFilter(logger0, lvl)
logger2 := log.With(logger1, "ts", log.DefaultTimestampUTC, "caller", log.Caller(3))

the new code is like this:

logger0 := NewXXXLogger(...)
logger1 := log.With(logger0, "ts", log.DefaultTimestampUTC, "caller", log.Caller(5))
logger2 := level.NewFilter(logger1, lvl)

the order matters since the logger2.Log does level filtering first then call the logger1.Log on demand, the logger1.Log evaluates the log.Valuer such as log.Caller..

I have add the reference link in the comments: go-kit/log#14 (comment)

@alanprot
Copy link
Member

alanprot commented May 9, 2023

NIce! Ok..

Copy link
Contributor

@alvinlin123 alvinlin123 left a comment

Choose a reason for hiding this comment

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

This is an awesome enhancement, thank you so much!

@alvinlin123 alvinlin123 merged commit 2e6e4ae into cortexproject:master May 10, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants