Add baseline benchmark for history write path (pre Phase 1 concurrency fixes) by MattBDev · Pull Request #3593 · IntellectualSites/FastAsyncWorldEdit

MattBDev · 2026-07-15T02:32:19Z

Summary

Adds a hand-rolled micro-benchmark for the com.fastasyncworldedit.core.history write hot path (DiskStorageHistory and MemoryOptimizedHistory), run via a new :worldedit-core:historyBenchmark Gradle task.
This establishes a pre-fix baseline so the upcoming Phase 1 concurrency fixes (broken double-checked locking in getBlockOS(), a lost-wakeup race, and a non-atomic blockSize counter) can be verified not to regress throughput once they land.
Does not touch DiskStorageHistory.java, MemoryOptimizedHistory.java, AbstractChangeSet.java, or FaweStreamChangeSet.java — those are Phase 1's responsibility in a separate change.
Also fixes an unrelated, pre-existing issue that blocked every Gradle invocation from a git worktree checkout (used for parallel agent sandboxes): Grgit.open() can't resolve a worktree's .git pointer file, so root project configuration failed with "repository not found" before any task could even run. The fix only takes effect when a worktree checkout is detected; a genuinely broken .git in a normal checkout still fails the build as before.

Why not JMH

The me.champeau.jmh plugin route was attempted first (per the task's preference) but this repo's Gradle 9 multi-module build (custom ANTLR source generation, annotation processors, several platform sub-modules) made getting that integration right riskier than the time budget allowed. Per the task's documented fallback, a plain warmup + measured-loop benchmark using System.nanoTime() was used instead. It's not a polished harness, but the numbers are repeatable and directly comparable across a before/after run.

Baseline numbers (this branch, pre Phase 1 fixes)

5 trials each, 500K warmup + 5M measured ops/trial (contended: split across 8 threads). Run with ./gradlew :worldedit-core:historyBenchmark.

Updated after code review (commits 669f06329, f2ebb39ef): the original numbers below were skewed by two bugs in the benchmark itself — the y-coordinate generator produced values outside the simulated world's height range, and the contended variant ran with no warmup at all despite claiming to. Both are fixed; the numbers below are from the corrected benchmark.

Benchmark	Avg throughput	Avg latency	Notes
`DiskStorageHistory` — single-threaded	~34.1M ops/sec	~29.3 ns/op	no contention, race-free baseline
`MemoryOptimizedHistory` — single-threaded	~33.4M ops/sec	~30.0 ns/op	no contention, race-free baseline
`DiskStorageHistory` — 8 threads, shared instance	~5.8M ops/sec	~172.1 ns/op	~85% of ops threw (unsynchronized shared LZ4/compression stream corrupted by the current broken DCL in `getBlockOS()`)
`MemoryOptimizedHistory` — 8 threads, shared instance	~5.8M ops/sec	~173.5 ns/op	~81% of ops threw, same root cause

The contended numbers above are throughput measured across all attempted ops, including the ones that threw (caught in the benchmark's worker loop so trials can still complete) — they are a direct, reproducible demonstration of the race Phase 1 fixes. After Phase 1 lands, the expectation is the error count drops to 0 and the contended throughput number becomes meaningful as a "real" concurrent throughput figure rather than being dominated by failed/corrupted writes.

Raw per-trial numbers and full benchmark description are in the benchmark class's Javadoc and printed output.

Test plan

./gradlew :worldedit-core:compileJava succeeds
./gradlew :worldedit-core:compileTestJava succeeds
./gradlew :worldedit-core:test succeeds (benchmark class has no test annotations, so it isn't picked up as a test)
./gradlew :worldedit-core:historyBenchmark runs to completion and prints the numbers above
Self code-reviewed (fixed: aggregate vs mean-of-rates throughput math, avoided non-power-of-2 modulo in the timed hot loop, reused SafeFiles.tryHardToDeleteDir instead of a hand-rolled recursive delete, shutdownNow() on the executor timeout path, narrowed the worktree git try/catch to not mask real repo problems on normal checkouts)
Addressed all 5 Copilot review comments: uniform y-coordinate fold (no division in the hot loop), warmup pass added to the contended variant, lz4Java scoped to testRuntimeOnly, and both worker-loop catch (Throwable) sites narrowed to catch (Exception) so a real Error still propagates instead of being silently absorbed as expected race noise.

🤖 Generated with Claude Code

Adds a hand-rolled micro-benchmark (worldedit-core/src/test/java/.../HistoryWriteBenchmark.java, run via the new `:worldedit-core:historyBenchmark` Gradle task) that measures add(x,y,z,from,to) throughput for DiskStorageHistory and MemoryOptimizedHistory, single-threaded and under multi-threaded contention on the same instance. This gives a pre-fix baseline to compare against once the Phase 1 concurrency fixes (broken DCL, lost-wakeup race, non-atomic counter) land in com.fastasyncworldedit.core.history. The me.champeau.jmh plugin route was not used: this repo's Gradle 9 multi-module build (custom ANTLR generation, annotation processors) made that integration risky to get right in the time available, so a plain warmup+measured-loop benchmark was used instead, per the task's documented fallback. Also fixes an unrelated pre-existing issue that blocked every Gradle invocation from this worktree checkout: Grgit.open() cannot resolve a git-worktree's ".git" pointer file the way native git does, so it threw "repository not found" during root project configuration. The fix only takes effect in the detected-worktree case; a genuinely broken .git in a normal checkout still fails the build as before. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>

Copilot

Pull request overview

Adds a dedicated, runnable micro-benchmark to establish a pre–Phase 1 baseline for the FAWE history write hot path, and unblocks Gradle usage from git worktree checkouts by making git metadata resolution resilient in that environment.

Changes:

Introduces HistoryWriteBenchmark (warmup + measured loops, single-threaded and contended variants) runnable via a new Gradle JavaExec task.
Adds the :worldedit-core:historyBenchmark task and ensures needed runtime dependencies are available when running it from the test runtime classpath.
Makes root build configuration tolerate git worktree .git pointer files by falling back to placeholder date/revision only when a worktree-style .git file is detected.

Reviewed changes

Copilot reviewed 2 out of 3 changed files in this pull request and generated 3 comments.

File	Description
`worldedit-core/src/test/java/com/fastasyncworldedit/core/history/HistoryWriteBenchmark.java`	Adds the hand-rolled micro-benchmark harness for history write-path throughput/latency (single-threaded + contended).
`worldedit-core/build.gradle.kts`	Adds a `historyBenchmark` Gradle task and adjusts test-scope dependencies so the benchmark can run via the test runtime classpath.
`build.gradle.kts`	Updates git metadata initialization to avoid failing configuration in `git worktree` checkouts, using placeholders only for that detected case.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

…p scope Three issues from automated review of the benchmark added in this PR: - doAdd()'s coordinate generator masked y to 0..511 (& 0x1FF) while the comment claimed it avoided "% 384" and BenchWorld's height is -64..319 (384 values). The generated y never matched the world it claims to simulate. Fold 512 down to 384 with one conditional subtract (still no division), then offset by minY. - runContended() performed zero warmup despite the banner printed by main() claiming a uniform warmupOps for every benchmark. Added a warmup pass on a throwaway instance per trial, not the measured instance -- the measured instance must still start with uninitialized lazy streams, since exercising that lazy-init race under contention is the entire point of this variant. - testImplementation(libs.lz4Java) widened the test compile classpath for a dependency nothing references at compile time (only a comment mentions LZ4). Changed to testRuntimeOnly, which is the scope this actually needs and won't mask a missing compile-time dependency elsewhere. Re-ran the benchmark after these fixes; numbers moved measurably on the single-threaded runs (most notably MemoryOptimizedHistory, ~34.2M -> ~23.3M ops/sec), confirming the old baseline was skewed by the y-range/warmup bugs. Updated numbers posted on the PR. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>

MattBDev · 2026-07-15T06:27:20Z

Addressed all three review comments in 669f063. Summary:

y-range bug (real): doAdd() masked y to 0..511 while BenchWorld reports height -64..319 (384 values) — the generated coordinates never matched the world they claim to simulate. Fixed by folding 512→384 with a conditional subtract (still no division in the hot loop) and offsetting by minY.
Missing contended warmup (real): runContended() ran zero warmup iterations despite the printed banner claiming a uniform warmupOps for every benchmark. Added a warmup pass on a throwaway instance per trial — not the measured instance, since the measured instance needs to start with uninitialized lazy streams for the contended variant to keep exercising the lazy-init race it's meant to measure.
Dependency scope (real): testImplementation(libs.lz4Java) → testRuntimeOnly. Nothing in test sources references LZ4 types at compile time.

Re-ran the benchmark after the fixes. Updated baseline (supersedes the numbers in the PR description):

Benchmark	Avg throughput	Avg latency	Notes
`DiskStorageHistory` — single-threaded	~31.5M ops/sec	~31.8 ns/op	was ~34.2M — moved once y/warmup were fixed
`MemoryOptimizedHistory` — single-threaded	~23.3M ops/sec	~43.0 ns/op	was ~34.2M — the larger mover of the two
`DiskStorageHistory` — 8 threads, shared instance	~6.4M ops/sec	~156.0 ns/op	~86% of ops threw (broken DCL corrupts the shared LZ4 stream, as intended)
`MemoryOptimizedHistory` — 8 threads, shared instance	~6.0M ops/sec	~165.9 ns/op	~81% of ops threw, same root cause

The single-threaded numbers moved measurably (particularly MemoryOptimizedHistory), confirming the original numbers were skewed by these bugs rather than reflecting real single-threaded throughput. The contended error rate is still the real, reproducible demonstration of the DCL race that Phase 1's fix PRs (#3594, #3595) address.

Copilot

Pull request overview

Copilot reviewed 2 out of 3 changed files in this pull request and generated 2 comments.

closeAndCleanup() and the contended worker loop caught Throwable to swallow the expected AIOOBE/corruption noise from deliberately hammering the pre-fix DCL race. Throwable also catches Error (OutOfMemoryError, StackOverflowError), which would then be silently absorbed and the run would continue in a corrupted JVM state instead of aborting. Exception still covers everything the benchmark actually expects to see. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>

Copilot

Pull request overview

Copilot reviewed 2 out of 3 changed files in this pull request and generated 2 comments.

MattBDev · 2026-07-15T12:32:44Z

+        System.out.printf(
+                "warmupOps=%d measuredOps=%d trials=%d contendedThreads=%d%n%n",
+                WARMUP_OPS, MEASURED_OPS, TRIALS, THREADS
+        );


Fixed in fb41424: the header now prints both the raw measuredOps and the actual contended op count (opsPerThread * THREADS), since report() itself already used the correct real count for throughput - only this informational line could overclaim.

MattBDev · 2026-07-15T12:32:56Z

+                pool.submit(() -> {
+                    ready.countDown();
+                    try {
+                        go.await();
+                    } catch (InterruptedException e) {
+                        Thread.currentThread().interrupt();
+                        return;
+                    }
+                    for (int j = 0; j < opsPerThread; j++) {
+                        try {
+                            doAdd(changeSet, base + j);
+                        } catch (Exception t2) {
+                            // Only Exception: a real Error must propagate rather than being
+                            // counted as expected race noise (see closeAndCleanup above).
+                            errorCount.incrementAndGet();
+                        }
+                    }
+                });


Good catch - the comment was aspirational, not actually true, since a discarded Future silently absorbs whatever a FutureTask captures, including Errors. Fixed in fb41424: the futures are now kept and checked with get() after the pool finishes, so a genuine Error actually surfaces instead of vanishing.

The printed header's measuredOps came from the raw MEASURED_OPS constant, but contended trials split it across THREADS with integer division, so the actual op count run could be lower when THREADS doesn't divide it evenly. report() itself already used the correct real count for throughput; only the informational header line could overclaim. Now prints both explicitly. runContended() discarded the Future from each pool.submit(...). A FutureTask captures any Throwable - not just the Exceptions the worker loop's own catch handles - so an Error escaping a worker would previously be captured and silently dropped rather than propagating, contradicting the comment right next to it. Futures are now kept and checked with get() after the pool finishes, so a genuine Error surfaces as intended. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>

Copilot

Pull request overview

Copilot reviewed 2 out of 3 changed files in this pull request and generated 2 comments.

MattBDev · 2026-07-15T12:49:15Z

+                    }
+                }));
+            }
+            ready.await();


