spate_core/metrics/sink.rs
1//! Sink-shard handles (`spate_sink_*`), one struct per shard worker, plus the
2//! end-to-end latency histogram observed at the terminal stage.
3
4use super::labels::{ComponentLabels, OwnedGauge};
5use super::names;
6use super::ownership::{SeriesClaim, series_key};
7use super::{E2eBasis, MetricsError};
8use crate::error::ErrorClass;
9use metrics::{Counter, Histogram, SharedString};
10use std::collections::HashMap;
11use std::sync::Mutex;
12use std::time::Duration;
13
14/// Why a sink batch was sealed and flushed.
15#[derive(Clone, Copy, Debug, PartialEq, Eq)]
16pub enum FlushReason {
17 /// `max_rows` reached.
18 Rows,
19 /// `max_bytes` reached.
20 Bytes,
21 /// Linger deadline expired.
22 Linger,
23 /// Drain (shutdown or revocation) forced the seal.
24 Drain,
25}
26
27impl FlushReason {
28 fn label(self) -> &'static str {
29 match self {
30 FlushReason::Rows => "rows",
31 FlushReason::Bytes => "bytes",
32 FlushReason::Linger => "linger",
33 FlushReason::Drain => "drain",
34 }
35 }
36}
37
38/// Outcome of one sink write attempt (the `outcome` label on
39/// `spate_sink_write_duration_seconds`).
40///
41/// One family with a label rather than two names, matching `outcome` on the
42/// three counter families that already use it. Both outcomes are the same
43/// measurement (time inside `write_batch`) over the same population
44/// (attempts), so the aggregate is well-defined.
45#[derive(Clone, Copy, Debug, PartialEq, Eq)]
46#[non_exhaustive]
47pub(crate) enum AttemptOutcome {
48 /// The write was accepted.
49 Ok,
50 /// The write failed; its taxonomy class goes to
51 /// [`SinkShardMetrics::errors`].
52 Error,
53}
54
55/// Per-replica handles inside one shard.
56#[derive(Debug)]
57struct ReplicaMetrics {
58 healthy: OwnedGauge,
59 breaker_opens: Counter,
60 errors: Counter,
61}
62
63/// Sink-shard handles (`spate_sink_*`), one struct per shard worker.
64#[derive(Debug)]
65pub struct SinkShardMetrics {
66 records: Counter,
67 bytes: Counter,
68 batch_rows: Histogram,
69 batch_bytes: Histogram,
70 flush_rows: Counter,
71 flush_bytes: Counter,
72 flush_linger: Counter,
73 flush_drain: Counter,
74 flush_duration: Histogram,
75 write_ok: Histogram,
76 write_err: Histogram,
77 permit_wait: Histogram,
78 retries: Counter,
79 retry_backoff: OwnedGauge,
80 /// Current backoff step, in seconds, of every batch of this shard that is
81 /// sleeping between write attempts, keyed by batch sequence number. The
82 /// gauge publishes the max; the map is bounded by `inflight.max_per_shard`
83 /// and empties back to nothing whenever the shard stops backing off.
84 backoff_steps: Mutex<HashMap<u64, f64>>,
85 err_retryable: Counter,
86 err_record: Counter,
87 err_fatal: Counter,
88 inflight: OwnedGauge,
89 abandoned: Counter,
90 drain_overrun: Counter,
91 shard_healthy: OwnedGauge,
92 e2e: Histogram,
93 e2e_basis: E2eBasis,
94 replicas: Vec<ReplicaMetrics>,
95 _claim: Option<SeriesClaim>,
96}
97
98impl SinkShardMetrics {
99 /// Resolve all handles for one shard. `replicas` are display names used
100 /// as the `replica` label (bounded by cluster topology). `e2e_basis`
101 /// selects the time base for `spate_e2e_latency_seconds`; [the metrics
102 /// reference] carries what each basis measures.
103 ///
104 /// Call **after** [`install`](crate::metrics::install). Handles bind to
105 /// the recorder present at construction, and a handle built before the
106 /// exporter exists silently records into the void.
107 ///
108 /// Claims this shard's series (the labels plus `shard`) so that only one
109 /// live handle set publishes them. The gauges here are edge-triggered
110 /// (health flips on a breaker transition, backoff on a retry), so a second
111 /// writer's reading would stand until the owner's next transition, which
112 /// for a quarantined shard may be never. A collision therefore logs and
113 /// leaves this instance a shadow: its counters still record, its gauges do
114 /// not. Assembly through [`Pipeline`](crate::pipeline::Pipeline) refuses
115 /// to build instead.
116 ///
117 /// [the metrics reference]: https://spate.kainth.dev/docs/METRICS
118 pub fn new(
119 labels: &ComponentLabels,
120 shard: u32,
121 replicas: &[String],
122 e2e_basis: E2eBasis,
123 ) -> Self {
124 let claim = SeriesClaim::claim_or_shadow(Self::key(labels, shard));
125 Self::build(labels, shard, replicas, e2e_basis, claim)
126 }
127
128 /// Resolve all handles for one shard, failing when another live handle set
129 /// already owns the shard's series. The pipeline builder's path.
130 ///
131 /// # Errors
132 ///
133 /// [`MetricsError::DuplicateSeries`] on a collision.
134 pub fn try_new(
135 labels: &ComponentLabels,
136 shard: u32,
137 replicas: &[String],
138 e2e_basis: E2eBasis,
139 ) -> Result<Self, MetricsError> {
140 let claim = SeriesClaim::try_claim(Self::key(labels, shard))?;
141 Ok(Self::build(labels, shard, replicas, e2e_basis, Some(claim)))
142 }
143
144 fn key(labels: &ComponentLabels, shard: u32) -> String {
145 series_key("sink", labels, &format!("shard={shard}"))
146 }
147
148 fn build(
149 labels: &ComponentLabels,
150 shard: u32,
151 replicas: &[String],
152 e2e_basis: E2eBasis,
153 claim: Option<SeriesClaim>,
154 ) -> Self {
155 // Resolved before any handle is written. The initial publishes below
156 // are the writes that would clobber a live owner's reading.
157 let owned = claim.is_some();
158 let shard: SharedString = shard.to_string().into();
159 let replicas = replicas
160 .iter()
161 .map(|replica| {
162 let m = ReplicaMetrics {
163 healthy: OwnedGauge::new(
164 labels.gauge2(
165 names::SINK_REPLICA_HEALTHY,
166 names::L_SHARD,
167 shard.clone(),
168 names::L_REPLICA,
169 replica.clone(),
170 ),
171 owned,
172 ),
173 breaker_opens: labels.counter2(
174 names::SINK_BREAKER_OPENS_TOTAL,
175 names::L_SHARD,
176 shard.clone(),
177 names::L_REPLICA,
178 replica.clone(),
179 ),
180 errors: labels.counter2(
181 names::SINK_REPLICA_ERRORS_TOTAL,
182 names::L_SHARD,
183 shard.clone(),
184 names::L_REPLICA,
185 replica.clone(),
186 ),
187 };
188 m.healthy.set(1.0);
189 m
190 })
191 .collect();
192 let shard_healthy = OwnedGauge::new(
193 labels.gauge1(names::SINK_SHARD_HEALTHY, names::L_SHARD, shard.clone()),
194 owned,
195 );
196 shard_healthy.set(1.0);
197 // Published as `0` from construction rather than left absent until the
198 // first retry. "This shard is not backing off" is true of a shard that
199 // has never written. (Contrast `spate_source_lag_records`, where
200 // absence carries information; see the "Absent, zero, and stale"
201 // section of `docs/METRICS.md`.)
202 let retry_backoff = OwnedGauge::new(
203 labels.gauge1(
204 names::SINK_RETRY_BACKOFF_SECONDS,
205 names::L_SHARD,
206 shard.clone(),
207 ),
208 owned,
209 );
210 retry_backoff.set(0.0);
211 SinkShardMetrics {
212 records: labels.counter1(names::SINK_RECORDS_TOTAL, names::L_SHARD, shard.clone()),
213 bytes: labels.counter1(names::SINK_BYTES_TOTAL, names::L_SHARD, shard.clone()),
214 batch_rows: labels.histogram(names::SINK_BATCH_ROWS),
215 batch_bytes: labels.histogram(names::SINK_BATCH_BYTES),
216 flush_rows: labels.counter2(
217 names::SINK_FLUSHES_TOTAL,
218 names::L_SHARD,
219 shard.clone(),
220 names::L_REASON,
221 FlushReason::Rows.label(),
222 ),
223 flush_bytes: labels.counter2(
224 names::SINK_FLUSHES_TOTAL,
225 names::L_SHARD,
226 shard.clone(),
227 names::L_REASON,
228 FlushReason::Bytes.label(),
229 ),
230 flush_linger: labels.counter2(
231 names::SINK_FLUSHES_TOTAL,
232 names::L_SHARD,
233 shard.clone(),
234 names::L_REASON,
235 FlushReason::Linger.label(),
236 ),
237 flush_drain: labels.counter2(
238 names::SINK_FLUSHES_TOTAL,
239 names::L_SHARD,
240 shard.clone(),
241 names::L_REASON,
242 FlushReason::Drain.label(),
243 ),
244 flush_duration: labels.histogram1(
245 names::SINK_FLUSH_DURATION_SECONDS,
246 names::L_SHARD,
247 shard.clone(),
248 ),
249 write_ok: labels.histogram2(
250 names::SINK_WRITE_DURATION_SECONDS,
251 names::L_SHARD,
252 shard.clone(),
253 names::L_OUTCOME,
254 "ok",
255 ),
256 write_err: labels.histogram2(
257 names::SINK_WRITE_DURATION_SECONDS,
258 names::L_SHARD,
259 shard.clone(),
260 names::L_OUTCOME,
261 "error",
262 ),
263 permit_wait: labels.histogram1(
264 names::SINK_PERMIT_WAIT_DURATION_SECONDS,
265 names::L_SHARD,
266 shard.clone(),
267 ),
268 retries: labels.counter1(names::SINK_RETRIES_TOTAL, names::L_SHARD, shard.clone()),
269 retry_backoff,
270 backoff_steps: Mutex::new(HashMap::new()),
271 err_retryable: labels.counter2(
272 names::SINK_ERRORS_TOTAL,
273 names::L_SHARD,
274 shard.clone(),
275 names::L_ERROR_TYPE,
276 ErrorClass::Retryable.label(),
277 ),
278 err_record: labels.counter2(
279 names::SINK_ERRORS_TOTAL,
280 names::L_SHARD,
281 shard.clone(),
282 names::L_ERROR_TYPE,
283 ErrorClass::RecordLevel.label(),
284 ),
285 err_fatal: labels.counter2(
286 names::SINK_ERRORS_TOTAL,
287 names::L_SHARD,
288 shard.clone(),
289 names::L_ERROR_TYPE,
290 ErrorClass::Fatal.label(),
291 ),
292 inflight: OwnedGauge::new(
293 labels.gauge1(names::SINK_INFLIGHT_BATCHES, names::L_SHARD, shard.clone()),
294 owned,
295 ),
296 abandoned: labels.counter1(
297 names::SINK_ABANDONED_BATCHES_TOTAL,
298 names::L_SHARD,
299 shard.clone(),
300 ),
301 drain_overrun: labels.counter1(names::SINK_DRAIN_OVERRUN_TOTAL, names::L_SHARD, shard),
302 shard_healthy,
303 e2e: labels.histogram(names::E2E_LATENCY_SECONDS),
304 e2e_basis,
305 replicas,
306 _claim: claim,
307 }
308 }
309
310 /// Observe end-to-end latency for one durably written batch, from its
311 /// oldest record. `ingest_age` is time since that record entered the
312 /// terminal stage; `oldest_event_ms` is its source event time. The
313 /// configured basis picks which one lands in the histogram (event
314 /// basis falls back to ingest when no event time was available).
315 #[inline]
316 pub fn e2e_observed(&self, ingest_age: Duration, oldest_event_ms: i64) {
317 let latency = match self.e2e_basis {
318 E2eBasis::Event if oldest_event_ms != i64::MAX => {
319 let now_ms = std::time::SystemTime::now()
320 .duration_since(std::time::UNIX_EPOCH)
321 .map(|d| i64::try_from(d.as_millis()).unwrap_or(i64::MAX))
322 .unwrap_or(0);
323 Duration::from_millis(u64::try_from(now_ms - oldest_event_ms).unwrap_or(0))
324 }
325 _ => ingest_age,
326 };
327 self.e2e.record(latency.as_secs_f64());
328 }
329
330 /// Record one durably acknowledged flush.
331 ///
332 /// `d` is the batch's **seal-to-settle** time, and contains everything
333 /// that stood between the two: the wait for an `inflight.max_per_shard`
334 /// permit, every failed attempt, every retry-backoff sleep and
335 /// all-replicas-quarantined probe wait, and the write that finally
336 /// succeeded. It is the right input for a commit-lag budget and the wrong
337 /// one for "how fast is the sink". `write_attempt` answers that, and
338 /// `permit_waited` the queueing share.
339 ///
340 /// Only settled batches are observed. An abandoned one never reaches
341 /// here, whether it was aborted at the drain deadline, rejected with a
342 /// fatal class, exhausted `retry.max_attempts`, or died with a panicking
343 /// write task. All four are counted by [`abandoned`](Self::abandoned),
344 /// and the last three happen in steady state with no drain in sight.
345 #[inline]
346 pub fn flushed(&self, reason: FlushReason, rows: u64, bytes: u64, d: Duration) {
347 self.records.increment(rows);
348 self.bytes.increment(bytes);
349 self.batch_rows.record(rows as f64);
350 self.batch_bytes.record(bytes as f64);
351 self.flush_duration.record(d.as_secs_f64());
352 match reason {
353 FlushReason::Rows => self.flush_rows.increment(1),
354 FlushReason::Bytes => self.flush_bytes.increment(1),
355 FlushReason::Linger => self.flush_linger.increment(1),
356 FlushReason::Drain => self.flush_drain.increment(1),
357 }
358 }
359
360 /// Observe one write attempt: the time inside
361 /// [`ShardWriter::write_batch`](crate::sink::ShardWriter::write_batch) and
362 /// nothing else *of the framework's own*. Every attempt is observed,
363 /// retries included, so this is the sink system's round-trip
364 /// distribution. `spate_sink_flush_duration_seconds` cannot give that
365 /// signal, because it also carries the permit wait and the sleeps between
366 /// attempts.
367 ///
368 /// "Nothing else" is bounded by the writer's own implementation: a
369 /// connector that sleeps *inside* `write_batch` puts that sleep in here.
370 /// The Kafka sink does this when the producer queue is full, and the
371 /// wall-clock also charges whatever the sink's I/O runtime was busy with
372 /// at each await point. The framework's scheduling around the call is
373 /// excluded, namely the permit wait, the retry backoff, and the
374 /// all-replicas-quarantined probe wait.
375 ///
376 /// `outcome` splits the family: a batch rejected fatally in a millisecond
377 /// and one that times out after thirty seconds are both attempts, and
378 /// mixing them moves the distribution in opposite directions. The error's
379 /// taxonomy class stays on [`errors`](Self::errors).
380 ///
381 /// An attempt aborted at the drain deadline is never observed; the write
382 /// task is dropped mid-call, and a histogram observation is a point event
383 /// with nothing to strand (contrast
384 /// [`backing_off`](Self::backing_off), whose guard survives that abort).
385 /// Attempts that *completed* before the abort are
386 /// observed as usual, so an abandoned batch can leave `error`
387 /// observations here with no matching flush.
388 #[inline]
389 pub(crate) fn write_attempt(&self, outcome: AttemptOutcome, d: Duration) {
390 let h = match outcome {
391 AttemptOutcome::Ok => &self.write_ok,
392 AttemptOutcome::Error => &self.write_err,
393 };
394 h.record(d.as_secs_f64());
395 }
396
397 /// Observe how long a sealed batch waited for one of its shard's
398 /// `inflight.max_per_shard` slots before its first write attempt. This is
399 /// the queueing share of a flush, and the reading that tells a
400 /// healthy-but-slow dashboard apart from a saturated one.
401 ///
402 /// Observed for every sealed batch that starts a write, including the
403 /// healthy case where the permit is free and the observation is ~0. A
404 /// batch the drain deadline drops before it ever gets a permit is not
405 /// observed
406 /// (there is no wait that ended), and is counted by
407 /// [`abandoned`](Self::abandoned).
408 #[inline]
409 pub(crate) fn permit_waited(&self, d: Duration) {
410 self.permit_wait.record(d.as_secs_f64());
411 }
412
413 /// Count flush attempts beyond the first.
414 #[inline]
415 pub fn retries(&self, n: u64) {
416 self.retries.increment(n);
417 }
418
419 /// Publish `delay` as `batch`'s current retry backoff step for as long as
420 /// the returned guard lives.
421 ///
422 /// `spate_sink_retry_backoff_seconds` reads the **max** across the shard's
423 /// backing-off batches (a shard writes up to `inflight.max_per_shard` of
424 /// them at once, each with its own backoff), and `0` once none is backing
425 /// off. It answers "how long is this shard currently sleeping between
426 /// attempts".
427 ///
428 /// The value is the step being served, not the time left in it. It does
429 /// not count down while the sleep runs.
430 ///
431 /// Scope: the sleep between attempts *on an available replica*. A shard
432 /// whose every replica is quarantined also sleeps, waiting for the
433 /// earliest of a probe window and an in-flight probe reporting, and reads
434 /// `0` throughout, because no attempt is being backed off.
435 /// `spate_sink_shard_healthy == 0` is that state's signal, since the write
436 /// loop waits only when no replica is circuit-closed. The implication runs
437 /// one way. A shard with no circuit-closed replica can still be handing
438 /// out a half-open probe, and so not be waiting at all, so shard health
439 /// *covers* the wait rather than coinciding with it. Alerting on it cannot
440 /// miss a parked shard.
441 ///
442 /// Clearing is tied to the guard's `Drop` rather than to a settle/abandon
443 /// call because the sleeping task can be *aborted*; the sink's drain
444 /// deadline cancels in-flight writes wherever they are parked. Dropping
445 /// the task future drops the guard, so an abandoned batch cannot strand
446 /// the gauge at a value the shard is no longer sleeping.
447 ///
448 /// # Panics
449 ///
450 /// Debug builds only: `batch` must be unique among this shard's *live*
451 /// guards. Two live guards sharing a key collapse to one entry, and the
452 /// first `Drop` withdraws both contributions, so the gauge would read
453 /// `0` while the other sleep is still running. In-tree the key is the
454 /// batch sequence number, which is monotonic per shard.
455 #[must_use]
456 pub fn backing_off(&self, batch: u64, delay: Duration) -> BackoffGuard<'_> {
457 self.publish_backoff(|steps| {
458 let previous = steps.insert(batch, delay.as_secs_f64());
459 debug_assert!(
460 previous.is_none(),
461 "a live BackoffGuard already exists for batch {batch}"
462 );
463 });
464 BackoffGuard {
465 metrics: self,
466 batch,
467 }
468 }
469
470 /// Mutate the backing-off set and republish the max (`0` when empty).
471 /// Called only from the retry path, never per record.
472 fn publish_backoff(&self, mutate: impl FnOnce(&mut HashMap<u64, f64>)) {
473 // Poison-tolerant because this also runs from `BackoffGuard::drop`.
474 // A panicking `expect` there, reached while already unwinding, aborts
475 // the process. The critical section only inserts, removes and folds,
476 // so a poisoned map is not a corrupt one; recovering it publishes a
477 // stale reading at worst.
478 let mut steps = self
479 .backoff_steps
480 .lock()
481 .unwrap_or_else(std::sync::PoisonError::into_inner);
482 mutate(&mut steps);
483 let max = steps.values().copied().fold(0.0_f64, f64::max);
484 // Published *under* the lock. Releasing it first lets two publishers'
485 // `set` calls land in the opposite order from the snapshots they
486 // computed, stranding the gauge at a value no batch is serving. That
487 // lasts until the next mutation, which is `retry.max` away under a
488 // patient policy and never once the shard recovers. Two write tasks
489 // per shard is the default (`inflight.max_per_shard: 2`) on a
490 // multi-threaded I/O runtime. `Gauge::set` is an atomic store that
491 // cannot re-enter this function, so holding the lock across it cannot
492 // deadlock.
493 self.retry_backoff.set(max);
494 }
495
496 /// Count write errors of one taxonomy class.
497 #[inline]
498 pub fn errors(&self, class: ErrorClass, n: u64) {
499 match class {
500 ErrorClass::Retryable => self.err_retryable.increment(n),
501 ErrorClass::RecordLevel => self.err_record.increment(n),
502 ErrorClass::Fatal => self.err_fatal.increment(n),
503 }
504 }
505
506 /// Set the number of sealed batches currently in flight.
507 #[inline]
508 pub fn set_inflight(&self, batches: usize) {
509 self.inflight.set(batches as f64);
510 }
511
512 /// Mark one replica healthy (circuit closed) or quarantined (open).
513 pub fn set_replica_healthy(&self, replica: usize, healthy: bool) {
514 if let Some(r) = self.replicas.get(replica) {
515 r.healthy.set(if healthy { 1.0 } else { 0.0 });
516 }
517 }
518
519 /// Count a circuit-breaker open transition on one replica.
520 pub fn breaker_opened(&self, replica: usize) {
521 if let Some(r) = self.replicas.get(replica) {
522 r.breaker_opens.increment(1);
523 }
524 }
525
526 /// Count one failed write attempt attributed to a replica.
527 pub fn replica_error(&self, replica: usize) {
528 if let Some(r) = self.replicas.get(replica) {
529 r.errors.increment(1);
530 }
531 }
532
533 /// Record whether the shard has at least one circuit-closed replica.
534 /// Level-set and idempotent. The shard's breaker set republishes it on
535 /// every write outcome, not only on a transition, so a reading that has
536 /// gone stale corrects itself within one probe cycle.
537 pub fn set_shard_healthy(&self, up: bool) {
538 self.shard_healthy.set(if up { 1.0 } else { 0.0 });
539 }
540
541 /// Count batches abandoned at the drain deadline.
542 pub fn abandoned(&self, n: u64) {
543 self.abandoned.increment(n);
544 }
545
546 /// Record that this shard's worker had to be force-aborted because it did
547 /// not return by the drain deadline. A framework bug, not an operating
548 /// condition; see `SinkPool::drain`.
549 pub fn drain_overrun(&self) {
550 self.drain_overrun.increment(1);
551 }
552}
553
554/// One batch's contribution to `spate_sink_retry_backoff_seconds`, held for the
555/// duration of a backoff sleep. Returned by
556/// [`SinkShardMetrics::backing_off`]; dropping it (including by the write
557/// task being aborted mid-sleep) withdraws this batch's step and republishes
558/// the shard's max, `0` when it was the last one sleeping.
559#[derive(Debug)]
560pub struct BackoffGuard<'a> {
561 metrics: &'a SinkShardMetrics,
562 batch: u64,
563}
564
565impl Drop for BackoffGuard<'_> {
566 fn drop(&mut self) {
567 let batch = self.batch;
568 self.metrics.publish_backoff(|steps| {
569 steps.remove(&batch);
570 });
571 }
572}