Skip to content

fix(subtreevalidation): validate peer subtrees skipped during catchup once RUNNING again - #2055

Merged
icellan merged 8 commits into
bsv-blockchain:mainfrom
icellan:fix/subtree-backfill-after-catchup
Oct 27, 2026
Merged

icellan merged 8 commits into
bsv-blockchain:mainfrom
icellan:fix/subtree-backfill-after-catchup

Conversation

@icellan

@icellan icellan commented Oct 26, 2026

Copy link
Copy Markdown
Contributor

Problem

While the FSM is not RUNNING, subtreeMessageHandler returned nil for every peer-announced subtree, and the offset was auto-committed. Nothing ever came back for them.

On the scaling env on 2026-10-26, scale-3 sat in CATCHINGBLOCKS for 6 minutes (08:34:36–08:40:34). The next block (955) arrived with 286 subtrees the node had never validated. CheckBlockSubtrees read their 300M transactions from Aerospike (txmeta misses peaked at 3.65M/s), and validation took 6m21s. The next block arrived while 955 was still in flight and went to catchup too.

Change

  • What is kept. Subtrees announced while CATCHINGBLOCKS, and those found catching up after waiting for an admission slot, go into a bounded, deduplicated set in announcement order (skippedSubtrees).
    • subtreevalidation_skippedSubtreeBackfillMax sets the cap (default 4096; 0 keeps none). When full, the oldest is dropped.
    • IDLE (an operator STOP) is not kept, and entries older than 30 minutes are not replayed. By then the peers may have pruned the subtree, and a fetch that fails reports the peer.
  • When the replay starts. The first kept subtree starts a watcher on WaitForFSMtoTransitionToGivenState(RUNNING). Catchup sends RUN only after its last block, and the blockchain client keeps FSM notifications for its own state cache, so neither the subscription nor the next block would be early enough. A peer subtree handled in RUNNING and the block notification also start a replay.
  • How it runs. Oldest first, through subtreesHandler, so the admission limit, the quorum lock (which skips a subtree a block already validated) and the RUNNING re-check all apply. It uses at most half of subtreevalidation_peerSubtreeConcurrency, leaving the rest to live subtrees.
  • Unchanged. The live path is unchanged: no WithCreateConflicting. Txmeta ingestion is not touched.
  • New metric. teranode_subtreevalidation_skipped_peer_subtrees_total{outcome}, with outcomes recorded, evicted, replayed and replay_failed.

The CHANGELOG diff also re-indents four nested bullets of the #2037 entry (whitespace only), because markdownlint rejects the file otherwise.

Tests

  • Covered in skipped_subtrees_test.go:

    • kept while catching up and not while IDLE;
    • the cap evicts the oldest, and duplicates are not counted;
    • announcement order;
    • stale entries dropped;
    • replay on reaching RUNNING with no message or block, from a message in RUNNING, and from the block-notification path;
    • shutdown launches nothing;
    • half the admission slots;
    • failures counted, not fatal;
    • the post-admission drop site;
    • blocks-only and malformed messages not kept.

    Each one fails with its piece reverted.

  • go test -race ./services/subtreevalidation/... passes, and make lint reports 0 issues.

  • ./settings passes except TestBlockAssemblyTxMapDirs_DefaultEmpty and TestSubtreeMmapDir_DefaultEmpty, which fail locally only because of my settings_local.conf.

Limits

  • The set is in memory. A restart before the replay loses it, as before.
  • A subtree that fails on replay is not retried, the same as on the live path; block validation still validates it if a block needs it.

@github-actions

github-actions Bot commented Oct 26, 2026 •

Copy link
Copy Markdown
Contributor

🤖 Claude Code Review

Status: Complete

Current Review:
No blocking issues found. The latest commit moves the age timestamp out of subtreesHandler and into the Kafka handler. It is now taken when the message is received, before both the errgroup slot wait and the admission wait. A subtree that waited for a handler-group slot while the node moved into CATCHINGBLOCKS is therefore kept with its receipt time, not the time the wait ended. Every subtreesHandler caller passes the new receivedAt argument. The replay path does not go through subtreesHandler, so it still uses the entry's original recordedAt. TestSubtreeMessageHandler_AnnouncementTimeIsBeforeHandlerGroupWait holds the only admission slot to fill the group (max(4, NumCPU), the same limit as the handler), so it exercises the intended wait.

  • [Nit, still open] In the code, dropped covers every state other than RUNNING and CATCHINGBLOCKS, which includes LEGACYSYNCING. The metric help, the replaySubtree doc comment and the CHANGELOG describe it as IDLE only. Consider wording it as "not RUNNING or CATCHINGBLOCKS (for example IDLE)".

