diff --git a/build.gradle.kts b/build.gradle.kts index 328fc55282..d6d455a240 100644 --- a/build.gradle.kts +++ b/build.gradle.kts @@ -18,11 +18,28 @@ var revision: String by extra("") var buildNumber by extra("") var date: String by extra("") ext { - val git: Grgit = Grgit.open { - dir = File("$rootDir/.git") + // In a `git worktree` checkout (used e.g. by parallel agent sandboxes), `.git` is a pointer + // file rather than the git directory itself, and JGit (used by Grgit) does not resolve the + // worktree's `commondir` indirection the way native git does, so Grgit.open() throws even + // though `git` commands work fine in the same directory. Fall back to placeholder date/ + // revision values in that case (these are informational only, used in fawe.properties/ + // version string) - but only in the detected-worktree case, so a genuinely broken .git in a + // normal checkout still fails the build loudly instead of silently shipping "no.git.id". + val isWorktreeCheckout = File("$rootDir/.git").isFile + try { + val git: Grgit = Grgit.open { + dir = File("$rootDir/.git") + } + date = git.head().dateTime.format(DateTimeFormatter.ofPattern("yy.MM.dd")) + revision = "-${git.head().abbreviatedId}" + } catch (e: Exception) { + if (!isWorktreeCheckout) { + throw e + } + logger.warn("Error opening git repository for date/revision (worktree checkout); using placeholders", e) + date = DateTimeFormatter.ofPattern("yy.MM.dd").format(java.time.LocalDate.now()) + revision = "-no.git.id" } - date = git.head().dateTime.format(DateTimeFormatter.ofPattern("yy.MM.dd")) - revision = "-${git.head().abbreviatedId}" buildNumber = if (project.hasProperty("buildnumber")) { snapshot + "-" + project.properties["buildnumber"] as String } else { diff --git a/worldedit-core/build.gradle.kts b/worldedit-core/build.gradle.kts index dba8ca0823..aaefaf541a 100644 --- a/worldedit-core/build.gradle.kts +++ b/worldedit-core/build.gradle.kts @@ -62,6 +62,22 @@ dependencies { // Tests testRuntimeOnly(libs.log4j.core) testImplementation(libs.parallelgzip) + // lz4-java is compileOnly for main (provided by the platform module at runtime); the + // history write-path benchmark needs it available on the test runtime classpath since it + // exercises MainUtil's compression stream directly. See HistoryWriteBenchmark. Runtime-only + // since no test source references lz4 types at compile time. + testRuntimeOnly(libs.lz4Java) { isTransitive = false } +} + +tasks.register("historyBenchmark") { + group = "benchmark" + description = "Runs the hand-rolled com.fastasyncworldedit.core.history write-path baseline benchmark." + dependsOn(tasks.named("testClasses")) + classpath = sourceSets["test"].runtimeClasspath + mainClass.set("com.fastasyncworldedit.core.history.HistoryWriteBenchmark") + // The benchmark is disk/CPU bound and prints its own report; stream output live. + standardOutput = System.out + errorOutput = System.err } tasks.test { diff --git a/worldedit-core/src/test/java/com/fastasyncworldedit/core/history/HistoryWriteBenchmark.java b/worldedit-core/src/test/java/com/fastasyncworldedit/core/history/HistoryWriteBenchmark.java new file mode 100644 index 0000000000..b386d0cf43 --- /dev/null +++ b/worldedit-core/src/test/java/com/fastasyncworldedit/core/history/HistoryWriteBenchmark.java @@ -0,0 +1,281 @@ +package com.fastasyncworldedit.core.history; + +import com.fastasyncworldedit.core.history.changeset.FaweStreamChangeSet; +import com.sk89q.worldedit.util.io.file.SafeFiles; +import com.sk89q.worldedit.world.NullWorld; +import com.sk89q.worldedit.world.World; + +import java.io.File; +import java.io.IOException; +import java.nio.file.Files; +import java.nio.file.Path; +import java.util.ArrayList; +import java.util.List; +import java.util.UUID; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.ExecutionException; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.Future; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicLong; + +/** + * Hand-rolled micro-benchmark for the {@code com.fastasyncworldedit.core.history} write hot path + * ({@link DiskStorageHistory} and {@link MemoryOptimizedHistory}). + * + *

This is intentionally NOT a JMH benchmark. Wiring the {@code me.champeau.jmh} plugin into this + * repository's Gradle 9 multi-module build (custom ANTLR source generation, annotation processors, + * platform sub-modules) was judged likely to eat more time than the number itself was worth, so a + * plain warmup + measured-loop benchmark using {@link System#nanoTime()} was used instead, per the + * task's documented fallback. The goal is a repeatable, comparable number across a "before" and + * "after" run of the Phase 1 concurrency fixes, not a polished benchmarking harness.

+ * + *

Covers, per the write hot path that Phase 1 touches:

+ * + * + *

Run via the {@code historyBenchmark} Gradle task added in {@code worldedit-core/build.gradle.kts}:

+ * 
{@code ./gradlew :worldedit-core:historyBenchmark}
+ */ +public final class HistoryWriteBenchmark { + + private static final int WARMUP_OPS = 500_000; + private static final int MEASURED_OPS = 5_000_000; + private static final int TRIALS = 5; + private static final int THREADS = Math.max(2, Math.min(8, Runtime.getRuntime().availableProcessors())); + + private HistoryWriteBenchmark() { + } + + public static void main(String[] args) throws Exception { + System.out.println("=== FAWE history write-path baseline benchmark ==="); + // Contended trials split MEASURED_OPS across THREADS with integer division, so the actual + // op count they run can be slightly less than MEASURED_OPS when THREADS doesn't divide it + // evenly - report() itself always uses the real per-trial count for throughput, but print + // the two separately here so this header doesn't overclaim a single measuredOps for every + // benchmark variant. + int contendedMeasuredOps = (MEASURED_OPS / THREADS) * THREADS; + System.out.printf( + "warmupOps=%d measuredOps=%d (contended runs: %d actual, %d threads) trials=%d%n%n", + WARMUP_OPS, MEASURED_OPS, contendedMeasuredOps, THREADS, TRIALS + ); + + runSingleThreaded("DiskStorageHistory (single-thread)", HistoryWriteBenchmark::newDiskStorageHistory); + runSingleThreaded("MemoryOptimizedHistory (single-thread)", HistoryWriteBenchmark::newMemoryOptimizedHistory); + runContended("DiskStorageHistory (contended, " + THREADS + " threads)", HistoryWriteBenchmark::newDiskStorageHistory); + runContended( + "MemoryOptimizedHistory (contended, " + THREADS + " threads)", + HistoryWriteBenchmark::newMemoryOptimizedHistory + ); + + System.out.println("=== done ==="); + } + + private interface HistoryFactory { + + FaweStreamChangeSet create() throws IOException; + + } + + /** + * {@link NullWorld} whose {@code getMinY()}/{@code getMaxY()} do not reach into + * {@code WorldEdit.getInstance()} (which would require a fully bootstrapped platform). Every + * other call used by the write hot path is already a no-op / dummy in {@link NullWorld}. + */ + private static final class BenchWorld extends NullWorld { + + @Override + public int getMinY() { + return -64; + } + + @Override + public int getMaxY() { + return 319; + } + + } + + private static World world() { + return new BenchWorld(); + } + + private static FaweStreamChangeSet newDiskStorageHistory() throws IOException { + Path dir = Files.createTempDirectory("fawe-history-bench-"); + return new DiskStorageHistory(dir.toFile(), world(), UUID.randomUUID(), 0); + } + + private static FaweStreamChangeSet newMemoryOptimizedHistory() { + return new MemoryOptimizedHistory(world()); + } + + private static void doAdd(FaweStreamChangeSet changeSet, int i) { + // Bitmasks rather than i % 256 / i % 384: 384 is not a power of two, so that modulo + // compiles to an actual integer division, which would otherwise inflate the measured + // per-op cost with work that has nothing to do with add() itself. y needs the 384-value + // range of BenchWorld's height (-64..319), so fold the 9-bit 0..511 mask down to 0..383 + // with a single conditional subtract (still no division), then offset by minY. + int x = i & 0xFF; + int rawY = (i >>> 8) & 0x1FF; + int y = (rawY >= 384 ? rawY - 384 : rawY) - 64; + int z = (i >>> 17) & 0xFF; + changeSet.add(x, y, z, 1, 2); + } + + private static void closeAndCleanup(FaweStreamChangeSet changeSet) { + try { + changeSet.close(); + } catch (Exception e) { + // The contended benchmark deliberately hammers the pre-fix DCL race in getBlockOS(), + // which can leave the underlying (non-thread-safe) compression stream corrupted. + // close()/flush() can then throw unchecked exceptions (e.g. AIOOBE from LZ4). That is + // itself a data point (see the error count printed by report()), not a benchmark bug - + // swallow it here so remaining trials still run. Only Exception, not Throwable: a + // real Error (OutOfMemoryError, StackOverflowError) must still propagate and stop the + // run rather than being treated as expected race noise. + System.err.println(" (close() threw " + e + ")"); + } + if (changeSet instanceof DiskStorageHistory dsh) { + File dir = dsh.getBDFile().getParentFile(); + try { + SafeFiles.tryHardToDeleteDir(dir.toPath()); + } catch (IOException e) { + // Not fatal to the benchmark, but silently ignoring this let failed cleanups + // accumulate unnoticed across repeated runs (this benchmark can create sizeable + // on-disk histories). At least report it so it's diagnosable. + System.err.println(" (failed to clean up " + dir + ": " + e + ")"); + } + } + } + + private static void runSingleThreaded(String label, HistoryFactory factory) throws Exception { + long[] elapsedNanos = new long[TRIALS]; + for (int trial = 0; trial < TRIALS; trial++) { + FaweStreamChangeSet changeSet = factory.create(); + int i = 0; + for (; i < WARMUP_OPS; i++) { + doAdd(changeSet, i); + } + long start = System.nanoTime(); + for (int j = 0; j < MEASURED_OPS; j++, i++) { + doAdd(changeSet, i); + } + elapsedNanos[trial] = System.nanoTime() - start; + closeAndCleanup(changeSet); + } + report(label, elapsedNanos, MEASURED_OPS, 0); + } + + private static void runContended(String label, HistoryFactory factory) throws Exception { + int opsPerThread = MEASURED_OPS / THREADS; + long[] elapsedNanos = new long[TRIALS]; + long totalErrors = 0; + for (int trial = 0; trial < TRIALS; trial++) { + // Warm up JIT/class-loading on a throwaway instance rather than the measured one: the + // measured instance must still start with uninitialized lazy streams so this trial + // keeps exercising the lazy stream-init race under contention, which is the entire + // point of the contended variant. + FaweStreamChangeSet warmupChangeSet = factory.create(); + for (int i = 0; i < WARMUP_OPS; i++) { + doAdd(warmupChangeSet, i); + } + closeAndCleanup(warmupChangeSet); + + FaweStreamChangeSet changeSet = factory.create(); + ExecutorService pool = Executors.newFixedThreadPool(THREADS); + CountDownLatch ready = new CountDownLatch(THREADS); + CountDownLatch go = new CountDownLatch(1); + AtomicLong errorCount = new AtomicLong(); + // submit() discards its Future by default, and a FutureTask captures any Throwable + // (Exception or Error) rather than propagating it to the calling thread - so an + // Error escaping the loop below would previously vanish silently instead of actually + // propagating, contradicting the comment inside the loop. Keep the futures and check + // them after the pool finishes so a real Error is still surfaced. + List> futures = new ArrayList<>(THREADS); + for (int t = 0; t < THREADS; t++) { + final int base = t * opsPerThread; + futures.add(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(); + } + } + })); + } + if (!ready.await(1, TimeUnit.MINUTES)) { + pool.shutdownNow(); + throw new IllegalStateException("Benchmark worker threads did not all start in time"); + } + long start = System.nanoTime(); + go.countDown(); + pool.shutdown(); + if (!pool.awaitTermination(5, TimeUnit.MINUTES)) { + pool.shutdownNow(); + throw new IllegalStateException("Benchmark threads did not finish in time"); + } + for (Future future : futures) { + try { + future.get(); + } catch (ExecutionException e) { + throw new IllegalStateException("Benchmark worker thread failed", e.getCause()); + } + } + elapsedNanos[trial] = System.nanoTime() - start; + totalErrors += errorCount.get(); + closeAndCleanup(changeSet); + } + report(label, elapsedNanos, (long) opsPerThread * THREADS, totalErrors); + } + + private static void report(String label, long[] elapsedNanos, long opsPerTrial, long totalErrors) { + System.out.println(label + ":"); + long totalElapsedNanos = 0; + for (int trial = 0; trial < elapsedNanos.length; trial++) { + double seconds = elapsedNanos[trial] / 1_000_000_000.0; + double opsPerSec = opsPerTrial / seconds; + double nsPerOp = (double) elapsedNanos[trial] / opsPerTrial; + totalElapsedNanos += elapsedNanos[trial]; + System.out.printf( + " trial %d: %.2f ms, %,.0f ops/sec, %.1f ns/op%n", + trial + 1, elapsedNanos[trial] / 1_000_000.0, opsPerSec, nsPerOp + ); + } + // Aggregate throughput (total ops / total time) rather than the mean of the per-trial + // rates, so a single slow/fast trial (GC pause, OS scheduling) is weighted by how long it + // actually ran instead of counting equally with the others. + long totalOps = opsPerTrial * elapsedNanos.length; + 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) { + // This only counts exceptions that escape FaweStreamChangeSet#add(...) into this + // benchmark's own catch block. add() itself catches IOException internally and + // prints a stack trace rather than throwing, so IO-related failures from the race + // aren't reflected here - this is a lower bound on "ops threw", not a full count. + System.out.printf( + " -- %d/%d ops threw past add() (unsynchronized shared stream access; add() itself " + + "swallows some IOExceptions, so this undercounts total failures)%n", + totalErrors, totalOps + ); + } else { + System.out.println(); + } + System.out.println(); + } + +}