Skip to content

Commit 500950d

Browse files
authored
Merge pull request #155 from Flagsmith/feat/logs
feat: Use slog interally, add WithSlogLogger. Log HTTP requests/responses
2 parents adf54aa + af4e9cd commit 500950d

File tree

7 files changed

+206
-28
lines changed

7 files changed

+206
-28
lines changed

analytics.go

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -36,12 +36,16 @@ func NewAnalyticsProcessor(ctx context.Context, client *resty.Client, baseURL st
3636
endpoint: baseURL + AnalyticsEndpoint,
3737
log: log,
3838
}
39+
log.Debugf("analytics processor starting")
3940
go processor.start(ctx, tickerInterval)
4041
return &processor
4142
}
4243

4344
func (a *AnalyticsProcessor) start(ctx context.Context, tickerInterval int) {
4445
ticker := time.NewTicker(time.Duration(tickerInterval) * time.Millisecond)
46+
defer func() {
47+
a.log.Debugf("analytics processor stopped")
48+
}()
4549
for {
4650
select {
4751
case <-ticker.C:

analytics_test.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -43,7 +43,7 @@ func TestAnalytics(t *testing.T) {
4343
client.SetHeader("X-Environment-Key", EnvironmentAPIKey)
4444

4545
// Now let's create the processor
46-
processor := NewAnalyticsProcessor(context.Background(), client, server.URL+"/api/v1/", &analyticsTimer, createLogger())
46+
processor := NewAnalyticsProcessor(context.Background(), client, server.URL+"/api/v1/", &analyticsTimer, newSlogToLoggerAdapter(createLogger()))
4747

4848
// and, track some features
4949
processor.TrackFeature("feature_1")

client.go

Lines changed: 28 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ package flagsmith
33
import (
44
"context"
55
"fmt"
6+
"log/slog"
67
"strings"
78
"sync/atomic"
89
"time"
@@ -34,7 +35,7 @@ type Client struct {
3435
client *resty.Client
3536
ctxLocalEval context.Context
3637
ctxAnalytics context.Context
37-
log Logger
38+
log *slog.Logger
3839
offlineHandler OfflineHandler
3940
errorHandler func(handler *FlagsmithAPIError)
4041
}
@@ -70,7 +71,21 @@ func NewClient(apiKey string, options ...Option) *Client {
7071
opt(c)
7172
}
7273
}
73-
c.client.SetLogger(c.log)
74+
c.client = c.client.
75+
SetLogger(newSlogToRestyAdapter(c.log)).
76+
OnBeforeRequest(newRestyLogRequestMiddleware(c.log)).
77+
OnAfterResponse(newRestyLogResponseMiddleware(c.log))
78+
79+
c.log.Debug("initialising Flagsmith client",
80+
"base_url", c.config.baseURL,
81+
"local_evaluation", c.config.localEvaluation,
82+
"offline", c.config.offlineMode,
83+
"analytics", c.config.enableAnalytics,
84+
"realtime", c.config.useRealtime,
85+
"realtime_url", c.config.realtimeBaseUrl,
86+
"env_refresh_interval", c.config.envRefreshInterval,
87+
"timeout", c.config.timeout,
88+
)
7489

7590
if c.config.offlineMode && c.offlineHandler == nil {
7691
panic("offline handler must be provided to use offline mode.")
@@ -97,7 +112,15 @@ func NewClient(apiKey string, options ...Option) *Client {
97112
}
98113
// Initialise analytics processor
99114
if c.config.enableAnalytics {
100-
c.analyticsProcessor = NewAnalyticsProcessor(c.ctxAnalytics, c.client, c.config.baseURL, nil, c.log)
115+
c.analyticsProcessor = NewAnalyticsProcessor(
116+
c.ctxAnalytics,
117+
c.client,
118+
c.config.baseURL,
119+
nil,
120+
newSlogToLoggerAdapter(
121+
c.log.With(slog.String("worker", "analytics")),
122+
),
123+
)
101124
}
102125
return c
103126
}
@@ -319,7 +342,7 @@ func (c *Client) pollEnvironment(ctx context.Context) {
319342
defer cancel()
320343
err := c.UpdateEnvironment(ctx)
321344
if err != nil {
322-
c.log.Errorf("Failed to update environment: %v", err)
345+
c.log.Error("failed to update environment", "error", err)
323346
}
324347
}
325348
update()
@@ -364,6 +387,7 @@ func (c *Client) UpdateEnvironment(ctx context.Context) error {
364387
}
365388
c.identitiesWithOverrides.Store(identitiesWithOverrides)
366389

390+
c.log.Info("environment updated", "environment", env.APIKey)
367391
return nil
368392
}
369393

client_test.go

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,8 +5,10 @@ import (
55
"errors"
66
"fmt"
77
"io"
8+
"log/slog"
89
"net/http"
910
"net/http/httptest"
11+
"strings"
1012
"sync"
1113
"testing"
1214
"time"
@@ -959,3 +961,19 @@ data: {"updated_at": %f}
959961
// Flush the event to the client
960962
flusher.Flush()
961963
}
964+
965+
func TestWithSlogLogger(t *testing.T) {
966+
// Given
967+
var logOutput strings.Builder
968+
slogLogger := slog.New(slog.NewTextHandler(&logOutput, &slog.HandlerOptions{
969+
Level: slog.LevelDebug,
970+
}))
971+
972+
// When
973+
_ = flagsmith.NewClient(fixtures.EnvironmentAPIKey, flagsmith.WithSlogLogger(slogLogger))
974+
975+
// Then
976+
logStr := logOutput.String()
977+
t.Log(logStr)
978+
assert.Contains(t, logStr, "initialising Flagsmith client")
979+
}

logger.go

Lines changed: 131 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,14 @@
11
package flagsmith
22

33
import (
4-
"log"
4+
"context"
5+
"fmt"
6+
"log/slog"
57
"os"
8+
"strings"
9+
"time"
10+
11+
"github.com/go-resty/resty/v2"
612
)
713

814
// Logger is the interface used for logging by flagsmith client. This interface defines the methods
@@ -19,33 +25,140 @@ type Logger interface {
1925
Debugf(format string, v ...interface{})
2026
}
2127

22-
func createLogger() *logger {
23-
l := &logger{l: log.New(os.Stderr, "", log.Ldate|log.Lmicroseconds)}
24-
return l
28+
// slogToRestyAdapter adapts a slog.Logger to resty.Logger.
29+
type slogToRestyAdapter struct {
30+
logger *slog.Logger
31+
}
32+
33+
func newSlogToRestyAdapter(logger *slog.Logger) *slogToRestyAdapter {
34+
return &slogToRestyAdapter{logger: logger}
35+
}
36+
37+
func (l *slogToRestyAdapter) Errorf(format string, v ...interface{}) {
38+
l.logger.Error(format, v...)
39+
}
40+
41+
func (l *slogToRestyAdapter) Warnf(format string, v ...interface{}) {
42+
l.logger.Warn(format, v...)
43+
}
44+
45+
func (l *slogToRestyAdapter) Debugf(format string, v ...interface{}) {
46+
l.logger.Debug(format, v...)
2547
}
2648

27-
var _ Logger = (*logger)(nil)
49+
// slogToLoggerAdapter adapts a slog.Logger to our Logger interface.
50+
type slogToLoggerAdapter struct {
51+
logger *slog.Logger
52+
}
53+
54+
func newSlogToLoggerAdapter(logger *slog.Logger) *slogToLoggerAdapter {
55+
return &slogToLoggerAdapter{logger: logger}
56+
}
57+
58+
func (l *slogToLoggerAdapter) Errorf(format string, v ...interface{}) {
59+
l.logger.Error(fmt.Sprintf(format, v...))
60+
}
2861

29-
type logger struct {
30-
l *log.Logger
62+
func (l *slogToLoggerAdapter) Warnf(format string, v ...interface{}) {
63+
l.logger.Warn(fmt.Sprintf(format, v...))
3164
}
3265

33-
func (l *logger) Errorf(format string, v ...interface{}) {
34-
l.output("ERROR FLAGSMITH: "+format, v...)
66+
func (l *slogToLoggerAdapter) Debugf(format string, v ...interface{}) {
67+
l.logger.Debug(fmt.Sprintf(format, v...))
3568
}
3669

37-
func (l *logger) Warnf(format string, v ...interface{}) {
38-
l.output("WARN FLAGSMITH: "+format, v...)
70+
// loggerToSlogAdapter adapts our Logger interface to a slog.Logger.
71+
type loggerToSlogAdapter struct {
72+
logger Logger
3973
}
4074

41-
func (l *logger) Debugf(format string, v ...interface{}) {
42-
l.output("DEBUG FLAGSMITH: "+format, v...)
75+
func newLoggerToSlogAdapter(logger Logger) *slog.Logger {
76+
return slog.New(&loggerToSlogAdapter{logger: logger})
4377
}
4478

45-
func (l *logger) output(format string, v ...interface{}) {
46-
if len(v) == 0 {
47-
l.l.Print(format)
48-
return
79+
// implement slog.Handler interface to adapt our Logger interface to a slog.Logger
80+
81+
func (l *loggerToSlogAdapter) Enabled(ctx context.Context, level slog.Level) bool {
82+
return true
83+
}
84+
85+
func (l *loggerToSlogAdapter) Handle(ctx context.Context, r slog.Record) error {
86+
msg := r.Message
87+
var attrs strings.Builder
88+
r.Attrs(func(a slog.Attr) bool {
89+
attrs.WriteString(a.String() + " ")
90+
return true
91+
})
92+
msg += attrs.String()
93+
94+
switch r.Level {
95+
case slog.LevelError:
96+
l.logger.Errorf(msg)
97+
case slog.LevelWarn:
98+
l.logger.Warnf(msg)
99+
case slog.LevelDebug:
100+
l.logger.Debugf(msg)
101+
}
102+
return nil
103+
}
104+
105+
func (l *loggerToSlogAdapter) WithAttrs(_ []slog.Attr) slog.Handler {
106+
return l
107+
}
108+
109+
func (l *loggerToSlogAdapter) WithGroup(_ string) slog.Handler {
110+
return l
111+
}
112+
113+
func createLogger() *slog.Logger {
114+
return slog.New(slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{
115+
Level: slog.LevelDebug,
116+
}))
117+
}
118+
119+
const (
120+
contextLoggerKey contextKey = contextKey("logger")
121+
contextStartTimeKey contextKey = contextKey("startTime")
122+
)
123+
124+
func newRestyLogRequestMiddleware(logger *slog.Logger) resty.RequestMiddleware {
125+
return func(c *resty.Client, req *resty.Request) error {
126+
// Create a child logger with request metadata
127+
reqLogger := logger.WithGroup("http").With(
128+
"method", req.Method,
129+
"url", req.URL,
130+
)
131+
reqLogger.Debug("request")
132+
133+
// Store the logger in this request's context, and use it in the response
134+
req.SetContext(context.WithValue(req.Context(), contextLoggerKey, reqLogger))
135+
136+
// Time the current request
137+
req.SetContext(context.WithValue(req.Context(), contextStartTimeKey, time.Now()))
138+
139+
return nil
140+
}
141+
}
142+
143+
func newRestyLogResponseMiddleware(logger *slog.Logger) resty.ResponseMiddleware {
144+
return func(client *resty.Client, resp *resty.Response) error {
145+
// Retrieve the logger and start time from context
146+
reqLogger, _ := resp.Request.Context().Value(contextLoggerKey).(*slog.Logger)
147+
startTime, _ := resp.Request.Context().Value(contextStartTimeKey).(time.Time)
148+
149+
if reqLogger == nil {
150+
reqLogger = logger
151+
}
152+
reqLogger = reqLogger.With(
153+
slog.Int("status", resp.StatusCode()),
154+
slog.Duration("duration", time.Since(startTime)),
155+
slog.Int64("content_length", resp.Size()),
156+
)
157+
if resp.IsError() {
158+
reqLogger.Error("error response")
159+
} else {
160+
reqLogger.Debug("response")
161+
}
162+
return nil
49163
}
50-
l.l.Printf(format, v...)
51164
}

options.go

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,8 @@ import (
44
"context"
55
"strings"
66
"time"
7+
8+
"log/slog"
79
)
810

911
type Option func(c *Client)
@@ -22,6 +24,8 @@ var _ = []Option{
2224
WithProxy(""),
2325
WithRealtime(),
2426
WithRealtimeBaseURL(""),
27+
WithLogger(nil),
28+
WithSlogLogger(nil),
2529
}
2630

2731
func WithBaseURL(url string) Option {
@@ -93,6 +97,13 @@ func WithDefaultHandler(handler func(string) (Flag, error)) Option {
9397

9498
// Allows the client to use any logger that implements the `Logger` interface.
9599
func WithLogger(logger Logger) Option {
100+
return func(c *Client) {
101+
c.log = newLoggerToSlogAdapter(logger)
102+
}
103+
}
104+
105+
// WithSlogLogger allows the client to use a slog.Logger for logging.
106+
func WithSlogLogger(logger *slog.Logger) Option {
96107
return func(c *Client) {
97108
c.log = logger
98109
}

realtime.go

Lines changed: 13 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ import (
55
"context"
66
"encoding/json"
77
"errors"
8+
"log/slog"
89
"net/http"
910
"strings"
1011
"time"
@@ -20,41 +21,48 @@ func (c *Client) startRealtimeUpdates(ctx context.Context) {
2021
env, _ := c.environment.Load().(*environments.EnvironmentModel)
2122
stream_url := c.config.realtimeBaseUrl + "sse/environments/" + env.APIKey + "/stream"
2223
envUpdatedAt := env.UpdatedAt
24+
log := c.log.With(
25+
slog.String("worker", "realtime"),
26+
slog.String("stream", stream_url),
27+
)
28+
defer func() {
29+
log.Info("realtime stopped")
30+
}()
2331
for {
2432
select {
2533
case <-ctx.Done():
2634
return
2735
default:
2836
resp, err := http.Get(stream_url)
2937
if err != nil {
30-
c.log.Errorf("Error connecting to realtime server: %v", err)
38+
log.Error("failed to connect to realtime stream", "error", err)
3139
continue
3240
}
3341
defer resp.Body.Close()
42+
log.Info("connected")
3443

3544
scanner := bufio.NewScanner(resp.Body)
3645
for scanner.Scan() {
3746
line := scanner.Text()
3847
if strings.HasPrefix(line, "data: ") {
3948
parsedTime, err := parseUpdatedAtFromSSE(line)
4049
if err != nil {
41-
c.log.Errorf("Error reading realtime stream: %v", err)
50+
log.Error("failed to parse event message", "error", err, "message", line)
4251
continue
4352
}
4453
if parsedTime.After(envUpdatedAt) {
4554
err = c.UpdateEnvironment(ctx)
4655
if err != nil {
47-
c.log.Errorf("Failed to update the environment: %v", err)
56+
log.Error("failed to update environment after receiving event", "error", err)
4857
continue
4958
}
5059
env, _ := c.environment.Load().(*environments.EnvironmentModel)
51-
5260
envUpdatedAt = env.UpdatedAt
5361
}
5462
}
5563
}
5664
if err := scanner.Err(); err != nil {
57-
c.log.Errorf("Error reading realtime stream: %v", err)
65+
log.Error("error reading from realtime stream", "error", err)
5866
}
5967
}
6068
}

0 commit comments

Comments
 (0)