feat: new approach for context fields logging

8 files changed, 136 insertions, 21 deletions

diff --git a/library/go/core/log/ctxlog/ctxlog.go b/library/go/core/log/ctxlog/ctxlog.go
index e054e9c2ed..6792b02a79 100644
--- a/library/go/core/log/ctxlog/ctxlog.go
+++ b/library/go/core/log/ctxlog/ctxlog.go
@@ -105,10 +105,10 @@ func Fatalf(ctx context.Context, l log.Logger, format string, args ...interface{
 }
 
 func mergeFields(a, b []log.Field) []log.Field {
-	if a == nil {
+	if len(a) == 0 {
 		return b
 	}
-	if b == nil {
+	if len(b) == 0 {
 		return a
 	}
 
diff --git a/library/go/core/log/fields.go b/library/go/core/log/fields.go
index afd41c197e..ab19d2c2e3 100644
--- a/library/go/core/log/fields.go
+++ b/library/go/core/log/fields.go
@@ -1,6 +1,7 @@
 package log
 
 import (
+	"context"
 	"fmt"
 	"time"
 )
@@ -42,6 +43,8 @@ const (
 	FieldTypeReflect
 	// FieldTypeByteString is for a bytes that can be represented as UTF-8 string
 	FieldTypeByteString
+	// FieldTypeContext wraps context for lazy context fields evaluation if possible
+	FieldTypeContext
 )
 
 // Field stores one structured logging field
@@ -153,6 +156,8 @@ func (f Field) Any() interface{} {
 		return f.Interface()
 	case FieldTypeByteString:
 		return f.Interface()
+	case FieldTypeContext:
+		return f.Interface()
 	default:
 		// For when new field type is not added to this func
 		panic(fmt.Sprintf("unknown field type: %d", f.Type()))
@@ -371,6 +376,11 @@ func ByteString(key string, value []byte) Field {
 	return Field{key: key, ftype: FieldTypeByteString, iface: value}
 }
 
+// Context constructs field for lazy context fields evaluation if possible
+func Context(ctx context.Context) Field {
+	return Field{ftype: FieldTypeContext, iface: ctx}
+}
+
 // Any tries to deduce interface{} underlying type and constructs Field from it.
 // Use of this function is ok only for the sole purpose of not repeating its entire code
 // or parts of it in user's code (when you need to log interface{} types with unknown content).
@@ -440,6 +450,8 @@ func Any(key string, value interface{}) Field {
 		return NamedError(key, val)
 	case []error:
 		return Errors(key, val)
+	case context.Context:
+		return Context(val)
 	default:
 		return Field{key: key, ftype: FieldTypeAny, iface: value}
 	}
diff --git a/library/go/core/log/test/ctx_bench_test.go b/library/go/core/log/test/ctx_bench_test.go
new file mode 100644
index 0000000000..48a81ac705
--- /dev/null
+++ b/library/go/core/log/test/ctx_bench_test.go
@@ -0,0 +1,76 @@
+package test
+
+import (
+	"context"
+	"fmt"
+	"testing"
+
+	"github.com/ydb-platform/ydb/library/go/core/log"
+	"github.com/ydb-platform/ydb/library/go/core/log/ctxlog"
+	"github.com/ydb-platform/ydb/library/go/core/log/zap"
+	"github.com/ydb-platform/ydb/library/go/core/log/zap/encoders"
+	uberzap "go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+)
+
+type nopWriteSyncer struct{}
+
+func (nws *nopWriteSyncer) Write(p []byte) (n int, err error) {
+	return len(p), nil
+}
+
+func (nws *nopWriteSyncer) Sync() error {
+	return nil
+}
+
+type levelEnabler struct {
+	enabled bool
+}
+
+func (l *levelEnabler) Enabled(zapcore.Level) bool {
+	return l.enabled
+}
+
+func BenchmarkWithFields(b *testing.B) {
+	cfg := uberzap.NewDevelopmentEncoderConfig()
+	cfg.TimeKey = ""
+	cfg.LevelKey = ""
+	kvEnc, _ := encoders.NewKVEncoder(cfg)
+	enabler := &levelEnabler{}
+	core := zapcore.NewCore(kvEnc, &nopWriteSyncer{}, enabler)
+	logger := uberzap.New(core)
+	ctx := ctxlog.WithFields(context.Background(),
+		log.String("foo", "bar"),
+		log.String("bar", "baz"),
+	)
+
+	l := &zap.Logger{L: logger}
+	for _, enabled := range []bool{true, false} {
+		enabler.enabled = enabled
+		b.Run(fmt.Sprintf("zap_%t", enabled), func(b *testing.B) {
+			b.ReportAllocs()
+			for i := 0; i < b.N; i++ {
+				logger.Info("test", uberzap.String("foo", "bar"), uberzap.String("bar", "baz"))
+			}
+		})
+		b.Run(fmt.Sprintf("core_log_%t", enabled), func(b *testing.B) {
+			b.ReportAllocs()
+			for i := 0; i < b.N; i++ {
+				ctxlog.Info(ctx, l, "test", log.String("foo", "bar"), log.String("bar", "baz"))
+			}
+		})
+		b.Run(fmt.Sprintf("core_log_new_%t", enabled), func(b *testing.B) {
+			b.ReportAllocs()
+			for i := 0; i < b.N; i++ {
+				l.Info("test", log.String("foo", "bar"), log.String("bar", "baz"), log.Context(ctx))
+			}
+		})
+		b.Run(fmt.Sprintf("core_log_fmt_%t", enabled), func(b *testing.B) {
+			b.ReportAllocs()
+			for i := 0; i < b.N; i++ {
+				ctxlog.Infof(ctx, l, "test %s %d", "test", 42)
+			}
+		})
+	}
+
+}
diff --git a/library/go/core/log/test/ya.make b/library/go/core/log/test/ya.make
index be231ce558..353815993c 100644
--- a/library/go/core/log/test/ya.make
+++ b/library/go/core/log/test/ya.make
@@ -1,6 +1,9 @@
 GO_TEST()
 
+TAG(ya:run_go_benchmark)
+
 GO_TEST_SRCS(
+    ctx_bench_test.go
     log_bench_test.go
     log_test.go
 )
diff --git a/library/go/core/log/zap/context.go b/library/go/core/log/zap/context.go
new file mode 100644
index 0000000000..e154610b76
--- /dev/null
+++ b/library/go/core/log/zap/context.go
@@ -0,0 +1,31 @@
+package zap
+
+import (
+	"context"
+
+	"github.com/ydb-platform/ydb/library/go/core/log/ctxlog"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+)
+
+type ctxField struct {
+	ctx context.Context
+}
+
+// MarshalLogObject implements zapcore.ObjectMarshaler to append context fields directly to encoder in a lazy manner
+func (c ctxField) MarshalLogObject(encoder zapcore.ObjectEncoder) error {
+	fields := ctxlog.ContextFields(c.ctx)
+	for _, f := range fields {
+		zapifyField(f).AddTo(encoder)
+	}
+	return nil
+}
+
+// Context creates a log field from context - all fields bound with ctxlog.WithFields will be added.
+func Context(ctx context.Context) zap.Field {
+	return zap.Field{
+		Key:       "",
+		Type:      zapcore.InlineMarshalerType,
+		Interface: ctxField{ctx: ctx},
+	}
+}
diff --git a/library/go/core/log/zap/logrotate/ya.make b/library/go/core/log/zap/logrotate/ya.make
index 3171836441..a5e7973429 100644
--- a/library/go/core/log/zap/logrotate/ya.make
+++ b/library/go/core/log/zap/logrotate/ya.make
@@ -1,10 +1,9 @@
 GO_LIBRARY()
 
+SRCS(error.go)
+
 IF (OS_LINUX)
-    SRCS(
-        error.go
-        sink.go
-    )
+    SRCS(sink.go)
 
     GO_TEST_SRCS(sink_test.go)
 
@@ -12,10 +11,7 @@ IF (OS_LINUX)
 ENDIF()
 
 IF (OS_DARWIN)
-    SRCS(
-        error.go
-        sink.go
-    )
+    SRCS(sink.go)
 
     GO_TEST_SRCS(sink_test.go)
 
@@ -23,20 +19,11 @@ IF (OS_DARWIN)
 ENDIF()
 
 IF (OS_WINDOWS)
-    SRCS(
-        error.go
-        sink_stub.go
-    )
+    SRCS(sink_stub.go)
 ENDIF()
 
 END()
 
-IF (
-    OS_DARWIN
-    OR
-    OS_FREEBSD
-    OR
-    OS_LINUX
-)
+IF (OS_DARWIN OR OS_FREEBSD OR OS_LINUX)
     RECURSE_FOR_TESTS(gotest)
 ENDIF()
diff --git a/library/go/core/log/zap/ya.make b/library/go/core/log/zap/ya.make
index bc41967e07..98e479270f 100644
--- a/library/go/core/log/zap/ya.make
+++ b/library/go/core/log/zap/ya.make
@@ -1,6 +1,9 @@
 GO_LIBRARY()
 
+TAG(ya:run_go_benchmark)
+
 SRCS(
+    context.go
     deploy.go
     qloud.go
     zap.go
diff --git a/library/go/core/log/zap/zapify.go b/library/go/core/log/zap/zapify.go
index 5fd6ffb1be..4239949ce3 100644
--- a/library/go/core/log/zap/zapify.go
+++ b/library/go/core/log/zap/zapify.go
@@ -1,6 +1,7 @@
 package zap
 
 import (
+	"context"
 	"fmt"
 
 	"github.com/ydb-platform/ydb/library/go/core/log"
@@ -79,6 +80,8 @@ func zapifyField(field log.Field) zap.Field {
 		return zap.Reflect(field.Key(), field.Interface())
 	case log.FieldTypeByteString:
 		return zap.ByteString(field.Key(), field.Binary())
+	case log.FieldTypeContext:
+		return Context(field.Interface().(context.Context))
 	default:
 		// For when new field type is not added to this func
 		panic(fmt.Sprintf("unknown field type: %d", field.Type()))