Docs: The CHANGELOG entry under [Unreleased], the settings reference row, the longdesc and settings.conf all still match the implementation. "Announced" in those docs now means received by this node, which is close enough for operators.

History:

  • ✅ Reviewed: the live-subtree age is now taken at Kafka receipt, before the handler-group wait (latest commit).
  • ✅ Fixed earlier: replayed no longer counts requeued entries, requeued entries keep their announcement order and recordedAt, the watcher handoff is pinned by a test, and an IDLE replay is counted as dropped. All four review threads are resolved.

Comment thread services/subtreevalidation/skipped_subtrees.go Outdated
@github-actions

github-actions Bot commented Oct 26, 2026 •

Copy link
Copy Markdown
Contributor

Benchmark Comparison Report

Baseline: main (unknown)

Current: PR-2055 (748ec68)

Summary

  • Regressions: 0
  • Improvements: 0
  • Unchanged: 169
  • Significance level: p < 0.05
All benchmark results (sec/op)
Benchmark Baseline Current Change p-value
_NewBlockFromBytes-4 975.8n 1007.0n ~ 0.400
Block_ValidOrderAndBlessed_DiskVsMemory/leaves=1024/memory-4 11.71m 11.71m ~ 1.000
Block_ValidOrderAndBlessed_DiskVsMemory/leaves=1024/disk_1-4 12.88m 12.77m ~ 1.000
Block_ValidOrderAndBlessed_DiskVsMemory/leaves=1024/disk_2-4 13.85m 13.86m ~ 1.000
Block_ValidOrderAndBlessed_DiskVsMemory/leaves=16384/memo... 23.06m 22.54m ~ 1.000
Block_ValidOrderAndBlessed_DiskVsMemory/leaves=16384/disk... 30.43m 31.03m ~ 0.700
Block_ValidOrderAndBlessed_DiskVsMemory/leaves=16384/disk... 32.26m 31.82m ~ 0.700
Block_ValidOrderAndBlessed_DiskVsMemory/leaves=131072/mem... 91.57m 90.65m ~ 0.700
Block_ValidOrderAndBlessed_DiskVsMemory/leaves=131072/dis... 212.9m 224.0m ~ 0.100
Block_ValidOrderAndBlessed_DiskVsMemory/leaves=131072/dis... 208.7m 223.7m ~ 0.200
BlockTxMap/txs=16384/nodeindex-4 1.591m 1.585m ~ 0.700
BlockTxMap/txs=16384/swiss-4 12.13m 11.95m ~ 1.000
BlockTxMap/txs=262144/nodeindex-4 12.50m 12.50m ~ 1.000
BlockTxMap/txs=262144/swiss-4 37.32m 38.72m ~ 1.000
BlockTxMap/txs=4194304/nodeindex-4 401.4m 373.0m ~ 0.100
BlockTxMap/txs=4194304/swiss-4 846.4m 746.5m ~ 0.100
TxMapPut_MemoryVsDisk/txs=100000/memory-4 6.656m 5.127m ~ 0.100
TxMapPut_MemoryVsDisk/txs=100000/disk_1-4 11.030m 9.049m ~ 0.100
TxMapPut_MemoryVsDisk/txs=100000/disk_2-4 10.243m 7.495m ~ 0.100
TxMapGetFrozen_MemoryVsDisk/txs=100000/memory/hit-4 3.801m 2.722m ~ 0.100
TxMapGetFrozen_MemoryVsDisk/txs=100000/memory/miss-4 2.311m 2.246m ~ 0.700
TxMapGetFrozen_MemoryVsDisk/txs=100000/disk_1/hit-4 1.264m 1.206m ~ 0.100
TxMapGetFrozen_MemoryVsDisk/txs=100000/disk_1/miss-4 1.340m 1.242m ~ 0.400
TxMapGetFrozen_MemoryVsDisk/txs=100000/disk_2/hit-4 1.223m 1.176m ~ 0.100
TxMapGetFrozen_MemoryVsDisk/txs=100000/disk_2/miss-4 1.494m 1.251m ~ 0.100
ParentSpendsSetIfNotExists_MemoryVsDisk/inputs=200000/dis... 21.49m 19.75m ~ 0.100
ParentSpendsSetIfNotExists_MemoryVsDisk/inputs=200000/dis... 18.72m 18.72m ~ 0.700
InpointDedup/txs=16K-4 3.763m 3.919m ~ 0.700
InpointDedup/txs=128K-4 13.63m 13.54m ~ 1.000
InpointDedup/txs=1M-4 100.6m 100.0m ~ 1.000
InpointDedup_TinyRuns-4 36.53m 35.93m ~ 1.000
MiningCandidate_Stringify_Short-4 120.6n 121.5n ~ 0.700
MiningCandidate_Stringify_Long-4 932.7n 876.3n ~ 0.700
MiningSolution_Stringify-4 497.1n 483.3n ~ 0.700
BlockInfo_MarshalJSON-4 1.242µ 1.266µ ~ 0.400
DecodeSubtreeMeta/go-subtree-4 132.5m 131.4m ~ 1.000
DecodeSubtreeMeta/packed-4 33.40m 33.10m ~ 1.000
DecodeSubtreeMeta/go-subtree/parallel-4 67.92m 67.00m ~ 0.700
DecodeSubtreeMeta/packed/parallel-4 18.02m 18.79m ~ 0.100
ValidateSubtreeNodesMatchKey/leaves=1024-4 187.8µ 192.0µ ~ 0.200
ValidateSubtreeNodesMatchKey/leaves=1048576-4 57.75m 57.59m ~ 1.000
NewFromBytes-4 88.76n 81.06n ~ 0.100
AddTxBatchColumnar_Validation-4 1.433µ 1.392µ ~ 0.700
OffsetValidationLoop-4 371.1n 370.3n ~ 0.100
BuildSubtreeMeta/serialized-4 10.067m 9.608m ~ 0.700
BuildSubtreeMeta/decoded-4 22.01m 23.36m ~ 0.100
Mine_EasyDifficulty-4 61.31µ 61.77µ ~ 0.200
Mine_WithAddress-4 7.301µ 7.343µ ~ 0.400
DirectSubtreeAdd/4_per_subtree-4 80.08n 79.40n ~ 0.700
DirectSubtreeAdd/64_per_subtree-4 33.69n 33.24n ~ 1.000
DirectSubtreeAdd/256_per_subtree-4 31.89n 31.42n ~ 1.000
DirectSubtreeAdd/1024_per_subtree-4 30.46n 30.30n ~ 0.500
DirectSubtreeAdd/2048_per_subtree-4 29.76n 29.69n ~ 0.700
SubtreeProcessorAdd/4_per_subtree-4 246.1n 246.5n ~ 0.700
SubtreeProcessorAdd/64_per_subtree-4 281.8n 273.1n ~ 0.400
SubtreeProcessorAdd/256_per_subtree-4 299.1n 297.4n ~ 0.700
SubtreeProcessorAdd/1024_per_subtree-4 296.2n 295.9n ~ 1.000
SubtreeProcessorAdd/2048_per_subtree-4 291.3n 292.9n ~ 0.200
SubtreeProcessorRotate/4_per_subtree-4 297.6n 296.3n ~ 0.200
SubtreeProcessorRotate/64_per_subtree-4 297.6n 298.7n ~ 0.700
SubtreeProcessorRotate/256_per_subtree-4 298.3n 299.6n ~ 0.700
SubtreeProcessorRotate/1024_per_subtree-4 297.4n 305.7n ~ 0.200
SubtreeNodeAddOnly/4_per_subtree-4 66.09n 67.75n ~ 0.700
SubtreeNodeAddOnly/64_per_subtree-4 40.11n 41.05n ~ 0.700
SubtreeNodeAddOnly/256_per_subtree-4 38.87n 40.14n ~ 0.100
SubtreeNodeAddOnly/1024_per_subtree-4 38.79n 39.93n ~ 0.100
SubtreeCreationOnly/4_per_subtree-4 163.3n 162.8n ~ 1.000
SubtreeCreationOnly/64_per_subtree-4 420.0n 417.4n ~ 1.000
SubtreeCreationOnly/256_per_subtree-4 1.380µ 1.389µ ~ 0.700
SubtreeCreationOnly/1024_per_subtree-4 5.179µ 5.068µ ~ 1.000
SubtreeCreationOnly/2048_per_subtree-4 9.901µ 10.064µ ~ 1.000
SubtreeProcessorOverheadBreakdown/64_per_subtree-4 237.0n 236.0n ~ 0.400
SubtreeProcessorOverheadBreakdown/1024_per_subtree-4 289.8n 290.9n ~ 1.000
ParallelGetAndSetIfNotExists/1k_nodes-4 744.9µ 791.4µ ~ 0.700
ParallelGetAndSetIfNotExists/10k_nodes-4 4.689m 4.712m ~ 0.700
ParallelGetAndSetIfNotExists/50k_nodes-4 7.090m 7.257m ~ 0.100
ParallelGetAndSetIfNotExists/100k_nodes-4 9.699m 9.966m ~ 1.000
SequentialGetAndSetIfNotExists/1k_nodes-4 735.9µ 684.2µ ~ 1.000
SequentialGetAndSetIfNotExists/10k_nodes-4 5.458m 5.806m ~ 0.400
SequentialGetAndSetIfNotExists/50k_nodes-4 19.21m 19.73m ~ 0.400
SequentialGetAndSetIfNotExists/100k_nodes-4 33.97m 35.46m ~ 0.400
ProcessOwnBlockSubtreeNodesParallel/1k_nodes-4 847.8µ 773.3µ ~ 1.000
ProcessOwnBlockSubtreeNodesParallel/10k_nodes-4 7.296m 7.452m ~ 0.100
ProcessOwnBlockSubtreeNodesParallel/100k_nodes-4 12.45m 13.11m ~ 0.400
ProcessOwnBlockSubtreeNodesSequential/1k_nodes-4 770.2µ 762.6µ ~ 1.000
ProcessOwnBlockSubtreeNodesSequential/10k_nodes-4 8.696m 9.490m ~ 0.100
ProcessOwnBlockSubtreeNodesSequential/100k_nodes-4 51.18m 54.18m ~ 0.100
BlockAssembler_AddTx-4 0.01441n 0.01360n ~ 0.700
AddNode-4 8.698 8.523 ~ 1.000
AddNodeWithMap-4 8.514 9.240 ~ 0.100
DiskTxMap_SetIfNotExists-4 584.1n 592.6n ~ 0.400
DiskTxMap_SetIfNotExists_Parallel-4 218.4n 252.2n ~ 0.700
DiskTxMap_ExistenceOnly-4 244.9n 253.6n ~ 0.700
Queue-4 191.9n 187.4n ~ 0.100
AtomicPointer-4 8.174n 8.170n ~ 0.300
TxMapSetIfNotExists-4 52.90n 53.34n ~ 1.000
TxMapSetIfNotExistsDuplicate-4 49.11n 49.06n ~ 0.400
ChannelSendReceive-4 667.2n 647.6n ~ 0.200
CalcBlockWork-4 519.8n 519.7n ~ 1.000
CalculateWork-4 701.3n 706.1n ~ 1.000
CheckOldBlockIDs/on-chain-prefetch/1000-4 56.43µ 58.40µ ~ 1.000
CheckOldBlockIDs/in-memory-chain-check/1000-4 1.581m 1.528m ~ 0.700
CheckOldBlockIDs/on-chain-prefetch/10000-4 434.4µ 425.8µ ~ 0.100
CheckOldBlockIDs/in-memory-chain-check/10000-4 2.164m 2.134m ~ 0.200
BuildBlockLocatorString_Helpers/Size_10-4 1.326µ 1.426µ ~ 0.100
BuildBlockLocatorString_Helpers/Size_100-4 12.67µ 13.67µ ~ 0.100
BuildBlockLocatorString_Helpers/Size_1000-4 125.1µ 134.8µ ~ 0.100
CatchupWithHeaderCache-4 106.9m 107.1m ~ 0.100
_BufferPoolAllocation/16KB-4 2.534µ 2.790µ ~ 1.000
_BufferPoolAllocation/32KB-4 5.848µ 5.169µ ~ 0.100
_BufferPoolAllocation/64KB-4 11.63µ 11.29µ ~ 0.200
_BufferPoolAllocation/128KB-4 21.64µ 21.38µ ~ 0.700
_BufferPoolAllocation/512KB-4 88.80µ 99.68µ ~ 0.100
_BufferPoolConcurrent/32KB-4 13.63µ 13.93µ ~ 0.400
_BufferPoolConcurrent/64KB-4 21.13µ 22.31µ ~ 0.100
_BufferPoolConcurrent/512KB-4 112.4µ 118.3µ ~ 0.100
_SubtreeDeserializationWithBufferSizes/16KB-4 382.3µ 398.9µ ~ 0.100
_SubtreeDeserializationWithBufferSizes/32KB-4 374.7µ 393.8µ ~ 0.100
_SubtreeDeserializationWithBufferSizes/64KB-4 375.7µ 391.2µ ~ 0.100
_SubtreeDeserializationWithBufferSizes/128KB-4 377.3µ 384.3µ ~ 0.200
_SubtreeDeserializationWithBufferSizes/512KB-4 372.5µ 395.4µ ~ 0.100
_SubtreeDataDeserializationWithBufferSizes/16KB-4 21.97m 23.20m ~ 0.100
_SubtreeDataDeserializationWithBufferSizes/32KB-4 22.11m 23.53m ~ 0.200
_SubtreeDataDeserializationWithBufferSizes/64KB-4 22.69m 23.24m ~ 0.200
_SubtreeDataDeserializationWithBufferSizes/128KB-4 22.77m 22.83m ~ 1.000
_SubtreeDataDeserializationWithBufferSizes/512KB-4 21.96m 22.86m ~ 0.100
_PooledVsNonPooled/Pooled-4 375.6n 389.9n ~ 0.100
_PooledVsNonPooled/NonPooled-4 5.591µ 5.182µ ~ 0.400
_MemoryFootprint/Current_512KB_32concurrent-4 6.708µ 6.214µ ~ 0.200
_MemoryFootprint/Proposed_32KB_32concurrent-4 6.556µ 6.779µ ~ 0.100
_MemoryFootprint/Alternative_64KB_32concurrent-4 6.006µ 6.758µ ~ 0.100
_prepareTxsPerLevel-4 266.1m 267.3m ~ 0.400
_prepareTxsPerLevelOrdered-4 2.446m 2.498m ~ 0.700
_prepareTxsPerLevel_Comparison/Original-4 262.3m 261.4m ~ 1.000
_prepareTxsPerLevel_Comparison/Optimized-4 2.426m 2.510m ~ 0.700
SubtreeSizes/10k_tx_4_per_subtree-4 1.048m 1.041m ~ 0.100
SubtreeSizes/10k_tx_16_per_subtree-4 245.2µ 246.7µ ~ 0.400
SubtreeSizes/10k_tx_64_per_subtree-4 58.91µ 59.16µ ~ 1.000
SubtreeSizes/10k_tx_256_per_subtree-4 14.50µ 14.75µ ~ 0.700
SubtreeSizes/10k_tx_512_per_subtree-4 7.176µ 7.348µ ~ 0.200
SubtreeSizes/10k_tx_1024_per_subtree-4 3.598µ 3.527µ ~ 0.100
SubtreeSizes/10k_tx_2k_per_subtree-4 1.856µ 1.819µ ~ 0.200
BlockSizeScaling/10k_tx_64_per_subtree-4 59.78µ 59.21µ ~ 1.000
BlockSizeScaling/10k_tx_256_per_subtree-4 14.31µ 14.55µ ~ 0.700
BlockSizeScaling/10k_tx_1024_per_subtree-4 3.861µ 3.799µ ~ 0.700
BlockSizeScaling/50k_tx_64_per_subtree-4 310.0µ 309.7µ ~ 1.000
BlockSizeScaling/50k_tx_256_per_subtree-4 76.07µ 74.71µ ~ 0.400
BlockSizeScaling/50k_tx_1024_per_subtree-4 20.58µ 20.26µ ~ 0.700
SubtreeAllocations/small_subtrees_exists_check-4 137.0µ 137.2µ ~ 1.000
SubtreeAllocations/small_subtrees_data_fetch-4 147.9µ 146.5µ ~ 0.700
SubtreeAllocations/small_subtrees_full_validation-4 289.9µ 292.2µ ~ 0.400
SubtreeAllocations/medium_subtrees_exists_check-4 8.646µ 8.727µ ~ 0.100
SubtreeAllocations/medium_subtrees_data_fetch-4 9.384µ 9.286µ ~ 0.700
SubtreeAllocations/medium_subtrees_full_validation-4 18.46µ 18.52µ ~ 0.700
SubtreeAllocations/large_subtrees_exists_check-4 2.205µ 2.242µ ~ 0.300
SubtreeAllocations/large_subtrees_data_fetch-4 2.426µ 2.385µ ~ 0.400
SubtreeAllocations/large_subtrees_full_validation-4 4.605µ 4.652µ ~ 0.400
StoreBlockForkPath/inMemoryChainCheck=false-4 285.4µ 288.6µ ~ 0.200
StoreBlockForkPath/inMemoryChainCheck=true-4 1.011m 1.009m ~ 1.000
StoreBlock_Sequential/BelowCSVHeight-4 73.12µ 71.45µ ~ 0.100
StoreBlock_Sequential/AboveCSVHeight-4 73.21µ 72.06µ ~ 0.400
CheckSpendAndCreateMultiList_FanIn/parents=80000-4 53.85m 56.48m ~ 1.000
CheckSpendAndCreateMultiList_FanIn/parents=160000-4 131.6m 129.1m ~ 0.200
GetUtxoHashes-4 294.5n 295.1n ~ 1.000
GetUtxoHashes_ManyOutputs-4 43.52µ 42.97µ ~ 1.000
MetaBytes-4 69.81n 69.53n ~ 0.700
_NewMetaDataFromBytes-4 228.9n 226.8n ~ 0.100
_Bytes-4 348.8n 346.6n ~ 0.100
_MetaBytes-4 108.9n 109.7n ~ 0.400

