Skip to content

test(blockassembly/subtreeprocessor): add clock seam for deterministic tests#841

Merged
liam merged 3 commits into
bsv-blockchain:mainfrom
liam:liam/blockassembly-queue-clock-seam
May 11, 2026
Merged

test(blockassembly/subtreeprocessor): add clock seam for deterministic tests#841
liam merged 3 commits into
bsv-blockchain:mainfrom
liam:liam/blockassembly-queue-clock-seam

Conversation

@liam

@liam liam commented May 11, 2026

Copy link
Copy Markdown
Collaborator

Summary

Introduces an unexported clock interface in services/blockassembly/subtreeprocessor, injected into LockFreeQueue and SubtreeProcessor. The production default is realClock{} (calls time.Now()); tests install a fake to drive deterministic timestamps without time.Sleep.

Three time.Now() call sites are now mediated by the seam:

  • queue.go:63 - batch.time on enqueue
  • SubtreeProcessor.go:812 - validFromMillis in the Start-loop dequeue
  • SubtreeProcessor.go:3789 - validFromMillis in dequeueDuringBlockMovement

Five new tests / nine subtests in queue_test.go and conflicting_queue_race_test.go use the seam to characterize the queue's validFromMillis filter at queue.go:96 (boundary semantics, negative-cutoff bypass, clock-backstep behaviour, and the asymmetry between the two validFromMillis formulas at DoubleSpendWindow=0).

Motivation

blockassembly has time-dependent correctness logic gated by DoubleSpendWindow. The existing test workaround for this is time.Sleep (conflicting_queue_race_test.go:75 sleeps 5ms before calling dequeueDuringBlockMovement). A clock seam replaces wall-time waits with deterministic time, which is the prerequisite for any property/invariant testing of reorgs and drain ordering.

Perf gate

The hot path is LockFreeQueue.enqueueBatch (one timestamp per batch, called from every producer). Benchmarked on this machine with -count=30 -benchtime=10s before merging, and again same-day same-machine after the SubtreeProcessor seam was added:

baseline (main) with seam
BenchmarkQueue 170.4n ± 2% 170.3n ± 2%
p-value - 0.566 (n=10)

No measurable regression. Interface dispatch at the timestamp call is free here.

Latent finding (not addressed in this PR)

While writing the characterization tests, the two validFromMillis formulas diverge at DoubleSpendWindow == 0 (the documented default):

  • Start loop (:807-813) - zero-guarded: validFromMillis = 0 → queue filter off.
  • dequeueDuringBlockMovement (:3789) - unconditional: validFromMillis = Now().UnixMilli() → filter active, rejects same-ms batches.

conflicting_queue_race_test.go:71-75 papers over this with a 5ms sleep. The tests in this PR pin the current (asymmetric) behaviour. I'll open a follow-up to align the drain formula with the Start-loop zero-guard once this seam lands.

Test plan

  • go vet ./services/blockassembly/subtreeprocessor/ - clean
  • go test -race -count=1 ./services/blockassembly/subtreeprocessor/ - pass (153s)
  • go test -race -count=1 ./services/blockassembly/ - pass (102s)
  • Benchmark gate above (n=30 × 10s, then n=10 × 10s same-day re-check)
  • CI: staticcheck and golangci-lint are pinned to Go 1.25.5 locally vs the repo's Go 1.26.0 toolchain - pre-existing tooling mismatch, expecting CI to run clean.

liam added 3 commits May 8, 2026 10:54
Adds an unexported queueClock seam on LockFreeQueue so tests can stamp
batches with a controlled time. Default is realQueueClock{} which calls
time.Now(); production behaviour is unchanged.

Verified zero-cost on the per-batch ingestion hot path (queue.go) via
BenchmarkQueue with -benchtime=10s -count=30: +0.5 ns/op, p=0.625 -
indistinguishable from noise.
…cessor

Promotes the clock interface to a package-level type (clock / realClock,
replacing queue-local queueClock / realQueueClock) and threads it through
SubtreeProcessor so the two validFromMillis calculations - in the Start
dequeue loop and in dequeueDuringBlockMovement - read through stp.clock.

Tests can now install one fake clock and have both batch timestamps
(LockFreeQueue) and DoubleSpendWindow boundary calculations honour it.

