Skip to content
quarry Artifact [b849d0ca5e]
Login

Artifact [b849d0ca5e]

Check-ins Using Download Hex

Artifact b849d0ca5ef00e6c573af176d00908bca140c25ca6d45864d633f86694eaec27:

// 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}
	// URL is the path actually requested. The route is what groups
	// rows; this is what identifies one. A panel of a dozen renders all
	// reading GET /r/{repo}/timeline cannot say which repository was
	// slow, which is the first thing anybody asks — and the drilldown
	// existed precisely because the pattern hides the variable that
	// matters most.
	//
	// Path only, never the query: filters are unbounded and would make
	// this the highest-cardinality column in the store for no gain the
	// route and repo do not already give.
	URL     string
	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
	health Health
	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()
}

// Health is what an admin surface can say about the durable store.
//
// A forge that failed to open it records nothing and, until this
// existed, said nothing either: the live panels are fed by the rings
// and look identical either way. That is how a schema failure would
// have reached production unnoticed — it was caught in a test run by
// luck, not by the interface.
type Health struct {
	// Configured is false when analytics is switched off, which is a
	// choice rather than a fault and must not read as one.
	Configured bool   `json:"configured"`
	Path       string `json:"path"`
	// Err is the reason the store is not recording: a failure to open
	// it, or the last write failure reported by the sink.
	Err string `json:"err"`
	// Kept is the retention window, empty when rows are kept forever.
	Kept string `json:"kept"`
}

// TrendPoint is one day of a route's history.
//
// The live panels are a snapshot of one process's memory, which cannot
// answer the question an operator actually has after a deploy: is this
// getting worse. The store held the rows to answer it and nothing read
// them back.
type TrendPoint struct {
	Day   string `json:"day"`
	N     int    `json:"n"`
	P50Ms int64  `json:"p50Ms"`
	P95Ms int64  `json:"p95Ms"`
	MaxMs int64  `json:"maxMs"`
}

// Trend reports a route's daily percentiles over the last days, oldest
// first. An empty path trends the whole forge.
//
// Answered by the durable sink or not at all: a recorder with history
// switched off returns nothing rather than inventing a trend from the
// ring, which covers minutes and would read as days.
func (r *Recorder) Trend(path string, days int) ([]TrendPoint, error) {
	r.mu.Lock()
	sink := r.sink
	r.mu.Unlock()
	t, ok := sink.(interface {
		Trend(string, int) ([]TrendPoint, error)
	})
	if !ok {
		return nil, nil
	}
	return t.Trend(path, days)
}

// HistoryRow is one recorded render read back from the store.
type HistoryRow struct {
	At        string `json:"at"`
	Path      string `json:"path"`
	URL       string `json:"url"`
	Repo      string `json:"repo"`
	ElapsedMs int64  `json:"elapsedMs"`
	OpsMs     int64  `json:"opsMs"`
	ZitMs     int64  `json:"zitMs"`
	Status    int    `json:"status"`
}

// HistoryQuery narrows a read of the store.
type HistoryQuery struct {
	// Find matches the route or the requested path, case-insensitively.
	Find string
	// Repo narrows to one repository.
	Repo string
	// Sort is "slowest" or "recent"; recent is the default.
	Sort  string
	Days  int
	Limit int
}

// History reads renders back from the durable store, newest or slowest
// first.
//
// The panels show a ring of the last few hundred renders in one
// process's memory. That is the right thing for "what is happening now"
// and the wrong thing for "when did this start", which is the question
// somebody actually has when they open the page after a report.
func (r *Recorder) History(q HistoryQuery) ([]HistoryRow, error) {
	r.mu.Lock()
	sink := r.sink
	r.mu.Unlock()
	h, ok := sink.(interface {
		History(HistoryQuery) ([]HistoryRow, error)
	})
	if !ok {
		return nil, nil
	}
	return h.History(q)
}

// SetHealth records what happened when the durable store was opened.
func (r *Recorder) SetHealth(h Health) {
	r.mu.Lock()
	r.health = h
	r.mu.Unlock()
}

// Health reports the durable store's state, folding in the sink's own
// last write failure so a store that opened and then broke is not
// reported as healthy.
func (r *Recorder) Health() Health {
	r.mu.Lock()
	h, sink := r.health, r.sink
	r.mu.Unlock()
	if h.Err == "" {
		if e, ok := sink.(interface{ Err() error }); ok {
			if err := e.Err(); err != nil {
				h.Err = err.Error()
			}
		}
	}
	return h
}

// 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()
}