Skip to content
Closed
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
5 changes: 4 additions & 1 deletion docs/src/content/docs/packages/log.mdx
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ Core Components:
- `WideEventLogger`: Writes finalized `Event` values through a `Sampler` and can also be installed as the package default logger for `Debug`/`Info`/`Warn`/`Error` calls.
- `WideEventMiddleware`: Creates request-wide events, stores them in context, and emits them after handlers finish.
- `Sampler`, `SamplerFunc`, `DefaultSampler`: Tail-sampling rules for keeping errors, slow requests, selected status codes, and random samples.
- `LevelInfoForced`: Marks an otherwise-successful event as always-retained while still rendering its severity as `INFO`.
- `EventFromContext`: Fetches the current request-wide event from context using `WideEventKey`.

[Full package docs at pkg.go.dev](https://pkg.go.dev/github.com/platforma-dev/platforma/log)
Expand Down Expand Up @@ -62,7 +63,9 @@ Core Components:
log.SetDefault(wideLogger)
```

In that mode, `log.Info(...)` and related calls emit a short-lived event that still goes through the configured sampler, just like explicit wide events created via middleware or `WriteEvent(...)`.
In that mode, `Debug`/`Info`/`Warn`/`Error` calls emit short-lived events through the same wide-event pipeline. `Info(...)` uses `log.LevelInfoForced`, so explicit info logs are retained while still rendering as `INFO`.

When a specific request-wide event must always be retained even though it is not slow and has no errors, set its level to `log.LevelInfoForced`. `DefaultSampler` treats that level as always-keep, but the emitted log line still shows `INFO`.

4. Enrich events and logs inside handlers

Expand Down
2 changes: 1 addition & 1 deletion log/event.go
Original file line number Diff line number Diff line change
Expand Up @@ -147,7 +147,7 @@ func (e *Event) toAttrs(additionalReservedAttrKeys []string) []slog.Attr {
for _, step := range e.steps {
steps = append(steps, map[string]any{
"timestamp": step.Timestamp,
"level": step.Level.String(),
"level": formatLevel(step.Level),
"name": step.Name,
})
}
Expand Down
156 changes: 156 additions & 0 deletions log/forced_level_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,156 @@
package log_test

import (
"bytes"
"context"
"encoding/json"
"log/slog"
"testing"
"time"

platformalog "github.com/platforma-dev/platforma/log"
)

func TestDefaultSamplerForcedInfoLevel(t *testing.T) {
t.Parallel()

sampler := platformalog.NewDefaultSampler(time.Hour, 500, 0)

t.Run("forced info is always sampled", func(t *testing.T) {
t.Parallel()

event := platformalog.NewEvent("background.job")
event.SetLevel(platformalog.LevelInfoForced)

if !sampler.ShouldSample(context.Background(), event) {
t.Fatal("expected forced info event to be sampled")
}
})

t.Run("regular info still depends on sampler rules", func(t *testing.T) {
t.Parallel()

event := platformalog.NewEvent("background.job")
event.SetLevel(slog.LevelInfo)

if sampler.ShouldSample(context.Background(), event) {
t.Fatal("expected regular info event to be dropped when no sampler rule matches")
}
})
}

func TestEventToAttrsFormatsForcedInfoStep(t *testing.T) {
t.Parallel()

event := platformalog.NewEvent("background.job")
event.AddStep(platformalog.LevelInfoForced, "marked for retention")

attrs := event.ToAttrs()

for _, attr := range attrs {
if attr.Key != "steps" {
continue
}

steps, ok := attr.Value.Any().([]map[string]any)
if !ok {
t.Fatalf("expected steps attr to be []map[string]any, got %T", attr.Value.Any())
}

if len(steps) != 1 {
t.Fatalf("expected 1 step, got %d", len(steps))
}

level, ok := steps[0]["level"].(string)
if !ok {
t.Fatalf("expected step level to be string, got %T", steps[0]["level"])
}

if level != "INFO" {
t.Fatalf("expected forced info step level to render as INFO, got %q", level)
}

return
}

t.Fatal("expected steps attr to be present")
}

func TestWideEventLoggerRendersForcedInfoLevelAsInfo(t *testing.T) {
t.Parallel()

var buf bytes.Buffer
logger := platformalog.NewWideEventLogger(&buf, platformalog.SamplerFunc(func(_ context.Context, _ *platformalog.Event) bool {
return true
}), "json", nil)

event := platformalog.NewEvent("background.job")
event.SetLevel(platformalog.LevelInfoForced)

logger.WriteEvent(context.Background(), event)

var payload map[string]any
if err := json.Unmarshal(buf.Bytes(), &payload); err != nil {
t.Fatalf("unmarshal log output: %v", err)
}

level, ok := payload["level"].(string)
if !ok {
t.Fatalf("expected level field to be string, got %T", payload["level"])
}

if level != "INFO" {
t.Fatalf("expected forced info event to render as INFO, got %q", level)
}
}

func TestWideEventLoggerInfoContextUsesForcedInfoLevel(t *testing.T) {
t.Parallel()

var buf bytes.Buffer
logger := platformalog.NewWideEventLogger(
&buf,
platformalog.NewDefaultSampler(time.Hour, 500, 0),
"json",
nil,
)

logger.InfoContext(context.Background(), "forced info")

var payload map[string]any
if err := json.Unmarshal(buf.Bytes(), &payload); err != nil {
t.Fatalf("unmarshal log output: %v", err)
}

level, ok := payload["level"].(string)
if !ok {
t.Fatalf("expected level field to be string, got %T", payload["level"])
}

if level != "INFO" {
t.Fatalf("expected forced info log to render as INFO, got %q", level)
}
}

func TestNewLoggerRendersForcedInfoLevelAsInfo(t *testing.T) {
t.Parallel()

var buf bytes.Buffer
logger := platformalog.New(&buf, "json", slog.LevelDebug, nil)

logger.Log(context.Background(), platformalog.LevelInfoForced, "forced info")

var payload map[string]any
if err := json.Unmarshal(buf.Bytes(), &payload); err != nil {
t.Fatalf("unmarshal log output: %v", err)
}

level, ok := payload["level"].(string)
if !ok {
t.Fatalf("expected level field to be string, got %T", payload["level"])
}

if level != "INFO" {
t.Fatalf("expected forced info log to render as INFO, got %q", level)
}
}
27 changes: 27 additions & 0 deletions log/level.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
package log

import "log/slog"

const (
// LevelInfoForced keeps an event regardless of tail-sampling rules while rendering as INFO in output.
LevelInfoForced slog.Level = slog.LevelInfo + 1
)

func formatLevel(level slog.Level) string {
if level == LevelInfoForced {
return slog.LevelInfo.String()
}

return level.String()
}

func replaceLevelAttr(a slog.Attr) slog.Attr {
switch level := a.Value.Any().(type) {
case slog.Level:
return slog.String(a.Key, formatLevel(level))
case slog.Leveler:
return slog.String(a.Key, formatLevel(level.Level()))
default:
return a
}
}
15 changes: 13 additions & 2 deletions log/log.go
Original file line number Diff line number Diff line change
Expand Up @@ -83,11 +83,22 @@ func (h *contextHandler) Handle(ctx context.Context, r slog.Record) error {

// New creates a new slog.Logger with the specified type (json/text), log level, and additional context keys to include.
func New(w io.Writer, loggerType string, level slog.Level, contextKeys map[string]any) *slog.Logger {
opts := &slog.HandlerOptions{
Level: level,
ReplaceAttr: func(_ []string, a slog.Attr) slog.Attr {
if a.Key == slog.LevelKey {
return replaceLevelAttr(a)
}

return a
},
}

if loggerType == "json" {
return slog.New(&contextHandler{slog.NewJSONHandler(w, &slog.HandlerOptions{Level: level}), contextKeys})
return slog.New(&contextHandler{slog.NewJSONHandler(w, opts), contextKeys})
}

return slog.New(&contextHandler{slog.NewTextHandler(w, &slog.HandlerOptions{Level: level}), contextKeys})
return slog.New(&contextHandler{slog.NewTextHandler(w, opts), contextKeys})
}

// Debug logs a message at Debug level.
Expand Down
4 changes: 4 additions & 0 deletions log/sampler.go
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,10 @@ func NewDefaultSampler(slowThreshold time.Duration, keepHTTPStatusAtLeast int, r

// ShouldSample decides if event should be logged.
func (s *DefaultSampler) ShouldSample(_ context.Context, e *Event) bool {
if e.Level() >= LevelInfoForced {
return true
}

if e.HasErrors() {
return true
}
Expand Down
6 changes: 5 additions & 1 deletion log/wideevent_logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,10 @@ func NewWideEventLogger(w io.Writer, s Sampler, loggerType string, contextKeys m
opts := &slog.HandlerOptions{
Level: slog.LevelDebug,
ReplaceAttr: func(_ []string, a slog.Attr) slog.Attr {
if a.Key == slog.LevelKey {
return replaceLevelAttr(a)
}

if a.Key == slog.TimeKey {
return slog.Attr{}
}
Expand Down Expand Up @@ -82,7 +86,7 @@ func (l *WideEventLogger) DebugContext(ctx context.Context, msg string, args ...

// InfoContext logs a message at Info level with context.
func (l *WideEventLogger) InfoContext(ctx context.Context, msg string, args ...any) {
l.writeSimpleLog(ctx, slog.LevelInfo, msg, args...)
l.writeSimpleLog(ctx, LevelInfoForced, msg, args...)
}

// WarnContext logs a message at Warn level with context.
Expand Down
Loading