No behaviour change in production. Verified zero-cost on BenchmarkQueue
same-day same-machine: 170.4n -> 170.3n, p=0.566 (n=10 x 10s).
Use the new clock seam to characterize the queue's validFromMillis filter
deterministically, without time.Sleep. Five tests / nine subtests pin:

  * Start-loop vs dequeueDuringBlockMovement asymmetry at
    DoubleSpendWindow=0 (default). The Start loop's zero-guard
    short-circuits the filter; the drain formula does not, so
    same-millisecond batches get held back during block-movement drains.
    Pinned at the formula level (queue_test.go) and at the real call
    site (conflicting_queue_race_test.go) with a +1ms control case
    that mirrors the existing time.Sleep(5ms) workaround at
    conflicting_queue_race_test.go:75 deterministically.

  * Inclusive-reject semantics at batch.time == validFromMillis, and
    admission one millisecond below the boundary.

  * Negative validFromMillis short-circuits the > 0 guard and disables
    filtering. Dormant in production (Now().UnixMilli() is in the
    trillions) but worth pinning so a future caller or test built on
    time.Time{} does not silently lose double-spend protection.

  * Clock-backward jump under NTP correction holds batches until the
    drain clock recovers past batch.time + window.
@github-actions

github-actions Bot commented May 11, 2026

Copy link
Copy Markdown
Contributor

🤖 Claude Code Review

Status: Complete

Current Review:
No issues found. This is a clean implementation of a clock seam for deterministic testing with excellent test coverage and documentation.

Summary:
The PR introduces an unexported clock interface to enable deterministic testing of time-dependent logic in block assembly. The implementation is minimal, well-documented, and includes comprehensive characterization tests that pin the current behavior around validFromMillis filtering, including the documented asymmetry between the Start loop and dequeueDuringBlockMovement at DoubleSpendWindow=0.

Strengths:

  • Zero-allocation clock seam (interface dispatch is free on the hot path per benchmark data)
  • Comprehensive test coverage documenting boundary conditions, edge cases (clock backstep), and the intentional asymmetry
  • Tests replace time.Sleep with deterministic time control
  • Excellent documentation explaining the "why" behind the tests

@github-actions

Copy link
Copy Markdown
Contributor

Benchmark Comparison Report

Baseline: main (unknown)

