Skip to content

Commit b1fe23f

Browse files
feat(metrics): expose async-operation queue + consolidation backlog as gauges (#1987)
* feat(metrics): expose async-operation queue + consolidation backlog as gauges The bank-stats endpoint already computes operations_by_status, pending_consolidation and failed_consolidation, but only as a point-in-time HTTP response per bank. There's no way to trend or alert on "is the worker keeping up?" / "is the knowledge base caught up?" from Prometheus. This adds three observable gauges, fed by a 30s background-refresh cache (the same pattern as the existing db-pool gauges, so the /metrics scrape path stays synchronous): - hindsight_async_operations{operation_type,status} -- worker queue depth for non-terminal states. pending = queued backlog (e.g. retain / consolidation), processing = in-flight, failed = stranded. Terminal states (completed, cancelled) are deliberately excluded: a gauge of finished work grows without bound and says nothing about current load. The processing series is the only signal that surfaces a hung operation holding a worker slot. - hindsight_consolidation_backlog -- source memories (experience/world) not yet consolidated into observations (pending_consolidation). - hindsight_consolidation_failed -- source memories whose consolidation permanently failed, recoverable via the consolidation recovery endpoint (failed_consolidation). The SQL is lifted from the bank-stats endpoint and is index-backed (idx_async_operations_status, idx_memory_units_unconsolidated). Per-bank labels are gated behind the existing metrics_include_bank_id flag (off by default); when off, counts aggregate per tenant/schema, bounding cardinality to a handful of series. All queries are PostgreSQL-specific (FILTER, information_schema), consistent with this collector already being bound to an asyncpg pool. * review: address feedback on backlog metrics - Split the consolidation backlog into two separate COUNT(*) queries, each with a WHERE matching a partial-index predicate exactly (idx_memory_units_ unconsolidated / idx_memory_units_consolidation_failed), instead of one aggregate with two FILTERs that seq-scans the whole memory_units table on every 30s refresh across every schema. GROUP BY bank_id still composes (bank_id is each index's lead column). - Type the gauge cache keys as NamedTuples (_AsyncOpKey, _BacklogKey) instead of raw tuples. - Hoist `import asyncio` to module scope (was imported inside two methods). - Document that _backlog_task is process-lifetime and intentionally not cancelled (no teardown hook to hang it on). - Add tests for the per_bank=True path (bank_id in the cache key + GROUP BY bank_id in the SQL + bank_id gauge attribute) and assert the backlog queries are index-matched, not FILTER scans. * fix(metrics): force index scan for the consolidation backlog count Splitting the consolidation count into two index-predicate-matched COUNT(*) queries fixed the failed count (index-only scan) but NOT the backlog count. Verified on a 114k-row memory_units via EXPLAIN ANALYZE: the backlog query still seq-scans (~92 ms) because `consolidated_at IS NULL` is true for ~40% of the table (every observation has a null consolidated_at), so the planner misjudges selectivity and won't use idx_memory_units_unconsolidated even though the predicate matches it exactly. ANALYZE doesn't change the plan (structural, not stale stats); `enable_seqscan=off` confirms the index is usable (~0.1 ms). Run the backlog count in a scoped transaction with SET LOCAL enable_seqscan=off to force the partial-index scan (verified ~0.07 ms, transaction-scoped, no leak). The failed count needs no nudge — consolidation_failed_at IS NOT NULL is rare, so its index is chosen on cost. * feat(metrics): gate consolidation backlog gauges behind config flag (off by default) Add HINDSIGHT_API_METRICS_BACKLOG_ENABLED (default false). The async-operation queue + consolidation backlog gauges run periodic per-schema COUNT queries on a background task, so they are now opt-in rather than always-on when a db pool is set. * chore: sync embed env template + prettify paperclip README after main merge --------- Co-authored-by: Nicolò Boschi <boschi1997@gmail.com>
1 parent ce81217 commit b1fe23f

8 files changed

Lines changed: 489 additions & 10 deletions

File tree

.env.example

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -162,6 +162,10 @@ HINDSIGHT_API_LOG_LEVEL=info
162162
# Custom service name and environment (optional, defaults: hindsight-api, development)
163163
# HINDSIGHT_API_OTEL_SERVICE_NAME=hindsight-production
164164
# HINDSIGHT_API_OTEL_DEPLOYMENT_ENVIRONMENT=production
165+
#
166+
# Expose async-operation queue + consolidation-backlog gauges on /metrics.
167+
# Runs periodic per-schema COUNT queries on a background task (disabled by default).
168+
# HINDSIGHT_API_METRICS_BACKLOG_ENABLED=true
165169

166170
# -----------------------------------------------------------------------------
167171
# Control Plane (Optional)

hindsight-api-slim/hindsight_api/config.py

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -375,6 +375,7 @@ def normalize_config_dict(config: dict[str, Any]) -> dict[str, Any]:
375375
ENV_OTEL_SERVICE_NAME = "HINDSIGHT_API_OTEL_SERVICE_NAME"
376376
ENV_OTEL_DEPLOYMENT_ENVIRONMENT = "HINDSIGHT_API_OTEL_DEPLOYMENT_ENVIRONMENT"
377377
ENV_METRICS_INCLUDE_BANK_ID = "HINDSIGHT_API_METRICS_INCLUDE_BANK_ID"
378+
ENV_METRICS_BACKLOG_ENABLED = "HINDSIGHT_API_METRICS_BACKLOG_ENABLED"
378379

379380
# Vertex AI configuration
380381
ENV_LLM_VERTEXAI_PROJECT_ID = "HINDSIGHT_API_LLM_VERTEXAI_PROJECT_ID"
@@ -974,6 +975,7 @@ def _parse_strategy_boosts(raw: str | None) -> dict[str, str]:
974975
DEFAULT_OTEL_SERVICE_NAME = "hindsight-api"
975976
DEFAULT_OTEL_DEPLOYMENT_ENVIRONMENT = "development"
976977
DEFAULT_METRICS_INCLUDE_BANK_ID = False # Disabled by default to avoid high-cardinality OTel metric growth
978+
DEFAULT_METRICS_BACKLOG_ENABLED = False # Disabled by default: runs periodic per-schema COUNT queries
977979

978980
# Audit log defaults
979981
DEFAULT_AUDIT_LOG_ENABLED = False # Disabled by default
@@ -1651,6 +1653,7 @@ class HindsightConfig:
16511653
otel_service_name: str
16521654
otel_deployment_environment: str
16531655
metrics_include_bank_id: bool
1656+
metrics_backlog_enabled: bool
16541657

