Skip to content

feat(stats): never read a height older than the deadline it enforces - #77

Open
bdchatham wants to merge 2 commits into
brandon2/plt-1076-receipts-replace-hashesfrom
brandon2/plt-1077-read-within-deadline
Open

feat(stats): never read a height older than the deadline it enforces#77
bdchatham wants to merge 2 commits into
brandon2/plt-1076-receipts-replace-hashesfrom
brandon2/plt-1077-read-within-deadline

Conversation

@bdchatham

Copy link
Copy Markdown
Contributor

TOT-023. Fourth in the outcome-tracking stack.

A transaction past reapAfter counts as expired whatever a later block says. Reading that block answers a question the run has closed, and can only reopen a settled outcome.

What changes

Each height's read gets what is left of its own deadline, capped by readTimeout. A height with nothing left costs no request at all.

func (t *InclusionTracker) readBudget(arrival time.Time) time.Duration {
	return min(readTimeout, time.Until(arrival.Add(t.reapAfter)))
}

Budgeting the remainder rather than a fresh window is the load-bearing choice. A window measured from now would let a read starting just inside the deadline finish outside it, so the oldest height the run ever asks for would be reapAfter + readTimeout. Measuring the remainder makes it exactly reapAfter, whatever readTimeout says — which matters because that bound is the retention floor under the tracking node, and it should not move with a constant this file happens to own.

It also drains a backlog instead of deepening one. A tracker falling behind gives each later head a smaller budget, and once a head has none left it costs no request, so the loop catches up rather than paying readTimeout per height forever.

readTimeout stops being the bound. Its own comment said it "should stay below the run's reap deadline" — true at the 30s default, false at --inclusion-reap-after=5s. An assumption a flag can break is not a bound.

A skipped height is recorded as a hole, not passed over. The run did not read it, so a transaction in flight across it is not evidence about the chain either way. The log records entering and leaving the state rather than every height inside it: at a sub-second block interval, one line per height would push the run summary out of any bounded log tail.

Test fixtures move off a fixed epoch

matchBlock now measures a head's age against the real clock, so a fixture stamping a head at time.Unix(1000, 0) is a head the tracker is decades behind on. Fixtures use headArrived() / sentAt() helpers that keep the same two-second latency gap. Tests that forced a reap with reapAfter = time.Nanosecond now age the entries directly, because reapAfter is also the read deadline and a one-nanosecond tracker reads nothing.

Assertions are unchanged.

Checked

Three new tests, each broken on purpose first:

mutation caught by
budget ignores head age, so stale heights get read TestAHeightPastTheDeadlineIsNotRead
past-deadline height is read anyway TestAHeightPastTheDeadlineIsNotRead
read unbounded by a tight reapAfter TestATightReapDeadlineBoundsTheRead

gofmt, go vet, full suite clean.

TOT-023. A transaction past reapAfter counts as expired whatever a later
block says, so reading that block answers a question the run has closed and
can only reopen a settled outcome.

Each height's read now gets what is left of its own deadline, capped by
readTimeout, and a height with nothing left costs no request. Budgeting the
remainder rather than a fresh window is what makes the oldest height the run
ever asks for exactly reapAfter: a window measured from now would let a read
starting just inside the deadline finish outside it, and the retention floor
this puts under the tracking node would then move with a constant this file
owns.

It also drains a backlog instead of deepening one. A tracker falling behind
gives each later head a smaller budget, and once a head has none left it
costs no request at all.

readTimeout stops being the bound. Its own comment said it "should stay below
the run's reap deadline", which held at the 30s default and not at
--inclusion-reap-after=5s. An assumption a flag can break is not a bound.

Test fixtures move off a fixed Unix second, because matchBlock now measures a
head's age against the real clock and a head stamped in 1970 is one the
tracker is decades behind on.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@cursor

cursor Bot commented Aug 29, 2026

Copy link
Copy Markdown

PR Summary

Medium Risk
Changes when blocks are read and how lagging trackers attribute outcomes (holes / status_unavailable vs expired), which affects load-test metrics and operator signals; scope is confined to stats inclusion tracking with broad test updates.

Overview
Implements TOT-023 so the inclusion tracker does not fetch receipts for heads that are already older than reapAfter—those txs have reaped, and a late read could only disturb settled outcomes or pull unnecessary history from the node.