Current: PR-841 (c45f17b)

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.546µ 1.559µ ~ 0.400
SplitSyncedParentMap_SetIfNotExists/256_buckets-4 71.50n 71.43n ~ 0.700
SplitSyncedParentMap_SetIfNotExists/16_buckets-4 71.20n 71.06n ~ 0.100
SplitSyncedParentMap_SetIfNotExists/1_bucket-4 70.96n 71.11n ~ 0.400
SplitSyncedParentMap_ConcurrentSetIfNotExists/256_buckets... 33.12n 32.82n ~ 1.000
SplitSyncedParentMap_ConcurrentSetIfNotExists/16_buckets_... 55.78n 54.77n ~ 0.200
SplitSyncedParentMap_ConcurrentSetIfNotExists/1_bucket_pa... 125.3n 127.0n ~ 0.100
MiningCandidate_Stringify_Short-4 217.2n 220.4n ~ 0.400
MiningCandidate_Stringify_Long-4 1.630µ 1.633µ ~ 0.300
MiningSolution_Stringify-4 864.1n 855.9n ~ 0.400
BlockInfo_MarshalJSON-4 1.714µ 1.729µ ~ 0.200
NewFromBytes-4 129.9n 163.1n ~ 0.200
Mine_EasyDifficulty-4 71.03µ 66.92µ ~ 0.100
Mine_WithAddress-4 7.213µ 6.997µ ~ 0.100
BlockAssembler_AddTx-4 0.03034n 0.03149n ~ 1.000
AddNode-4 10.90 11.31 ~ 0.400
AddNodeWithMap-4 11.03 11.66 ~ 0.100
DiskTxMap_SetIfNotExists-4 3.957µ 3.922µ ~ 0.400
DiskTxMap_SetIfNotExists_Parallel-4 3.696µ 3.718µ ~ 0.400
DiskTxMap_ExistenceOnly-4 617.6n 513.6n ~ 0.700
Queue-4 197.0n 199.0n ~ 1.000
AtomicPointer-4 3.683n 3.643n ~ 0.200
ReorgOptimizations/DedupFilterPipeline/Old/10K-4 960.2µ 812.1µ ~ 0.100
ReorgOptimizations/DedupFilterPipeline/New/10K-4 812.8µ 798.1µ ~ 0.200
ReorgOptimizations/AllMarkFalse/Old/10K-4 117.1µ 114.0µ ~ 0.700
ReorgOptimizations/AllMarkFalse/New/10K-4 64.77µ 64.98µ ~ 1.000
ReorgOptimizations/HashSlicePool/Old/10K-4 66.22µ 57.65µ ~ 1.000
ReorgOptimizations/HashSlicePool/New/10K-4 11.13µ 11.23µ ~ 0.200
ReorgOptimizations/NodeFlags/Old/10K-4 5.611µ 5.159µ ~ 0.100
ReorgOptimizations/NodeFlags/New/10K-4 2.073µ 1.760µ ~ 0.100
ReorgOptimizations/DedupFilterPipeline/Old/100K-4 11.04m 11.23m ~ 0.700
ReorgOptimizations/DedupFilterPipeline/New/100K-4 9.667m 10.348m ~ 0.100
ReorgOptimizations/AllMarkFalse/Old/100K-4 1.212m 1.120m ~ 0.700
ReorgOptimizations/AllMarkFalse/New/100K-4 706.6µ 705.9µ ~ 1.000
ReorgOptimizations/HashSlicePool/Old/100K-4 605.6µ 578.4µ ~ 0.100
ReorgOptimizations/HashSlicePool/New/100K-4 201.3µ 199.4µ ~ 0.700
ReorgOptimizations/NodeFlags/Old/100K-4 52.68µ 51.07µ ~ 0.700
ReorgOptimizations/NodeFlags/New/100K-4 18.37µ 19.08µ ~ 0.400
TxMapSetIfNotExists-4 46.36n 46.36n ~ 1.000
TxMapSetIfNotExistsDuplicate-4 38.69n 38.96n ~ 0.100
ChannelSendReceive-4 574.0n 612.7n ~ 0.100
DirectSubtreeAdd/4_per_subtree-4 75.50n 73.92n ~ 0.400
DirectSubtreeAdd/64_per_subtree-4 41.47n 42.49n ~ 1.000
DirectSubtreeAdd/256_per_subtree-4 40.24n 40.15n ~ 1.000
DirectSubtreeAdd/1024_per_subtree-4 38.73n 38.67n ~ 0.400
DirectSubtreeAdd/2048_per_subtree-4 38.58n 38.42n ~ 0.300
SubtreeProcessorAdd/4_per_subtree-4 328.8n 326.6n ~ 1.000
SubtreeProcessorAdd/64_per_subtree-4 317.9n 323.1n ~ 0.100
SubtreeProcessorAdd/256_per_subtree-4 318.7n 319.0n ~ 1.000
SubtreeProcessorAdd/1024_per_subtree-4 312.3n 308.2n ~ 0.100
SubtreeProcessorAdd/2048_per_subtree-4 315.3n 310.4n ~ 0.100
SubtreeProcessorRotate/4_per_subtree-4 313.6n 310.8n ~ 0.700
SubtreeProcessorRotate/64_per_subtree-4 312.1n 312.4n ~ 1.000
SubtreeProcessorRotate/256_per_subtree-4 312.3n 313.1n ~ 1.000
SubtreeProcessorRotate/1024_per_subtree-4 315.6n 315.0n ~ 1.000
SubtreeNodeAddOnly/4_per_subtree-4 89.01n 88.61n ~ 0.100
SubtreeNodeAddOnly/64_per_subtree-4 65.46n 65.15n ~ 0.200
SubtreeNodeAddOnly/256_per_subtree-4 64.52n 64.22n ~ 0.200
SubtreeNodeAddOnly/1024_per_subtree-4 63.91n 63.67n ~ 0.200
SubtreeCreationOnly/4_per_subtree-4 146.6n 147.5n ~ 0.700
SubtreeCreationOnly/64_per_subtree-4 546.2n 556.7n ~ 1.000
SubtreeCreationOnly/256_per_subtree-4 1.993µ 1.960µ ~ 0.700
SubtreeCreationOnly/1024_per_subtree-4 6.301µ 6.313µ ~ 0.700
SubtreeCreationOnly/2048_per_subtree-4 11.57µ 11.57µ ~ 0.700
SubtreeProcessorOverheadBreakdown/64_per_subtree-4 310.5n 312.6n ~ 1.000
SubtreeProcessorOverheadBreakdown/1024_per_subtree-4 314.3n 311.6n ~ 1.000
ParallelGetAndSetIfNotExists/1k_nodes-4 665.9µ 663.8µ ~ 1.000
ParallelGetAndSetIfNotExists/10k_nodes-4 1.749m 1.762m ~ 1.000
ParallelGetAndSetIfNotExists/50k_nodes-4 8.733m 9.050m ~ 0.100
ParallelGetAndSetIfNotExists/100k_nodes-4 17.60m 18.31m ~ 0.100
SequentialGetAndSetIfNotExists/1k_nodes-4 695.9µ 686.4µ ~ 0.400
SequentialGetAndSetIfNotExists/10k_nodes-4 3.375m 3.259m ~ 0.400
SequentialGetAndSetIfNotExists/50k_nodes-4 12.40m 12.39m ~ 0.700
SequentialGetAndSetIfNotExists/100k_nodes-4 24.05m 23.53m ~ 0.100
ProcessOwnBlockSubtreeNodesParallel/1k_nodes-4 738.0µ 720.6µ ~ 0.200
ProcessOwnBlockSubtreeNodesParallel/10k_nodes-4 4.739m 4.714m ~ 0.700
ProcessOwnBlockSubtreeNodesParallel/100k_nodes-4 21.84m 21.88m ~ 0.400
ProcessOwnBlockSubtreeNodesSequential/1k_nodes-4 761.8µ 760.3µ ~ 0.700
ProcessOwnBlockSubtreeNodesSequential/10k_nodes-4 7.122m 7.440m ~ 0.400
ProcessOwnBlockSubtreeNodesSequential/100k_nodes-4 47.14m 48.89m ~ 0.100
CalcBlockWork-4 496.2n 498.9n ~ 0.700
CalculateWork-4 681.1n 676.1n ~ 0.200
BuildBlockLocatorString_Helpers/Size_10-4 1.016µ 1.016µ ~ 0.700
BuildBlockLocatorString_Helpers/Size_100-4 9.785µ 9.769µ ~ 0.700
BuildBlockLocatorString_Helpers/Size_1000-4 114.7µ 116.4µ ~ 0.700
CatchupWithHeaderCache-4 103.7m 103.7m ~ 0.700
_BufferPoolAllocation/16KB-4 3.559µ 3.552µ ~ 1.000
_BufferPoolAllocation/32KB-4 7.430µ 8.439µ ~ 0.400
_BufferPoolAllocation/64KB-4 16.61µ 18.54µ ~ 0.100
_BufferPoolAllocation/128KB-4 31.59µ 29.98µ ~ 0.100
_BufferPoolAllocation/512KB-4 110.4µ 111.4µ ~ 0.400
_BufferPoolConcurrent/32KB-4 17.60µ 19.35µ ~ 0.100
_BufferPoolConcurrent/64KB-4 28.24µ 28.10µ ~ 0.700
_BufferPoolConcurrent/512KB-4 148.2µ 140.8µ ~ 0.200
_SubtreeDeserializationWithBufferSizes/16KB-4 624.5µ 603.0µ ~ 0.100
_SubtreeDeserializationWithBufferSizes/32KB-4 620.4µ 623.9µ ~ 0.100
_SubtreeDeserializationWithBufferSizes/64KB-4 619.6µ 616.5µ ~ 1.000
_SubtreeDeserializationWithBufferSizes/128KB-4 620.2µ 623.9µ ~ 1.000
_SubtreeDeserializationWithBufferSizes/512KB-4 616.4µ 627.2µ ~ 0.100
_SubtreeDataDeserializationWithBufferSizes/16KB-4 35.49m 35.74m ~ 0.400
_SubtreeDataDeserializationWithBufferSizes/32KB-4 36.14m 35.88m ~ 0.400
_SubtreeDataDeserializationWithBufferSizes/64KB-4 35.77m 35.70m ~ 1.000
_SubtreeDataDeserializationWithBufferSizes/128KB-4 35.97m 36.57m ~ 0.400
_SubtreeDataDeserializationWithBufferSizes/512KB-4 35.55m 36.04m ~ 0.100
_PooledVsNonPooled/Pooled-4 739.3n 743.0n ~ 0.700
_PooledVsNonPooled/NonPooled-4 7.015µ 6.687µ ~ 0.100
_MemoryFootprint/Current_512KB_32concurrent-4 6.708µ 6.717µ ~ 1.000
_MemoryFootprint/Proposed_32KB_32concurrent-4 9.623µ 9.596µ ~ 0.700
_MemoryFootprint/Alternative_64KB_32concurrent-4 9.464µ 8.860µ ~ 0.100
_prepareTxsPerLevel-4 401.2m 402.3m ~ 1.000
_prepareTxsPerLevelOrdered-4 3.486m 3.507m ~ 0.700
_prepareTxsPerLevel_Comparison/Original-4 403.8m 400.0m ~ 0.700
_prepareTxsPerLevel_Comparison/Optimized-4 3.476m 3.600m ~ 0.100
SubtreeSizes/10k_tx_4_per_subtree-4 1.409m 1.382m ~ 0.100
SubtreeSizes/10k_tx_16_per_subtree-4 322.2µ 323.0µ ~ 1.000
SubtreeSizes/10k_tx_64_per_subtree-4 78.93µ 78.38µ ~ 0.200
SubtreeSizes/10k_tx_256_per_subtree-4 19.86µ 19.80µ ~ 1.000
SubtreeSizes/10k_tx_512_per_subtree-4 9.707µ 9.782µ ~ 0.200
SubtreeSizes/10k_tx_1024_per_subtree-4 4.776µ 4.785µ ~ 0.700
SubtreeSizes/10k_tx_2k_per_subtree-4 2.426µ 2.443µ ~ 1.000
BlockSizeScaling/10k_tx_64_per_subtree-4 77.68µ 76.50µ ~ 0.100
BlockSizeScaling/10k_tx_256_per_subtree-4 19.53µ 19.78µ ~ 0.400
BlockSizeScaling/10k_tx_1024_per_subtree-4 4.826µ 4.889µ ~ 0.100
BlockSizeScaling/50k_tx_64_per_subtree-4 395.9µ 386.7µ ~ 0.400
BlockSizeScaling/50k_tx_256_per_subtree-4 96.27µ 95.77µ ~ 1.000
BlockSizeScaling/50k_tx_1024_per_subtree-4 23.94µ 24.11µ ~ 0.700
SubtreeAllocations/small_subtrees_exists_check-4 158.3µ 160.8µ ~ 0.100
SubtreeAllocations/small_subtrees_data_fetch-4 165.5µ 165.9µ ~ 0.700
SubtreeAllocations/small_subtrees_full_validation-4 320.1µ 321.4µ ~ 1.000
SubtreeAllocations/medium_subtrees_exists_check-4 9.684µ 9.724µ ~ 1.000
SubtreeAllocations/medium_subtrees_data_fetch-4 10.35µ 10.31µ ~ 0.700
SubtreeAllocations/medium_subtrees_full_validation-4 19.92µ 19.82µ ~ 0.200
SubtreeAllocations/large_subtrees_exists_check-4 2.379µ 2.392µ ~ 0.100
SubtreeAllocations/large_subtrees_data_fetch-4 2.538µ 2.597µ ~ 0.100
SubtreeAllocations/large_subtrees_full_validation-4 4.995µ 4.974µ ~ 1.000
StoreBlock_Sequential/BelowCSVHeight-4 322.8µ 316.0µ ~ 0.400
StoreBlock_Sequential/AboveCSVHeight-4 324.4µ 326.2µ ~ 1.000
GetUtxoHashes-4 256.4n 254.6n ~ 0.700
GetUtxoHashes_ManyOutputs-4 49.32µ 49.02µ ~ 0.100
_NewMetaDataFromBytes-4 237.0n 234.6n ~ 0.300
_Bytes-4 642.2n 636.0n ~ 0.200
_MetaBytes-4 588.7n 589.3n ~ 1.000

Threshold: >10% with p < 0.05 | Generated: 2026-05-11 11:51 UTC

@sonarqubecloud

Copy link
Copy Markdown

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