Skip to main content

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}