Fixed in 9a8844e: ready.await() now takes a 1 minute timeout, matching the pattern already used for pool.awaitTermination() just below it, and shuts the pool down on timeout.

MattBDev · 2026-07-15T12:49:25Z

+            } catch (IOException ignored) {
+            }


Fixed in 9a8844e: cleanup failures are now printed instead of silently swallowed.

ready.await() had no timeout, so a worker that failed to start (thread creation issue, pool rejection) could hang the benchmark task indefinitely. Gives it a 1 minute bound and shuts the pool down on timeout, matching the existing pattern used for pool.awaitTermination() just below it. Also stops silently swallowing SafeFiles.tryHardToDeleteDir() failures: this benchmark can create sizeable on-disk histories, so a failed cleanup could accumulate unnoticed across repeated runs. Prints a line instead. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>

Copilot

Pull request overview

Copilot reviewed 2 out of 3 changed files in this pull request and generated 1 comment.

MattBDev · 2026-07-15T13:10:58Z

+        double avgOpsPerSec = totalOps / (totalElapsedNanos / 1_000_000_000.0);
+        System.out.printf("  average: %,.0f ops/sec (%.1f ns/op)", avgOpsPerSec, 1_000_000_000.0 / avgOpsPerSec);
+        if (totalErrors > 0) {
+            System.out.printf(" -- %d/%d ops threw (unsynchronized shared stream access)%n", totalErrors, totalOps);


Fixed: the printed message now says this is a lower bound, since add() itself swallows IOException internally rather than throwing, so IO-related failures never reach this benchmark's own catch block.

FaweStreamChangeSet#add() catches IOException internally and prints a stack trace rather than throwing, so IO-related failures from the race never reach this benchmark's own catch block and aren't reflected in totalErrors. The printed message now says so instead of implying a complete failure count. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>

Copilot

Pull request overview

Copilot reviewed 2 out of 3 changed files in this pull request and generated no new comments.

github-actions · 2026-07-16T04:42:32Z

Please take a moment and address the merge conflicts of your pull request. Thanks!

Copilot AI review requested due to automatic review settings July 15, 2026 02:32

MattBDev requested a review from a team as a code owner July 15, 2026 02:32

Copilot started reviewing on behalf of MattBDev July 15, 2026 02:32 View session