feat: add logging hook, rm logging from evaluation (#289)

* add logging hook and doc Signed-off-by: liran2000 <[email protected]> Signed-off-by: Todd Baert <[email protected]> Co-authored-by: Todd Baert <[email protected]>
open-feature · Oct 23, 2024 · 7850eec · 7850eec
1 parent ddfffdd
commit 7850eec
Show file tree

Hide file tree

Showing 10 changed files with 389 additions and 127 deletions.
diff --git a/README.md b/README.md
@@ -175,21 +175,39 @@ value, err := client.BooleanValue(
 
 ### Logging
 
-The standard Go log package is used by default to show error logs.
-This can be overridden using the structured logging, [logr](https://github.com/go-logr/logr) API, allowing integration to any package.
-There are already [integration implementations](https://github.com/go-logr/logr#implementations-non-exhaustive) for many of the popular logger packages.
+Note that in accordance with the OpenFeature specification, the SDK doesn't generally log messages during flag evaluation.
+
+#### Logging Hook
+
+The GO SDK includes a `LoggingHook`, which logs detailed information at key points during flag evaluation, using [slog](https://pkg.go.dev/log/slog) structured logging API.
+This hook can be particularly helpful for troubleshooting and debugging; simply attach it at the global, client or invocation level and ensure your log level is set to "debug".
+
+##### Usage example
 
 ```go
-var l logr.Logger
-l = integratedlogr.New() // replace with your chosen integrator
+// configure slog
+var programLevel = new(slog.LevelVar)
+programLevel.Set(slog.LevelDebug)
+h := slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{Level: programLevel})
+slog.SetDefault(slog.New(h))
+
+// add a hook globally, to run on all evaluations
+hook, err := NewLoggingHook(false)
+if err != nil {
+  // handle error
+}
 
-openfeature.SetLogger(l) // set the logger at global level
+openfeature.AddHooks(hook)
+
+client.BooleanValueDetails(context.Background(), "not-exist", true, openfeature.EvaluationContext{})
 
-c := openfeature.NewClient("log").WithLogger(l) // set the logger at client level
 ```
 
-[logr](https://github.com/go-logr/logr) uses incremental verbosity levels (akin to named levels but in integer form).
-The SDK logs `info` at level `0` and `debug` at level `1`. Errors are always logged.
+###### Output
+> {"time":"2024-10-23T13:33:09.8870867+03:00","level":"DEBUG","msg":"Before stage","domain":"test-client","provider_name":"InMemoryProvider","flag_key":"not-exist","default_value":true}  
+{"time":"2024-10-23T13:33:09.8968242+03:00","level":"ERROR","msg":"Error stage","domain":"test-client","provider_name":"InMemoryProvider","flag_key":"not-exist","default_value":true,"error_message":"error code: FLAG_NOT_FOUND: flag for key not-exist not found"}
+
+See [hooks](#hooks) for more information on configuring hooks.
 
 ### Domains
 Clients can be assigned to a domain. A domain is a logical identifier which can be used to associate clients with a particular provider. If a domain has no associated provider, the default provider is used.

diff --git a/openfeature/client.go b/openfeature/client.go
@@ -41,7 +41,6 @@ type Client struct {
 	metadata          ClientMetadata
 	hooks             []Hook
 	evaluationContext EvaluationContext
-	logger            logr.Logger
 
 	mx sync.RWMutex
 }
@@ -52,25 +51,24 @@ var _ IClient = (*Client)(nil)
 // NewClient returns a new Client. Name is a unique identifier for this client
 // This helper exists for historical reasons. It is recommended to interact with IEvaluation to derive IClient instances.
 func NewClient(name string) *Client {
-	return newClient(name, api, eventing, logger)
+	return newClient(name, api, eventing)
 }
 
-func newClient(name string, apiRef evaluationImpl, eventRef clientEvent, log logr.Logger) *Client {
+func newClient(name string, apiRef evaluationImpl, eventRef clientEvent) *Client {
 	return &Client{
 		api:               apiRef,
 		clientEventing:    eventRef,
-		logger:            log,
 		metadata:          ClientMetadata{name: name},
 		hooks:             []Hook{},
 		evaluationContext: EvaluationContext{},
 	}
 }
 
+// Deprecated
 // WithLogger sets the logger of the client
 func (c *Client) WithLogger(l logr.Logger) *Client {
 	c.mx.Lock()
 	defer c.mx.Unlock()
-	c.logger = l
 	return c
 }
 
@@ -395,10 +393,6 @@ func (c *Client) BooleanValueDetails(ctx context.Context, flag string, defaultVa
 	value, ok := evalDetails.Value.(bool)
 	if !ok {
 		err := errors.New("evaluated value is not a boolean")
-		c.logger.Error(
-			err, "invalid flag resolution type", "expectedType", "boolean",
-			"gotType", fmt.Sprintf("%T", evalDetails.Value),
-		)
 		boolEvalDetails := BooleanEvaluationDetails{
 			Value:             defaultValue,
 			EvaluationDetails: evalDetails.EvaluationDetails,
@@ -443,10 +437,6 @@ func (c *Client) StringValueDetails(ctx context.Context, flag string, defaultVal
 	value, ok := evalDetails.Value.(string)
 	if !ok {
 		err := errors.New("evaluated value is not a string")
-		c.logger.Error(
-			err, "invalid flag resolution type", "expectedType", "string",
-			"gotType", fmt.Sprintf("%T", evalDetails.Value),
-		)
 		strEvalDetails := StringEvaluationDetails{
 			Value:             defaultValue,
 			EvaluationDetails: evalDetails.EvaluationDetails,
@@ -491,10 +481,6 @@ func (c *Client) FloatValueDetails(ctx context.Context, flag string, defaultValu
 	value, ok := evalDetails.Value.(float64)
 	if !ok {
 		err := errors.New("evaluated value is not a float64")
-		c.logger.Error(
-			err, "invalid flag resolution type", "expectedType", "float64",
-			"gotType", fmt.Sprintf("%T", evalDetails.Value),
-		)
 		floatEvalDetails := FloatEvaluationDetails{
 			Value:             defaultValue,
 			EvaluationDetails: evalDetails.EvaluationDetails,
@@ -539,10 +525,6 @@ func (c *Client) IntValueDetails(ctx context.Context, flag string, defaultValue
 	value, ok := evalDetails.Value.(int64)
 	if !ok {
 		err := errors.New("evaluated value is not an int64")
-		c.logger.Error(
-			err, "invalid flag resolution type", "expectedType", "int64",
-			"gotType", fmt.Sprintf("%T", evalDetails.Value),
-		)
 		intEvalDetails := IntEvaluationDetails{
 			Value:             defaultValue,
 			EvaluationDetails: evalDetails.EvaluationDetails,
@@ -698,10 +680,6 @@ func (c *Client) evaluate(
 	evalCtx, err = c.beforeHooks(ctx, hookCtx, apiClientInvocationProviderHooks, evalCtx, options)
 	hookCtx.evaluationContext = evalCtx
 	if err != nil {
-		c.logger.Error(
-			err, "before hook", "flag", flag, "defaultValue", defaultValue,
-			"evaluationContext", evalCtx, "evaluationOptions", options, "type", flagType.String(),
-		)
 		err = fmt.Errorf("before hook: %w", err)
 		c.errorHooks(ctx, hookCtx, providerInvocationClientApiHooks, err, options)
 		return evalDetails, err
@@ -736,11 +714,6 @@ func (c *Client) evaluate(
 
 	err = resolution.Error()
 	if err != nil {
-		c.logger.Error(
-			err, "flag resolution", "flag", flag, "defaultValue", defaultValue,
-			"evaluationContext", evalCtx, "evaluationOptions", options, "type", flagType.String(), "errorCode", err,
-			"errMessage", resolution.ResolutionError.message,
-		)
 		err = fmt.Errorf("error code: %w", err)
 		c.errorHooks(ctx, hookCtx, providerInvocationClientApiHooks, err, options)
 		evalDetails.ResolutionDetail = resolution.ResolutionDetail()
@@ -751,10 +724,6 @@ func (c *Client) evaluate(
 	evalDetails.ResolutionDetail = resolution.ResolutionDetail()
 
 	if err := c.afterHooks(ctx, hookCtx, providerInvocationClientApiHooks, evalDetails, options); err != nil {
-		c.logger.Error(
-			err, "after hook", "flag", flag, "defaultValue", defaultValue,
-			"evaluationContext", evalCtx, "evaluationOptions", options, "type", flagType.String(),
-		)
 		err = fmt.Errorf("after hook: %w", err)
 		c.errorHooks(ctx, hookCtx, providerInvocationClientApiHooks, err, options)
 		return evalDetails, err

diff --git a/openfeature/event_executor.go b/openfeature/event_executor.go
@@ -6,7 +6,8 @@ import (
 	"sync"
 	"time"
 
-	"github.com/go-logr/logr"
+	"log/slog"
+
 	"golang.org/x/exp/maps"
 )
 
@@ -37,19 +38,17 @@ type eventExecutor struct {
 	activeSubscriptions      []providerReference
 	apiRegistry              map[EventType][]EventCallback
 	scopedRegistry           map[string]scopedCallback
-	logger                   logr.Logger
 	eventChan                chan eventPayload
 	once                     sync.Once
 	mu                       sync.Mutex
 }
 
-func newEventExecutor(logger logr.Logger) *eventExecutor {
+func newEventExecutor() *eventExecutor {
 	executor := eventExecutor{
 		namedProviderReference: map[string]providerReference{},
 		activeSubscriptions:    []providerReference{},
 		apiRegistry:            map[EventType][]EventCallback{},
 		scopedRegistry:         map[string]scopedCallback{},
-		logger:                 logger,
 		eventChan:              make(chan eventPayload, 5),
 	}
 
@@ -87,14 +86,6 @@ type providerReference struct {
 	shutdownSemaphore chan interface{}
 }
 
-// updateLogger updates the executor's logger
-func (e *eventExecutor) updateLogger(l logr.Logger) {
-	e.mu.Lock()
-	defer e.mu.Unlock()
-
-	e.logger = l
-}
-
 // AddHandler adds an API(global) level handler
 func (e *eventExecutor) AddHandler(t EventType, c EventCallback) {
 	e.mu.Lock()
@@ -377,7 +368,7 @@ func (e *eventExecutor) executeHandler(f func(details EventDetails), event Event
 	go func() {
 		defer func() {
 			if r := recover(); r != nil {
-				e.logger.Info("recovered from a panic")
+				slog.Info("recovered from a panic")
 			}
 		}()
 

diff --git a/openfeature/event_executor_test.go b/openfeature/event_executor_test.go
@@ -6,13 +6,11 @@ import (
 	"testing"
 	"time"
 
-	"github.com/go-logr/logr"
-	"github.com/open-feature/go-sdk/openfeature/internal"
 	"golang.org/x/exp/slices"
 )
 
 func init() {
-	logger = logr.New(internal.Logger{})
+
 }
 
 // Requirement 5.1.1 The provider MAY define a mechanism for signaling the occurrence of one of a set of events,
@@ -31,7 +29,7 @@ func TestEventHandler_RegisterUnregisterEventProvider(t *testing.T) {
 			eventingImpl,
 		}
 
-		executor := newEventExecutor(logger)
+		executor := newEventExecutor()
 		err := executor.registerDefaultProvider(eventingProvider)
 		if err != nil {
 			t.Fatal(err)
@@ -1173,7 +1171,7 @@ func TestEventHandler_1ToNMapping(t *testing.T) {
 			&ProviderEventing{},
 		}
 
-		executor := newEventExecutor(logger)
+		executor := newEventExecutor()
 
 		err := executor.registerDefaultProvider(eventingProvider)
 		if err != nil {
@@ -1215,7 +1213,7 @@ func TestEventHandler_1ToNMapping(t *testing.T) {
 			},
 		}
 
-		executor := newEventExecutor(logger)
+		executor := newEventExecutor()
 
 		err := executor.registerDefaultProvider(eventingProvider)
 		if err != nil {
@@ -1266,7 +1264,7 @@ func TestEventHandler_1ToNMapping(t *testing.T) {
 			},
 		}
 
-		executor := newEventExecutor(logger)
+		executor := newEventExecutor()
 
 		err := executor.registerNamedEventingProvider("clientA", eventingProvider)
 		if err != nil {
@@ -1317,7 +1315,7 @@ func TestEventHandler_1ToNMapping(t *testing.T) {
 			},
 		}
 
-		executor := newEventExecutor(logger)
+		executor := newEventExecutor()
 
 		err := executor.registerNamedEventingProvider("clientA", eventingProvider)
 		if err != nil {
@@ -1354,7 +1352,7 @@ func TestEventHandler_1ToNMapping(t *testing.T) {
 
 func TestEventHandler_Registration(t *testing.T) {
 	t.Run("API handlers", func(t *testing.T) {
-		executor := newEventExecutor(logger)
+		executor := newEventExecutor()
 
 		// Add multiple - ProviderReady
 		executor.AddHandler(ProviderReady, &h1)
@@ -1392,7 +1390,7 @@ func TestEventHandler_Registration(t *testing.T) {
 	})
 
 	t.Run("Client handlers", func(t *testing.T) {
-		executor := newEventExecutor(logger)
+		executor := newEventExecutor()
 
 		// Add multiple - client a
 		executor.AddClientHandler("a", ProviderReady, &h1)
@@ -1429,7 +1427,7 @@ func TestEventHandler_Registration(t *testing.T) {
 
 func TestEventHandler_APIRemoval(t *testing.T) {
 	t.Run("API level removal", func(t *testing.T) {
-		executor := newEventExecutor(logger)
+		executor := newEventExecutor()
 
 		// Add multiple - ProviderReady
 		executor.AddHandler(ProviderReady, &h1)
@@ -1482,7 +1480,7 @@ func TestEventHandler_APIRemoval(t *testing.T) {
 	})
 
 	t.Run("Client level removal", func(t *testing.T) {
-		executor := newEventExecutor(logger)
+		executor := newEventExecutor()
 
 		// Add multiple - client a
 		executor.AddClientHandler("a", ProviderReady, &h1)
@@ -1539,7 +1537,7 @@ func TestEventHandler_APIRemoval(t *testing.T) {
 	})
 
 	t.Run("remove handlers that were not added", func(t *testing.T) {
-		executor := newEventExecutor(logger)
+		executor := newEventExecutor()
 
 		// removal of non-added handlers shall not panic
 		executor.RemoveHandler(ProviderReady, &h1)