Skip to content
quarry Artifact [a4f4b27dd1]
Login

Artifact [a4f4b27dd1]

Check-ins Using Download Hex

Artifact a4f4b27dd18fab9b2136d9c549056cc4032fb7b51268e9da8d4142ae82887f2a:

// Package obs is the forge's view of its own behaviour: how long pages
// take, and what the store subprocesses cost.
//
// It exists because quarry could not answer either question. A render
// time was printed in the page footer and thrown away, so a 4.24-second
// files page was visible only to whoever loaded it and happened to read
// the footer. Subprocess load was visible nowhere at all: a warm loop
// once spawned 134 concurrent `zit ls --long` against the same hash,
// load average 546 on 14 cores, and the forge's own admin page showed
// "all healthy" throughout.
//
// Two deliberate limits.
//
// The rings are SMALL and in memory. This package answers "what is
// happening now, and in the recent past" — the snapshot every comparable
// admin surface settles on, and the one GitLab's own docs are candid
// about: a point-in-time view cannot tell you what happened an hour ago.
// History belongs in the analytics store behind Sink, not here.
//
// Sink is an interface with a no-op default because the persistent
// implementation is DuckDB, which is cgo. quarry is CGO-free on purpose
// — the SQLite driver is a wasm build for exactly this reason — so that
// the forge can theoretically compile to wasm for an embedded UI. That
// embedded build ships no analytics, so it wires no sink and never
// links DuckDB. Nothing on the request path may import the persistent
// implementation directly.
package obs

import (
	"sync"
	"time"
)

// Render is one page served.
type Render struct {
	// ID ties a render to the store calls made while serving it. The
	// panel could say a route was slow and nothing more: the subprocess
	// list and the render 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.
	ID      string
	At      time.Time
	Path    string // the ROUTE, not the URL: /r/{repo}/checkin/{hash}
	Repo    string
	Elapsed time.Duration
	// Ops is time inside op handlers and CONTAINS Zit: the registry is
	// the seam every page's data crosses, and store calls happen inside
	// it. They are reported as container and content, never summed.
	//
	// Neither accounts for the whole of Elapsed, and the REMAINDER is
	// the point: the files page spent 675ms with no zit call at all and
	// nothing could say where it went. What these two do not cover is
	// template execution and the server's own overhead, and seeing that
	// gap shrink is how the instrumentation earns its keep.
	Ops, Zit time.Duration
	Status   int
}

// Subprocess is one zit invocation.
type Subprocess struct {
	// RenderID names the request being served, empty for work with no
	// request behind it — ingest rounds, warm passes, the doc indexer.
	// That emptiness is informative: store load with no render to blame
	// is background work, and telling the two apart is most of what the
	// subprocess panel is for.
	RenderID string
	At       time.Time
	Verb     string // ls, diff, cat, tarball…
	Repo     string
	Duration time.Duration
	Err      bool
}

// Sink receives every observation for durable storage. The default is a
// no-op: a forge with no analytics store still shows the live panels,
// because those read the rings rather than the sink.
type Sink interface {
	Render(Render)
	Subprocess(Subprocess)
}

type nopSink struct{}

func (nopSink) Render(Render)         {}
func (nopSink) Subprocess(Subprocess) {}

// Recorder holds the live rings and forwards to a sink.
type Recorder struct {
	mu    sync.Mutex
	sink  Sink
	rend  ring[Render]
	subs  ring[Subprocess]
	paths map[string]*pathStat
	// live is the CURRENT subprocess count, which is the number the
	// stampede made matter: a listing that is slow is a performance
	// note, and thirteen of the same listing at once is an incident.
	live    int
	liveMax int
	// slow remembers which routes have already been reported, so a
	// route that is slow a thousand times notifies once. errlog's rule:
	// an alert channel that repeats itself gets muted, and a muted
	// channel is worse than none because it reads as healthy.
	slow map[string]bool
	// OnSlow runs the FIRST time a route exceeds Budget. Set by the
	// composition root when a notification plane exists; nil is the
	// ordinary case and costs nothing.
	OnSlow func(Render)
}

// Budget is the render time above which a page needs attention.
//
// ONE definition. It was a literal repeated in a template — the panel
// coloured a p95 over 500ms and nothing else knew the number — so a
// forge could show a route in red and tell nobody. The colouring and
// the notification read this.
//
// 500ms is a product decision, not a measurement: it is the point at
// which a page stops feeling immediate. Everything the forge serves is
// comfortably inside it today; the value exists so that stops being
// true loudly rather than quietly.
const Budget = 500 * time.Millisecond

// Default is the process-wide recorder, the shape errlog.Default
// already uses for the same reason: the funnels that observe (one HTTP
// middleware, one subprocess wrapper) are deep in call chains that
// should not have to be handed one.
var Default = NewRecorder(500, nil)

// NewRecorder builds a recorder keeping the last n of each kind.
func NewRecorder(n int, sink Sink) *Recorder {
	if n <= 0 {
		n = 500
	}
	if sink == nil {
		sink = nopSink{}
	}
	return &Recorder{sink: sink, rend: newRing[Render](n), subs: newRing[Subprocess](n),
		paths: map[string]*pathStat{}, slow: map[string]bool{}}
}

// SetSink swaps the durable destination. Safe at any time; the rings are
// unaffected, so the live panels never depend on it.
func (r *Recorder) SetSink(s Sink) {
	if s == nil {
		s = nopSink{}
	}
	r.mu.Lock()
	r.sink = s
	r.mu.Unlock()
}

// RecordRender files one page.
func (r *Recorder) RecordRender(v Render) {
	if r == nil {
		return
	}
	r.mu.Lock()
	r.rend.push(v)
	p := r.paths[v.Path]
	if p == nil {
		p = &pathStat{}
		r.paths[v.Path] = p
	}
	p.add(v.Elapsed)
	sink := r.sink
	// First crossing only, and decided under the lock so two slow
	// requests racing cannot both report the same route.
	var tell func(Render)
	if v.Elapsed > Budget && !r.slow[v.Path] {
		r.slow[v.Path] = true
		tell = r.OnSlow
	}
	r.mu.Unlock()
	sink.Render(v)
	if tell != nil {
		tell(v)
	}
}

// RecordSubprocess files one zit invocation and closes its live slot.
func (r *Recorder) RecordSubprocess(v Subprocess) {
	if r == nil {
		return
	}
	r.mu.Lock()
	r.subs.push(v)
	if r.live > 0 {
		r.live--
	}
	sink := r.sink
	r.mu.Unlock()
	sink.Subprocess(v)
}

// Spawned opens a live slot, before the work begins. Paired with
// RecordSubprocess so the count reflects what is RUNNING rather than
// what has finished — the finished ones were never the problem.
func (r *Recorder) Spawned() {
	if r == nil {
		return
	}
	r.mu.Lock()
	r.live++
	if r.live > r.liveMax {
		r.liveMax = r.live
	}
	r.mu.Unlock()
}