Threshold: >10% with p < 0.05 | Generated: 2026-10-27 17:42 UTC

@oskarszoon oskarszoon left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The backfill has a lost replay trigger, can fetch subtrees beyond its stated 30-minute limit, and can count an unvalidated subtree as replayed. Please address these before merging.

  • services/subtreevalidation/skipped_subtrees.go:205: If another catchup records entries while a replay is active, its RUNNING watcher can exit on the replaying guard. The active replay then finishes without draining those entries. Arrange a follow-up replay; a scoped test reproduced one entry left queued with no new event.
  • services/subtreevalidation/skipped_subtrees.go:221: Recheck each entry's age after it obtains a replay worker slot. The current batch-start check can let an entry wait past 30 minutes, fetch from a peer that has pruned it, and report that peer.
  • services/subtreevalidation/skipped_subtrees.go:232: Count replayed only after validation completes or an existing subtree is confirmed. A requeue after another catchup, or a held quorum lock with no stored file, currently increments it.
  • services/subtreevalidation/skipped_subtrees.go:74: Preserve the original announcement time when replay requeues an entry during catchup. Resetting it can fetch from and report the original peer more than 30 minutes after its announcement.

@freemans13 freemans13 left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Request changes on e903bee6906debd2eb7193cecc14aa36390dd15a. I reproduced the lost-trigger and expiry problems in oskarszoon's review. The inline comment adds a related queue-ordering failure that drops newer announcements.

  • A second RUNNING watcher can finish while the first replay is active. After that replay finishes, the regression finds one queued entry with both watching=false and replaying=false. Nothing drains it without another external event.
  • An entry can expire while waiting for admission. A regression using the real replay/admission path, SQLite blockchain client and in-memory Kafka fetched it after 30 minutes. A simulated 404 then published peer_cannot_provide_subtree against the original valid peer ID. Check age after admission, before network work, as well as preserving the original timestamp across catchups.
  • With a full queue, requeuing old replay entries can evict newer announcements. Preserve their original ordering as described inline.

