Skip to content

fix(blockassembly/subtreeprocessor): zero-guard validFromMillis in dequeueDuringBlockMovement#846

Merged
liam merged 1 commit into
bsv-blockchain:mainfrom
liam:liam/blockassembly-fix-zerowindow-drain
May 12, 2026
Merged

fix(blockassembly/subtreeprocessor): zero-guard validFromMillis in dequeueDuringBlockMovement#846
liam merged 1 commit into
bsv-blockchain:mainfrom
liam:liam/blockassembly-fix-zerowindow-drain

Conversation

@liam

@liam liam commented May 12, 2026

Copy link
Copy Markdown
Collaborator

Summary

Mirrors the Start-loop's zero-guard at dequeueDuringBlockMovement so DoubleSpendWindow == 0 disables the queue filter consistently across both call sites. Closes a same-millisecond admission gap that only manifests under the default config.

The bug

The Start-loop dequeue at SubtreeProcessor.go:810-813 zero-guards the calculation:

validFromMillis := int64(0)
if stp.settings.BlockAssembly.DoubleSpendWindow > 0 {
    validFromMillis = stp.clock.Now().Add(-stp.settings.BlockAssembly.DoubleSpendWindow).UnixMilli()
}

dequeueDuringBlockMovement (pre-fix :3789) skipped that guard and ran the calculation unconditionally:

validFromMillis := stp.clock.Now().Add(-1 * stp.settings.BlockAssembly.DoubleSpendWindow).UnixMilli()

At DoubleSpendWindow == 0 that yields clock.Now().UnixMilli() (> 0), which trips the queue filter at queue.go:96 (validFromMillis > 0 && time >= validFromMillis) and rejects any batch enqueued in the same millisecond as the drain.

DoubleSpendWindow defaults to 0 (settings/blockassembly_settings.go:29). Under the default config, a block-movement drain could miss fresh batches that the Start loop would have admitted, leaving them queued for the next iteration. The fix is one zero-guard, mirroring the Start loop verbatim.

This was characterized in #841 and is the asymmetry called out in that PR's "Latent finding" section.

Test changes

  • Test_zeroWindowAsymmetryTest_zeroWindowFormulasAgree - renamed and flipped the drain subtest to assert admission. The test now pins post-fix parity between the two formulas.
  • TestDequeueDuringBlockMovement_ZeroWindowAsymmetry...AdmitsSameMillisecond - flipped same_millisecond_batch_is_held_back to assert the batch drains. Kept the +1ms control subtest as a separate (now - window) cutoff smoke.
  • TestDequeueDuringBlockMovement_RejectsChildOfConflictingParent - replaced the time.Sleep(5 * time.Millisecond) workaround with the clock seam (both stp.clock and stp.queue.clock pin to the same instant). With the fix, the batch admits at window=0 and the conflicting-parent rejection path is exercised deterministically. No more wall-time wait.

Test plan

  • go vet ./services/blockassembly/... - clean
  • go test -race -count=1 ./services/blockassembly/subtreeprocessor/ - pass (164s)
  • go test -race -count=1 ./services/blockassembly/ - pass (101s)
  • BenchmarkQueue sanity (control plane, not hot path): 154-193 ns/op, in line with previous runs.

Notes

  • Production change: 5 added lines + 1 modified line in SubtreeProcessor.go, no API change, no new imports.
  • The fix is on a control-plane path (only runs during block movement) so it does not affect the hot tx-batching path.
  • Builds on test(blockassembly/subtreeprocessor): add clock seam for deterministic tests #841 (the clock seam) for test determinism; both characterization tests and the de-flaked race test use fixedClock to drive timestamps without time.Sleep.

…queueDuringBlockMovement

The Start-loop dequeue at SubtreeProcessor.go:810-813 zero-guards the
validFromMillis calculation so a DoubleSpendWindow of 0 disables the
queue filter entirely. dequeueDuringBlockMovement was missing the
guard and unconditionally computed clock.Now().Add(-1 * window), which
at window=0 yields clock.Now().UnixMilli(). The queue filter at
queue.go:96 ("validFromMillis > 0 && time >= validFromMillis") then
activated, holding back any batch enqueued in the same millisecond as
the drain.

DoubleSpendWindow defaults to 0 (settings/blockassembly_settings.go:29),
so under the default config a block-movement drain could miss
fresh batches that the Start loop would have admitted, leaving them
queued for the next iteration. Mirroring the Start-loop guard restores
parity between the two call sites.

