Exporting Diff-Sync Metrics to Prometheus Jump to heading

Expose the health of an OSM replication loop as Prometheus metrics, with types whose silence is visible and a /metrics endpoint that never touches the network.

Prerequisites Jump to heading

Conceptual minimum Jump to heading

Two design choices decide whether these metrics are useful during an incident: the type of each metric, and where the work happens.

Metric types for replication signals and how each behaves when the exporter stops A grid of five metrics. Sequence lag and timestamp lag are gauges and freeze at whatever healthy value they last held when the exporter stops. Last-success as an absolute epoch gauge visibly ages because now minus it keeps growing. Diffs applied is a counter whose rate falls to zero. Apply duration is a histogram that simply receives no new observations. Metric type decides what an alert rule can say type what a stopped exporter looks like sequence lag Gauge frozen at a healthy value timestamp lag Gauge frozen at a healthy value last success (epoch) Gauge, absolute time visibly ages — now minus it grows diffs applied Counter rate() falls to zero apply duration Histogram no new observations Two of these five go quiet in a way that reads as healthy. Exporting the heartbeat as an absolute timestamp rather than an age is what fixes it.
A gauge that stops updating is indistinguishable from a gauge that is fine. Pick types whose silence is visible.

The type matters because of how each behaves when the thing producing it dies. A gauge holds its last value forever, so a lag gauge from a crashed process reads as a perfectly healthy number until someone notices the series is stale. A counter’s rate() falls to zero, which is visible. And an absolute timestamp gauge — “the unix time of the last successful iteration” rather than “seconds since” — keeps degrading because the alert expression subtracts it from time(), which keeps moving even when the process does not.

Where the upstream fetch belongs relative to the metrics endpoint A four-stage chain. The loop iteration fetches state.txt once, the only outbound call. It then updates the registry in process, setting gauges and incrementing counters in microseconds. The metrics endpoint renders from memory with no I/O. Prometheus scrapes it every thirty seconds, so many replicas cost one upstream fetch per loop iteration rather than one per scrape. Scrape must never reach the network loop iteration fetch state.txt once the only outbound call update the registry set gauges, inc counters in-process, microseconds /metrics render from memory no I/O of any kind Prometheus scrapes every 30 s many replicas, one upstream fetch Ten replicas scraped every fifteen seconds is 2 400 requests an hour. If the scrape triggers the upstream fetch, that load lands on a shared community server.
The rule is simple and easy to violate by accident: the collector reads memory, the loop reads the network.

The second choice is where the upstream fetch lives. Computing lag requires reading the stream’s state.txt, and it is tempting to do that inside the collector so the number is always fresh. Do not: a scrape is triggered by Prometheus, on its schedule, from potentially several servers, and hooking it to an outbound HTTP request turns your monitoring into load on a shared community server. The loop already fetches state.txt once per iteration for its own purposes; publish that.

Runnable solution Jump to heading

python
#!/usr/bin/env python3
"""Prometheus metrics for an OSM diff-sync loop. The collector never does I/O."""
from __future__ import annotations

import logging
import time
from datetime import datetime, timezone

from prometheus_client import Counter, Gauge, Histogram, start_http_server

logger = logging.getLogger(__name__)

LABELS = ["stream", "region"]

# Gauges: current state. Fine here because the heartbeat below makes staleness visible.
SEQ_LAG = Gauge("osm_replication_sequence_lag",
                "Upstream head sequence minus the locally applied sequence", LABELS)
TS_LAG = Gauge("osm_replication_timestamp_lag_seconds",
               "Age in seconds of the newest applied diff", LABELS)
UPSTREAM_AGE = Gauge("osm_replication_upstream_age_seconds",
                     "Age in seconds of the newest diff the stream has published", LABELS)
APPLIED_SEQ = Gauge("osm_replication_applied_sequence",
                    "The sequence number currently applied locally", LABELS)

# Absolute timestamp, not an age: an expression of time() - this keeps growing
# after the process dies, which is exactly what an alert needs.
LAST_SUCCESS = Gauge("osm_replication_last_success_timestamp_seconds",
                     "Unix time of the last successful loop iteration", LABELS)