Each focused regression reproduced twice with the race detector. The existing SubtreeValidation and settings suites passed with SETTINGS_CONTEXT=test go test -race -tags testtxmetacache -count=2 ./services/subtreevalidation/... ./settings. I did not run the full repository suite or verify CI.

Comment thread services/subtreevalidation/skipped_subtrees.go Outdated
@icellan

icellan commented Oct 27, 2026

Copy link
Copy Markdown
Contributor Author

Addressed in ec8aa0b, with a regression test for each point. Each test fails on e903bee.

  • skipped_subtrees.go:205, lost trigger: when a replay ends with entries left, it clears replaying and starts a RUNNING watcher. The watcher now clears watching before it calls the replay, so the replay's new watcher can't lose that flag to the old one. TestReplaySkippedSubtrees_KeptDuringReplayAreReplayedAfter
  • skipped_subtrees.go:221, expiry after admission: the replay now takes the admission slot itself, then checks age and FSM before any network work. subtreesHandler is split into admitPeerSubtree and validateAdmittedPeerSubtree. Past the limit, the entry counts as expired and is never fetched. TestReplaySkippedSubtrees_ExpiresWhileWaitingForAdmission
  • skipped_subtrees.go:232, replayed overcount: replayed now counts only validated subtrees or ones confirmed stored. A held quorum lock with nothing stored counts nothing, and a kept-again entry counts as requeued. The live path still returns ErrSubtreeExists for both lock cases, as before. TestReplaySkippedSubtrees_HeldLockIsNotReplayed, TestReplaySkippedSubtrees_KeptAgainIsNotReplayed
  • skipped_subtrees.go:74, timestamp reset: record() keeps the caller's recordedAt, and the requeue passes the original entry. Ordering is covered in the inline thread.