readBudget(arrival) sets each height’s read timeout to the remaining time until arrival + reapAfter, capped by readTimeout. If the budget is below minReadBudget, matchBlock calls skipPastDeadline: no RPC, increment blindHeights, metric label past_deadline, and a one-time warning log until the tracker catches up again.

readReceipts now takes that budget instead of always using readTimeout, so a short --inclusion-reap-after actually limits reads and backlog drains (shrinking budgets, then zero-cost skips) instead of paying 10s per stale height.

Tests switch from fixed Unix timestamps to headArrived() / sentAt() (real clock) and use expireInflight where instant reap used to rely on reapAfter = 1ns, since reapAfter is now also the read deadline. Three new tests lock skip behavior, remainder budgeting, and tight reap vs readTimeout.

Reviewed by Cursor Bugbot for commit ea335a6. Bugbot is set up for automated code reviews on this repo. Configure here.

@bdchatham

Copy link
Copy Markdown
Contributor Author

@seidroid review

readTimeout stopped being the bound in the commit before this one.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@bdchatham

Copy link
Copy Markdown
Contributor Author

Note on a failure mode this change introduces, and where it is closed.

A run that falls chronically behind now skips every height, so every transaction reports status_unavailable and the run exits 0 having said nothing about the chain. That is honest but quiet: the only signals are the transition log line and inclusion_block_fetch_errors{reason="past_deadline"}.

#78, the next PR in this stack, closes it. Its report fires a warning on exactly that shape:

WARNING: this run read no execution status. It cannot say what the chain
did with any of these transactions. The committed and reverted counts below
read 0 because nothing was read, NOT because nothing committed or reverted.

The predicate is Tracked && Committed == 0 && Reverted == 0 && StatusUnavailable > 0. The last clause matters: without it a run whose transactions all expired would take the same banner, and that run read every block and saw nothing, which is a claim it is entitled to make.

Two smaller ones I accepted rather than coded around:

minReadBudget (25ms) tightens the bound to reapAfter - 25ms, which is tighter than a MUST NOT requires, so it is safe. Worth knowing if anyone computes the retention floor to the millisecond.

pastDeadline is edge-triggered on a single bool, so a tracker oscillating around the boundary logs a pair of lines per oscillation. Bounded by the block rate, and far below the per-height rate it replaces.

One-way door worth flagging: reason="past_deadline" is a new label value on inclusion_block_fetch_errors. Anything enumerating that label needs to know.

Verified with -race at -count=1: clean.

@seidroid seidroid Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Budgeting each height's read from the remainder of its own reap deadline is well-reasoned and correctly implemented, and the fixture move off a fixed epoch is the right call. The findings are non-blocking: four tests that kept a time.Nanosecond reapAfter now take the new skip path and no longer exercise what they name, one test sits 5ms above minReadBudget, and pastDeadline is not cleared on the read-error path.

Findings: 0 blocking | 4 non-blocking | 3 posted inline

Blockers

  • None at the file/PR level.

Non-blocking

  • [suggestion] --inclusion-reap-after has no lower-bound validation (main.go:58, config/settings.go). Before this PR a small value only shortened the reap window; now it also caps every read budget, so any value at or below minReadBudget (25ms) makes matchBlock skip every height, issue zero receipt requests, and report the whole run as status_unavailable with no error. Worth rejecting or warning on InclusionReapAfter <= minReadBudget at startup — this is the same class of flag-breakable assumption the PR removed from readTimeout.
  • 3 suggestion(s)/nit(s) flagged inline on specific lines.

Comment thread stats/inclusion_outcome_test.go
Comment thread stats/inclusion_outcome_test.go
Comment thread stats/inclusion_tracker.go

@seidroid seidroid Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Budgeting each height's read from the remainder of its own reap deadline is sound and correctly implemented, and moving fixtures off a fixed epoch is the right consequence. No commits have landed since the previous review, so all four earlier non-blocking findings — four tests whose named cause is now short-circuited by the skip path, one test with 5ms of slack above minReadBudget, and pastDeadline not cleared on the read-error path — are still present and re-raised.

Findings: 0 blocking | 4 non-blocking | 3 posted inline

Blockers

  • None at the file/PR level.

