Update lazy logger not to materialize unless it's being written to

[rabbbit]

Lazy logger is frequently used to delay (expensive) logger initialization unless we actually write to it.

This works for a pattern like:

logger := logger.With(.../*fields)

err := foo()
if err != nil {
   logger.Info("foo: %w, err)
}

Another common pattern, though, is

logger := logger.With(.../*fields)

// a lot of code

logger.Debug("something happened") // only Info is enabled

Here, despite the logs being discarded, we still initialize the logger even though it might be expensive.

This diff attempts to mitigate this by using the original core for level checking. This, afaiu, should be safe as With is only for field creation, and should not be changing log levels.

Preserving the original core to avoid race conditions (torn interfaces) on actual With initialization.

[codecov]

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 98.54%. Comparing base (7c80d7b) to head (2569897).
⚠️ Report is 2 commits behind head on master.

Additional details and impacted files

@@            Coverage Diff             @@
##           master    #1519      +/-   ##
==========================================
- Coverage   98.61%   98.54%   -0.07%     
==========================================
  Files          53       53              
  Lines        3031     3033       +2     
==========================================
  Hits         2989     2989              
- Misses         34       35       +1     
- Partials        8        9       +1     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

[prashantv]

this seems reasonable, though I am wondering whether we can do a more thorough check here,

if ce := d.originalCore.Check(e, nil); ce == nil {
  return ce
}

we pass nil since we don't want the underlying core to add itself to the CheckedEntry, but we do want to know what it would have done.

that should do more than the level check, but if the entry is supposed to be logged, we'll end up allocating an additional CheckedEntry

[rabbbit]

So this I wondered about and this is where my knowledge of zap ended.

I had this originally like that, but then the zapcore documentation says:

// If the entry
// should be logged, the Core adds itself to the CheckedEntry and returns
// the result.
which make it sound like by calling CheckedEntry, we'll have two cores having the same message (as you say), which seemed undesirable, even outside of the allocation? (won't this log twice?)

we can do a more thorough check here
WDYM here? Why is Check more thorough than Enabled?

[rabbbit]

I guess I'd want to avoid that one alloc if possible too.

[prashantv]

Check may decide not to log for reasons other than level, e.g., take a look at the sampler
https://github.com/uber-go/zap/blob/master/zapcore/sampler.go#L214-L229

Re: two cores logging twice, my snippet intentionally doesn't pass ce to the originalCore.Check to avoid adding to the same ce.

That said, reasoning about whether this will work correctly with sampling is non-trivial, so I think it may be better to stick to the level check only.