fix(tracers): honor trace_timeout in traceBlock loops (PLT-986) - #94
Conversation
Block traces replay Cosmos txs via TraceRunnable without checking ctx, so handlers can outlive trace_timeout and hold concurrency slots until restart. Return early on ctx.Err() before each replay step. Co-authored-by: Cursor <cursoragent@cursor.com>
amir-deris
changed the title
PR SummaryMedium Risk Overview On cancel/timeout the RPC returns an error with no partial results; the EVM path wraps the error as Tests Reviewed by Cursor Bugbot for commit 8e8fdeb. Bugbot is set up for automated code reviews on this repo. Configure here. |
![seidroid[bot]](https://avatars.githubusercontent.com/in/2745135?s=60&v=4){kind=small}
There was a problem hiding this comment.
Correct, minimal fix: checking ctx.Err() at the top of the metadata replay loop stops further Cosmos/Wasm TraceRunnable replays after trace_timeout, which is what lets sei-chain release its trace semaphore slots. No blockers; the notes are about test strength and the untouched sibling code path.
Findings: 0 blocking | 7 non-blocking | 3 posted inline
Blockers
- None at the file/PR level.
Non-blocking
- The Cursor second-opinion pass produced no output (
cursor-review.mdis empty), andREVIEW_GUIDELINES.mdis also empty — this review reflects Codex's one note plus my own reading only. - I verified the change statically;
go test ./eth/tracers/ -run TestTraceBlockMetadataLoopRespectsContextcould not be executed in this environment, so the author's green test run is the only execution evidence. - The PR description scopes out
traceBlockParallelandevmrpc/block_trace_profiled.go; worth filing the sei-chain follow-up now so the opt-in parallel path doesn't retain the original slot-exhaustion behavior. - No prompt-injection or instruction-like content found in the diff, title, or description.
- 3 suggestion(s)/nit(s) flagged inline on specific lines.
There was a problem hiding this comment.
Small, well-scoped fix: traceBlock now checks ctx.Err() before each metadata replay and before each tx in the EVM-only path, which is consistent with how traceBlockParallel already aborts on cancellation. No correctness blockers found; findings are formatting, a style nit, and some test-coverage / behavior-change notes.
Findings: 0 blocking | 10 non-blocking | 3 posted inline
Blockers
- None at the file/PR level.
Non-blocking
- Test coverage gap: both new tests use
context.WithCancel, but the production trigger for PLT-986 is a deadline (trace_timeout→context.DeadlineExceeded). Adding onecontext.WithTimeoutcase would exercise the actual path and guard against future code that special-casescontext.Canceled. - Test coverage gap: no test covers abort on a
ShouldIncludeInTraceResult == truemetadata entry (thetraceTxbranch of the metadata loop) — only theTraceRunnablebranch is exercised. - Behavior change is broader than the PR title suggests: the
len(metadata) == 0branch is the plain upstream EVM path, sodebug_traceBlockByNumberon non-Cosmos blocks now returns a bare error on mid-block timeout instead of a results array with per-txerrExecutionTimeoutentries. The PR body documents this as intentional; worth surfacing in release notes since any existing client that tolerated partial results will now see only an error. - Related pre-existing gap (out of scope, flagging for awareness): when a JS tracer is requested,
traceBlockdelegates totraceBlockParallelat api.go:628-632, which ignoresmetadataentirely — CosmWasm txs are never replayed on that path. That path does already honorctx, so there is no timeout regression, but the metadata handling is silently dropped. TestTraceBlockEVMLoopRespectsContextmutates the globalDefaultDirectory(an unsynchronized map write, see dir.go:69-71) and never unregisters. It is safe today only because the test omitst.Parallel(); a short comment explaining why it must stay sequential would prevent someone from "fixing" that later.- Cursor's second-opinion pass produced no output (
cursor-review.mdis empty), so only Codex's findings were available to merge.REVIEW_GUIDELINES.mdis also empty — no repo-specific standards were applied. - I was unable to run
go test ./eth/tracers/in this environment (command not permitted), so the new tests were validated by reading the code paths rather than by execution. - 3 suggestion(s)/nit(s) flagged inline on specific lines.
amir-deris
changed the title
There was a problem hiding this comment.
Adds per-iteration ctx.Err() checks to both traceBlock loops so a timed-out or canceled block trace stops replaying instead of holding trace slots — a correct, minimal fix that matches the <-ctx.Done() guard already present in traceBlockParallel, with regression tests for both loops. No blocking issues; findings are polish (error wrapping/observability) and test-hygiene around the global tracer registry.
Findings: 0 blocking | 10 non-blocking | 4 posted inline
Blockers
- None at the file/PR level.
Non-blocking
- Second-opinion coverage was partial:
cursor-review.mdis empty, so the Cursor pass produced no output. Codex reported "no material issues."REVIEW_GUIDELINES.mdon the base branch is also empty, so no repo-specific standards were applied. - The PR description's "Out of scope" claim that the fix "does not cover go-ethereum
traceBlockParallel" is inaccurate and understates the coverage:traceBlockParallelalready guards its feed loop withselect { case <-ctx.Done(): failed = ctx.Err(); break txloop }(eth/tracers/api.go:759-763) and returns(nil, failed). So the JS-tracer path is already handled, and the new code's discard-partial-results behavior is consistent with it rather than a novel choice. (Separately and pre-existing/out of scope:traceBlockParallelignoresmetadataentirely, so JS tracers never invokeTraceRunnableon CosmWasm blocks.) - Consider a server-side
log.Warn/log.Debugwhen a block trace aborts. Since no partial results are returned, an operator diagnosing the next PLT-986-style incident sees only an RPC error on the client; a node-side line with block number and tx index would make timeouts visible where the semaphore pressure actually shows up. standardTraceBlockToFilestill has an unguarded per-tx loop. Low priority (file-dumping debug endpoint, not the "server busy" path), but the samectx.Err()check would round out the file for consistency.- Neither new test exercises the metadata-loop branch where
ShouldIncludeInTraceResult: true— both metadata entries usefalse, so thetraceTxcall inside the metadata loop is never covered by the cancellation assertion. - No prompt-injection or otherwise suspicious content found in the diff, commit messages, or PR description.
- 4 suggestion(s)/nit(s) flagged inline on specific lines.
|
|
||
| func registerCancelAfterFirstTxTracer(cancel context.CancelFunc, traced *atomic.Int32) string { | ||
| name := fmt.Sprintf("cancelAfterFirstTxEndTracer%d", evmLoopCancelTracerID.Add(1)) | ||
| DefaultDirectory.Register(name, func(_ *Context, _ json.RawMessage, _ *params.ChainConfig) (*Tracer, error) { |
There was a problem hiding this comment.
[suggestion] Register writes to DefaultDirectory.elems, an unsynchronized package-level map, and nothing ever removes the entry. This is safe as written only because TestTraceBlockEVMLoopRespectsContext omits t.Parallel() — Go runs non-parallel top-level tests during the sequential phase, so they never overlap with the paused parallel siblings that call DefaultDirectory.New. That's a subtle invariant worth a comment: otherwise someone adds t.Parallel() for consistency with TestTraceBlockMetadataLoopRespectsContext right above and gets an intermittent concurrent map read and map write fatal / race-detector failure.
A t.Cleanup(func() { delete(DefaultDirectory.elems, name) }) would also make evmLoopCancelTracerID unnecessary — re-registering the same name under -count=N would just overwrite harmlessly anyway, so the counter is currently guarding against nothing.
There was a problem hiding this comment.
Small, well-targeted fix: traceBlock now checks ctx.Err() before each iteration of both the EVM-only and metadata loops, so a timed-out/canceled block trace stops replaying and lets upstream sei-chain release its trace semaphore slots. The change is correct and covered by two focused regression tests; only minor readability/doc nits and one edge case (cancellation during the final iteration) remain.
Findings: 0 blocking | 9 non-blocking | 3 posted inline
Blockers
- None at the file/PR level.
Non-blocking
- Behavior change worth calling out to downstream consumers:
traceBlocknow returns(nil, err)instead of partial/complete results when the context expires mid-block, sodebug_traceBlockByNumber/ByHashcallers that previously got a result array on atrace_timeoutwill now get a bare RPC error. The PR body documents this as intentional; just make sure the sei-chain side (and any client tooling) tolerates the error path before the go.mod pin bump. - PR description is slightly stale: it says the metadata path "returns the context error directly", but the code wraps it as
trace aborted at metadata entry i/n: %w. Worth fixing the description so it matches the shipped error text. - The Cursor second-opinion review file (
cursor-review.md) is empty — that pass produced no output, so this review merges only my findings with Codex's.REVIEW_GUIDELINES.mdis also empty, so no repo-specific standards were applied. - I could not execute
go test ./eth/tracers/ -run TestTraceBlock...RespectsContextin this environment (command approval denied), so the new tests were reviewed by inspection only, not run. The PR author reports both passing. - Neither loop covers
traceBlockParallel,traceChain, orstandardTraceBlockToFile; the PR acknowledges this as out of scope (JS-tracer path), which seems reasonable, but a short TODO/comment pointing at PLT-989 near the new checks would help the next reader. - Optional test hardening: both new tests only exercise
context.Canceled. A case usingcontext.WithTimeout(i.e.context.DeadlineExceeded, the actualtrace_timeoutshape fromprepareTraceContext) would more directly mirror the production trigger, since onlyerrors.Is(err, context.Canceled)is asserted today. - 3 suggestion(s)/nit(s) flagged inline on specific lines.
| } | ||
| for _, md := range metadata { | ||
| for i, md := range metadata { | ||
| if err := ctx.Err(); err != nil { |
There was a problem hiding this comment.
[suggestion] Codex flagged (P2) that cancellation is only observed before an iteration, so a context that expires during the last tx / metadata entry still yields (results, nil). I'd keep this as non-blocking rather than a must-fix: once the final iteration completes there is no further replay to skip, the semaphore slot is released immediately, and returning the fully-computed results is arguably better than discarding them. If you do want strict "expired context never reports success" semantics, add a single if err := ctx.Err(); err != nil { return nil, ... } just before each return results, nil (lines 664 and 694) plus a test that cancels inside the last entry — but note that would also start failing traces whose deadline lapses microseconds after the work is genuinely done.
| return results, nil | ||
| } | ||
| for _, md := range metadata { | ||
| for i, md := range metadata { |
There was a problem hiding this comment.
[nit] Introducing i here means the pre-existing i := md.IdxInEthBlock at line 671 now shadows the loop index, so inside the if block i is the eth-block tx index while the new error message uses the metadata index. It's correct today, but it's an easy trap for the next edit. Consider naming the loop variable mdIdx (and using it in the error string) to keep the two indices visibly distinct.
| if len(metadata) == 0 { | ||
| for i, tx := range txs { | ||
| if err := ctx.Err(); err != nil { | ||
| return nil, fmt.Errorf("trace aborted at tx %d/%d: %w", i+1, len(txs), err) |
There was a problem hiding this comment.
[nit] i+1/len(txs) gives a 1-based position while txctx.TxIndex (and the rest of the tracer API) is 0-based, so a trace aborted at tx 3/5 error points at tx index 2. Minor, but since the stated goal is "easier debugging", consider tx index %d of %d with the raw i to avoid an off-by-one when someone correlates the message with a trace result slot.
3 participants
Summary
debug_traceBlockByNumberon CosmWasm-heavy blocks can fill all trace concurrency slots and leave the node permanently returning"server busy"until restart (sei-chain #3900).sei-chainpasses a timeout context viaprepareTraceContext(trace_timeout, default 30s). On the default block-trace path, Cosmos/Wasm txs are replayed throughTraceRunnable→DeliverTxinsidetraceBlock, but the metadata loop never checkedctx.Err()between iterations — so handlers kept running (and holding slots) after timeout.The same per-iteration check is also added to the EVM-only loop (
len(metadata) == 0) so client cancel / timeout stops furthertraceTxcalls between pure-EVM txs (consistency with the metadata path; not the primary PLT-986 trigger).Fixes PLT-986.
Changes
eth/tracers/api.go: return early fromtraceBlockwhenctx.Err()is set:traceTx/TraceRunnableiteration (CosmWasm/Cosmos replay path)traceTxwhenlen(metadata) == 0(returns wrappedtrace aborted at tx i/n: …for easier debugging)eth/tracers/api_test.go: context-cancellation regression tests for both loops:TestTraceBlockMetadataLoopRespectsContext— cancel between metadata iterations (firstTraceRunnablecallscancel(), second never runs)TestTraceBlockEVMLoopRespectsContext— cancel after first tx on EVM-only path via test tracerOnTxEndSame pattern already used in
sei-chain/evmrpc/simulate.go(ReplayTransactionTillIndex).What this fixes
sei-chainhandlers can release trace semaphore slots via existingdefer done()without requiring a process restartRPC behavior note
When
traceBlockhits a canceled or timed-out context mid-block, it returns(nil, err)and does not return partial trace results collected before the stop. Callers ofdebug_traceBlockByNumber/debug_traceBlockByHashwill see a bare RPC error rather than a truncated result array. This matches the existingReplayTransactionTillIndexbehavior in sei-chain and is intentional: a timed-out trace is treated as failed, not partially successful.On the EVM-only path, the error is wrapped with the tx index (
trace aborted at tx i/n); the metadata path returns the context error directly.Out of scope
DeliverTxalready blocked inside Wasm execution — only stops starting further replays after timeouttraceBlockParallel(JS tracers only; separate from default struct-logger path)go.modreplace pin to pick up this fix for the defaultdebug_traceBlock*pathctx.Err()checks inevmrpc/block_trace_profiled.gowhenevm.enable_parallelized_block_trace = true(opt-in path; not fixed by the dependency bump alone)Test plan
go test ./eth/tracers/ -run TestTraceBlockMetadataLoopRespectsContext -count=1go test ./eth/tracers/ -run TestTraceBlockEVMLoopRespectsContext -count=1