feat: enable request logging via the --debug flag (#226)

<!-- Please use this template for your pull request. -->
<!-- Please use the sections that you need and delete other sections -->

## This PR
<!-- add the description of the PR here -->

- The `--debug` flag now also controls the logging for requests, when
set all logging levels are enabled for the `XXXWithID` `logger` methods
and allows the setting of request fields, allowing for improved
performance when logs are not required.
- `NewLogger` now takes an additional boolean argument to set the
internal `reqIDLogging` field, this field is also set to false when the
`*zap.Logger` argument is nil

### Related Issues
<!-- add here the GitHub issue that this PR resolves if applicable -->

### Notes
<!-- any additional notes for this PR -->

### Follow-up Tasks
<!-- anything that is related to this PR but not done here should be
noted under this section -->
<!-- if there is a need for a new issue, please link it here -->
This flag should be set by default in the operator
open-feature/open-feature-operator#260
### How to test
<!-- if applicable, add testing instructions under this section -->

Signed-off-by: James Milligan <james@omnant.co.uk>
Signed-off-by: James Milligan <75740990+james-milligan@users.noreply.github.com>
Co-authored-by: Skye Gill <gill.skye95@gmail.com>

cmd/start.go

@@ -85,7 +85,7 @@ var startCmd = &cobra.Command{
 		if err != nil {
 			log.Fatalf("can't initialize zap logger: %v", err)
 		}
-		logger := logger.NewLogger(l)
+		logger := logger.NewLogger(l, Debug)
 		rtLogger := logger.WithFields(zap.String("component", "start"))
 
 		if viper.GetString(syncProviderFlagName) != "" {

pkg/eval/fractional_evaluation_test.go

@@ -281,7 +281,7 @@ func TestFractionalEvaluation(t *testing.T) {
 	const reqID = "default"
 	for name, tt := range tests {
 		t.Run(name, func(t *testing.T) {
-			je := NewJSONEvaluator(logger.NewLogger(nil))
+			je := NewJSONEvaluator(logger.NewLogger(nil, false))
 			je.state = tt.flags
 
 			value, variant, reason, err := resolve[string](

pkg/eval/json_evaluator_test.go

@@ -275,7 +275,7 @@ var Flags = fmt.Sprintf(`{
 	DisabledFlag)
 
 func TestGetState_Valid_ContainsFlag(t *testing.T) {
-	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
+	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, false)}
 	_, err := evaluator.SetState("", ValidFlags)
 	if err != nil {
 		t.Fatalf("Expected no error")
@@ -295,7 +295,7 @@ func TestGetState_Valid_ContainsFlag(t *testing.T) {
 }
 
 func TestSetState_Invalid_Error(t *testing.T) {
-	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
+	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, false)}
 
 	// set state with an invalid flag definition
 	_, err := evaluator.SetState("", InvalidFlags)
@@ -305,7 +305,7 @@ func TestSetState_Invalid_Error(t *testing.T) {
 }
 
 func TestSetState_Valid_NoError(t *testing.T) {
-	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
+	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, false)}
 
 	// set state with a valid flag definition
 	_, err := evaluator.SetState("", ValidFlags)
@@ -329,7 +329,7 @@ func TestResolveBooleanValue(t *testing.T) {
 		{DisabledFlag, nil, StaticBoolValue, model.ErrorReason, model.FlagDisabledErrorCode},
 	}
 	const reqID = "default"
-	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
+	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, false)}
 	_, err := evaluator.SetState("", Flags)
 	if err != nil {
 		t.Fatalf("Expected no error")
@@ -368,7 +368,7 @@ func TestResolveStringValue(t *testing.T) {
 		{DisabledFlag, nil, "", model.ErrorReason, model.FlagDisabledErrorCode},
 	}
 	const reqID = "default"
-	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
+	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, false)}
 	_, err := evaluator.SetState("", Flags)
 	if err != nil {
 		t.Fatalf("Expected no error")
@@ -408,7 +408,7 @@ func TestResolveFloatValue(t *testing.T) {
 		{DisabledFlag, nil, 0, model.ErrorReason, model.FlagDisabledErrorCode},
 	}
 	const reqID = "default"
-	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
+	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, false)}
 	_, err := evaluator.SetState("", Flags)
 	if err != nil {
 		t.Fatalf("Expected no error")
@@ -448,7 +448,7 @@ func TestResolveIntValue(t *testing.T) {
 		{DisabledFlag, nil, 0, model.ErrorReason, model.FlagDisabledErrorCode},
 	}
 	const reqID = "default"
-	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
+	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, false)}
 	_, err := evaluator.SetState("", Flags)
 	if err != nil {
 		t.Fatalf("Expected no error")
@@ -488,7 +488,7 @@ func TestResolveObjectValue(t *testing.T) {
 		{DisabledFlag, nil, "{}", model.ErrorReason, model.FlagDisabledErrorCode},
 	}
 	const reqID = "default"
-	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
+	evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, false)}
 	_, err := evaluator.SetState("", Flags)
 	if err != nil {
 		t.Fatalf("Expected no error")
@@ -606,7 +606,7 @@ func TestMergeFlags(t *testing.T) {
 		tt := tt
 		t.Run(tt.name, func(t *testing.T) {
 			t.Parallel()
-			got, _ := tt.current.Merge(logger.NewLogger(nil), tt.newSource, tt.new)
+			got, _ := tt.current.Merge(logger.NewLogger(nil, false), tt.newSource, tt.new)
 			require.Equal(t, tt.want, got)
 		})
 	}

pkg/logger/logger.go

@@ -40,9 +40,13 @@ type Logger struct {
 	requestFields *sync.Map
 	Logger        *zap.Logger
 	fields        []zap.Field
+	reqIDLogging  bool
 }
 
 func (l *Logger) DebugWithID(reqID string, msg string, fields ...zap.Field) {
+	if !l.reqIDLogging {
+		return
+	}
 	if ce := l.Logger.Check(zap.DebugLevel, msg); ce != nil {
 		fields = append(fields, l.getFieldsForLog(reqID)...)
 		ce.Write(fields...)
@@ -57,6 +61,9 @@ func (l *Logger) Debug(msg string, fields ...zap.Field) {
 }
 
 func (l *Logger) InfoWithID(reqID string, msg string, fields ...zap.Field) {
+	if !l.reqIDLogging {
+		return
+	}
 	if ce := l.Logger.Check(zap.InfoLevel, msg); ce != nil {
 		fields = append(fields, l.getFieldsForLog(reqID)...)
 		ce.Write(fields...)
@@ -71,6 +78,9 @@ func (l *Logger) Info(msg string, fields ...zap.Field) {
 }
 
 func (l *Logger) WarnWithID(reqID string, msg string, fields ...zap.Field) {
+	if !l.reqIDLogging {
+		return
+	}
 	if ce := l.Logger.Check(zap.WarnLevel, msg); ce != nil {
 		fields = append(fields, l.getFieldsForLog(reqID)...)
 		ce.Write(fields...)
@@ -85,6 +95,9 @@ func (l *Logger) Warn(msg string, fields ...zap.Field) {
 }
 
 func (l *Logger) ErrorWithID(reqID string, msg string, fields ...zap.Field) {
+	if !l.reqIDLogging {
+		return
+	}
 	if ce := l.Logger.Check(zap.ErrorLevel, msg); ce != nil {
 		fields = append(fields, l.getFieldsForLog(reqID)...)
 		ce.Write(fields...)
@@ -99,6 +112,9 @@ func (l *Logger) Error(msg string, fields ...zap.Field) {
 }
 
 func (l *Logger) FatalWithID(reqID string, msg string, fields ...zap.Field) {
+	if !l.reqIDLogging {
+		return
+	}
 	if ce := l.Logger.Check(zap.FatalLevel, msg); ce != nil {
 		fields = append(fields, l.getFieldsForLog(reqID)...)
 		ce.Write(fields...)
@@ -115,6 +131,9 @@ func (l *Logger) Fatal(msg string, fields ...zap.Field) {
 // WriteFields adds field key and value pairs to the highest level Logger, they will be applied to all
 // subsequent log calls using the matching requestID
 func (l *Logger) WriteFields(reqID string, fields ...zap.Field) {
+	if !l.reqIDLogging {
+		return
+	}
 	res := append(l.getFields(reqID), fields...)
 	l.requestFields.Store(reqID, res)
 }
@@ -140,6 +159,9 @@ func (l *Logger) getFieldsForLog(reqID string) []zap.Field {
 
 // ClearFields clears all stored fields for a given requestID, important for maintaining performance
 func (l *Logger) ClearFields(reqID string) {
+	if !l.reqIDLogging {
+		return
+	}
 	l.requestFields.Delete(reqID)
 }
 
@@ -169,15 +191,19 @@ func NewZapLogger(level zapcore.Level) (*zap.Logger, error) {
 	return cfg.Build()
 }
 
-// NewLogger returns the logging wrapper for a given *zap.logger,
-// will return a wrapped zap noop logger if none is provided
-func NewLogger(logger *zap.Logger) *Logger {
+// NewLogger returns the logging wrapper for a given *zap.logger.
+// Noop logger bypasses the setting of fields, improving performance.
+// If *zap.Logger is nil a noop logger is set
+// and the reqIDLogging argument is overwritten to false
+func NewLogger(logger *zap.Logger, reqIDLogging bool) *Logger {
 	if logger == nil {
+		reqIDLogging = false
 		logger = zap.New(nil)
 	}
 	return &Logger{
 		Logger:        logger.WithOptions(zap.AddCallerSkip(1)),
 		requestFields: &sync.Map{},
+		reqIDLogging:  reqIDLogging,
 	}
 }
 
@@ -189,5 +215,6 @@ func (l *Logger) WithFields(fields ...zap.Field) *Logger {
 		Logger:        l.Logger,
 		requestFields: l.requestFields,
 		fields:        fields,
+		reqIDLogging:  l.reqIDLogging,
 	}
 }

pkg/logger/logger_test.go

@@ -20,7 +20,7 @@ func TestFieldStorageAndRetrieval(t *testing.T) {
 		},
 	}
 	for name, test := range tests {
-		l := NewLogger(nil)
+		l := NewLogger(&zap.Logger{}, true)
 		l.WriteFields(name, test.fields...)
 		returnedFields := l.getFields(name)
 		if !reflect.DeepEqual(returnedFields, test.fields) {
@@ -32,7 +32,7 @@ func TestFieldStorageAndRetrieval(t *testing.T) {
 func TestLoggerChildOperation(t *testing.T) {
 	id := "test"
 	// create parent logger
-	p := NewLogger(nil)
+	p := NewLogger(&zap.Logger{}, true)
 	// add field 1
 	field1 := zap.Int("field", 1)
 	p.WriteFields(id, field1)

pkg/service/connect_service_test.go

@@ -87,7 +87,7 @@ func TestConnectService_UnixConnection(t *testing.T) {
 				ConnectServiceConfiguration: &service.ConnectServiceConfiguration{
 					ServerSocketPath: tt.socketPath,
 				},
-				Logger: logger.NewLogger(nil),
+				Logger: logger.NewLogger(nil, false),
 			}
 			ctx := context.Background()
 			ctx, cancel := context.WithTimeout(ctx, 5*time.Second)
@@ -181,7 +181,7 @@ func TestConnectService_ResolveBoolean(t *testing.T) {
 			).AnyTimes()
 			s := service.ConnectService{
 				Eval:   eval,
-				Logger: logger.NewLogger(nil),
+				Logger: logger.NewLogger(nil, false),
 			}
 			got, err := s.ResolveBoolean(tt.functionArgs.ctx, connect.NewRequest(tt.functionArgs.req))
 			if err != nil && !errors.Is(err, tt.wantErr) {
@@ -229,7 +229,7 @@ func BenchmarkConnectService_ResolveBoolean(b *testing.B) {
 		).AnyTimes()
 		s := service.ConnectService{
 			Eval:   eval,
-			Logger: logger.NewLogger(nil),
+			Logger: logger.NewLogger(nil, false),
 		}
 		b.Run(name, func(b *testing.B) {
 			for i := 0; i < b.N; i++ {
@@ -315,7 +315,7 @@ func TestConnectService_ResolveString(t *testing.T) {
 			)
 			s := service.ConnectService{
 				Eval:   eval,
-				Logger: logger.NewLogger(nil),
+				Logger: logger.NewLogger(nil, false),
 			}
 			got, err := s.ResolveString(tt.functionArgs.ctx, connect.NewRequest(tt.functionArgs.req))
 			if (err != nil) && !errors.Is(err, tt.wantErr) {
@@ -364,7 +364,7 @@ func BenchmarkConnectService_ResolveString(b *testing.B) {
 
 		s := service.ConnectService{
 			Eval:   eval,
-			Logger: logger.NewLogger(nil),
+			Logger: logger.NewLogger(nil, false),
 		}
 		b.Run(name, func(b *testing.B) {
 			for i := 0; i < b.N; i++ {
@@ -450,7 +450,7 @@ func TestConnectService_ResolveFloat(t *testing.T) {
 			).AnyTimes()
 			s := service.ConnectService{
 				Eval:   eval,
-				Logger: logger.NewLogger(nil),
+				Logger: logger.NewLogger(nil, false),
 			}
 			got, err := s.ResolveFloat(tt.functionArgs.ctx, connect.NewRequest(tt.functionArgs.req))
 			if (err != nil) && !errors.Is(err, tt.wantErr) {
@@ -499,7 +499,7 @@ func BenchmarkConnectService_ResolveFloat(b *testing.B) {
 
 		s := service.ConnectService{
 			Eval:   eval,
-			Logger: logger.NewLogger(nil),
+			Logger: logger.NewLogger(nil, false),
 		}
 		b.Run(name, func(b *testing.B) {
 			for i := 0; i < b.N; i++ {
@@ -585,7 +585,7 @@ func TestConnectService_ResolveInt(t *testing.T) {
 			).AnyTimes()
 			s := service.ConnectService{
 				Eval:   eval,
-				Logger: logger.NewLogger(nil),
+				Logger: logger.NewLogger(nil, false),
 			}
 			got, err := s.ResolveInt(tt.functionArgs.ctx, connect.NewRequest(tt.functionArgs.req))
 			if (err != nil) && !errors.Is(err, tt.wantErr) {
@@ -634,7 +634,7 @@ func BenchmarkConnectService_ResolveInt(b *testing.B) {
 
 		s := service.ConnectService{
 			Eval:   eval,
-			Logger: logger.NewLogger(nil),
+			Logger: logger.NewLogger(nil, false),
 		}
 		b.Run(name, func(b *testing.B) {
 			for i := 0; i < b.N; i++ {
@@ -724,7 +724,7 @@ func TestConnectService_ResolveObject(t *testing.T) {
 			).AnyTimes()
 			s := service.ConnectService{
 				Eval:   eval,
-				Logger: logger.NewLogger(nil),
+				Logger: logger.NewLogger(nil, false),
 			}
 
 			if name != "eval returns error" {
@@ -783,7 +783,7 @@ func BenchmarkConnectService_ResolveObject(b *testing.B) {
 
 		s := service.ConnectService{
 			Eval:   eval,
-			Logger: logger.NewLogger(nil),
+			Logger: logger.NewLogger(nil, false),
 		}
 		if name != "eval returns error" {
 			outParsed, err := structpb.NewStruct(tt.evalFields.result)

pkg/sync/filepath_sync_test.go

@@ -74,7 +74,7 @@ func TestFilePathSync_Notify(t *testing.T) {
 
 			fpSync := sync.FilePathSync{
 				URI:    dirName,
-				Logger: logger.NewLogger(nil),
+				Logger: logger.NewLogger(nil, false),
 			}
 			inotifyChan := make(chan sync.INotify)
 
@@ -118,7 +118,7 @@ func TestFilePathSync_Fetch(t *testing.T) {
 		"success": {
 			fpSync: sync.FilePathSync{
 				URI:    fmt.Sprintf("%s/%s", dirName, fetchFileName),
-				Logger: logger.NewLogger(nil),
+				Logger: logger.NewLogger(nil, false),
 			},
 			handleResponse: func(t *testing.T, fetched string, err error) {
 				if err != nil {
@@ -133,7 +133,7 @@ func TestFilePathSync_Fetch(t *testing.T) {
 		"not found": {
 			fpSync: sync.FilePathSync{
 				URI:    fmt.Sprintf("%s/%s", dirName, "not_found"),
-				Logger: logger.NewLogger(nil),
+				Logger: logger.NewLogger(nil, false),
 			},
 			handleResponse: func(t *testing.T, fetched string, err error) {
 				if err == nil {

pkg/sync/http_sync_test.go

@@ -105,7 +105,7 @@ func TestHTTPSync_Fetch(t *testing.T) {
 				Client:      mockClient,
 				BearerToken: tt.bearerToken,
 				LastBodySHA: tt.lastBodySHA,
-				Logger:      logger.NewLogger(nil),
+				Logger:      logger.NewLogger(nil, false),
 			}
 
 			fetched, err := httpSync.Fetch(context.Background())
@@ -188,7 +188,7 @@ func TestHTTPSync_Notify(t *testing.T) {
 				Client:      mockClient,
 				Cron:        mockCron,
 				LastBodySHA: tt.lastBodySHA,
-				Logger:      logger.NewLogger(nil),
+				Logger:      logger.NewLogger(nil, false),
 			}
 
 			go func() {