Skip to content
quarry Artifact [658c503f34]
Login

Artifact [658c503f34]

Check-ins Using Download Hex

Artifact 658c503f34d129bd45e758c12fd9cc0cbc2639844de58e3cdb8c98ae1de22098:

package obs

import (
	"cmp"
	"slices"
	"sort"
	"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.
// StoreBusy is the wall time during which at least one subprocess was
// running inside [start, end) — REGARDLESS of which render, if any,
// spawned it.
//
// The footer used to take its zit figure from the timing context, which
// a call made on context.Background() does not carry. A page that
// blocked six seconds on a warm pass therefore reported "ops 11.09s,
// zit 32.9ms", and the panel's own note — that ops minus zit is index
// and OLTP work — was false while it did. Three diagnoses were wrong
// before the subprocess tally gave it away.
//
// Overlap, not attribution: a render that waits on a detached call is
// waiting whether or not the call belongs to it, and that wait is the
// thing a reader of the footer needs to see. Spans are unioned for the
// same reason the timing package unions its own — two concurrent
// half-second calls are half a second of waiting, not one second.
func (r *Recorder) StoreBusy(start, end time.Time) time.Duration {
	if r == nil || !end.After(start) {
		return 0
	}
	r.mu.Lock()
	subs := r.subs.all()
	r.mu.Unlock()

	type span struct{ a, b time.Time }
	var spans []span
	for _, s := range subs {
		lo, hi := s.At, s.At.Add(s.Duration)
		if lo.Before(start) {
			lo = start
		}
		if hi.After(end) {
			hi = end
		}
		if hi.After(lo) {
			spans = append(spans, span{lo, hi})
		}
	}
	if len(spans) == 0 {
		return 0
	}
	sort.Slice(spans, func(i, j int) bool { return spans[i].a.Before(spans[j].a) })
	var total time.Duration
	cur := spans[0]
	for _, sp := range spans[1:] {
		if sp.a.After(cur.b) {
			total += cur.b.Sub(cur.a)
			cur = sp
			continue
		}
		if sp.b.After(cur.b) {
			cur.b = sp.b
		}
	}
	return total + cur.b.Sub(cur.a)
}

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]
}