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

perf: use zap's Check() to prevent useless allocs #6560

Merged
merged 7 commits into from
Sep 13, 2024

Conversation

dunglas
Copy link
Collaborator

@dunglas dunglas commented Sep 4, 2024

Zap provides an optional API to prevent allocating fields that will never be used because the configured log level is higher than the emitted log.

We had good results using this trick in Mercure and more recently in FrankenPHP. This is also the trick that has been used in #6541.

This is especially important for DEBUG and INFO level logs (which are usually disabled in production), as well as for benchmarks (where logs are usually entirely disabled).

As you can see in the added benchmark, this significantly improves performance:

Before (no logs):

goos: darwin
goarch: arm64
pkg: github.com/caddyserver/caddy/v2/modules/caddyhttp
cpu: Apple M1 Pro
BenchmarkServer_LogRequest_NopLogger
BenchmarkServer_LogRequest_NopLogger-10    	 2797832	       433.9 ns/op	     408 B/op	       3 allocs/op
PASS
ok  	github.com/caddyserver/caddy/v2/modules/caddyhttp	2.150s

After (no logs):

goos: darwin
goarch: arm64
pkg: github.com/caddyserver/caddy/v2/modules/caddyhttp
cpu: Apple M1 Pro
BenchmarkServer_LogRequest_NopLogger
BenchmarkServer_LogRequest_NopLogger-10    	 8031225	       144.5 ns/op	       8 B/op	       1 allocs/op
PASS
ok  	github.com/caddyserver/caddy/v2/modules/caddyhttp	1.804s

Our FrankenPHP benchmarks show that the server can handle ~1% more requests per second by applying this patch (a Hello World page). In some cases, the performance gain can be more important (streaming for instance, which logs many things at the DEBUG level).

The optimized syntax is a bit more verbose, but not that much IMHO.

@francislavoie francislavoie added the optimization 📉 Performance or cost improvements label Sep 4, 2024
repl.Set("http.response.status", status) // will be 0 if no response is written by us (Go will write 200 to client)
repl.Set("http.response.size", size)
repl.Set("http.response.duration", duration)
repl.Set("http.response.duration_ms", duration.Seconds()*1e3) // multiply seconds to preserve decimal (see #4666)
Copy link
Member

Choose a reason for hiding this comment

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

I'm not sure if it's correct to sometimes not set the replacer. It has side effects, it's not only used in logging.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

It is already not in some cases:

https://github.com/caddyserver/caddy/blob/master/modules/caddyhttp/server.go#L757-L760

Should we always set them?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

I restored the previous behavior, but maybe should we set the replacer before the existing guard clause

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

(benchmark updated)

Copy link
Member

@mholt mholt left a comment

Choose a reason for hiding this comment

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

Thanks so much for contributing this, @dunglas! Can't wait to try this out :)

@mholt mholt merged commit f4bf4e0 into caddyserver:master Sep 13, 2024
30 of 33 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
optimization 📉 Performance or cost improvements
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants