Artifact [a935950ef8]

Artifact a935950ef89caa6ce37fc822203669a8df616cb7c67c9764d0eaaf7f6875b00c:

• File internal/obs/stats.go — part of check-in [bc35cc0c45] at 2026-08-25 21:42:15 on branch ops-drill — ops: tie a store call to the request that caused it

  The panel could find a slow route and never say why: the render list and the subprocess list were two independent tables, so 'GET /search took 1132ms' and 'zit artifact ran 499 times' could not be connected even when one caused the other.

  Every request is now tagged at the outermost middleware, and every store call records the tag. Work with no request behind it — ingest rounds, warm passes, the doc indexer — records the empty string, which is itself the useful distinction: store load with nothing to blame is background, and telling the two apart is most of what the subprocess panel is for.

  Also fixes a silent hole of the same shape as the route-pattern bug: Repo was read with req.PathValue in the outermost middleware, where the router has not set it — the values live on the request the mux passes DOWN. Every render recorded until now carried an empty repo, 61 of 61 rows in the analytics store, which made the numbers unattributable on a fleet where repository size is the dominant cost. Read from the path instead. (user: dmestas, size: 4119) [annotate] [blame] [check-ins using] [more...]

package obs

import (
	"cmp"
	"slices"
	"time"
)

// ring is a fixed-size window of the most recent values. Bounded on
// purpose: this package is the snapshot, and an unbounded buffer in a
// long-lived server is a leak wearing a feature's clothes.
type ring[T any] struct {
	buf  []T
	next int
	full bool
}

func newRing[T any](n int) ring[T] { return ring[T]{buf: make([]T, n)} }

func (r *ring[T]) push(v T) {
	r.buf[r.next] = v
	r.next++
	if r.next == len(r.buf) {
		r.next, r.full = 0, true
	}
}

// all returns the window newest first.
func (r *ring[T]) all() []T {
	n := r.next
	if r.full {
		n = len(r.buf)
	}
	out := make([]T, 0, n)
	for i := 0; i < n; i++ {
		j := r.next - 1 - i
		if j < 0 {
			j += len(r.buf)
		}
		out = append(out, r.buf[j])
	}
	return out
}

// pathStat accumulates one route's durations. Kept as a sample window
// rather than a running mean: a mean hides the tail, and the tail is
// what a reader is looking for on this page.
type pathStat struct {
	n       int
	samples ring[time.Duration]
	max     time.Duration
}

func (p *pathStat) add(d time.Duration) {
	if p.samples.buf == nil {
		p.samples = newRing[time.Duration](128)
	}
	p.n++
	p.samples.push(d)
	if d > p.max {
		p.max = d
	}
}

// PathStat is one route's rolled-up timing, for the admin surface.
type PathStat struct {
	Path string
	N    int
	P50  time.Duration
	P95  time.Duration
	Max  time.Duration
}

// RouteDetail is one route's recent renders with the store calls each
// one made. The panel finds a slow route; this is what says why.
type RouteDetail struct {
	Path    string
	Renders []RenderCalls
}

// RenderCalls is one request and what it asked the store for.
type RenderCalls struct {
	Render Render
	Calls  []Subprocess
}

// Route gathers a route's recent renders and attributes each one's
// store calls to it, newest first.
//
// Read from the same rings the panels read, so a request that has aged
// out of the window simply is not here. That is the honest limit of a
// snapshot: this answers "what did that slow request just do", not
// "what happened yesterday", which is the analytics store's question.
func (r *Recorder) Route(path string, limit int) RouteDetail {
	if r == nil {
		return RouteDetail{}
	}
	if limit <= 0 {
		limit = 20
	}
	r.mu.Lock()
	renders, subs := r.rend.all(), r.subs.all()
	r.mu.Unlock()

	byRender := map[string][]Subprocess{}
	for _, s := range subs {
		if s.RenderID != "" {
			byRender[s.RenderID] = append(byRender[s.RenderID], s)
		}
	}
	out := RouteDetail{Path: path}
	for _, v := range renders {
		if v.Path != path || len(out.Renders) >= limit {
			continue
		}
		calls := byRender[v.ID]
		// Oldest first WITHIN a request: the order the page made them
		// is the order a reader reconstructs the work in.
		slices.Reverse(calls)
		out.Renders = append(out.Renders, RenderCalls{Render: v, Calls: calls})
	}
	return out
}

// Snapshot is everything the ops page shows, taken under one lock so
// the panels agree with each other.
type Snapshot struct {
	Paths       []PathStat
	Renders     []Render
	Subprocess  []Subprocess
	LiveSubproc int
	PeakSubproc int
}

// Snapshot reads the rings. Slowest paths first by p95, because the
// question this page answers is "what is slow", not "what is busy".
func (r *Recorder) Snapshot() Snapshot {
	if r == nil {
		return Snapshot{}
	}
	r.mu.Lock()
	defer r.mu.Unlock()
	s := Snapshot{
		Renders: r.rend.all(), Subprocess: r.subs.all(),
		LiveSubproc: r.live, PeakSubproc: r.liveMax,
	}
	for path, st := range r.paths {
		xs := st.samples.all()
		slices.Sort(xs)
		s.Paths = append(s.Paths, PathStat{
			Path: path, N: st.n, Max: st.max,
			P50: pct(xs, 0.50), P95: pct(xs, 0.95),
		})
	}
	slices.SortFunc(s.Paths, func(a, b PathStat) int {
		if c := cmp.Compare(b.P95, a.P95); c != 0 {
			return c
		}
		return cmp.Compare(a.Path, b.Path)
	})
	return s
}

// pct is the nearest-rank percentile of a SORTED slice.
func pct(xs []time.Duration, q float64) time.Duration {
	if len(xs) == 0 {
		return 0
	}
	i := int(float64(len(xs))*q+0.5) - 1
	if i < 0 {
		i = 0
	}
	if i >= len(xs) {
		i = len(xs) - 1
	}
	return xs[i]
}