Test changes:

* Test_zeroWindowAsymmetry → Test_zeroWindowFormulasAgree. Renamed and
  flipped the drain subtest to assert admission. Now pins post-fix
  parity instead of the pre-fix divergence.

* TestDequeueDuringBlockMovement_ZeroWindowAsymmetry → ...AdmitsSameMillisecond.
  Renamed and flipped same_millisecond_batch_is_held_back to assert
  the batch drains into the subtree. control_one_ms_advance subtest
  kept as a separate (now - window) cutoff smoke.

* TestDequeueDuringBlockMovement_RejectsChildOfConflictingParent:
  replaced the time.Sleep(5ms) workaround with the clock seam. Both
  stp.clock and stp.queue.clock pin to the same instant; the fix
  admits the batch at window=0 so the conflicting-parent rejection
  path is exercised deterministically.
@github-actions

github-actions Bot commented May 12, 2026

Copy link
Copy Markdown
Contributor

🤖 Claude Code Review

Status: Complete

Summary: No issues found. This is a well-executed bug fix with excellent test coverage.

Review:

The PR correctly resolves a control-flow asymmetry between two dequeue call sites. The implementation is solid:

  • Logic: The zero-guard mirrors the Start-loop formula exactly (SubtreeProcessor.go:810-813), achieving parity at DoubleSpendWindow=0. The queue filter at queue.go:96 short-circuits when validFromMillis == 0, which is the documented default behavior.

  • Tests: All three modified tests properly verify the fix. The renamed tests (Test_zeroWindowFormulasAgree, TestDequeueDuringBlockMovement_ZeroWindowAdmitsSameMillisecond) assert post-fix parity and now pass. The deterministic clock seam (test(blockassembly/subtreeprocessor): add clock seam for deterministic tests #841) eliminates the 5ms sleep workaround, improving test reliability.

  • Scope: Minimal diff (9 additions, 1 deletion in production code). Changes are confined to the control plane (block movement), so no impact on the hot batching path.

  • Documentation: Inline comment at SubtreeProcessor.go:3789-3793 clearly explains the zero-guard rationale and references the queue filter, which aids future maintainability.

The PR description thoroughly documents the bug, test changes, and verification steps. Test plan shows clean go vet, go test -race, and benchmark sanity checks.

@sonarqubecloud

Copy link
Copy Markdown

@github-actions

Copy link
Copy Markdown
Contributor

Benchmark Comparison Report

Baseline: main (unknown)

Current: PR-846 (4f53b8b)

Summary

  • Regressions: 0
  • Improvements: 0
  • Unchanged: 142
  • Significance level: p < 0.05
All benchmark results (sec/op)
Benchmark Baseline Current Change p-value
_NewBlockFromBytes-4 1.804µ 1.671µ ~ 0.100
SplitSyncedParentMap_SetIfNotExists/256_buckets-4 61.58n 61.67n ~ 0.400
SplitSyncedParentMap_SetIfNotExists/16_buckets-4 61.59n 61.53n ~ 0.700
SplitSyncedParentMap_SetIfNotExists/1_bucket-4 61.73n 61.66n ~ 0.200
SplitSyncedParentMap_ConcurrentSetIfNotExists/256_buckets... 32.22n 30.43n ~ 0.200
SplitSyncedParentMap_ConcurrentSetIfNotExists/16_buckets_... 54.21n 51.91n ~ 0.700
SplitSyncedParentMap_ConcurrentSetIfNotExists/1_bucket_pa... 107.3n 108.8n ~ 0.700
MiningCandidate_Stringify_Short-4 266.6n 263.3n ~ 0.100
MiningCandidate_Stringify_Long-4 1.921µ 1.903µ ~ 0.100
MiningSolution_Stringify-4 982.5n 978.9n ~ 0.400
BlockInfo_MarshalJSON-4 1.742µ 1.748µ ~ 0.600
NewFromBytes-4 130.0n 151.1n ~ 1.000
Mine_EasyDifficulty-4 60.64µ 61.04µ ~ 1.000
Mine_WithAddress-4 6.808µ 6.724µ ~ 0.700
DirectSubtreeAdd/4_per_subtree-4 61.83n 62.15n ~ 1.000
DirectSubtreeAdd/64_per_subtree-4 31.54n 28.87n ~ 0.100
DirectSubtreeAdd/256_per_subtree-4 30.27n 27.44n ~ 0.100
DirectSubtreeAdd/1024_per_subtree-4 29.06n 26.39n ~ 0.100
DirectSubtreeAdd/2048_per_subtree-4 28.63n 25.98n ~ 0.100
SubtreeProcessorAdd/4_per_subtree-4 288.3n 287.8n ~ 1.000
SubtreeProcessorAdd/64_per_subtree-4 282.4n 278.5n ~ 0.400
SubtreeProcessorAdd/256_per_subtree-4 281.3n 283.9n ~ 0.200
SubtreeProcessorAdd/1024_per_subtree-4 272.3n 274.9n ~ 0.100
SubtreeProcessorAdd/2048_per_subtree-4 271.6n 274.8n ~ 0.400
SubtreeProcessorRotate/4_per_subtree-4 277.2n 278.3n ~ 0.700
SubtreeProcessorRotate/64_per_subtree-4 279.6n 277.2n ~ 0.100
SubtreeProcessorRotate/256_per_subtree-4 274.4n 276.0n ~ 1.000
SubtreeProcessorRotate/1024_per_subtree-4 274.3n 276.6n ~ 0.100
SubtreeNodeAddOnly/4_per_subtree-4 54.87n 54.38n ~ 0.200
SubtreeNodeAddOnly/64_per_subtree-4 34.61n 34.46n ~ 0.700
SubtreeNodeAddOnly/256_per_subtree-4 33.65n 33.37n ~ 0.100
SubtreeNodeAddOnly/1024_per_subtree-4 32.81n 32.83n ~ 1.000
SubtreeCreationOnly/4_per_subtree-4 114.0n 114.6n ~ 0.700
SubtreeCreationOnly/64_per_subtree-4 408.1n 409.3n ~ 0.700
SubtreeCreationOnly/256_per_subtree-4 1.380µ 1.494µ ~ 0.700
SubtreeCreationOnly/1024_per_subtree-4 4.434µ 4.479µ ~ 0.400
SubtreeCreationOnly/2048_per_subtree-4 8.438µ 8.541µ ~ 0.700
SubtreeProcessorOverheadBreakdown/64_per_subtree-4 271.6n 279.0n ~ 0.200
SubtreeProcessorOverheadBreakdown/1024_per_subtree-4 275.8n 281.7n ~ 0.700
ParallelGetAndSetIfNotExists/1k_nodes-4 609.0µ 608.2µ ~ 1.000
ParallelGetAndSetIfNotExists/10k_nodes-4 1.359m 1.489m ~ 0.700
ParallelGetAndSetIfNotExists/50k_nodes-4 6.801m 7.081m ~ 0.100
ParallelGetAndSetIfNotExists/100k_nodes-4 13.88m 13.99m ~ 0.100
SequentialGetAndSetIfNotExists/1k_nodes-4 689.3µ 698.0µ ~ 0.700
SequentialGetAndSetIfNotExists/10k_nodes-4 2.929m 3.372m ~ 0.100
SequentialGetAndSetIfNotExists/50k_nodes-4 10.89m 11.33m ~ 0.100
SequentialGetAndSetIfNotExists/100k_nodes-4 20.82m 20.66m ~ 0.400
ProcessOwnBlockSubtreeNodesParallel/1k_nodes-4 648.2µ 651.3µ ~ 0.700
ProcessOwnBlockSubtreeNodesParallel/10k_nodes-4 4.428m 4.219m ~ 0.100
ProcessOwnBlockSubtreeNodesParallel/100k_nodes-4 17.27m 17.00m ~ 0.100
ProcessOwnBlockSubtreeNodesSequential/1k_nodes-4 728.1µ 714.6µ ~ 0.400
ProcessOwnBlockSubtreeNodesSequential/10k_nodes-4 6.827m 5.929m ~ 0.100
ProcessOwnBlockSubtreeNodesSequential/100k_nodes-4 44.03m 38.46m ~ 0.100
BlockAssembler_AddTx-4 0.02747n 0.02871n ~ 0.400
AddNode-4 11.21 10.75 ~ 0.700
AddNodeWithMap-4 10.25 11.40 ~ 0.200
DiskTxMap_SetIfNotExists-4 3.682µ 3.830µ ~ 0.700
DiskTxMap_SetIfNotExists_Parallel-4 3.486µ 3.638µ ~ 0.100
DiskTxMap_ExistenceOnly-4 316.1n 319.3n ~ 1.000
Queue-4 195.4n 204.6n ~ 0.200
AtomicPointer-4 3.742n 3.256n ~ 0.100
ReorgOptimizations/DedupFilterPipeline/Old/10K-4 828.4µ 816.3µ ~ 0.100
ReorgOptimizations/DedupFilterPipeline/New/10K-4 791.5µ 796.1µ ~ 0.700
ReorgOptimizations/AllMarkFalse/Old/10K-4 113.2µ 123.0µ ~ 0.100
ReorgOptimizations/AllMarkFalse/New/10K-4 64.49µ 64.39µ ~ 1.000
ReorgOptimizations/HashSlicePool/Old/10K-4 62.92µ 68.91µ ~ 0.100
ReorgOptimizations/HashSlicePool/New/10K-4 11.48µ 11.29µ ~ 0.200
ReorgOptimizations/NodeFlags/Old/10K-4 5.214µ 5.462µ ~ 0.200
ReorgOptimizations/NodeFlags/New/10K-4 1.826µ 1.939µ ~ 0.200
ReorgOptimizations/DedupFilterPipeline/Old/100K-4 9.263m 10.085m ~ 0.100
ReorgOptimizations/DedupFilterPipeline/New/100K-4 9.782m 9.508m ~ 1.000
ReorgOptimizations/AllMarkFalse/Old/100K-4 1.180m 1.158m ~ 0.700
ReorgOptimizations/AllMarkFalse/New/100K-4 706.6µ 706.1µ ~ 1.000
ReorgOptimizations/HashSlicePool/Old/100K-4 615.0µ 624.6µ ~ 0.700
ReorgOptimizations/HashSlicePool/New/100K-4 196.8µ 197.7µ ~ 1.000
ReorgOptimizations/NodeFlags/Old/100K-4 54.30µ 53.83µ ~ 1.000
ReorgOptimizations/NodeFlags/New/100K-4 19.13µ 18.52µ ~ 0.100
TxMapSetIfNotExists-4 46.23n 46.35n ~ 1.000
TxMapSetIfNotExistsDuplicate-4 38.67n 38.88n ~ 0.600
ChannelSendReceive-4 623.7n 580.6n ~ 0.100
CalcBlockWork-4 506.4n 505.9n ~ 1.000
CalculateWork-4 704.1n 701.6n ~ 0.700
BuildBlockLocatorString_Helpers/Size_10-4 1.323µ 1.412µ ~ 0.100
BuildBlockLocatorString_Helpers/Size_100-4 13.08µ 13.67µ ~ 1.000
BuildBlockLocatorString_Helpers/Size_1000-4 126.0µ 168.7µ ~ 0.200
CatchupWithHeaderCache-4 104.3m 104.4m ~ 0.700
_BufferPoolAllocation/16KB-4 3.327µ 3.457µ ~ 0.100
_BufferPoolAllocation/32KB-4 7.459µ 8.234µ ~ 1.000
_BufferPoolAllocation/64KB-4 15.46µ 16.48µ ~ 0.400
_BufferPoolAllocation/128KB-4 31.89µ 28.31µ ~ 0.100
_BufferPoolAllocation/512KB-4 104.6µ 118.0µ ~ 0.100
_BufferPoolConcurrent/32KB-4 17.84µ 19.41µ ~ 0.100
_BufferPoolConcurrent/64KB-4 28.30µ 30.86µ ~ 0.100
_BufferPoolConcurrent/512KB-4 142.3µ 148.3µ ~ 0.100
_SubtreeDeserializationWithBufferSizes/16KB-4 666.5µ 637.0µ ~ 0.100
_SubtreeDeserializationWithBufferSizes/32KB-4 655.5µ 629.1µ ~ 0.100
_SubtreeDeserializationWithBufferSizes/64KB-4 656.7µ 634.2µ ~ 0.100
_SubtreeDeserializationWithBufferSizes/128KB-4 660.9µ 629.2µ ~ 0.100
_SubtreeDeserializationWithBufferSizes/512KB-4 673.4µ 645.6µ ~ 0.100
_SubtreeDataDeserializationWithBufferSizes/16KB-4 35.53m 35.74m ~ 0.100
_SubtreeDataDeserializationWithBufferSizes/32KB-4 35.55m 35.68m ~ 0.700
_SubtreeDataDeserializationWithBufferSizes/64KB-4 35.52m 35.72m ~ 0.200
_SubtreeDataDeserializationWithBufferSizes/128KB-4 35.47m 35.22m ~ 0.400
_SubtreeDataDeserializationWithBufferSizes/512KB-4 35.15m 35.42m ~ 0.700
_PooledVsNonPooled/Pooled-4 736.4n 737.1n ~ 0.800
_PooledVsNonPooled/NonPooled-4 7.149µ 6.774µ ~ 0.700
_MemoryFootprint/Current_512KB_32concurrent-4 6.674µ 6.751µ ~ 0.400
_MemoryFootprint/Proposed_32KB_32concurrent-4 9.059µ 9.992µ ~ 0.100
_MemoryFootprint/Alternative_64KB_32concurrent-4 8.797µ 9.441µ ~ 0.100
SubtreeSizes/10k_tx_4_per_subtree-4 1.567m 1.601m ~ 0.700
SubtreeSizes/10k_tx_16_per_subtree-4 361.1µ 381.9µ ~ 0.100
SubtreeSizes/10k_tx_64_per_subtree-4 86.51µ 91.79µ ~ 0.100
SubtreeSizes/10k_tx_256_per_subtree-4 21.06µ 22.93µ ~ 0.100
SubtreeSizes/10k_tx_512_per_subtree-4 10.52µ 11.31µ ~ 0.100
SubtreeSizes/10k_tx_1024_per_subtree-4 5.212µ 5.584µ ~ 0.100
SubtreeSizes/10k_tx_2k_per_subtree-4 2.707µ 2.841µ ~ 0.100
BlockSizeScaling/10k_tx_64_per_subtree-4 85.96µ 88.88µ ~ 0.100
BlockSizeScaling/10k_tx_256_per_subtree-4 21.60µ 22.87µ ~ 0.100
BlockSizeScaling/10k_tx_1024_per_subtree-4 5.383µ 5.617µ ~ 0.100
BlockSizeScaling/50k_tx_64_per_subtree-4 451.7µ 452.9µ ~ 1.000
BlockSizeScaling/50k_tx_256_per_subtree-4 109.3µ 109.8µ ~ 0.400
BlockSizeScaling/50k_tx_1024_per_subtree-4 26.75µ 26.81µ ~ 1.000
SubtreeAllocations/small_subtrees_exists_check-4 177.8µ 175.1µ ~ 1.000
SubtreeAllocations/small_subtrees_data_fetch-4 189.6µ 192.9µ ~ 0.700
SubtreeAllocations/small_subtrees_full_validation-4 375.2µ 377.3µ ~ 0.700
SubtreeAllocations/medium_subtrees_exists_check-4 10.69µ 10.55µ ~ 0.700
SubtreeAllocations/medium_subtrees_data_fetch-4 11.19µ 11.28µ ~ 0.700
SubtreeAllocations/medium_subtrees_full_validation-4 21.40µ 21.66µ ~ 0.200
SubtreeAllocations/large_subtrees_exists_check-4 2.540µ 2.549µ ~ 1.000
SubtreeAllocations/large_subtrees_data_fetch-4 2.768µ 2.774µ ~ 1.000
SubtreeAllocations/large_subtrees_full_validation-4 5.597µ 5.450µ ~ 0.100
_prepareTxsPerLevel-4 408.1m 403.9m ~ 0.200
_prepareTxsPerLevelOrdered-4 4.286m 3.709m ~ 0.100
_prepareTxsPerLevel_Comparison/Original-4 407.2m 402.2m ~ 0.400
_prepareTxsPerLevel_Comparison/Optimized-4 3.576m 3.502m ~ 0.400
StoreBlock_Sequential/BelowCSVHeight-4 335.6µ 337.2µ ~ 0.700
StoreBlock_Sequential/AboveCSVHeight-4 342.5µ 334.0µ ~ 0.100
GetUtxoHashes-4 252.1n 254.6n ~ 0.700
GetUtxoHashes_ManyOutputs-4 49.03µ 48.77µ ~ 1.000
_NewMetaDataFromBytes-4 234.4n 233.2n ~ 0.100
_Bytes-4 618.7n 620.4n ~ 0.100
_MetaBytes-4 570.8n 571.6n ~ 0.700

Threshold: >10% with p < 0.05 | Generated: 2026-05-12 08:47 UTC

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.

3 participants