Add bottleneck and run-time metrics for indexer utilisation - #1486
Conversation
Add two counters that attribute batch-processing idle time to its cause, so dashboards can tell whether fetching or storage writes is the constraint rather than only seeing which stage is busy: - envio_processing_stalled_on_fetch_seconds: time the processing loop sat with an empty buffer waiting for fetched events. - envio_processing_stalled_on_storage_write_seconds: time processing was blocked on write backpressure (Writing.awaitCapacity). Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01TCWAgbg4CSpwkYctA4LWa1
|
Note Reviews pausedIt looks like this branch is under active development. To avoid overwhelming you with review comments due to an influx of new commits, CodeRabbit has automatically paused this review. You can configure this behavior by changing the Use the following commands to manage reviews:
Use the checkboxes below for quick actions:
📝 WalkthroughWalkthroughProcessing stall durations are tracked for fetch starvation and storage-write waits, exposed through indexer metrics, rendered as Prometheus counters and process-time gauges, and covered by collection and state-accounting tests. ChangesProcessing stall metrics
Estimated code review effort: 3 (Moderate) | ~20 minutes Sequence Diagram(s)sequenceDiagram
participant BatchProcessing
participant EventProcessing
participant IndexerState
participant Metrics
BatchProcessing->>IndexerState: markProcessingStalledOnFetch()
EventProcessing->>IndexerState: recordStalledOnStorageWrite(seconds)
IndexerState->>Metrics: toMetrics()
Metrics->>Metrics: render process and stall metrics
Possibly related PRs
🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 1
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@packages/envio/src/IndexerState.res`:
- Around line 403-412: Update the transition handlers beginReorg, stop, and
errorExit to finalize the active processingStalledOnFetchSince interval
consistently with beginProcessing, adding its elapsed duration to
processingStalledOnFetchSeconds before clearing the ref. Ensure each transition
clears the stall state so toMetrics does not count rollback or shutdown time and
later beginProcessing cannot flush it again.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro
Run ID: b53d1afa-7282-41a4-b0ff-31f471518787
📒 Files selected for processing (6)
packages/envio-tests/test/lib_tests/Metrics_test.respackages/envio/src/BatchProcessing.respackages/envio/src/EventProcessing.respackages/envio/src/IndexerState.respackages/envio/src/IndexerState.resipackages/envio/src/Metrics.res
| let beginProcessing = (state: t) => { | ||
| switch state.processingStalledOnFetchSince { | ||
| | Some(since) => | ||
| state.processingStalledOnFetchSeconds = | ||
| state.processingStalledOnFetchSeconds +. since->Performance.secondsSince | ||
| state.processingStalledOnFetchSince = None | ||
| | None => () | ||
| } | ||
| state.isProcessing = true | ||
| } |
There was a problem hiding this comment.
🎯 Functional Correctness | 🟠 Major | 🏗️ Heavy lift
Terminate active fetch stalls on reorg and shutdown.
processingStalledOnFetchSince is only cleared by beginProcessing; beginReorg, stop, and errorExit leave it set. toMetrics therefore keeps adding elapsed time during rollback/shutdown, and a later beginProcessing flushes that transition time into the cumulative counter. Finalize the interval at each transition—or explicitly discard it per the metric contract—and clear the ref; guarding only the scrape is insufficient.
Also applies to: 508-513
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
In `@packages/envio/src/IndexerState.res` around lines 403 - 412, Update the
transition handlers beginReorg, stop, and errorExit to finalize the active
processingStalledOnFetchSince interval consistently with beginProcessing, adding
its elapsed duration to processingStalledOnFetchSeconds before clearing the ref.
Ensure each transition clears the stall state so toMetrics does not count
rollback or shutdown time and later beginProcessing cannot flush it again.
Don't attribute processing idle time to fetch starvation when every chain has already buffered up to its known head. In that state the loop is idling at the tip waiting for new blocks, not bottlenecked on fetch, so counting it inflated envio_processing_stalled_on_fetch_seconds. Uses ChainState.isFetchingAtHead, which accounts for blockLag and endBlock rather than a raw buffer-equals-height comparison. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01TCWAgbg4CSpwkYctA4LWa1
![chatgpt-codex-connector[bot]](https://avatars.githubusercontent.com/in/1144995?s=60&v=4){kind=small}
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 85d54c4e96
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| state.processingStalledOnFetchSeconds = | ||
| state.processingStalledOnFetchSeconds +. since->Performance.secondsSince | ||
| state.processingStalledOnFetchSince = None |
There was a problem hiding this comment.
Folding every open fetch-stall interval here misattributes rollback time when a fetch response arrives while processing is already idle and detects a reorg: that path calls beginReorg/scheduleRollback() without beginProcessing, so processingStalledOnFetchSince stays open through the async rollback work and is only added when rollback later schedules processing. In reorg-heavy runs this makes envio_processing_stalled_on_fetch_seconds spike even though the processor was resolving rollback, not waiting for fetched events; clear or close this timer when entering rollback/reorg instead.
Useful? React with 👍 / 👎.
Expose two render-time gauges so a single /metrics scrape is self-describing without a query-time clock: - envio_process_elapsed_seconds: seconds since the indexer started. Dividing a cumulative counter by it yields that stage's share of the whole run straight from one snapshot. - envio_scrape_time_seconds: unix time the snapshot was generated, so a scrape can be dated on its own. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01TCWAgbg4CSpwkYctA4LWa1
Move the three process-time gauges to the top of the render, right below envio_info, ordered start time, metric time, elapsed. Rename envio_scrape_time_seconds to envio_process_metric_time_seconds for a consistent envio_process_* prefix. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01TCWAgbg4CSpwkYctA4LWa1
Extract the fetch-stall fold into settleStalledOnFetch and call it from beginReorg. Without it, a stall interval opened before a reorg stayed open across the rollback and was folded into envio_processing_stalled_on_fetch_seconds on the next beginProcessing, double-counting time envio_rollback_seconds already owns. Rename the Metrics.t field scrapeTime to metricTime to match the envio_process_metric_time_seconds metric it renders. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01TCWAgbg4CSpwkYctA4LWa1
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: dfd8aad84b
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| let writeStallRef = Performance.now() | ||
| await indexerState->Writing.awaitCapacity | ||
| indexerState->IndexerState.recordStalledOnStorageWrite( | ||
| ~seconds=writeStallRef->Performance.secondsSince, |
There was a problem hiding this comment.
When Writing.awaitCapacity returns immediately because the change count is below keepLatestChangesLimit, awaiting its already-resolved promise still defers this continuation to a microtask, so every processed batch adds scheduling latency to envio_processing_stalled_on_storage_write_seconds despite no storage backpressure. On high-throughput or event-loop-busy indexers this can make the new metric falsely identify storage writes as a bottleneck; measure only the branch that actually waits for a commit/capacity to be freed.
Useful? React with 👍 / 👎.
| ->Array.every(ChainState.isFetchingAtHead) | ||
| ) | ||
| ) { | ||
| state->IndexerState.markProcessingStalledOnFetch |
There was a problem hiding this comment.
When a fetch response is applied after an empty processNextBatch has taken its snapshot but before the caller resumes from await, that response can enqueue ready items while its scheduleProcessing() call is ignored because isProcessing is still true. This path then starts the fetch-stall interval solely from the frontier check without rechecking for buffered work; if the response also fills the shared fetch budget, the subsequent fetch kick has nothing to dispatch, so the metric can keep reporting fetch starvation while processable events are already buffered. Recheck for work or rerun processing before marking the stall.
Useful? React with 👍 / 👎.
| ~name="envio_process_elapsed_seconds", | ||
| ~help="Seconds elapsed since the indexer started. Divide a cumulative counter (e.g. envio_processing_seconds) by this to get its share of the whole run without a query-time clock.", | ||
| ~kind="gauge", | ||
| ~value=(metrics.metricTime->Date.getTime -. metrics.startTime->Date.getTime) /. 1000., |
There was a problem hiding this comment.
If the host wall clock is corrected after the indexer starts—for example by NTP synchronization, a manual clock change, or a VM clock adjustment—subtracting these two Date values makes envio_process_elapsed_seconds jump forward, move backward, or even become negative. The cumulative processing and stall counters use monotonic Performance durations, so dividing them by this wall-clock-derived gauge can produce invalid utilization shares; retain a monotonic start reference and use it for elapsed time while keeping metricTime as the wall-clock timestamp.
Useful? React with 👍 / 👎.
Cover the two invariants the stall counter depends on: a repeated mark must not restart an open interval, and beginReorg must settle it so the rollback that follows isn't folded into the stall. The reorg case is a regression test for the double-count fixed in the previous commit — reverting that fix makes it fail with the full rollback span attributed to envio_processing_stalled_on_fetch_seconds. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01TCWAgbg4CSpwkYctA4LWa1
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 5c3e0ccd2a
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| processingSeconds: state.processingSeconds, | ||
| processingStalledOnFetchSeconds: state.processingStalledOnFetchSeconds +. | ||
| switch state.processingStalledOnFetchSince { | ||
| | Some(since) => since->Performance.secondsSince |
There was a problem hiding this comment.
When a state is already fetch-stalled and a fetch/write failure invokes errorExit (or a test/dev handoff calls stop), those shutdown transitions only set isStopped and leave processingStalledOnFetchSince open. Because this getter unconditionally adds secondsSince for an open interval, subsequent metrics snapshots keep increasing envio_processing_stalled_on_fetch_seconds after every indexer loop has halted; settle the interval as part of both stop transitions so the counter freezes at shutdown.
Useful? React with 👍 / 👎.
Replace the minimal Utils.magic state with MockIndexer.InMemoryStore.make, so the tests drive a real IndexerState and read the counter through toMetrics rather than a hand-built stub that would break confusingly if a transition started reading another field. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01TCWAgbg4CSpwkYctA4LWa1
DZakh
changed the title
Drop internal vocabulary (backpressure, buffer, query-time clock) and say what each metric is for: how to spot the bottleneck and where to look next when a rate is high. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01TCWAgbg4CSpwkYctA4LWa1
There was a problem hiding this comment.
Actionable comments posted: 1
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@scenarios/test_codegen/test/IndexerStateStall_test.res`:
- Around line 25-30: Strengthen the test around IndexerState.beginReorg by
adding a delay after markProcessingStalledOnFetch and before beginReorg, then
assert that settledOnReorg is positive. Retain the existing later equality
assertion so rollback time remains excluded.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro
Run ID: 27cb8fff-bdc5-4bf1-acf9-e1977e77d577
📒 Files selected for processing (3)
packages/envio-tests/test/lib_tests/Metrics_test.respackages/envio/src/Metrics.resscenarios/test_codegen/test/IndexerStateStall_test.res
🚧 Files skipped from review as they are similar to previous changes (2)
- packages/envio/src/Metrics.res
- packages/envio-tests/test/lib_tests/Metrics_test.res
- Derive envio_process_elapsed_seconds from a monotonic reference taken at startup instead of subtracting two wall-clock Dates. An NTP correction could otherwise skew, or invert, the denominator used to divide the Performance-based counters. - Settle an open fetch stall in stop and errorExit, so the counter freezes at shutdown rather than growing for as long as the process serves metrics. - Time only the over-limit path in awaitCapacity. Timing every call charged each batch the microtask hop of awaiting an already-resolved promise, reading as storage backpressure that wasn't there. - Wait before beginReorg in the reorg test, so it distinguishes settling the interval from discarding it. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01TCWAgbg4CSpwkYctA4LWa1
…s-yjmhos' into claude/indexer-bottleneck-metrics-yjmhos
2 participants
Summary
The existing utilisation metrics (
envio_storage_load_seconds,envio_processing_seconds,envio_preload_seconds, …) show which stage is busy, but not which one everything else is waiting on. In a pipeline where fetching runs concurrently with processing and writes happen off the processing path, busy-time alone can't identify the bottleneck.This adds the missing wait-side accounting, plus the time gauges needed to read a scrape without a query-time clock.
New metrics
Stall counters — attribute processing idle time to its cause:
envio_processing_stalled_on_fetch_secondsenvio_processing_stalled_on_storage_write_secondsWriting.awaitCapacity)The write stall closes a real blind spot:
awaitCapacitypreviously ran before any timer started, so when Postgres writes were the constraint, every panel went down and nothing went up.Together with the existing counters, the processing side now accounts for its own wall clock —
preload + processing + stalled_on_fetch + stalled_on_storage_writecovers busy and both wait causes, so one stacked panel points at the constraint.Process time gauges — rendered at the top of the payload, so a single scrape is self-describing:
envio_process_start_time_secondsenvio_process_metric_time_secondsenvio_process_elapsed_secondselapsedmakes counter shares readable straight off one payload, with norate()and no external clock — e.g.envio_processing_stalled_on_storage_write_seconds / envio_process_elapsed_secondsis the fraction of the run spent stalled on writes.metric_timedates a saved scrape.Implementation notes
beginProcessing.toMetricsadds the in-progress interval so a scrape mid-stall isn't stale, matching the existingSourceManagerstatus pattern. The counter stays monotonic across a stall.ChainState.isFetchingAtHead(which accounts forblockLagandendBlockrather than a raw buffer-equals-height check). Without this the counter climbed while simply idling at the tip, where nothing is bottlenecked.beginReorgcloses any open stall interval. Otherwise an interval opened before a reorg stayed open across the rollback and was folded into the stall on the nextbeginProcessing— double-counting timeenvio_rollback_secondsalready owns. Reachable on multichain indexers where one chain backfills while another reorgs at head.Caveat worth knowing
stalled_on_fetchalso accrues briefly at startup, before the first height query returns (knownHeight === 0). The at-head gate covers the steady-state tip case. The metric is named "stalled" rather than "bottlenecked" for this reason, and the help text points atenvio_indexing_source_waiting_secondsfor disambiguation.Tests
Metrics_test.res: the golden snapshot covers all five new metrics with explicit values.IndexerStateStall_test.res(new): covers the two invariants the counter depends on — a repeated mark must not restart an open interval, andbeginReorgmust settle it. Drives a realIndexerStateviaMockIndexer.InMemoryStore.makeand reads the counter throughtoMetrics.The reorg test is a genuine regression test, not just a passing assertion: reverting the
beginReorgsettle makes it fail with the full simulated rollback span attributed toenvio_processing_stalled_on_fetch_seconds(expected 0.0502 to be 0.00004).Not included
envio_indexing_buffer_size / envio_indexing_target_buffer_size,envio_indexing_idle_seconds,envio_effect_queue_wait_seconds,nodejs_eventloop_utilization) — no code change needed for those.timestampCaughtUpToHeadOrEndblockexposed as a gauge.🤖 Generated with Claude Code
https://claude.ai/code/session_01TCWAgbg4CSpwkYctA4LWa1
Summary by CodeRabbit
New Features
Bug Fixes