fix(engine): union v1.36.9 (G9 reconcile) + v1.36.7 engine fixes for v1.36.10

v1.36.9 (G9: reconcileVMToCertified + orphan_reconcile_test.go) branched off a
lineage that predates the five engine fixes on the v1.36.7 hotfix line. This
release folds those fixes onto v1.36.9's rewritten engine.go so the flag-day
ship vehicle carries BOTH the orphan-reconcile safety fix AND the non-leader
build-spin fix.

Re-applied by intent, not cherry-picked: a raw cherry-pick of 250065556
conflicts because engine.go was rewritten +143/-76 for G9. The resulting
buildBlocksLocked is byte-identical to v1.36.7's, and integration.go matches
2c52eb0d1's blob exactly.

Folded in (originals credited):
- 250065556  consume build demand on BuildBlock error instead of holding it
             (kills the non-leader hot spin). CONSUME pendingBuildBlocks before
             BuildBlock; on a no-block / "not our proposer slot" outcome clear
             remaining demand and log Debug (was Error). A non-leader's
             BuildBlock always errors under single-proposer scheduling, so the
             old hold-the-demand path was an unbounded per-tick spin.
- 2c52eb0d1  wire the runtime logger (SetLogger + NewRuntime) — engine was
             permanently log.Noop, silently discarding every internal decision.
- 45b589b42  log rebuilds of an undecided proposal slot.
- 93984fedd  log consensus.AddBlock rejections (was a silent continue).
- 30f44fbc0  log self-built block verification failures (was a silent continue).

Skipped c4581d40e (geth v1.20.1 bump): v1.36.9 already pins luxfi/geth v1.20.1.
go.mod / go.sum unchanged.

Preserved from v1.36.9: G9 reconcileVMToCertified + orphan_reconcile_test.go.

Tests assert the consume-on-error invariant (no spin, no accumulation, recovery
via a fresh Notify): TestBuildBlockError_ConsumesDemand,
TestBuildBlockError_RetriesOnNextNotify,
TestBuildBlockError_RepeatedFailures_NoPermanentHalt,
TestTransitiveNotifyPendingTxsWithVMError.

Co-authored-by: Hanzo Dev <dev@hanzo.ai>

engine/chain/comprehensive_test.go

@@ -621,8 +621,10 @@ func TestTransitiveNotifyPendingTxsWithVMError(t *testing.T) {
 	err := engine.Notify(ctx, msg)
 	require.NoError(err) // Errors are swallowed, not fatal
 
-	// Pending builds must NOT be cleared on error — retained for retry (Q-01 fix)
-	require.Equal(1, engine.PendingBuildBlocks())
+	// The failed build CONSUMES its demand (no spin): a non-leader's BuildBlock
+	// fails every slot until its window opens, so holding the demand was an
+	// unbounded hot loop. Liveness comes from fresh triggers, not held demand.
+	require.Equal(0, engine.PendingBuildBlocks())
 }
 
 // TestTransitiveNotifyStateSyncDone tests Notify with StateSyncDone message

engine/chain/engine.go

@@ -1103,6 +1103,22 @@ func (t *Transitive) SetVM(vm BlockBuilder) {
 	t.vm = vm
 }
 
+// SetLogger sets the engine logger after construction. The integration layer
+// builds the engine via NewWithParams (which carries no logger), so without
+// this setter the engine keeps its log.Noop() default and EVERY internal
+// decision — build-loop drops, verify failures, AddBlock rejections, vote-path
+// faults — is silently discarded. A rebuild storm ran 4M iterations with zero
+// engine log lines because of exactly that. Nil / zero loggers are ignored so
+// callers can pass their config logger unconditionally.
+func (t *Transitive) SetLogger(l log.Logger) {
+	if l == nil || l.IsZero() {
+		return
+	}
+	t.mu.Lock()
+	defer t.mu.Unlock()
+	t.log = l
+}
+
 // -----------------------------------------------------------------------------
 // Consensus operations
 // -----------------------------------------------------------------------------
@@ -3884,6 +3900,17 @@ func (t *Transitive) buildBlocksLocked(ctx context.Context) error {
 			break
 		}
 
+		// CONSUME the demand for THIS attempt BEFORE calling out (avalanchego's model:
+		// snow/engine/snowman decrements pendingBuildBlocks before BuildBlock and treats a
+		// failed build as consumed). The old code held the demand on error and returned, so
+		// the very next Notify re-entered and re-called BuildBlock — and under single-proposer
+		// scheduling a NON-leader's BuildBlock ALWAYS fails ("not our proposer slot") until its
+		// window opens, so the held demand became an unbounded hot spin (a non-leader burned CPU
+		// rebuilding a slot it can never win, 4 of 5 nodes, forever). Consuming it makes a failed
+		// build cost exactly one attempt; the node re-attempts on a FRESH trigger — its slot
+		// opening (proposervm WaitForEvent) or the elected leader's block advancing our tip.
+		t.pendingBuildBlocks--
+
 		// UNLOCK-BEFORE-CALL-OUT: BuildBlock is an external VM call — release t.mu around it, then
 		// re-acquire to process (buildBlocksLocked is entered and returns with t.mu held). The loop
 		// re-checks pendingBuildBlocks after re-lock, so a concurrent change is handled.
@@ -3891,14 +3918,19 @@ func (t *Transitive) buildBlocksLocked(ctx context.Context) error {
 		vmBlock, err := t.vm.BuildBlock(ctx)
 		t.mu.Lock()
 		if err != nil {
-			t.log.Error("BuildBlock failed, will retry next tick",
-				"error", err,
-				"pendingBuildBlocks", t.pendingBuildBlocks)
-			// Do NOT decrement pendingBuildBlocks — the request is still
-			// outstanding and will be retried on the next Notify or pipeline tick.
+			// Not a fault: most commonly "not this node's proposer slot" under
+			// single-proposer scheduling — the normal state for every non-leader at
+			// each height. This attempt is already consumed; CLEAR any remaining
+			// queued demand too, because it would fail identically on this same tick
+			// (same preference, same slot). Then wait for a FRESH trigger — the
+			// node's slot opening (proposervm WaitForEvent) or the leader's block
+			// advancing our tip — rather than re-calling BuildBlock every notify (the
+			// old hot spin). Debug (not Error) so a healthy fleet stays quiet.
+			t.pendingBuildBlocks = 0
+			t.log.Debug("BuildBlock produced no block (likely not our proposer slot) — waiting for a fresh trigger",
+				"error", err)
 			return nil
 		}
-		t.pendingBuildBlocks--
 
 		t.blocksBuilt++
 
@@ -3917,6 +3949,15 @@ func (t *Transitive) buildBlocksLocked(ctx context.Context) error {
 		// so peer votes accumulate on one ID to α instead of scattering. A new
 		// parent/height is a new key and builds normally. Re-solicit is K>1 only.
 		if existing := t.pendingOwnProposals[t.proposalKeyOf(consensusBlock)]; existing != nil && !existing.Decided {
+			// The VM re-wrapped an undecided slot. This is expected ONCE in a while; a sustained
+			// stream means the slot is never being decided and the VM is spinning (rebuild storm).
+			t.log.Info("rebuilt an undecided slot — re-soliciting votes",
+				"newBlkID", vmBlock.ID(),
+				"existingBlkID", existing.ConsensusBlock.id,
+				"keyParentID", consensusBlock.parentID,
+				"keyHeight", consensusBlock.height,
+				"existingHeight", existing.ConsensusBlock.height,
+				"K", t.consensus.K())
 			reSolicit := t.proposer != nil && t.consensus.K() > 1
 			reqBlockID, reqBlockData := existing.ConsensusBlock.id, existing.ConsensusBlock.data
 			t.mu.Unlock()
@@ -3932,6 +3973,19 @@ func (t *Transitive) buildBlocksLocked(ctx context.Context) error {
 		// is never added to consensus, so IsAccepted cannot return true for it.
 		t.mu.Unlock()
 		if err := vmBlock.Verify(ctx); err != nil {
+			// A block we built ourselves that fails its OWN verification is a real fault
+			// (VM state, proposer/epoch rule, timestamp window...). Dropping it silently left
+			// the node in an INVISIBLE HOT LOOP: the VM keeps re-notifying while its txs sit in
+			// the mempool, so the engine rebuilds → drops → rebuilds forever — no block ever
+			// enters consensus and NOT ONE log line says why (observed: 4.07M consecutive
+			// "built block" lines, chain stuck at height 1, zero errors logged). The drop itself
+			// is correct (an unverifiable block must never reach consensus); the SILENCE is the
+			// bug. Log the fault so it is diagnosable at the point of failure.
+			t.log.Error("built block failed verification — dropping",
+				"blkID", vmBlock.ID(),
+				"height", vmBlock.Height(),
+				"parentID", vmBlock.ParentID(),
+				"error", err)
 			t.mu.Lock()
 			continue
 		}
@@ -3945,6 +3999,19 @@ func (t *Transitive) buildBlocksLocked(ctx context.Context) error {
 		t.mu.Lock()
 
 		if addErr != nil {
+			// Same silent-drop class as the Verify failure above. consensus.AddBlock's only
+			// rejection is "block already exists" — which a self-built block hits whenever the
+			// VM re-mints an IDENTICAL envelope (the proposervm block timestamp is truncated to
+			// a whole second, so every rebuild inside that second yields the SAME blkID). The
+			// bare continue then skipped Propose/RequestVotes entirely: the block was never sent
+			// to peers, never voted on, never decided — while the VM kept re-notifying because
+			// its txs were still pending. Result: a silent rebuild storm with the chain pinned at
+			// its height and no log line naming the cause. Log it at the point of the drop.
+			t.log.Error("built block rejected by consensus — dropping",
+				"blkID", vmBlock.ID(),
+				"height", vmBlock.Height(),
+				"parentID", vmBlock.ParentID(),
+				"error", addErr)
 			continue
 		}
 

engine/chain/engine_test.go

@@ -1498,9 +1498,15 @@ func (m *failingBuildVM) SetPreference(_ context.Context, id ids.ID) error {
 	return nil
 }
 
-// TestBuildBlockError_DoesNotDecrementPending verifies Q-01: BuildBlock error
-// must not decrement pendingBuildBlocks so the build is retried.
-func TestBuildBlockError_DoesNotDecrementPending(t *testing.T) {
+// TestBuildBlockError_ConsumesDemand verifies that a BuildBlock error CONSUMES
+// the build demand (does NOT hold it), so a failing build costs exactly one
+// attempt instead of spinning. Under single-proposer scheduling a non-leader's
+// BuildBlock always fails ("not our slot") until its window opens; the previous
+// hold-the-demand behavior turned that into an unbounded hot loop (4 of 5 nodes
+// rebuilding a slot they can never win). Liveness is preserved by FRESH triggers
+// — the node's slot opening or the leader's block advancing the tip — verified in
+// TestBuildBlockError_RetriesOnNextNotify.
+func TestBuildBlockError_ConsumesDemand(t *testing.T) {
 	vm := &failingBuildVM{failCount: 1}
 	eng := newTestEngine(WithVM(vm))
 
@@ -1514,14 +1520,15 @@ func TestBuildBlockError_DoesNotDecrementPending(t *testing.T) {
 		t.Fatalf("Notify: %v", err)
 	}
 
-	// BuildBlock was called once (and failed)
+	// BuildBlock was called exactly once (and failed)
 	if vm.callCount != 1 {
 		t.Fatalf("expected 1 BuildBlock call, got %d", vm.callCount)
 	}
 
-	// pendingBuildBlocks must still be 1 — NOT decremented on error
-	if got := eng.PendingBuildBlocks(); got != 1 {
-		t.Fatalf("expected pendingBuildBlocks=1 after error, got %d", got)
+	// pendingBuildBlocks must be 0 — the failed attempt CONSUMED its demand,
+	// so the engine does not re-call BuildBlock every tick (no spin).
+	if got := eng.PendingBuildBlocks(); got != 0 {
+		t.Fatalf("expected pendingBuildBlocks=0 (consumed on error), got %d", got)
 	}
 }
 
@@ -1536,36 +1543,36 @@ func TestBuildBlockError_RetriesOnNextNotify(t *testing.T) {
 	}
 	defer eng.Stop(context.Background())
 
-	// First Notify: BuildBlock fails, counter stays at 1
+	// First Notify: BuildBlock fails and the demand is consumed (no spin).
 	eng.Notify(context.Background(), Message{Type: PendingTxs})
 	if vm.callCount != 1 {
 		t.Fatalf("expected 1 call after first Notify, got %d", vm.callCount)
 	}
-	if eng.PendingBuildBlocks() != 1 {
-		t.Fatalf("expected pendingBuildBlocks=1 after error, got %d", eng.PendingBuildBlocks())
+	if eng.PendingBuildBlocks() != 0 {
+		t.Fatalf("expected pendingBuildBlocks=0 (consumed on error), got %d", eng.PendingBuildBlocks())
 	}
 
-	// Second Notify: adds another pending + retries. failCount=1 means second
-	// call succeeds. The loop processes both pending (the retained one + new one).
+	// A FRESH Notify re-attempts — this is the liveness path (the node's slot
+	// opened / the leader's block advanced the tip). failCount=1 so this one
+	// succeeds and builds the block.
 	eng.Notify(context.Background(), Message{Type: PendingTxs})
-
-	// Second call succeeded, third call is the second pending item.
-	// Call 2 succeeded (first pending consumed), call 3 succeeded (second pending consumed).
-	if vm.callCount < 2 {
-		t.Fatalf("expected at least 2 BuildBlock calls after retry, got %d", vm.callCount)
+	if vm.callCount != 2 {
+		t.Fatalf("expected 2 BuildBlock calls after retry, got %d", vm.callCount)
 	}
 
-	// All pending should be consumed now
+	// Demand consumed, block built.
 	if got := eng.PendingBuildBlocks(); got != 0 {
 		t.Fatalf("expected pendingBuildBlocks=0 after successful retry, got %d", got)
 	}
 }
 
 // TestBuildBlockError_RepeatedFailures_NoPermanentHalt verifies that repeated
-// BuildBlock failures don't permanently halt block production. Each Notify
-// retains the counter, so future Notifys always attempt to build.
+// BuildBlock failures neither spin nor accumulate, and never permanently halt
+// production. Each failed attempt CONSUMES its demand (no hot loop, no growing
+// counter); a fresh Notify after recovery builds a block. Liveness comes from
+// fresh triggers, not from hoarding stale demand.
 func TestBuildBlockError_RepeatedFailures_NoPermanentHalt(t *testing.T) {
-	vm := &failingBuildVM{failCount: 100} // fails 100 times
+	vm := &failingBuildVM{failCount: 100} // fails the first 100 attempts
 	eng := newTestEngine(WithVM(vm))
 
 	if err := eng.Start(context.Background(), true); err != nil {
@@ -1573,28 +1580,29 @@ func TestBuildBlockError_RepeatedFailures_NoPermanentHalt(t *testing.T) {
 	}
 	defer eng.Stop(context.Background())
 
-	// Send 5 notifications — all will fail but counter grows
+	// Send 5 notifications — each fails and is CONSUMED (one attempt apiece).
 	for i := 0; i < 5; i++ {
 		eng.Notify(context.Background(), Message{Type: PendingTxs})
 	}
 
-	// pendingBuildBlocks should be 5 — none consumed because all failed
-	if got := eng.PendingBuildBlocks(); got != 5 {
-		t.Fatalf("expected pendingBuildBlocks=5 after 5 failures, got %d", got)
+	// No accumulation, no spin: exactly 5 attempts, 0 demand left.
+	if vm.callCount != 5 {
+		t.Fatalf("expected exactly 5 BuildBlock attempts (one per Notify), got %d", vm.callCount)
+	}
+	if got := eng.PendingBuildBlocks(); got != 0 {
+		t.Fatalf("expected pendingBuildBlocks=0 (each failure consumed), got %d", got)
 	}
 
-	// Now make BuildBlock succeed (lower failCount below callCount)
+	// Recovery: make BuildBlock succeed. A fresh Notify builds one block.
 	vm.failCount = vm.callCount // next call will succeed
 
-	// Next Notify adds one more pending (total 6) and retries — all 6 should build
 	eng.Notify(context.Background(), Message{Type: PendingTxs})
 
 	if got := eng.PendingBuildBlocks(); got != 0 {
 		t.Fatalf("expected pendingBuildBlocks=0 after recovery, got %d", got)
 	}
-
-	if len(vm.blocks) < 6 {
-		t.Fatalf("expected at least 6 blocks built after recovery, got %d", len(vm.blocks))
+	if len(vm.blocks) < 1 {
+		t.Fatalf("expected a block built after recovery, got %d", len(vm.blocks))
 	}
 }
 

engine/chain/integration.go

@@ -421,6 +421,12 @@ func NewRuntime(cfg NetworkConfig) *Runtime {
 	// RequestVotes while buildBlocksLocked held t.mu, self-deadlocking on the non-reentrant
 	// t.mu.RLock (the live n=1 freeze), and delivered a redundant vote that could sit uncounted in
 	// handleVote's not-yet-tracked buffer. Both hazards are gone with the path removed.
+	// Wire the runtime logger into the engine. NewWithParams leaves the engine on
+	// its log.Noop() default, which silently discards every internal decision the
+	// engine makes (verify drops, AddBlock rejections, build-loop stalls). The
+	// gossiperProposer below already receives cfg.Logger; the engine must too.
+	engine.SetLogger(cfg.Logger)
+
 	engine.SetProposer(&gossiperProposer{
 		gossiper:   cfg.Gossiper,
 		chainID:    cfg.ChainID,