New metric outcomes expired and requeued are in the CHANGELOG entry and the metric help.

SETTINGS_CONTEXT=test go test -race -tags testtxmetacache -count=2 ./services/subtreevalidation/... passes, and the new tests pass 5x under -race.

@freemans13 freemans13 left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Approve on ec8aa0b7f. All three points from my review on e903bee69 are fixed, and so are oskarszoon's four. Two things need doing before merge, and neither is a code finding:

  • No CI has run on ec8aa0b7f. Only Socket Security posted a check run. The last full run was on e903bee69.
  • GitHub reports the PR as DIRTY, meaning it now conflicts with main. That conflict is probably why CI did not start.

How I checked the fixes. I undid each fix in a scratch worktree and ran its regression test:

Fix undone Test Result
Age check after admission removed ExpiresWhileWaitingForAdmission fails
record() inserts at the tail again KeptAgainKeepsAnnouncementOrder fails
A held lock counts as replayed HeldLockIsNotReplayed fails
A requeue counts as replayed KeptAgainIsNotReplayed fails
End-of-replay recheck removed KeptDuringReplayAreReplayedAfter fails
Watcher clears watching after the replay call (the old defer) KeptDuringReplayAreReplayedAfter passes

The last row is the first inline comment. The fix is correct, but nothing pins its ordering half. The second inline comment is a small observability gap. Both are non-blocking.

