Skip to content

Move expected-behaviour warns/errors into per-slot counters so ERROR means urgent #542

Description

@0w3n-d

Status

The relay emits ~4.0M WARN/ERROR lines per day on mainnet, of which about
99.7% report ordinary behaviour driven by an external actor — a builder, a
proposer, a beacon node, a peer relay, or a client. An ERROR currently
carries no signal that anything needs attention, so nobody can watch the log,
and a real fault is invisible in the volume.

Measured on titan_relay.log.2026-08-30, relay-mainnet-1-aws-fr, using the
call-site counter in scripts/ (see Open questions). 39 of 205 call sites
account for all of it.

Eight tiles already have the structure this needs: report_slot_stats with a
per-slot SlotStats reset on transition, in the housekeeper, simulator,
bid decoder, bid sorter, auctioneer, top bid, data gatherer and block merging
tiles. The target state is that a quiet slot logs one stats line per tile and
nothing else, and every remaining WARN/ERROR means someone should look.

Two mechanical faults inflate the volume on top of the classification work:

#[tracing::instrument(..., err)] defaults to ERROR.
api/proposer/get_payload.rs:137 and :210 and
api/proposer/register.rs:39 use bare err, so every Err return becomes an
ERROR event with no message, ~11.6k/day. Every sibling handler already uses
err(level = tracing::Level::TRACE):
get_header.rs:102, header_stream.rs:42, get_execution_payload_bid.rs:27,
submit_signed_beacon_block.rs:22, submit_builder_preferences.rs:21. The
three outliers should match. This also double-logs: a past-slot request
produces both the warn!("request for past slot") at get_payload.rs:283 and
an ERROR from the instrument event.

Two log calls have no message at all.
api/builder/submit_block.rs:94 is tracing::error!(err = result.error_msg.as_str())
— 90,437/day with no builder pubkey, no block hash, no slot, and no message to
grep for. common/utils.rs:161 is error!("{message}").

Why now

Two real bugs (#537, #538) were invisible in this log for weeks because their
symptoms looked like every other line. Making the log quiet is what makes the
next one visible.

Behavior must not change

Only log levels, log sites and the contents of report_slot_stats lines
change. No control flow moves. Existing tests cover the behaviour around each
site; the new tests assert counter increments rather than log output.

Affected surface

crates/relay/src/api/, crates/relay/src/auctioneer/,
crates/relay/src/block_merging/, crates/relay/src/gossip/,
crates/relay/src/data_gatherer/, crates/common/src/beacon/,
crates/common/src/utils.rs, plus helix-gattaca src/provider.rs (separate
repo, tracked here for completeness).

Move to per-slot counters

Count/day Site Counter
2,286,112 block_merging/tile.rs:727 merging reject rejects_by_code; covered by #538
669,414 api/router.rs:146 request timed out timeouts_by_route
179,586 helix-gattaca provider.rs:278 missing Date-Milliseconds counter; most mev-boost clients never send it
90,437 api/builder/submit_block.rs:94 rejections_by_reason
11,603 get_payload.rs:137/:210 instrument events level fix, not a counter
7,515 helix-gattaca provider.rs:240 untagged user agent counter
4,474 get_payload.rs:283 request for past slot counter
3,581 gossip/mod.rs:49 error processing gossiped payload counter keyed by error
3,165 auctioneer/get_payload.rs:27 wrong slot counter; inherent gossip race
2,315 auctioneer/context.rs:372 already demoted counter
1,931 block_merging/tile.rs:621 builder disconnected counter; reconnect is already INFO
1,084 get_payload.rs:270 no slot proposer duty counter
792 common/beacon/beacon_client.rs:96 accepted but not processed counter; a duplicate-block 202 is normal with several relays
403 auctioneer/mod.rs:429 unknown parent hash counter
361 auctioneer/get_header.rs:42 no bids for this fork counter
257 get_header.rs:241/:244 didn't complete sleep/fetch counter; timing games working as intended
449 gossip/client.rs:97/:192 peer timeout, broadcast fail per-peer counter; WARN once per slot if a peer is down for a whole slot

Stays a real ERROR

Each of these means the relay is broken or lost money, and each is rare:

  • get_payload.rs:391 error publishing block; :448 beacon rejected block as invalid.
  • get_payload.rs:469 V1 response-safety buffer, withholding payload — a missed slot.
  • block_merging/tile.rs:739 merging fatal; :1152 merged block sim failed, which disables merging.
  • block_merging/tile.rs:345 merge builder unbundled an order.
  • The ring-overrun family, above a per-slot threshold (Ring buffer overruns silently drop submissions and sim results #539).
  • The panic hook at common/utils.rs:147.

Steps (each becomes one PR)

  • Step 1: Set err(level = tracing::Level::TRACE) on the three instrument outliers, and give submit_block.rs:94 a message plus builder pubkey, block hash and slot. Fix the respopnse typo at submit_block.rs:99 and drop that site to WARN. (tests: existing handler tests) (PR: )
  • Step 2: API surface — router.rs:146, submit_block.rs:94, get_payload.rs:270/:283, get_header.rs:241/:244. Add an API SlotStats with report_slot_stats, matching the existing tiles. (tests: counter tests) (PR: )
  • Step 3: Auctioneer — mod.rs:429, get_header.rs:42, get_payload.rs:27, context.rs:372. Fold into the existing auctioneer slot stats line. (tests: counter tests) (PR: )
  • Step 4: Gossip and peers — gossip/mod.rs:49, gossip/client.rs:97/:192, per peer. (tests: counter tests) (PR: )
  • Step 5: Beacon client and data gatherer — beacon_client.rs:96, and the S3 counter from S3 archive uploads fail ~58k/day with no retry #540. (tests: counter tests) (PR: )
  • Step 6: Block merging — tile.rs:621; the reject counter arrives with Relay forwards mergeable blocks for past slots and activates never-stored base blocks (2.23M rejects/day) #538 Step 3. (tests: counter tests) (PR: )
  • Step 7: Raise the matching changes against helix-gattaca for provider.rs:240/:278. (tests: that repo's own) (PR: )

Open questions

The call-site counter used for these measurements is a standalone script that
extracts every error!/warn! format string from the source and attributes
each production log line back to a file:line. It is not in the repo yet.
Should it live in scripts/? It made this analysis possible and would make
the follow-up measurable, but it needs one caveat documented: it cannot see
events generated by #[instrument(err)], since those have no format string in
the source.

Separately, the file logger keeps ANSI colour codes — init_tracing_log in
crates/common/src/utils.rs never calls .with_ansi(false) for the file
layer. Every line in the 12GB of retained logs carries escape sequences, and
grep ' ERROR ' does not match. Worth fixing here or in its own issue.

Activity

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    refactorRestructuring with no intended behavior change

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions