Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 13 commits into from
Oct 23, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
36 changes: 27 additions & 9 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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.
toddbaert marked this conversation as resolved.
Show resolved Hide resolved
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".

beeme1mr marked this conversation as resolved.
Show resolved Hide resolved
##### 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.
Expand Down
37 changes: 3 additions & 34 deletions openfeature/client.go
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,6 @@ type Client struct {
metadata ClientMetadata
hooks []Hook
evaluationContext EvaluationContext
logger logr.Logger

mx sync.RWMutex
}
Expand All @@ -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
toddbaert marked this conversation as resolved.
Show resolved Hide resolved
// 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
}

Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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()
Expand All @@ -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
Expand Down
17 changes: 4 additions & 13 deletions openfeature/event_executor.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,8 @@
"sync"
"time"

"github.com/go-logr/logr"
"log/slog"

"golang.org/x/exp/maps"
)

Expand Down Expand Up @@ -37,19 +38,17 @@
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),
}

Expand Down Expand Up @@ -87,14 +86,6 @@
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()
Expand Down Expand Up @@ -377,7 +368,7 @@
go func() {
defer func() {
if r := recover(); r != nil {
e.logger.Info("recovered from a panic")
slog.Info("recovered from a panic")

Check warning on line 371 in openfeature/event_executor.go

View check run for this annotation

Codecov / codecov/patch

openfeature/event_executor.go#L371

Added line #L371 was not covered by tests
}
}()

Expand Down
24 changes: 11 additions & 13 deletions openfeature/event_executor_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand All @@ -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)
Expand Down Expand Up @@ -1173,7 +1171,7 @@ func TestEventHandler_1ToNMapping(t *testing.T) {
&ProviderEventing{},
}

executor := newEventExecutor(logger)
executor := newEventExecutor()

err := executor.registerDefaultProvider(eventingProvider)
if err != nil {
Expand Down Expand Up @@ -1215,7 +1213,7 @@ func TestEventHandler_1ToNMapping(t *testing.T) {
},
}

executor := newEventExecutor(logger)
executor := newEventExecutor()

err := executor.registerDefaultProvider(eventingProvider)
if err != nil {
Expand Down Expand Up @@ -1266,7 +1264,7 @@ func TestEventHandler_1ToNMapping(t *testing.T) {
},
}

executor := newEventExecutor(logger)
executor := newEventExecutor()

err := executor.registerNamedEventingProvider("clientA", eventingProvider)
if err != nil {
Expand Down Expand Up @@ -1317,7 +1315,7 @@ func TestEventHandler_1ToNMapping(t *testing.T) {
},
}

executor := newEventExecutor(logger)
executor := newEventExecutor()

err := executor.registerNamedEventingProvider("clientA", eventingProvider)
if err != nil {
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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)
Expand Down
Loading
Loading