I read the subtreesHandler split with the live path in mind. Both lock outcomes still return ErrSubtreeExists, as before, and the admission-wait metric and span placement are unchanged.

SETTINGS_CONTEXT=test go test -race -tags testtxmetacache -count=1 ./services/subtreevalidation/... passed (440 s, race detector on). The skipped-subtree and replay tests passed five times under -race. I did not run the full repository suite.

Comment thread services/subtreevalidation/skipped_subtrees.go
Comment thread services/subtreevalidation/skipped_subtrees.go

@oskarszoon oskarszoon left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Two issues still need changes. A live subtree announcement can acquire a fresh age after waiting for admission, allowing replay beyond the stated 30 minutes. The new handoff regression test also passes when the watcher ordering that prevents stranded entries is removed. The earlier replay fixes otherwise hold. This HEAD has no Go CI results and currently conflicts with main.

  • services/subtreevalidation/subtreeHandler.go:148: Capture the announcement time before the admission wait and carry it into the catchup queue. The current time.Now() starts the age limit after the wait, so a stale announcement can be fetched and its peer reported after pruning.
  • services/subtreevalidation/skipped_subtrees_test.go:465: Make the handoff test hold the second watcher after its failed replay attempt while the first replay tries to start a replacement watcher. Restoring the old deferred watching clear currently leaves this test passing, despite reopening the lost-trigger race.

