Skip to content

grpclog: change logger to avoid Printf when the logger is io.Discard #7471

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

Merged
merged 1 commit into from
Nov 26, 2024

Conversation

rob05c
Copy link
Contributor

@rob05c rob05c commented Aug 1, 2024

Changes the logger to not call Printf when the logger is io.Discard.

Also changes the logger constructor to use io.Discard instead of io.MultiWriter(io.Discard, io.Discard), which is necessary to detect all levels being discarded.

This is a significant performance improvement for disabled logs, see #7463 for details.

Notes:

  • This is similar to how the std does it, see log.go
  • I was hoping to use the std log.Printf itself, but I don't think that's possible, because the JSON option needs to Printf and then escape the result after interpolating, which I don't think is possible with what's exposed by the std (possibly sans some overly complex io.Writer interceptors).
  • It could use log.Printf for the non-JSON, but there's not much point if we can't use it for the JSON, and it would incur an unnecessary atomic call.
  • The constructor io.Discard logic could be made faster (e.g. with more nested if's), and could do smarter things around the discard/multiwriter. I wrote it this way for readability, and because I don't think the performance is significant. But I'm happy to change it.

Fixes #7463

RELEASE NOTES:

  • grpclog: Avoid expensive printf calls for io.Discard loggers.

Copy link

linux-foundation-easycla bot commented Aug 1, 2024

CLA Signed

The committers listed above are authorized under a signed CLA.

  • ✅ login: rob05c / name: Robert O Butts (98aa027)

Copy link

codecov bot commented Aug 1, 2024

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 81.87%. Comparing base (a3a8657) to head (98aa027).
Report is 31 commits behind head on master.

Additional details and impacted files
@@            Coverage Diff             @@
##           master    #7471      +/-   ##
==========================================
- Coverage   81.87%   81.87%   -0.01%     
==========================================
  Files         373      374       +1     
  Lines       37822    38024     +202     
==========================================
+ Hits        30967    31131     +164     
- Misses       5563     5585      +22     
- Partials     1292     1308      +16     
Files with missing lines Coverage Δ
grpclog/internal/loggerv2.go 100.00% <100.00%> (+48.07%) ⬆️

... and 39 files with indirect coverage changes

@rob05c rob05c force-pushed the rob05c/nil-loggers branch 6 times, most recently from 463f9b1 to ae6fd53 Compare August 5, 2024 17:40
@rob05c rob05c force-pushed the rob05c/nil-loggers branch 2 times, most recently from bf693df to bd9603c Compare August 5, 2024 18:15
@purnesh42H purnesh42H self-assigned this Aug 6, 2024
@purnesh42H purnesh42H assigned rob05c and unassigned purnesh42H Aug 7, 2024
@rob05c rob05c force-pushed the rob05c/nil-loggers branch from bd9603c to 2da6dee Compare August 8, 2024 09:08
@rob05c rob05c requested a review from purnesh42H August 8, 2024 09:17
@rob05c rob05c force-pushed the rob05c/nil-loggers branch 5 times, most recently from 2242738 to 1184eb7 Compare August 13, 2024 12:28
@rob05c rob05c requested a review from purnesh42H August 13, 2024 13:04
@rob05c rob05c requested a review from dfawley November 10, 2024 19:31
@rob05c rob05c force-pushed the rob05c/nil-loggers branch 7 times, most recently from 3931f73 to b711721 Compare November 10, 2024 20:37
@github-actions github-actions bot removed the stale label Nov 10, 2024
@rob05c rob05c force-pushed the rob05c/nil-loggers branch 9 times, most recently from 459a5cb to 16b93cd Compare November 10, 2024 23:17
@rob05c
Copy link
Contributor Author

rob05c commented Nov 11, 2024

N.B. I made a few changes since the last review, adding

var sprintf = fmt.Sprintf
var exit = os.Exit

in loggerv2.go, to make it possible to test that os.Exit is called and fmt.Sprintf isn't.

Testing Sprintf not being called on io.Discard was previously done via the closure. After removing the closure, this allows the test to change the var to test.

For the exit, the Github ARM runner started breaking with the external call this PR was previously doing to test log.Fatal/os.Exit (a la https://go.dev/talks/2014/testing.slide#23), fork/exec /tmp/go-build692284400/b709/internal.test: invalid argument. It seems that since a recent change the arm test is doing something strange with processes. I couldn't get it to work, so I changed to the var instead, which the test can change, so it can be tested in the same process without actually exiting.

IMO the tests are valuable, but I realise it's a bit unusual, I can remove the vars and corresponding tests if you don't agree.

Changes the logger to not call Printf when the logger is io.Discard.

Also changes the logger constructor to use io.Discard instead of
io.MultiWriter(io.Discard, io.Discard), which is necessary to
detect all levels being discarded.

Fixes grpc#7463
@rob05c rob05c force-pushed the rob05c/nil-loggers branch from c6a3444 to 98aa027 Compare November 18, 2024 13:39
Copy link
Member

@dfawley dfawley left a comment

Choose a reason for hiding this comment

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

LGTM, thank you! PTAL @purnesh42H

@dfawley dfawley assigned purnesh42H and unassigned dfawley Nov 25, 2024
@purnesh42H purnesh42H merged commit bb7ae0a into grpc:master Nov 26, 2024
15 checks passed
@github-actions github-actions bot locked as resolved and limited conversation to collaborators May 26, 2025
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Type: Performance Performance improvements (CPU, network, memory, etc)
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Improve Logger Performance When Disabled
5 participants