// 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
// Surface is the door the request came in by: SurfaceWeb for a
// page, SurfaceAPI for /api/v1. Both are filed here, side by side,
// so a slow API call is as visible as a slow page.
Surface string
}
// 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
// Reason is the background activity this call served — sync,
// ingest, warm, doc index, ci — empty when a render caused it and
// RenderID names which. Together the two answer "what asked for
// this", which a verb and a repository alone cannot: one slow
// listing is a note, and the same listing thirteen times over is an
// incident only once you know who is asking for it.
Reason 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]
// rendAPI is the API's own window. A runner or a crawler calls the
// API far more often than anybody loads a page, and in one shared
// window its calls pushed the pages out of view.
rendAPI 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), rendAPI: 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"`
// Dropped counts observations the store refused because its buffer
// was full: the writer fell behind the traffic.
Dropped uint64 `json:"dropped"`
}
// 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"`
Surface string `json:"surface"`
}
// 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 d, ok := sink.(interface{ Dropped() uint64 }); ok {
h.Dropped = d.Dropped()
}
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()
if v.Surface == SurfaceAPI {
r.rendAPI.push(v)
} else {
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()
}