# Counters: their rate() falls to zero when work stops.
DIFFS_APPLIED = Counter("osm_replication_diffs_applied_total",
                        "Diffs successfully applied", LABELS)
DIFF_FAILURES = Counter("osm_replication_diff_failures_total",
                        "Diffs that failed to apply", LABELS + ["reason"])

APPLY_SECONDS = Histogram("osm_replication_apply_duration_seconds",
                          "Wall-clock time to apply one diff", LABELS,
                          buckets=(0.5, 1, 2, 5, 10, 30, 60, 120, 300))


class ReplicationMetrics:
    """Owns the label values for one stream/region pair."""

    def __init__(self, stream: str, region: str) -> None:
        self.labels = {"stream": stream, "region": region}

    def observe_state(self, applied_seq: int, applied_ts: datetime,
                      head_seq: int, head_ts: datetime) -> None:
        """Called once per loop iteration, after the loop has already fetched state.txt."""
        now = datetime.now(timezone.utc)
        SEQ_LAG.labels(**self.labels).set(head_seq - applied_seq)
        TS_LAG.labels(**self.labels).set((now - applied_ts).total_seconds())
        UPSTREAM_AGE.labels(**self.labels).set((now - head_ts).total_seconds())
        APPLIED_SEQ.labels(**self.labels).set(applied_seq)

    def observe_apply(self, seconds: float) -> None:
        APPLY_SECONDS.labels(**self.labels).observe(seconds)
        DIFFS_APPLIED.labels(**self.labels).inc()

    def observe_failure(self, reason: str) -> None:
        """`reason` must come from a small fixed set — it is a label."""
        DIFF_FAILURES.labels(**self.labels, reason=reason).inc()

    def heartbeat(self) -> None:
        LAST_SUCCESS.labels(**self.labels).set(time.time())


FAILURE_REASONS = frozenset({"fetch", "decompress", "apply", "checkpoint", "lock"})


def classify(exc: Exception) -> str:
    """Map an exception to one of a fixed set of reasons, so the label stays bounded."""
    name = type(exc).__name__.lower()
    if "url" in name or "http" in name or "timeout" in name:
        return "fetch"
    if "zlib" in name or "gzip" in name or "eof" in name:
        return "decompress"
    if "lock" in name or "blocking" in name:
        return "lock"
    return "apply"


if __name__ == "__main__":
    start_http_server(9187)          # serves /metrics from the in-process registry
    metrics = ReplicationMetrics(stream="minute", region="ireland")
    logger.info("metrics endpoint listening on :9187")
    # ... the loop calls observe_state / observe_apply / heartbeat as it runs ...

Wiring it into the loop, with the ordering that matters:

python
def iteration(metrics: ReplicationMetrics) -> None:
    head = fetch_head()                       # the ONE outbound call per iteration
    applied = read_checkpoint()
    metrics.observe_state(applied.sequence, applied.timestamp, head.sequence, head.timestamp)
    if head.sequence <= applied.sequence:
        metrics.heartbeat()                   # nothing to do is still a successful iteration
        return
    started = time.monotonic()
    try:
        apply_diff(applied.sequence + 1)
        write_checkpoint(applied.sequence + 1)
    except Exception as exc:
        metrics.observe_failure(classify(exc))
        raise
    metrics.observe_apply(time.monotonic() - started)
    metrics.heartbeat()

Step-by-step walkthrough Jump to heading

observe_state takes the head values as arguments rather than fetching them. That single decision is what keeps the collector I/O-free — the loop has already paid for the fetch, and the metrics layer is a consumer of that result rather than a second caller.

heartbeat is called on the “nothing to do” path as well as the success path. A loop that finds itself already current has had a successful iteration, and omitting the heartbeat there means a pipeline that has caught up looks dead within minutes.

classify exists to keep the reason label bounded. Using str(exc) as a label value seems convenient and creates a new time series for every distinct error message, including ones containing sequence numbers and URLs.