… once RUNNING again

While the node was not RUNNING, the subtree validator dropped every
peer-announced subtree and committed the Kafka offset, so nothing came back
for them. After a 6-minute catchup on scale-3 the next block arrived with 286
subtrees unvalidated and checking it read 300M transactions from the UTXO
store, which made that block slow enough to start the next catchup.

Subtrees announced while not RUNNING, or found not RUNNING after waiting for
an admission slot, are now kept (deduplicated, up to
subtreevalidation_skippedSubtreeBackfillMax, default 4096; 0 keeps none). The
first peer subtree handled in RUNNING replays them through subtreesHandler, so
the admission limit, the quorum lock and the RUNNING check all apply and a
subtree validated meanwhile is skipped. The live path is unchanged: no
conflicting txs are created and txmeta ingestion is not touched. New metric
teranode_subtreevalidation_skipped_peer_subtrees_total{outcome}.

Also re-indents four nested bullets of an existing CHANGELOG entry that the
markdown lint hook rejects.
… replay from the block notification too

Review follow-ups on the backfill:
- Keep subtrees only while CATCHINGBLOCKS. IDLE can last days; by then the
  peers may have pruned the subtrees and a replay that cannot fetch one
  reports the peer.
- When full, drop the oldest entry instead of refusing the newest: the newest
  announcements are the ones the next block needs. Replay in announcement
  order, so parents start before the subtrees that spend from them.
- Start the replay from the block notification as well, so a block arriving
  before any peer subtree message still sets it going.
- Use at most half the peer-subtree admission slots, leaving the rest to live
  subtrees; stop launching on shutdown and don't log cancellations.
- Metric outcomes: recorded (new entries only), evicted, replayed,
  replay_failed.
…UNNING, drop entries older than 30 minutes

Catchup sends RUN only after its last block, and the blockchain client keeps
FSM notifications for its own state cache, so the replay could only start on
the next peer subtree message or block. On a quiet network that is the next
block, validated with the kept subtrees still unvalidated. The first kept
subtree now starts a watcher that waits for RUNNING and replays.

The replay runs on the parent context rather than an errgroup context, so a
watcher started by a subtree kept again during the replay outlives it.

Entries older than 30 minutes are not replayed: a catchup followed by a long
operator STOP would otherwise replay subtrees the peers may have pruned, and
a failed fetch reports the peer.
…catchups

- A replay that ends with subtrees kept meanwhile starts a new RUNNING watcher;
  the watcher that found the replay running had given up, leaving them queued.
  The watcher now clears its flag before replaying, so the new one can start.
- The age limit is checked again once a replayed subtree has an admission
  slot, so a subtree that waited past 30 minutes is not fetched from a peer
  that may have pruned it.
- A subtree kept again because the node is catching up again keeps its
  announcement time and goes back in announcement order; with the queue full
  it is the one dropped, not newer announcements.
