feat(server): instrument HTTP and store with bounded metrics - #173
feat(server): instrument HTTP and store with bounded metrics#173Bnjoroge1 wants to merge 6 commits into
Conversation
Wire the observability handle into the hot path without holding the global lock during export. Replace the default TraceLayer that leaked raw URIs with a safe middleware that records method, matched route template (never concrete ID or query, 1000 IDs remain one series), finite surface (native, runner, broker, results, webhook, git, oidc, live_logs, public, test, unknown) and status class. The live_logs WebSocket is excluded from the duration histogram and will be tracked via livelog connections instead. Active requests are an updown gauge; durations use the 0.005..10s buckets. Add a shared MetricsRegistry in preloop-observability (HttpMetrics + StoreMetrics) with Prometheus text rendering. The registry is cloneable via the Observability handle (already in AppState) and is fed only from the cached snapshot or via the InstrumentedStore wrapper — no await while holding InnerState. Wrap the private Store trait once in store.rs with InstrumentedStore: all seven methods (load_into, store_inner, store_meta_only, store_run_event, store_workflow_run_counter, store_log_chunk, append_event) record preloop.store.operation.duration with backend, operation, outcome and the consecutive-failures gauge, preserving every return/error and the best-effort persistence rule. Bootstrap wraps the store returned by open_store with the same observability handle (backend sqlite vs postgres detected from PRELOOP_STORE_URL). Extend GET /metrics to append the registry's http and store exposition after the snapshot-based pool/queue gauges, still behind native bearer. cargo check, fmt, sg-scan-strict and preloop-observability tests (12, including route normalization and bounded-series) pass; run/job and broker lifecycle counters remain for the next change. Entire-Checkpoint: 01M0GJQ8PAGXWHJTR7WHR0SGVS
Add lifecycle counters to the shared registry so each terminal reason is counted exactly once. Hook AppState::emit where JobStatus and JobCompleted are persisted: map ExecutionStatus to a bounded conclusion (success, failure, cancelled, skipped) and reason to the finite set the plan allows (timeout, no_runner, lease_expired, deaf_runner, startup_orphan, concurrency_cancelled, etc., otherwise unknown), then increment preloop.job.completed. The event itself is the proof of old→terminal movement, so the metric is recorded here rather than at the state mutation to avoid double-counting on duplicate store_run_event emits. Add LifecycleMetrics to the registry with job_completed, queue_wait histogram (0.1..900s), broker_poll and session_transition counters, and render them in the Prometheus exposition. Queue wait and broker poll hooks are stubbed for the next change (concurrency decision at apply_queue_mode and broker poll outcomes at broker_acquire). cargo check, fmt and sg-scan-strict pass; observability tests 12 pass (single-threaded due to env var sharing). Entire-Checkpoint: 01M0GKDFWWC2FE1GSNTVPM8JN5
Entire-Checkpoint: 01M0GKSZQZF3W5Y845G32JMS81
Entire-Checkpoint: 01M0GKV2PHJV613WVX8YRXEYMV
Entire-Checkpoint: 01M0GKX9XYV46TF4X69AF6S12X
…lity handle Entire-Checkpoint: 01M0GMXWV4EG9KC96M5RJD5DG9
|
You have reached your Codex usage limits for code reviews. You can see your limits in the Codex usage dashboard. |
|
Important Review skippedAuto reviews are disabled on base/target branches other than the default branch. Please check the settings in the CodeRabbit UI or the ⚙️ Run configurationConfiguration used: Organization UI Review profile: CHILL Plan: Pro Plus Run ID: You can disable this status message by setting the Use the checkbox below for a quick retry:
Comment |
![macroscopeapp[bot]](https://avatars.githubusercontent.com/in/900172?s=60&v=4){kind=small}
| // Ensure it's a segment boundary: /api/v1/runs/abc should match /api/v1/runs/:run_id | ||
| // but /api/v1/runsXYZ should not. | ||
| let rest = &path[prefix.len()..]; | ||
| if rest.is_empty() || rest.starts_with('/') { |
There was a problem hiding this comment.
🟡 Medium src/metrics.rs:504
normalize_route labels /api/v1/runs as /api/v1/runs/:run_id and labels unrelated or incomplete /api/v1/.../workflows/... paths as /api/v1/.../artifacts/:artifact_id. The prefix check only verifies the first parameter boundary, so it accepts empty parameters and never validates later template segments; match the complete segment structure and require every parameter segment to be nonempty.
🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/preloop-observability/src/metrics.rs around line 504:
`normalize_route` labels `/api/v1/runs` as `/api/v1/runs/:run_id` and labels unrelated or incomplete `/api/v1/.../workflows/...` paths as `/api/v1/.../artifacts/:artifact_id`. The prefix check only verifies the first parameter boundary, so it accepts empty parameters and never validates later template segments; match the complete segment structure and require every parameter segment to be nonempty.
| // rather than at the state mutation to avoid double-counting on | ||
| // duplicate `store_run_event` emits. | ||
| match &event { | ||
| NdjsonEvent::JobStatus { status, reason, .. } if status.is_terminal() => { |
There was a problem hiding this comment.
🟡 Medium src/state.rs:850
preloop_job_completed overcounts jobs because every terminal JobStatus event increments it, even when no old-to-terminal transition occurred. patch_timeline_records emits terminal events for completed step records using the logical job ID, and repeated completion requests can emit Cancelled again for an already-cancelled job; therefore one job contributes multiple increments. Record this metric only at the authoritative completion transition, or deduplicate terminal events by job.
Also found in 1 other location(s)
crates/preloop-runner-server/src/broker.rs:850
Counting every terminal
NdjsonEvent::JobStatusdoes not count terminal job transitions exactly once.patch_timeline_recordsprojects each completed timeline record (including completed step records) into a terminalJobStatususing the logical job ID, and normal completion later emits another terminalJobStatus; repeated timeline PATCHes can add still more. Consequentlypreloop_job_completedovercounts a single job, potentially once per completed step plus completion, so alerts and job totals are incorrect. Deduplicate by job transition or record only at the authoritative completion mutation.
🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/preloop-runner-server/src/state.rs around line 850:
`preloop_job_completed` overcounts jobs because every terminal `JobStatus` event increments it, even when no old-to-terminal transition occurred. `patch_timeline_records` emits terminal events for completed step records using the logical job ID, and repeated completion requests can emit `Cancelled` again for an already-cancelled job; therefore one job contributes multiple increments. Record this metric only at the authoritative completion transition, or deduplicate terminal events by job.
Also found in 1 other location(s):
- crates/preloop-runner-server/src/broker.rs:850 -- Counting every terminal `NdjsonEvent::JobStatus` does not count terminal job transitions exactly once. `patch_timeline_records` projects each completed timeline record (including completed step records) into a terminal `JobStatus` using the logical job ID, and normal completion later emits another terminal `JobStatus`; repeated timeline PATCHes can add still more. Consequently `preloop_job_completed` overcounts a single job, potentially once per completed step plus completion, so alerts and job totals are incorrect. Deduplicate by job transition or record only at the authoritative completion mutation.
| impl LifecycleMetrics { | ||
| pub fn record_job_completed(&self, conclusion: &str, reason: &str) { | ||
| let labels = JobCompletedLabels { | ||
| conclusion: conclusion.to_string(), |
There was a problem hiding this comment.
🟡 Medium src/metrics.rs:295
LifecycleMetrics creates a new map entry for every distinct caller-provided label string, so unique reason values passed to record_job_completed permanently grow the registry and process memory. Constrain these labels to finite types or map unknown values to fixed labels before using them as keys.
🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/preloop-observability/src/metrics.rs around line 295:
`LifecycleMetrics` creates a new map entry for every distinct caller-provided label string, so unique `reason` values passed to `record_job_completed` permanently grow the registry and process memory. Constrain these labels to finite types or map unknown values to fixed labels before using them as keys.
| if path.contains(':') { | ||
| return path.to_string(); | ||
| } |
There was a problem hiding this comment.
🟠 High src/metrics.rs:458
normalize_route returns any raw path containing : verbatim, so unmatched requests such as /missing:id1 and /missing:id2 create distinct route labels instead of /unknown and allow the in-memory series maps to grow without bound. Do not infer that a value is a trusted Axum template from the presence of :; let only the known-template matching logic preserve templates.
- // Already a template? (contains ':')
- if path.contains(':') {
- return path.to_string();
- }🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/preloop-observability/src/metrics.rs around lines 458-460:
`normalize_route` returns any raw path containing `:` verbatim, so unmatched requests such as `/missing:id1` and `/missing:id2` create distinct route labels instead of `/unknown` and allow the in-memory series maps to grow without bound. Do not infer that a value is a trusted Axum template from the presence of `:`; let only the known-template matching logic preserve templates.
| .observability | ||
| .metrics() | ||
| .lifecycle | ||
| .record_queue_wait("claimed", std::time::Duration::from_secs(1)); |
There was a problem hiding this comment.
🟡 Medium src/broker.rs:882
preloop_job_queue_wait_seconds records 1 second for every successful claim, regardless of how long the job actually waited in the queue. This makes the histogram's latency data incorrect; retain an enqueue timestamp and record the elapsed duration at claim instead.
🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/preloop-runner-server/src/broker.rs around line 882:
`preloop_job_queue_wait_seconds` records `1` second for every successful claim, regardless of how long the job actually waited in the queue. This makes the histogram's latency data incorrect; retain an enqueue timestamp and record the elapsed duration at claim instead.
| if let Some(lbl) = labels { | ||
| let mut lbl = lbl; | ||
| lbl.status_class = sc.clone(); | ||
| // Record duration only for non-live_logs | ||
| shared | ||
| .state | ||
| .observability | ||
| .metrics() | ||
| .http | ||
| .observe_duration(lbl.clone(), elapsed); | ||
| shared.state.observability.metrics().http.dec_active(&lbl); | ||
| } |
There was a problem hiding this comment.
🟡 Medium src/http_metrics.rs:66
http_server_active_requests permanently retains the placeholder status_class = "2xx" entry for every non-2xx response, so /metrics increasingly overstates active concurrency. The middleware mutates the label to the response class before dec_active, causing the decrement to look up a different series; decrement the original labels before changing status_class.
| if let Some(lbl) = labels { | |
| let mut lbl = lbl; | |
| lbl.status_class = sc.clone(); | |
| // Record duration only for non-live_logs | |
| shared | |
| .state | |
| .observability | |
| .metrics() | |
| .http | |
| .observe_duration(lbl.clone(), elapsed); | |
| shared.state.observability.metrics().http.dec_active(&lbl); | |
| } | |
| if let Some(lbl) = labels { | |
| shared.state.observability.metrics().http.dec_active(&lbl); | |
| let mut lbl = lbl; | |
| lbl.status_class = sc.clone(); | |
| shared | |
| .state | |
| .observability | |
| .metrics() | |
| .http | |
| .observe_duration(lbl.clone(), elapsed); | |
| } |
Also found in 2 other location(s)
crates/preloop-observability/src/metrics.rs:78
dec_activelooks up the fullHttpLabels, includingstatus_class. The middleware increments with placeholderstatus_class = "2xx", then replaces it with the response's actual class before calling this method. Every 4xx/5xx response therefore fails to decrement the original entry, sohttp_server_active_requestspermanently accumulates completed error requests.
crates/preloop-runner-server/src/routes.rs:815
Installing
http_metrics_middlewareexposes a label mismatch in its active-request accounting: it callsinc_activewithstatus_class = "2xx"before dispatch, then changes that label to the actual response class beforedec_active. Every 4xx/5xx request therefore permanently increments the2xxactive series and decrements a different 4xx/5xx series below zero, so/metricsreports increasingly incorrect active-request gauges.
🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/preloop-runner-server/src/http_metrics.rs around lines 66-77:
`http_server_active_requests` permanently retains the placeholder `status_class = "2xx"` entry for every non-2xx response, so `/metrics` increasingly overstates active concurrency. The middleware mutates the label to the response class before `dec_active`, causing the decrement to look up a different series; decrement the original labels before changing `status_class`.
Also found in 2 other location(s):
- crates/preloop-observability/src/metrics.rs:78 -- `dec_active` looks up the full `HttpLabels`, including `status_class`. The middleware increments with placeholder `status_class = "2xx"`, then replaces it with the response's actual class before calling this method. Every 4xx/5xx response therefore fails to decrement the original entry, so `http_server_active_requests` permanently accumulates completed error requests.
- crates/preloop-runner-server/src/routes.rs:815 -- Installing `http_metrics_middleware` exposes a label mismatch in its active-request accounting: it calls `inc_active` with `status_class = "2xx"` before dispatch, then changes that label to the actual response class before `dec_active`. Every 4xx/5xx request therefore permanently increments the `2xx` active series and decrements a different 4xx/5xx series below zero, so `/metrics` reports increasingly incorrect active-request gauges.
| out.push_str("# TYPE preloop_job_completed counter\n"); | ||
| for (labels, cnt) in self.job_completed.read().iter() { | ||
| out.push_str(&format!( | ||
| "preloop_job_completed{{conclusion=\"{}\",reason=\"{}\"}} {}\n", |
There was a problem hiding this comment.
🟡 Medium src/metrics.rs:340
LifecycleMetrics::render emits malformed Prometheus exposition when a public record_* method receives a label containing \, ", or a newline; for example, reason = "a\"\nb" can inject additional metric lines and make /metrics scrapes fail or report misleading series. Escape every label value before interpolating it into the quoted metric labels.
🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/preloop-observability/src/metrics.rs around line 340:
`LifecycleMetrics::render` emits malformed Prometheus exposition when a public `record_*` method receives a label containing `\`, `"`, or a newline; for example, `reason = "a\"\nb"` can inject additional metric lines and make `/metrics` scrapes fail or report misleading series. Escape every label value before interpolating it into the quoted metric labels.
| req: Request, | ||
| next: Next, | ||
| ) -> Response { | ||
| let method = req.method().to_string(); |
There was a problem hiding this comment.
🟠 High src/http_metrics.rs:29
Custom HTTP methods are copied into the method label, so an unauthenticated client can send a unique valid method token per request and create an unbounded durations series, eventually exhausting server memory. Normalize extension methods to a fixed other label (or a finite allowlist) before constructing HttpLabels.
🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/preloop-runner-server/src/http_metrics.rs around line 29:
Custom HTTP methods are copied into the `method` label, so an unauthenticated client can send a unique valid method token per request and create an unbounded `durations` series, eventually exhausting server memory. Normalize extension methods to a fixed `other` label (or a finite allowlist) before constructing `HttpLabels`.
1 participant
Bounded HTTP middleware (matched route template, finite surface, status class; live-log websocket excluded) replacing
TraceLayer;InstrumentedStoredecorator timing all seven store operations; lifecycle counters for job terminal transitions, queue wait, broker poll outcomes, session create/delete, and concurrency decisions; store always instrumented even without an explicit observability handle. Cardinality stays bounded by construction: every label derives from a finite set.Part of a stacked series (merge bottom-up):
Summary by cubic
Instruments HTTP and store with a bounded in-memory metrics registry and replaces
tower_http::trace::TraceLayerwith a safe middleware. This prevents high-cardinality labels, adds lifecycle counters, and appends these series to the existing/metricsoutput./ws/live-logsfrom duration histograms; adds an active-requests gauge; never emits raw URIs or queries. Falls back to normalized templates when no matched route exists.Storeonce withInstrumentedStore, timing all seven operations and labeling by backend (sqlite|postgres) and outcome (ok|error). Tracks a consecutive-failures gauge. Store stays instrumented even when no explicit observability handle is passed./metrics: appends the registry’s HTTP, store, and lifecycle exposition after the snapshot-based gauges.Written for commit e355896. Summary will update on new commits.
Note
Add bounded in-memory metrics for HTTP, store, and lifecycle in runner server
MetricsRegistryinpreloop-observabilitywith bounded-label histograms and gauges for HTTP, store, and lifecycle metrics, rendered in Prometheus formatInstrumentedStoreto record operation duration and consecutive failures keyed by backend and operationhttp_metrics_middlewareto record active-request gauge and request-duration histogram; replaces the previousTraceLayer::new_for_http()layerGET /metricsTraceLayerin routes.rs drops automatic HTTP request/response tracing spans; the new middleware creates an info-level span but does not enter it📊 Macroscope summarized e355896. 10 files reviewed, 14 issues evaluated, 6 issues filtered, 8 comments posted
🗂️ Filtered Issues
crates/preloop-observability/src/metrics.rs — 4 comments posted, 5 evaluated, 1 filtered
dec_activelooks up the fullHttpLabels, includingstatus_class. The middleware increments with placeholderstatus_class = "2xx", then replaces it with the response's actual class before calling this method. Every 4xx/5xx response therefore fails to decrement the original entry, sohttp_server_active_requestspermanently accumulates completed error requests. [ Cross-file consolidated ]crates/preloop-runner-server/src/bootstrap.rs — 0 comments posted, 2 evaluated, 2 filtered
PRELOOP_STORE_URLeven whenconfig.store_urlisSome, althoughAppState::new_with_storegives the explicit argument precedence. For example, an explicit SQLite URL with a stale Postgres environment variable opens SQLite but labels every store metric asbackend="postgres", producing incorrect telemetry. [ Out of scope (post-validation triage) ]InstrumentedStoreis installed only afterAppState::new_with_storereturns, but that constructor has already made the soleStore::load_intocall. Consequentlypreloop.store.operation.durationnever records theload_intooperation (including startup failures), despite the decorator implementing that metric; the store must be wrapped before state loading to instrument all operations. [ Out of scope (post-validation triage) ]crates/preloop-runner-server/src/broker.rs — 1 comment posted, 3 evaluated, 2 filtered
broker_delete_session_rootrecords a successful delete even when neitherx-actions-sessionnor thesessionIdquery parameter is present. In that caseremove_broker_sessionis never called, yet the endpoint returns 204 and incrementspreloop_runner_session_transition_total{operation="delete",reason="ok"}, so malformed/no-op requests inflate the successful lifecycle metric. [ Out of scope (post-validation triage) ]NdjsonEvent::JobStatusdoes not count terminal job transitions exactly once.patch_timeline_recordsprojects each completed timeline record (including completed step records) into a terminalJobStatususing the logical job ID, and normal completion later emits another terminalJobStatus; repeated timeline PATCHes can add still more. Consequentlypreloop_job_completedovercounts a single job, potentially once per completed step plus completion, so alerts and job totals are incorrect. Deduplicate by job transition or record only at the authoritative completion mutation. [ Cross-file consolidated ]crates/preloop-runner-server/src/routes.rs — 0 comments posted, 1 evaluated, 1 filtered
http_metrics_middlewareexposes a label mismatch in its active-request accounting: it callsinc_activewithstatus_class = "2xx"before dispatch, then changes that label to the actual response class beforedec_active. Every 4xx/5xx request therefore permanently increments the2xxactive series and decrements a different 4xx/5xx series below zero, so/metricsreports increasingly incorrect active-request gauges. [ Cross-file consolidated ]