With --debug.logslowblock, xOneRS writes two JSON lines for a block: Block received when a peer sends or announces it, and Slow block when its import ends. Both carry the block hash and a wall-clock time in milliseconds. Join them on the hash, and you get the time from receive to the new head, and the time of each import phase. Both lines come from PR #1038, merged on 2026-11-15, which is not in the v0.1.0 release.

This post is the field guide. For the general log format see xOne log formats and reading an xOne node log.

Why were these lines added?

To find where the head-arrival time goes. A five-minute sample showed the xOneRS nodes report a new net2040 head a few tenths of a second later than geth-XDC on the same host (block arrival sample, issue #1015). The sample could not tell whether the time is spent before the block arrives, in verification, in execution or in the commit. These two lines split it.

The 30-minute side-by-side run against geth-XDC (steps 3 and 4 of #1015) has not been reported. Issue #1015 was closed on 2026-11-15 by PR #1128, which adds ops/bench/measure-head-lag.sh to sample local head flips against a peer RPC on the same host, with a checklist in docs/ops/head-lag.md. The PR does not report a new result. This post has no result table for that reason. It gives the method only.

How do I turn the lines on?

Start the node with --debug.logslowblock 0. The value is a Go duration: 0 logs every imported block, a value such as 500ms logs only blocks whose import took at least that long, and a negative value (the default, -1ns) is off (docs/cli/flags.md).

  • The receive line is written for any threshold that is set, so it comes with the phase lines and never alone.
  • Both lines go to stderr as JSON, whatever --log.format is set to.
  • With the switch off, neither line is written. The import path does not change.

What does the "Block received" line contain?

One line each time a peer sends a NewBlock message, and one line for each NewBlockHashes message (for its highest entry only, so the log stays bounded). The same hash can appear several times, from several peers. The first one is the receive time.

REFERENCE TABLEScroll to explore all columns →
Field Meaning
level debug
msg Block received
how NewBlock (the full block) or NewBlockHashes (an announcement)
block.number, block.hash The block
peer Short id of the peer that sent it
mono_ms Monotonic time since the chain service started. Not changed by a clock step
unix_ms Wall clock, milliseconds since 1970

What does the "Slow block" line contain?

One line for each imported block that reached the threshold (observe/slow.rs). The source names geth-XDC's slowBlockLog (level, msg, block, timing, throughput) as the model. The timing fields are xOne's own phases.

REFERENCE TABLEScroll to explore all columns →
Field Meaning
level, msg warn, Slow block
block number, hash, gas_used, tx_count
timing.verify_ms Header and QC verification
timing.senders_ms Waiting for sender recovery of the body
timing.execution_ms Transaction execution and the state root
timing.commit_ms The store commit: the insert time less verify, senders and execution
timing.history_ms History record, consensus rows, subscriptions and checkpoint start, after the commit
timing.total_ms Start of the import to the end
throughput.mgas_per_sec Gas used per second of total_ms
end_unix_ms Wall clock when the import ended. The head has moved by then

How do I join the two lines?

Group the lines by block.hash. Take the smallest unix_ms of the receive lines and the end_unix_ms of the phase line. The difference is receive-to-head. This jq program prints number, hash, first receive, receive-to-head (ms) and import total (ms):

xone --network net2040 --debug.logslowblock 0 2> node.err
jq -Rnr -f join.jq node.err

join.jq:

[inputs | fromjson? | select(.msg == "Block received" or .msg == "Slow block")]
| group_by(.block.hash)[]
| { number: .[0].block.number,
    hash: .[0].block.hash,
    first_rx: ([.[] | select(.msg == "Block received") | .unix_ms] | min),
    end: ([.[] | select(.msg == "Slow block") | .end_unix_ms] | max),
    total_ms: ([.[] | select(.msg == "Slow block") | .timing.total_ms] | max) }
| select(.first_rx != null and .end != null)
| [.number, .hash, .first_rx, .end - .first_rx, .total_ms] | @tsv

fromjson? skips lines that are not JSON, so text log lines in the same stream do no harm. A block that was fetched by sync and never announced has no receive line, and the select drops it.

How do I get the arrival delay?

The arrival delay is unix_ms of the first receive line less the block's timestamp (from eth_getBlockByNumber, in seconds). Two limits apply:

  • The block timestamp has a resolution of one second, so one block gives an error of up to one second. Use the median over many blocks.
  • The host clock must be synchronised (NTP). Receive-to-head does not depend on this, because both of its times come from the same process clock.

Frequently asked questions

Does --debug.logslowblock slow the node down?

The cost was not measured. At 0 the node writes one JSON line per imported block and one per received block message, and does nothing else different.

Why can the same block have several "Block received" lines?

Each peer that sends or announces the block gives one line. Use the earliest unix_ms.

Is this in the v0.1.0 release?

No. The receive line and end_unix_ms came with PR #1038 on 2026-11-15. Build from main at or after that merge.

Has xOne been measured against geth-XDC with these lines?

Not yet. Issue #1015 was closed with a measurement script (PR #1128), but no side-by-side result has been reported.

Sources