Non-blocking

  • [suggestion] --inclusion-reap-after has no lower-bound validation (main.go:58, config/settings.go:101). NewInclusionTracker floors only non-positive values (stats/inclusion_tracker.go:231), so any value in (0, 25ms] now makes readBudget fall under minReadBudget for every head: matchBlock skips all heights, the run issues zero receipt requests, and every transaction reports status_unavailable with no error surfaced. Before this PR a small value only shortened the reap window. Rejecting or warning on InclusionReapAfter <= minReadBudget at startup would close the same class of flag-breakable assumption the PR just removed from readTimeout. (Re-raised: unchanged since the previous review.)
  • 3 suggestion(s)/nit(s) flagged inline on specific lines.


src.SetFetchErr(errors.New("connection refused"))
tr.matchBlock(context.Background(), 9, 0, time.Unix(1002, 0))
tr.matchBlock(context.Background(), 9, 0, headArrived())

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[suggestion] Still unresolved — no commit has landed since this was first raised, and I re-verified it against the current tree.

This test is vacuous. newTestTracker(t, time.Nanosecond, ...) on line 165 makes readBudget(headArrived()) negative, so matchBlock takes the new skipPastDeadline branch at inclusion_tracker.go:582 and returns before touching the source — src.SetFetchErr is never consumed and FetchCount() stays 0. The StatusUnavailable == 1 assertion is satisfied by the skip's blindHeights++, not by the unreadable-block path the test name and its TOT-004/TOT-020/SC-011 tags claim to guard. Mutating recordBlindFetch would no longer fail it.

The PR already applied the fix for this exact pattern elsewhere (TestAnIdleBlockIsNotAHole, TestAPartlyNullReadMatchesWhatArrivedAndCountsTheRest, TestExpiredIsReachableInTheRecommendedTopology, TestInclusion_ReapVsLateInclusion); the same treatment applies here — time.Minute plus expireInflight(t, tr) before the reap.

Three more time.Nanosecond trackers reach matchBlock/processHead and lose their intended cause the same way:

  • line 243 TestTransactionsRegisteredAfterTheHoleStillExpire — the hole is now a skip, not a failed fetch
  • lines 470 and 700 (TestASkippedHeadIsCountedAsAHole, TestASingleMissedHeadIsCountedAsAHole) — the first processHead already skips and poisons blindHeights, so the assertion holds even if recordBlindGap were deleted, which is the one thing those tests exist to catch

The fetch-error path itself stays covered by TestAnErrorThatWillNotChangeCostsOneRequest and TestARetryGivesUpAndBecomesAHole, so this is lost coverage rather than none.


src.SetReceipts(5, receipts...)
tr.matchBlock(ctx, 5, 0, time.Unix(1002, 0))
tr.matchBlock(ctx, 5, 0, headArrived())

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[suggestion] Still unresolved — line 296 is unchanged at 30*time.Millisecond.

TestOutcomesPartitionEveryAcceptedTx builds its tracker with reapAfter = 30*time.Millisecond, only 5ms above minReadBudget (notFoundBackoff = 25ms, inclusion_tracker.go:916). headArrived() is evaluated at the call site, so readBudget sees 30ms - ε; any scheduling or GC delay above 5ms between the two flips the branch and matchBlock skips the read entirely, leaving the six receipts unmatched and breaking the Committed/Reverted assertions below. That was harmless before this PR because reapAfter did not bound reads at all — it does now, and 5ms of slack is thin under -race on a loaded CI runner. Raising reapAfter here and forcing the reap with expireInflight, as the other converted tests do, removes the coupling.

s.firstReadAt = time.Now()
}
caughtUp = s.pastDeadline
s.pastDeadline = false

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[suggestion] Still unresolved — the error path at line 599 is unchanged.

s.pastDeadline is only cleared on the successful-read path. If the tracker catches up but the next read fails, matchBlock returns at the recordBlindFetch branch (line 599) with the flag still set, so the "caught up ... heights are read again" line never prints and, more importantly, entered stays false on the next genuine relapse — the operator gets no warning for the second episode of the very state this flag exists to report. Clearing it alongside recordBlindFetch, or resetting it as soon as a height is read rather than after the read returns receipts, closes the gap. Attribution is unaffected (blindHeights carries that), so this is log fidelity only.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant