Observability¶
Rose currently uses several observability systems:
- Google Cloud Logging for backend application logs
- Sentry for error tracking and uptime monitoring (see Sentry Uptime Monitoring)
- PostHog for product analytics
- Langfuse for LLM tracing and prompt observability
- Grafana Cloud for OpenTelemetry metrics (chat latency & per-LLM-call)
Sentry Uptime Monitoring¶
Sentry polls the backend deep status probe (GET /status on ixsearch_api) to
detect outages in any of the widget's runtime dependencies — MongoDB, Redis,
Neo4j, Supabase, Azure OpenAI, OpenAI, Langfuse.
How the endpoint works¶
| Endpoint | Purpose | Auth | Probes |
|---|---|---|---|
GET /health |
Liveness — Cloud Run probe | none | none |
GET /ping |
Ultra-light readiness | none | none |
GET /ready |
Cloud Run readiness — used by load balancer | none | MongoDB ping, Redis ping |
GET /status |
Deep status probe (Sentry uptime) | X-Status-Token header |
MongoDB dbStats, Redis DBSIZE, Neo4j RETURN 1, Supabase REST query, Azure OpenAI /openai/models, OpenAI /v1/models, Langfuse reach |
Response shape (200 all-ok, 503 if any critical service is down):
{
"status": "ok",
"version": "1.407.0",
"environment": "production",
"public_ip": "34.x.x.x",
"timestamp": "2026-05-26T17:43:06.796311+00:00",
"services": {
"mongodb": {"status": "ok", "latency_ms": 157, "detail": "collections=14"},
"redis": {"status": "ok", "latency_ms": 70, "detail": "keys=64036"},
"neo4j": {"status": "ok", "latency_ms": 470, "detail": null},
"supabase": {"status": "ok", "latency_ms": 90, "detail": null},
"azure_openai": {"status": "ok", "latency_ms": 200, "detail": null},
"openai": {"status": "ok", "latency_ms": 1366, "detail": null},
"langfuse": {"status": "ok", "latency_ms": 135, "detail": null}
}
}
Critical services (mongodb, redis, neo4j, supabase, azure_openai, openai) flip
the global status to down and trigger HTTP 503. Non-critical (langfuse)
stay HTTP 200 but show up as degraded/down in the body — Sentry
can alert on partial regressions via body-match rules.
Code: backend/packages/ixweb/ixweb/routes/health.py.
Authentication¶
/status is not public — guarded by a shared-secret header so only Sentry
can hit it.
| Header | Form |
|---|---|
X-Status-Token: <secret> |
preferred |
Authorization: Bearer <secret> |
accepted (for Sentry compatibility) |
Missing or wrong token → HTTP 404 (not 401) to avoid leaking endpoint
existence to scrapers. Comparison uses hmac.compare_digest (timing-safe).
The secret is stored in GCP Secret Manager under the name
STATUS_PROBE_TOKEN in project inboundx. The backend fetches it via
ixinfra.utils.secret_manager.get_secret, which checks env first then falls
back to Secret Manager (cached per process via @lru_cache). Cloud Run's
default service account already has roles/secretmanager.secretAccessor at
project level, so no per-secret IAM binding is required.
Rotating the token¶
gcloud secrets versions add STATUS_PROBE_TOKEN \
--data-file=<(openssl rand -hex 32) \
--project=inboundx
The backend caches the token via @lru_cache for the lifetime of each worker
process. Restart the Cloud Run service (or trigger a new revision) to pick up
the new version. Then update the corresponding Sentry monitor's header value.
Configuring a Sentry Uptime Monitor¶
- Read the token out of Secret Manager:
-
In Sentry: Alerts → Uptime Monitors → Create Monitor.
-
Fill in:
-
URL: pick per environment
- production:
https://api.userose.ai/status - staging:
https://api-staging.userose.ai/status - test:
https://api-test.userose.ai/status
- production:
- Method:
GET - Interval: 1–5 minutes
- Timeout: 10 seconds (each backend probe is capped at 2 s; nine in parallel + network overhead fits comfortably)
- Headers:
- Name:
X-Status-Token - Value: paste the token from step 1
- Name:
- Expected status code:
200 -
Body match (optional):
"status":"ok"to alert when the endpoint returns 200 but a non-critical dependency isdegraded -
Alert routing: wire to the same channel as other backend Sentry alerts.
Local testing¶
The local backend respects the same token. Set it in backend/.env.local:
Restart just dev <environment>, then preview the response in playground at
http://localhost:3001/status — paste the same
token into the page (stored in localStorage under rose:status_probe_token).
Pick the endpoint with the API endpoint selector at the top.
Adding a new probe¶
In backend/packages/ixweb/ixweb/routes/health.py:
- Add
_probe_<service>() -> ServiceStatusthat wraps the check inasyncio.wait_for(..., timeout=STATUS_PROBE_TIMEOUT_S)and returnsServiceStatus(status, latency_ms, detail). - Add the name to the
nameslist and the coroutine toprobesinside_run_status_probes. - If the service is widget-critical, add its name to the
CRITICAL_SERVICESset so a failure flips HTTP to 503. - Use
_http_auth_probefor endpoints requiring a key,_http_reach_probefor unauthenticated reachability.
OpenTelemetry Metrics (Grafana Cloud)¶
Backend services emit native OpenTelemetry metrics to Grafana Cloud over OTLP/HTTP. Traces and logs are intentionally not exported: LLM traces go to Langfuse via its own SDK, and infra APM (HTTP request/health spans) is not collected at all.
Superlog and the FastAPI/HTTPX/Requests/logging auto-instrumentors were removed (IX-4127). They were fanning every
/healthand/api/versionspan into Langfuse via the shared global TracerProvider, doubling the Langfuse observation bill for zero observability value. Metrics were repointed from Superlog to Grafana Cloud; the browser backoffice OTel bootstrap was deleted (backoffice keeps Sentry + PostHog).
Which service exports what:
ixsearch-api— chat latency and per-LLM-call metrics (see Chat Latency & LLM-Call Metrics).knowledge-api/knowledge-content-worker— operation/dispatch/task counters.
The Grafana Basic-auth token lives in Secret Manager under
GRAFANA_OTLP_AUTH_BACKEND; the shared reader factory is
ixinfra.utils.grafana_otlp.grafana_metric_reader().
Manual start_as_current_span calls are inert
Several services still wrap domain operations in tracer.start_as_current_span
(ixknowledge_api/service.py, ixknowledge_api/auth.py,
ixknowledge_content_worker/runner.py + knowledge_client.py,
ixadmin_api/knowledge_*.py). Since no service sets a TracerProvider any
more, these resolve to the no-op tracer and record nothing — they are harmless
but produce no telemetry. Do not add new ones expecting spans to appear; delete
them opportunistically when touching those files.
In a process that does initialise a Langfuse client, the SDK registers a
global TracerProvider, so these spans do get created. They still never reach
Langfuse: the SDK v4 default span filter only exports spans created by
langfuse-sdk, spans carrying gen_ai.* attributes, and known LLM
instrumentation scopes. That filter is what now structurally prevents the
IX-4127 fan-out; do not pass should_export_span=lambda span: True to restore
the pre-v4 export-everything behavior.
Chat Latency & LLM-Call Metrics (Grafana Cloud)¶
Native OTel metrics emitted by the Website Agent and shipped to Grafana Cloud. They answer "how fast is Rose, end-to-end and per model call?" — latency lives here; token/cost analytics stay in Langfuse.
Measurement tiers¶
| Tier | What | Where measured |
|---|---|---|
| A. Whole-turn | request → first/last token, spanning every node (intent → retrieval → answer/redirect/booking) | ixchat/chatbot.py (graph stream anchor) |
| A′. Request-boundary | HTTP-in → response done; includes pre-graph preamble | ixsearch_api/routes/chat.py |
| B. Per-LLM-call | one record per model invocation, by use case (node) | ixchat/nodes/streaming_utils.py + ixllm.metrics.timed_llm_call |
Instrument inventory¶
Names carry the rose_chat_ prefix and no unit suffix — Grafana Cloud's
OTLP→Prometheus normalization appends _seconds / _total and the
_bucket/_sum/_count series. Explicit second-scale histogram buckets are set
via Views in observability.py (default OTel buckets are tuned for counts).
| Instrument | Type | Unit | Tier | Notes |
|---|---|---|---|---|
rose_chat_replies_total |
Counter | 1 |
A | silent-Rose canary — one per reply leaving the graph, by outcome (success/empty/error) and site |
rose_chat_inflight |
UpDownCounter | 1 |
A | in-flight chat requests (live concurrency), by site |
rose_chat_answer_ttft |
Histogram | s |
A | whole-turn time to first token (streaming only) |
rose_chat_answer_duration |
Histogram | s |
A | whole-turn end-to-end, request → last token (TTLT; streaming + non-streaming) |
chat.query.duration |
Histogram | s |
A′ | request-boundary end-to-end (both endpoints) |
rose_chat_llm_call_duration |
Histogram | s |
B | per model call; _count = call rate |
rose_chat_llm_call_ttft |
Histogram | s |
B | per-call first-token latency (streaming calls) |
rose_chat_llm_tokens |
Counter | tokens |
B | best-effort token usage (see caveat) |
Temporality & per-instance series¶
All instruments export with cumulative temporality (the OTel default).
Do not switch to delta — Grafana Cloud / Mimir's OTLP gateway rejects delta
counters/histograms with HTTP 400 (invalid temporality and type combination),
which silently drops every metric batch and leaves dashboards empty.
The search API runs 2–3 Cloud Run instances. Each stamps a unique
service.instance.id (observability.py:_resource), so every instance is its
own Prometheus series — this, not delta, is what keeps cross-instance counters
from collapsing into one bouncing series (which would make rate()/increase()
read each dip as a counter reset). Consequence: always aggregate across
instances in queries — sum(rose_chat_inflight) for the fleet total,
sum(rate(rose_chat_replies_total[5m])), sum by (le, …) (rate(..._bucket[5m]))
before histogram_quantile.
Histogram buckets¶
Each histogram costs one series per bucket, so N explicit boundaries bill N+3
series per attribute combo (N+1 buckets including +Inf, plus _sum and _count).
| Family | Boundaries (s) | Series/combo | Instruments |
|---|---|---|---|
| fast | 0.3, 0.45, 0.6, 0.8, 1.2, 2, 3, 5 |
11 | rose_chat_llm_call_ttft, rose_chat_llm_call_duration, rose_chat_llm_attempt_duration |
| slow | 2, 5, 6, 7, 8, 13 |
9 | rose_chat_answer_duration, rose_chat_answer_ttft, chat.query.duration |
Whole-answer TTFT includes orchestration before the first answer token, so it uses
the whole-turn slow family (IX-4878). With the previous fast assignment,
observations above 5s all entered +Inf; histogram_quantile returns the highest
finite boundary when the requested percentile falls in that overflow bucket,
making TTFT percentiles appear capped at exactly 5s. The same limitation applies
above 13s for slow and above 5s for the remaining per-call fast metrics.
The families get different budgets because their cardinality scales
differently. Tier-A whole-turn histograms carry site, so their series count
grows with every client onboarded. Tier-B per-call histograms deliberately carry no
site (see the tagging plan), so they stay bounded by use_case x model x provider
however many clients exist. Boundaries are expensive on slow, comparatively
cheap on fast.
Place boundaries from measured distributions, never from intuition. A boundary only earns its series if real observations straddle it, and a bucket that swallows several quantiles turns all of them into linear interpolation. Two measurements from 2026-08 drove the sets above:
rose_chat_answer_durationreturned p50/p90/p95 of 6.5 / 7.7 / 7.85 - exactly5 + q * 3. All three sat in one(5, 8]bucket. The only facts the histogram held were p50 < 5s and p95 < 8s.rose_chat_llm_call_durationforinterest_signals_detectorreturned 375 / 475 / 488ms - exactly250 + q * 250, one saturated(0.25, 0.5]bucket.profile_extractorshowed the same signature across(1, 2].
Node p50s span ~375ms (interest_signals_detector, query_rewriter,
skill_selector) through ~0.5-1s (suggesters, intent_classifier) and ~1.5-2s
(profile_extractor) to 2-5s (answer_writer, redirect_handler), which is why
fast spends eight boundaries: per-node comparison is the entire point of the
per-use-case dashboard, and three boundaries in that range could not deliver it.
The failure mode is silent. histogram_quantile always returns a plausible
number, so a boundary set that no longer straddles the distribution looks healthy
while reporting fiction. The tell is a percentile holding a constant value for long
stretches, or a set of quantiles matching lower + q * width for some bucket.
Re-run the quantiles after any latency-affecting change and confirm they don't all
land in one bucket.
When changing boundaries, expect a transient: the retired le series stop receiving
samples and go stale, so histogram_quantile over a window straddling the deploy
reads oddly for a few minutes.
Export interval & cost (IX-4409)¶
Metrics export every 60s — _EXPORT_INTERVAL_MS in the search API's
observability.py, _DEFAULT_EXPORT_INTERVAL_MS in
ixinfra/utils/grafana_otlp.py (the latter also covers the Knowledge API and the
knowledge content worker, which call grafana_metric_reader() with no argument).
Grafana Cloud bills active series × DPM (data points per minute). At 60s every
series is billed at the 1-DPM baseline; the previous 15s interval charged 4× that
for identical information. The interval is not lowered further — 1 DPM is the
billing floor, so a longer interval adds staleness (and thins [5m] rate windows)
without saving anything.
No counter or histogram data is lost. Cumulative temporality means every
add() / record() lands in an in-process accumulator immediately; the export
ships the running total rather than a sample, so reply counts and histogram bucket
counts are identical at 15s and 60s. What the longer interval costs is timestamp
granularity — a latency spike is localizable to a 60s window instead of a 15s one.
Consequences to keep in mind:
- Alerts fire up to 45s later than they would at 15s.
- An ungraceful process death (OOM, SIGKILL) now loses up to 60s of accumulated
increments instead of up to 15s. Graceful exits are unaffected: the lifespan
shutdown flushes (
shutdown_metricsin the search API,shutdown_exportersin the knowledge services), which covers deploys and Cloud Run scale-down. - A fresh worker's first periodic export happens a full 60s after boot (45s later
than before) — the reader sleeps one interval before its first collection. The
seeded
rose_chat_replies_total0-baseline is exempt: startup force-flushes it immediately (seeseed_reply_seriesandforce_flush_metrics). - Rate and histogram queries are unaffected — they all use
[5m]windows, which stay valid at 1 DPM. Do not write windows under[5m]. - Gauge-style instant reads lose resolution.
sum(rose_chat_inflight)is not a rate query — it reads the UpDownCounter's value at collection time. A request that starts and finishes between two ticks nets to zero and is never observed. That was already true at 15s, but the blind window is now 4× wider while a typical chat turn is only ~2–5s, sorose_chat_inflightis a coarse once-a-minute sample of concurrency, not a peak detector. Do not build sub-minute concurrency alerting on it; userate(rose_chat_replies_total[5m])for throughput instead.
Adaptive Metrics (ingest-time aggregation)¶
Grafana Cloud's Adaptive Metrics can aggregate labels away at ingest, cutting
stored (billable) series without a deploy. The lever that matters here is
instance / service_instance_id: aggregating those two collapses the
5-workers × 2–3-instances fan-out, and — because service.instance.id is a fresh
uuid4() per process — it also stops every deploy from abandoning the whole series
set and minting a new one. The code still emits the per-instance id: it is required
pre-aggregation so cumulative counters from different workers don't collide (see
above). It simply stops being billed per instance.
Rules when applying recommendations:
- Never aggregate a metric that backs an alert or a recording rule.
Aggregated series are emitted from a buffer rather than passed straight through,
so an alert evaluating an aggregated metric reads delayed data — which produces
both false positives and missed firings.
rose_chat_replies_totalis therefore excluded from Adaptive Metrics entirely, not merely "done last": it is the silent-Rose canary, and it is a single counter whose aggregation would save a trivial number of series in exchange for putting the one alert that matters on delayed input. Check the per-metric Usage panel's Alerting and recording rules count before writing any rule; non-zero means leave the metric alone. - Don't click "Apply recommendation" blind. It aggregates by "labels currently
in use", inferred from observed queries — so a real dimension with no panel built
yet reads as unused.
rose_chat_llm_attempt_durationis the example: it is the per-model-health signal, and the default recommendation stripsgen_ai_request_model/gen_ai_provider_name/app_gen_ai_use_case. Copy the JSON, cut the aggregate-label list down to the instance labels, apply that. - When hand-editing the JSON, change only the aggregate-labels list. Leave
Typesas Grafana generated it — counters must keep a counter-aware aggregation (sum:counter); substituting a plainsummis-handles counter resets and breaksrate()/increase()over the aggregated series. - Verify the real query, not the rule preview. After applying, run the actual
dashboard query against the aggregated metric and confirm it still returns data —
e.g.
sum(rate(rose_chat_llm_attempt_duration_seconds_bucket[5m])). A rule can look correct in the editor and still strip a label the query groups by. - Watch for churn-induced resets. Aggregating a cumulative counter across a
churning
instancelabel can make a disappearing worker read as a counter reset. Prove the mechanism on a zero-usage metric for ~24h before extending it.
The per-metric Usage panel (Alerting rules / Dashboards / Queries) in that same UI is the authoritative check on whether an instrument is actually consumed — no dashboards or alerts live in this repo.
Tagging plan¶
Discipline: bounded, low-cardinality only. Never session_id, raw IDs,
turn_number, or exception messages. Resource attrs already carry
service.name, deployment.environment.name, service.version,
vcs.ref.head.revision — do not duplicate env/version on metrics.
Whole-turn (A) attributes — chosen to join with rose_chat_replies_total:
| Attribute | Example | Source |
|---|---|---|
site |
mayday.fr |
state["site_name"] (matches the canary's site) |
outcome |
success / empty / error |
mirrors rose_chat_replies_total |
response_node |
answer_writer / redirect_handler / booking_handler |
node that produced the answer |
streaming |
true / false |
streaming vs non-streaming entry point |
Per-LLM-call (B) attributes — OTel GenAI semantic conventions:
| Attribute | Example | Source |
|---|---|---|
app.gen_ai.use_case |
answer_writer, intent_classifier |
the node / route use case (ResolvedChatHandle.use_case) |
gen_ai.request.model |
gpt-5.4, gpt-4.1-mini |
route policy model |
gen_ai.provider.name |
openai / azure / cerebras |
route policy provider |
outcome |
success / error |
call result |
error.type |
timeout / rate_limited / upstream_5xx |
only on outcome=error (short, bounded) |
token_type |
input / output / cache_read |
rose_chat_llm_tokens only |
Dots become _ as Grafana labels (gen_ai_request_model, app_gen_ai_use_case).
Per-call metrics are deliberately not tagged with site (avoids
site × model × node series blowup) — site-level latency lives in tier A.
Why call-site instrumentation (not a callback handler)¶
A LangChain callback handler is not used for per-call metrics because:
- Several aux nodes pass
config={"callbacks": []}(a Langfuse Omit-bug dodge) — a graph-config handler would be stripped on exactly those calls. - No-fallback use cases (
redirect_handler,booking_handler) stream through a raw client — wrapping it in a proxy risks breakingastream_events. - Langfuse traces via OTEL spans, not the callbacks list.
Instead: astream_accumulate (one chokepoint for all streaming answer calls)
takes use_case/request_model/provider kwargs, and structured ainvoke
sites are wrapped with ixllm.metrics.timed_llm_call(...).
Token caveat: reliable token usage is unavailable at call sites —
with_structured_output(...)returns a parsed object with nousage_metadata. The OpenAI and Azure clients setstream_usage=True, so streamed answer calls do carry usage; other providers may not.rose_chat_llm_tokensis best-effort; full token/cost analytics stay in Langfuse.
Prefix-cache hit rate (IX-4353)¶
token_type=cache_read is the share of a call's input tokens that OpenAI /
Azure served from their automatic prefix cache, so a route's hit rate is
cache_read / input. It is worth watching on answer_writer, by far the
largest prompt in the system: caching is keyed on an exact leading match, so
any per-turn content that drifts ahead of the stable head silently zeroes it.
ixskills/prompt_layout.py declares the section order that keeps the head
stable; ixchat/utils/answer_prompt.py is the only place allowed to assemble
the answer system prompt.
The answer route also sends OpenAI's prompt_cache_key (the site domain), which
routes a client's turns to the same backend so the stable head is more likely to
still be resident. It showed no measurable effect in single-stream local testing
— the regime it targets is concurrent traffic spread across sites and instances,
which only exists in production.
The PromQL below gives the fleet-wide hit rate, which is all this metric can
answer: like every tier-B instrument, rose_chat_llm_tokens is deliberately not
tagged with site (see the attribute table above — site × model × node would blow
up the series count). So it can show that the rate moved, but not which clients
moved it, and it cannot attribute a change to the per-site cache key on its own.
For per-client attribution use Langfuse, which carries session and site metadata
per generation.
Cacheable-prefix length (IX-4360)¶
cache_read alone is a poor signal to iterate on: it carries real provider-side
variance, and the same client on the same code has returned 0 cached tokens on one
run and 2 816 on the next. rose_chat_prompt_cacheable_prefix_chars is the
deterministic companion. The answer prompt is a message array — a system message
holding identity plus always-on client skills, then the conversation replayed as
real human/assistant messages, then the per-turn sections riding on the visitor's
own turn. Everything up to and including the last history message is byte-identical
to the previous turn's prompt by construction, so its length is the prefix a
provider could serve from cache. No diffing needed, and it is emitted per site.
Read it against rose_chat_prompt_chars for the share. Both are tagged by site
only — deliberately, since a turn dimension would multiply the series count for
every client — so this metric cannot show progression within a session. Mixed
across all sessions and turns under steady traffic the p50 is flat by
construction, and a flat p50 therefore means nothing on its own. What it answers
is the cross-sectional question: what share of a client's prompts is turn-stable,
and did it move when we changed the layout. For per-session progression use
Langfuse, which carries session id and turn number per generation.
The number to watch is the share, and what breaks it is per-turn content
leaking ahead of the history. If it drops for one client, check
section_for_skill in ixskills/prompt_layout.py (an always-on skill that
interpolates a per-turn value belongs in TURN_SKILLS, not STATIC_SKILLS) and
the conversation_history skill body, which must stay free of placeholders.
The metric reports only what the next turn can genuinely reuse: the newest exchange is excluded (the visitor message sat in a different position last turn, and the reply did not exist yet), the history contributes nothing under the single-system-message layout, and it falls back to the system message alone on a turn where the trim window advances.
Chars, not tokens: no tokenizer is loaded on that path, and the useful signal is the trend rather than the absolute number. Roughly 4 chars to the token.
Example PromQL (Grafana Explore)¶
# p95 whole-turn TTFT per site
histogram_quantile(0.95, sum by (le, site) (rate(rose_chat_answer_ttft_seconds_bucket[5m])))
# p95 per-call latency by model and use case (node)
histogram_quantile(0.95, sum by (le, gen_ai_request_model, app_gen_ai_use_case)
(rate(rose_chat_llm_call_duration_seconds_bucket[5m])))
# token throughput by model and type
sum by (gen_ai_request_model, token_type) (rate(rose_chat_llm_tokens_total[5m]))
# prefix-cache hit rate on the answer route
sum(rate(rose_chat_llm_tokens_total{app_gen_ai_use_case="answer_writer", token_type="cache_read"}[30m]))
/ sum(rate(rose_chat_llm_tokens_total{app_gen_ai_use_case="answer_writer", token_type="input"}[30m]))
# share of the answer prompt that is turn-stable, per site (the number to watch)
sum by (site) (rate(rose_chat_prompt_cacheable_prefix_chars_sum[30m]))
/ sum by (site) (rate(rose_chat_prompt_chars_total[30m]))
# distribution of the turn-stable prefix per site — cross-sectional, NOT a
# within-session trend (see above). Explicit char buckets are set in observability.py;
# without them the OTel defaults stop at 10 000 and every quantile saturates.
histogram_quantile(0.5, sum by (le, site) (rate(rose_chat_prompt_cacheable_prefix_chars_bucket[30m])))
Code map¶
| File | Role |
|---|---|
backend/packages/ixchat/ixchat/metrics.py |
tier-A histograms + record_answer() |
backend/packages/ixllm/ixllm/metrics.py |
tier-B instruments + timed_llm_call, record_*, extract_usage |
backend/packages/ixchat/ixchat/nodes/streaming_utils.py |
per-call emit for streaming answer calls |
backend/apps/api/search/ixsearch_api/.../observability.py |
bucket Views on the MeterProvider |
backend/apps/api/search/ixsearch_api/.../routes/chat.py |
tier-A′ chat.query.duration (both endpoints) |
Harvesting production turns from Langfuse¶
To replay or measure real traffic offline, read observations by name rather than
listing traces: trace.list times out on the production project.
lf.api.observations.get_many(
name="tool-lightrag-retrieval", environment="production",
from_start_time=since, limit=100, cursor=cursor, fields="core,basic,io",
)
parse_io_as_json=True is rejected (400): input and output come back as strings,
so parse them yourself. Join per trace_id:
| observation | carries |
|---|---|
tool-lightrag-retrieval |
query, rag_mode, retrieval start/end |
llm-intent-classifier |
chat_history (formatted USER: / ASSISTANT: lines), input |
agent-intent-router |
domain_id; its end time closes the parallel branches |
llm-answer |
start time, i.e. when the answer stopped waiting for retrieval |
Harvested turns contain visitor data: keep them under .context/, never commit them.
PostHog Batch Pipeline Stall Alerting (IX-4046)¶
The posthog_batch_processor Cloud Run job (every 5 min) transforms
posthog_events_raw → the live analytics tables and advances
posthog_batch_cursor. Its original alerting was crash-only: a dead or
partial export returns 0 silently ("No raw events to process — clean skip"),
indistinguishable from "no traffic". On 2026-07-18 that let a 12h hole in
posthog_events_raw pass with zero alerts.
Two silent-failure detectors now run on every batch invocation — including
the clean-skip path, which is the exact signature of a stalled export
(check_pipeline_health in ixposthog_batch/monitoring.py, called from
run_batch's finally).
1. Cursor lag (primary)¶
now() - posthog_batch_cursor.last_processed_timestamp. Catches export stall,
processor stall, and a frozen cursor at once.
- Emitted as the
posthog_batch_cursor_lag_secondsgauge to Grafana Cloud OTLP (same fan-out +GRAFANA_OTLP_AUTH_BACKENDtoken as the chat metrics above), labelledenvironmentanddeployment_environment_name. - The job also Slacks itself past
CURSOR_LAG_ALERT_SECONDS(default 7200 = 2 h, env-overridable) viaixinfra.notifications.send_slack_notification— same channel as job-failure alerts.
Why the threshold is 2 h and not 30 min (IX-4143)¶
The PostHog batch export's shortest interval on our plan is hourly, so a healthy cursor lag is a sawtooth, not a flat line: it drops to a few minutes when the hour's batch lands (~5–16 min past the hour), then climbs past 70 min before the next one. The original 1800 s threshold sat in the middle of that normal range, so production Slacked a false "cursor stalled" for roughly half of every hour. Any threshold below one full export interval is a guaranteed hourly false alarm. 7200 s means "a whole hourly batch went missing" — the real failure.
If the export interval is ever shortened, lower this threshold with it.
1b. Raw ingest lag (IX-4211)¶
now() - max(posthog_events_raw.inserted_at), emitted as
posthog_batch_raw_ingest_lag_seconds, Slacking past INGEST_LAG_ALERT_SECONDS
(same 2 h default and the same sawtooth reasoning as cursor lag).
Cursor lag alone cannot tell you which side failed: a stalled export freezes the cursor too, so "export down" and "processor down" look identical on it. Ingest lag moves only with the export, so the pair disambiguates:
| cursor lag | ingest lag | verdict |
|---|---|---|
| high | high | export down — nothing is arriving |
| high | normal | processor down — rows are arriving, nobody consumes them |
| normal | high | impossible in practice; suspect a hand-edited cursor |
The probe is an index-backed ORDER BY inserted_at DESC LIMIT 1 on the partial
index idx_posthog_events_raw_inserted_at. It must keep its
inserted_at IS NOT NULL filter — the index is partial, and without the filter the
planner falls onto a 34 GB sequential scan every five minutes.
2. Export coverage (secondary)¶
PostHog's own count of one anchor event (rw_posthog_initialized) vs the rows
that landed in posthog_events_raw for the same event over a settled 60-min
window (ending 2 h ago). Slacks below EXPORT_COVERAGE_MIN_RATIO (default
0.99). This is the only detector for "the export is running but incomplete" —
cursor lag misses it, because the cursor keeps advancing.
3. Processing coverage (secondary)¶
The same anchor in posthog_events_raw vs session_events (rw_-stripped name,
posthog_initialized), emitted as posthog_batch_processing_ratio and Slacking
below PROCESSING_COVERAGE_MIN_RATIO (default 0.99).
Why both floors are 0.99, and why they used to be 0.5 (IX-4211)¶
Both legs are 1:1 by construction and read 1.000 in health. Measured hour by hour on 2026-07-27: leg 2 read ~1.000 on 21 hours and 0.621 / 0.615 / 0.979 on three — and all three were real data loss, confirmed by heap position, not noise. The shared 0.5 floor let a 38%-loss hour pass silently for weeks. There is no healthy value below 1.000 on either leg; 1% of headroom is the whole budget.
COVERAGE_MIN_RATIO still overrides both legs when set, so existing deployment
overrides and the COVERAGE_MIN_RATIO=2 force-a-fire validation below keep working.
The processing leg settles 6 h back, not 2 h¶
Since IX-4211 the cursor follows ingestion order, so a chunk PostHog delivers
5 h late is processed 5 h late — correctly. A window evaluated sooner reads that as
a deficit. _PROCESSING_WINDOW_END_LAG is therefore 6 h, sized on measured
ingestion lateness (p99 1 h 08 m, max 1 h 08 m 28 s on the first post-migration
batch).
If this leg produces false fires, widen the window — never lower the threshold. Lowering the threshold is exactly what caused the blindness this detector exists to end.
Detector 2 stops at the landing zone. This covers the rest of the chain: rows that
landed in raw but were never transformed. Write failures already crash the run into
a Slack alert and poison rows already land in posthog_batch_dlq, so what this adds
is the happy-path case — a filter or transform bug silently dropping rows. That is
the segment the retired session_events_backup comparison used to cover, since the
backup was an independent capture of the final table.
Reads ~1.000, but not exactly: only $pageview and web_vitals are skipped on
the way into session_events (processor.py), so the anchor is essentially 1:1 —
measured 6224 / 6225 = 0.9998 in production. The occasional single-row shortfall
is a raw row with no resolvable session id, which _group_by_session skips by
design (it still advances the cursor). That drift is a handful of rows in thousands
and nowhere near the threshold, but it is why this leg is not asserted as an exact
equality. Skipped entirely when raw holds zero rows for the window — nothing landed
means nothing could be processed, and detector 2 has already alerted.
Both ratios are graphed¶
The ratios are emitted as gauges on every
evaluation, healthy or not — same Grafana Cloud OTLP path and environment label as
the cursor-lag gauge. Graph it before touching the 0.5 threshold: that number is a
guess, and the gauge is what turns it into an observed band. It also exposes slow
decay, which a fixed threshold cannot see.
Unlike cursor lag, this one does not query PostHog on every 5-min invocation. The window is snapped to the clock hour, and a Redis claim keyed by environment + window lets the first available run evaluate it while later runs skip it. A short lease covers the active evaluation; after normal completion the claim is retained for two hours. If the process fails mid-check, the short lease expires and a later run retries. This keeps the normal rate at 24 PostHog queries/day without losing an hour when the minute-zero invocation cannot acquire the processor lock.
PostHog is queried directly through the HogQL query API
(POST https://eu.posthog.com/api/projects/80620/query/), authenticated with a
dedicated monitoring key (query:read scope only) read from
POSTHOG_MONITORING_API_KEY — a standalone Secret Manager secret, env-overridable
for local runs. See the operator-setup section below.
A missing key silently disables this check — it logs a warning and returns, and
nobody reads job logs. That is the same failure shape as the < 50 rows skip this
check replaced, so it needs the same treatment: the gauge below is emitted only
when the check actually ran, so a missing/rotated/expired key, a failing query, or
a dead job all stop the series. Alert on its absence (rule 2 below) — do not rely on
the warning.
Why one anchor event rather than the whole export: the batch export is configured
with a hand-managed include_events allowlist, and mirroring that list in code would
drift silently the moment someone edits it in the PostHog UI. A partial export
drops rows across all event types, so a single event detects it just as well.
rw_posthog_initialized fires once per session init — ~850/h at the overnight
trough, ~20k/h at peak — so the ratio stays meaningful with no absolute row
floor. That matters: the previous check (session_events vs the webhook's
session_events_backup) skipped below 50 reference rows, so decommissioning the
backup webhook would have silently retired the detector instead of failing loudly
(IX-4170).
Why the window ends 2 h ago and not 30 min (IX-4147)¶
Same sawtooth as above, one layer down. PostHog's own event count is complete for
the window immediately; posthog_events_raw can only be as complete as the last
hourly export. With a 30-min settle lag the window's tail simply had not been
exported yet, and coverage read as 90 - cursor_lag_minutes out of 60 minutes —
33% at the sawtooth peak, ~48% mid-cycle. Production Slacked "Partial export
suspected" every hour on data that was 100% complete two hours later. The settle
lag tracks DEFAULT_CURSOR_LAG_ALERT_SECONDS, so both detectors share one
definition of "a whole hourly batch went missing".
Grafana alert rules (belt-and-suspenders — not redundant)¶
The job's own Slack is fast and independent of Grafana, but it cannot detect its own absence — "the job never ran" (dead scheduler, crash-loop, image won't boot) or "the check returned early" produce no Slack, because nothing ran to send one. Both rules below exist to alert on silence, which is why No Data → Alerting is the load-bearing setting in each.
Because these rules aggregate the whole metric — max(metric), no series matcher —
any emitter of the metric name can page production. On 2026-08-25 rule 1 fired
at a 48-day cursor lag while the Cloud Run job was logging 1556 s: the sample came
from somewhere else entirely (IX-4444). Metric export is therefore gated on running
under Cloud Run (K_SERVICE for services, CLOUD_RUN_JOB for jobs) in
metrics_export_allowed() — an allow-list rather than a deny-list on IX_IS_LOCAL,
because just _run-docker-posthog-batch mounts GCP credentials into a container
that never sets that flag.
Consequence for the forced-validation run below: just _run-posthog-batch cannot
produce a gauge any more. Validate on Cloud Run with an execution-scoped override
instead, which exercises the real export path:
gcloud run jobs execute posthog-batch-production --region=europe-west9 \
--update-env-vars=EXPORT_COVERAGE_MIN_RATIO=2
Rule 1 — cursor stalled / job dead
- Alerting → Alert rules → New, on the Grafana Cloud Prometheus datasource.
- Query:
max(posthog_batch_cursor_lag_seconds)(addby (environment)to alert per-env). - Condition:
> 7200for 5m (match the job-side threshold — see the hourly-sawtooth note above;> 1800false-fires every hour). - Set No Data handling to Alerting — a stalled gauge (job dead) is itself the alert.
- Contact point → the same Slack channel as the job alerts.
Rule 1b — export stalled (which side is down)
- Query:
max(posthog_batch_raw_ingest_lag_seconds). - Condition:
> 7200for 5m. - No Data → Alerting.
- Contact point → same Slack channel.
Pair this with Rule 1 on a single dashboard row: firing together means the export is down, Rule 1 alone means the processor is.
Rule 2 — coverage gap, or the coverage check going silent
- Query:
min(posthog_batch_export_coverage_ratio). Add a second rule onmin(posthog_batch_processing_ratio)with the same no-data window for the raw →session_eventsleg. - Condition:
< 0.99for 15m, on both rules. Not 0.5 — see the why-0.99 note above; at 0.5 a 38%-loss hour reads as healthy. - No Data → Alerting, evaluated over a window of at least 3 h. The gauge is written once an hour (see the cadence note above), so a shorter window false-fires between emissions.
- Contact point → same Slack channel.
If the processing rule fires on a legitimately-late export chunk, widen
_PROCESSING_WINDOW_END_LAG in monitoring.py — do not relax this condition.
Rule 2's No-Data arm is the one that matters most: it is the only thing that
catches a missing, rotated, or expired POSTHOG_MONITORING_API_KEY, a PostHog API
outage, or a query that started failing — all of which make the check return early
and log a warning nobody reads. Without it, the coverage detector can be disabled
by a credential change and stay disabled indefinitely, which is precisely the
failure mode IX-4170 was filed to remove.
Expect a rare double-fire (job-side + Grafana) when a threshold is crossed while
the job still runs; harmless for a silent-failure guard. These rules are the
durable alerts that survive backup-webhook decommission, and rule 1 is the exit
criterion for IX-4035. Both job-side detectors now reference PostHog or
posthog_events_raw only, so the decommission removes no monitoring.
Operator setup for the export-coverage check¶
The credential is a dedicated monitoring key, deliberately not folded into the
rose-backend-env-* bundle: it is read-only, single-purpose, and independently
rotatable.
- Create the PostHog key. Settings → Personal API keys
(EU, not
us.). Labelrose-posthog-batch-monitoring, scoped to the Rose app (80620) project only, with exactly one scope: Query → Read (query:read). No write scopes, nobatch_export:read— the check never reads the export config. - Store it as a standalone Secret Manager secret named
POSTHOG_MONITORING_API_KEY:
printf %s "$KEY" | gcloud secrets create POSTHOG_MONITORING_API_KEY \
--project=inboundx --data-file=- --replication-policy=automatic
# rotation later:
printf %s "$NEW_KEY" | gcloud secrets versions add POSTHOG_MONITORING_API_KEY \
--project=inboundx --data-file=-
printf rather than echo — a trailing newline lands in the secret payload and
breaks the Authorization header.
3. Grant the Cloud Run service account access. The Terraform in
infrastructure/secret-manager-iam.tf only grants secretAccessor on the
rose-backend-env-* / rose-frontend-env-* bundles, so a standalone secret is
unreadable until granted — the job would log PermissionDenied and skip.
The binding is declared in local.standalone_secret_names there, but do not
run a bare tf-with-env.sh apply for it: the root module also covers VPC,
static IPs, Cloudflare and MongoDB Atlas, so a full apply reconciles all of that
to add one binding. Grant it directly instead (after step 2 — the binding needs
the secret to exist):
gcloud secrets add-iam-policy-binding POSTHOG_MONITORING_API_KEY \
--project=inboundx \
--member="serviceAccount:$(gcloud projects describe inboundx --format='value(projectNumber)')-compute@developer.gserviceaccount.com" \
--role=roles/secretmanager.secretAccessor
google_secret_manager_secret_iam_member is additive and idempotent, so the next
full apply reconciles to the same binding rather than conflicting with it.
get_secret() checks the environment first, so an entry in backend/.env.<env>
still overrides the secret for local runs — but production reads the standalone
secret.
Until all three steps are done the job logs
POSTHOG_MONITORING_API_KEY unavailable — export-coverage check disabled each run
and never emits posthog_batch_export_coverage_ratio. That log is the only
in-band signal, which is why Grafana rule 2 below is mandatory rather than
optional: a key that is never created — or is rotated, expires, or loses its IAM
binding later — otherwise leaves you silently down to cursor lag alone.
Forced validation¶
CURSOR_LAG_ALERT_SECONDS=0 just _run-posthog-batch <env> forces a lag fire →
expect a Slack message + a posthog_batch_cursor_lag_seconds log line. It does
not put the gauge in Grafana: since IX-4444 export is gated on Cloud Run's own
markers, so anything run off Cloud Run — _run-posthog-batch, _run-docker-posthog-batch,
an ad-hoc script — logs the value and skips the push. To validate the Grafana leg,
use an execution-scoped override on the real job:
gcloud run jobs execute posthog-batch-production --region=europe-west9 \
--update-env-vars=CURSOR_LAG_ALERT_SECONDS=0
COVERAGE_MIN_RATIO=2 just _run-posthog-batch <env> does the same for the coverage
detector — any real ratio is then below threshold. The first successful invocation
for that settled window retains its Redis claim, so delete the
lock:posthog-batch:coverage:<env>:<window> key before repeating this forced check
within the same hour.
Two warnings on both commands. Slack + Supabase are shared across environments, so
this posts a real message to the job-alerts channel. More importantly,
_run-posthog-batch runs the full processor, not just the health checks: it
writes session_events / visitor_sessions to production and advances the
cursor, which makes the next scheduled run skip that work. To exercise only the
read-only coverage inputs (secret → PostHog query → raw count → ratio), call
_posthog_anchor_count and count_raw_events_in_window from a throwaway script
instead — no writes, no Slack, no cursor movement.