Repository navigation
test: validate state transition with leanSpec fixtures - #17
Merged
Merged
Conversation
MegaRedHand
marked this pull request as ready for review
January 13, 2026 14:34
tcoratger
pushed a commit
to tcoratger/ethlambda
that referenced
this pull request
Oct 30, 2026
lambdaclass#17) * feat(blockchain): time a block's import end to end and log the breakdown A block that misses the interval its chain expects attestations at is the symptom; which part of the import spent the time is the question, and until now nothing could answer it. `store::on_block` logged three durations, the mailbox hop between the p2p actor and the chain actor was invisible, and so were `update_head`, the engine round trip, the per-table size estimates every import pays for, and every hold. Instants are captured where a boundary is crossed and returned up the stack; nothing subtracts anything until `BlockImportReport`, which is the sole consumer. That is what lets one report serve both chains: a section that never ran leaves its pair `None` and is simply not printed, so a lean block shows no beacon rows and a beacon block shows no `verify_*`. The three holds carry `_start`/`_end` pairs rather than single instants because a held block does not walk the timeline once, it loops: guards run again for a block held for its parent, the availability check runs again for one held for its columns, and a single instant per boundary would let the second pass overwrite the first and the wait disappear into whichever section straddled it. `held_timings`, taken on release and removed by `discard_pending_subtree`, is what carries a block's original arrival across a hold so its end-to-end time still starts where it really started. `da_complete_on_arrival` is asked before the parent check, which is the only moment it is answerable. Without it an absent `columns_wait` row reads two ways at once: the columns were never missing, or they landed while the block was held for its parent. With it the two are distinguishable, which is the point of separating the parent wait from the availability wait at all. `BlockArrival` rides on `NewBlock` rather than the timings themselves, so `ethlambda-network-api` keeps knowing nothing about the import path that depends on it. The two timing logs `store.rs` already emitted move to debug rather than being deleted: the tree carries the same numbers, and the paths that print no tree (the Hive driver's verify endpoint, the spec-test runner) still have something to turn on. No metrics yet. * feat(metrics): publish a block's import sections as one histogram `lean_fork_choice_block_processing_time_seconds` starts inside `store::on_block`, so everything the previous commit made visible in the log was still invisible to a dashboard: the mailbox hop, the holds, the head update, the engine round trips, and the per-table size estimates every import pays for. One histogram carries all of it, sections and totals alike. They share a unit and a bucket set, and the query these exist for is `rate(..._sum[5m])`, seconds spent per second, which does not divide by an event count and so does not care that some sections are counted per block and others per arrival. Splitting them into separate metrics bought nothing that a `phase` label does not already give, and cost four more families to document, register and keep in step. `lean_block_import_cascade_blocks` is there for when the two counts do need relating, and because the distribution is the part the ratio of two `_count`s cannot give: a mean of 1.2 is a steady 1.2 or a constant 1 with rare bursts of 40, and those are different problems. `total` is written only when the block actually imported. A held block has no total, because its import has not finished, and publishing the span from the wire to wherever it stopped as one would put a two-slot parent wait into the import-cost percentiles. That is what an `outcome` label would have had to exist to filter back out, so there is no `outcome` label. `source` has two values. `Deferred` is not one of them: it says how a block reached the actor this time, not how it reached the node, and a deferred block is a gossip or sync block that waited. Labelling it separately would take it out of the population it belongs to for every section it has left to cross, while duplicating a fact the `defer` section already carries. `BlockArrival` therefore carries the source across the hold, and the handler resolves it before any timing is built. A block this node built itself is not measured at all: it crossed no wire, so its `decode` and `queue` sections are zeroes taken when the import began, and either wire source's percentiles would be understated by them. Both still appear in the log, which has a name for every case because a line costs nothing to write. Series are left to appear as blocks arrive rather than being seeded: a third of the phases are beacon-only, and a lean node can never write to them. A test asserts the tree's sections and the metric's per-block `phase` labels are the same list in the same order, so a section added to one without the other fails the build rather than logging something no dashboard can find. * fix(blockchain): stop charging a hold to the guards section as well `process_or_pend_block` marked `guards_start` with `.or_else`, so a block released from a parent hold kept the start its first pass had taken while `guards_end` was marked on the final pass. The section then spanned the whole wait: a block held eight seconds for its parent printed `parent_wait` of eight seconds and `guards` of eight seconds, and the tree's percentages summed past a hundred. Each pass now marks its own start, which is what the field always meant. Keeping the first mark had a reason, though not a good one: the mailbox handler had already taken it, and overwriting it would have dropped everything the handler does on a block's behalf before the import path sees it. That work is real and occasionally large, since it includes the store-clock catch-up, which can run a whole tick. So it becomes its own `admit` section rather than the head of the first pass's guards, and the guards section goes back to meaning one pass's checks. The regression test asserts what the defect violated: a held block's sections must not sum past its end-to-end span. * refactor(blockchain): drop three import sections that never moved `events`, `evict` and `metrics` each took under a millisecond in all 5248 imports a mainnet follower measured, so they were three rows that never moved in every tree printed and three label values on the phase histogram that never said anything. The work they covered still happens and is still counted, just charged to the section it follows rather than to one of its own: `absorb_tail` moves the end of whichever section ran last, which is `fc_head` on lean and `block_atts` on beacon. Extending the last section rather than the first keeps the rows contiguous, so the tree still sums to end-to-end. * fix(blockchain): scope the decode section to the path that decodes Only gossip decodes a block itself. The req/resp codec has already turned the bytes into a block before any handler sees one, so that path had no decode boundary left to take and reported a zero instead: `BlockArrival` stamped `wire` and `decoded` at the same instant after the fact. A zero is worse than nothing here, because it reads as free work rather than as unmeasured work and drags the decode histogram down with samples that measured nothing. `BlockArrival` now carries `decode_start: Option<Instant>` beside the hand-off, `None` saying the producer did not decode the block, and a fetched block's first section is `queue`. End to end therefore no longer starts at `decode_start`, which not every block has, but at `first_instant`, which falls back to the hand-off. The consequence to keep in mind when reading the numbers is that a gossip block's total and a fetched block's total no longer start at the same point in the block's life, and a fetched one's excludes the request round trip entirely; both are written down. * refactor(blockchain): drop a guards mark nothing could read `process_and_publish_block` is lean's locally-built path and calls `process_block` directly, bypassing `process_or_pend_block`, which is the only place `guards_start` is ever set. So this wrote an end whose start was always `None`, and `Row::new` yields no elapsed unless it has both, so the row never reached the tree or the histogram either way. Removing it also drops the `mut`, leaving the timings built and handed over in one expression.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
No description provided.