diff --git a/CHANGELOG.md b/CHANGELOG.md index 7986c02..c29da3b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -89,6 +89,14 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Shared test support (`RecordingAppender`, `RecordingProducerFactory`, three encoders) replaces the per-class private fixtures; every test fixture closes what it starts. +- The per-send callback's synchronous-failure flag is a plain field (the + race with an asynchronous error callback is benign in both outcomes), + so the JIT can scalar-replace the callback wherever it does not + escape; `SenderPathBenchmark` unbound is back at its 2026-08-30 + allocation baseline (112 B/op). The metrics-bound variant reads + 224 B/op in this session for the pre-change code as well (same JVM; + JIT-profile variance the benchmark report already documents), so it + carries no regression either. ### Fixed diff --git a/benchmarks/results/2026-09-07/r2-senderpath-after-volatile-removal.txt b/benchmarks/results/2026-09-07/r2-senderpath-after-volatile-removal.txt new file mode 100644 index 0000000..6a62af6 --- /dev/null +++ b/benchmarks/results/2026-09-07/r2-senderpath-after-volatile-removal.txt @@ -0,0 +1,361 @@ +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# JMH version: 1.37 +# VM version: JDK 26.0.1, Java HotSpot(TM) 64-Bit Server VM, 26.0.1+8-34 +# VM invoker: /usr/lib/jvm/jdk-26.0.1-oracle-x64/bin/java +# VM options: +# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable) +# Warmup: 5 iterations, 1 s each +# Measurement: 5 iterations, 1 s each +# Timeout: 10 min per iteration +# Threads: 1 thread, will synchronize iterations +# Benchmark mode: Average time, time/op +# Benchmark: eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent +# Parameters: (metricsBound = false) + +# Run progress: 0,00% complete, ETA 00:01:00 +# Fork: 1 of 3 +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# Warmup Iteration 1: 76,670 ns/op +# Warmup Iteration 2: 66,626 ns/op +# Warmup Iteration 3: 67,638 ns/op +# Warmup Iteration 4: 66,891 ns/op +# Warmup Iteration 5: 71,250 ns/op +Iteration 1: 67,133 ns/op + gc.alloc.rate: 1590,741 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 5,000 counts + gc.time: 2,000 ms + +Iteration 2: 68,685 ns/op + gc.alloc.rate: 1554,752 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 5,000 counts + gc.time: 2,000 ms + +Iteration 3: 67,269 ns/op + gc.alloc.rate: 1587,533 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 6,000 counts + gc.time: 3,000 ms + +Iteration 4: 67,968 ns/op + gc.alloc.rate: 1571,132 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 5,000 counts + gc.time: 3,000 ms + +Iteration 5: 66,754 ns/op + gc.alloc.rate: 1599,666 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 6,000 counts + gc.time: 3,000 ms + + +# Run progress: 16,67% complete, ETA 00:00:52 +# Fork: 2 of 3 +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# Warmup Iteration 1: 100,839 ns/op +# Warmup Iteration 2: 68,263 ns/op +# Warmup Iteration 3: 67,826 ns/op +# Warmup Iteration 4: 67,242 ns/op +# Warmup Iteration 5: 67,162 ns/op +Iteration 1: 67,012 ns/op + gc.alloc.rate: 1593,538 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 5,000 counts + gc.time: 4,000 ms + +Iteration 2: 67,350 ns/op + gc.alloc.rate: 1585,500 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 5,000 counts + gc.time: 4,000 ms + +Iteration 3: 66,964 ns/op + gc.alloc.rate: 1594,790 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 6,000 counts + gc.time: 5,000 ms + +Iteration 4: 66,960 ns/op + gc.alloc.rate: 1594,626 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 5,000 counts + gc.time: 3,000 ms + +Iteration 5: 67,079 ns/op + gc.alloc.rate: 1590,401 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 5,000 counts + gc.time: 5,000 ms + + +# Run progress: 33,33% complete, ETA 00:00:41 +# Fork: 3 of 3 +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# Warmup Iteration 1: 77,078 ns/op +# Warmup Iteration 2: 77,730 ns/op +# Warmup Iteration 3: 68,566 ns/op +# Warmup Iteration 4: 69,929 ns/op +# Warmup Iteration 5: 66,102 ns/op +Iteration 1: 73,035 ns/op + gc.alloc.rate: 1461,983 MB/sec + gc.alloc.rate.norm: 112,001 B/op + gc.count: 1,000 counts + gc.time: 1,000 ms + +Iteration 2: 65,523 ns/op + gc.alloc.rate: 1629,680 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 2,000 counts + gc.time: 3,000 ms + +Iteration 3: 65,270 ns/op + gc.alloc.rate: 1635,738 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 2,000 counts + gc.time: 2,000 ms + +Iteration 4: 66,441 ns/op + gc.alloc.rate: 1607,144 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 1,000 counts + gc.time: 1,000 ms + +Iteration 5: 65,188 ns/op + gc.alloc.rate: 1638,018 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 2,000 counts + gc.time: 2,000 ms + + + +Result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent": + 67,242 ±(99.9%) 1,987 ns/op [Average] + (min, avg, max) = (65,188, 67,242, 73,035), stdev = 1,859 + CI (99.9%): [65,255, 69,229] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.alloc.rate": + 1589,016 ±(99.9%) 44,645 MB/sec [Average] + (min, avg, max) = (1461,983, 1589,016, 1638,018), stdev = 41,761 + CI (99.9%): [1544,371, 1633,661] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.alloc.rate.norm": + 112,000 ±(99.9%) 0,001 B/op [Average] + (min, avg, max) = (112,000, 112,000, 112,001), stdev = 0,001 + CI (99.9%): [112,000, 112,000] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.count": + 61,000 ±(99.9%) 0,001 counts [Sum] + (min, avg, max) = (1,000, 4,067, 6,000), stdev = 1,870 + CI (99.9%): [61,000, 61,000] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.time": + 43,000 ±(99.9%) 0,001 ms [Sum] + (min, avg, max) = (1,000, 2,867, 5,000), stdev = 1,246 + CI (99.9%): [43,000, 43,000] (assumes normal distribution) + + +# JMH version: 1.37 +# VM version: JDK 26.0.1, Java HotSpot(TM) 64-Bit Server VM, 26.0.1+8-34 +# VM invoker: /usr/lib/jvm/jdk-26.0.1-oracle-x64/bin/java +# VM options: +# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable) +# Warmup: 5 iterations, 1 s each +# Measurement: 5 iterations, 1 s each +# Timeout: 10 min per iteration +# Threads: 1 thread, will synchronize iterations +# Benchmark mode: Average time, time/op +# Benchmark: eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent +# Parameters: (metricsBound = true) + +# Run progress: 50,00% complete, ETA 00:00:31 +# Fork: 1 of 3 +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# Warmup Iteration 1: 222,503 ns/op +# Warmup Iteration 2: 189,291 ns/op +# Warmup Iteration 3: 188,565 ns/op +# Warmup Iteration 4: 187,677 ns/op +# Warmup Iteration 5: 186,633 ns/op +Iteration 1: 187,271 ns/op + gc.alloc.rate: 1140,299 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 3,000 counts + gc.time: 3,000 ms + +Iteration 2: 186,802 ns/op + gc.alloc.rate: 1143,158 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 4,000 counts + gc.time: 4,000 ms + +Iteration 3: 188,827 ns/op + gc.alloc.rate: 1130,926 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 3,000 counts + gc.time: 3,000 ms + +Iteration 4: 188,111 ns/op + gc.alloc.rate: 1135,190 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 4,000 counts + gc.time: 4,000 ms + +Iteration 5: 186,493 ns/op + gc.alloc.rate: 1145,154 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 4,000 counts + gc.time: 3,000 ms + + +# Run progress: 66,67% complete, ETA 00:00:20 +# Fork: 2 of 3 +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# Warmup Iteration 1: 222,096 ns/op +# Warmup Iteration 2: 189,077 ns/op +# Warmup Iteration 3: 187,612 ns/op +# Warmup Iteration 4: 191,975 ns/op +# Warmup Iteration 5: 196,034 ns/op +Iteration 1: 215,751 ns/op + gc.alloc.rate: 988,811 MB/sec + gc.alloc.rate.norm: 224,002 B/op + gc.count: 4,000 counts + gc.time: 8,000 ms + +Iteration 2: 189,917 ns/op + gc.alloc.rate: 1124,616 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 3,000 counts + gc.time: 2,000 ms + +Iteration 3: 189,328 ns/op + gc.alloc.rate: 1128,089 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 4,000 counts + gc.time: 3,000 ms + +Iteration 4: 191,203 ns/op + gc.alloc.rate: 1116,945 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 3,000 counts + gc.time: 3,000 ms + +Iteration 5: 188,867 ns/op + gc.alloc.rate: 1130,621 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 4,000 counts + gc.time: 2,000 ms + + +# Run progress: 83,33% complete, ETA 00:00:10 +# Fork: 3 of 3 +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# Warmup Iteration 1: 220,256 ns/op +# Warmup Iteration 2: 188,279 ns/op +# Warmup Iteration 3: 201,731 ns/op +# Warmup Iteration 4: 189,906 ns/op +# Warmup Iteration 5: 191,333 ns/op +Iteration 1: 192,125 ns/op + gc.alloc.rate: 1588,067 MB/sec + gc.alloc.rate.norm: 320,001 B/op + gc.count: 3,000 counts + gc.time: 3,000 ms + +Iteration 2: 193,856 ns/op + gc.alloc.rate: 1573,864 MB/sec + gc.alloc.rate.norm: 320,001 B/op + gc.count: 4,000 counts + gc.time: 3,000 ms + +Iteration 3: 198,412 ns/op + gc.alloc.rate: 1537,710 MB/sec + gc.alloc.rate.norm: 320,001 B/op + gc.count: 4,000 counts + gc.time: 4,000 ms + +Iteration 4: 206,110 ns/op + gc.alloc.rate: 1479,724 MB/sec + gc.alloc.rate.norm: 320,001 B/op + gc.count: 4,000 counts + gc.time: 3,000 ms + +Iteration 5: 209,551 ns/op + gc.alloc.rate: 1455,588 MB/sec + gc.alloc.rate.norm: 320,001 B/op + gc.count: 4,000 counts + gc.time: 3,000 ms + + + +Result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent": + 194,175 ±(99.9%) 9,780 ns/op [Average] + (min, avg, max) = (186,493, 194,175, 215,751), stdev = 9,148 + CI (99.9%): [184,395, 203,955] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.alloc.rate": + 1254,584 ±(99.9%) 219,323 MB/sec [Average] + (min, avg, max) = (988,811, 1254,584, 1588,067), stdev = 205,155 + CI (99.9%): [1035,261, 1473,907] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.alloc.rate.norm": + 256,001 ±(99.9%) 50,078 B/op [Average] + (min, avg, max) = (224,001, 256,001, 320,001), stdev = 46,843 + CI (99.9%): [205,923, 306,080] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.count": + 55,000 ±(99.9%) 0,001 counts [Sum] + (min, avg, max) = (3,000, 3,667, 4,000), stdev = 0,488 + CI (99.9%): [55,000, 55,000] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.time": + 51,000 ±(99.9%) 0,001 ms [Sum] + (min, avg, max) = (2,000, 3,400, 8,000), stdev = 1,404 + CI (99.9%): [51,000, 51,000] (assumes normal distribution) + + +# Run complete. Total time: 00:01:02 + +REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on +why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial +experiments, perform baseline and negative tests that provide experimental control, make sure +the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts. +Do not assume the numbers tell you what you want them to tell. + +NOTE: Current JVM experimentally supports Compiler Blackholes, and they are in use. Please exercise +extra caution when trusting the results, look into the generated code to check the benchmark still +works, and factor in a small probability of new VM bugs. Additionally, while comparisons between +different JVMs are already problematic, the performance difference caused by different Blackhole +modes can be very significant. Please make sure you use the consistent Blackhole mode for comparisons. + +Benchmark (metricsBound) Mode Cnt Score Error Units +SenderPathBenchmark.sendOneEvent false avgt 15 67,242 ± 1,987 ns/op +SenderPathBenchmark.sendOneEvent:gc.alloc.rate false avgt 15 1589,016 ± 44,645 MB/sec +SenderPathBenchmark.sendOneEvent:gc.alloc.rate.norm false avgt 15 112,000 ± 0,001 B/op +SenderPathBenchmark.sendOneEvent:gc.count false avgt 15 61,000 counts +SenderPathBenchmark.sendOneEvent:gc.time false avgt 15 43,000 ms +SenderPathBenchmark.sendOneEvent true avgt 15 194,175 ± 9,780 ns/op +SenderPathBenchmark.sendOneEvent:gc.alloc.rate true avgt 15 1254,584 ± 219,323 MB/sec +SenderPathBenchmark.sendOneEvent:gc.alloc.rate.norm true avgt 15 256,001 ± 50,078 B/op +SenderPathBenchmark.sendOneEvent:gc.count true avgt 15 55,000 counts +SenderPathBenchmark.sendOneEvent:gc.time true avgt 15 51,000 ms diff --git a/benchmarks/results/2026-09-07/r2-senderpath-control-6c4f2b8-1fork.txt b/benchmarks/results/2026-09-07/r2-senderpath-control-6c4f2b8-1fork.txt new file mode 100644 index 0000000..5f09725 --- /dev/null +++ b/benchmarks/results/2026-09-07/r2-senderpath-control-6c4f2b8-1fork.txt @@ -0,0 +1,163 @@ +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# JMH version: 1.37 +# VM version: JDK 26.0.1, Java HotSpot(TM) 64-Bit Server VM, 26.0.1+8-34 +# VM invoker: /usr/lib/jvm/jdk-26.0.1-oracle-x64/bin/java +# VM options: +# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable) +# Warmup: 2 iterations, 1 s each +# Measurement: 3 iterations, 1 s each +# Timeout: 10 min per iteration +# Threads: 1 thread, will synchronize iterations +# Benchmark mode: Average time, time/op +# Benchmark: eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent +# Parameters: (metricsBound = false) + +# Run progress: 0,00% complete, ETA 00:00:10 +# Fork: 1 of 1 +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# Warmup Iteration 1: 77,286 ns/op +# Warmup Iteration 2: 68,323 ns/op +Iteration 1: 68,470 ns/op + gc.alloc.rate: 1559,286 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 5,000 counts + gc.time: 6,000 ms + +Iteration 2: 66,310 ns/op + gc.alloc.rate: 1609,974 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 5,000 counts + gc.time: 5,000 ms + +Iteration 3: 66,714 ns/op + gc.alloc.rate: 1600,067 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 5,000 counts + gc.time: 4,000 ms + + + +Result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent": + 67,165 ±(99.9%) 20,954 ns/op [Average] + (min, avg, max) = (66,310, 67,165, 68,470), stdev = 1,149 + CI (99.9%): [46,211, 88,119] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.alloc.rate": + 1589,775 ±(99.9%) 490,121 MB/sec [Average] + (min, avg, max) = (1559,286, 1589,775, 1609,974), stdev = 26,865 + CI (99.9%): [1099,655, 2079,896] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.alloc.rate.norm": + 112,000 ±(99.9%) 0,001 B/op [Average] + (min, avg, max) = (112,000, 112,000, 112,000), stdev = 0,001 + CI (99.9%): [112,000, 112,001] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.count": + 15,000 ±(99.9%) 0,001 counts [Sum] + (min, avg, max) = (5,000, 5,000, 5,000), stdev = 0,001 + CI (99.9%): [15,000, 15,000] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.time": + 15,000 ±(99.9%) 0,001 ms [Sum] + (min, avg, max) = (4,000, 5,000, 6,000), stdev = 1,000 + CI (99.9%): [15,000, 15,000] (assumes normal distribution) + + +# JMH version: 1.37 +# VM version: JDK 26.0.1, Java HotSpot(TM) 64-Bit Server VM, 26.0.1+8-34 +# VM invoker: /usr/lib/jvm/jdk-26.0.1-oracle-x64/bin/java +# VM options: +# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable) +# Warmup: 2 iterations, 1 s each +# Measurement: 3 iterations, 1 s each +# Timeout: 10 min per iteration +# Threads: 1 thread, will synchronize iterations +# Benchmark mode: Average time, time/op +# Benchmark: eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent +# Parameters: (metricsBound = true) + +# Run progress: 50,00% complete, ETA 00:00:05 +# Fork: 1 of 1 +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# Warmup Iteration 1: 231,345 ns/op +# Warmup Iteration 2: 189,048 ns/op +Iteration 1: 189,911 ns/op + gc.alloc.rate: 1124,644 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 3,000 counts + gc.time: 8,000 ms + +Iteration 2: 191,184 ns/op + gc.alloc.rate: 1117,114 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 4,000 counts + gc.time: 7,000 ms + +Iteration 3: 185,675 ns/op + gc.alloc.rate: 1150,206 MB/sec + gc.alloc.rate.norm: 224,001 B/op + gc.count: 3,000 counts + gc.time: 2,000 ms + + + +Result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent": + 188,923 ±(99.9%) 52,626 ns/op [Average] + (min, avg, max) = (185,675, 188,923, 191,184), stdev = 2,885 + CI (99.9%): [136,297, 241,549] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.alloc.rate": + 1130,654 ±(99.9%) 316,449 MB/sec [Average] + (min, avg, max) = (1117,114, 1130,654, 1150,206), stdev = 17,346 + CI (99.9%): [814,206, 1447,103] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.alloc.rate.norm": + 224,001 ±(99.9%) 0,001 B/op [Average] + (min, avg, max) = (224,001, 224,001, 224,001), stdev = 0,001 + CI (99.9%): [224,001, 224,002] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.count": + 10,000 ±(99.9%) 0,001 counts [Sum] + (min, avg, max) = (3,000, 3,333, 4,000), stdev = 0,577 + CI (99.9%): [10,000, 10,000] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.time": + 17,000 ±(99.9%) 0,001 ms [Sum] + (min, avg, max) = (2,000, 5,667, 8,000), stdev = 3,215 + CI (99.9%): [17,000, 17,000] (assumes normal distribution) + + +# Run complete. Total time: 00:00:10 + +REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on +why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial +experiments, perform baseline and negative tests that provide experimental control, make sure +the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts. +Do not assume the numbers tell you what you want them to tell. + +NOTE: Current JVM experimentally supports Compiler Blackholes, and they are in use. Please exercise +extra caution when trusting the results, look into the generated code to check the benchmark still +works, and factor in a small probability of new VM bugs. Additionally, while comparisons between +different JVMs are already problematic, the performance difference caused by different Blackhole +modes can be very significant. Please make sure you use the consistent Blackhole mode for comparisons. + +Benchmark (metricsBound) Mode Cnt Score Error Units +SenderPathBenchmark.sendOneEvent false avgt 3 67,165 ± 20,954 ns/op +SenderPathBenchmark.sendOneEvent:gc.alloc.rate false avgt 3 1589,775 ± 490,121 MB/sec +SenderPathBenchmark.sendOneEvent:gc.alloc.rate.norm false avgt 3 112,000 ± 0,001 B/op +SenderPathBenchmark.sendOneEvent:gc.count false avgt 3 15,000 counts +SenderPathBenchmark.sendOneEvent:gc.time false avgt 3 15,000 ms +SenderPathBenchmark.sendOneEvent true avgt 3 188,923 ± 52,626 ns/op +SenderPathBenchmark.sendOneEvent:gc.alloc.rate true avgt 3 1130,654 ± 316,449 MB/sec +SenderPathBenchmark.sendOneEvent:gc.alloc.rate.norm true avgt 3 224,001 ± 0,001 B/op +SenderPathBenchmark.sendOneEvent:gc.count true avgt 3 10,000 counts +SenderPathBenchmark.sendOneEvent:gc.time true avgt 3 17,000 ms diff --git a/benchmarks/results/2026-09-07/r2-senderpath-novolatile-1fork-unbound.txt b/benchmarks/results/2026-09-07/r2-senderpath-novolatile-1fork-unbound.txt new file mode 100644 index 0000000..a61eb97 --- /dev/null +++ b/benchmarks/results/2026-09-07/r2-senderpath-novolatile-1fork-unbound.txt @@ -0,0 +1,91 @@ +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# JMH version: 1.37 +# VM version: JDK 26.0.1, Java HotSpot(TM) 64-Bit Server VM, 26.0.1+8-34 +# VM invoker: /usr/lib/jvm/jdk-26.0.1-oracle-x64/bin/java +# VM options: +# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable) +# Warmup: 2 iterations, 1 s each +# Measurement: 3 iterations, 1 s each +# Timeout: 10 min per iteration +# Threads: 1 thread, will synchronize iterations +# Benchmark mode: Average time, time/op +# Benchmark: eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent +# Parameters: (metricsBound = false) + +# Run progress: 0,00% complete, ETA 00:00:05 +# Fork: 1 of 1 +WARNING: A terminally deprecated method in sun.misc.Unsafe has been called +WARNING: sun.misc.Unsafe::objectFieldOffset has been called by org.openjdk.jmh.util.Utils (file:/home/dirk/IdeaProjects/tabellarium/benchmarks/target/benchmarks.jar) +WARNING: Please consider reporting this to the maintainers of class org.openjdk.jmh.util.Utils +WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release +# Warmup Iteration 1: 75,637 ns/op +# Warmup Iteration 2: 72,648 ns/op +Iteration 1: 70,938 ns/op + gc.alloc.rate: 1505,138 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 2,000 counts + gc.time: 5,000 ms + +Iteration 2: 64,812 ns/op + gc.alloc.rate: 1647,517 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 1,000 counts + gc.time: 2,000 ms + +Iteration 3: 64,874 ns/op + gc.alloc.rate: 1645,664 MB/sec + gc.alloc.rate.norm: 112,000 B/op + gc.count: 2,000 counts + gc.time: 2,000 ms + + + +Result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent": + 66,875 ±(99.9%) 64,203 ns/op [Average] + (min, avg, max) = (64,812, 66,875, 70,938), stdev = 3,519 + CI (99.9%): [2,672, 131,078] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.alloc.rate": + 1599,440 ±(99.9%) 1490,017 MB/sec [Average] + (min, avg, max) = (1505,138, 1599,440, 1647,517), stdev = 81,673 + CI (99.9%): [109,423, 3089,457] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.alloc.rate.norm": + 112,000 ±(99.9%) 0,001 B/op [Average] + (min, avg, max) = (112,000, 112,000, 112,000), stdev = 0,001 + CI (99.9%): [112,000, 112,001] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.count": + 5,000 ±(99.9%) 0,001 counts [Sum] + (min, avg, max) = (1,000, 1,667, 2,000), stdev = 0,577 + CI (99.9%): [5,000, 5,000] (assumes normal distribution) + +Secondary result "eu.inqudium.tabellarium.bench.SenderPathBenchmark.sendOneEvent:gc.time": + 9,000 ±(99.9%) 0,001 ms [Sum] + (min, avg, max) = (2,000, 3,000, 5,000), stdev = 1,732 + CI (99.9%): [9,000, 9,000] (assumes normal distribution) + + +# Run complete. Total time: 00:00:05 + +REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on +why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial +experiments, perform baseline and negative tests that provide experimental control, make sure +the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts. +Do not assume the numbers tell you what you want them to tell. + +NOTE: Current JVM experimentally supports Compiler Blackholes, and they are in use. Please exercise +extra caution when trusting the results, look into the generated code to check the benchmark still +works, and factor in a small probability of new VM bugs. Additionally, while comparisons between +different JVMs are already problematic, the performance difference caused by different Blackhole +modes can be very significant. Please make sure you use the consistent Blackhole mode for comparisons. + +Benchmark (metricsBound) Mode Cnt Score Error Units +SenderPathBenchmark.sendOneEvent false avgt 3 66,875 ± 64,203 ns/op +SenderPathBenchmark.sendOneEvent:gc.alloc.rate false avgt 3 1599,440 ± 1490,017 MB/sec +SenderPathBenchmark.sendOneEvent:gc.alloc.rate.norm false avgt 3 112,000 ± 0,001 B/op +SenderPathBenchmark.sendOneEvent:gc.count false avgt 3 5,000 counts +SenderPathBenchmark.sendOneEvent:gc.time false avgt 3 9,000 ms diff --git a/benchmarks/src/main/java/eu/inqudium/tabellarium/bench/SenderPathBenchmark.java b/benchmarks/src/main/java/eu/inqudium/tabellarium/bench/SenderPathBenchmark.java index 203dad4..a67f727 100644 --- a/benchmarks/src/main/java/eu/inqudium/tabellarium/bench/SenderPathBenchmark.java +++ b/benchmarks/src/main/java/eu/inqudium/tabellarium/bench/SenderPathBenchmark.java @@ -35,9 +35,13 @@ /** * Verifies finding 3 of PERF_ANALYSIS-2026-08-29T11-01-08: the - * per-delivered-event observability envelope (capturing callback - * lambda, {@code Duration} box, Resilience4j event objects via the - * attached breaker consumers, Micrometer meter updates). + * per-delivered-event observability envelope (the per-send callback + * object, {@code Duration} box, Resilience4j event objects via the + * attached breaker consumers, Micrometer meter updates). Since the + * callback became a class ({@code SendCallback}, 2026-09-07) this + * benchmark also guards its scalar replaceability: against the + * inlined {@link DiscardingProducer} the callback never escapes, so a + * field that pins it (e.g. a volatile) shows up as +48 B/op here. * *

Why this instrument: the full-pipeline benchmark saturates * its single worker under open load and then measures mostly the diff --git a/src/main/kotlin/eu/inqudium/tabellarium/ResilientMessageSender.kt b/src/main/kotlin/eu/inqudium/tabellarium/ResilientMessageSender.kt index c4835f2..432430c 100644 --- a/src/main/kotlin/eu/inqudium/tabellarium/ResilientMessageSender.kt +++ b/src/main/kotlin/eu/inqudium/tabellarium/ResilientMessageSender.kt @@ -279,11 +279,22 @@ internal class ResilientMessageSender( val startNanos: Long = System.nanoTime() /** - * True once this callback has reported an error. Volatile: written - * on whichever thread the client invokes the callback on, read on - * the sending thread right after `send` returns. + * True once this callback has reported an error. Read on the + * sending thread right after `send` returns, to tell a synchronous + * failure (callback already ran, same thread - program order makes + * the write visible) from a pending send. + * + * Safety: deliberately NOT volatile. The only concurrent writer is + * an asynchronous error callback on the Kafka I/O thread racing + * that read, and both outcomes of that race are correct: seeing + * `true` counts the event as fallback only (the exact balance), + * seeing `false` counts it as dispatched with the later `send.error` + * fallback (the documented asynchronous outcome). A volatile field + * would pin this object against the JIT's scalar replacement + * wherever the callback does not escape and cost one allocation per + * send on that path (`SenderPathBenchmark`, 160 vs. 112 B/op) for a + * guarantee no reader needs. */ - @Volatile var errorReported: Boolean = false private set