Add an option to defer expensive With operations

One common problem we see is that Loggers may be composed with
one or more With() statements but never used in a non error path.

For example, an author might write at the start of a function:

```
l := logger.With(zap.String("foo", "bar"))
```

but never use 'l' except in error branches. However, in
the non error cases, the expensive with operation has been
performed which can result in expensive (in terms of heap, CPU)
cloning (e.g of the JSON encoder) for no benefit.

This commit adds a new option, WithDeferred which defers all of
this expense until the time of first use. This creates considerable
performance improvement in the non error path at the slight expense
of performance over the existing implementation:

```
% go test -bench=Benchmark5Withs
goos: darwin
goarch: arm64
pkg: go.uber.org/zap
Benchmark5WithsUsed-10               	  492462	      2328 ns/op
Benchmark5WithsNotUsed-10            	  548709	      2284 ns/op
Benchmark5WithsDeferredUsed-10       	  469576	      2565 ns/op
Benchmark5WithsDeferredNotUsed-10    	 2590400	       465.7 ns/op
```

exp/go.sum

@@ -19,8 +19,6 @@ go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ=
 go.uber.org/multierr v1.10.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=
 go.uber.org/zap v1.24.0 h1:FiJd5l1UOLj0wCgbSE0rwwXHzEdAZS6hiiSnxJN/D60=
 go.uber.org/zap v1.24.0/go.mod h1:2kMP+WWQ8aoFoedH3T2sq6iJ2yDWpHbP0f6MQbS9Gkg=
-golang.org/x/exp v0.0.0-20230425010034-47ecfdc1ba53 h1:5llv2sWeaMSnA3w2kS57ouQQ4pudlXrR0dCgw51QK9o=
-golang.org/x/exp v0.0.0-20230425010034-47ecfdc1ba53/go.mod h1:V1LtkGg67GoY2N1AnLN78QLrzxkLyJw7RJb1gzOOz9w=
 golang.org/x/exp v0.0.0-20230801115018-d63ba01acd4b h1:r+vk0EmXNmekl0S0BascoeeoHk/L7wmaW2QF90K+kYI=
 golang.org/x/exp v0.0.0-20230801115018-d63ba01acd4b/go.mod h1:FXUEEKJgO7OQYeo8N01OfiKP8RXMtf6e8aTskBGqWdc=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=

logger.go

@@ -40,6 +40,7 @@ import (
 type Logger struct {
 	core zapcore.Core
 
+	deferWith   bool
 	development bool
 	addCaller   bool
 	onFatal     zapcore.CheckWriteHook // default is WriteThenFatal
@@ -178,6 +179,11 @@ func (log *Logger) With(fields ...Field) *Logger {
 	if len(fields) == 0 {
 		return log
 	}
+	if log.deferWith {
+		l := *log
+		l.core = zapcore.NewDeferredWith(log.core, fields)
+		return &l
+	}
 	l := log.clone()
 	l.core = l.core.With(fields)
 	return l

logger_bench_test.go

@@ -65,6 +65,21 @@ func withBenchedLogger(b *testing.B, f func(*Logger)) {
 	})
 }
 
+func withBenchedDeferredLogger(b *testing.B, f func(*Logger)) {
+	logger := New(
+		zapcore.NewCore(
+			zapcore.NewJSONEncoder(NewProductionConfig().EncoderConfig),
+			&ztest.Discarder{},
+			DebugLevel,
+		), DeferWith())
+	b.ResetTimer()
+	b.RunParallel(func(pb *testing.PB) {
+		for pb.Next() {
+			f(logger)
+		}
+	})
+}
+
 func BenchmarkNoContext(b *testing.B) {
 	withBenchedLogger(b, func(log *Logger) {
 		log.Info("No context.")
@@ -216,6 +231,48 @@ func Benchmark10Fields(b *testing.B) {
 	})
 }
 
+func Benchmark5WithsUsed(b *testing.B) {
+	withBenchedLogger(b, func(log *Logger) {
+		l1 := log.With(String("k1", "v1"))
+		l2 := l1.With(String("k2", "v2"))
+		l3 := l2.With(String("k3", "v3"))
+		l4 := l3.With(String("k4", "v4"))
+		l5 := l4.With(String("k5", "v5"))
+		l5.Info("used")
+	})
+}
+
+func Benchmark5WithsNotUsed(b *testing.B) {
+	withBenchedLogger(b, func(log *Logger) {
+		l1 := log.With(String("k1", "v1"))
+		l2 := l1.With(String("k2", "v2"))
+		l3 := l2.With(String("k3", "v3"))
+		l4 := l3.With(String("k4", "v4"))
+		_ = l4.With(String("k5", "v5"))
+	})
+}
+
+func Benchmark5WithsDeferredUsed(b *testing.B) {
+	withBenchedDeferredLogger(b, func(log *Logger) {
+		l1 := log.With(String("k1", "v1"))
+		l2 := l1.With(String("k2", "v2"))
+		l3 := l2.With(String("k3", "v3"))
+		l4 := l3.With(String("k4", "v4"))
+		l5 := l4.With(String("k5", "v5"))
+		l5.Info("used")
+	})
+}
+
+func Benchmark5WithsDeferredNotUsed(b *testing.B) {
+	withBenchedDeferredLogger(b, func(log *Logger) {
+		l1 := log.With(String("k1", "v1"))
+		l2 := l1.With(String("k2", "v2"))
+		l3 := l2.With(String("k3", "v3"))
+		l4 := l3.With(String("k4", "v4"))
+		_ = l4.With(String("k5", "v5"))
+	})
+}
+
 func Benchmark100Fields(b *testing.B) {
 	const batchSize = 50
 	logger := New(zapcore.NewCore(

logger_test.go

@@ -140,6 +140,23 @@ func TestLoggerWith(t *testing.T) {
 	})
 }
 
+func TestLoggerWithDeferred(t *testing.T) {
+	fieldOpts := opts(Fields(Int("foo", 42)), DeferWith())
+	withLogger(t, DebugLevel, fieldOpts, func(logger *Logger, logs *observer.ObservedLogs) {
+		// Child loggers should have copy-on-write semantics, so two children
+		// shouldn't stomp on each other's fields or affect the parent's fields.
+		logger.With(String("one", "two")).Info("")
+		logger.With(String("three", "four")).Info("")
+		logger.Info("")
+
+		assert.Equal(t, []observer.LoggedEntry{
+			{Context: []Field{Int("foo", 42), String("one", "two")}},
+			{Context: []Field{Int("foo", 42), String("three", "four")}},
+			{Context: []Field{Int("foo", 42)}},
+		}, logs.AllUntimed(), "Unexpected cross-talk between child loggers.")
+	})
+}
+
 func TestLoggerLogPanic(t *testing.T) {
 	for _, tt := range []struct {
 		do       func(*Logger)

options.go

@@ -132,6 +132,14 @@ func IncreaseLevel(lvl zapcore.LevelEnabler) Option {
 	})
 }
 
+// DeferWith defers any With operation unless the logger is actually
+// used to emit a log. This can save heap allocation and CPU
+func DeferWith() Option {
+	return optionFunc(func(log *Logger) {
+		log.deferWith = true
+	})
+}
+
 // OnFatal sets the action to take on fatal logs.
 //
 // Deprecated: Use [WithFatalHook] instead.

zapcore/deferred_with.go

@@ -0,0 +1,79 @@
+// Copyright (c) 2023 Uber Technologies, Inc.
+//
+// Permission is hereby granted, free of charge, to any person obtaining a copy
+// of this software and associated documentation files (the "Software"), to deal
+// in the Software without restriction, including without limitation the rights
+// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+// copies of the Software, and to permit persons to whom the Software is
+// furnished to do so, subject to the following conditions:
+//
+// The above copyright notice and this permission notice shall be included in
+// all copies or substantial portions of the Software.
+//
+// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
+// THE SOFTWARE.
+
+package zapcore
+
+import "sync"
+
+type deferredWithCore struct {
+	Core
+	sync.Once
+	fields []Field
+}
+
+var (
+	_ Core           = (*deferredWithCore)(nil)
+	_ leveledEnabler = (*deferredWithCore)(nil)
+)
+
+// NewDeferredWith wraps a Core with a "lazy" core that will.
+// only execute With operations if the logger is actually used
+func NewDeferredWith(core Core, fields []Field) *deferredWithCore {
+	return &deferredWithCore{
+		Core:   core,
+		fields: fields,
+	}
+}
+
+func (d *deferredWithCore) initOnce() {
+	d.Once.Do(func() {
+		d.Core = d.Core.With(d.fields)
+	})
+}
+
+func (d *deferredWithCore) With(fields []Field) Core {
+	d.initOnce()
+	return d.Core.With(fields)
+}
+
+func (d *deferredWithCore) Check(e Entry, ce *CheckedEntry) *CheckedEntry {
+	d.initOnce()
+	return d.Core.Check(e, ce)
+}
+
+func (d *deferredWithCore) Write(e Entry, fields []Field) error {
+	d.initOnce()
+	return d.Core.Write(e, fields)
+}
+
+func (d *deferredWithCore) Sync() error {
+	d.initOnce()
+	return d.Core.Sync()
+}
+
+func (d *deferredWithCore) Enabled(l Level) bool {
+	d.initOnce()
+	return d.Core.Enabled(l)
+}
+
+func (d *deferredWithCore) Level() Level {
+	d.initOnce()
+	return LevelOf(d.Core)
+}