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

[rob05c]

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 https://github.com/grpc/grpc-go/issues/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.

[linux-foundation-easycla[bot]]

The committers listed above are authorized under a signed CLA.

• :white_check_mark: login: rob05c / name: Robert O Butts (98aa02793b6700a1b4c40cf99dd4070aa8ccf5f7)

[codecov[bot]]

Codecov Report

All modified and coverable lines are covered by tests :white_check_mark:

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%)	:arrow_up:

... and 39 files with indirect coverage changes

[easwars]

I'm sorry, but I merged a change recently that refactored the logging implementations. So, this PR might have significant merge conflicts now.

[rob05c]

I'm sorry, but I merged a change recently that refactored the logging implementations. So, this PR might have significant merge conflicts now.

I fixed the conflicts.

[purnesh42H]

@rob05c Overall looks good to me. Just one clarification needed about warnLog and infoLog which I asked in one of the above comment

[purnesh42H]

Adding @dfawley as 2nd reviewer

[rob05c]

Ok, I think I addressed all the comments again. Let me know if I missed anything.

Also, the PR started failing a new Github check for RELEASE NOTES in the description, so I attempted to add it like I see in other PRs. I'm happy to change it if it isn't right, just let me know

[rob05c]

Is there anything else I need to do for this to be merged?

[purnesh42H]

Doug is reviewing it. Nothing is needed from you right now.

[dfawley]

Is there anything else I need to do for this to be merged?

Apologies; I have a lot on my plate right now, but will try to get to this in the next week or so.

[github-actions[bot]]

This PR is labeled as requiring an update from the reporter, and no update has been received after 6 days. If no update is provided in the next 7 days, this issue will be automatically closed.

[rob05c]

This PR is labeled as requiring an update from the reporter, and no update has been received after 6 days. If no update is provided in the next 7 days, this issue will be automatically closed.

Sorry, I was on vacation last week. I'll try to address the comments sometime this week

[github-actions[bot]]

This PR is labeled as requiring an update from the reporter, and no update has been received after 6 days. If no update is provided in the next 7 days, this issue will be automatically closed.

[rob05c]

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.