Skip to content

Streaming book-diff writer intermittently stalls across the UTC day rollover (00:00) #154

Description

@Mr-Moonsilver

Summary

When run with --write-raw-book-diffs, the node's streaming per-hour book-diff
writer occasionally goes silent starting shortly after 00:00 UTC and does not
resume until at or just before the next hour rotation (01:00), at which point
the new file appears already containing only the tail of the buffered writes.
This is intermittent (2 of 4 observed midnights hit) and produces no error,
warning, or log line of any kind — it is silent on both the node's own journal
and at the OS level. Everything else about the node (chain sync, other capture
streams, the batch/bronze block pipeline) continues normally throughout.

Environment

  • Non-validator node (run-non-validator), mainnet.
  • Flags of interest: --write-raw-book-diffs (plus --write-fills,
    --write-misc-events, --write-order-statuses, --write-hip3-oracle-updates
    — all healthy throughout every incident).
  • Same binary build and same long-running process (no restart) across both a
    clean night and a hit night in one case — rules out a fresh-start or
    version-specific trigger.

Observed behavior (two independent incidents)

2026-07-01 (hit #1): the hour-00 file did not appear until ~00:59:05 (our
consumer's 0.5s-cadence directory scan found nothing newer for the entire hour;
the raw file was age-pruned before we could do direct post-hoc inspection of
it). Our consumer first read data spanning the final ~52s of the hour
(00:59:05–00:59:57).

2026-07-02 (hit #2): the prior hour's file received its final writes
normally (fully drained by our consumer by ~00:00:33), then went completely
silent. The hour-00 file was not created until 00:59:59.7, and direct
post-hoc inspection of it shows it contained only 1,808 rows across 170 coins
spanning 00:59:59.688–00:59:59.947 (~260ms) — i.e. genuinely no backlog in the
file, just the tail of whatever was sitting in a write buffer at the moment the
next hour's rotation forced a flush.

2026-06-30 and 2026-07-03 (clean, for contrast): normal continuous writing
straight across the boundary — e.g. on 07-03 the hour-23 file sealed at
00:00:00.000Z (5,150,401,307 bytes) and the hour-00 file was already
358,129,081 bytes and growing by 00:02:05, continuing at a normal ~250MB/min.

What we ruled out (and how)

  1. Not a process restart / redeploy. Same PID and same binary index served
    both a clean night (2026-06-30) and both hit nights — process freshness is
    not protective, and nothing changed at either the onset or recovery
    boundary of either incident.
  2. Not a full-node hang or crash. Chain sync, RPC, and every other
    streaming capture output (fills, misc-events, TWAP statuses, HIP-3 oracle
    updates) created their own hour-00 files on time on both hit nights,
    confirmed via filesystem birth-time (stat), not just log absence.
  3. Not a downstream/consumer artifact. Our consumer's continuous 0.5s
    directory scan (mtime-based newest-file selection) found no newer file to
    switch to for the entire stall hour — continuous indirect sampling — and
    post-hoc inspection of the Jul-02 hour-00 file confirms it was created at
    00:59:59.7 containing only the final ~260ms. Separately, lsof on the open
    file (same evening) showed the node process holding the fd directly with no
    intermediary process — this is not a shipping, transport, or ingestion-side
    effect.
  4. Not related to the batch/replay-based export path. The separate
    block-file batch pipeline that independently re-derives the same data was
    unaffected both nights — this is isolated to the streaming writer only.
  5. Silent at every observable layer. The node's own journal logged nothing
    writer-related at either incident (no restart, resubscribe, error, or
    buffer-warning lines) — only routine, unrelated per-midnight bookkeeping
    (an EVM-checkpoint prune) at 00:00:00.04 both nights.

Working hypothesis

Something in the streaming writer's day-rollover handling (new date directory
creation + opening the new hour's file) has an intermittent race. The two
different recovery shapes we observed (a large replay-like burst vs. a tiny
buffer-tail flush with no replay) suggest this may not be a single deterministic
bug but a class of related rollover-timing issues, possibly interacting with
how/when the writer's internal buffer gets flushed relative to the new file
being opened.

Questions for the node team

  1. Is this a known issue with the streaming raw-book-diff writer (or the
    day-rollover/file-rotation logic it shares with other writers)?
  2. Is there a way to detect this condition from inside the node process
    (e.g. an internal metric or log line we could opt into) rather than only
    externally via write-silence?
  3. Are there configuration knobs that affect buffer-flush timing around file
    rotation that might make this less likely?

Impact on our side (informational, not asking for a workaround)

Impact is confined to our live/streaming consumption band only — our durable
batch/bronze record is unaffected (see "ruled out" #4). We've deployed
detection (a write-silence watchdog that pages within ~6 minutes of onset) and
consumer-side exclusion windows around the affected minutes; we're not asking
for a workaround, just visibility into whether this is known/tracked.

Raw per-night evidence (byte counts, timestamps, lsof output) is attached as a
follow-up comment below.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions