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 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/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/demo-app/cmd/wide-events/main.go b/demo-app/cmd/wide-events/main.go new file mode 100644 index 0000000..5d802bd --- /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), + "json", + 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/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", 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" 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) } - }) } 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..3a2da4f --- /dev/null +++ b/log2/context.go @@ -0,0 +1,31 @@ +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 new file mode 100644 index 0000000..c9acb56 --- /dev/null +++ b/log2/event.go @@ -0,0 +1,349 @@ +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 new file mode 100644 index 0000000..27e77e3 --- /dev/null +++ b/log2/logger.go @@ -0,0 +1,124 @@ +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 new file mode 100644 index 0000000..a47624a --- /dev/null +++ b/log2/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/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/log3/event.go b/log3/event.go new file mode 100644 index 0000000..e2da8ba --- /dev/null +++ b/log3/event.go @@ -0,0 +1,131 @@ +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(name string) *Event { + return &Event{ + name: name, + timestamp: time.Now(), + level: slog.LevelDebug, + attrs: map[string]any{}, + } +} + +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 + } +} + +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.setLevelNoLock(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.setLevelNoLock(slog.LevelError) + + e.errors = append(e.errors, errorRecord{ + Timestamp: time.Now(), + Error: err.Error(), + }) +} + +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) + 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", steps), + slog.Any("errors", eventErrors), + } +} + +type stepRecord struct { + 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 `json:"timestamp"` + Error string `json:"error"` +} diff --git a/log3/logger.go b/log3/logger.go new file mode 100644 index 0000000..00b5404 --- /dev/null +++ b/log3/logger.go @@ -0,0 +1,30 @@ +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()...) + } +} diff --git a/log3/sampler.go b/log3/sampler.go new file mode 100644 index 0000000..61518c7 --- /dev/null +++ b/log3/sampler.go @@ -0,0 +1,61 @@ +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(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 { + 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 +}