OXYGENHUB
# 9e8cbfc3ad00 oxygenhub / crates / hub / src / metrics.rs
19.7 KiB · Rust · last changed Flow's job times in /metrics (refs oxygenflow#35, closes #212) 15 days ago source blame history raw
1
//! `/metrics` (oxygenhub#212): the hub's numbers in the Prometheus text
2
//! format, for a monitoring stack (oxygenhub-gcp's Prometheus and Grafana).
3
//! Private: served only to a bearer of `[server] metrics_token`, and not
4
//! at all while that is unset.
5
//!
6
//! The process, the state cache, repositories kept in buckets, OxygenFlow's
7
//! jobs, runs and runners, the transparency log, the database pool, pushes,
8
//! backups, mail, and HTTP requests by route class and status with latency
9
//! histograms. The rest the issue lists comes next.
10
11
use crate::{db, Shared};
12
use axum::extract::State;
13
use axum::http::{header, HeaderMap, StatusCode};
14
use axum::response::{IntoResponse, Response};
15
use std::collections::HashMap;
16
use std::fmt::Write;
17
use std::sync::atomic::{AtomicU64, Ordering};
18
use std::sync::Mutex;
19
20
/// Messages the hub sent, and failed to send, since it started.
21
pub static MAIL_SENT: AtomicU64 = AtomicU64::new(0);
22
pub static MAIL_FAILED: AtomicU64 = AtomicU64::new(0);
23
24
/// Latency buckets, in seconds.
25
const BUCKETS: [f64; 12] = [0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1.0, 2.5, 5.0, 10.0, 30.0];
26
/// At most this many route classes are kept; more go to `other`.
27
const MAX_ROUTES: usize = 300;
28
29
#[derive(Default)]
30
struct Hist {
31
    /// Requests by status class (2xx … 5xx).
32
    by_status: [u64; 4],
33
    buckets: [u64; BUCKETS.len()],
34
    sum: f64,
35
    count: u64,
36
}
37
38
static HTTP: Mutex<Option<HashMap<(String, String), Hist>>> = Mutex::new(None);
39
40
/// Bytes the protocol received and sent, by endpoint, counted before the
41
/// answer is compressed: what pushes and fetches carry.
42
static PROTOCOL: Mutex<std::collections::BTreeMap<&'static str, (u64, u64)>> = Mutex::new(std::collections::BTreeMap::new());
43
44
/// Count a protocol call's request and response bodies.
45
pub fn protocol_bytes(endpoint: &'static str, received: u64, sent: u64) {
46
    let mut g = PROTOCOL.lock().unwrap_or_else(|p| p.into_inner());
47
    let e = g.entry(endpoint).or_default();
48
    e.0 += received;
49
    e.1 += sent;
50
}
51
52
/// A request's route class: a few dozen at most, so a label never holds a
53
/// user's or repository's name.
54
pub fn route_class(path: &str) -> String {
55
    let segs: Vec<&str> = path.trim_start_matches('/').split('/').filter(|s| !s.is_empty()).collect();
56
    let tab = |s: &str| s.chars().all(|c| c.is_ascii_lowercase() || c == '-' || c == '.') && s.len() <= 24;
57
    match segs.as_slice() {
58
        [] => "page:home".into(),
59
        ["static", ..] => "static".into(),
60
        ["api", "v1", area, ..] if tab(area) => format!("api:{area}"),
61
        ["api", ..] => "api".into(),
62
        ["log", ..] => "tlog".into(),
63
        [".well-known", ..] => "well-known".into(),
64
        ["live", ..] => "live".into(),
65
        ["avatar", ..] => "avatar".into(),
66
        [_, _, "oxy", "v1", endpoint, ..] if tab(endpoint) => format!("protocol:{endpoint}"),
67
        [_, _, "oxy", ..] => "protocol".into(),
68
        [_, _, t, ..] if tab(t) => format!("page:{t}"),
69
        [_, _] => "page:repository".into(),
70
        [one] if tab(one) => format!("page:{one}"),
71
        _ => "page:other".into(),
72
    }
73
}
74
75
/// Count a request (from the router's outermost timing layer).
76
pub fn observe(method: &str, path: &str, status: u16, seconds: f64) {
77
    let mut g = HTTP.lock().unwrap_or_else(|p| p.into_inner());
78
    let map = g.get_or_insert_with(HashMap::new);
79
    let mut route = route_class(path);
80
    if !map.contains_key(&(route.clone(), method.to_string())) && map.len() >= MAX_ROUTES {
81
        route = "other".into();
82
    }
83
    let h = map.entry((route, method.to_string())).or_default();
84
    let class = (status / 100).clamp(2, 5) as usize - 2;
85
    h.by_status[class] += 1;
86
    for (i, b) in BUCKETS.iter().enumerate() {
87
        if seconds <= *b {
88
            h.buckets[i] += 1;
89
        }
90
    }
91
    h.sum += seconds;
92
    h.count += 1;
93
}
94
95
fn http_families(out: &mut String) {
96
    let g = HTTP.lock().unwrap_or_else(|p| p.into_inner());
97
    let Some(map) = g.as_ref() else { return };
98
    let mut keys: Vec<&(String, String)> = map.keys().collect();
99
    keys.sort();
100
    let _ = writeln!(out, "# HELP oxyhub_http_requests_total HTTP requests by route class, method and status class.");
101
    let _ = writeln!(out, "# TYPE oxyhub_http_requests_total counter");
102
    for k in &keys {
103
        let h = &map[*k];
104
        for (i, n) in h.by_status.iter().enumerate().filter(|(_, n)| **n > 0) {
105
            let _ = writeln!(
106
                out,
107
                "oxyhub_http_requests_total{{route=\"{}\",method=\"{}\",status=\"{}xx\"}} {n}",
108
                label(&k.0),
109
                label(&k.1),
110
                i + 2
111
            );
112
        }
113
    }
114
    let _ = writeln!(out, "# HELP oxyhub_http_request_duration_seconds How long requests took, by route class and method.");
115
    let _ = writeln!(out, "# TYPE oxyhub_http_request_duration_seconds histogram");
116
    for k in &keys {
117
        let h = &map[*k];
118
        let l = format!("route=\"{}\",method=\"{}\"", label(&k.0), label(&k.1));
119
        for (i, b) in BUCKETS.iter().enumerate() {
120
            let _ = writeln!(out, "oxyhub_http_request_duration_seconds_bucket{{{l},le=\"{b}\"}} {}", h.buckets[i]);
121
        }
122
        let _ = writeln!(out, "oxyhub_http_request_duration_seconds_bucket{{{l},le=\"+Inf\"}} {}", h.count);
123
        let _ = writeln!(out, "oxyhub_http_request_duration_seconds_sum{{{l}}} {}", h.sum);
124
        let _ = writeln!(out, "oxyhub_http_request_duration_seconds_count{{{l}}} {}", h.count);
125
    }
126
}
127
128
/// One metric family: its help, type and samples (label set, value).
129
fn family(out: &mut String, name: &str, help: &str, kind: &str, samples: &[(String, f64)]) {
130
    let _ = writeln!(out, "# HELP {name} {help}");
131
    let _ = writeln!(out, "# TYPE {name} {kind}");
132
    for (labels, v) in samples {
133
        if labels.is_empty() {
134
            let _ = writeln!(out, "{name} {v}");
135
        } else {
136
            let _ = writeln!(out, "{name}{{{labels}}} {v}");
137
        }
138
    }
139
}
140
141
/// A label value, escaped as the text format asks.
142
fn label(v: &str) -> String {
143
    v.replace('\\', "\\\\").replace('"', "\\\"").replace('\n', "\\n")
144
}
145
146
/// The process's resident memory, from /proc (Linux), in bytes.
147
fn resident_bytes() -> Option<f64> {
148
    let statm = std::fs::read_to_string("/proc/self/statm").ok()?;
149
    let pages: f64 = statm.split_whitespace().nth(1)?.parse().ok()?;
150
    Some(pages * 4096.0)
151
}
152
153
/// The metrics as text, for whoever is let in.
154
pub async fn render(app: &Shared) -> String {
155
    let mut out = String::new();
156
    family(
157
        &mut out,
158
        "oxyhub_build_info",
159
        "The hub's version and build.",
160
        "gauge",
161
        &[(format!("version=\"{}\",build=\"{}\"", env!("CARGO_PKG_VERSION"), label(env!("OXY_BUILD_ID"))), 1.0)],
162
    );
163
    family(
164
        &mut out,
165
        "oxyhub_uptime_seconds",
166
        "Seconds since the hub started.",
167
        "gauge",
168
        &[(String::new(), app.started.elapsed().as_secs_f64())],
169
    );
170
    if let Some(rss) = resident_bytes() {
171
        family(&mut out, "oxyhub_resident_memory_bytes", "The process's resident memory.", "gauge", &[(String::new(), rss)]);
172
    }
173
    let (states, weight, summaries) = app.repos.cache().stats();
174
    family(&mut out, "oxyhub_state_cache_states", "States the state cache holds.", "gauge", &[(String::new(), states as f64)]);
175
    family(
176
        &mut out,
177
        "oxyhub_state_cache_bytes",
178
        "What the state cache's states are estimated to weigh.",
179
        "gauge",
180
        &[(String::new(), weight as f64)],
181
    );
182
    family(
183
        &mut out,
184
        "oxyhub_state_cache_budget_bytes",
185
        "What the state cache may hold.",
186
        "gauge",
187
        &[(String::new(), crate::repos::cache::budget() as f64)],
188
    );
189
    family(&mut out, "oxyhub_state_cache_summaries", "Summaries the state cache holds.", "gauge", &[(String::new(), summaries as f64)]);
190
    let strata = oxy_strata::stats();
191
    family(
192
        &mut out,
193
        "oxyhub_bucket_clients_opened_total",
194
        "Bucket store clients opened.",
195
        "counter",
196
        &[(String::new(), strata.opens as f64)],
197
    );
198
    family(
199
        &mut out,
200
        "oxyhub_bucket_requests_total",
201
        "Requests to bucket stores, by kind.",
202
        "counter",
203
        &strata.ops().map(|(k, n)| (format!("kind=\"{k}\""), n as f64)).collect::<Vec<_>>(),
204
    );
205
    family(
206
        &mut out,
207
        "oxyhub_bucket_request_seconds_total",
208
        "Time spent in requests to bucket stores.",
209
        "counter",
210
        &[(String::new(), strata.millis as f64 / 1000.0)],
211
    );
212
    let jobs: Vec<(String, i64)> =
213
        sqlx::query_as("SELECT status, COUNT(*) FROM flow_jobs WHERE status IN ('queued', 'running') GROUP BY status")
214
            .fetch_all(&app.db)
215
            .await
216
            .unwrap_or_default();
217
    let count = |s: &str| jobs.iter().find(|(k, _)| k == s).map(|(_, n)| *n).unwrap_or(0) as f64;
218
    let waiting: i64 = sqlx::query_scalar("SELECT COUNT(*) FROM flow_jobs WHERE status = 'queued' AND approval = 'waiting'")
219
        .fetch_one(&app.db)
220
        .await
221
        .unwrap_or(0);
222
    family(
223
        &mut out,
224
        "oxyhub_flow_jobs",
225
        "OxygenFlow jobs now, by state (waiting: for a person's approval).",
226
        "gauge",
227
        &[
228
            ("state=\"queued\"".into(), count("queued") - waiting as f64),
229
            ("state=\"waiting\"".into(), waiting as f64),
230
            ("state=\"running\"".into(), count("running")),
231
        ],
232
    );
233
    let runners = db::runners::list(&app.db).await.unwrap_or_default();
234
    family(
235
        &mut out,
236
        "oxyhub_flow_runners",
237
        "Registered OxygenFlow runners, by whether they reported in the last minutes.",
238
        "gauge",
239
        &[
240
            ("online=\"true\"".into(), runners.iter().filter(|r| r.online()).count() as f64),
241
            ("online=\"false\"".into(), runners.iter().filter(|r| !r.online()).count() as f64),
242
        ],
243
    );
244
    let now = db::now_ms();
245
    family(
246
        &mut out,
247
        "oxyhub_flow_runner_last_seen_seconds",
248
        "Seconds since each registered runner last called the hub.",
249
        "gauge",
250
        &runners
251
            .iter()
252
            .filter_map(|r| r.last_seen_ms.map(|t| (format!("runner=\"{}\"", label(&r.name)), (now - t).max(0) as f64 / 1000.0)))
253
            .collect::<Vec<_>>(),
254
    );
255
    let since = now - 86_400_000;
256
    let runs: Vec<(String, i64)> = sqlx::query_as("SELECT status, COUNT(*) FROM flow_runs WHERE finished_ms > $1 GROUP BY status")
257
        .bind(since)
258
        .fetch_all(&app.db)
259
        .await
260
        .unwrap_or_default();
261
    family(
262
        &mut out,
263
        "oxyhub_flow_runs_last_day",
264
        "OxygenFlow runs finished in the last 24 hours, by result.",
265
        "gauge",
266
        &["passed", "failed", "error"]
267
            .iter()
268
            .map(|r| (format!("result=\"{r}\""), runs.iter().find(|(s, _)| s == r).map(|(_, n)| *n).unwrap_or(0) as f64))
269
            .collect::<Vec<_>>(),
270
    );
271
    family(&mut out, "oxyhub_tlog_entries", "Entries in the transparency log.", "gauge", &[(String::new(), app.tlog.size() as f64)]);
272
    let protocol: Vec<(&'static str, (u64, u64))> =
273
        PROTOCOL.lock().unwrap_or_else(|p| p.into_inner()).iter().map(|(k, v)| (*k, *v)).collect();
274
    family(
275
        &mut out,
276
        "oxyhub_protocol_bytes_total",
277
        "Bytes the Oxygen protocol received and sent since the hub started, by endpoint, before compression: push carries pushes, fetch and objects carry fetches.",
278
        "counter",
279
        &protocol
280
            .iter()
281
            .flat_map(|(e, (rx, tx))| {
282
                [(format!("endpoint=\"{e}\",direction=\"received\""), *rx as f64), (format!("endpoint=\"{e}\",direction=\"sent\""), *tx as f64)]
283
            })
284
            .collect::<Vec<_>>(),
285
    );
286
    family(
287
        &mut out,
288
        "oxyhub_mail_total",
289
        "Messages the hub sent and failed to send since it started.",
290
        "counter",
291
        &[
292
            ("result=\"sent\"".into(), MAIL_SENT.load(Ordering::Relaxed) as f64),
293
            ("result=\"failed\"".into(), MAIL_FAILED.load(Ordering::Relaxed) as f64),
294
        ],
295
    );
296
    family(
297
        &mut out,
298
        "oxyhub_db_connections",
299
        "The database pool's connections, by whether they are idle.",
300
        "gauge",
301
        &[
302
            ("idle=\"true\"".into(), app.db.num_idle() as f64),
303
            ("idle=\"false\"".into(), (app.db.size() as f64 - app.db.num_idle() as f64).max(0.0)),
304
        ],
305
    );
306
    let (ok, refused): (Option<i64>, Option<i64>) =
307
        sqlx::query_as("SELECT SUM(CASE WHEN ok THEN 1 ELSE 0 END), SUM(CASE WHEN ok THEN 0 ELSE 1 END) FROM pushes WHERE at_ms > $1")
308
            .bind(since)
309
            .fetch_one(&app.db)
310
            .await
311
            .unwrap_or((None, None));
312
    family(
313
        &mut out,
314
        "oxyhub_pushes_last_day",
315
        "Reference updates pushed in the last 24 hours, by whether they were accepted.",
316
        "gauge",
317
        &[("result=\"accepted\"".into(), ok.unwrap_or(0) as f64), ("result=\"refused\"".into(), refused.unwrap_or(0) as f64)],
318
    );
319
    let backups: Vec<(String, String, i64, Option<i64>)> = sqlx::query_as(
320
        "SELECT owner, status, started_ms, finished_ms FROM backup_runs WHERE id IN (SELECT MAX(id) FROM backup_runs GROUP BY owner) ORDER BY owner",
321
    )
322
    .fetch_all(&app.db)
323
    .await
324
    .unwrap_or_default();
325
    family(
326
        &mut out,
327
        "oxyhub_backup_last_run_age_seconds",
328
        "Seconds since each owner's latest backup run started.",
329
        "gauge",
330
        &backups.iter().map(|(o, _, s, _)| (format!("owner=\"{}\"", label(o)), (now - s) as f64 / 1000.0)).collect::<Vec<_>>(),
331
    );
332
    family(
333
        &mut out,
334
        "oxyhub_backup_last_run_ok",
335
        "Whether each owner's latest finished backup run succeeded (1), was partial or failed (0); running ones are left out.",
336
        "gauge",
337
        &backups
338
            .iter()
339
            .filter(|(_, st, _, f)| f.is_some() && st != "running")
340
            .map(|(o, st, _, _)| (format!("owner=\"{}\"", label(o)), if st == "ok" { 1.0 } else { 0.0 }))
341
            .collect::<Vec<_>>(),
342
    );
343
    flow_timings(app, &mut out, now).await;
344
    if let Ok((waiting, dead)) = db::queue::counts(&app.db).await {
345
        family(
346
            &mut out,
347
            "oxyhub_queue_items",
348
            "Items in the durable work queue (#276): waiting (due, backing off or claimed) and dead (failed every attempt).",
349
            "gauge",
350
            &[("state=\"waiting\"".into(), waiting as f64), ("state=\"dead\"".into(), dead as f64)],
351
        );
352
    }
353
    http_families(&mut out);
354
    out
355
}
356
357
/// A finished job's runner, result, note, and when it was ready, started
358
/// and finished.
359
type JobTimes = (String, String, String, Option<i64>, Option<i64>, Option<i64>);
360
361
/// Bucket bounds for job times, in seconds.
362
const JOB_SECONDS: [f64; 11] = [1.0, 5.0, 15.0, 30.0, 60.0, 120.0, 300.0, 600.0, 1200.0, 1800.0, 3600.0];
363
364
/// Flow's job times over the last day (oxygenflow#35), by runner: how long
365
/// jobs waited from ready to started (queue time) and ran (run time), and
366
/// how many finished, by result, and were reused (#265).
367
async fn flow_timings(app: &Shared, out: &mut String, now: i64) {
368
    let rows: Vec<JobTimes> = sqlx::query_as(
369
        "SELECT runner, status, error, COALESCE(ready_ms, queued_ms), started_ms, finished_ms FROM flow_jobs \
370
         WHERE finished_ms >= $1 AND status IN ('passed', 'failed', 'error', 'cancelled')",
371
    )
372
    .bind(now - 86_400_000)
373
    .fetch_all(&app.db)
374
    .await
375
    .unwrap_or_default();
376
    let mut queue: std::collections::BTreeMap<String, Vec<f64>> = Default::default();
377
    let mut run: std::collections::BTreeMap<String, Vec<f64>> = Default::default();
378
    let mut finished: std::collections::BTreeMap<(String, String), f64> = Default::default();
379
    let mut reused = 0.0;
380
    for (runner, status, error, ready, started, finished_ms) in &rows {
381
        if error.starts_with("reused from run #") {
382
            reused += 1.0;
383
            continue;
384
        }
385
        let r = if runner.is_empty() { "none".to_string() } else { runner.clone() };
386
        *finished.entry((r.clone(), status.clone())).or_default() += 1.0;
387
        if let (Some(ready), Some(started)) = (ready, started) {
388
            queue.entry(r.clone()).or_default().push((started - ready).max(0) as f64 / 1000.0);
389
        }
390
        if let (Some(started), Some(f)) = (started, finished_ms) {
391
            run.entry(r).or_default().push((f - started).max(0) as f64 / 1000.0);
392
        }
393
    }
394
    histogram(
395
        out,
396
        "oxyhub_flow_job_queue_seconds",
397
        "How long finished jobs of the last day waited from ready to started, by runner.",
398
        &queue,
399
    );
400
    histogram(out, "oxyhub_flow_job_run_seconds", "How long finished jobs of the last day ran, by runner.", &run);
401
    family(
402
        out,
403
        "oxyhub_flow_jobs_finished_last_day",
404
        "Jobs that finished in the last day, by runner and result (none: never placed).",
405
        "gauge",
406
        &finished.iter().map(|((r, st), n)| (format!("runner=\"{}\",status=\"{}\"", label(r), label(st)), *n)).collect::<Vec<_>>(),
407
    );
408
    family(
409
        out,
410
        "oxyhub_flow_jobs_reused_last_day",
411
        "Jobs of the last day that reused a pass on the same state instead of running (#265).",
412
        "gauge",
413
        &[(String::new(), reused)],
414
    );
415
}
416
417
/// A histogram family from samples (seconds) per runner.
418
fn histogram(out: &mut String, name: &str, help: &str, by_runner: &std::collections::BTreeMap<String, Vec<f64>>) {
419
    let _ = writeln!(out, "# HELP {name} {help}");
420
    let _ = writeln!(out, "# TYPE {name} histogram");
421
    for (runner, samples) in by_runner {
422
        let l = format!("runner=\"{}\"", label(runner));
423
        for b in JOB_SECONDS {
424
            let n = samples.iter().filter(|s| **s <= b).count();
425
            let _ = writeln!(out, "{name}_bucket{{{l},le=\"{b}\"}} {n}");
426
        }
427
        let _ = writeln!(out, "{name}_bucket{{{l},le=\"+Inf\"}} {}", samples.len());
428
        let _ = writeln!(out, "{name}_sum{{{l}}} {}", samples.iter().sum::<f64>());
429
        let _ = writeln!(out, "{name}_count{{{l}}} {}", samples.len());
430
    }
431
}
432
433
/// `GET /metrics`.
434
pub async fn metrics(State(app): State<Shared>, headers: HeaderMap) -> Response {
435
    let want = &app.config.server.metrics_token;
436
    if want.is_empty() {
437
        return (StatusCode::NOT_FOUND, "metrics are off: set [server] metrics_token in hub.toml\n").into_response();
438
    }
439
    let given = oxy_server::bearer_token(&headers).unwrap_or("");
440
    if !crate::auth::mac_equal(given, want) {
441
        return (StatusCode::UNAUTHORIZED, [(header::WWW_AUTHENTICATE, "Bearer")], "a bearer token is needed\n").into_response();
442
    }
443
    ([(header::CONTENT_TYPE, "text/plain; version=0.0.4; charset=utf-8"), (header::CACHE_CONTROL, "no-store")], render(&app).await)
444
        .into_response()
445
}
446
447
#[cfg(test)]
448
mod tests {
449
450
    #[test]
451
    fn job_times_are_cumulative_buckets_per_runner() {
452
        let mut by: std::collections::BTreeMap<String, Vec<f64>> = Default::default();
453
        by.insert("earth-1".into(), vec![0.5, 20.0, 4000.0]);
454
        let mut out = String::new();
455
        super::histogram(&mut out, "x_seconds", "help", &by);
456
        assert!(out.contains("x_seconds_bucket{runner=\"earth-1\",le=\"1\"} 1"), "{out}");
457
        assert!(out.contains("x_seconds_bucket{runner=\"earth-1\",le=\"30\"} 2"), "{out}");
458
        assert!(out.contains("x_seconds_bucket{runner=\"earth-1\",le=\"3600\"} 2"), "{out}");
459
        assert!(
460
            out.contains("x_seconds_bucket{runner=\"earth-1\",le=\"+Inf\"} 3") && out.contains("x_seconds_count{runner=\"earth-1\"} 3"),
461
            "{out}"
462
        );
463
    }
464
465
    #[test]
466
    fn route_classes_hold_no_names() {
467
        for (path, class) in [
468
            ("/", "page:home"),
469
            ("/static/hub.js", "static"),
470
            ("/api/v1/repos/andy/demo/issues", "api:repos"),
471
            ("/andy/demo/oxy/v1/negotiate", "protocol:negotiate"),
472
            ("/andy/demo/issue/3", "page:issue"),
473
            ("/andy/demo", "page:repository"),
474
            ("/explore", "page:explore"),
475
            ("/Andy_McCall", "page:other"),
476
            ("/log/tile/0/000", "tlog"),
477
        ] {
478
            assert_eq!(super::route_class(path), class, "{path}");
479
        }
480
    }
481
}