From 7c7b314b196680bc2fff8c4d446b41f9bacaa7b8 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Sat, 14 Feb 2026 22:05:51 +0300 Subject: [PATCH 01/38] log2 first iteration --- log2/config.go | 42 ++++ log2/context.go | 27 +++ log2/context_test.go | 92 +++++++++ log2/event.go | 373 +++++++++++++++++++++++++++++++++++ log2/event_test.go | 197 ++++++++++++++++++ log2/http_middleware.go | 99 ++++++++++ log2/http_middleware_test.go | 140 +++++++++++++ log2/logger.go | 123 ++++++++++++ log2/sampling.go | 204 +++++++++++++++++++ log2/sampling_test.go | 166 ++++++++++++++++ log2/test_helpers_test.go | 70 +++++++ 11 files changed, 1533 insertions(+) create mode 100644 log2/config.go create mode 100644 log2/context.go create mode 100644 log2/context_test.go create mode 100644 log2/event.go create mode 100644 log2/event_test.go create mode 100644 log2/http_middleware.go create mode 100644 log2/http_middleware_test.go create mode 100644 log2/logger.go create mode 100644 log2/sampling.go create mode 100644 log2/sampling_test.go create mode 100644 log2/test_helpers_test.go diff --git a/log2/config.go b/log2/config.go new file mode 100644 index 0000000..928449f --- /dev/null +++ b/log2/config.go @@ -0,0 +1,42 @@ +// Package log2 provides wide-event logging with tail sampling. +package log2 + +import ( + "io" + "log/slog" + "os" + "time" +) + +const ( + defaultFormat = "json" + defaultKeepStatus = 500 + defaultMaxSteps = 100 + defaultRandomKeepRate = 0.05 + defaultSlowThreshold = 2 * time.Second +) + +// Config configures logger behavior. +type Config struct { + Writer io.Writer + Format string + Level slog.Level + ContextKeys map[string]any + Sampler TailSampler + MaxSteps int +} + +// DefaultConfig returns default logger configuration. +func DefaultConfig() Config { + return Config{ + Writer: os.Stdout, + Format: defaultFormat, + Level: slog.LevelInfo, + Sampler: NewDefaultTailSampler(DefaultTailSamplerConfig{ + SlowThreshold: defaultSlowThreshold, + RandomKeepRate: defaultRandomKeepRate, + KeepStatusAtLeast: defaultKeepStatus, + }), + MaxSteps: defaultMaxSteps, + } +} diff --git a/log2/context.go b/log2/context.go new file mode 100644 index 0000000..a704ac6 --- /dev/null +++ b/log2/context.go @@ -0,0 +1,27 @@ +package log2 + +import "context" + +type contextKey string + +// LogEventContextKey is used to store Event in context. +var LogEventContextKey any = contextKey("platformaLog2Event") //nolint:gochecknoglobals + +// EventFromContext gets an event from context. +func EventFromContext(ctx context.Context) (*Event, bool) { + if ctx == nil { + return nil, false + } + + ev, ok := ctx.Value(LogEventContextKey).(*Event) + if !ok || ev == nil { + return nil, false + } + + return ev, true +} + +// WithEvent stores an event in context. +func WithEvent(ctx context.Context, ev *Event) context.Context { + return context.WithValue(ctx, LogEventContextKey, ev) +} diff --git a/log2/context_test.go b/log2/context_test.go new file mode 100644 index 0000000..2bc2f74 --- /dev/null +++ b/log2/context_test.go @@ -0,0 +1,92 @@ +package log2_test + +import ( + "bytes" + "context" + "log/slog" + "testing" + + "github.com/platforma-dev/platforma/log" + "github.com/platforma-dev/platforma/log2" +) + +func TestEventFromContextMiss(t *testing.T) { + t.Parallel() + + ev, ok := log2.EventFromContext(context.Background()) + if ok { + t.Fatalf("expected ok=false, got true with event=%v", ev) + } + if ev != nil { + t.Fatalf("expected nil event, got %v", ev) + } +} + +func TestEventFromContextWithRawContextValue(t *testing.T) { + t.Parallel() + + logger := log2.New(log2.Config{Writer: &bytes.Buffer{}}) + ev := logger.Start(context.Background(), "ctx") + + ctx := context.WithValue(context.Background(), log2.LogEventContextKey, ev) + got, ok := log2.EventFromContext(ctx) + if !ok { + t.Fatalf("expected ok=true") + } + if got != ev { + t.Fatalf("expected the same event pointer") + } +} + +func TestWithEvent(t *testing.T) { + t.Parallel() + + logger := log2.New(log2.Config{Writer: &bytes.Buffer{}}) + ev := logger.Start(context.Background(), "ctx") + + ctx := log2.WithEvent(context.Background(), ev) + got, ok := log2.EventFromContext(ctx) + if !ok { + t.Fatalf("expected ok=true") + } + if got != ev { + t.Fatalf("expected the same event pointer") + } +} + +func TestStartCollectsDefaultContextKeys(t *testing.T) { + t.Parallel() + + buffer := &bytes.Buffer{} + logger := log2.New(log2.Config{ + Writer: buffer, + Format: "json", + Level: slog.LevelInfo, + Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), + }) + + ctx := context.WithValue(context.Background(), log.TraceIDKey, "trace-123") + ctx = context.WithValue(ctx, log.UserIDKey, "user-99") + + ev := logger.Start(ctx, "collect-keys") + if err := ev.Finish(); err != nil { + t.Fatalf("Finish() returned error: %v", err) + } + + events := readEvents(t, buffer) + if len(events) != 1 { + t.Fatalf("expected 1 event, got %d", len(events)) + } + + if events[0]["traceId"] != "trace-123" { + t.Fatalf("expected top-level traceId=trace-123, got %v", events[0]["traceId"]) + } + + attrs := requireMap(t, events[0], "attrs") + if attrs["traceId"] != "trace-123" { + t.Fatalf("expected attrs.traceId=trace-123, got %v", attrs["traceId"]) + } + if attrs["userId"] != "user-99" { + t.Fatalf("expected attrs.userId=user-99, got %v", attrs["userId"]) + } +} diff --git a/log2/event.go b/log2/event.go new file mode 100644 index 0000000..c0d4f14 --- /dev/null +++ b/log2/event.go @@ -0,0 +1,373 @@ +package log2 + +import ( + "context" + "errors" + "fmt" + "log/slog" + "math" + "strconv" + "sync" + "time" + + "github.com/platforma-dev/platforma/log" +) + +// ErrEventAlreadyFinished means Finish was called more than once. +var ErrEventAlreadyFinished = errors.New("event already finished") + +type stepRecord struct { + ts time.Time + level string + msg string + attrs map[string]any +} + +type errorRecord struct { + ts time.Time + err string + attrs map[string]any +} + +type eventPayload struct { + eventName string + level slog.Level + durationMs int64 + sampled bool + samplingReason string + traceID string + attrs map[string]any + steps []map[string]any + errors []map[string]any + stepsDropped int +} + +// Event is a mutable wide event. +type Event struct { + mu sync.Mutex + + logger *Logger + eventName string + startedAt time.Time + + attrs map[string]any + steps []stepRecord + errors []errorRecord + hasError bool + finished bool + stepsDropped int +} + +// Add adds persistent attributes to the event. +func (e *Event) Add(attrs ...any) { + if e == nil { + return + } + + normalized := normalizeAttrs(attrs...) + + e.mu.Lock() + defer e.mu.Unlock() + + if e.finished { + return + } + + mergeAttrs(e.attrs, normalized) +} + +// Step appends a timeline step to the event. +func (e *Event) Step(level slog.Level, msg string, attrs ...any) { + if e == nil { + return + } + + e.mu.Lock() + defer e.mu.Unlock() + + if e.finished { + return + } + + if len(e.steps) >= e.logger.maxSteps { + e.stepsDropped++ + return + } + + e.steps = append(e.steps, stepRecord{ + ts: nowUTC(), + level: level.String(), + msg: msg, + attrs: normalizeAttrs(attrs...), + }) +} + +// Error appends an error to the event. +func (e *Event) Error(err error, attrs ...any) { + if e == nil || err == nil { + return + } + + e.mu.Lock() + defer e.mu.Unlock() + + if e.finished { + return + } + + e.hasError = true + e.errors = append(e.errors, errorRecord{ + ts: nowUTC(), + err: err.Error(), + attrs: normalizeAttrs(attrs...), + }) +} + +// Finish finalizes and emits the event depending on sampling decision. +func (e *Event) Finish(attrs ...any) error { + if e == nil { + return nil + } + + e.mu.Lock() + if e.finished { + e.mu.Unlock() + return ErrEventAlreadyFinished + } + + mergeAttrs(e.attrs, normalizeAttrs(attrs...)) + + duration := nowUTC().Sub(e.startedAt) + status := inferStatus(e.attrs) + level := inferLevel(status, e.hasError) + attrsCopy := copyAttrs(e.attrs) + stepsCopy := copySteps(e.steps) + errorsCopy := copyErrors(e.errors) + stepsDropped := e.stepsDropped + traceID := extractString(attrsCopy, string(log.TraceIDKey)) + + decision := e.logger.sampler.ShouldSample(EventView{ + Status: status, + Duration: duration, + HasError: e.hasError, + Attrs: attrsCopy, + }) + + e.finished = true + logger := e.logger + e.mu.Unlock() + + if !decision.Keep { + return nil + } + + return logger.emit(context.Background(), eventPayload{ + eventName: e.eventName, + level: level, + durationMs: duration.Milliseconds(), + sampled: true, + samplingReason: decision.Reason, + traceID: traceID, + attrs: attrsCopy, + steps: stepsCopy, + errors: errorsCopy, + stepsDropped: stepsDropped, + }) +} + +func nowUTC() time.Time { + return time.Now().UTC() +} + +func collectContextAttrs(ctx context.Context, extraKeys map[string]any) map[string]any { + attrs := map[string]any{} + + defaultKeys := []struct { + name string + key any + }{ + {name: string(log.DomainNameKey), key: log.DomainNameKey}, + {name: string(log.TraceIDKey), key: log.TraceIDKey}, + {name: string(log.ServiceNameKey), key: log.ServiceNameKey}, + {name: string(log.StartupTaskKey), key: log.StartupTaskKey}, + {name: string(log.UserIDKey), key: log.UserIDKey}, + {name: string(log.WorkerIDKey), key: log.WorkerIDKey}, + } + + for _, item := range defaultKeys { + if value := ctx.Value(item.key); value != nil { + attrs[item.name] = value + } + } + + for outputKey, ctxKey := range extraKeys { + if value := ctx.Value(ctxKey); value != nil { + attrs[outputKey] = value + } + } + + return attrs +} + +func normalizeAttrs(attrs ...any) map[string]any { + normalized := make(map[string]any, len(attrs)/2) + + for i := 0; i < len(attrs); i++ { + if attr, ok := attrs[i].(slog.Attr); ok { + normalized[attr.Key] = attr.Value.Any() + continue + } + + if i+1 >= len(attrs) { + break + } + + key := fmt.Sprint(attrs[i]) + normalized[key] = attrs[i+1] + i++ + } + + return normalized +} + +func mergeAttrs(dst map[string]any, src map[string]any) { + for key, value := range src { + dst[key] = value + } +} + +func copyAttrs(src map[string]any) map[string]any { + if src == nil { + return nil + } + + dst := make(map[string]any, len(src)) + for key, value := range src { + dst[key] = value + } + + return dst +} + +func copySteps(src []stepRecord) []map[string]any { + steps := make([]map[string]any, 0, len(src)) + for _, step := range src { + entry := map[string]any{ + "ts": step.ts, + "level": step.level, + "msg": step.msg, + } + mergeAttrs(entry, step.attrs) + steps = append(steps, entry) + } + + return steps +} + +func copyErrors(src []errorRecord) []map[string]any { + errs := make([]map[string]any, 0, len(src)) + for _, item := range src { + entry := map[string]any{ + "ts": item.ts, + "error": item.err, + } + mergeAttrs(entry, item.attrs) + errs = append(errs, entry) + } + + return errs +} + +func inferLevel(status int, hasError bool) slog.Level { + if hasError || status >= defaultKeepStatus { + return slog.LevelError + } + + if status >= 400 { + return slog.LevelWarn + } + + return slog.LevelInfo +} + +func inferStatus(attrs map[string]any) int { + if status, ok := toInt(attrs["status"]); ok { + return status + } + + if status, ok := toInt(attrs["statusCode"]); ok { + return status + } + + if status, ok := toInt(attrs["response.status"]); ok { + return status + } + + if responseAny, ok := attrs["response"]; ok { + if response, okMap := responseAny.(map[string]any); okMap { + if status, okStatus := toInt(response["status"]); okStatus { + return status + } + } + } + + return 0 +} + +func toInt(value any) (int, bool) { + switch typed := value.(type) { + case int: + return typed, true + case int8: + return int(typed), true + case int16: + return int(typed), true + case int32: + return int(typed), true + case int64: + return int(typed), true + case uint: + if typed > uint(math.MaxInt) { + return 0, false + } + return int(typed), true + case uint8: + return int(typed), true + case uint16: + return int(typed), true + case uint32: + return int(typed), true + case uint64: + if typed > uint64(math.MaxInt) { + return 0, false + } + return int(typed), true + case float32: + return int(typed), true + case float64: + return int(typed), true + case string: + parsed, err := strconv.Atoi(typed) + if err != nil { + return 0, false + } + + return parsed, true + default: + return 0, false + } +} + +func extractString(attrs map[string]any, key string) string { + value, ok := attrs[key] + if !ok { + return "" + } + + stringValue, ok := value.(string) + if !ok { + return "" + } + + return stringValue +} diff --git a/log2/event_test.go b/log2/event_test.go new file mode 100644 index 0000000..fbff343 --- /dev/null +++ b/log2/event_test.go @@ -0,0 +1,197 @@ +package log2_test + +import ( + "bytes" + "context" + "errors" + "log/slog" + "sync" + "testing" + + "github.com/platforma-dev/platforma/log2" +) + +func TestEventLifecycle(t *testing.T) { + t.Parallel() + + buffer := &bytes.Buffer{} + logger := log2.New(log2.Config{ + Writer: buffer, + Format: "json", + Level: slog.LevelDebug, + Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), + MaxSteps: 10, + }) + + ev := logger.Start(context.Background(), "auth_request", "component", "handler") + ev.Add("userId", "u-1", "attempt", 2) + ev.Step(slog.LevelInfo, "request accepted") + ev.Error(errors.New("boom"), "phase", "validation") + + if err := ev.Finish("status", 500); err != nil { + t.Fatalf("Finish() returned error: %v", err) + } + + events := readEvents(t, buffer) + if len(events) != 1 { + t.Fatalf("expected 1 emitted event, got %d", len(events)) + } + + event := events[0] + if event["event"] != "auth_request" { + t.Fatalf("expected event name auth_request, got %v", event["event"]) + } + if event["samplingReason"] != "forced" { + t.Fatalf("expected sampling reason forced, got %v", event["samplingReason"]) + } + if event["sampled"] != true { + t.Fatalf("expected sampled=true, got %v", event["sampled"]) + } + + attrs := requireMap(t, event, "attrs") + if attrs["component"] != "handler" { + t.Fatalf("expected component=handler, got %v", attrs["component"]) + } + if attrs["userId"] != "u-1" { + t.Fatalf("expected userId=u-1, got %v", attrs["userId"]) + } + if attrs["attempt"] != float64(2) { + t.Fatalf("expected attempt=2, got %v", attrs["attempt"]) + } + if attrs["status"] != float64(500) { + t.Fatalf("expected status=500, got %v", attrs["status"]) + } + + steps := requireSlice(t, event, "steps") + if len(steps) != 1 { + t.Fatalf("expected 1 step, got %d", len(steps)) + } + + errorsList := requireSlice(t, event, "errors") + if len(errorsList) != 1 { + t.Fatalf("expected 1 error, got %d", len(errorsList)) + } +} + +func TestEventAttributeOverwrite(t *testing.T) { + t.Parallel() + + buffer := &bytes.Buffer{} + logger := log2.New(log2.Config{ + Writer: buffer, + Format: "json", + Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), + }) + + ev := logger.Start(context.Background(), "overwrite") + ev.Add("key", "first") + ev.Add("key", "second") + + if err := ev.Finish(); err != nil { + t.Fatalf("Finish() returned error: %v", err) + } + + events := readEvents(t, buffer) + if len(events) != 1 { + t.Fatalf("expected 1 event, got %d", len(events)) + } + + attrs := requireMap(t, events[0], "attrs") + if attrs["key"] != "second" { + t.Fatalf("expected key=second, got %v", attrs["key"]) + } +} + +func TestEventFinishCalledTwice(t *testing.T) { + t.Parallel() + + logger := log2.New(log2.Config{ + Writer: &bytes.Buffer{}, + Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), + }) + + ev := logger.Start(context.Background(), "double_finish") + if err := ev.Finish(); err != nil { + t.Fatalf("first Finish() returned error: %v", err) + } + + err := ev.Finish() + if !errors.Is(err, log2.ErrEventAlreadyFinished) { + t.Fatalf("expected ErrEventAlreadyFinished, got %v", err) + } +} + +func TestEventConcurrentAccessAndStepCap(t *testing.T) { + t.Parallel() + + buffer := &bytes.Buffer{} + logger := log2.New(log2.Config{ + Writer: buffer, + Format: "json", + Level: slog.LevelDebug, + Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), + MaxSteps: 5, + }) + + ev := logger.Start(context.Background(), "concurrent") + + var wg sync.WaitGroup + for i := range 20 { + wg.Add(1) + go func(i int) { + defer wg.Done() + ev.Add("counter", i) + ev.Step(slog.LevelInfo, "work", "i", i) + if i%3 == 0 { + ev.Error(errors.New("worker-error"), "i", i) + } + }(i) + } + + wg.Wait() + + if err := ev.Finish("status", 200); err != nil { + t.Fatalf("Finish() returned error: %v", err) + } + + events := readEvents(t, buffer) + if len(events) != 1 { + t.Fatalf("expected 1 event, got %d", len(events)) + } + + event := events[0] + steps := requireSlice(t, event, "steps") + if len(steps) != 5 { + t.Fatalf("expected 5 steps (cap), got %d", len(steps)) + } + + dropped, ok := event["stepsDropped"].(float64) + if !ok { + t.Fatalf("expected stepsDropped to exist") + } + if dropped != float64(15) { + t.Fatalf("expected stepsDropped=15, got %v", dropped) + } +} + +func TestEventDroppedBySampler(t *testing.T) { + t.Parallel() + + buffer := &bytes.Buffer{} + logger := log2.New(log2.Config{ + Writer: buffer, + Format: "json", + Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: false, Reason: "drop"} }), + }) + + ev := logger.Start(context.Background(), "drop_me") + ev.Add("k", "v") + if err := ev.Finish(); err != nil { + t.Fatalf("Finish() returned error: %v", err) + } + + events := readEvents(t, buffer) + if len(events) != 0 { + t.Fatalf("expected no emitted events, got %d", len(events)) + } +} diff --git a/log2/http_middleware.go b/log2/http_middleware.go new file mode 100644 index 0000000..a47624a --- /dev/null +++ b/log2/http_middleware.go @@ -0,0 +1,99 @@ +package log2 + +import ( + "errors" + "fmt" + "net/http" +) + +var errPanicRecovered = errors.New("panic recovered") //nolint:gochecknoglobals + +// HTTPMiddlewareConfig configures wide-event HTTP middleware. +type HTTPMiddlewareConfig struct { + EventName string + RouteAttr string +} + +// NewHTTPMiddleware creates middleware that builds one wide event per request. +func NewHTTPMiddleware(l *Logger, cfg HTTPMiddlewareConfig) func(http.Handler) http.Handler { + logger := l + if logger == nil { + logger = Default + } + + eventName := cfg.EventName + if eventName == "" { + eventName = "http_request" + } + + routeAttr := cfg.RouteAttr + if routeAttr == "" { + routeAttr = "route" + } + + return func(next http.Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + ev := logger.Start(r.Context(), eventName) + ctx := WithEvent(r.Context(), ev) + r = r.WithContext(ctx) + + rec := &statusRecorder{ResponseWriter: w, status: http.StatusOK} + + defer func() { + panicValue := recover() + + route := r.Pattern + if route == "" { + route = r.URL.Path + } + + requestAttrs := map[string]any{ + "method": r.Method, + "path": r.URL.Path, + "route": route, + "remoteAddr": r.RemoteAddr, + } + responseAttrs := map[string]any{ + "status": rec.status, + "bytes": rec.bytes, + } + + ev.Add( + "request", requestAttrs, + "response", responseAttrs, + routeAttr, route, + ) + + if panicValue != nil { + ev.Error(fmt.Errorf("%w: %v", errPanicRecovered, panicValue)) + } + + _ = ev.Finish("status", rec.status) + + if panicValue != nil { + panic(panicValue) + } + }() + + next.ServeHTTP(rec, r) + }) + } +} + +type statusRecorder struct { + http.ResponseWriter + status int + bytes int +} + +func (r *statusRecorder) WriteHeader(statusCode int) { + r.status = statusCode + r.ResponseWriter.WriteHeader(statusCode) +} + +func (r *statusRecorder) Write(body []byte) (int, error) { + bytesWritten, err := r.ResponseWriter.Write(body) + r.bytes += bytesWritten + //nolint:wrapcheck // preserve exact error semantics from wrapped ResponseWriter. + return bytesWritten, err +} diff --git a/log2/http_middleware_test.go b/log2/http_middleware_test.go new file mode 100644 index 0000000..a881a23 --- /dev/null +++ b/log2/http_middleware_test.go @@ -0,0 +1,140 @@ +package log2_test + +import ( + "bytes" + "fmt" + "log/slog" + "net/http" + "net/http/httptest" + "strings" + "testing" + + "github.com/platforma-dev/platforma/log2" +) + +func TestHTTPMiddlewareEmitsSingleWideEvent(t *testing.T) { + t.Parallel() + + buffer := &bytes.Buffer{} + logger := log2.New(log2.Config{ + Writer: buffer, + Format: "json", + Level: slog.LevelInfo, + Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), + }) + + middleware := log2.NewHTTPMiddleware(logger, log2.HTTPMiddlewareConfig{}) + handler := middleware(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + ev, ok := log2.EventFromContext(r.Context()) + if !ok { + t.Fatalf("expected event in request context") + } + ev.Add("handler", "users") + + w.WriteHeader(http.StatusTeapot) + _, _ = w.Write([]byte("hello")) + })) + + req := httptest.NewRequest(http.MethodGet, "/users/42", nil) + rec := httptest.NewRecorder() + handler.ServeHTTP(rec, req) + + events := readEvents(t, buffer) + if len(events) != 1 { + t.Fatalf("expected 1 event, got %d", len(events)) + } + + event := events[0] + if event["event"] != "http_request" { + t.Fatalf("expected event=http_request, got %v", event["event"]) + } + + attrs := requireMap(t, event, "attrs") + if attrs["status"] != float64(http.StatusTeapot) { + t.Fatalf("expected status %d, got %v", http.StatusTeapot, attrs["status"]) + } + if attrs["route"] != "/users/42" { + t.Fatalf("expected fallback route /users/42, got %v", attrs["route"]) + } + + request := requireMap(t, attrs, "request") + if request["method"] != http.MethodGet { + t.Fatalf("expected method GET, got %v", request["method"]) + } + if request["path"] != "/users/42" { + t.Fatalf("expected path /users/42, got %v", request["path"]) + } + + response := requireMap(t, attrs, "response") + if response["status"] != float64(http.StatusTeapot) { + t.Fatalf("expected response.status=%d, got %v", http.StatusTeapot, response["status"]) + } + if response["bytes"] != float64(5) { + t.Fatalf("expected response.bytes=5, got %v", response["bytes"]) + } +} + +func TestHTTPMiddlewarePanicPath(t *testing.T) { + t.Parallel() + + buffer := &bytes.Buffer{} + logger := log2.New(log2.Config{ + Writer: buffer, + Format: "json", + Level: slog.LevelInfo, + Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), + }) + + middleware := log2.NewHTTPMiddleware(logger, log2.HTTPMiddlewareConfig{}) + handler := middleware(http.HandlerFunc(func(http.ResponseWriter, *http.Request) { + panic("boom") + })) + + req := httptest.NewRequest(http.MethodGet, "/panic", nil) + rec := httptest.NewRecorder() + + panicRecovered := false + func() { + defer func() { + if recovered := recover(); recovered != nil { + panicRecovered = true + if fmt.Sprint(recovered) != "boom" { + t.Fatalf("expected panic value boom, got %v", recovered) + } + } + }() + handler.ServeHTTP(rec, req) + }() + + if !panicRecovered { + t.Fatalf("expected panic to be rethrown by middleware") + } + + events := readEvents(t, buffer) + if len(events) != 1 { + t.Fatalf("expected 1 event, got %d", len(events)) + } + + event := events[0] + if event["level"] != "ERROR" { + t.Fatalf("expected level ERROR for panic path, got %v", event["level"]) + } + + errorsList := requireSlice(t, event, "errors") + if len(errorsList) != 1 { + t.Fatalf("expected exactly 1 recorded error, got %d", len(errorsList)) + } + + errorMap, ok := errorsList[0].(map[string]any) + if !ok { + t.Fatalf("expected errors[0] to be map, got %T", errorsList[0]) + } + + errorText, ok := errorMap["error"].(string) + if !ok { + t.Fatalf("expected errors[0].error string, got %T", errorMap["error"]) + } + if !strings.Contains(errorText, "panic recovered: boom") { + t.Fatalf("expected panic error text to include panic recovered: boom, got %q", errorText) + } +} diff --git a/log2/logger.go b/log2/logger.go new file mode 100644 index 0000000..f6fc6f9 --- /dev/null +++ b/log2/logger.go @@ -0,0 +1,123 @@ +package log2 + +import ( + "context" + "fmt" + "io" + "log/slog" +) + +// Logger writes sampled wide events. +type Logger struct { + handler slog.Handler + sampler TailSampler + contextKeys map[string]any + maxSteps int +} + +// Default is package-level default logger. +var Default = New(DefaultConfig()) //nolint:gochecknoglobals + +// New creates a new wide-event logger. +func New(cfg Config) *Logger { + writer := cfg.Writer + if writer == nil { + writer = io.Discard + } + + var handler slog.Handler + if cfg.Format == "text" { + handler = slog.NewTextHandler(writer, &slog.HandlerOptions{Level: cfg.Level}) + } else { + handler = slog.NewJSONHandler(writer, &slog.HandlerOptions{Level: cfg.Level}) + } + + sampler := cfg.Sampler + if sampler == nil { + sampler = NewDefaultTailSampler(DefaultTailSamplerConfig{}) + } + + maxSteps := cfg.MaxSteps + if maxSteps <= 0 { + maxSteps = defaultMaxSteps + } + + return &Logger{ + handler: handler, + sampler: sampler, + contextKeys: copyAttrs(cfg.ContextKeys), + maxSteps: maxSteps, + } +} + +// SetDefault sets the package-level default logger. +func SetDefault(l *Logger) { + if l == nil { + Default = New(DefaultConfig()) + return + } + + Default = l +} + +// Start creates a new event using the package-level default logger. +func Start(ctx context.Context, eventName string, attrs ...any) *Event { + return Default.Start(ctx, eventName, attrs...) +} + +// Start creates a new event using this logger. +func (l *Logger) Start(ctx context.Context, eventName string, attrs ...any) *Event { + if l == nil { + return Default.Start(ctx, eventName, attrs...) + } + + baseAttrs := collectContextAttrs(ctx, l.contextKeys) + mergeAttrs(baseAttrs, normalizeAttrs(attrs...)) + + return &Event{ + logger: l, + eventName: eventName, + startedAt: nowUTC(), + attrs: baseAttrs, + steps: make([]stepRecord, 0), + errors: make([]errorRecord, 0), + } +} + +func (l *Logger) emit(ctx context.Context, event eventPayload) error { + if l == nil { + return nil + } + + if !l.handler.Enabled(ctx, event.level) { + return nil + } + + rec := slog.NewRecord(nowUTC(), event.level, event.eventName, 0) + rec.AddAttrs( + slog.String("event", event.eventName), + slog.Int64("durationMs", event.durationMs), + slog.Bool("sampled", event.sampled), + slog.String("samplingReason", event.samplingReason), + ) + + if event.traceID != "" { + rec.AddAttrs(slog.String("traceId", event.traceID)) + } + + rec.AddAttrs( + slog.Any("attrs", event.attrs), + slog.Any("steps", event.steps), + slog.Any("errors", event.errors), + ) + + if event.stepsDropped > 0 { + rec.AddAttrs(slog.Int("stepsDropped", event.stepsDropped)) + } + + if err := l.handler.Handle(ctx, rec); err != nil { + return fmt.Errorf("failed to write log event: %w", err) + } + + return nil +} diff --git a/log2/sampling.go b/log2/sampling.go new file mode 100644 index 0000000..98cd363 --- /dev/null +++ b/log2/sampling.go @@ -0,0 +1,204 @@ +package log2 + +import ( + "math/rand" + "reflect" + "strings" + "time" +) + +// TailSampler decides whether a finished event should be emitted. +type TailSampler interface { + ShouldSample(EventView) SamplingDecision +} + +// SamplingDecision is the sampler decision. +type SamplingDecision struct { + Keep bool + Reason string +} + +// EventView is immutable event information for sampling. +type EventView struct { + Status int + Duration time.Duration + HasError bool + Attrs map[string]any +} + +// DefaultTailSamplerConfig configures the default tail sampler. +type DefaultTailSamplerConfig struct { + SlowThreshold time.Duration + RandomKeepRate float64 + KeepStatusAtLeast int + KeepRules []KeepRule + RandomFloat func() float64 +} + +// KeepRule defines a forced-keep rule. +type KeepRule struct { + Field string + Op string + Value any +} + +type defaultTailSampler struct { + slowThreshold time.Duration + randomKeepRate float64 + keepStatusAtLeast int + keepRules []KeepRule + randomFloat func() float64 +} + +// NewDefaultTailSampler creates a rule-based tail sampler. +// +//nolint:iface // public API returns TailSampler to allow custom implementations. +func NewDefaultTailSampler(cfg DefaultTailSamplerConfig) TailSampler { + slowThreshold := cfg.SlowThreshold + if slowThreshold <= 0 { + slowThreshold = defaultSlowThreshold + } + + keepStatusAtLeast := cfg.KeepStatusAtLeast + if keepStatusAtLeast <= 0 { + keepStatusAtLeast = defaultKeepStatus + } + + randomKeepRate := cfg.RandomKeepRate + if randomKeepRate <= 0 { + randomKeepRate = defaultRandomKeepRate + } + if randomKeepRate > 1 { + randomKeepRate = 1 + } + + randomFloat := cfg.RandomFloat + if randomFloat == nil { + randomFloat = rand.Float64 + } + + keepRules := make([]KeepRule, len(cfg.KeepRules)) + copy(keepRules, cfg.KeepRules) + + return &defaultTailSampler{ + slowThreshold: slowThreshold, + randomKeepRate: randomKeepRate, + keepStatusAtLeast: keepStatusAtLeast, + keepRules: keepRules, + randomFloat: randomFloat, + } +} + +func (s *defaultTailSampler) ShouldSample(view EventView) SamplingDecision { + if view.HasError { + return SamplingDecision{Keep: true, Reason: "error"} + } + + if view.Status >= s.keepStatusAtLeast { + return SamplingDecision{Keep: true, Reason: "status"} + } + + if view.Duration >= s.slowThreshold { + return SamplingDecision{Keep: true, Reason: "slow"} + } + + for _, rule := range s.keepRules { + if ruleMatches(view.Attrs, rule) { + return SamplingDecision{Keep: true, Reason: "rule"} + } + } + + if s.randomFloat() < s.randomKeepRate { + return SamplingDecision{Keep: true, Reason: "random"} + } + + return SamplingDecision{Keep: false, Reason: "drop"} +} + +func ruleMatches(attrs map[string]any, rule KeepRule) bool { + value, exists := lookupPath(attrs, rule.Field) + + switch strings.ToLower(rule.Op) { + case "eq": + if !exists { + return false + } + return valuesEqual(value, rule.Value) + case "in": + if !exists { + return false + } + return valueIn(value, rule.Value) + case "exists": + return exists + case "true": + if !exists { + return false + } + boolValue, ok := value.(bool) + return ok && boolValue + default: + return false + } +} + +func lookupPath(attrs map[string]any, path string) (any, bool) { + if attrs == nil { + return nil, false + } + + if direct, ok := attrs[path]; ok { + return direct, true + } + + current := any(attrs) + for _, part := range strings.Split(path, ".") { + asMap, ok := current.(map[string]any) + if !ok { + return nil, false + } + + next, ok := asMap[part] + if !ok { + return nil, false + } + + current = next + } + + return current, true +} + +func valueIn(value any, candidates any) bool { + candidateValue := reflect.ValueOf(candidates) + if !candidateValue.IsValid() { + return false + } + + kind := candidateValue.Kind() + if kind != reflect.Slice && kind != reflect.Array { + return false + } + + for i := range candidateValue.Len() { + if valuesEqual(value, candidateValue.Index(i).Interface()) { + return true + } + } + + return false +} + +func valuesEqual(a any, b any) bool { + if reflect.DeepEqual(a, b) { + return true + } + + ai, aok := toInt(a) + bi, bok := toInt(b) + if aok && bok { + return ai == bi + } + + return false +} diff --git a/log2/sampling_test.go b/log2/sampling_test.go new file mode 100644 index 0000000..1d23d00 --- /dev/null +++ b/log2/sampling_test.go @@ -0,0 +1,166 @@ +package log2_test + +import ( + "testing" + "time" + + "github.com/platforma-dev/platforma/log2" +) + +func TestDefaultTailSamplerKeepsError(t *testing.T) { + t.Parallel() + + sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ + RandomKeepRate: 0.01, + RandomFloat: func() float64 { return 0.99 }, + }) + + decision := sampler.ShouldSample(log2.EventView{HasError: true}) + if !decision.Keep { + t.Fatalf("expected keep for error") + } + if decision.Reason != "error" { + t.Fatalf("expected reason=error, got %q", decision.Reason) + } +} + +func TestDefaultTailSamplerKeepsByStatus(t *testing.T) { + t.Parallel() + + sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ + KeepStatusAtLeast: 500, + RandomKeepRate: 0.01, + RandomFloat: func() float64 { return 0.99 }, + }) + + decision := sampler.ShouldSample(log2.EventView{Status: 503}) + if !decision.Keep { + t.Fatalf("expected keep for status") + } + if decision.Reason != "status" { + t.Fatalf("expected reason=status, got %q", decision.Reason) + } +} + +func TestDefaultTailSamplerKeepsBySlowDuration(t *testing.T) { + t.Parallel() + + sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ + SlowThreshold: 100 * time.Millisecond, + RandomKeepRate: 0.01, + RandomFloat: func() float64 { return 0.99 }, + }) + + decision := sampler.ShouldSample(log2.EventView{Duration: 200 * time.Millisecond}) + if !decision.Keep { + t.Fatalf("expected keep for slow event") + } + if decision.Reason != "slow" { + t.Fatalf("expected reason=slow, got %q", decision.Reason) + } +} + +func TestDefaultTailSamplerKeepsByRule(t *testing.T) { + t.Parallel() + + t.Run("eq", func(t *testing.T) { + t.Parallel() + + sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ + KeepRules: []log2.KeepRule{{Field: "attrs.feature", Op: "eq", Value: "change_password"}}, + RandomKeepRate: 0.01, + RandomFloat: func() float64 { return 0.99 }, + }) + + decision := sampler.ShouldSample(log2.EventView{Attrs: map[string]any{ + "attrs": map[string]any{"feature": "change_password"}, + }}) + if !decision.Keep || decision.Reason != "rule" { + t.Fatalf("expected keep with reason=rule, got keep=%v reason=%q", decision.Keep, decision.Reason) + } + }) + + t.Run("in", func(t *testing.T) { + t.Parallel() + + sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ + KeepRules: []log2.KeepRule{{Field: "queue", Op: "in", Value: []string{"billing", "emails"}}}, + RandomKeepRate: 0.01, + RandomFloat: func() float64 { return 0.99 }, + }) + + decision := sampler.ShouldSample(log2.EventView{Attrs: map[string]any{"queue": "emails"}}) + if !decision.Keep || decision.Reason != "rule" { + t.Fatalf("expected keep with reason=rule, got keep=%v reason=%q", decision.Keep, decision.Reason) + } + }) + + t.Run("exists", func(t *testing.T) { + t.Parallel() + + sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ + KeepRules: []log2.KeepRule{{Field: "vip", Op: "exists"}}, + RandomKeepRate: 0.01, + RandomFloat: func() float64 { return 0.99 }, + }) + + decision := sampler.ShouldSample(log2.EventView{Attrs: map[string]any{"vip": "yes"}}) + if !decision.Keep || decision.Reason != "rule" { + t.Fatalf("expected keep with reason=rule, got keep=%v reason=%q", decision.Keep, decision.Reason) + } + }) + + t.Run("true", func(t *testing.T) { + t.Parallel() + + sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ + KeepRules: []log2.KeepRule{{Field: "security.risk", Op: "true"}}, + RandomKeepRate: 0.01, + RandomFloat: func() float64 { return 0.99 }, + }) + + decision := sampler.ShouldSample(log2.EventView{Attrs: map[string]any{"security": map[string]any{"risk": true}}}) + if !decision.Keep || decision.Reason != "rule" { + t.Fatalf("expected keep with reason=rule, got keep=%v reason=%q", decision.Keep, decision.Reason) + } + }) +} + +func TestDefaultTailSamplerRandomPath(t *testing.T) { + t.Parallel() + + t.Run("keep", func(t *testing.T) { + t.Parallel() + + sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ + SlowThreshold: 5 * time.Second, + KeepStatusAtLeast: 500, + RandomKeepRate: 0.10, + RandomFloat: func() float64 { return 0.09 }, + }) + + decision := sampler.ShouldSample(log2.EventView{}) + if !decision.Keep || decision.Reason != "random" { + t.Fatalf("expected random keep, got keep=%v reason=%q", decision.Keep, decision.Reason) + } + }) + + t.Run("drop", func(t *testing.T) { + t.Parallel() + + sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ + SlowThreshold: 5 * time.Second, + KeepStatusAtLeast: 500, + RandomKeepRate: 0.10, + RandomFloat: func() float64 { return 0.11 }, + }) + + decision := sampler.ShouldSample(log2.EventView{}) + if decision.Keep { + t.Fatalf("expected drop") + } + if decision.Reason != "drop" { + t.Fatalf("expected reason=drop, got %q", decision.Reason) + } + }) +} diff --git a/log2/test_helpers_test.go b/log2/test_helpers_test.go new file mode 100644 index 0000000..67bb4b6 --- /dev/null +++ b/log2/test_helpers_test.go @@ -0,0 +1,70 @@ +package log2_test + +import ( + "bytes" + "encoding/json" + "strings" + "testing" + + "github.com/platforma-dev/platforma/log2" +) + +type samplerFunc func(log2.EventView) log2.SamplingDecision + +func (f samplerFunc) ShouldSample(view log2.EventView) log2.SamplingDecision { + return f(view) +} + +func readEvents(t *testing.T, buffer *bytes.Buffer) []map[string]any { + t.Helper() + + trimmed := strings.TrimSpace(buffer.String()) + if trimmed == "" { + return nil + } + + lines := strings.Split(trimmed, "\n") + events := make([]map[string]any, 0, len(lines)) + + for _, line := range lines { + event := make(map[string]any) + if err := json.Unmarshal([]byte(line), &event); err != nil { + t.Fatalf("failed to parse event json: %v", err) + } + events = append(events, event) + } + + return events +} + +func requireMap(t *testing.T, source map[string]any, key string) map[string]any { + t.Helper() + + value, ok := source[key] + if !ok { + t.Fatalf("expected key %q to exist", key) + } + + asMap, ok := value.(map[string]any) + if !ok { + t.Fatalf("expected %q to be a map, got %T", key, value) + } + + return asMap +} + +func requireSlice(t *testing.T, source map[string]any, key string) []any { + t.Helper() + + value, ok := source[key] + if !ok { + t.Fatalf("expected key %q to exist", key) + } + + asSlice, ok := value.([]any) + if !ok { + t.Fatalf("expected %q to be a slice, got %T", key, value) + } + + return asSlice +} From 823440a979be4a6797caee1b669b7fb349b7d263 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Sat, 14 Feb 2026 22:08:29 +0300 Subject: [PATCH 02/38] Update log.go --- log/log.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log/log.go b/log/log.go index c9e8639..4b8ccb5 100644 --- a/log/log.go +++ b/log/log.go @@ -1,5 +1,5 @@ // Package log provides structured logging functionality with context support. -package log +package log //nolint:revive import ( "context" From 312f040dbcd1de368220fb1e1a09648b4eab5c24 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Sat, 14 Feb 2026 22:18:14 +0300 Subject: [PATCH 03/38] Implement log2 tail sampling --- log2/context.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/log2/context.go b/log2/context.go index a704ac6..67230bc 100644 --- a/log2/context.go +++ b/log2/context.go @@ -23,5 +23,9 @@ func EventFromContext(ctx context.Context) (*Event, bool) { // WithEvent stores an event in context. func WithEvent(ctx context.Context, ev *Event) context.Context { + if ctx == nil { + ctx = context.Background() + } + return context.WithValue(ctx, LogEventContextKey, ev) } From 645fbfb9e5f9ba9161bd3ff12c9251f0d03efa1e Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Sun, 15 Feb 2026 10:12:43 +0300 Subject: [PATCH 04/38] move package-docs skill --- {.opencode => .agents}/skills/package-docs/SKILL.md | 0 1 file changed, 0 insertions(+), 0 deletions(-) rename {.opencode => .agents}/skills/package-docs/SKILL.md (100%) diff --git a/.opencode/skills/package-docs/SKILL.md b/.agents/skills/package-docs/SKILL.md similarity index 100% rename from .opencode/skills/package-docs/SKILL.md rename to .agents/skills/package-docs/SKILL.md From 6fd763c822052cf0e3c243abad8160ec5431ebd4 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Sun, 15 Feb 2026 10:12:57 +0300 Subject: [PATCH 05/38] init log2 docs --- docs/astro.config.mjs | 1 + docs/src/content/docs/packages/log2.mdx | 195 ++++++++++++++++++++++++ 2 files changed, 196 insertions(+) create mode 100644 docs/src/content/docs/packages/log2.mdx diff --git a/docs/astro.config.mjs b/docs/astro.config.mjs index 811882f..6d34fe8 100644 --- a/docs/astro.config.mjs +++ b/docs/astro.config.mjs @@ -28,6 +28,7 @@ export default defineConfig({ "packages/database", "packages/httpserver", "packages/log", + "packages/log2", "packages/queue", "packages/scheduler", "packages/auth", diff --git a/docs/src/content/docs/packages/log2.mdx b/docs/src/content/docs/packages/log2.mdx new file mode 100644 index 0000000..37cc730 --- /dev/null +++ b/docs/src/content/docs/packages/log2.mdx @@ -0,0 +1,195 @@ +--- +title: log2 +--- +import { Steps } from '@astrojs/starlight/components'; + +The `log2` package provides wide-event logging with tail sampling, so each operation emits one structured event enriched with timeline steps, errors, and request context. + +Core Components: + +- `Config`: Logger configuration (`Writer`, `Format`, `Level`, `ContextKeys`, `Sampler`, `MaxSteps`). +- `DefaultConfig`: Returns defaults for output format, level, max steps, and sampler settings. +- `Logger`: Wide-event logger instance. +- `New`: Creates a logger from `Config`. +- `SetDefault`: Replaces package-level default logger. +- `Start`: Starts an event (`log2.Start` and `(*Logger).Start`). +- `Event`: Mutable event object. +- `Event.Add`, `Event.Step`, `Event.Error`, `Event.Finish`: Event lifecycle methods. +- `TailSampler`: Sampling interface. +- `SamplingDecision`: Keep/drop decision with reason. +- `EventView`: Immutable event view for sampling. +- `DefaultTailSamplerConfig`: Config for default sampler. +- `KeepRule`: Rule definition for forced-keep sampling. +- `NewDefaultTailSampler`: Builds default rule-based sampler. +- `HTTPMiddlewareConfig`, `NewHTTPMiddleware`: HTTP middleware that creates one event per request. +- `WithEvent`, `EventFromContext`, `LogEventContextKey`: Context helpers. +- `ErrEventAlreadyFinished`: Returned when `Finish` is called more than once. + +[Full package docs at pkg.go.dev](https://pkg.go.dev/github.com/platforma-dev/platforma/log2) + +## Step-by-step guide + + + +1. Create a logger + + ```go + cfg := log2.DefaultConfig() + cfg.Level = slog.LevelInfo + logger := log2.New(cfg) + log2.SetDefault(logger) + ``` + + `DefaultConfig` includes: + + - `Format: "json"` + - Default tail sampler (keep errors, 5xx, slow events, and a random sample) + - `MaxSteps: 100` + +2. Start and enrich an event + + ```go + ev := logger.Start(ctx, "auth_request", "component", "handler") + ev.Add("userId", "u-123") + ev.Step(slog.LevelInfo, "credentials_validated", "provider", "password") + ``` + + `Add` merges persistent attributes. `Step` appends timeline entries. + +3. Record errors and finish + + ```go + if err != nil { + ev.Error(err, "stage", "db_lookup") + } + + if finishErr := ev.Finish("status", 200); finishErr != nil { + if errors.Is(finishErr, log2.ErrEventAlreadyFinished) { + // finish was called twice + } + } + ``` + + `Finish` evaluates sampling using event status, duration, errors, and attributes. + +4. Configure custom tail sampling rules + + ```go + cfg := log2.DefaultConfig() + cfg.Sampler = log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ + KeepRules: []log2.KeepRule{ + {Field: "attrs.feature", Op: "eq", Value: "change_password"}, + {Field: "queue", Op: "in", Value: []string{"billing", "emails"}}, + {Field: "vip", Op: "exists"}, + {Field: "security.risk", Op: "true"}, + }, + RandomKeepRate: 0.01, + }) + logger := log2.New(cfg) + ``` + + Supported rule operators are `eq`, `in`, `exists`, and `true`. + +5. Add HTTP middleware and use event from request context + + ```go + logger := log2.New(log2.DefaultConfig()) + middleware := log2.NewHTTPMiddleware(logger, log2.HTTPMiddlewareConfig{ + EventName: "http_request", + RouteAttr: "route", + }) + + mux := http.NewServeMux() + mux.HandleFunc("/ping", func(w http.ResponseWriter, r *http.Request) { + if ev, ok := log2.EventFromContext(r.Context()); ok { + ev.Step(slog.LevelInfo, "handler_started", "path", r.URL.Path) + } + + w.WriteHeader(http.StatusOK) + _, _ = w.Write([]byte("pong")) + }) + + handler := middleware(mux) + _ = handler + ``` + + Middleware stores the event in context using `WithEvent`, collects request/response metadata, and calls `Finish` automatically. + + + +## Behavior notes + +- `Finish` called twice returns `ErrEventAlreadyFinished`. +- Event log level is inferred: + - `ERROR` for event errors or 5xx status. + - `WARN` for 4xx status. + - `INFO` otherwise. +- Status is inferred from `status`, `statusCode`, `response.status`, or `response.status` inside a `response` map. +- If steps exceed `MaxSteps`, extra steps are dropped and counted in `stepsDropped`. + +## Integration with `log` context keys + +`log2.Start` extracts known context values from the `log` package and includes them in event attributes when present: + +- `traceId` +- `serviceName` +- `domainName` +- `startupTask` +- `userId` +- `workerId` + +This allows `log2` events to align with existing `log` and `httpserver` context propagation. + +## Complete example + +```go +package main + +import ( + "context" + "errors" + "log/slog" + "net/http" + "os" + "time" + + "github.com/platforma-dev/platforma/log2" +) + +func main() { + cfg := log2.DefaultConfig() + cfg.Writer = os.Stdout + cfg.Level = slog.LevelInfo + cfg.Sampler = log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ + SlowThreshold: 500 * time.Millisecond, + RandomKeepRate: 0.02, + }) + + logger := log2.New(cfg) + middleware := log2.NewHTTPMiddleware(logger, log2.HTTPMiddlewareConfig{}) + + mux := http.NewServeMux() + mux.HandleFunc("/users", func(w http.ResponseWriter, r *http.Request) { + ev, ok := log2.EventFromContext(r.Context()) + if ok { + ev.Step(slog.LevelInfo, "fetch_users_started") + defer func() { + if err := ev.Finish("status", http.StatusOK); err != nil && !errors.Is(err, log2.ErrEventAlreadyFinished) { + // Handle finish error. + } + }() + } + + w.WriteHeader(http.StatusOK) + _, _ = w.Write([]byte(`{"users":[]}`)) + }) + + server := &http.Server{ + Addr: ":8080", + Handler: middleware(mux), + } + + _ = server.ListenAndServe() + _ = server.Shutdown(context.Background()) +} +``` From 1d9f14b50c6bbd2032496f1f2c7fdcaf000d007b Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Sun, 15 Feb 2026 19:56:36 +0300 Subject: [PATCH 06/38] expose docs on dev command --- Taskfile.dist.yml | 2 +- docs/package.json | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/Taskfile.dist.yml b/Taskfile.dist.yml index 5c19ff0..ca1481b 100644 --- a/Taskfile.dist.yml +++ b/Taskfile.dist.yml @@ -24,4 +24,4 @@ tasks: docs: dir: docs cmds: - - npm run dev + - bun run dev diff --git a/docs/package.json b/docs/package.json index 0b2d575..a86d185 100644 --- a/docs/package.json +++ b/docs/package.json @@ -3,7 +3,7 @@ "type": "module", "version": "0.0.1", "scripts": { - "dev": "astro dev", + "dev": "astro dev --host", "start": "astro dev", "build": "astro build", "preview": "astro preview", From 7edc5226ee703ecd3529f28ab11e4f45ca10028b Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Sun, 15 Feb 2026 22:49:39 +0300 Subject: [PATCH 07/38] cleaning up --- log2/context.go | 2 +- log2/context_test.go | 92 ---------- log2/event.go | 54 ++---- log2/event_test.go | 197 --------------------- log2/http_middleware_test.go | 140 --------------- log2/logger.go | 5 +- log2/{http_middleware.go => middleware.go} | 0 log2/sampling_test.go | 166 ----------------- log2/test_helpers_test.go | 70 -------- 9 files changed, 19 insertions(+), 707 deletions(-) delete mode 100644 log2/context_test.go delete mode 100644 log2/event_test.go delete mode 100644 log2/http_middleware_test.go rename log2/{http_middleware.go => middleware.go} (100%) delete mode 100644 log2/sampling_test.go delete mode 100644 log2/test_helpers_test.go diff --git a/log2/context.go b/log2/context.go index 67230bc..3a2da4f 100644 --- a/log2/context.go +++ b/log2/context.go @@ -5,7 +5,7 @@ import "context" type contextKey string // LogEventContextKey is used to store Event in context. -var LogEventContextKey any = contextKey("platformaLog2Event") //nolint:gochecknoglobals +const LogEventContextKey contextKey = "platformaLogEvent" // EventFromContext gets an event from context. func EventFromContext(ctx context.Context) (*Event, bool) { diff --git a/log2/context_test.go b/log2/context_test.go deleted file mode 100644 index 2bc2f74..0000000 --- a/log2/context_test.go +++ /dev/null @@ -1,92 +0,0 @@ -package log2_test - -import ( - "bytes" - "context" - "log/slog" - "testing" - - "github.com/platforma-dev/platforma/log" - "github.com/platforma-dev/platforma/log2" -) - -func TestEventFromContextMiss(t *testing.T) { - t.Parallel() - - ev, ok := log2.EventFromContext(context.Background()) - if ok { - t.Fatalf("expected ok=false, got true with event=%v", ev) - } - if ev != nil { - t.Fatalf("expected nil event, got %v", ev) - } -} - -func TestEventFromContextWithRawContextValue(t *testing.T) { - t.Parallel() - - logger := log2.New(log2.Config{Writer: &bytes.Buffer{}}) - ev := logger.Start(context.Background(), "ctx") - - ctx := context.WithValue(context.Background(), log2.LogEventContextKey, ev) - got, ok := log2.EventFromContext(ctx) - if !ok { - t.Fatalf("expected ok=true") - } - if got != ev { - t.Fatalf("expected the same event pointer") - } -} - -func TestWithEvent(t *testing.T) { - t.Parallel() - - logger := log2.New(log2.Config{Writer: &bytes.Buffer{}}) - ev := logger.Start(context.Background(), "ctx") - - ctx := log2.WithEvent(context.Background(), ev) - got, ok := log2.EventFromContext(ctx) - if !ok { - t.Fatalf("expected ok=true") - } - if got != ev { - t.Fatalf("expected the same event pointer") - } -} - -func TestStartCollectsDefaultContextKeys(t *testing.T) { - t.Parallel() - - buffer := &bytes.Buffer{} - logger := log2.New(log2.Config{ - Writer: buffer, - Format: "json", - Level: slog.LevelInfo, - Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), - }) - - ctx := context.WithValue(context.Background(), log.TraceIDKey, "trace-123") - ctx = context.WithValue(ctx, log.UserIDKey, "user-99") - - ev := logger.Start(ctx, "collect-keys") - if err := ev.Finish(); err != nil { - t.Fatalf("Finish() returned error: %v", err) - } - - events := readEvents(t, buffer) - if len(events) != 1 { - t.Fatalf("expected 1 event, got %d", len(events)) - } - - if events[0]["traceId"] != "trace-123" { - t.Fatalf("expected top-level traceId=trace-123, got %v", events[0]["traceId"]) - } - - attrs := requireMap(t, events[0], "attrs") - if attrs["traceId"] != "trace-123" { - t.Fatalf("expected attrs.traceId=trace-123, got %v", attrs["traceId"]) - } - if attrs["userId"] != "user-99" { - t.Fatalf("expected attrs.userId=user-99, got %v", attrs["userId"]) - } -} diff --git a/log2/event.go b/log2/event.go index c0d4f14..c9acb56 100644 --- a/log2/event.go +++ b/log2/event.go @@ -95,7 +95,7 @@ func (e *Event) Step(level slog.Level, msg string, attrs ...any) { } e.steps = append(e.steps, stepRecord{ - ts: nowUTC(), + ts: time.Now().UTC(), level: level.String(), msg: msg, attrs: normalizeAttrs(attrs...), @@ -117,7 +117,7 @@ func (e *Event) Error(err error, attrs ...any) { e.hasError = true e.errors = append(e.errors, errorRecord{ - ts: nowUTC(), + ts: time.Now().UTC(), err: err.Error(), attrs: normalizeAttrs(attrs...), }) @@ -137,9 +137,17 @@ func (e *Event) Finish(attrs ...any) error { mergeAttrs(e.attrs, normalizeAttrs(attrs...)) - duration := nowUTC().Sub(e.startedAt) - status := inferStatus(e.attrs) - level := inferLevel(status, e.hasError) + status := 0 + statusFromAttrs, ok := e.attrs["request.status"] + if ok { + status, ok = statusFromAttrs.(int) + if !ok { + status = 0 + } + } + + duration := time.Now().UTC().Sub(e.startedAt) + level := inferLevel(e.hasError) attrsCopy := copyAttrs(e.attrs) stepsCopy := copySteps(e.steps) errorsCopy := copyErrors(e.errors) @@ -175,10 +183,6 @@ func (e *Event) Finish(attrs ...any) error { }) } -func nowUTC() time.Time { - return time.Now().UTC() -} - func collectContextAttrs(ctx context.Context, extraKeys map[string]any) map[string]any { attrs := map[string]any{} @@ -278,42 +282,14 @@ func copyErrors(src []errorRecord) []map[string]any { return errs } -func inferLevel(status int, hasError bool) slog.Level { - if hasError || status >= defaultKeepStatus { +func inferLevel(hasError bool) slog.Level { + if hasError { return slog.LevelError } - if status >= 400 { - return slog.LevelWarn - } - return slog.LevelInfo } -func inferStatus(attrs map[string]any) int { - if status, ok := toInt(attrs["status"]); ok { - return status - } - - if status, ok := toInt(attrs["statusCode"]); ok { - return status - } - - if status, ok := toInt(attrs["response.status"]); ok { - return status - } - - if responseAny, ok := attrs["response"]; ok { - if response, okMap := responseAny.(map[string]any); okMap { - if status, okStatus := toInt(response["status"]); okStatus { - return status - } - } - } - - return 0 -} - func toInt(value any) (int, bool) { switch typed := value.(type) { case int: diff --git a/log2/event_test.go b/log2/event_test.go deleted file mode 100644 index fbff343..0000000 --- a/log2/event_test.go +++ /dev/null @@ -1,197 +0,0 @@ -package log2_test - -import ( - "bytes" - "context" - "errors" - "log/slog" - "sync" - "testing" - - "github.com/platforma-dev/platforma/log2" -) - -func TestEventLifecycle(t *testing.T) { - t.Parallel() - - buffer := &bytes.Buffer{} - logger := log2.New(log2.Config{ - Writer: buffer, - Format: "json", - Level: slog.LevelDebug, - Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), - MaxSteps: 10, - }) - - ev := logger.Start(context.Background(), "auth_request", "component", "handler") - ev.Add("userId", "u-1", "attempt", 2) - ev.Step(slog.LevelInfo, "request accepted") - ev.Error(errors.New("boom"), "phase", "validation") - - if err := ev.Finish("status", 500); err != nil { - t.Fatalf("Finish() returned error: %v", err) - } - - events := readEvents(t, buffer) - if len(events) != 1 { - t.Fatalf("expected 1 emitted event, got %d", len(events)) - } - - event := events[0] - if event["event"] != "auth_request" { - t.Fatalf("expected event name auth_request, got %v", event["event"]) - } - if event["samplingReason"] != "forced" { - t.Fatalf("expected sampling reason forced, got %v", event["samplingReason"]) - } - if event["sampled"] != true { - t.Fatalf("expected sampled=true, got %v", event["sampled"]) - } - - attrs := requireMap(t, event, "attrs") - if attrs["component"] != "handler" { - t.Fatalf("expected component=handler, got %v", attrs["component"]) - } - if attrs["userId"] != "u-1" { - t.Fatalf("expected userId=u-1, got %v", attrs["userId"]) - } - if attrs["attempt"] != float64(2) { - t.Fatalf("expected attempt=2, got %v", attrs["attempt"]) - } - if attrs["status"] != float64(500) { - t.Fatalf("expected status=500, got %v", attrs["status"]) - } - - steps := requireSlice(t, event, "steps") - if len(steps) != 1 { - t.Fatalf("expected 1 step, got %d", len(steps)) - } - - errorsList := requireSlice(t, event, "errors") - if len(errorsList) != 1 { - t.Fatalf("expected 1 error, got %d", len(errorsList)) - } -} - -func TestEventAttributeOverwrite(t *testing.T) { - t.Parallel() - - buffer := &bytes.Buffer{} - logger := log2.New(log2.Config{ - Writer: buffer, - Format: "json", - Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), - }) - - ev := logger.Start(context.Background(), "overwrite") - ev.Add("key", "first") - ev.Add("key", "second") - - if err := ev.Finish(); err != nil { - t.Fatalf("Finish() returned error: %v", err) - } - - events := readEvents(t, buffer) - if len(events) != 1 { - t.Fatalf("expected 1 event, got %d", len(events)) - } - - attrs := requireMap(t, events[0], "attrs") - if attrs["key"] != "second" { - t.Fatalf("expected key=second, got %v", attrs["key"]) - } -} - -func TestEventFinishCalledTwice(t *testing.T) { - t.Parallel() - - logger := log2.New(log2.Config{ - Writer: &bytes.Buffer{}, - Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), - }) - - ev := logger.Start(context.Background(), "double_finish") - if err := ev.Finish(); err != nil { - t.Fatalf("first Finish() returned error: %v", err) - } - - err := ev.Finish() - if !errors.Is(err, log2.ErrEventAlreadyFinished) { - t.Fatalf("expected ErrEventAlreadyFinished, got %v", err) - } -} - -func TestEventConcurrentAccessAndStepCap(t *testing.T) { - t.Parallel() - - buffer := &bytes.Buffer{} - logger := log2.New(log2.Config{ - Writer: buffer, - Format: "json", - Level: slog.LevelDebug, - Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), - MaxSteps: 5, - }) - - ev := logger.Start(context.Background(), "concurrent") - - var wg sync.WaitGroup - for i := range 20 { - wg.Add(1) - go func(i int) { - defer wg.Done() - ev.Add("counter", i) - ev.Step(slog.LevelInfo, "work", "i", i) - if i%3 == 0 { - ev.Error(errors.New("worker-error"), "i", i) - } - }(i) - } - - wg.Wait() - - if err := ev.Finish("status", 200); err != nil { - t.Fatalf("Finish() returned error: %v", err) - } - - events := readEvents(t, buffer) - if len(events) != 1 { - t.Fatalf("expected 1 event, got %d", len(events)) - } - - event := events[0] - steps := requireSlice(t, event, "steps") - if len(steps) != 5 { - t.Fatalf("expected 5 steps (cap), got %d", len(steps)) - } - - dropped, ok := event["stepsDropped"].(float64) - if !ok { - t.Fatalf("expected stepsDropped to exist") - } - if dropped != float64(15) { - t.Fatalf("expected stepsDropped=15, got %v", dropped) - } -} - -func TestEventDroppedBySampler(t *testing.T) { - t.Parallel() - - buffer := &bytes.Buffer{} - logger := log2.New(log2.Config{ - Writer: buffer, - Format: "json", - Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: false, Reason: "drop"} }), - }) - - ev := logger.Start(context.Background(), "drop_me") - ev.Add("k", "v") - if err := ev.Finish(); err != nil { - t.Fatalf("Finish() returned error: %v", err) - } - - events := readEvents(t, buffer) - if len(events) != 0 { - t.Fatalf("expected no emitted events, got %d", len(events)) - } -} diff --git a/log2/http_middleware_test.go b/log2/http_middleware_test.go deleted file mode 100644 index a881a23..0000000 --- a/log2/http_middleware_test.go +++ /dev/null @@ -1,140 +0,0 @@ -package log2_test - -import ( - "bytes" - "fmt" - "log/slog" - "net/http" - "net/http/httptest" - "strings" - "testing" - - "github.com/platforma-dev/platforma/log2" -) - -func TestHTTPMiddlewareEmitsSingleWideEvent(t *testing.T) { - t.Parallel() - - buffer := &bytes.Buffer{} - logger := log2.New(log2.Config{ - Writer: buffer, - Format: "json", - Level: slog.LevelInfo, - Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), - }) - - middleware := log2.NewHTTPMiddleware(logger, log2.HTTPMiddlewareConfig{}) - handler := middleware(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - ev, ok := log2.EventFromContext(r.Context()) - if !ok { - t.Fatalf("expected event in request context") - } - ev.Add("handler", "users") - - w.WriteHeader(http.StatusTeapot) - _, _ = w.Write([]byte("hello")) - })) - - req := httptest.NewRequest(http.MethodGet, "/users/42", nil) - rec := httptest.NewRecorder() - handler.ServeHTTP(rec, req) - - events := readEvents(t, buffer) - if len(events) != 1 { - t.Fatalf("expected 1 event, got %d", len(events)) - } - - event := events[0] - if event["event"] != "http_request" { - t.Fatalf("expected event=http_request, got %v", event["event"]) - } - - attrs := requireMap(t, event, "attrs") - if attrs["status"] != float64(http.StatusTeapot) { - t.Fatalf("expected status %d, got %v", http.StatusTeapot, attrs["status"]) - } - if attrs["route"] != "/users/42" { - t.Fatalf("expected fallback route /users/42, got %v", attrs["route"]) - } - - request := requireMap(t, attrs, "request") - if request["method"] != http.MethodGet { - t.Fatalf("expected method GET, got %v", request["method"]) - } - if request["path"] != "/users/42" { - t.Fatalf("expected path /users/42, got %v", request["path"]) - } - - response := requireMap(t, attrs, "response") - if response["status"] != float64(http.StatusTeapot) { - t.Fatalf("expected response.status=%d, got %v", http.StatusTeapot, response["status"]) - } - if response["bytes"] != float64(5) { - t.Fatalf("expected response.bytes=5, got %v", response["bytes"]) - } -} - -func TestHTTPMiddlewarePanicPath(t *testing.T) { - t.Parallel() - - buffer := &bytes.Buffer{} - logger := log2.New(log2.Config{ - Writer: buffer, - Format: "json", - Level: slog.LevelInfo, - Sampler: samplerFunc(func(log2.EventView) log2.SamplingDecision { return log2.SamplingDecision{Keep: true, Reason: "forced"} }), - }) - - middleware := log2.NewHTTPMiddleware(logger, log2.HTTPMiddlewareConfig{}) - handler := middleware(http.HandlerFunc(func(http.ResponseWriter, *http.Request) { - panic("boom") - })) - - req := httptest.NewRequest(http.MethodGet, "/panic", nil) - rec := httptest.NewRecorder() - - panicRecovered := false - func() { - defer func() { - if recovered := recover(); recovered != nil { - panicRecovered = true - if fmt.Sprint(recovered) != "boom" { - t.Fatalf("expected panic value boom, got %v", recovered) - } - } - }() - handler.ServeHTTP(rec, req) - }() - - if !panicRecovered { - t.Fatalf("expected panic to be rethrown by middleware") - } - - events := readEvents(t, buffer) - if len(events) != 1 { - t.Fatalf("expected 1 event, got %d", len(events)) - } - - event := events[0] - if event["level"] != "ERROR" { - t.Fatalf("expected level ERROR for panic path, got %v", event["level"]) - } - - errorsList := requireSlice(t, event, "errors") - if len(errorsList) != 1 { - t.Fatalf("expected exactly 1 recorded error, got %d", len(errorsList)) - } - - errorMap, ok := errorsList[0].(map[string]any) - if !ok { - t.Fatalf("expected errors[0] to be map, got %T", errorsList[0]) - } - - errorText, ok := errorMap["error"].(string) - if !ok { - t.Fatalf("expected errors[0].error string, got %T", errorMap["error"]) - } - if !strings.Contains(errorText, "panic recovered: boom") { - t.Fatalf("expected panic error text to include panic recovered: boom, got %q", errorText) - } -} diff --git a/log2/logger.go b/log2/logger.go index f6fc6f9..27e77e3 100644 --- a/log2/logger.go +++ b/log2/logger.go @@ -5,6 +5,7 @@ import ( "fmt" "io" "log/slog" + "time" ) // Logger writes sampled wide events. @@ -77,7 +78,7 @@ func (l *Logger) Start(ctx context.Context, eventName string, attrs ...any) *Eve return &Event{ logger: l, eventName: eventName, - startedAt: nowUTC(), + startedAt: time.Now().UTC(), attrs: baseAttrs, steps: make([]stepRecord, 0), errors: make([]errorRecord, 0), @@ -93,7 +94,7 @@ func (l *Logger) emit(ctx context.Context, event eventPayload) error { return nil } - rec := slog.NewRecord(nowUTC(), event.level, event.eventName, 0) + rec := slog.NewRecord(time.Now().UTC(), event.level, event.eventName, 0) rec.AddAttrs( slog.String("event", event.eventName), slog.Int64("durationMs", event.durationMs), diff --git a/log2/http_middleware.go b/log2/middleware.go similarity index 100% rename from log2/http_middleware.go rename to log2/middleware.go diff --git a/log2/sampling_test.go b/log2/sampling_test.go deleted file mode 100644 index 1d23d00..0000000 --- a/log2/sampling_test.go +++ /dev/null @@ -1,166 +0,0 @@ -package log2_test - -import ( - "testing" - "time" - - "github.com/platforma-dev/platforma/log2" -) - -func TestDefaultTailSamplerKeepsError(t *testing.T) { - t.Parallel() - - sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ - RandomKeepRate: 0.01, - RandomFloat: func() float64 { return 0.99 }, - }) - - decision := sampler.ShouldSample(log2.EventView{HasError: true}) - if !decision.Keep { - t.Fatalf("expected keep for error") - } - if decision.Reason != "error" { - t.Fatalf("expected reason=error, got %q", decision.Reason) - } -} - -func TestDefaultTailSamplerKeepsByStatus(t *testing.T) { - t.Parallel() - - sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ - KeepStatusAtLeast: 500, - RandomKeepRate: 0.01, - RandomFloat: func() float64 { return 0.99 }, - }) - - decision := sampler.ShouldSample(log2.EventView{Status: 503}) - if !decision.Keep { - t.Fatalf("expected keep for status") - } - if decision.Reason != "status" { - t.Fatalf("expected reason=status, got %q", decision.Reason) - } -} - -func TestDefaultTailSamplerKeepsBySlowDuration(t *testing.T) { - t.Parallel() - - sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ - SlowThreshold: 100 * time.Millisecond, - RandomKeepRate: 0.01, - RandomFloat: func() float64 { return 0.99 }, - }) - - decision := sampler.ShouldSample(log2.EventView{Duration: 200 * time.Millisecond}) - if !decision.Keep { - t.Fatalf("expected keep for slow event") - } - if decision.Reason != "slow" { - t.Fatalf("expected reason=slow, got %q", decision.Reason) - } -} - -func TestDefaultTailSamplerKeepsByRule(t *testing.T) { - t.Parallel() - - t.Run("eq", func(t *testing.T) { - t.Parallel() - - sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ - KeepRules: []log2.KeepRule{{Field: "attrs.feature", Op: "eq", Value: "change_password"}}, - RandomKeepRate: 0.01, - RandomFloat: func() float64 { return 0.99 }, - }) - - decision := sampler.ShouldSample(log2.EventView{Attrs: map[string]any{ - "attrs": map[string]any{"feature": "change_password"}, - }}) - if !decision.Keep || decision.Reason != "rule" { - t.Fatalf("expected keep with reason=rule, got keep=%v reason=%q", decision.Keep, decision.Reason) - } - }) - - t.Run("in", func(t *testing.T) { - t.Parallel() - - sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ - KeepRules: []log2.KeepRule{{Field: "queue", Op: "in", Value: []string{"billing", "emails"}}}, - RandomKeepRate: 0.01, - RandomFloat: func() float64 { return 0.99 }, - }) - - decision := sampler.ShouldSample(log2.EventView{Attrs: map[string]any{"queue": "emails"}}) - if !decision.Keep || decision.Reason != "rule" { - t.Fatalf("expected keep with reason=rule, got keep=%v reason=%q", decision.Keep, decision.Reason) - } - }) - - t.Run("exists", func(t *testing.T) { - t.Parallel() - - sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ - KeepRules: []log2.KeepRule{{Field: "vip", Op: "exists"}}, - RandomKeepRate: 0.01, - RandomFloat: func() float64 { return 0.99 }, - }) - - decision := sampler.ShouldSample(log2.EventView{Attrs: map[string]any{"vip": "yes"}}) - if !decision.Keep || decision.Reason != "rule" { - t.Fatalf("expected keep with reason=rule, got keep=%v reason=%q", decision.Keep, decision.Reason) - } - }) - - t.Run("true", func(t *testing.T) { - t.Parallel() - - sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ - KeepRules: []log2.KeepRule{{Field: "security.risk", Op: "true"}}, - RandomKeepRate: 0.01, - RandomFloat: func() float64 { return 0.99 }, - }) - - decision := sampler.ShouldSample(log2.EventView{Attrs: map[string]any{"security": map[string]any{"risk": true}}}) - if !decision.Keep || decision.Reason != "rule" { - t.Fatalf("expected keep with reason=rule, got keep=%v reason=%q", decision.Keep, decision.Reason) - } - }) -} - -func TestDefaultTailSamplerRandomPath(t *testing.T) { - t.Parallel() - - t.Run("keep", func(t *testing.T) { - t.Parallel() - - sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ - SlowThreshold: 5 * time.Second, - KeepStatusAtLeast: 500, - RandomKeepRate: 0.10, - RandomFloat: func() float64 { return 0.09 }, - }) - - decision := sampler.ShouldSample(log2.EventView{}) - if !decision.Keep || decision.Reason != "random" { - t.Fatalf("expected random keep, got keep=%v reason=%q", decision.Keep, decision.Reason) - } - }) - - t.Run("drop", func(t *testing.T) { - t.Parallel() - - sampler := log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ - SlowThreshold: 5 * time.Second, - KeepStatusAtLeast: 500, - RandomKeepRate: 0.10, - RandomFloat: func() float64 { return 0.11 }, - }) - - decision := sampler.ShouldSample(log2.EventView{}) - if decision.Keep { - t.Fatalf("expected drop") - } - if decision.Reason != "drop" { - t.Fatalf("expected reason=drop, got %q", decision.Reason) - } - }) -} diff --git a/log2/test_helpers_test.go b/log2/test_helpers_test.go deleted file mode 100644 index 67bb4b6..0000000 --- a/log2/test_helpers_test.go +++ /dev/null @@ -1,70 +0,0 @@ -package log2_test - -import ( - "bytes" - "encoding/json" - "strings" - "testing" - - "github.com/platforma-dev/platforma/log2" -) - -type samplerFunc func(log2.EventView) log2.SamplingDecision - -func (f samplerFunc) ShouldSample(view log2.EventView) log2.SamplingDecision { - return f(view) -} - -func readEvents(t *testing.T, buffer *bytes.Buffer) []map[string]any { - t.Helper() - - trimmed := strings.TrimSpace(buffer.String()) - if trimmed == "" { - return nil - } - - lines := strings.Split(trimmed, "\n") - events := make([]map[string]any, 0, len(lines)) - - for _, line := range lines { - event := make(map[string]any) - if err := json.Unmarshal([]byte(line), &event); err != nil { - t.Fatalf("failed to parse event json: %v", err) - } - events = append(events, event) - } - - return events -} - -func requireMap(t *testing.T, source map[string]any, key string) map[string]any { - t.Helper() - - value, ok := source[key] - if !ok { - t.Fatalf("expected key %q to exist", key) - } - - asMap, ok := value.(map[string]any) - if !ok { - t.Fatalf("expected %q to be a map, got %T", key, value) - } - - return asMap -} - -func requireSlice(t *testing.T, source map[string]any, key string) []any { - t.Helper() - - value, ok := source[key] - if !ok { - t.Fatalf("expected key %q to exist", key) - } - - asSlice, ok := value.([]any) - if !ok { - t.Fatalf("expected %q to be a slice, got %T", key, value) - } - - return asSlice -} From 61e01ea5f1ca10bf0f7ebbbfa8640afb22f1ca02 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Sun, 15 Feb 2026 23:39:56 +0300 Subject: [PATCH 08/38] next try init --- log3/event.go | 104 +++++++++++++++++++++++++++++++++++++++++++++++++ log3/logger.go | 29 ++++++++++++++ 2 files changed, 133 insertions(+) create mode 100644 log3/event.go create mode 100644 log3/logger.go diff --git a/log3/event.go b/log3/event.go new file mode 100644 index 0000000..8e31e87 --- /dev/null +++ b/log3/event.go @@ -0,0 +1,104 @@ +package log3 + +import ( + "log/slog" + "maps" + "sync" + "time" +) + +type Event struct { + mu sync.Mutex + + name string + timestamp time.Time + level slog.Level + duration time.Duration + attrs map[string]any + steps []stepRecord + errors []errorRecord +} + +func NewEvent() *Event { + return &Event{ + timestamp: time.Now(), + level: slog.LevelDebug, + attrs: map[string]any{}, + } +} + +func (e *Event) SetLevel(level slog.Level) { + e.mu.Lock() + defer e.mu.Unlock() + + if level > e.level { + e.level = level + } +} + +func (e *Event) AddAttrs(attrs map[string]any) { + e.mu.Lock() + defer e.mu.Unlock() + + maps.Copy(e.attrs, attrs) +} + +func (e *Event) AddStep(level slog.Level, name string) { + e.mu.Lock() + defer e.mu.Unlock() + + e.SetLevel(level) + + e.steps = append(e.steps, stepRecord{ + timestamp: time.Now(), + level: level, + name: name, + }) +} + +func (e *Event) AddError(err error) { + e.mu.Lock() + defer e.mu.Unlock() + + e.SetLevel(slog.LevelError) + + e.errors = append(e.errors, errorRecord{ + timestamp: time.Now(), + err: err, + }) +} + +func (e *Event) Finish() { + e.mu.Lock() + defer e.mu.Unlock() + + e.duration = time.Since(e.timestamp) +} + +func (e *Event) ToAttrs() []slog.Attr { + e.mu.Lock() + defer e.mu.Unlock() + + e.duration = time.Since(e.timestamp) + + return []slog.Attr{ + slog.String("name", e.name), + slog.Time("timestamp", e.timestamp), + slog.Int("level", int(e.level)), + slog.Duration("duration", e.duration), + slog.Any("attrs", e.attrs), + slog.Any("steps", e.steps), + slog.Any("errors", e.errors), + } +} + +type stepRecord struct { + timestamp time.Time + level slog.Level + name string +} + +type errorRecord struct { + timestamp time.Time + err error +} diff --git a/log3/logger.go b/log3/logger.go new file mode 100644 index 0000000..89ff943 --- /dev/null +++ b/log3/logger.go @@ -0,0 +1,29 @@ +package log3 + +import ( + "context" + "io" + "log/slog" +) + +type Logger struct { + w io.Writer + sampler func(*Event) bool + logger *slog.Logger +} + +func (l *Logger) WriteEvent(ctx context.Context, e *Event) { + e.Finish() + + if l.sampler(e) { + l.logger.LogAttrs(ctx, e.level, "", e.ToAttrs()...) + } +} + +func mapToAttrs(data map[string]any) []slog.Attr { + attrs := make([]slog.Attr, 0, len(data)) + for k, v := range data { + attrs = append(attrs, slog.Any(k, v)) + } + return attrs +} From c7aae03bfb5063858f6f4fe2eab36fd22ed0fe1d Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 07:24:33 +0300 Subject: [PATCH 09/38] Update logger even more --- log3/logger.go | 21 +++++++++--------- log3/sampler.go | 57 +++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 68 insertions(+), 10 deletions(-) create mode 100644 log3/sampler.go diff --git a/log3/logger.go b/log3/logger.go index 89ff943..00b5404 100644 --- a/log3/logger.go +++ b/log3/logger.go @@ -4,26 +4,27 @@ import ( "context" "io" "log/slog" + + "github.com/platforma-dev/platforma/log" ) type Logger struct { w io.Writer - sampler func(*Event) bool + sampler Sampler logger *slog.Logger } +func NewWideEventLogger(w io.Writer, s Sampler, loggerType string, contextKeys map[string]any) *Logger { + return &Logger{ + sampler: s, + logger: log.New(w, loggerType, slog.LevelDebug, contextKeys), + } +} + func (l *Logger) WriteEvent(ctx context.Context, e *Event) { e.Finish() - if l.sampler(e) { + if l.sampler.ShouldSample(ctx, e) { l.logger.LogAttrs(ctx, e.level, "", e.ToAttrs()...) } } - -func mapToAttrs(data map[string]any) []slog.Attr { - attrs := make([]slog.Attr, 0, len(data)) - for k, v := range data { - attrs = append(attrs, slog.Any(k, v)) - } - return attrs -} diff --git a/log3/sampler.go b/log3/sampler.go new file mode 100644 index 0000000..9779e42 --- /dev/null +++ b/log3/sampler.go @@ -0,0 +1,57 @@ +package log3 + +import ( + "context" + "math/rand/v2" + "time" +) + +type Sampler interface { + ShouldSample(ctx context.Context, e *Event) bool +} + +type SamplerFunc func(ctx context.Context, e *Event) bool + +func (f SamplerFunc) ShouldSample(ctx context.Context, e *Event) bool { + return f(ctx, e) +} + +type DefaultSampler struct { + slowThreshold time.Duration + keepHttpStatusAtLeast int + randomKeepRate float64 +} + +func NewDefaultSampler() *DefaultSampler { + return &DefaultSampler{} +} + +func (s *DefaultSampler) ShouldSample(ctx context.Context, e *Event) bool { + if len(e.errors) > 0 { + return true + } + + if e.duration >= s.slowThreshold { + return true + } + + httpStatus := 0 + statusFromMap, exists := e.attrs["request.status"] + if exists { + success := false + httpStatus, success = statusFromMap.(int) + if !success { + httpStatus = 0 + } + } + + if httpStatus >= s.keepHttpStatusAtLeast { + return true + } + + if s.randomKeepRate <= rand.Float64() { + return true + } + + return false +} From aae72ee6838093cf737dade5a7e53f50165bbbc2 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 07:25:17 +0300 Subject: [PATCH 10/38] Delete log2.mdx --- docs/src/content/docs/packages/log2.mdx | 195 ------------------------ 1 file changed, 195 deletions(-) delete mode 100644 docs/src/content/docs/packages/log2.mdx diff --git a/docs/src/content/docs/packages/log2.mdx b/docs/src/content/docs/packages/log2.mdx deleted file mode 100644 index 37cc730..0000000 --- a/docs/src/content/docs/packages/log2.mdx +++ /dev/null @@ -1,195 +0,0 @@ ---- -title: log2 ---- -import { Steps } from '@astrojs/starlight/components'; - -The `log2` package provides wide-event logging with tail sampling, so each operation emits one structured event enriched with timeline steps, errors, and request context. - -Core Components: - -- `Config`: Logger configuration (`Writer`, `Format`, `Level`, `ContextKeys`, `Sampler`, `MaxSteps`). -- `DefaultConfig`: Returns defaults for output format, level, max steps, and sampler settings. -- `Logger`: Wide-event logger instance. -- `New`: Creates a logger from `Config`. -- `SetDefault`: Replaces package-level default logger. -- `Start`: Starts an event (`log2.Start` and `(*Logger).Start`). -- `Event`: Mutable event object. -- `Event.Add`, `Event.Step`, `Event.Error`, `Event.Finish`: Event lifecycle methods. -- `TailSampler`: Sampling interface. -- `SamplingDecision`: Keep/drop decision with reason. -- `EventView`: Immutable event view for sampling. -- `DefaultTailSamplerConfig`: Config for default sampler. -- `KeepRule`: Rule definition for forced-keep sampling. -- `NewDefaultTailSampler`: Builds default rule-based sampler. -- `HTTPMiddlewareConfig`, `NewHTTPMiddleware`: HTTP middleware that creates one event per request. -- `WithEvent`, `EventFromContext`, `LogEventContextKey`: Context helpers. -- `ErrEventAlreadyFinished`: Returned when `Finish` is called more than once. - -[Full package docs at pkg.go.dev](https://pkg.go.dev/github.com/platforma-dev/platforma/log2) - -## Step-by-step guide - - - -1. Create a logger - - ```go - cfg := log2.DefaultConfig() - cfg.Level = slog.LevelInfo - logger := log2.New(cfg) - log2.SetDefault(logger) - ``` - - `DefaultConfig` includes: - - - `Format: "json"` - - Default tail sampler (keep errors, 5xx, slow events, and a random sample) - - `MaxSteps: 100` - -2. Start and enrich an event - - ```go - ev := logger.Start(ctx, "auth_request", "component", "handler") - ev.Add("userId", "u-123") - ev.Step(slog.LevelInfo, "credentials_validated", "provider", "password") - ``` - - `Add` merges persistent attributes. `Step` appends timeline entries. - -3. Record errors and finish - - ```go - if err != nil { - ev.Error(err, "stage", "db_lookup") - } - - if finishErr := ev.Finish("status", 200); finishErr != nil { - if errors.Is(finishErr, log2.ErrEventAlreadyFinished) { - // finish was called twice - } - } - ``` - - `Finish` evaluates sampling using event status, duration, errors, and attributes. - -4. Configure custom tail sampling rules - - ```go - cfg := log2.DefaultConfig() - cfg.Sampler = log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ - KeepRules: []log2.KeepRule{ - {Field: "attrs.feature", Op: "eq", Value: "change_password"}, - {Field: "queue", Op: "in", Value: []string{"billing", "emails"}}, - {Field: "vip", Op: "exists"}, - {Field: "security.risk", Op: "true"}, - }, - RandomKeepRate: 0.01, - }) - logger := log2.New(cfg) - ``` - - Supported rule operators are `eq`, `in`, `exists`, and `true`. - -5. Add HTTP middleware and use event from request context - - ```go - logger := log2.New(log2.DefaultConfig()) - middleware := log2.NewHTTPMiddleware(logger, log2.HTTPMiddlewareConfig{ - EventName: "http_request", - RouteAttr: "route", - }) - - mux := http.NewServeMux() - mux.HandleFunc("/ping", func(w http.ResponseWriter, r *http.Request) { - if ev, ok := log2.EventFromContext(r.Context()); ok { - ev.Step(slog.LevelInfo, "handler_started", "path", r.URL.Path) - } - - w.WriteHeader(http.StatusOK) - _, _ = w.Write([]byte("pong")) - }) - - handler := middleware(mux) - _ = handler - ``` - - Middleware stores the event in context using `WithEvent`, collects request/response metadata, and calls `Finish` automatically. - - - -## Behavior notes - -- `Finish` called twice returns `ErrEventAlreadyFinished`. -- Event log level is inferred: - - `ERROR` for event errors or 5xx status. - - `WARN` for 4xx status. - - `INFO` otherwise. -- Status is inferred from `status`, `statusCode`, `response.status`, or `response.status` inside a `response` map. -- If steps exceed `MaxSteps`, extra steps are dropped and counted in `stepsDropped`. - -## Integration with `log` context keys - -`log2.Start` extracts known context values from the `log` package and includes them in event attributes when present: - -- `traceId` -- `serviceName` -- `domainName` -- `startupTask` -- `userId` -- `workerId` - -This allows `log2` events to align with existing `log` and `httpserver` context propagation. - -## Complete example - -```go -package main - -import ( - "context" - "errors" - "log/slog" - "net/http" - "os" - "time" - - "github.com/platforma-dev/platforma/log2" -) - -func main() { - cfg := log2.DefaultConfig() - cfg.Writer = os.Stdout - cfg.Level = slog.LevelInfo - cfg.Sampler = log2.NewDefaultTailSampler(log2.DefaultTailSamplerConfig{ - SlowThreshold: 500 * time.Millisecond, - RandomKeepRate: 0.02, - }) - - logger := log2.New(cfg) - middleware := log2.NewHTTPMiddleware(logger, log2.HTTPMiddlewareConfig{}) - - mux := http.NewServeMux() - mux.HandleFunc("/users", func(w http.ResponseWriter, r *http.Request) { - ev, ok := log2.EventFromContext(r.Context()) - if ok { - ev.Step(slog.LevelInfo, "fetch_users_started") - defer func() { - if err := ev.Finish("status", http.StatusOK); err != nil && !errors.Is(err, log2.ErrEventAlreadyFinished) { - // Handle finish error. - } - }() - } - - w.WriteHeader(http.StatusOK) - _, _ = w.Write([]byte(`{"users":[]}`)) - }) - - server := &http.Server{ - Addr: ":8080", - Handler: middleware(mux), - } - - _ = server.ListenAndServe() - _ = server.Shutdown(context.Background()) -} -``` From 0192a5f46353d584fddd32e127deb99573300300 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 08:24:35 +0300 Subject: [PATCH 11/38] demo --- demo-app/cmd/wide-events/main.go | 31 +++++++++++++++++++++++++ log3/event.go | 40 +++++++++++++++++++++----------- log3/sampler.go | 8 +++++-- 3 files changed, 63 insertions(+), 16 deletions(-) create mode 100644 demo-app/cmd/wide-events/main.go diff --git a/demo-app/cmd/wide-events/main.go b/demo-app/cmd/wide-events/main.go new file mode 100644 index 0000000..932a7ee --- /dev/null +++ b/demo-app/cmd/wide-events/main.go @@ -0,0 +1,31 @@ +package main + +import ( + "context" + "errors" + "log/slog" + "os" + "time" + + "github.com/platforma-dev/platforma/log3" +) + +func main() { + logger := log3.NewWideEventLogger( + os.Stdout, + log3.NewDefaultSampler(3*time.Second, 200, 0.1), + "text", + nil, + ) + + ev := log3.NewEvent("test_event") + + ev.AddStep(slog.LevelInfo, "some step") + ev.AddError(errors.New("some error")) + ev.AddAttrs(map[string]any{ + "attr1": 1, + "attr2": true, + }) + + logger.WriteEvent(context.Background(), ev) +} diff --git a/log3/event.go b/log3/event.go index 8e31e87..1519218 100644 --- a/log3/event.go +++ b/log3/event.go @@ -19,8 +19,9 @@ type Event struct { errors []errorRecord } -func NewEvent() *Event { +func NewEvent(name string) *Event { return &Event{ + name: name, timestamp: time.Now(), level: slog.LevelDebug, attrs: map[string]any{}, @@ -31,6 +32,10 @@ func (e *Event) SetLevel(level slog.Level) { e.mu.Lock() defer e.mu.Unlock() + e.setLevelNoLock(level) +} + +func (e *Event) setLevelNoLock(level slog.Level) { if level > e.level { e.level = level } @@ -47,12 +52,12 @@ func (e *Event) AddStep(level slog.Level, name string) { e.mu.Lock() defer e.mu.Unlock() - e.SetLevel(level) + e.setLevelNoLock(level) e.steps = append(e.steps, stepRecord{ - timestamp: time.Now(), - level: level, - name: name, + Timestamp: time.Now(), + Level: level, + Name: name, }) } @@ -60,11 +65,11 @@ func (e *Event) AddError(err error) { e.mu.Lock() defer e.mu.Unlock() - e.SetLevel(slog.LevelError) + e.setLevelNoLock(slog.LevelError) e.errors = append(e.errors, errorRecord{ - timestamp: time.Now(), - err: err, + Timestamp: time.Now(), + Error: err.Error(), }) } @@ -84,7 +89,6 @@ func (e *Event) ToAttrs() []slog.Attr { return []slog.Attr{ slog.String("name", e.name), slog.Time("timestamp", e.timestamp), - slog.Int("level", int(e.level)), slog.Duration("duration", e.duration), slog.Any("attrs", e.attrs), slog.Any("steps", e.steps), @@ -93,12 +97,20 @@ func (e *Event) ToAttrs() []slog.Attr { } type stepRecord struct { - timestamp time.Time - level slog.Level - name string + Timestamp time.Time `json:"timestamp"` + Level slog.Level `json:"level"` + Name string `json:"name"` +} + +func (r stepRecord) LogValue() slog.Value { + return slog.GroupValue( + slog.Time("timestamp", r.Timestamp), + slog.String("name", r.Name), + slog.String("level", r.Level.String()), + ) } type errorRecord struct { - timestamp time.Time - err error + Timestamp time.Time `json:"timestamp"` + Error string `json:"error"` } diff --git a/log3/sampler.go b/log3/sampler.go index 9779e42..61518c7 100644 --- a/log3/sampler.go +++ b/log3/sampler.go @@ -22,8 +22,12 @@ type DefaultSampler struct { randomKeepRate float64 } -func NewDefaultSampler() *DefaultSampler { - return &DefaultSampler{} +func NewDefaultSampler(slowThreshold time.Duration, keepHttpStatusAtLeast int, randomKeepRate float64) *DefaultSampler { + return &DefaultSampler{ + slowThreshold: slowThreshold, + keepHttpStatusAtLeast: keepHttpStatusAtLeast, + randomKeepRate: randomKeepRate, + } } func (s *DefaultSampler) ShouldSample(ctx context.Context, e *Event) bool { From 8bb29621ad0b70d0716ca29de99c393d0b13a599 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 08:30:45 +0300 Subject: [PATCH 12/38] Update astro.config.mjs --- docs/astro.config.mjs | 1 - 1 file changed, 1 deletion(-) diff --git a/docs/astro.config.mjs b/docs/astro.config.mjs index 6d34fe8..811882f 100644 --- a/docs/astro.config.mjs +++ b/docs/astro.config.mjs @@ -28,7 +28,6 @@ export default defineConfig({ "packages/database", "packages/httpserver", "packages/log", - "packages/log2", "packages/queue", "packages/scheduler", "packages/auth", From 233777170c8b2328bd068b08142c6f5f4f2fced8 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 08:31:11 +0300 Subject: [PATCH 13/38] better case from log attrs --- demo-app/cmd/wide-events/main.go | 2 +- log3/event.go | 19 +++++++++++++++++-- 2 files changed, 18 insertions(+), 3 deletions(-) diff --git a/demo-app/cmd/wide-events/main.go b/demo-app/cmd/wide-events/main.go index 932a7ee..5d802bd 100644 --- a/demo-app/cmd/wide-events/main.go +++ b/demo-app/cmd/wide-events/main.go @@ -14,7 +14,7 @@ func main() { logger := log3.NewWideEventLogger( os.Stdout, log3.NewDefaultSampler(3*time.Second, 200, 0.1), - "text", + "json", nil, ) diff --git a/log3/event.go b/log3/event.go index 1519218..e2da8ba 100644 --- a/log3/event.go +++ b/log3/event.go @@ -85,14 +85,29 @@ func (e *Event) ToAttrs() []slog.Attr { defer e.mu.Unlock() e.duration = time.Since(e.timestamp) + steps := make([]map[string]any, 0, len(e.steps)) + for _, step := range e.steps { + steps = append(steps, map[string]any{ + "timestamp": step.Timestamp, + "level": step.Level.String(), + "name": step.Name, + }) + } + eventErrors := make([]map[string]any, 0, len(e.errors)) + for _, eventError := range e.errors { + eventErrors = append(eventErrors, map[string]any{ + "timestamp": eventError.Timestamp, + "error": eventError.Error, + }) + } return []slog.Attr{ slog.String("name", e.name), slog.Time("timestamp", e.timestamp), slog.Duration("duration", e.duration), slog.Any("attrs", e.attrs), - slog.Any("steps", e.steps), - slog.Any("errors", e.errors), + slog.Any("steps", steps), + slog.Any("errors", eventErrors), } } From 11861ff571dec349ffd83fa4b274c587d4dfeb5e Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 20:11:01 +0300 Subject: [PATCH 14/38] Move trace id middleware to log package --- demo-app/cmd/api/main.go | 2 +- demo-app/cmd/auth/main.go | 2 +- {httpserver => log}/traceid.go | 12 +++++------- {httpserver => log}/traceid_test.go | 18 ++++++++---------- 4 files changed, 15 insertions(+), 19 deletions(-) rename {httpserver => log}/traceid.go (71%) rename {httpserver => log}/traceid_test.go (55%) diff --git a/demo-app/cmd/api/main.go b/demo-app/cmd/api/main.go index 7fc3432..c17208f 100644 --- a/demo-app/cmd/api/main.go +++ b/demo-app/cmd/api/main.go @@ -31,7 +31,7 @@ func main() { }) // Add middleware to HTTP server. It will add trace ID to logs and responce headers - api.Use(httpserver.NewTraceIDMiddleware(nil, "")) + api.Use(log.NewTraceIDMiddleware(nil, "")) // Create handler group subApiGroup := httpserver.NewHandlerGroup() diff --git a/demo-app/cmd/auth/main.go b/demo-app/cmd/auth/main.go index a2d8c25..9215b10 100644 --- a/demo-app/cmd/auth/main.go +++ b/demo-app/cmd/auth/main.go @@ -31,7 +31,7 @@ func main() { app.RegisterDomain("auth", "main", authDomain) api := httpserver.New("8080", 3*time.Second) - api.Use(httpserver.NewTraceIDMiddleware(nil, "")) + api.Use(log.NewTraceIDMiddleware(nil, "")) api.Use(httpserver.NewRecoverMiddleware()) api.HandleGroup("/auth", authDomain.HandleGroup) diff --git a/httpserver/traceid.go b/log/traceid.go similarity index 71% rename from httpserver/traceid.go rename to log/traceid.go index ad1f744..24f08a6 100644 --- a/httpserver/traceid.go +++ b/log/traceid.go @@ -1,26 +1,24 @@ -package httpserver +package log import ( "context" "net/http" - "github.com/platforma-dev/platforma/log" - "github.com/google/uuid" ) -// TraceIDMiddleware is a middleware that adds a trace ID to the request context and response headers. +// TraceIDMiddleware adds a trace ID to request context and response headers. type TraceIDMiddleware struct { contextKey any header string } // NewTraceIDMiddleware returns a new TraceID middleware. -// If key is nil, log.TraceIdKey is used. +// If key is nil, TraceIDKey is used. // If header is empty, "Platforma-Trace-Id" is used. func NewTraceIDMiddleware(contextKey any, header string) *TraceIDMiddleware { if contextKey == nil { - contextKey = log.TraceIDKey + contextKey = TraceIDKey } if header == "" { @@ -30,7 +28,7 @@ func NewTraceIDMiddleware(contextKey any, header string) *TraceIDMiddleware { return &TraceIDMiddleware{contextKey: contextKey, header: header} } -// Wrap implements the Middleware interface by adding trace ID to requests. +// Wrap adds trace ID to requests. func (m *TraceIDMiddleware) Wrap(h http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { traceID := uuid.NewString() diff --git a/httpserver/traceid_test.go b/log/traceid_test.go similarity index 55% rename from httpserver/traceid_test.go rename to log/traceid_test.go index ed65bd6..29263ff 100644 --- a/httpserver/traceid_test.go +++ b/log/traceid_test.go @@ -1,27 +1,26 @@ -package httpserver_test +package log_test import ( "net/http" "net/http/httptest" "testing" - "github.com/platforma-dev/platforma/httpserver" - "github.com/platforma-dev/platforma/log" + platformalog "github.com/platforma-dev/platforma/log" ) -func TestTraceIdMiddleware(t *testing.T) { +func TestTraceIDMiddleware(t *testing.T) { t.Parallel() t.Run("default params", func(t *testing.T) { t.Parallel() - m := httpserver.NewTraceIDMiddleware(nil, "") - wrappedHandler := m.Wrap(&handler{serveHTTP: func(w http.ResponseWriter, r *http.Request) { - i, ok := r.Context().Value(log.TraceIDKey).(string) + m := platformalog.NewTraceIDMiddleware(nil, "") + wrappedHandler := m.Wrap(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + i, ok := r.Context().Value(platformalog.TraceIDKey).(string) if ok { w.Header().Add("TraceIdFromContext", i) } - }}) + })) r := httptest.NewRequest(http.MethodGet, "/", nil) w := httptest.NewRecorder() @@ -34,8 +33,7 @@ func TestTraceIdMiddleware(t *testing.T) { } if len(resp.Header.Get("TraceIdFromContext")) == 0 { - t.Fatalf("trsce id from cotext expected, got: %s", resp.Header) + t.Fatalf("trace id from context expected, got: %s", resp.Header) } - }) } From 1e6c00bf0c44c7426980bec460c76c43b8eb25ec Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 20:22:58 +0300 Subject: [PATCH 15/38] Merge log3 into log package --- demo-app/cmd/wide-events/main.go | 8 +- {log3 => log}/event.go | 12 +- {log3 => log}/sampler.go | 14 +- log/welogger.go | 30 +++ log2/config.go | 42 ---- log2/context.go | 31 --- log2/event.go | 349 ------------------------------- log2/logger.go | 124 ----------- log2/middleware.go | 99 --------- log2/sampling.go | 204 ------------------ log3/logger.go | 30 --- 11 files changed, 55 insertions(+), 888 deletions(-) rename {log3 => log}/event.go (85%) rename {log3 => log}/sampler.go (67%) create mode 100644 log/welogger.go delete mode 100644 log2/config.go delete mode 100644 log2/context.go delete mode 100644 log2/event.go delete mode 100644 log2/logger.go delete mode 100644 log2/middleware.go delete mode 100644 log2/sampling.go delete mode 100644 log3/logger.go diff --git a/demo-app/cmd/wide-events/main.go b/demo-app/cmd/wide-events/main.go index 5d802bd..b3701d9 100644 --- a/demo-app/cmd/wide-events/main.go +++ b/demo-app/cmd/wide-events/main.go @@ -7,18 +7,18 @@ import ( "os" "time" - "github.com/platforma-dev/platforma/log3" + "github.com/platforma-dev/platforma/log" ) func main() { - logger := log3.NewWideEventLogger( + logger := log.NewWideEventLogger( os.Stdout, - log3.NewDefaultSampler(3*time.Second, 200, 0.1), + log.NewDefaultSampler(3*time.Second, 200, 0.1), "json", nil, ) - ev := log3.NewEvent("test_event") + ev := log.NewEvent("test_event") ev.AddStep(slog.LevelInfo, "some step") ev.AddError(errors.New("some error")) diff --git a/log3/event.go b/log/event.go similarity index 85% rename from log3/event.go rename to log/event.go index e2da8ba..bacb265 100644 --- a/log3/event.go +++ b/log/event.go @@ -1,4 +1,4 @@ -package log3 +package log import ( "log/slog" @@ -7,6 +7,7 @@ import ( "time" ) +// Event is a mutable wide event. type Event struct { mu sync.Mutex @@ -19,6 +20,7 @@ type Event struct { errors []errorRecord } +// NewEvent creates a new wide event. func NewEvent(name string) *Event { return &Event{ name: name, @@ -28,6 +30,7 @@ func NewEvent(name string) *Event { } } +// SetLevel sets event level if it is higher than the current one. func (e *Event) SetLevel(level slog.Level) { e.mu.Lock() defer e.mu.Unlock() @@ -41,6 +44,7 @@ func (e *Event) setLevelNoLock(level slog.Level) { } } +// AddAttrs adds attributes to event data. func (e *Event) AddAttrs(attrs map[string]any) { e.mu.Lock() defer e.mu.Unlock() @@ -48,6 +52,7 @@ func (e *Event) AddAttrs(attrs map[string]any) { maps.Copy(e.attrs, attrs) } +// AddStep appends an event step and potentially escalates level. func (e *Event) AddStep(level slog.Level, name string) { e.mu.Lock() defer e.mu.Unlock() @@ -61,6 +66,7 @@ func (e *Event) AddStep(level slog.Level, name string) { }) } +// AddError appends an error and escalates event level to error. func (e *Event) AddError(err error) { e.mu.Lock() defer e.mu.Unlock() @@ -73,6 +79,7 @@ func (e *Event) AddError(err error) { }) } +// Finish stores current event duration. func (e *Event) Finish() { e.mu.Lock() defer e.mu.Unlock() @@ -80,11 +87,13 @@ func (e *Event) Finish() { e.duration = time.Since(e.timestamp) } +// ToAttrs converts event to slog attributes. func (e *Event) ToAttrs() []slog.Attr { e.mu.Lock() defer e.mu.Unlock() e.duration = time.Since(e.timestamp) + steps := make([]map[string]any, 0, len(e.steps)) for _, step := range e.steps { steps = append(steps, map[string]any{ @@ -93,6 +102,7 @@ func (e *Event) ToAttrs() []slog.Attr { "name": step.Name, }) } + eventErrors := make([]map[string]any, 0, len(e.errors)) for _, eventError := range e.errors { eventErrors = append(eventErrors, map[string]any{ diff --git a/log3/sampler.go b/log/sampler.go similarity index 67% rename from log3/sampler.go rename to log/sampler.go index 61518c7..c3523c6 100644 --- a/log3/sampler.go +++ b/log/sampler.go @@ -1,4 +1,4 @@ -package log3 +package log import ( "context" @@ -6,30 +6,36 @@ import ( "time" ) +// Sampler decides whether a wide event should be emitted. type Sampler interface { ShouldSample(ctx context.Context, e *Event) bool } +// SamplerFunc is a function adapter for Sampler. type SamplerFunc func(ctx context.Context, e *Event) bool +// ShouldSample implements Sampler. func (f SamplerFunc) ShouldSample(ctx context.Context, e *Event) bool { return f(ctx, e) } +// DefaultSampler samples by error, duration, status code, and random keep rate. type DefaultSampler struct { slowThreshold time.Duration keepHttpStatusAtLeast int randomKeepRate float64 } -func NewDefaultSampler(slowThreshold time.Duration, keepHttpStatusAtLeast int, randomKeepRate float64) *DefaultSampler { +// NewDefaultSampler creates a rule-based sampler. +func NewDefaultSampler(slowThreshold time.Duration, keepHTTPStatusAtLeast int, randomKeepRate float64) *DefaultSampler { return &DefaultSampler{ slowThreshold: slowThreshold, - keepHttpStatusAtLeast: keepHttpStatusAtLeast, + keepHttpStatusAtLeast: keepHTTPStatusAtLeast, randomKeepRate: randomKeepRate, } } +// ShouldSample decides if event should be logged. func (s *DefaultSampler) ShouldSample(ctx context.Context, e *Event) bool { if len(e.errors) > 0 { return true @@ -53,7 +59,7 @@ func (s *DefaultSampler) ShouldSample(ctx context.Context, e *Event) bool { return true } - if s.randomKeepRate <= rand.Float64() { + if rand.Float64() < s.randomKeepRate { return true } diff --git a/log/welogger.go b/log/welogger.go new file mode 100644 index 0000000..a91312c --- /dev/null +++ b/log/welogger.go @@ -0,0 +1,30 @@ +package log + +import ( + "context" + "io" + "log/slog" +) + +// WideEventLogger writes wide events with tail sampling. +type WideEventLogger struct { + sampler Sampler + logger *slog.Logger +} + +// NewWideEventLogger creates a wide-event logger. +func NewWideEventLogger(w io.Writer, s Sampler, loggerType string, contextKeys map[string]any) *WideEventLogger { + return &WideEventLogger{ + sampler: s, + logger: New(w, loggerType, slog.LevelDebug, contextKeys), + } +} + +// WriteEvent finalizes event duration and conditionally writes it. +func (l *WideEventLogger) WriteEvent(ctx context.Context, e *Event) { + e.Finish() + + if l.sampler.ShouldSample(ctx, e) { + l.logger.LogAttrs(ctx, e.level, "", e.ToAttrs()...) + } +} diff --git a/log2/config.go b/log2/config.go deleted file mode 100644 index 928449f..0000000 --- a/log2/config.go +++ /dev/null @@ -1,42 +0,0 @@ -// Package log2 provides wide-event logging with tail sampling. -package log2 - -import ( - "io" - "log/slog" - "os" - "time" -) - -const ( - defaultFormat = "json" - defaultKeepStatus = 500 - defaultMaxSteps = 100 - defaultRandomKeepRate = 0.05 - defaultSlowThreshold = 2 * time.Second -) - -// Config configures logger behavior. -type Config struct { - Writer io.Writer - Format string - Level slog.Level - ContextKeys map[string]any - Sampler TailSampler - MaxSteps int -} - -// DefaultConfig returns default logger configuration. -func DefaultConfig() Config { - return Config{ - Writer: os.Stdout, - Format: defaultFormat, - Level: slog.LevelInfo, - Sampler: NewDefaultTailSampler(DefaultTailSamplerConfig{ - SlowThreshold: defaultSlowThreshold, - RandomKeepRate: defaultRandomKeepRate, - KeepStatusAtLeast: defaultKeepStatus, - }), - MaxSteps: defaultMaxSteps, - } -} diff --git a/log2/context.go b/log2/context.go deleted file mode 100644 index 3a2da4f..0000000 --- a/log2/context.go +++ /dev/null @@ -1,31 +0,0 @@ -package log2 - -import "context" - -type contextKey string - -// LogEventContextKey is used to store Event in context. -const LogEventContextKey contextKey = "platformaLogEvent" - -// EventFromContext gets an event from context. -func EventFromContext(ctx context.Context) (*Event, bool) { - if ctx == nil { - return nil, false - } - - ev, ok := ctx.Value(LogEventContextKey).(*Event) - if !ok || ev == nil { - return nil, false - } - - return ev, true -} - -// WithEvent stores an event in context. -func WithEvent(ctx context.Context, ev *Event) context.Context { - if ctx == nil { - ctx = context.Background() - } - - return context.WithValue(ctx, LogEventContextKey, ev) -} diff --git a/log2/event.go b/log2/event.go deleted file mode 100644 index c9acb56..0000000 --- a/log2/event.go +++ /dev/null @@ -1,349 +0,0 @@ -package log2 - -import ( - "context" - "errors" - "fmt" - "log/slog" - "math" - "strconv" - "sync" - "time" - - "github.com/platforma-dev/platforma/log" -) - -// ErrEventAlreadyFinished means Finish was called more than once. -var ErrEventAlreadyFinished = errors.New("event already finished") - -type stepRecord struct { - ts time.Time - level string - msg string - attrs map[string]any -} - -type errorRecord struct { - ts time.Time - err string - attrs map[string]any -} - -type eventPayload struct { - eventName string - level slog.Level - durationMs int64 - sampled bool - samplingReason string - traceID string - attrs map[string]any - steps []map[string]any - errors []map[string]any - stepsDropped int -} - -// Event is a mutable wide event. -type Event struct { - mu sync.Mutex - - logger *Logger - eventName string - startedAt time.Time - - attrs map[string]any - steps []stepRecord - errors []errorRecord - hasError bool - finished bool - stepsDropped int -} - -// Add adds persistent attributes to the event. -func (e *Event) Add(attrs ...any) { - if e == nil { - return - } - - normalized := normalizeAttrs(attrs...) - - e.mu.Lock() - defer e.mu.Unlock() - - if e.finished { - return - } - - mergeAttrs(e.attrs, normalized) -} - -// Step appends a timeline step to the event. -func (e *Event) Step(level slog.Level, msg string, attrs ...any) { - if e == nil { - return - } - - e.mu.Lock() - defer e.mu.Unlock() - - if e.finished { - return - } - - if len(e.steps) >= e.logger.maxSteps { - e.stepsDropped++ - return - } - - e.steps = append(e.steps, stepRecord{ - ts: time.Now().UTC(), - level: level.String(), - msg: msg, - attrs: normalizeAttrs(attrs...), - }) -} - -// Error appends an error to the event. -func (e *Event) Error(err error, attrs ...any) { - if e == nil || err == nil { - return - } - - e.mu.Lock() - defer e.mu.Unlock() - - if e.finished { - return - } - - e.hasError = true - e.errors = append(e.errors, errorRecord{ - ts: time.Now().UTC(), - err: err.Error(), - attrs: normalizeAttrs(attrs...), - }) -} - -// Finish finalizes and emits the event depending on sampling decision. -func (e *Event) Finish(attrs ...any) error { - if e == nil { - return nil - } - - e.mu.Lock() - if e.finished { - e.mu.Unlock() - return ErrEventAlreadyFinished - } - - mergeAttrs(e.attrs, normalizeAttrs(attrs...)) - - status := 0 - statusFromAttrs, ok := e.attrs["request.status"] - if ok { - status, ok = statusFromAttrs.(int) - if !ok { - status = 0 - } - } - - duration := time.Now().UTC().Sub(e.startedAt) - level := inferLevel(e.hasError) - attrsCopy := copyAttrs(e.attrs) - stepsCopy := copySteps(e.steps) - errorsCopy := copyErrors(e.errors) - stepsDropped := e.stepsDropped - traceID := extractString(attrsCopy, string(log.TraceIDKey)) - - decision := e.logger.sampler.ShouldSample(EventView{ - Status: status, - Duration: duration, - HasError: e.hasError, - Attrs: attrsCopy, - }) - - e.finished = true - logger := e.logger - e.mu.Unlock() - - if !decision.Keep { - return nil - } - - return logger.emit(context.Background(), eventPayload{ - eventName: e.eventName, - level: level, - durationMs: duration.Milliseconds(), - sampled: true, - samplingReason: decision.Reason, - traceID: traceID, - attrs: attrsCopy, - steps: stepsCopy, - errors: errorsCopy, - stepsDropped: stepsDropped, - }) -} - -func collectContextAttrs(ctx context.Context, extraKeys map[string]any) map[string]any { - attrs := map[string]any{} - - defaultKeys := []struct { - name string - key any - }{ - {name: string(log.DomainNameKey), key: log.DomainNameKey}, - {name: string(log.TraceIDKey), key: log.TraceIDKey}, - {name: string(log.ServiceNameKey), key: log.ServiceNameKey}, - {name: string(log.StartupTaskKey), key: log.StartupTaskKey}, - {name: string(log.UserIDKey), key: log.UserIDKey}, - {name: string(log.WorkerIDKey), key: log.WorkerIDKey}, - } - - for _, item := range defaultKeys { - if value := ctx.Value(item.key); value != nil { - attrs[item.name] = value - } - } - - for outputKey, ctxKey := range extraKeys { - if value := ctx.Value(ctxKey); value != nil { - attrs[outputKey] = value - } - } - - return attrs -} - -func normalizeAttrs(attrs ...any) map[string]any { - normalized := make(map[string]any, len(attrs)/2) - - for i := 0; i < len(attrs); i++ { - if attr, ok := attrs[i].(slog.Attr); ok { - normalized[attr.Key] = attr.Value.Any() - continue - } - - if i+1 >= len(attrs) { - break - } - - key := fmt.Sprint(attrs[i]) - normalized[key] = attrs[i+1] - i++ - } - - return normalized -} - -func mergeAttrs(dst map[string]any, src map[string]any) { - for key, value := range src { - dst[key] = value - } -} - -func copyAttrs(src map[string]any) map[string]any { - if src == nil { - return nil - } - - dst := make(map[string]any, len(src)) - for key, value := range src { - dst[key] = value - } - - return dst -} - -func copySteps(src []stepRecord) []map[string]any { - steps := make([]map[string]any, 0, len(src)) - for _, step := range src { - entry := map[string]any{ - "ts": step.ts, - "level": step.level, - "msg": step.msg, - } - mergeAttrs(entry, step.attrs) - steps = append(steps, entry) - } - - return steps -} - -func copyErrors(src []errorRecord) []map[string]any { - errs := make([]map[string]any, 0, len(src)) - for _, item := range src { - entry := map[string]any{ - "ts": item.ts, - "error": item.err, - } - mergeAttrs(entry, item.attrs) - errs = append(errs, entry) - } - - return errs -} - -func inferLevel(hasError bool) slog.Level { - if hasError { - return slog.LevelError - } - - return slog.LevelInfo -} - -func toInt(value any) (int, bool) { - switch typed := value.(type) { - case int: - return typed, true - case int8: - return int(typed), true - case int16: - return int(typed), true - case int32: - return int(typed), true - case int64: - return int(typed), true - case uint: - if typed > uint(math.MaxInt) { - return 0, false - } - return int(typed), true - case uint8: - return int(typed), true - case uint16: - return int(typed), true - case uint32: - return int(typed), true - case uint64: - if typed > uint64(math.MaxInt) { - return 0, false - } - return int(typed), true - case float32: - return int(typed), true - case float64: - return int(typed), true - case string: - parsed, err := strconv.Atoi(typed) - if err != nil { - return 0, false - } - - return parsed, true - default: - return 0, false - } -} - -func extractString(attrs map[string]any, key string) string { - value, ok := attrs[key] - if !ok { - return "" - } - - stringValue, ok := value.(string) - if !ok { - return "" - } - - return stringValue -} diff --git a/log2/logger.go b/log2/logger.go deleted file mode 100644 index 27e77e3..0000000 --- a/log2/logger.go +++ /dev/null @@ -1,124 +0,0 @@ -package log2 - -import ( - "context" - "fmt" - "io" - "log/slog" - "time" -) - -// Logger writes sampled wide events. -type Logger struct { - handler slog.Handler - sampler TailSampler - contextKeys map[string]any - maxSteps int -} - -// Default is package-level default logger. -var Default = New(DefaultConfig()) //nolint:gochecknoglobals - -// New creates a new wide-event logger. -func New(cfg Config) *Logger { - writer := cfg.Writer - if writer == nil { - writer = io.Discard - } - - var handler slog.Handler - if cfg.Format == "text" { - handler = slog.NewTextHandler(writer, &slog.HandlerOptions{Level: cfg.Level}) - } else { - handler = slog.NewJSONHandler(writer, &slog.HandlerOptions{Level: cfg.Level}) - } - - sampler := cfg.Sampler - if sampler == nil { - sampler = NewDefaultTailSampler(DefaultTailSamplerConfig{}) - } - - maxSteps := cfg.MaxSteps - if maxSteps <= 0 { - maxSteps = defaultMaxSteps - } - - return &Logger{ - handler: handler, - sampler: sampler, - contextKeys: copyAttrs(cfg.ContextKeys), - maxSteps: maxSteps, - } -} - -// SetDefault sets the package-level default logger. -func SetDefault(l *Logger) { - if l == nil { - Default = New(DefaultConfig()) - return - } - - Default = l -} - -// Start creates a new event using the package-level default logger. -func Start(ctx context.Context, eventName string, attrs ...any) *Event { - return Default.Start(ctx, eventName, attrs...) -} - -// Start creates a new event using this logger. -func (l *Logger) Start(ctx context.Context, eventName string, attrs ...any) *Event { - if l == nil { - return Default.Start(ctx, eventName, attrs...) - } - - baseAttrs := collectContextAttrs(ctx, l.contextKeys) - mergeAttrs(baseAttrs, normalizeAttrs(attrs...)) - - return &Event{ - logger: l, - eventName: eventName, - startedAt: time.Now().UTC(), - attrs: baseAttrs, - steps: make([]stepRecord, 0), - errors: make([]errorRecord, 0), - } -} - -func (l *Logger) emit(ctx context.Context, event eventPayload) error { - if l == nil { - return nil - } - - if !l.handler.Enabled(ctx, event.level) { - return nil - } - - rec := slog.NewRecord(time.Now().UTC(), event.level, event.eventName, 0) - rec.AddAttrs( - slog.String("event", event.eventName), - slog.Int64("durationMs", event.durationMs), - slog.Bool("sampled", event.sampled), - slog.String("samplingReason", event.samplingReason), - ) - - if event.traceID != "" { - rec.AddAttrs(slog.String("traceId", event.traceID)) - } - - rec.AddAttrs( - slog.Any("attrs", event.attrs), - slog.Any("steps", event.steps), - slog.Any("errors", event.errors), - ) - - if event.stepsDropped > 0 { - rec.AddAttrs(slog.Int("stepsDropped", event.stepsDropped)) - } - - if err := l.handler.Handle(ctx, rec); err != nil { - return fmt.Errorf("failed to write log event: %w", err) - } - - return nil -} diff --git a/log2/middleware.go b/log2/middleware.go deleted file mode 100644 index a47624a..0000000 --- a/log2/middleware.go +++ /dev/null @@ -1,99 +0,0 @@ -package log2 - -import ( - "errors" - "fmt" - "net/http" -) - -var errPanicRecovered = errors.New("panic recovered") //nolint:gochecknoglobals - -// HTTPMiddlewareConfig configures wide-event HTTP middleware. -type HTTPMiddlewareConfig struct { - EventName string - RouteAttr string -} - -// NewHTTPMiddleware creates middleware that builds one wide event per request. -func NewHTTPMiddleware(l *Logger, cfg HTTPMiddlewareConfig) func(http.Handler) http.Handler { - logger := l - if logger == nil { - logger = Default - } - - eventName := cfg.EventName - if eventName == "" { - eventName = "http_request" - } - - routeAttr := cfg.RouteAttr - if routeAttr == "" { - routeAttr = "route" - } - - return func(next http.Handler) http.Handler { - return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - ev := logger.Start(r.Context(), eventName) - ctx := WithEvent(r.Context(), ev) - r = r.WithContext(ctx) - - rec := &statusRecorder{ResponseWriter: w, status: http.StatusOK} - - defer func() { - panicValue := recover() - - route := r.Pattern - if route == "" { - route = r.URL.Path - } - - requestAttrs := map[string]any{ - "method": r.Method, - "path": r.URL.Path, - "route": route, - "remoteAddr": r.RemoteAddr, - } - responseAttrs := map[string]any{ - "status": rec.status, - "bytes": rec.bytes, - } - - ev.Add( - "request", requestAttrs, - "response", responseAttrs, - routeAttr, route, - ) - - if panicValue != nil { - ev.Error(fmt.Errorf("%w: %v", errPanicRecovered, panicValue)) - } - - _ = ev.Finish("status", rec.status) - - if panicValue != nil { - panic(panicValue) - } - }() - - next.ServeHTTP(rec, r) - }) - } -} - -type statusRecorder struct { - http.ResponseWriter - status int - bytes int -} - -func (r *statusRecorder) WriteHeader(statusCode int) { - r.status = statusCode - r.ResponseWriter.WriteHeader(statusCode) -} - -func (r *statusRecorder) Write(body []byte) (int, error) { - bytesWritten, err := r.ResponseWriter.Write(body) - r.bytes += bytesWritten - //nolint:wrapcheck // preserve exact error semantics from wrapped ResponseWriter. - return bytesWritten, err -} diff --git a/log2/sampling.go b/log2/sampling.go deleted file mode 100644 index 98cd363..0000000 --- a/log2/sampling.go +++ /dev/null @@ -1,204 +0,0 @@ -package log2 - -import ( - "math/rand" - "reflect" - "strings" - "time" -) - -// TailSampler decides whether a finished event should be emitted. -type TailSampler interface { - ShouldSample(EventView) SamplingDecision -} - -// SamplingDecision is the sampler decision. -type SamplingDecision struct { - Keep bool - Reason string -} - -// EventView is immutable event information for sampling. -type EventView struct { - Status int - Duration time.Duration - HasError bool - Attrs map[string]any -} - -// DefaultTailSamplerConfig configures the default tail sampler. -type DefaultTailSamplerConfig struct { - SlowThreshold time.Duration - RandomKeepRate float64 - KeepStatusAtLeast int - KeepRules []KeepRule - RandomFloat func() float64 -} - -// KeepRule defines a forced-keep rule. -type KeepRule struct { - Field string - Op string - Value any -} - -type defaultTailSampler struct { - slowThreshold time.Duration - randomKeepRate float64 - keepStatusAtLeast int - keepRules []KeepRule - randomFloat func() float64 -} - -// NewDefaultTailSampler creates a rule-based tail sampler. -// -//nolint:iface // public API returns TailSampler to allow custom implementations. -func NewDefaultTailSampler(cfg DefaultTailSamplerConfig) TailSampler { - slowThreshold := cfg.SlowThreshold - if slowThreshold <= 0 { - slowThreshold = defaultSlowThreshold - } - - keepStatusAtLeast := cfg.KeepStatusAtLeast - if keepStatusAtLeast <= 0 { - keepStatusAtLeast = defaultKeepStatus - } - - randomKeepRate := cfg.RandomKeepRate - if randomKeepRate <= 0 { - randomKeepRate = defaultRandomKeepRate - } - if randomKeepRate > 1 { - randomKeepRate = 1 - } - - randomFloat := cfg.RandomFloat - if randomFloat == nil { - randomFloat = rand.Float64 - } - - keepRules := make([]KeepRule, len(cfg.KeepRules)) - copy(keepRules, cfg.KeepRules) - - return &defaultTailSampler{ - slowThreshold: slowThreshold, - randomKeepRate: randomKeepRate, - keepStatusAtLeast: keepStatusAtLeast, - keepRules: keepRules, - randomFloat: randomFloat, - } -} - -func (s *defaultTailSampler) ShouldSample(view EventView) SamplingDecision { - if view.HasError { - return SamplingDecision{Keep: true, Reason: "error"} - } - - if view.Status >= s.keepStatusAtLeast { - return SamplingDecision{Keep: true, Reason: "status"} - } - - if view.Duration >= s.slowThreshold { - return SamplingDecision{Keep: true, Reason: "slow"} - } - - for _, rule := range s.keepRules { - if ruleMatches(view.Attrs, rule) { - return SamplingDecision{Keep: true, Reason: "rule"} - } - } - - if s.randomFloat() < s.randomKeepRate { - return SamplingDecision{Keep: true, Reason: "random"} - } - - return SamplingDecision{Keep: false, Reason: "drop"} -} - -func ruleMatches(attrs map[string]any, rule KeepRule) bool { - value, exists := lookupPath(attrs, rule.Field) - - switch strings.ToLower(rule.Op) { - case "eq": - if !exists { - return false - } - return valuesEqual(value, rule.Value) - case "in": - if !exists { - return false - } - return valueIn(value, rule.Value) - case "exists": - return exists - case "true": - if !exists { - return false - } - boolValue, ok := value.(bool) - return ok && boolValue - default: - return false - } -} - -func lookupPath(attrs map[string]any, path string) (any, bool) { - if attrs == nil { - return nil, false - } - - if direct, ok := attrs[path]; ok { - return direct, true - } - - current := any(attrs) - for _, part := range strings.Split(path, ".") { - asMap, ok := current.(map[string]any) - if !ok { - return nil, false - } - - next, ok := asMap[part] - if !ok { - return nil, false - } - - current = next - } - - return current, true -} - -func valueIn(value any, candidates any) bool { - candidateValue := reflect.ValueOf(candidates) - if !candidateValue.IsValid() { - return false - } - - kind := candidateValue.Kind() - if kind != reflect.Slice && kind != reflect.Array { - return false - } - - for i := range candidateValue.Len() { - if valuesEqual(value, candidateValue.Index(i).Interface()) { - return true - } - } - - return false -} - -func valuesEqual(a any, b any) bool { - if reflect.DeepEqual(a, b) { - return true - } - - ai, aok := toInt(a) - bi, bok := toInt(b) - if aok && bok { - return ai == bi - } - - return false -} diff --git a/log3/logger.go b/log3/logger.go deleted file mode 100644 index 00b5404..0000000 --- a/log3/logger.go +++ /dev/null @@ -1,30 +0,0 @@ -package log3 - -import ( - "context" - "io" - "log/slog" - - "github.com/platforma-dev/platforma/log" -) - -type Logger struct { - w io.Writer - sampler Sampler - logger *slog.Logger -} - -func NewWideEventLogger(w io.Writer, s Sampler, loggerType string, contextKeys map[string]any) *Logger { - return &Logger{ - sampler: s, - logger: log.New(w, loggerType, slog.LevelDebug, contextKeys), - } -} - -func (l *Logger) WriteEvent(ctx context.Context, e *Event) { - e.Finish() - - if l.sampler.ShouldSample(ctx, e) { - l.logger.LogAttrs(ctx, e.level, "", e.ToAttrs()...) - } -} From ad00c58f16d6d1c1f85b02062b6f66251460c842 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 20:30:21 +0300 Subject: [PATCH 16/38] Remove default time from wide logs --- log/welogger.go | 19 ++++++++++++++++++- 1 file changed, 18 insertions(+), 1 deletion(-) diff --git a/log/welogger.go b/log/welogger.go index a91312c..1298753 100644 --- a/log/welogger.go +++ b/log/welogger.go @@ -14,9 +14,26 @@ type WideEventLogger struct { // NewWideEventLogger creates a wide-event logger. func NewWideEventLogger(w io.Writer, s Sampler, loggerType string, contextKeys map[string]any) *WideEventLogger { + opts := &slog.HandlerOptions{ + Level: slog.LevelDebug, + ReplaceAttr: func(_ []string, a slog.Attr) slog.Attr { + if a.Key == slog.TimeKey { + return slog.Attr{} + } + return a + }, + } + + var handler slog.Handler + if loggerType == "json" { + handler = slog.NewJSONHandler(w, opts) + } else { + handler = slog.NewTextHandler(w, opts) + } + return &WideEventLogger{ sampler: s, - logger: New(w, loggerType, slog.LevelDebug, contextKeys), + logger: slog.New(&contextHandler{handler, contextKeys}), } } From 94267b3d8e9a7e9aadb7dc2e151d229dd4cde4a5 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 20:55:33 +0300 Subject: [PATCH 17/38] Add wide event middleware --- log/event_context.go | 18 +++++++ log/wideevent_middleware.go | 95 +++++++++++++++++++++++++++++++++++++ 2 files changed, 113 insertions(+) create mode 100644 log/event_context.go create mode 100644 log/wideevent_middleware.go diff --git a/log/event_context.go b/log/event_context.go new file mode 100644 index 0000000..ebe0b6d --- /dev/null +++ b/log/event_context.go @@ -0,0 +1,18 @@ +package log + +import "context" + +const ( + // WideEventKey is the default context key for request-wide events. + WideEventKey contextKey = "wideEvent" +) + +// EventFromContext returns a wide event from context when present. +func EventFromContext(ctx context.Context) *Event { + event, ok := ctx.Value(WideEventKey).(*Event) + if !ok { + return nil + } + + return event +} diff --git a/log/wideevent_middleware.go b/log/wideevent_middleware.go new file mode 100644 index 0000000..35005be --- /dev/null +++ b/log/wideevent_middleware.go @@ -0,0 +1,95 @@ +package log + +import ( + "context" + "fmt" + "net/http" +) + +const defaultWideEventName = "http.request" + +// WideEventMiddleware creates and writes a request-wide event. +type WideEventMiddleware struct { + logger *WideEventLogger + eventName string + contextKey any +} + +// NewWideEventMiddleware creates middleware that stores a wide event in request context +// and writes it after request processing. +func NewWideEventMiddleware(logger *WideEventLogger, eventName string, contextKey any) *WideEventMiddleware { + if eventName == "" { + eventName = defaultWideEventName + } + + if contextKey == nil { + contextKey = WideEventKey + } + + return &WideEventMiddleware{ + logger: logger, + eventName: eventName, + contextKey: contextKey, + } +} + +// Wrap creates request-wide event, stores it in context and writes event after handling. +func (m *WideEventMiddleware) Wrap(next http.Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + event := NewEvent(m.eventName) + event.AddAttrs(map[string]any{ + "request.method": r.Method, + "request.path": r.URL.Path, + "request.remoteAddr": r.RemoteAddr, + }) + + ctx := context.WithValue(r.Context(), m.contextKey, event) + r = r.WithContext(ctx) + + recorder := &statusResponseWriter{ + ResponseWriter: w, + statusCode: http.StatusOK, + } + + defer func() { + recovered := recover() + if recovered != nil { + event.AddError(fmt.Errorf("panic: %v", recovered)) + if !recorder.wroteHeader { + recorder.statusCode = http.StatusInternalServerError + } + } + + event.AddAttrs(map[string]any{ + "request.status": recorder.statusCode, + }) + m.logger.WriteEvent(ctx, event) + + if recovered != nil { + panic(recovered) + } + }() + + next.ServeHTTP(recorder, r) + }) +} + +type statusResponseWriter struct { + http.ResponseWriter + statusCode int + wroteHeader bool +} + +func (w *statusResponseWriter) WriteHeader(statusCode int) { + w.statusCode = statusCode + w.wroteHeader = true + w.ResponseWriter.WriteHeader(statusCode) +} + +func (w *statusResponseWriter) Write(p []byte) (int, error) { + if !w.wroteHeader { + w.WriteHeader(http.StatusOK) + } + + return w.ResponseWriter.Write(p) +} From 0e4f171dca92eec435ddba33bf5390dec3500a9d Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 20:56:44 +0300 Subject: [PATCH 18/38] rename --- log/{welogger.go => wideevent_logger.go} | 0 1 file changed, 0 insertions(+), 0 deletions(-) rename log/{welogger.go => wideevent_logger.go} (100%) diff --git a/log/welogger.go b/log/wideevent_logger.go similarity index 100% rename from log/welogger.go rename to log/wideevent_logger.go From 51e3ea4ca7316ca9e41df141052b5088d4be48c2 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:04:25 +0300 Subject: [PATCH 19/38] fix linter error --- log/sampler.go | 18 ++++++++---------- log/wideevent_middleware.go | 12 ++++++++++-- 2 files changed, 18 insertions(+), 12 deletions(-) diff --git a/log/sampler.go b/log/sampler.go index c3523c6..a03e34b 100644 --- a/log/sampler.go +++ b/log/sampler.go @@ -22,7 +22,7 @@ func (f SamplerFunc) ShouldSample(ctx context.Context, e *Event) bool { // DefaultSampler samples by error, duration, status code, and random keep rate. type DefaultSampler struct { slowThreshold time.Duration - keepHttpStatusAtLeast int + keepHTTPStatusAtLeast int randomKeepRate float64 } @@ -30,13 +30,13 @@ type DefaultSampler struct { func NewDefaultSampler(slowThreshold time.Duration, keepHTTPStatusAtLeast int, randomKeepRate float64) *DefaultSampler { return &DefaultSampler{ slowThreshold: slowThreshold, - keepHttpStatusAtLeast: keepHTTPStatusAtLeast, + keepHTTPStatusAtLeast: keepHTTPStatusAtLeast, randomKeepRate: randomKeepRate, } } // ShouldSample decides if event should be logged. -func (s *DefaultSampler) ShouldSample(ctx context.Context, e *Event) bool { +func (s *DefaultSampler) ShouldSample(_ context.Context, e *Event) bool { if len(e.errors) > 0 { return true } @@ -46,19 +46,17 @@ func (s *DefaultSampler) ShouldSample(ctx context.Context, e *Event) bool { } httpStatus := 0 - statusFromMap, exists := e.attrs["request.status"] - if exists { - success := false - httpStatus, success = statusFromMap.(int) - if !success { - httpStatus = 0 + if statusFromMap, exists := e.attrs["request.status"]; exists { + if status, ok := statusFromMap.(int); ok { + httpStatus = status } } - if httpStatus >= s.keepHttpStatusAtLeast { + if httpStatus >= s.keepHTTPStatusAtLeast { return true } + //nolint:gosec // Non-cryptographic sampling is sufficient for log event retention. if rand.Float64() < s.randomKeepRate { return true } diff --git a/log/wideevent_middleware.go b/log/wideevent_middleware.go index 35005be..a45217d 100644 --- a/log/wideevent_middleware.go +++ b/log/wideevent_middleware.go @@ -2,12 +2,15 @@ package log import ( "context" + "errors" "fmt" "net/http" ) const defaultWideEventName = "http.request" +var errPanicRecovered = errors.New("panic recovered") + // WideEventMiddleware creates and writes a request-wide event. type WideEventMiddleware struct { logger *WideEventLogger @@ -54,7 +57,7 @@ func (m *WideEventMiddleware) Wrap(next http.Handler) http.Handler { defer func() { recovered := recover() if recovered != nil { - event.AddError(fmt.Errorf("panic: %v", recovered)) + event.AddError(fmt.Errorf("%w: %v", errPanicRecovered, recovered)) if !recorder.wroteHeader { recorder.statusCode = http.StatusInternalServerError } @@ -91,5 +94,10 @@ func (w *statusResponseWriter) Write(p []byte) (int, error) { w.WriteHeader(http.StatusOK) } - return w.ResponseWriter.Write(p) + n, err := w.ResponseWriter.Write(p) + if err != nil { + return n, fmt.Errorf("write response body: %w", err) + } + + return n, nil } From e977f827d080b8cacb8d3b5e2befb324680e2c92 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:11:51 +0300 Subject: [PATCH 20/38] Disable revive var-naming for log --- .golangci.yml | 5 +++++ log/log.go | 2 +- 2 files changed, 6 insertions(+), 1 deletion(-) diff --git a/.golangci.yml b/.golangci.yml index c5e8103..20d0492 100644 --- a/.golangci.yml +++ b/.golangci.yml @@ -72,6 +72,11 @@ linters: linters: - revive + - path: log/.*\.go + text: "var-naming: avoid package names that conflict with Go standard library package names" + linters: + - revive + - path: _test\.go linters: - dupl diff --git a/log/log.go b/log/log.go index 4b8ccb5..c9e8639 100644 --- a/log/log.go +++ b/log/log.go @@ -1,5 +1,5 @@ // Package log provides structured logging functionality with context support. -package log //nolint:revive +package log import ( "context" From ad293222e94609d02f042ce9813f7cb4a5140251 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:21:10 +0300 Subject: [PATCH 21/38] Add thread-safe Event getters --- log/event.go | 26 ++++++++++++++++++++++++++ log/sampler.go | 6 +++--- 2 files changed, 29 insertions(+), 3 deletions(-) diff --git a/log/event.go b/log/event.go index bacb265..12e6655 100644 --- a/log/event.go +++ b/log/event.go @@ -87,6 +87,32 @@ func (e *Event) Finish() { e.duration = time.Since(e.timestamp) } +// HasErrors returns true if the event has errors. +func (e *Event) HasErrors() bool { + e.mu.Lock() + defer e.mu.Unlock() + + return len(e.errors) > 0 +} + +// Duration returns the event duration. +func (e *Event) Duration() time.Duration { + e.mu.Lock() + defer e.mu.Unlock() + + return e.duration +} + +// Attr returns an event attribute by key. +func (e *Event) Attr(key string) (any, bool) { + e.mu.Lock() + defer e.mu.Unlock() + + value, ok := e.attrs[key] + + return value, ok +} + // ToAttrs converts event to slog attributes. func (e *Event) ToAttrs() []slog.Attr { e.mu.Lock() diff --git a/log/sampler.go b/log/sampler.go index a03e34b..e2d9463 100644 --- a/log/sampler.go +++ b/log/sampler.go @@ -37,16 +37,16 @@ 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 len(e.errors) > 0 { + if e.HasErrors() { return true } - if e.duration >= s.slowThreshold { + if e.Duration() >= s.slowThreshold { return true } httpStatus := 0 - if statusFromMap, exists := e.attrs["request.status"]; exists { + if statusFromMap, exists := e.Attr("request.status"); exists { if status, ok := statusFromMap.(int); ok { httpStatus = status } From 96bcd6e30525efa4532621e4db374dd80f74d692 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:23:49 +0300 Subject: [PATCH 22/38] fix request status sampling condition --- log/event.go | 8 ++++++++ log/sampler.go | 16 +++++++++------- 2 files changed, 17 insertions(+), 7 deletions(-) diff --git a/log/event.go b/log/event.go index 12e6655..2b1ffe3 100644 --- a/log/event.go +++ b/log/event.go @@ -103,6 +103,14 @@ func (e *Event) Duration() time.Duration { return e.duration } +// Name returns the event name. +func (e *Event) Name() string { + e.mu.Lock() + defer e.mu.Unlock() + + return e.name +} + // Attr returns an event attribute by key. func (e *Event) Attr(key string) (any, bool) { e.mu.Lock() diff --git a/log/sampler.go b/log/sampler.go index e2d9463..2b1d03c 100644 --- a/log/sampler.go +++ b/log/sampler.go @@ -45,15 +45,17 @@ func (s *DefaultSampler) ShouldSample(_ context.Context, e *Event) bool { return true } - httpStatus := 0 - if statusFromMap, exists := e.Attr("request.status"); exists { - if status, ok := statusFromMap.(int); ok { - httpStatus = status + if e.Name() == "http.request" { + httpStatus := 0 + if statusFromMap, exists := e.Attr("request.status"); exists { + if status, ok := statusFromMap.(int); ok { + httpStatus = status + } } - } - if httpStatus >= s.keepHTTPStatusAtLeast { - return true + if httpStatus >= s.keepHTTPStatusAtLeast { + return true + } } //nolint:gosec // Non-cryptographic sampling is sufficient for log event retention. From 8b15f0f1688db69b117e9fec1b8f23cd3e5f77b3 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:26:09 +0300 Subject: [PATCH 23/38] Add Event Level getter usage --- log/event.go | 8 ++++++++ log/wideevent_logger.go | 2 +- 2 files changed, 9 insertions(+), 1 deletion(-) diff --git a/log/event.go b/log/event.go index 2b1ffe3..25d0186 100644 --- a/log/event.go +++ b/log/event.go @@ -103,6 +103,14 @@ func (e *Event) Duration() time.Duration { return e.duration } +// Level returns the event level. +func (e *Event) Level() slog.Level { + e.mu.Lock() + defer e.mu.Unlock() + + return e.level +} + // Name returns the event name. func (e *Event) Name() string { e.mu.Lock() diff --git a/log/wideevent_logger.go b/log/wideevent_logger.go index 1298753..c9e0030 100644 --- a/log/wideevent_logger.go +++ b/log/wideevent_logger.go @@ -42,6 +42,6 @@ func (l *WideEventLogger) WriteEvent(ctx context.Context, e *Event) { e.Finish() if l.sampler.ShouldSample(ctx, e) { - l.logger.LogAttrs(ctx, e.level, "", e.ToAttrs()...) + l.logger.LogAttrs(ctx, e.Level(), "", e.ToAttrs()...) } } From 135b36c727c5501eb31f316ea3af43c063a774bf Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:27:24 +0300 Subject: [PATCH 24/38] Add nil guard in log event --- log/event.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/log/event.go b/log/event.go index 25d0186..3cfe834 100644 --- a/log/event.go +++ b/log/event.go @@ -68,6 +68,10 @@ func (e *Event) AddStep(level slog.Level, name string) { // AddError appends an error and escalates event level to error. func (e *Event) AddError(err error) { + if err == nil { + return + } + e.mu.Lock() defer e.mu.Unlock() From d76af498a5dbd92c30bb375ab1be678f06f66aeb Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:34:59 +0300 Subject: [PATCH 25/38] Clone attrs map in log event --- log/event.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log/event.go b/log/event.go index 3cfe834..27e94e6 100644 --- a/log/event.go +++ b/log/event.go @@ -161,7 +161,7 @@ func (e *Event) ToAttrs() []slog.Attr { slog.String("name", e.name), slog.Time("timestamp", e.timestamp), slog.Duration("duration", e.duration), - slog.Any("attrs", e.attrs), + slog.Any("attrs", maps.Clone(e.attrs)), slog.Any("steps", steps), slog.Any("errors", eventErrors), } From bbf9a452a488f184d850488c1e013ed4d7a7ab07 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:39:17 +0300 Subject: [PATCH 26/38] do not set duration in ToAttrs --- log/event.go | 2 -- 1 file changed, 2 deletions(-) diff --git a/log/event.go b/log/event.go index 27e94e6..3403d76 100644 --- a/log/event.go +++ b/log/event.go @@ -138,8 +138,6 @@ func (e *Event) ToAttrs() []slog.Attr { e.mu.Lock() defer e.mu.Unlock() - e.duration = time.Since(e.timestamp) - steps := make([]map[string]any, 0, len(e.steps)) for _, step := range e.steps { steps = append(steps, map[string]any{ From 09f9737f4668ebcaa175732b0d9c395ba44287c1 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:39:50 +0300 Subject: [PATCH 27/38] Update event.go --- log/event.go | 8 -------- 1 file changed, 8 deletions(-) diff --git a/log/event.go b/log/event.go index 3403d76..343bfc7 100644 --- a/log/event.go +++ b/log/event.go @@ -171,14 +171,6 @@ type stepRecord struct { Name string `json:"name"` } -func (r stepRecord) LogValue() slog.Value { - return slog.GroupValue( - slog.Time("timestamp", r.Timestamp), - slog.String("name", r.Name), - slog.String("level", r.Level.String()), - ) -} - type errorRecord struct { Timestamp time.Time `json:"timestamp"` Error string `json:"error"` From 52df568328f02b0518db1a0f8e53127bedcdff1d Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:40:58 +0300 Subject: [PATCH 28/38] fix revive linter settings --- .golangci.yml | 14 +++++++++----- 1 file changed, 9 insertions(+), 5 deletions(-) diff --git a/.golangci.yml b/.golangci.yml index 20d0492..c626887 100644 --- a/.golangci.yml +++ b/.golangci.yml @@ -63,6 +63,15 @@ linters: case: rules: json: camel + + revive: + rules: + - name: var-naming + arguments: + - [] + - [] + - skip-package-name-collision-with-go-std: true + exclusions: paths: - demo-app @@ -72,11 +81,6 @@ linters: linters: - revive - - path: log/.*\.go - text: "var-naming: avoid package names that conflict with Go standard library package names" - linters: - - revive - - path: _test\.go linters: - dupl From ce48a4e98ce2815ce170ebadfce23f7d927087fe Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:43:58 +0300 Subject: [PATCH 29/38] return prev golangci-lint config --- .golangci.yml | 13 +++++-------- 1 file changed, 5 insertions(+), 8 deletions(-) diff --git a/.golangci.yml b/.golangci.yml index c626887..06f083b 100644 --- a/.golangci.yml +++ b/.golangci.yml @@ -64,14 +64,6 @@ linters: rules: json: camel - revive: - rules: - - name: var-naming - arguments: - - [] - - [] - - skip-package-name-collision-with-go-std: true - exclusions: paths: - demo-app @@ -81,6 +73,11 @@ linters: linters: - revive + - path: log/.*\.go + text: "var-naming: avoid package names that conflict with Go standard library package names" + linters: + - revive + - path: _test\.go linters: - dupl From 011b11172af13628fb596c39c5875ba0dfc39f53 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:55:27 +0300 Subject: [PATCH 30/38] Update log.mdx --- docs/src/content/docs/packages/log.mdx | 193 ++++++++----------------- 1 file changed, 61 insertions(+), 132 deletions(-) diff --git a/docs/src/content/docs/packages/log.mdx b/docs/src/content/docs/packages/log.mdx index 1b8df71..18ff264 100644 --- a/docs/src/content/docs/packages/log.mdx +++ b/docs/src/content/docs/packages/log.mdx @@ -2,17 +2,21 @@ title: log --- import { LinkButton, Steps } from '@astrojs/starlight/components'; +import { Code } from '@astrojs/starlight/components'; +import importedCode from '../../../../../demo-app/cmd/wide-events/main.go?raw'; -The `log` package provides structured logging with automatic context value extraction for tracing and debugging. +The `log` package provides structured application logs, HTTP trace propagation, and request-wide event logging with tail sampling. Core Components: -- `Logger`: Default logger instance used by package-level logging functions. -- `New`: Creates a new `slog.Logger` with text or JSON output and custom context keys. -- `SetDefault`: Replaces the default logger used by package-level functions. -- `TraceIDKey`, `ServiceNameKey`, `WorkerIDKey`, etc.: Context keys automatically extracted into log output. -- `Debug`, `Info`, `Warn`, `Error`: Package-level logging functions. -- `DebugContext`, `InfoContext`, `WarnContext`, `ErrorContext`: Context-aware logging functions that extract trace IDs and other values. +- `Logger`, `SetDefault`, `Debug`/`Info`/`Warn`/`Error`: Package-level logging API built on top of `slog`. +- `New`: Builds a text or JSON logger that automatically extracts values like `traceId` and `serviceName` from `context.Context`. +- `TraceIDMiddleware`: Adds a per-request trace ID to context and response headers. +- `Event`: Mutable wide-event model with attrs, steps, errors, severity, and duration. +- `WideEventLogger`: Writes finalized `Event` values through a `Sampler`. +- `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. +- `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) @@ -20,168 +24,93 @@ Core Components: -1. Use package-level logging functions +1. Configure default structured logging ```go - log.Info("server started", "port", 8080) - log.Error("failed to connect", "error", err) + logger := log.New(os.Stdout, "json", slog.LevelInfo, nil) + log.SetDefault(logger) ``` - These use the default logger which outputs text format at Info level. - - Expected output: - - ``` - time=2025-01-01T12:00:00.000+00:00 level=INFO msg="server started" port=8080 - ``` + This switches package-level logging to JSON and keeps context extraction enabled. -2. Use context-aware logging +2. Add trace IDs to each request ```go - ctx := context.WithValue(ctx, log.TraceIDKey, "abc-123") - log.InfoContext(ctx, "processing request", "path", "/users") + server := httpserver.New("8080", 3*time.Second) + server.Use(log.NewTraceIDMiddleware(nil, "")) ``` - Context values from known keys are automatically added to log output. - - Expected output: + With default arguments, the middleware stores IDs under `log.TraceIDKey` and writes `Platforma-Trace-Id` response headers. - ``` - time=2025-01-01T12:00:00.000+00:00 level=INFO msg="processing request" path=/users traceId=abc-123 - ``` - -3. Create a custom logger +3. Configure wide-event logging with sampling ```go - logger := log.New(os.Stdout, "json", slog.LevelDebug, nil) - logger.Info("message", "key", "value") + wideLogger := log.NewWideEventLogger( + os.Stdout, + log.NewDefaultSampler(2*time.Second, 500, 0.05), + "json", + nil, + ) + server.Use(log.NewWideEventMiddleware(wideLogger, "", nil)) ``` - The second argument is the format: `"text"` or `"json"`. The third is the minimum log level. + This keeps all error events, slow requests (>=2s), `5xx` responses, and 5% of the remaining traffic. - Expected JSON output: - - ```json - {"time":"2025-01-01T12:00:00.000+00:00","level":"INFO","msg":"message","key":"value"} - ``` - -4. Set a custom default logger +4. Enrich events and logs inside handlers ```go - logger := log.New(os.Stdout, "json", slog.LevelDebug, nil) - log.SetDefault(logger) + server.HandleFunc("/users", func(w http.ResponseWriter, r *http.Request) { + log.InfoContext(r.Context(), "users request started") - log.Info("now using JSON format") - ``` + if ev := log.EventFromContext(r.Context()); ev != nil { + ev.AddStep(slog.LevelInfo, "query users table") + ev.AddAttrs(map[string]any{"users.limit": 50}) + } - After calling `SetDefault`, all package-level functions use the new logger. + w.WriteHeader(http.StatusOK) + }) + ``` -5. Add custom context keys + `InfoContext` includes request metadata (for example `traceId`), and `EventFromContext` lets handlers attach detailed wide-event data. - ```go - type myKey string - const RequestIDKey myKey = "requestId" +5. Verify runtime output - customKeys := map[string]any{ - "requestId": RequestIDKey, - } - logger := log.New(os.Stdout, "text", slog.LevelInfo, customKeys) - log.SetDefault(logger) - - ctx := context.WithValue(ctx, RequestIDKey, "req-456") - log.InfoContext(ctx, "custom key extracted") + ```json + {"level":"INFO","msg":"users request started","traceId":"14b3..."} + {"level":"INFO","name":"http.request","duration":"12ms","attrs":{"request.status":200}} ``` - Expected output: - - ``` - time=2025-01-01T12:00:00.000+00:00 level=INFO msg="custom key extracted" requestId=req-456 - ``` + The first line is an immediate log entry. The second line is the finalized request-wide event emitted after the response is completed. -## Built-in context keys - -The logger automatically extracts these context keys when using `*Context` functions: - -| Key | Description | -|-----|-------------| -| `TraceIDKey` | Request trace ID for distributed tracing | -| `ServiceNameKey` | Service identifier | -| `DomainNameKey` | Domain name for domain-based architectures | -| `StartupTaskKey` | Startup task name during application initialization | -| `UserIDKey` | Authenticated user ID | -| `WorkerIDKey` | Queue processor worker ID | - ## Using with Application -The `application` package and other Platforma components automatically set context keys like `ServiceNameKey` and `StartupTaskKey`. Use context-aware logging to include this information: +Integrate logging by registering an HTTP service and attaching `log` middlewares before `app.Run`: ```go app := application.New() -app.OnStart(application.StartupTask{ - Name: "init-cache", - Task: func(ctx context.Context, config any) error { - log.InfoContext(ctx, "initializing cache") - // startupTask=init-cache automatically added to output - return nil - }, -}, nil) - -app.Run(ctx) -``` - -With `httpserver.TraceIDMiddleware`, the trace ID is automatically available in request handlers: - -```go server := httpserver.New("8080", 3*time.Second) -server.Use(httpserver.NewTraceIDMiddleware(nil, "")) - -server.HandleFunc("/users", func(w http.ResponseWriter, r *http.Request) { - log.InfoContext(r.Context(), "handling request") - // traceId= automatically added to output -}) -``` +server.Use(log.NewTraceIDMiddleware(nil, "")) -## Complete example - -```go -package main - -import ( - "context" - "log/slog" - "net/http" - "os" - "time" - - "github.com/platforma-dev/platforma/application" - "github.com/platforma-dev/platforma/httpserver" - "github.com/platforma-dev/platforma/log" +wideLogger := log.NewWideEventLogger( + os.Stdout, + log.NewDefaultSampler(2*time.Second, 500, 0.05), + "json", + nil, ) +server.Use(log.NewWideEventMiddleware(wideLogger, "", nil)) -func main() { - ctx := context.Background() - - // Configure JSON logging at Debug level - logger := log.New(os.Stdout, "json", slog.LevelDebug, nil) - log.SetDefault(logger) - - app := application.New() - - server := httpserver.New("8080", 3*time.Second) - server.Use(httpserver.NewTraceIDMiddleware(nil, "")) +server.HandleFunc("/health", func(w http.ResponseWriter, r *http.Request) { + log.InfoContext(r.Context(), "health check") + w.WriteHeader(http.StatusOK) +}) - server.HandleFunc("/ping", func(w http.ResponseWriter, r *http.Request) { - log.InfoContext(r.Context(), "ping received") - w.Write([]byte("pong")) - }) +app.RegisterService("api", server) +app.Run(ctx) +``` - app.RegisterService("api", server) +## Complete example - if err := app.Run(ctx); err != nil { - log.ErrorContext(ctx, "app finished with error", "error", err) - } -} -``` + From 87762078cc0fffd5a71202dee4f310791557e0a4 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Mon, 16 Feb 2026 21:56:37 +0300 Subject: [PATCH 31/38] remove empty msg field --- log/wideevent_logger.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log/wideevent_logger.go b/log/wideevent_logger.go index c9e0030..189ef79 100644 --- a/log/wideevent_logger.go +++ b/log/wideevent_logger.go @@ -17,7 +17,7 @@ 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.TimeKey { + if a.Key == slog.TimeKey || a.Key == slog.MessageKey { return slog.Attr{} } return a From 40262d5726242e0c278eb78e8f5691dc96f4e866 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Tue, 17 Feb 2026 08:33:55 +0300 Subject: [PATCH 32/38] Flatten wide event attrs --- docs/src/content/docs/packages/log.mdx | 2 +- log/event.go | 46 ++++++++++++++++++++++++-- log/wideevent_logger.go | 37 ++++++++++++++++++--- 3 files changed, 77 insertions(+), 8 deletions(-) diff --git a/docs/src/content/docs/packages/log.mdx b/docs/src/content/docs/packages/log.mdx index 18ff264..1547a6f 100644 --- a/docs/src/content/docs/packages/log.mdx +++ b/docs/src/content/docs/packages/log.mdx @@ -77,7 +77,7 @@ Core Components: ```json {"level":"INFO","msg":"users request started","traceId":"14b3..."} - {"level":"INFO","name":"http.request","duration":"12ms","attrs":{"request.status":200}} + {"level":"INFO","name":"http.request","duration":"12ms","request.status":200} ``` The first line is an immediate log entry. The second line is the finalized request-wide event emitted after the response is completed. diff --git a/log/event.go b/log/event.go index 343bfc7..ac823ba 100644 --- a/log/event.go +++ b/log/event.go @@ -3,6 +3,8 @@ package log import ( "log/slog" "maps" + "slices" + "sort" "sync" "time" ) @@ -135,6 +137,10 @@ func (e *Event) Attr(key string) (any, bool) { // ToAttrs converts event to slog attributes. func (e *Event) ToAttrs() []slog.Attr { + return e.toAttrs(nil) +} + +func (e *Event) toAttrs(additionalReservedAttrKeys []string) []slog.Attr { e.mu.Lock() defer e.mu.Unlock() @@ -155,14 +161,40 @@ func (e *Event) ToAttrs() []slog.Attr { }) } - return []slog.Attr{ + builtinAttrKeys := wideEventBuiltinAttrKeys() + reservedAttrKeys := make([]string, 0, len(builtinAttrKeys)+len(additionalReservedAttrKeys)) + reservedAttrKeys = append(reservedAttrKeys, builtinAttrKeys...) + for _, key := range additionalReservedAttrKeys { + if slices.Contains(reservedAttrKeys, key) { + continue + } + reservedAttrKeys = append(reservedAttrKeys, key) + } + + attrs := make([]slog.Attr, 0, len(e.attrs)+len(builtinAttrKeys)) + attrs = append(attrs, slog.String("name", e.name), slog.Time("timestamp", e.timestamp), slog.Duration("duration", e.duration), - slog.Any("attrs", maps.Clone(e.attrs)), slog.Any("steps", steps), slog.Any("errors", eventErrors), + ) + + customAttrKeys := make([]string, 0, len(e.attrs)) + for key := range e.attrs { + if slices.Contains(reservedAttrKeys, key) { + continue + } + + customAttrKeys = append(customAttrKeys, key) } + sort.Strings(customAttrKeys) + + for _, key := range customAttrKeys { + attrs = append(attrs, slog.Any(key, e.attrs[key])) + } + + return attrs } type stepRecord struct { @@ -175,3 +207,13 @@ type errorRecord struct { Timestamp time.Time `json:"timestamp"` Error string `json:"error"` } + +func wideEventBuiltinAttrKeys() []string { + return []string{ + "name", + "timestamp", + "duration", + "steps", + "errors", + } +} diff --git a/log/wideevent_logger.go b/log/wideevent_logger.go index 189ef79..476b667 100644 --- a/log/wideevent_logger.go +++ b/log/wideevent_logger.go @@ -4,12 +4,14 @@ import ( "context" "io" "log/slog" + "slices" ) // WideEventLogger writes wide events with tail sampling. type WideEventLogger struct { - sampler Sampler - logger *slog.Logger + sampler Sampler + logger *slog.Logger + reservedAttrKeys []string } // NewWideEventLogger creates a wide-event logger. @@ -32,8 +34,9 @@ func NewWideEventLogger(w io.Writer, s Sampler, loggerType string, contextKeys m } return &WideEventLogger{ - sampler: s, - logger: slog.New(&contextHandler{handler, contextKeys}), + sampler: s, + logger: slog.New(&contextHandler{handler, contextKeys}), + reservedAttrKeys: wideEventReservedAttrKeys(contextKeys), } } @@ -42,6 +45,30 @@ func (l *WideEventLogger) WriteEvent(ctx context.Context, e *Event) { e.Finish() if l.sampler.ShouldSample(ctx, e) { - l.logger.LogAttrs(ctx, e.Level(), "", e.ToAttrs()...) + l.logger.LogAttrs(ctx, e.Level(), "", e.toAttrs(l.reservedAttrKeys)...) } } + +func wideEventReservedAttrKeys(contextKeys map[string]any) []string { + reservedAttrKeys := append([]string{}, wideEventBuiltinAttrKeys()...) + reservedAttrKeys = appendUnique(reservedAttrKeys, slog.LevelKey) + reservedAttrKeys = appendUnique(reservedAttrKeys, string(DomainNameKey)) + reservedAttrKeys = appendUnique(reservedAttrKeys, string(TraceIDKey)) + reservedAttrKeys = appendUnique(reservedAttrKeys, string(ServiceNameKey)) + reservedAttrKeys = appendUnique(reservedAttrKeys, string(StartupTaskKey)) + reservedAttrKeys = appendUnique(reservedAttrKeys, string(UserIDKey)) + reservedAttrKeys = appendUnique(reservedAttrKeys, string(WorkerIDKey)) + for key := range contextKeys { + reservedAttrKeys = appendUnique(reservedAttrKeys, key) + } + + return reservedAttrKeys +} + +func appendUnique(keys []string, key string) []string { + if slices.Contains(keys, key) { + return keys + } + + return append(keys, key) +} From a4cff940eea7f7af5635a1b8794469bf6a628aff Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Tue, 17 Feb 2026 08:53:07 +0300 Subject: [PATCH 33/38] fix potential nil sampler --- log/wideevent_logger.go | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/log/wideevent_logger.go b/log/wideevent_logger.go index 476b667..f3d8ccf 100644 --- a/log/wideevent_logger.go +++ b/log/wideevent_logger.go @@ -16,6 +16,11 @@ type WideEventLogger struct { // NewWideEventLogger creates a wide-event logger. func NewWideEventLogger(w io.Writer, s Sampler, loggerType string, contextKeys map[string]any) *WideEventLogger { + // If no sampler provided, use a keep-all sampler to prevent nil panics + if s == nil { + s = SamplerFunc(func(_ context.Context, _ *Event) bool { return true }) + } + opts := &slog.HandlerOptions{ Level: slog.LevelDebug, ReplaceAttr: func(_ []string, a slog.Attr) slog.Attr { From 77c0b240b45c3abca67ca07ea34ce682e7a0540d Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Tue, 17 Feb 2026 08:54:24 +0300 Subject: [PATCH 34/38] Guard against nil logger to avoid runtime panics. --- log/wideevent_middleware.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/log/wideevent_middleware.go b/log/wideevent_middleware.go index a45217d..486dea2 100644 --- a/log/wideevent_middleware.go +++ b/log/wideevent_middleware.go @@ -21,6 +21,10 @@ type WideEventMiddleware struct { // NewWideEventMiddleware creates middleware that stores a wide event in request context // and writes it after request processing. func NewWideEventMiddleware(logger *WideEventLogger, eventName string, contextKey any) *WideEventMiddleware { + if logger == nil { + panic("WideEventMiddleware: logger is nil") + } + if eventName == "" { eventName = defaultWideEventName } From ba2cca1800964c18c82a782bdac9ea2a2ad91778 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Tue, 17 Feb 2026 09:08:18 +0300 Subject: [PATCH 35/38] remove unused json tags --- log/event.go | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/log/event.go b/log/event.go index ac823ba..8a4c8c1 100644 --- a/log/event.go +++ b/log/event.go @@ -198,14 +198,14 @@ func (e *Event) toAttrs(additionalReservedAttrKeys []string) []slog.Attr { } type stepRecord struct { - Timestamp time.Time `json:"timestamp"` - Level slog.Level `json:"level"` - Name string `json:"name"` + Timestamp time.Time + Level slog.Level + Name string } type errorRecord struct { - Timestamp time.Time `json:"timestamp"` - Error string `json:"error"` + Timestamp time.Time + Error string } func wideEventBuiltinAttrKeys() []string { From b083838ff73488f92d217b08aecefe768fd14a54 Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Tue, 17 Feb 2026 09:09:59 +0300 Subject: [PATCH 36/38] sing a set for reserved key lookup --- log/event.go | 14 ++++++-------- 1 file changed, 6 insertions(+), 8 deletions(-) diff --git a/log/event.go b/log/event.go index 8a4c8c1..9056206 100644 --- a/log/event.go +++ b/log/event.go @@ -4,7 +4,6 @@ import ( "log/slog" "maps" "slices" - "sort" "sync" "time" ) @@ -180,19 +179,18 @@ func (e *Event) toAttrs(additionalReservedAttrKeys []string) []slog.Attr { slog.Any("errors", eventErrors), ) + reservedSet := make(map[string]struct{}, len(reservedAttrKeys)) + for _, k := range reservedAttrKeys { + reservedSet[k] = struct{}{} + } + customAttrKeys := make([]string, 0, len(e.attrs)) for key := range e.attrs { - if slices.Contains(reservedAttrKeys, key) { + if _, reserved := reservedSet[key]; reserved { continue } - customAttrKeys = append(customAttrKeys, key) } - sort.Strings(customAttrKeys) - - for _, key := range customAttrKeys { - attrs = append(attrs, slog.Any(key, e.attrs[key])) - } return attrs } From 867b82f20e4e7bbe93c9062de1534b564e21892e Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Tue, 17 Feb 2026 09:12:44 +0300 Subject: [PATCH 37/38] fix using a set for reserved key lookup --- log/event.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/log/event.go b/log/event.go index 9056206..2f58eeb 100644 --- a/log/event.go +++ b/log/event.go @@ -192,6 +192,10 @@ func (e *Event) toAttrs(additionalReservedAttrKeys []string) []slog.Attr { customAttrKeys = append(customAttrKeys, key) } + for _, key := range customAttrKeys { + attrs = append(attrs, slog.Any(key, e.attrs[key])) + } + return attrs } From e742a5ce76a75041b67bb8489da33f1640c3b9da Mon Sep 17 00:00:00 2001 From: Denis Mishankov Date: Tue, 17 Feb 2026 09:25:03 +0300 Subject: [PATCH 38/38] Add optional interface delegation --- log/wideevent_middleware.go | 39 +++++++++++++++++++++++++++++++++++++ 1 file changed, 39 insertions(+) diff --git a/log/wideevent_middleware.go b/log/wideevent_middleware.go index 486dea2..12c2c95 100644 --- a/log/wideevent_middleware.go +++ b/log/wideevent_middleware.go @@ -1,9 +1,11 @@ package log import ( + "bufio" "context" "errors" "fmt" + "net" "net/http" ) @@ -105,3 +107,40 @@ func (w *statusResponseWriter) Write(p []byte) (int, error) { return n, nil } + +func (w *statusResponseWriter) Flush() { + if flusher, ok := w.ResponseWriter.(http.Flusher); ok { + flusher.Flush() + } +} + +func (w *statusResponseWriter) Hijack() (net.Conn, *bufio.ReadWriter, error) { + hijacker, ok := w.ResponseWriter.(http.Hijacker) + if !ok { + return nil, nil, http.ErrNotSupported + } + + conn, rw, err := hijacker.Hijack() + if err != nil { + return nil, nil, fmt.Errorf("hijack response writer: %w", err) + } + + return conn, rw, nil +} + +func (w *statusResponseWriter) Push(target string, opts *http.PushOptions) error { + pusher, ok := w.ResponseWriter.(http.Pusher) + if !ok { + return http.ErrNotSupported + } + + if err := pusher.Push(target, opts); err != nil { + return fmt.Errorf("push response writer: %w", err) + } + + return nil +} + +func (w *statusResponseWriter) Unwrap() http.ResponseWriter { + return w.ResponseWriter +}