package tracelog import ( "encoding/json" "fmt" "io" "maps" "os" "slices" "strconv" "strings" "sync" "time" ) // Collector groups a stream of log entries into traces and renders each // trace as soon as its request completes (the "http response" entry). // Unfinished traces are flushed after MaxAge so hung or crashed requests // still show their logs. type Collector struct { Out io.Writer // MaxAge bounds how long an unfinished trace is buffered. Zero means // 30 seconds. MaxAge time.Duration // PassThrough prints entries that have no request ID as single lines. // When false those entries are dropped. PassThrough bool // Filter, when set, decides whether a completed trace is rendered. Filter func(id string, entries []Entry) bool // Color renders anomaly callouts in yellow ANSI color. Enable when Out // is a terminal (IsTerminal). Color bool mu sync.Mutex pending map[string][]Entry } // Add feeds one log entry to the collector. Entries with an empty id are // printed immediately (or dropped, per PassThrough); others are buffered // under their trace until the trace completes. func (c *Collector) Add(id string, e Entry) { c.mu.Lock() defer c.mu.Unlock() if id == "" { if c.PassThrough { fmt.Fprintf(c.Out, "%s %-5s %s%s\n", e.Time.Format("2006-01-02 15:04:05"), e.Level, e.Msg, formatAttrs(e.Attrs)) } return } if c.pending == nil { c.pending = map[string][]Entry{} } c.pending[id] = append(c.pending[id], e) if e.Msg == "http response" { c.render(id, c.pending[id]) delete(c.pending, id) } c.sweep(e.Time) } // Sweep flushes unfinished traces older than MaxAge. Call it periodically // when the input stream can go quiet (e.g. a live tail). func (c *Collector) Sweep(now time.Time) { c.mu.Lock() defer c.mu.Unlock() c.sweep(now) } // Flush renders all buffered traces, finished or not. Call it when the // input stream ends. func (c *Collector) Flush() { c.mu.Lock() defer c.mu.Unlock() for _, id := range slices.Sorted(maps.Keys(c.pending)) { c.render(id, c.pending[id]) delete(c.pending, id) } } func (c *Collector) sweep(now time.Time) { maxAge := c.MaxAge if maxAge == 0 { maxAge = 30 * time.Second } for id, entries := range c.pending { if now.Sub(entries[0].Time) > maxAge { c.render(id+" (incomplete)", entries) delete(c.pending, id) } } } func (c *Collector) render(id string, entries []Entry) { if c.Filter != nil && !c.Filter(id, entries) { return } render(c.Out, id, entries, c.Color) } // IsTerminal reports whether w writes to a terminal, for deciding whether // to render with color. func IsTerminal(w io.Writer) bool { f, ok := w.(*os.File) if !ok { return false } stat, err := f.Stat() return err == nil && stat.Mode()&os.ModeCharDevice != 0 } // ParseLine parses one slog JSON log line into its request ID and entry. // It returns ok=false for lines that aren't JSON logs. func ParseLine(line []byte) (id string, e Entry, ok bool) { var attrs map[string]any if json.Unmarshal(line, &attrs) != nil { return "", Entry{}, false } if ts, found := attrs["time"].(string); found { e.Time, _ = time.Parse(time.RFC3339Nano, ts) } id, _ = attrs["request"].(string) e.Level, _ = attrs["level"].(string) e.Msg, _ = attrs["msg"].(string) delete(attrs, "request") delete(attrs, "time") delete(attrs, "level") delete(attrs, "msg") for _, k := range slices.Sorted(maps.Keys(attrs)) { e.Attrs = append(e.Attrs, Attr{k, formatJSONValue(k, attrs[k])}) } return id, e, true } func formatJSONValue(key string, v any) string { // Durations are logged as nanosecond numbers. f, isNum := v.(float64) if isNum && key == "duration" { return FormatDuration(time.Duration(f)) } if isNum { return strconv.FormatFloat(f, 'f', -1, 64) } s := fmt.Sprintf("%v", v) if strings.ContainsAny(s, " \"") { return fmt.Sprintf("%q", s) } return s }