Three candidate labels and their cardinality consequences Three panels. A stream label with values such as minute or hour is bounded at two or three values and is necessary because a host syncing two regions has two independent lags. A region label is bounded by your own deployment and lets one alert rule cover all regions. A sequence label carrying the identifier is unbounded, creating a new time series every minute and destroying the time-series database within days. Labels: the ones worth having and the one that will hurt stream stream="minute"` / `"hour" Bounded: two or three values A host syncing two regions has two independent lags Without it they merge into nonsense region region="ireland" Bounded by your own deployment Lets one alert rule cover all Keep it to deployed regions, not to every region that exists sequence sequence="6123456" Unbounded — new value every minute A new time series per minute Kills the TSDB within days Never label with an id Cardinality is the one Prometheus mistake that is expensive to undo, because the damage is in the storage rather than in the code.
Labels are dimensions, not data. Anything that takes a new value on every observation belongs in the metric value or in a log line.

APPLY_SECONDS uses explicit buckets because the defaults are tuned for HTTP request latency and put almost everything in the top bucket for a job measured in seconds. Buckets should straddle the values you actually see and the value you would alert on.

Verification Jump to heading

Scrape it by hand and read the output — the shape tells you most of what you need:

bash
curl -s localhost:9187/metrics | grep '^osm_replication'

Three things to check. Every series carries both labels; a series with empty label values means .labels() was called with positional arguments in the wrong order. osm_replication_last_success_timestamp_seconds is a large number close to the current unix time, not a small number of seconds. And osm_replication_diffs_applied_total increases between two scrapes taken a minute apart on a live loop.

Then confirm the endpoint is genuinely inert:

bash
# Watch outbound connections while scraping repeatedly.
for i in $(seq 20); do curl -s localhost:9187/metrics >/dev/null; done &
ss -tnp | grep -c planet.osm.org        # expect 0

Any outbound connection attributable to the scrape means the collector is doing work it should not.

Common errors and fixes Jump to heading

Symptom Root cause Fix
Lag looks healthy while the loop is dead Gauge frozen at its last value Alert on time() - last_success_timestamp
Prometheus memory grows steadily Sequence number or error text used as a label Bound every label to a fixed set
/metrics slow or timing out Collector performs an HTTP fetch Publish values the loop already computed
Two regions merged into one series Labels omitted Label by stream and region from the start
Counter resets on every scrape New registry created per request One module-level registry for the process
Histogram is all in the +Inf bucket Default buckets, seconds-scale data Set buckets that straddle real values

Frequently Asked Questions Jump to heading

Should the loop and the metrics endpoint be the same process?

They can be, and it is simpler, but it has the weakness that a crashed loop takes the endpoint with it — Prometheus then reports the target as down, which is actionable but tells you nothing about how far behind the data is. A small sidecar that reads the same checkpoint keeps reporting a rising lag while the loop is dead, which is a more informative failure. If you run only one, run it in-process and alert on target-down as well as on lag.

Why a counter for diffs applied when the sequence number is already a gauge?

They answer different questions. The gauge says where you are; the counter says whether you are moving. rate(osm_replication_diffs_applied_total[5m]) going to zero is a clean signal that survives restarts and does not depend on knowing what a healthy sequence number looks like today.

What scrape interval makes sense?

Thirty seconds is fine and fifteen is unnecessary. The underlying data changes once a minute at best, so scraping faster than the loop iterates just stores duplicate samples. What matters more is that the scrape interval is comfortably shorter than the alerting window, so a rule with a five-minute for clause has several samples to work with.

Should I export per-diff timings or just the total?

The histogram is worth its cost. When lag starts rising the first question is whether each diff got slower or whether more diffs arrived, and a duration histogram answers it immediately. A single total gives you neither.

Specification reference Jump to heading

Prometheus metric types: a Gauge may go up and down and holds its last value; a Counter only increases and resets to zero on process restart, which client libraries and rate() handle; a Histogram samples observations into configurable buckets. Label values form part of the time-series identity, so the number of series is the product of the cardinalities of all labels.

Up one level: Replication Monitoring & Lag Alerting.