ethereum-optimism / ethereum-optimism/optimism

op-supernode: derivation silently forks after invalidation replacement and logsDB cannot recover

Open
#22,138 3 comments 0 reactions 0 assignees View on GitHub
Dominant language
Go
Stars
6.5k
Forks
4k
Avg merge
2d 15h
Merged PRs (30d)
145

Description

## Summary

The supernode bookkept a chain that doesn't exist, then got permanently stuck on it.

An invalid cross-chain message got invalidated — normal, that's what this devnet tests. Recovery worked: bad block 259685 was replaced, and everyone agreed on the replacement.

Then two blocks later, at 259687, the supernode's derivation quietly produced a different block than the rest of the network. Not an error — just different. It kept going that way for ~1390 blocks over ~24 minutes, sealing every one into its logsDB and marking them cross-safe at ~300 timestamps per 5 minutes. Nothing checked whether the blocks it was verifying existed on its own execution engine. They didn't.

When the next invalid message arrived, the supernode made an invalidation decision against blocks from that private chain — denylisting hashes no node has ever seen. That forced a direct comparison, and the two chains finally collided: logsDB's newest block was on the fork, and the real next block's parent wasn't it. `block parent hash does not match logsDB`.

It cannot get out. Its rewind only walks back to blocks logsDB already holds — all of which are on the fork. The true common ancestor is ~1390 blocks below that, unreachable. So it retries the same doomed operation every 2 seconds; still doing so 4h40m later, as of writing.

Beyond one node: other CLs get their cross-safe head from the supernode. It can't advance, so none of theirs do. Both chains kept producing blocks at full rate throughout — ~15,600 of them — none of which can ever become cross-safe. Every dashboard reads green: unsafe head fine, local-safe fine, L1 fine, pods healthy. The only signals that move are ones nothing alerts on.

**Two defects, not one:**

1. **Derivation forked and nothing noticed.** Blocks 259684–259686 matched the network; 259687 onward did not. A derived block that doesn't match the node's own engine should be a loud failure, not the foundation of its safety database.
2. **Once wedged, no way out** — even though the node logs `super authority safe head non-canonical (reorg signal)`, meaning it detected exactly this condition and cannot act on it.

The sharp part: **the fix for #2 already exists in this codebase.** `reconcileLogsDBTail` (`op-supernode/supernode/activity/interop/log_backfill.go:209`) does precisely the needed rewind-to-common-ancestor, and its doc comment describes this failure verbatim:

```go
// reconcileLogsDBTail trims tail blocks whose hash no longer matches canonical,
// so backfill resumes from a block that is still in force. Without this, an L2
// reorg that occurs while supernode is offline leaves the tail diverged and the
// first seal on resume loops forever on ErrParentHashMismatch.
```

It has exactly one call site — `log_backfill.go:177`, the cold-start/backfill path. The live frontier path never calls it; `interop.go:889` just wraps the error and returns, so the next round fails identically:

```go
if err := i.persistFrontierLogs(pending.Result.Timestamp, pending.Result.L2Heads); err != nil {
return false, fmt.Errorf("persist frontier logs: %w", err)
}
```

So defect 2 is not a missing capability — it is an existing, tested remedy that is not wired into the live path.

> **Revision note.** Earlier versions of this issue identified the fork point as block 261076 and framed the cause as an off-by-one in the invalidation rewind target, and described the impact as confined to one node. Both were wrong; the corrections and the evidence trail are in the comments. Two findings unrelated to the supernode (invalidation-round serialization vs. the smoke test's 20-minute deadline, and an EL outage on `ops-reth-a-sn-1`) are also recorded in the comments rather than here, to keep this issue on the supernode defect.

## Environment

- Devnet: `interop-reorg-4` (dev-ent, `oplabs-dev-ent-networks-us-ue1-0`)
- Chains: `420120186` (`interop-reorg-4-0`), `420120187` (`interop-reorg-4-1`)
- Component: `op-supernode`, image `op-supernode:v1.0.0-rc.7` (`sha256:f2d228cc31af98633b0d91776667d2798aac0e8c0247584f99a0a0852b01c4d5`)
- Specimen: `an-interop-reorg-4-supernode-2`, pod `op-supernode-0` — up since 2026-07-29 16:17:32, **zero container restarts**, so it observed the entire event with one continuous logsDB. All supernode logs below are from it.
- Date: 2026-07-30, all times UTC

## Defect 1 — derivation silently forked at 259687

`supernode-2` logs every derived block as `Record local safe head … l2=:`. Comparing those hashes against `opn-reth-a-rpc-0` on chain 420120186:

| height | supernode-2 derived | canonical (all ELs) | |
|---|---|---|---|
| 259547 | `0x5c3e3538cc5f6e11` | same | match |
| 259684 | `0x5ef2ede6b821201b` | same | match — `lastValidParentBlock` of the 16:39 invalidation |
| 259685 | `0x53f8d09893162824` | same | match — **the replacement block itself** |
| 259686 | `0xfea5576f7584b141` | same | match |
| **259687** | `0x724cc9354a4012b9` | `0x3686d4bfb9c01076` | **DIVERGED** |
| 259688 | `0x570005061f8a3163` | `0xfcb7150a8535493e` | diverged |
| 259691 | `0x5dba543162d95c67` | `0x44cdfaedf64919a9` | diverged |
| 259692 | `0x65544ddb908fecd9` | `0x2623f286d3cbbefc` | diverged |
| 260047 | `0xf6c9281280dd` | `0x64f215c3ed00` | diverged |
| 260445 | `0x6fa21e6c519b` | `0x994dc79a1a61` | diverged |
| 260737 | `0x23133e785628` | `0x5aab00e259a4` | diverged |
| 260862 | `0xc95da95b702d` | `0xf51ab543f7df` | diverged |
| 260912 | `0x7ec3a7bc933c` | `0x68ff95f9a1f1` | diverged |
| 261076 | `0xb540da3392b1` | `0x5274e13066ef` | diverged |

The replacement at 259685 landed correctly and matched the network. 259686 matched. **From 259687 the derived chain went onto its own branch and never rejoined** — ~1390 blocks, ~24 minutes.

`0x5dba543162d95c67:259691` and `0xb540da33…:261076` are not found on any EL in the devnet: `opn-reth-a-rpc-0`, `opn-reth-f-seq-0/1/2`, `ops-reth-a-sn-0/1/2`.

Every node in the devnet agrees on the canonical value at 261076, including the supernode's own paired EL:

```
opn-reth-a-rpc-0 0x5274e13066ef6c0a4ef8825abe851e82c76524b16ff7722ddc52627b4399845a
opn-reth-f-seq-0 0x5274e13066ef6c0a4ef8825abe851e82c76524b16ff7722ddc52627b4399845a
opn-reth-f-seq-1 0x5274e13066ef6c0a4ef8825abe851e82c76524b16ff7722ddc52627b4399845a
opn-reth-f-seq-2 0x5274e13066ef6c0a4ef8825abe851e82c76524b16ff7722ddc52627b4399845a
ops-reth-a-sn-2 0x5274e13066ef6c0a4ef8825abe851e82c76524b16ff7722ddc52627b4399845a
```

Five other CL nodes derived independently over the same L1 data and all agree with the ELs. Only `supernode-2` disagrees.

### It verified against the fork the entire time

`increase(supernode_interop_timestamps_verified_total{namespace="an-interop-reorg-4-supernode-2"}[5m])`, spanning the period on the private fork:

```
16:40=298 16:45=301 16:50=300 16:55=244 17:00=300 17:05=188
```

~300 timestamps verified per 5 minutes against a chain that does not exist. `l2_local_safe` and `l2_safe` advanced normally throughout. Nothing in the interop path noticed.

Corroboration from the sequencer side: at 17:04 the chain-0 op-node reported `externalSafe=0x44cdfaedf64919a9…:259691` — the canonical hash — while the supernode held `0x5dba5431…` at that same height. They had already disagreed for 25 minutes.

### What the invalidation at 17:03 was actually computed against

Because the node was on the fork, the 17:03:04 invalidation decision named blocks that only ever existed in its own view:

```
lvl=info msg="added block to deny list" chainID=420120186 invalidatedBlock=0x8ddee908869d5a00ae594317950fc6598b5e1b64465225c52100302375b3856b:261077 lastValidParentBlock=0xb540da3392b1110066983116c6516dd9aae82c2350ccafaf98a3d48c38b11f52:261076 decisionTimestamp=1785430769
lvl=warn msg="initiating rewind after block invalidation" chainID=420120186 invalidatedBlock=0x8ddee908...:261077 lastValidParentBlock=0xb540da33...:261076
lvl=info msg="chain rewind completed" chainID=420120186 invalidatedBlock=0x8ddee908...:261077 lastValidParentBlock=0xb540da33...:261076 rewindTargetBlock=0xb540da3392b1110066983116c6516dd9aae82c2350ccafaf9...
lvl=info msg="added block to deny list" chainID=420120187 invalidatedBlock=0xc44cd9919faded8d74c045b577160c461295faf5b2817869bdd1641334fbdfe1:261077 lastValidParentBlock=0xa7c3f936c75efb0965bc3eb9e165a5e121b4241b54542db614ab8a443bfff89a:261076 decisionTimestamp=1785430769
lvl=info msg="chain rewind completed" chainID=420120187 invalidatedBlock=0xc44cd991...:261077 lastValidParentBlock=0xa7c3f936...:261076 rewindTargetBlock=0xa7c3f936c75efb0965bc3eb9e165a5e121b4241b54542db61...
```

`0xb540da33…:261076` was never canonical. logsDB was already on the fork by this point; the invalidation simply set its rewind target to another fork block, sealing in the dead end.

## Defect 2 — logsDB cannot recover from a non-canonical frontier

logsDB enforces a contiguity rule: to seal block N+1, its parent hash must equal the last block sealed. That rule is correct — it is what keeps the log chain unbroken.

Here the last sealed block is on the private fork, and the real next block's parent is a block logsDB never sealed. So the check fails, and it fails identically on every retry.

The escape would be to rewind logsDB to the last block that still matches the real chain and re-seal forward. It cannot: its rewind only targets blocks logsDB already holds, and every one of those is on the fork. The last in-force block is 259686, ~1390 blocks below the frontier, out of reach.

And it knows. Every cycle it logs `super authority safe head non-canonical (reorg signal)` with both hashes side by side — its own and the real one. It has diagnosed itself correctly and has no lever to pull.

There is a revealing asymmetry: **restarting the pod with logsDB intact would heal it**, because the cold-start path calls `reconcileLogsDBTail` and would trim the diverged tail. Staying up never heals, because the live path does not. Same database, same divergence, opposite outcome depending on whether the process restarts.

From 17:06:40 onward, every ~2 seconds, on both chains, still going 4h40m later:

```
lvl=warn msg="super authority safe head non-canonical (reorg signal)" chain_id=420120186 vn_id=d6c6 super_authority_safe=0xb540da3392b1110066983116c6516dd9aae82c2350ccafaf98a3d48c38b11f52:261076 canonical=0x5274e13066ef6c0a4ef8825abe851e82c76524b16ff7722ddc52627b4399845a:261076
lvl=warn msg="super authority safe head non-canonical (reorg signal)" chain_id=420120187 vn_id=bf35 super_authority_safe=0xa7c3f936c75efb0965bc3eb9e165a5e121b4241b54542db614ab8a443bfff89a:261076 canonical=0x58df1ebb1cb9a3802b3401680e811de09552c737e6125d789670c4958d27a274:261076

lvl=error msg="failed to progress and record interop" activity=interop err="persist frontier logs: chain 420120186: block 261077 parent hash 0x5274e13066ef6c0a4ef8825abe851e82c76524b16ff7722ddc52627b4399845a does not match logsDB last sealed block hash 0xb540da3392b1110066983116c6516dd9aae82c2350ccafaf98a3d48c38b11f52: block parent hash does not match logsDB"
lvl=error msg="failed to progress and record interop" activity=interop err="persist frontier logs: chain 420120187: block 261077 parent hash 0x58df1ebb1cb9a3802b3401680e811de09552c737e6125d789670c4958d27a274 does not match logsDB last sealed block hash 0xa7c3f936c75efb0965bc3eb9e165a5e121b4241b54542db614ab8a443bfff89a: block parent hash does not match logsDB"
```

`supernode_interop_verified_timestamp` frozen at `1785430768` since ~17:03. Lag grows 1:1 with wall clock (17193s / 4.78h at the last check):

```
17:00=182 17:15=932 17:30=1832 17:45=2732 18:00=3632 18:15=4532 18:30=5432
18:45=6332 19:00=7232 19:15=8132 19:30=9032 19:45=9932 20:00=10832 20:15=11732 20:30=12632
```

`increase(supernode_interop_round_decisions_total[15m])` — `wait` goes to zero and `advance` flat-lines at exactly the 2s retry cadence (450 per 15m = 0.5/s), i.e. the round loop spinning on the same failing frontier:

```
advance: 16:45=916 17:00=1071 17:15=410 17:30=450 17:45=449 ... 20:30=450
wait: 16:45=871 17:00=854 17:15=390 17:30=0 17:45=0 ... 20:30=0
```

`increase(supernode_interop_timestamps_verified_total[15m])` — zero from 17:30 on:

```
16:45=916 17:00=1071 17:15=161 17:30=0 17:45=0 18:00=0 ... 20:30=0
```

## Impact

Cross-safe stopped advancing devnet-wide. `optimism_syncStatus` via `proxyd-cl`, 4h44m after the event:

| field | chain 420120186 | chain 420120187 |
|---|---|---|
| `unsafe_l2` | 276581 | 276571 |
| `local_safe_l2` | 276581 | 276571 |
| **`safe_l2`** | **259685** `0x53f8d098…` | **259685** `0xb604566e…` |
| **`finalized_l2`** | **259685** `0x53f8d098…` | **259685** `0xb604566e…` |

Those two hashes at 259685 are the replacement blocks from the 16:39 invalidation — cross-safe is pinned to the last block before the fork at 259687.

Per-node `op_node_default_refs_number{layer="l2",type="l2_safe"}`, chain 420120186 — every CL froze between 17:00 and 17:30:

| node | cross-safe frozen at |
|---|---|
| `opn-reth-a-rpc-0` | 261041 |
| `opn-reth-f-seq-1` | 261041 |
| `opn-reth-f-snapsync-0` | 261030 |
| `opn-reth-f-seq-0` | 260992 |
| `opn-reth-f-seq-2` | 260992 |
| supernode-backed view (`proxyd-cl`) | 259685 |

Every frozen height sits below 261076 and clusters in 259685–261041, which is independent confirmation of a fork at 259687 rather than at 261076. Meanwhile `local_safe_l2` on `opn-reth-a-rpc-0` went 260936 (17:00) → 276580 (21:20): ~15600 blocks of local-safe progress with zero cross-safe progress.

**Nothing alerts on this.** `unsafe_l2`, `local_safe_l2`, `cross_unsafe_l2`, `l1_head`, block production and pod health all look normal. The only signals that move are `supernode_interop_verified_timestamp` (frozen), `op_node_default_refs_number{type="l2_safe"}` (frozen everywhere), and the `super authority safe head non-canonical` log — none of them alerted.

## How it started

The trigger was two back-to-back invalid-exec-message rounds from `op-chain-ops/cmd/interop-smoke`.

**16:39:02 — first round, block 259685, both chains.** This one recovered correctly:

```
lvl=info msg="added block to deny list" chainID=420120186 invalidatedBlock=0x0b8b07674e5bbb74ddcba99cb35db5c4793c77a81ef682763f06d4df3f2b49ac:259685 lastValidParentBlock=0x5ef2ede6b821201bc10c6e25479e1dfba6ea573fef5f4510f4205658d57d6f47:259684 decisionTimestamp=1785429377
lvl=warn msg="initiating rewind after block invalidation" chainID=420120186 invalidatedBlock=0x0b8b0767...:259685 lastValidParentBlock=0x5ef2ede6...:259684
lvl=info msg="chain rewind completed" chainID=420120186 invalidatedBlock=0x0b8b0767...:259685 lastValidParentBlock=0x5ef2ede6...:259684 rewindTargetBlock=0x5ef2ede6b821201bc10c6e25479e1dfba6ea573fef5f4510f...
lvl=warn msg="Gating unsafe ingestion during invalidation recovery" chain_id=420120186 vn_id=438a maxDeniedHeight=259685 finalized=0x022906f9f37efad1a5f15fb810b85b6837fca06d3a903cddc085fa8b284f6fab:12107
lvl=warn msg="Requesting deposits-only replacement for derived payload" chain_id=420120186 vn_id=438a blockNumber=0x3f665 blockHash=0x0b8b07674e5bbb74ddcba99cb35db5c4793c77a81ef682763f06d4df3f2b49ac derivedFrom=0x39f2225b8113243d642ca5b7b16372646ef0bdceba5affc2bea1e43f6ceb11f2:11383671
```

**16:58:16 — gating lifted:**

```
lvl=warn msg="Resuming unsafe ingestion, finality passed the invalidation" chain_id=420120186 vn_id=438a maxDeniedHeight=259685 finalized=0x53f8d09893162824c455733115c8f1081666554c730587cc779b9875f1f8934a:259685
lvl=warn msg="Resuming unsafe ingestion, finality passed the invalidation" chain_id=420120187 vn_id=325d maxDeniedHeight=259685 finalized=0xb604566e0fd6babf73c6b261153b355dcd556373c28ca50fda760aae33b74e34:259685
```

The replacement at 259685 is correct and matches the network. **Divergence begins at 259687, i.e. two blocks after the replaced block**, and goes undetected from there.

**16:59:29–16:59:42 —** the second smoke round's 12 invalid blocks land on the real chain (261077, 261080, 261082, 261085, 261087, 261090, both chains). **17:03:04 —** the supernode invalidates "261077" against its fork, as shown above. **17:06:40 —** the permanent error loop begins.

Note the 17:03 round logged no `Requesting deposits-only replacement for derived payload`, unlike the 16:39 round — worth checking whether the recovery path aborted early, and whether that is cause or consequence.

Also note `finalized` falls back to the interop-activation anchor (`:12107`) on invalidation and the virtual node IDs rotate (`438a`→`d6c6`, `325d`→`bf35`), which wipes monotonic caches. PR #22129 ("op-supernode: hold finalized instead of publishing activation anchor on zero FinalizedL1") looks related.

## Reproduction

```
go run ./cmd/interop-smoke invalid-message \
--l2a-rpc https://interop-reorg-4-0.optimism.io \
--l2b-rpc https://interop-reorg-4-1.optimism.io \
--private-key \
--tx-per-block 6 --direction both
```

Run it, let the invalidation round complete, then run it again. The first round recovered; the second wedged the node. The 12 invalid blocks were all correctly replaced on the real chain, so the reorg machinery itself works — the failure is in what the supernode derived afterwards.

### Unit-test reproduction for defect 2

Defect 2 is reproducible without a devnet, in `op-supernode/supernode/activity/interop/`. The harness already exists — `newInteropTestHarness(t)`, `WithChain(id, func(m *mockChainContainer))`, `WithActivation`, and direct `db.SealBlock(...)` access — and there is a close precedent in `TestColdStartBackfill_RecoversFromOfflineReorg` (`startup_test.go:370`), which is the offline-reorg twin of this bug and seeds a deliberately diverged tail.

A live-path version:

1. Build the harness with one chain, verification already initialized (so it takes the live path, not cold start).
2. `SealBlock` a tail where blocks ≤ N match `mockChainContainer`'s canonical output and blocks > N do not — the 259686/259687 boundary.
3. Drive the `DecisionAdvance` branch so it calls `persistFrontierLogs` for the next timestamp.
4. Assert it does **not** keep returning `ErrParentHashMismatch` across repeated rounds — i.e. that it reconciles and makes progress.

That test fails on current `develop` and passes once `reconcileLogsDBTail` runs on the live path.

Defect 1 is not reproducible this way — the silent fork is in derivation after an invalidation replacement, so it needs the real pipeline (op-e2e / acceptance-tests). The tractable form there is an invariant rather than a bug repro: after invalidation recovery, assert each derived block hash matches what the engine returns at that height, and fail on the first mismatch. That is also the production fix for defect 1, and would have caught this in seconds instead of 24 minutes.

## Expected behaviour

1. **A derived block whose hash does not match what the engine holds must fail loudly and immediately** — not be sealed into logsDB, not become the basis of interop verification, and never become the basis of an invalidation decision. ~1390 blocks and ~24 minutes of verifying a nonexistent chain is the core defect.
2. **Wire `reconcileLogsDBTail` into the live frontier path.** It already does the right thing on the backfill path; on `ErrParentHashMismatch` (or on `super authority safe head non-canonical`) the live path should reconcile back to the last in-force block — 259686 here — and re-seal forward, instead of failing `persist frontier logs` forever.
3. **Fail visibly.** A node that has detected its frontier is non-canonical should escalate rather than spin silently while every head metric reads green.

## Open question

What does the derivation pipeline resume from after `chain rewind completed` and the deposits-only replacement, such that 259685 and 259686 come out correct but 259687 does not? Stale batch-queue state, a wrong L1 origin, or a wrong sequence number would all fit the observed boundary. Determining whether the fork blocks differ from canonical in their L1 origin / sequence number / attributes, versus being the same attributes on a different parent, would separate a bad resume point from a bad engine interaction. The payloads are no longer on the ELs, so this likely needs a repro.

## Notes

Diagnosis was read-only: Grafana Cloud metrics/logs plus `cast` and `optimism_syncStatus` against the devnet. No state was modified.

**Live specimen.** As of 21:46 UTC, `an-interop-reorg-4-supernode-2` is still wedged — `supernode_interop_verified_timestamp` 17193s (4.78h) behind, `persist frontier logs` errors still firing within the last 5 minutes. It is the best specimen for inspecting the diverged logsDB before it is recycled. `supernode-0` and `supernode-1` were redeployed onto a `22129-merge` build at 20:44:54 and 20:23:33 and are not valid specimens. Note that restarting `supernode-2` will likely *destroy* the evidence by triggering the cold-start reconcile.

Contributor guide

Open the contributing guide

Research direction

Start with op-supernode/supernode/activity/interop.go:889 and compare the live frontier path with reconcileLogsDBTail in log_backfill.go:209, whose existing call site is at line 177. Trace how non-canonical safe heads reach persistFrontierLogs and review the existing log backfill tests. Done should include recovery from a diverged live logsDB frontier and detection of derived blocks that do not match the execution engine.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
databases, distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Quiet
Clarity
Mostly clear
Newbie friendliness
48/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.