gunnar_core/observe.rs
1//! **What an operator can see**: the `tracing` targets, the request id, and
2//! the server's counters.
3//!
4//! # The measurement this module answers
5//!
6//! 58 `tracing::` call sites in 27182 lines of code, no `span!`, no
7//! `#[instrument]`, no request id, no timing and no counters. Closing the gRPC
8//! audit hole moved the worst of that distribution and none of the total.
9//! At forge scale an operator has minutes to answer *which connection, which
10//! principal, which repository, how long did it take, how many failed, is the
11//! queue growing*. None of it was answerable from gunnar's output at all.
12//!
13//! # One vocabulary, not one per crate
14//!
15//! [`TARGET_AUDIT`] already existed, in `gunnar_grpc::auth`. Everything added
16//! since is a **sibling of it**, defined here once, so `RUST_LOG` selects a
17//! *subsystem* rather than a crate name that happens to hold the call site:
18//!
19//! | target | what is on it |
20//! |---|---|
21//! | [`TARGET_AUDIT`] | control-plane mutations: who called what, and the decision |
22//! | [`TARGET_SSH`] | the connection: accept, publickey, exec dispatch, every refusal |
23//! | [`TARGET_GIT`] | transfers: upload-pack, receive-pack, objects, packs, bytes |
24//! | [`TARGET_POLICY`] | the push gate: which gate refused which reference |
25//! | [`TARGET_STORE`] | ref transactions, compare-and-swap contention, repack |
26//! | [`TARGET_METRICS`] | the counters: the heartbeat, and the scrape endpoint |
27//! | [`TARGET_LFS`] | large-file transfers: the session, its verbs, its refusals |
28//! | [`TARGET_RUNNER`] | the build runner: what it picked up, what it built, its refusals |
29//! | [`TARGET_ARCHIVE`] | archiving a repository off the box and back in |
30//! | [`TARGET_REPLICATION`] | replication to a standby: shipped, lagging, refused |
31//! | [`TARGET_SPACE`] | disk headroom: what a write may take, and the refusals when it is short |
32//! | [`TARGET_REPAIR`] | the repair plane: the boot check, the pull channel, the recharges they run |
33//! | [`TARGET_LIVE`] | the live update: a version staged, the re-exec, the trial and its roll back |
34//!
35//! ```text
36//! RUST_LOG=warn,gunnar::audit=info,gunnar::git=info # the two an operator watches
37//! RUST_LOG=gunnar::ssh=debug # one connection, in detail
38//! ```
39//!
40//! `gunnar-grpc` cannot link this crate (it is expressed in `gunnar-proto`
41//! terms and deliberately has no `gunnar-core` edge), so it keeps its own
42//! `AUDIT_TARGET` **string**. That is the one place a constant is stated twice,
43//! and it is not left to a comment: `gunnar-cli` links both crates and
44//! `the_audit_target_is_the_same_string_in_both_crates` asserts they are equal.
45//!
46//! # Levels
47//!
48//! `info` is the production default and must stay legible: one line per
49//! connection authenticated, one per transfer served with its applied outputs,
50//! one per reference moved, and every refusal at `warn`. `debug` is the
51//! diagnostic tier: per-frame detail, environment requests, CAS retries. A
52//! server that has to run at `trace` to be legible has failed.
53//!
54//! # Cost
55//!
56//! [`RequestId`] is a `u64` that formats itself; it never allocates and never
57//! touches a lock. [`ServerMetrics`] is a flat block of [`AtomicU64`] read and
58//! written with [`Ordering::Relaxed`]. **No mutex is taken to record a
59//! counter**, because a signal that costs a lock is paid for by the thing it is
60//! measuring. `tracing`'s macros evaluate their field expressions only inside
61//! the `enabled!` branch, so a line that will not be emitted allocates nothing
62//! even where the field is a `String`.
63
64use std::sync::atomic::{AtomicU64, Ordering};
65use std::sync::OnceLock;
66
67// ───────────────────────────────────────────────────────────────────────────
68// Targets
69// ───────────────────────────────────────────────────────────────────────────
70
71/// Control-plane mutations: who called what, over which credential, and what
72/// was decided. Written by `gunnar-grpc`, which states the same literal
73/// because it cannot link this crate. See the module docs.
74pub const TARGET_AUDIT: &str = "gunnar::audit";
75
76/// The SSH connection: accepted, authenticated, dispatched, refused.
77pub const TARGET_SSH: &str = "gunnar::ssh";
78
79/// Git transfers: `upload-pack`, `receive-pack`, and their applied outputs.
80pub const TARGET_GIT: &str = "gunnar::git";
81
82/// The push gate: which gate refused which reference, and why.
83pub const TARGET_POLICY: &str = "gunnar::policy";
84
85/// Storage: ref transactions, compare-and-swap contention, repack.
86pub const TARGET_STORE: &str = "gunnar::store";
87
88/// The counter heartbeat, and the scrape endpoint.
89pub const TARGET_METRICS: &str = "gunnar::metrics";
90
91/// Large-file transfers: the LFS session, its verbs, and every refusal.
92///
93/// Added 2026-08-05, and it did not replace nothing. `gunnar-lfs` was emitting
94/// on **`"gunnar.lfs"`** — a dot, not a `::` — at five call sites, and
95/// the old znippy engine crate, `gunnar-cli`'s znippy-engine arm and `gunnar-znippy` were
96/// emitting on `"gunnar.store"` at twelve more. `RUST_LOG=gunnar::lfs=debug`
97/// selected none of them; neither did `gunnar::store=info`, which this
98/// module's own table tells an operator to use. Seventeen lines that could be
99/// written and never read.
100///
101/// That is exactly the failure [`TARGETS`] was written to prevent, and
102/// [`TARGETS`] could not see it: it checked the constants in its own list and
103/// no call site ever passes through it. The guard that can is
104/// `every_tracing_target_in_the_shipped_source_is_one_of_ours` in `gunnar-cli`'s
105/// `tests/observability.rs`, which reads the source of every shipped crate.
106pub const TARGET_LFS: &str = "gunnar::lfs";
107
108/// The build runner: what it picked up, what it built, and every refusal.
109///
110/// Added with the runner (roadmap phase 3). A separate target from
111/// [`TARGET_GIT`] because the two answer different questions — "did the push
112/// land" and "did the build run" — and an operator watching one rarely wants a
113/// wall of the other.
114pub const TARGET_RUNNER: &str = "gunnar::runner";
115
116/// Archiving a repository out of the box and back in (`Repos.ArchiveOut`).
117///
118/// `repo.archive_out` when a repository is written to its archive,
119/// `repo.archive_out_failed` when that write does not land.
120///
121/// Emitted by `gunnar-grpc`'s `service::repos` and undeclared until the two
122/// halves of this repository were merged (2026-08-31) — so
123/// `gunnar_core::observe::log_filter`, the filter a deployment installs,
124/// selected neither of its two call sites. The same defect [`TARGET_LFS`]
125/// documents, found by the guard that exists for it.
126///
127/// Undeclared is not harmless here: an archive-out that FAILS is the one event
128/// an operator has to see, so the failure of the very thing that protects the
129/// objects was the least visible line gunnar emitted.
130pub const TARGET_ARCHIVE: &str = "gunnar::archive";
131
132/// Replication to a standby: what was shipped, what lagged, what
133/// refused.
134///
135/// `replication.never_synced`, `replication.stale`, `replication.recovered`.
136///
137/// Emitted by `gunnar-server`'s `replication_view` and undeclared until
138/// 2026-08-31, alongside [`TARGET_ARCHIVE`] and for the same reason. It is the
139/// worst of the three to have had dark: a standby that receives nothing looks
140/// exactly like a standby with nothing to receive, and the lines that tell them
141/// apart were written into a filter that did not select them — so a mirror
142/// could quietly stop being a mirror.
143pub const TARGET_REPLICATION: &str = "gunnar::replication";
144/// The process's own limits: the descriptor budget PID 1 raised, and the WARN
145/// row when it could not raise it far enough.
146///
147/// Added 2026-08-30 for a defect of exactly the shape [`TARGET_LFS`]
148/// documents: `crate::limits` shipped emitting on `"gunnar::limits"`
149/// at two call sites, and no documented filter selected either of them. One of
150/// the two is the `!WARN limits.nofile.low` row the dashboard guide tells an
151/// operator to watch for.
152pub const TARGET_LIMITS: &str = "gunnar::limits";
153
154/// The object index: a reader's own scan of a pending pack, and the memory
155/// watchdog's pause and spill.
156///
157/// Emitted by the znippy git plugin, which cannot link this crate and states
158/// the literal, and rendered by the dashboard as `index paused: …` /
159/// `index.spilled`. Undeclared until 2026-08-30, so
160/// `gunnar_core::observe::log_filter` — the filter a deployment installs —
161/// selected none of it, which is exactly the memory-pressure story an operator
162/// needs when a box collapses under sustained create load.
163pub const TARGET_INDEX: &str = "gunnar::index";
164
165/// Plan enforcement (the `metered` build): a fact accepted or refused at
166/// `Entitlement.Set`, a push refused for a suspended namespace, a cap applied.
167/// Emitted by `gunnar-server::entitlement`; absent from a community binary,
168/// declared here regardless so the filter and the probes name it.
169pub const TARGET_ENTITLEMENT: &str = "gunnar::entitlement";
170/// The twin following a primary's transaction log (`gunnar-server::twin`).
171pub const TARGET_TWIN: &str = "gunnar::twin";
172/// Disk space: the headroom a write is admitted against, the space a push may
173/// take, and the refusals when the volume is short (`gunnar-ssh::space`,
174/// `gunnar-ssh::headroom`). Emitted since 5.x but undeclared until 2026-10-10
175/// (stinky row 22), so the installed filter selected none of it.
176pub const TARGET_SPACE: &str = "gunnar::space";
177
178/// The repair plane: the boot check's findings, the pull channel's word, and
179/// the recharges they run (`gunnar-server::serve`, 5.4 resilience).
180pub const TARGET_REPAIR: &str = "gunnar::repair";
181
182
183/// The live update: a version staged, the graceful stop and re-exec, the trial
184/// and a roll back.
185///
186/// Emitted by `gunnar-server::live_update` since the live update landed
187/// (2026-10-12) and undeclared until 2026-10-14 — so the filter a deployment
188/// installs selected none of its call sites. The defect [`TARGET_LFS`]
189/// documents, found by the guard that exists for it.
190pub const TARGET_LIVE: &str = "gunnar::live";
191
192/// Every target gunnar emits on, so a filter, a document or a test can
193/// enumerate them rather than guess.
194///
195/// A test asserts this list is exactly the constants above and that each is a
196/// `gunnar::` sibling. A target invented at one call site and spelled slightly
197/// differently is invisible to every filter written for the others, which is
198/// the failure this constant exists to prevent.
199pub const TARGETS: &[&str] = &[
200 TARGET_AUDIT,
201 TARGET_SSH,
202 TARGET_GIT,
203 TARGET_POLICY,
204 TARGET_STORE,
205 TARGET_METRICS,
206 TARGET_LFS,
207 TARGET_RUNNER,
208 TARGET_ARCHIVE,
209 TARGET_REPLICATION,
210 TARGET_LIMITS,
211 TARGET_INDEX,
212 TARGET_ENTITLEMENT,
213 TARGET_TWIN,
214 TARGET_SPACE,
215 TARGET_REPAIR,
216 TARGET_LIVE,
217];
218
219/// A `RUST_LOG` directive list: `base` for everything gunnar did not write, and
220/// `gunnar` for every one of [`TARGETS`].
221///
222/// **Built FROM [`TARGETS`], never written out beside it.** The table in this
223/// module's docs is prose and a reader can copy it wrong; a filter that a
224/// deployment installs must not be able to fall behind the list (one implementation). The
225/// 2026-08-05 `"gunnar.lfs"` finding is what a hand-written filter costs:
226/// seventeen call sites no documented filter selected, and nothing failed.
227///
228/// The two levels are separate arguments because they answer different
229/// questions. `base` is how much `russh`, `h2` and `gix` an operator wants to
230/// wade through; `gunnar` is how much of gunnar's own story they want. A single
231/// level cannot say "everything gunnar does, and nothing else at that volume".
232pub fn log_filter(base: &str, gunnar: &str) -> String {
233 let mut spec = String::with_capacity(base.len() + TARGETS.len() * 24);
234 spec.push_str(base);
235 for target in TARGETS {
236 spec.push(',');
237 spec.push_str(target);
238 spec.push('=');
239 spec.push_str(gunnar);
240 }
241 spec
242}
243
244/// Everything outside gunnar, in the filter a service is installed with.
245///
246/// `info` and not `warn`: the lines that say a listener bound, a host key was
247/// loaded and a runtime started come from gunnar at `info` too, and an operator
248/// reading a journal from the top wants the boot to be legible.
249pub const SERVICE_LOG_BASE: &str = "info";
250
251/// gunnar's own targets, in the filter a service is installed with.
252///
253/// `debug` rather than `info`, deliberately. A service is watched when
254/// something is being commissioned or has gone wrong, and the rungs above
255/// `info` in gunnar are per-frame protocol detail on gunnar's OWN targets only
256/// — `base` stays at `info`, so this does not drag `russh`, `h2` and `gix`
257/// debug into the journal with it. Turn it down with `--log-filter`, or move it
258/// live with `SIGUSR1` (`gunnar_cli::logging`).
259pub const SERVICE_LOG_GUNNAR: &str = "debug";
260
261/// **The `RUST_LOG` a `gunnar service install` bakes into the unit.**
262///
263/// One function, so the unit, the documentation and the test that proves the
264/// filter selects gunnar's lines all read the same string.
265pub fn service_log_filter() -> String {
266 log_filter(SERVICE_LOG_BASE, SERVICE_LOG_GUNNAR)
267}
268
269// ───────────────────────────────────────────────────────────────────────────
270// The request id
271// ───────────────────────────────────────────────────────────────────────────
272
273/// A per-connection (or per-request) identifier, carried as a span field so
274/// every line emitted underneath is attributable without repeating it.
275///
276/// # Why not a UUID
277///
278/// A UUID costs a dependency, 16 bytes and a formatting allocation to say
279/// something a 64-bit integer already says. This is a **process seed** in the
280/// high 32 bits and a monotonic counter in the low 32, rendered as 16 hex
281/// digits. Two ids from the same process never collide; two ids from different
282/// runs of the same server collide only if both start within the same
283/// microsecond *and* reach the same counter value, which is not a property a
284/// log correlation needs.
285///
286/// It is `Copy`, it is one `fetch_add(Relaxed)` to mint, and its `Display`
287/// writes into the formatter without allocating.
288#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Hash)]
289pub struct RequestId(u64);
290
291static NEXT_REQUEST_ID: AtomicU64 = AtomicU64::new(1);
292
293/// The high half: distinct per process, so two servers' logs merged into one
294/// stream do not appear to share connections.
295fn process_seed() -> u64 {
296 static SEED: OnceLock<u64> = OnceLock::new();
297 *SEED.get_or_init(|| {
298 let nanos = std::time::SystemTime::now()
299 .duration_since(std::time::UNIX_EPOCH)
300 .map(|d| d.as_nanos() as u64)
301 .unwrap_or(0);
302 // Mix the pid in so two processes started in the same nanosecond bucket
303 // still differ. `id()` is a `u32` and free.
304 (nanos ^ ((std::process::id() as u64) << 40)) & 0xffff_ffff
305 })
306}
307
308impl RequestId {
309 /// Mint the next id. One relaxed atomic increment; never blocks.
310 pub fn next() -> RequestId {
311 let n = NEXT_REQUEST_ID.fetch_add(1, Ordering::Relaxed);
312 RequestId((process_seed() << 32) | (n & 0xffff_ffff))
313 }
314
315 /// The raw value, for a caller that wants to store it as a number.
316 pub fn get(&self) -> u64 {
317 self.0
318 }
319}
320
321impl std::fmt::Display for RequestId {
322 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
323 write!(f, "{:016x}", self.0)
324 }
325}
326
327// ───────────────────────────────────────────────────────────────────────────
328// The counters
329// ───────────────────────────────────────────────────────────────────────────
330
331/// Everything an operator watches, as one flat block of atomics.
332///
333/// Held behind an `Arc` and shared by the SSH listener and the git transport,
334/// which is what makes "connections refused" and "pushes rejected" numbers
335/// about the **same server** rather than two crates' private tallies.
336///
337/// Every method is one `fetch_add(Relaxed)`. There is no lock anywhere in this
338/// type, and [`ServerMetrics::snapshot`] reads the fields independently rather
339/// than under a barrier: these are a signal, and a signal read atomically
340/// across eighteen fields would cost more than it tells anyone.
341#[derive(Debug, Default)]
342pub struct ServerMetrics {
343 connections_opened: AtomicU64,
344 connections_accepted: AtomicU64,
345 connections_anonymous: AtomicU64,
346 connections_refused: AtomicU64,
347 auth_faults: AtomicU64,
348 exec_refused: AtomicU64,
349 transfers_started: AtomicU64,
350 transfers_in_flight: AtomicU64,
351 transfers_failed: AtomicU64,
352 packs_served: AtomicU64,
353 objects_sent: AtomicU64,
354 bytes_out: AtomicU64,
355 bytes_in: AtomicU64,
356 pushes_accepted: AtomicU64,
357 pushes_rejected: AtomicU64,
358 refs_updated: AtomicU64,
359 refs_deleted: AtomicU64,
360 refs_rejected: AtomicU64,
361 gate_refusals: AtomicU64,
362}
363
364/// A reading of [`ServerMetrics`], taken at one moment.
365#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
366pub struct MetricsSnapshot {
367 /// TCP connections russh handed to gunnar.
368 pub connections_opened: u64,
369 /// Connections whose offered key named a principal.
370 pub connections_accepted: u64,
371 /// Connections admitted with **no key at all**, served as the
372 /// anonymous principal, which can only ever read a public repository.
373 ///
374 /// Counted separately from [`MetricsSnapshot::connections_accepted`] rather
375 /// than folded into it: "how much of my traffic is strangers" is the first
376 /// question an operator asks after making anything public, and a total that
377 /// mixed the two could not answer it.
378 pub connections_anonymous: u64,
379 /// Connections whose offered key named nobody. **Not** the same as
380 /// [`MetricsSnapshot::auth_faults`].
381 pub connections_refused: u64,
382 /// Connections refused because the identity table could not be *read*. A
383 /// storage fault looks exactly like an empty table from the client's side,
384 /// and an operator must be able to tell them apart.
385 pub auth_faults: u64,
386 /// Exec requests refused or denied after authentication: a non-git
387 /// command, an unknown repository, a missing grant.
388 pub exec_refused: u64,
389 /// Transfers admitted and begun.
390 pub transfers_started: u64,
391 /// Transfers running right now. A **gauge**, not a total.
392 pub transfers_in_flight: u64,
393 /// Transfers that ended with a protocol or storage error.
394 pub transfers_failed: u64,
395 /// `upload-pack` sessions that sent a packfile.
396 pub packs_served: u64,
397 /// Objects written into those packs.
398 pub objects_sent: u64,
399 /// Bytes gunnar wrote to git clients, counted at the wire.
400 pub bytes_out: u64,
401 /// Bytes gunnar read from git clients, counted at the wire.
402 pub bytes_in: u64,
403 /// Pushes in which every reference landed.
404 pub pushes_accepted: u64,
405 /// Pushes in which at least one reference was refused.
406 pub pushes_rejected: u64,
407 /// References moved.
408 pub refs_updated: u64,
409 /// References deleted.
410 pub refs_deleted: u64,
411 /// Reference updates refused, for any reason.
412 pub refs_rejected: u64,
413 /// Reference updates refused **by a named policy gate**. A subset of
414 /// [`MetricsSnapshot::refs_rejected`], which also counts connectivity
415 /// failures and the collateral refusals of an `--atomic` push.
416 pub gate_refusals: u64,
417}
418
419// **Every field above is written by real code.** A counter nothing increments
420// reads as "this never happens" and is worse than no counter at all. `repacks`
421// was in this struct for exactly one revision before it came out again, because
422// `gunnar gc` runs in a separate process that has no `ServerMetrics` to write
423// to. `a_real_clone_and_push_move_the_counters` in `gunnar-cli` pins the ones a
424// transfer touches; the rest have a red-first proof in their own crate.
425
426/// What a number **means to a reader**: a total that only climbs, or a level
427/// that moves both ways.
428///
429/// One field in this type is a gauge — [`MetricsSnapshot::transfers_in_flight`]
430/// — and it is the whole reason the distinction is carried rather than assumed.
431/// A scraper told everything is a counter charts a busy server's concurrency as
432/// a *rate of transfers per second*, which is a different number with a
433/// plausible shape, and the operator reading it has no way to know.
434#[derive(Debug, Clone, Copy, PartialEq, Eq)]
435pub enum MetricKind {
436 /// Monotonic since start-up. A reader takes its rate.
437 Counter,
438 /// A level, read as it stands.
439 Gauge,
440}
441
442impl MetricKind {
443 /// The word the exposition format's `# TYPE` line uses.
444 pub fn as_str(self) -> &'static str {
445 match self {
446 MetricKind::Counter => "counter",
447 MetricKind::Gauge => "gauge",
448 }
449 }
450}
451
452/// The kind word in the [`counters!`] table, as a value.
453///
454/// Two arms and no fallback, deliberately: a counter declared `guage` — or
455/// declared with no kind at all — **fails to compile**. The alternative is a
456/// default, and a default here would silently publish the next gauge as a
457/// counter, which is the one error in this file that produces a plausible
458/// wrong number instead of an obvious one.
459macro_rules! metric_kind {
460 (counter) => {
461 MetricKind::Counter
462 };
463 (gauge) => {
464 MetricKind::Gauge
465 };
466}
467
468macro_rules! counters {
469 ($($kind:ident $field:ident => $add:ident),* $(,)?) => {
470 impl ServerMetrics {
471 $(
472 #[doc = concat!("Add `n` to `", stringify!($field), "`.")]
473 pub fn $add(&self, n: u64) {
474 self.$field.fetch_add(n, Ordering::Relaxed);
475 }
476 )*
477
478 /// Read every counter.
479 pub fn snapshot(&self) -> MetricsSnapshot {
480 MetricsSnapshot {
481 $($field: self.$field.load(Ordering::Relaxed),)*
482 }
483 }
484 }
485
486 impl MetricsSnapshot {
487 /// Every counter as `(name, kind, value)`, in declaration order.
488 ///
489 /// Generated by the same macro arm that declares the fields, so a
490 /// counter added to [`ServerMetrics`] appears here — and therefore
491 /// on the scrape endpoint — **without anyone remembering to add
492 /// it**. The alternative was a second hand-written list of nineteen
493 /// names, and the counter left out of it would be the one nobody
494 /// could see.
495 ///
496 /// That is not a hypothetical. The heartbeat *was* such a list, and
497 /// it carried eighteen of the nineteen: `connections_anonymous` —
498 /// written by both transports, and the answer to *how much of my
499 /// traffic is strangers* — never appeared in a single line gunnar
500 /// ever printed. See [`MetricsSnapshot::emit_heartbeat`].
501 pub fn fields(&self) -> Vec<(&'static str, MetricKind, u64)> {
502 vec![$((stringify!($field), metric_kind!($kind), self.$field),)*]
503 }
504
505 /// The heartbeat line: one `info` on [`TARGET_METRICS`] naming every
506 /// counter.
507 ///
508 /// Here, and generated, for the reason above: this used to be a
509 /// hand-written `tracing::info!` in `gunnar-cli` listing eighteen of
510 /// the nineteen fields. Expanding from the declaration is the only
511 /// version of it that cannot fall behind (one implementation), and it puts the
512 /// log line and [`MetricsSnapshot::fields`] — the log and the wire —
513 /// on one source of truth rather than two that agree today.
514 ///
515 /// Structured fields and not a rendered string, unchanged from what
516 /// it replaced: `bytes_out=` has to stay greppable in the server's
517 /// stderr, and a JSON subscriber has to still see nineteen typed
518 /// numbers rather than one blob.
519 pub fn emit_heartbeat(&self) {
520 tracing::info!(
521 target: TARGET_METRICS,
522 event = "metrics",
523 $($field = self.$field,)*
524 "gunnar"
525 );
526 }
527 }
528 };
529}
530
531counters! {
532 counter connections_opened => add_connections_opened,
533 counter connections_accepted => add_connections_accepted,
534 counter connections_anonymous => add_connections_anonymous,
535 counter connections_refused => add_connections_refused,
536 counter auth_faults => add_auth_faults,
537 counter exec_refused => add_exec_refused,
538 counter transfers_started => add_transfers_started,
539 gauge transfers_in_flight => add_transfers_in_flight,
540 counter transfers_failed => add_transfers_failed,
541 counter packs_served => add_packs_served,
542 counter objects_sent => add_objects_sent,
543 counter bytes_out => add_bytes_out,
544 counter bytes_in => add_bytes_in,
545 counter pushes_accepted => add_pushes_accepted,
546 counter pushes_rejected => add_pushes_rejected,
547 counter refs_updated => add_refs_updated,
548 counter refs_deleted => add_refs_deleted,
549 counter refs_rejected => add_refs_rejected,
550 counter gate_refusals => add_gate_refusals,
551}
552
553impl ServerMetrics {
554 /// A fresh set of counters, all zero.
555 pub fn new() -> ServerMetrics {
556 ServerMetrics::default()
557 }
558
559 /// A transfer began. Returns a guard whose [`Drop`] decrements
560 /// `transfers_in_flight`, so the gauge cannot be leaked by an error path
561 /// that forgot to close it, the failure mode that turns a working gauge
562 /// into a server that appears permanently busy.
563 pub fn transfer_started(self: &std::sync::Arc<Self>) -> InFlightGuard {
564 self.transfers_started.fetch_add(1, Ordering::Relaxed);
565 self.transfers_in_flight.fetch_add(1, Ordering::Relaxed);
566 InFlightGuard {
567 metrics: std::sync::Arc::clone(self),
568 }
569 }
570}
571
572/// A held `transfers_in_flight` slot. Released by [`Drop`], never by a call.
573#[derive(Debug)]
574pub struct InFlightGuard {
575 metrics: std::sync::Arc<ServerMetrics>,
576}
577
578impl Drop for InFlightGuard {
579 fn drop(&mut self) {
580 self.metrics
581 .transfers_in_flight
582 .fetch_sub(1, Ordering::Relaxed);
583 }
584}
585
586impl MetricsSnapshot {
587 /// Has anything at all been served? Used by the heartbeat to stay quiet on
588 /// an idle server without going quiet on a busy one.
589 pub fn is_zero(&self) -> bool {
590 *self == MetricsSnapshot::default()
591 }
592}
593
594// ───────────────────────────────────────────────────────────────────────────
595// The scrape body
596// ───────────────────────────────────────────────────────────────────────────
597
598/// What every exposed name starts with, so one `gunnar_` selector reaches all
599/// of them and nothing gunnar publishes can collide with a neighbour's series.
600pub const SCRAPE_PREFIX: &str = "gunnar_";
601
602/// The `Content-Type` a Prometheus-compatible scraper expects. Stated once
603/// here, beside the renderer that decides the format, rather than in the
604/// listener that merely writes the header.
605pub const SCRAPE_CONTENT_TYPE: &str = "text/plain; version=0.0.4; charset=utf-8";
606
607impl MetricsSnapshot {
608 /// This reading in the Prometheus text exposition format.
609 ///
610 /// ```text
611 /// # TYPE gunnar_bytes_out counter
612 /// gunnar_bytes_out 4096
613 /// # TYPE gunnar_transfers_in_flight gauge
614 /// gunnar_transfers_in_flight 1
615 /// ```
616 ///
617 /// # Why the names are not suffixed `_total`
618 ///
619 /// Prometheus convention would call the first one `gunnar_bytes_out_total`.
620 /// It is a convention and not a requirement — `# TYPE` is what actually
621 /// carries the semantics, and this renderer emits it for every series — and
622 /// paying it would mean **one counter with two names**: `bytes_out=` in the
623 /// log and `gunnar_bytes_out_total` on the wire. The module's opening
624 /// section argues for one vocabulary across the whole server, and an
625 /// operator who greps the heartbeat and then greps the endpoint for the
626 /// same string is exactly who that section is for. The prefix is worth its
627 /// cost because it prevents collision; the suffix buys a lint.
628 ///
629 /// # Why there is no `# HELP`
630 ///
631 /// Every one of these fields is documented on [`MetricsSnapshot`], and a
632 /// `HELP` line would be a second copy of that prose, in a macro table,
633 /// diverging from the first (one implementation). `# TYPE` is the part a scraper reads.
634 ///
635 /// # Why this is here and not in the listener
636 ///
637 /// It is pure — a `&self` to a `String`, no clock, no I/O, no socket — so
638 /// the format can be asserted without binding a port, and the listener that
639 /// serves it stays a listener. It also means `gunnar-core` gained no
640 /// dependency for the endpoint: the HTTP is somebody else's problem.
641 pub fn render_prometheus(&self) -> String {
642 let mut out = String::with_capacity(self.fields().len() * 64);
643 for (name, kind, value) in self.fields() {
644 out.push_str("# TYPE ");
645 out.push_str(SCRAPE_PREFIX);
646 out.push_str(name);
647 out.push(' ');
648 out.push_str(kind.as_str());
649 out.push('\n');
650 out.push_str(SCRAPE_PREFIX);
651 out.push_str(name);
652 out.push(' ');
653 {
654 use std::fmt::Write as _;
655 // Writing into the buffer rather than `format!`-ing nineteen
656 // little `String`s and dropping each one. `write!` to a
657 // `String` is infallible; the `Result` is discarded for that
658 // reason and not because a failure would be tolerable.
659 let _ = write!(out, "{value}");
660 }
661 out.push('\n');
662 }
663 out
664 }
665}
666
667#[cfg(test)]
668mod tests {
669 use super::*;
670 use std::sync::Arc;
671
672 #[test]
673 fn every_target_is_a_gunnar_sibling_and_the_list_is_complete() {
674 // The scheme, asserted rather than described: one prefix, one `::`
675 // separator, no crate names. A target invented at a call site and
676 // spelled `gunnar_ssh` would be invisible to every filter written for
677 // the others.
678 for target in TARGETS {
679 assert!(
680 target.starts_with("gunnar::"),
681 "{target} is not a sibling of {TARGET_AUDIT}"
682 );
683 assert_eq!(
684 target.matches("::").count(),
685 1,
686 "{target} is not one level deep"
687 );
688 }
689 let mut sorted = TARGETS.to_vec();
690 sorted.sort_unstable();
691 sorted.dedup();
692 assert_eq!(sorted.len(), TARGETS.len(), "TARGETS holds a duplicate");
693 assert!(TARGETS.contains(&TARGET_AUDIT));
694 }
695
696 /// The filter must name **every** target, and it must be derived rather
697 /// than restated — that is the whole reason it is a function.
698 ///
699 /// The identity-value guard is the second half: a filter of `"trace"` would
700 /// select every line in this process and satisfy any test that only asked
701 /// "does gunnar's output appear". So this asserts the filter is a LIST that
702 /// names each target with the gunnar level, and that the base level is
703 /// still in it and is NOT that level. `tests/observability.rs` in
704 /// `gunnar-cli` then asserts the string actually decides events that way.
705 #[test]
706 fn the_service_filter_is_derived_from_the_target_list() {
707 let filter = service_log_filter();
708 for target in TARGETS {
709 let directive = format!("{target}={SERVICE_LOG_GUNNAR}");
710 assert!(
711 filter.contains(&directive),
712 "{directive} is missing from {filter}: a target added to TARGETS did not \
713 reach the filter a service is installed with"
714 );
715 }
716 assert!(
717 filter.starts_with(SERVICE_LOG_BASE),
718 "the filter must open with the base level: {filter}"
719 );
720 assert_ne!(
721 SERVICE_LOG_BASE, SERVICE_LOG_GUNNAR,
722 "with one level for both, this filter says nothing a bare level does not, and \
723 the test above cannot tell a derived filter from a blanket one"
724 );
725 assert_eq!(
726 filter.matches(',').count(),
727 TARGETS.len(),
728 "the filter holds a directive that is not one of ours: {filter}"
729 );
730 }
731
732 #[test]
733 fn request_ids_do_not_repeat() {
734 let a = RequestId::next();
735 let b = RequestId::next();
736 assert_ne!(a, b, "two ids from the same process collided");
737 assert_ne!(
738 a.to_string(),
739 b.to_string(),
740 "two ids RENDERED the same, which is what a log correlation sees"
741 );
742 assert_eq!(a.to_string().len(), 16, "the id must be fixed-width");
743 assert!(
744 a.to_string().chars().all(|c| c.is_ascii_hexdigit()),
745 "the id must be greppable"
746 );
747 // …and the seed half is stable within a process, so a human can spot
748 // two connections belonging to the same server at a glance.
749 assert_eq!(a.get() >> 32, b.get() >> 32);
750 }
751
752 #[test]
753 fn a_counter_moves_and_the_gauge_comes_back_down() {
754 let metrics = Arc::new(ServerMetrics::new());
755 let before = metrics.snapshot();
756 assert!(before.is_zero(), "a fresh set of counters must read zero");
757
758 metrics.add_bytes_out(4096);
759 metrics.add_objects_sent(7);
760 let guard = metrics.transfer_started();
761 let during = metrics.snapshot();
762 assert_eq!(during.bytes_out - before.bytes_out, 4096);
763 assert_eq!(during.objects_sent - before.objects_sent, 7);
764 assert_eq!(during.transfers_started, 1);
765 assert_eq!(during.transfers_in_flight, 1, "the gauge must be up");
766
767 drop(guard);
768 let after = metrics.snapshot();
769 assert_eq!(
770 after.transfers_in_flight, 0,
771 "the in-flight gauge leaked; a server that never comes back to zero \
772 reads as permanently saturated"
773 );
774 assert_eq!(
775 after.transfers_started, 1,
776 "the total is a total, not a gauge"
777 );
778 }
779
780 /// The guard that would have caught `connections_anonymous`.
781 ///
782 /// It names its own subject: **every field of [`MetricsSnapshot`] must be
783 /// reachable through [`MetricsSnapshot::fields`]**, counted against the
784 /// struct itself and not against a list this test also keeps. A second list
785 /// here would be the same defect one layer up — the one the endpoint would
786 /// then be missing a counter from, silently.
787 ///
788 /// It is counted from `Debug`, which the compiler derives from the struct
789 /// definition, so adding a field to `MetricsSnapshot` and forgetting the
790 /// `counters!` table makes this fail without anyone touching this file.
791 #[test]
792 fn every_field_of_the_snapshot_is_published() {
793 let snapshot = MetricsSnapshot::default();
794 let published: Vec<&str> = snapshot.fields().iter().map(|(name, _, _)| *name).collect();
795
796 // `MetricsSnapshot { connections_opened: 0, connections_accepted: 0, … }`
797 let debug = format!("{snapshot:?}");
798 let declared: Vec<String> = debug
799 .trim_start_matches("MetricsSnapshot {")
800 .trim_end_matches('}')
801 .split(',')
802 .filter_map(|pair| pair.split_once(':'))
803 .map(|(name, _)| name.trim().to_owned())
804 .collect();
805 assert_eq!(
806 declared.len(),
807 19,
808 "the Debug parse found {} fields, not the 19 this struct has, so this guard is \
809 reading nothing and would pass against an empty `fields()`: {debug}",
810 declared.len()
811 );
812
813 for field in &declared {
814 assert!(
815 published.contains(&field.as_str()),
816 "`{field}` is a counter of this server that NOTHING publishes: not the \
817 heartbeat, not the scrape endpoint. That is exactly how \
818 `connections_anonymous` stayed invisible."
819 );
820 }
821 assert_eq!(
822 published.len(),
823 declared.len(),
824 "fields() publishes {} names for {} struct fields",
825 published.len(),
826 declared.len()
827 );
828 }
829
830 /// The scrape body, asserted as **text a scraper parses**, not as a call
831 /// that returned.
832 #[test]
833 fn the_scrape_body_names_every_counter_with_its_kind_and_value() {
834 let metrics = Arc::new(ServerMetrics::new());
835 metrics.add_bytes_out(4096);
836 metrics.add_connections_anonymous(3);
837 let _guard = metrics.transfer_started();
838 let body = metrics.snapshot().render_prometheus();
839
840 // The value, not merely the name: a renderer that printed every series
841 // as 0 would satisfy a name-only assertion, and 0 is what a broken
842 // counter also looks like.
843 assert!(
844 body.contains("\ngunnar_bytes_out 4096\n"),
845 "the applied value is not in the body:\n{body}"
846 );
847 assert!(
848 body.contains("\ngunnar_connections_anonymous 3\n"),
849 "the counter no line ever carried is still not carried:\n{body}"
850 );
851 // Kind, and the one that matters: a scraper told the gauge is a counter
852 // charts concurrency as a rate.
853 assert!(
854 body.contains("# TYPE gunnar_transfers_in_flight gauge\n"),
855 "the in-flight gauge is not typed as a gauge:\n{body}"
856 );
857 assert!(
858 body.contains("# TYPE gunnar_bytes_out counter\n"),
859 "a total is not typed as a counter:\n{body}"
860 );
861 // Every series is prefixed and every series is typed, checked over the
862 // whole body rather than over the four names above.
863 let mut samples = 0;
864 for line in body.lines() {
865 if let Some(spec) = line.strip_prefix("# TYPE ") {
866 let (name, kind) = spec.split_once(' ').expect("a TYPE line is `name kind`");
867 assert!(name.starts_with(SCRAPE_PREFIX), "{name} is unprefixed");
868 assert!(kind == "counter" || kind == "gauge", "{kind} is not a kind");
869 continue;
870 }
871 assert!(line.starts_with(SCRAPE_PREFIX), "stray line: {line:?}");
872 let (name, value) = line.split_once(' ').expect("a sample is `name value`");
873 value
874 .parse::<u64>()
875 .unwrap_or_else(|_| panic!("{name} rendered {value:?}, which is not a number"));
876 assert!(
877 body.contains(&format!("# TYPE {name} ")),
878 "{name} is a sample with no TYPE line"
879 );
880 samples += 1;
881 }
882 assert_eq!(
883 samples,
884 metrics.snapshot().fields().len(),
885 "the body carries {samples} samples for {} counters",
886 metrics.snapshot().fields().len()
887 );
888 }
889
890 #[test]
891 fn counters_survive_concurrent_writers() {
892 // Relaxed ordering is still atomic. If any of this were a `+= 1` on a
893 // plain integer the total would come out short.
894 let metrics = Arc::new(ServerMetrics::new());
895 let mut threads = Vec::new();
896 for _ in 0..8 {
897 let metrics = Arc::clone(&metrics);
898 threads.push(std::thread::spawn(move || {
899 for _ in 0..1000 {
900 metrics.add_bytes_out(1);
901 let _guard = metrics.transfer_started();
902 }
903 }));
904 }
905 for t in threads {
906 t.join().expect("a counting thread");
907 }
908 let snapshot = metrics.snapshot();
909 assert_eq!(snapshot.bytes_out, 8000);
910 assert_eq!(snapshot.transfers_started, 8000);
911 assert_eq!(snapshot.transfers_in_flight, 0);
912 }
913}