diff --git a/docs/metrics.md b/docs/metrics.md index 70ba670f..8ed49ef8 100644 --- a/docs/metrics.md +++ b/docs/metrics.md @@ -148,10 +148,13 @@ Steps: ### Storage Request-Loss Diagnostics (collected via ZMQ, exposed on controller) -Arrivals are counted when the worker decodes a request, while `tq_storage_request_ops` only -advances once one completes, so a sustained gap between them means requests are arriving and -not finishing. The counters are cumulative per operation and carry no request identity, so -they characterise a unit, not any individual request. +Arrivals are counted when the worker decodes a request, and `tq_storage_request_ops` when its +handler returns or raises. The same worker answers the collector, so these counters are only +reported between requests: they cannot show a handler that is still running, and a unit stuck +in one stops answering, leaving its gauges at their last values (the timeout diagnosis then +reports `unit_not_serving`). To see handlers in progress, use the storage unit's own endpoint +below. The counters are cumulative per operation and carry no request identity, so they +characterise a unit, not any individual request. | Metric | Type | Labels | Description | |--------|------|--------|-------------| @@ -183,10 +186,14 @@ prevented every drop in that window. | Metric | Type | Labels | Description | |--------|------|--------|-------------| | `tq_storage_request_duration_seconds` | Histogram | `op_type` | Request latency (buckets: 1ms–5s) | -| `tq_storage_request_total` | Counter | `op_type` | Total requests processed | +| `tq_storage_request_total` | Counter | `op_type` | Requests whose handler has started | | `tq_storage_request_errors_total` | Counter | `op_type` | Total request errors | | `tq_storage_request_samples_total` | Counter | `op_type` | Total samples processed per operation | +This endpoint is served by its own thread rather than the worker, so `tq_storage_request_total` +minus `tq_storage_request_duration_seconds_count` (observed when a handler returns or raises) +gives the handlers still running, even while the worker is stuck. + > **Note on naming**: The ZMQ-collected gauges on the controller avoid all Prometheus reserved suffixes (`_total`, `_bucket`, `_sum`, `_count`, `_info`, `_created`) and the reserved `le` label to prevent type metadata conflicts that break `label_values()` queries. P50/P99 are computed on the storage unit side and sent as pre-calculated values. The storage unit's own endpoint uses standard Counter/Histogram naming conventions. ## Grafana Dashboard diff --git a/transfer_queue/storage/simple_storage.py b/transfer_queue/storage/simple_storage.py index ca8ad853..56d21dfa 100644 --- a/transfer_queue/storage/simple_storage.py +++ b/transfer_queue/storage/simple_storage.py @@ -1397,13 +1397,14 @@ def _handle_get_metrics(self) -> ZMQMessage: for op_type in ("PUT_DATA", "UPDATE_DATA", "GET_DATA", "CLEAR_DATA", "DUMP_ROWS", "LOAD_ROWS"): try: hist = self._metrics.request_duration.labels(op_type=op_type) - counter = self._metrics.request_total.labels(op_type=op_type) duration_sum = hist._sum.get() # Build cumulative counts once, reuse for total and quantiles cumulative_counts = self._cumulative_bucket_counts(hist) duration_count = cumulative_counts[-1] if cumulative_counts else 0 op_stats[op_type] = { - "request_count": counter._value.get(), + # Observed when the handler returns or raises. request_total counts entry and + # agrees only because this worker answers GET_METRICS after each handler. + "request_count": duration_count, "latency_avg": duration_sum / duration_count if duration_count > 0 else 0, "latency_p50": self._quantile_from_cumulative(hist, cumulative_counts, 0.50), "latency_p99": self._quantile_from_cumulative(hist, cumulative_counts, 0.99),