16551658
# Audit log configuration (static - server-level only)
16561659
audit_log_enabled: bool # Master switch for audit logging
@@ -2642,6 +2645,8 @@ def from_env(cls) -> "HindsightConfig":
26422645
otel_deployment_environment=os.getenv(ENV_OTEL_DEPLOYMENT_ENVIRONMENT, DEFAULT_OTEL_DEPLOYMENT_ENVIRONMENT),
26432646
metrics_include_bank_id=os.getenv(ENV_METRICS_INCLUDE_BANK_ID, str(DEFAULT_METRICS_INCLUDE_BANK_ID)).lower()
26442647
in ("true", "1", "yes"),
2648+
metrics_backlog_enabled=os.getenv(ENV_METRICS_BACKLOG_ENABLED, str(DEFAULT_METRICS_BACKLOG_ENABLED)).lower()
2649+
in ("true", "1", "yes"),
26452650
# Audit log configuration (static, server-level only)
26462651
audit_log_enabled=os.getenv(ENV_AUDIT_LOG_ENABLED, str(DEFAULT_AUDIT_LOG_ENABLED)).lower() == "true",
26472652
audit_log_actions=[

hindsight-api-slim/hindsight_api/metrics.py

Lines changed: 221 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@
1111
- Database connection pool metrics
1212
"""
1313

14+
import asyncio
1415
import importlib
1516
import logging
1617
import os
@@ -20,7 +21,7 @@
2021
import threading
2122
import time
2223
from contextlib import contextmanager
23-
from typing import TYPE_CHECKING, Callable
24+
from typing import TYPE_CHECKING, Callable, NamedTuple
2425

2526
from opentelemetry import metrics
2627
from opentelemetry.exporter.prometheus import PrometheusMetricReader
@@ -76,6 +77,28 @@ def _is_client_cancellation(exc: BaseException) -> bool:
7677
# HTTP request duration buckets (millisecond-level for fast endpoints)
7778
HTTP_DURATION_BUCKETS = (0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1.0, 2.5, 5.0, 10.0, 30.0)
7879

80+
# How often the backlog / queue-depth gauge caches are refreshed (seconds).
81+
# The counts are aggregate COUNT queries, so a background task refreshes a
82+
# cache and the observable gauges read from it — keeping the /metrics scrape
83+
# path synchronous (the same reason the db-pool gauges read cached state).
84+
BACKLOG_METRICS_REFRESH_SECONDS = 30
85+
86+
87+
class _AsyncOpKey(NamedTuple):
88+
"""Cache / label key for the async-operation queue gauge."""
89+
90+
tenant: str
91+
operation_type: str
92+
status: str
93+
bank_id: str | None
94+
95+
96+
class _BacklogKey(NamedTuple):
97+
"""Cache / label key for the consolidation backlog and failed gauges."""
98+
99+
tenant: str
100+
bank_id: str | None
101+
79102

80103
def get_token_bucket(token_count: int) -> str:
81104
"""
@@ -383,6 +406,13 @@ def __init__(self):
383406
# DB pool metrics holder (set via set_db_pool)
384407
self._db_pool: "asyncpg.Pool | None" = None
385408

409+
# Backlog / queue-depth gauge caches, refreshed by a background task
410+
# (see _setup_backlog_metrics) so the scrape path stays synchronous.
411+
self._async_ops_counts: dict[_AsyncOpKey, int] = {}
412+
self._consolidation_backlog: dict[_BacklogKey, int] = {}
413+
self._consolidation_failed: dict[_BacklogKey, int] = {}
414+
self._backlog_task: "asyncio.Task | None" = None
415+
386416
@contextmanager
387417
def record_operation(
388418
self,
@@ -650,6 +680,10 @@ def set_db_pool(self, pool: "asyncpg.Pool"):
650680
"""
651681
self._db_pool = pool
652682
self._setup_db_pool_metrics()
683+
from .config import get_config
684+
685+
if get_config().metrics_backlog_enabled:
686+
self._setup_backlog_metrics()
653687

654688
def _setup_db_pool_metrics(self):
655689
"""Set up observable gauges for database pool metrics."""
@@ -715,6 +749,192 @@ def get_pool_max_size(_options):
715749
unit="{connections}",
716750
)
717751

752+
def _setup_backlog_metrics(self):
753+
"""Observable gauges for the async-operation queue and the
754+
consolidation backlog.
755+
756+
These mirror fields the bank-stats endpoint already computes
757+
(``operations_by_status``, ``pending_consolidation``,
758+
``failed_consolidation``) but expose them as scrapable gauges, so
759+
queue depth and backlog can be trended and alerted on instead of only
760+
polled per-bank over HTTP. The two motivating questions both come for
761+
free here: "is the worker keeping up?" (async-op queue) and "is the
762+
knowledge base caught up?" (consolidation backlog) — including the
763+
``processing`` state, which is the only signal that surfaces a hung
764+
operation stuck holding a worker slot.
765+
766+
Counts are aggregate ``COUNT`` queries, so a background task refreshes
767+
a cache every ``BACKLOG_METRICS_REFRESH_SECONDS`` and these callbacks
768+
read it — keeping the scrape path synchronous, the same approach as
769+
the db-pool gauges above.
770+
"""
771+
if self._backlog_task is not None:
772+
return # already started for this collector
773+
774+
def get_async_operations(_options):
775+
for key, value in list(self._async_ops_counts.items()):
776+
attrs = {"tenant": key.tenant, "operation_type": key.operation_type, "status": key.status}
777+
if key.bank_id is not None:
778+
attrs["bank_id"] = key.bank_id
779+
yield metrics.Observation(value, attrs)
780+
781+
def get_consolidation_backlog(_options):
782+
for key, value in list(self._consolidation_backlog.items()):
783+
attrs = {"tenant": key.tenant}
784+
if key.bank_id is not None:
785+
attrs["bank_id"] = key.bank_id
786+
yield metrics.Observation(value, attrs)
787+
788+
def get_consolidation_failed(_options):
789+
for key, value in list(self._consolidation_failed.items()):
790+
attrs = {"tenant": key.tenant}
791+
if key.bank_id is not None:
792+
attrs["bank_id"] = key.bank_id
793+
yield metrics.Observation(value, attrs)
794+
795+
self.meter.create_observable_gauge(
796+
name="hindsight.async_operations",
797+
callbacks=[get_async_operations],
798+
description="Async operations in a non-terminal state, by operation_type and status "
799+
"(pending=queued backlog, processing=in-flight, failed=stranded)",
800+
unit="{operations}",
801+
)
802+
self.meter.create_observable_gauge(
803+
name="hindsight.consolidation.backlog",
804+
callbacks=[get_consolidation_backlog],
805+
description="Source memories (experience/world) not yet consolidated into observations",
806+
unit="{memories}",
807+
)
808+
self.meter.create_observable_gauge(
809+
name="hindsight.consolidation.failed",
810+
callbacks=[get_consolidation_failed],
811+
description="Source memories whose consolidation permanently failed "
812+
"(recoverable via the consolidation recovery endpoint)",
813+
unit="{memories}",
814+
)
815+
816+
# Drive the caches from a background task on the running loop.
817+
# set_db_pool runs during async startup, so a loop is normally present;
818+
# if not, the gauges simply stay empty rather than crashing collection.
819+
try:
820+
loop = asyncio.get_running_loop()
821+
except RuntimeError:
822+
logger.warning("No running event loop; backlog metrics disabled")
823+
return
824+
# Process-lifetime task: there is no collector teardown hook to cancel it
825+
# on, so it's torn down with the event loop at process shutdown. If a
826+
# shutdown path is ever added, cancel self._backlog_task there.
827+
self._backlog_task = loop.create_task(self._backlog_refresh_loop())
828+
829+
async def _backlog_refresh_loop(self):
830+
"""Periodically refresh the backlog / queue-depth caches."""
831+
while True:
832+
try:
833+
await self._refresh_backlog()
834+
except Exception:
835+
logger.debug("Backlog metrics refresh failed", exc_info=True)
836+
await asyncio.sleep(BACKLOG_METRICS_REFRESH_SECONDS)
837+
838+
async def _refresh_backlog(self):
839+
"""Recount the async-operation queue and consolidation backlog across
840+
every provisioned Hindsight schema.
841+
842+
Per-bank labels are gated behind ``metrics_include_bank_id`` (off by
843+
default) to keep cardinality bounded; when off, counts are aggregated
844+
per tenant/schema. All SQL here is PostgreSQL-specific (``FILTER``,
845+
``information_schema``), which is consistent with this collector
846+
already being bound to an asyncpg pool.
847+
"""
848+
if self._db_pool is None:
849+
return
850+
851+
async_ops: dict[_AsyncOpKey, int] = {}
852+
backlog: dict[_BacklogKey, int] = {}
853+
failed: dict[_BacklogKey, int] = {}
854+
per_bank = self._include_bank_id
855+
bank_sel = "bank_id, " if per_bank else ""
856+
bank_grp = " GROUP BY bank_id" if per_bank else ""
857+
858+
async with self._db_pool.acquire() as conn:
859+
# memory_units is the central per-tenant table; its presence marks a
860+
# provisioned Hindsight schema.
861+
schema_rows = await conn.fetch(
862+
"SELECT table_schema FROM information_schema.tables WHERE table_name = 'memory_units'"
863+
)
864+
for schema_row in schema_rows:
865+
schema = schema_row["table_schema"]
866+
867+
# Worker queue depth — mirrors operations_by_status, split by
868+
# operation_type. Terminal states (completed/cancelled) are
869+
# excluded on purpose: a gauge of finished work grows without
870+
# bound and says nothing about current load.
871+
# Index: idx_async_operations_status.
872+
ops_grp = "operation_type, status" + (", bank_id" if per_bank else "")
873+
try:
874+
rows = await conn.fetch(
875+
f"SELECT operation_type, status, {bank_sel}COUNT(*) AS count "
876+
f'FROM "{schema}".async_operations '
877+
"WHERE status IN ('pending', 'processing', 'failed') "
878+
f"GROUP BY {ops_grp}"
879+
)
880+
for row in rows:
881+
bank = row["bank_id"] if per_bank else None
882+
key = _AsyncOpKey(schema, row["operation_type"] or "unknown", row["status"], bank)
883+
async_ops[key] = async_ops.get(key, 0) + int(row["count"])
884+
except Exception:
885+
logger.debug("Async-ops queue query failed for schema %s", schema, exc_info=True)
886+
887+
# Consolidation backlog + stranded counts. Two separate COUNT(*)
888+
# queries rather than one with two FILTERs — each WHERE matches a
889+
# partial-index predicate exactly:
890+
# idx_memory_units_unconsolidated WHERE consolidated_at IS NULL ...
891+
# idx_memory_units_consolidation_failed WHERE consolidation_failed_at IS NOT NULL ...
892+
# GROUP BY bank_id still composes — bank_id is each index's lead column.
893+
#
894+
# The backlog count runs with seqscan disabled in a scoped
895+
# transaction. The partial index matches its predicate, but
896+
# `consolidated_at IS NULL` is true for a large fraction of the
897+
# table (every observation has a null consolidated_at), so the
898+
# planner misjudges selectivity and otherwise seq-scans the whole
899+
# (largest) table on every refresh — verified on a 114k-row table
900+
# via EXPLAIN: seq scan ~92 ms vs index scan ~0.1 ms. SET LOCAL
901+
# forces the index path and resets at transaction end. The failed
902+
# count below needs no such nudge: `consolidation_failed_at IS NOT
903+
# NULL` is rare, so its index is chosen on cost.
904+
try:
905+
async with conn.transaction():
906+
await conn.execute("SET LOCAL enable_seqscan = off")
907+
rows = await conn.fetch(
908+
f"SELECT {bank_sel}COUNT(*) AS count "
909+
f'FROM "{schema}".memory_units '
910+
"WHERE consolidated_at IS NULL AND fact_type IN ('experience', 'world')"
911+
f"{bank_grp}"
912+
)
913+
for row in rows:
914+
bank = row["bank_id"] if per_bank else None
915+
key = _BacklogKey(schema, bank)
916+
backlog[key] = backlog.get(key, 0) + int(row["count"])
917+
except Exception:
918+
logger.debug("Consolidation backlog query failed for schema %s", schema, exc_info=True)
919+
920+
try:
921+
rows = await conn.fetch(
922+
f"SELECT {bank_sel}COUNT(*) AS count "
923+
f'FROM "{schema}".memory_units '
924+
"WHERE consolidation_failed_at IS NOT NULL AND fact_type IN ('experience', 'world')"
925+
f"{bank_grp}"
926+
)
927+
for row in rows:
928+
bank = row["bank_id"] if per_bank else None
929+
key = _BacklogKey(schema, bank)
930+
failed[key] = failed.get(key, 0) + int(row["count"])
931+
except Exception:
932+
logger.debug("Consolidation failed query failed for schema %s", schema, exc_info=True)
933+
934+
self._async_ops_counts = async_ops
935+
self._consolidation_backlog = backlog
936+
self._consolidation_failed = failed
937+
718938

719939
# Global metrics collector instance (defaults to no-op)
720940
_metrics_collector: MetricsCollectorBase = NoOpMetricsCollector()

0 commit comments

Comments
 (0)