- replayed counts only validated or stored subtrees, not ones kept again or
  locked by another validation. New outcomes: expired, requeued.
…play drops

- subtreesHandler takes the announcement time before the admission wait, so
  a subtree kept for replay is aged from its arrival.
- A replayed subtree that finds the node IDLE is counted as dropped.
- A test holds the second RUNNING watcher right after its replay call, so the
  watcher clearing its flag before the call is pinned: the old deferred clear
  strands the subtree kept during the replay.
@icellan
icellan force-pushed the fix/subtree-backfill-after-catchup branch from ec8aa0b to e218573 Compare October 27, 2026 15:54
@icellan

icellan commented Oct 27, 2026

Copy link
Copy Markdown
Contributor Author

Addressed in 2a26227. The branch is rebased onto main, so it should no longer show as conflicting, and CI can run.

  • subtreeHandler.go:148, announcement time: subtreesHandler takes announcedAt before the admission wait and keeps that time when it records the subtree for replay. A subtree kept after a long wait is aged from its arrival. Regression: TestSubtreesHandler_AnnouncementTimeIsBeforeAdmissionWait, which holds the only admission slot for 300 ms and checks the kept time against arrival.
  • skipped_subtrees_test.go:465, handoff ordering: TestReplaySkippedSubtrees_WatcherHandoffInNarrowWindow holds the second watcher after its failed replay call while the first replay finishes and starts its replacement watcher. With the old deferred watching clear restored, the test fails and the entry stays queued.
  • A replayed subtree that finds the node IDLE is now counted as dropped (freemans13's inline).

Rebase conflicts: main added the TxMetaTombstoneWindow row next to SkippedSubtreeBackfillMax in subtreevalidation_settings.md. I kept both rows and set checkedRowsPerDoc for that doc to 26 (e218573).

SETTINGS_CONTEXT=test go test -race -tags testtxmetacache ./services/subtreevalidation/... passes on the rebased branch, and the skipped-subtree tests pass 5x under -race. In ./settings, TestSettingsDocDefaultsMatchCode passes. TestBlockAssemblyTxMapDirs_DefaultEmpty and TestSubtreeMmapDir_DefaultEmpty fail only locally, because of my settings_local.conf, and they fail the same way on main.

@icellan
icellan requested a review from oskarszoon October 27, 2026 15:54

@oskarszoon oskarszoon left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The new watcher test, admission-wait timestamp, and IDLE outcome address the issues I raised on the previous commit, and current-head CI is green. One age-limit path remains: a received RUNNING message can wait in the bounded handler group before its timestamp starts, then enter catchup and be replayed more than 30 minutes after receipt. Please carry receipt time across that wait before merging.

  • services/subtreevalidation/subtreeHandler.go:102 and :129: g.Go can block while the handler group is full, but announcedAt is set only inside the launched goroutine. I reproduced a 300 ms uncounted wait; the same sequence spanning the 30-minute cutoff can fetch from a peer after it has pruned the subtree and report that peer on a 404. Capture the time before g.Go, pass it into subtreesHandler, and cover the saturated-group catchup path.

@icellan
icellan requested a review from oskarszoon October 27, 2026 17:18
…the handler group wait

subtreeMessageHandler takes the receipt time before g.Go, which blocks while
the handler group is full, and passes it into subtreesHandler. A subtree that
waited there and then met a catchup was aged from the end of that wait, so a
replay could fetch it more than 30 minutes after receipt.
@icellan

icellan commented Oct 27, 2026

Copy link
Copy Markdown
Contributor Author

Fixed in be6d5a3.

  • subtreeHandler.go:102/:129: subtreeMessageHandler now takes receivedAt as soon as it receives a message, before the FSM check and before g.Go, which can block while the group is full. It passes that time into subtreesHandler, which uses it when recording the subtree for replay. subtreesHandler no longer reads the clock itself.
  • Regression: TestSubtreeMessageHandler_AnnouncementTimeIsBeforeHandlerGroupWait fills the handler group with subtrees blocked on a held admission slot. It then sends one more while RUNNING, waits 300 ms, switches to CATCHINGBLOCKS and checks the kept time against receipt. On e218573 it fails by exactly the 300 ms wait.

The full ./services/subtreevalidation/... suite passes under -race, the skipped-subtree tests pass 5x, and lint reports 0 new issues.

@sonarqubecloud

Copy link
Copy Markdown

@oskarszoon oskarszoon left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The handler-group receipt-time gap is fixed, and the new regression test fails when the timestamp is moved back after that wait. I found no remaining blocking issue at be6d5a33c.

@icellan
icellan merged commit 7cc6949 into bsv-blockchain:main Oct 27, 2026
38 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants