[Work in progress] Proof of concept deferred withs

As per internal Uber discussion

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)
+}