From 8a2caf91e06ffc589674d23e4ae69cd9966d4d31 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Mari=C3=A1n=20Ka=C5=BEim=C3=ADr?= Date: Fri, 14 Jun 2024 14:01:11 +0200 Subject: [PATCH] Java 17 mac pro M2 pro results added --- .../results-2024-06-14T1314-1.txt | 196 ++++++++ .../results-2024-06-14T1314-16.txt | 456 ++++++++++++++++++ .../results-2024-06-14T1314-32.txt | 199 ++++++++ .../results-2024-06-14T1314-4.txt | 217 +++++++++ 4 files changed, 1068 insertions(+) create mode 100755 results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-1.txt create mode 100755 results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-16.txt create mode 100755 results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-32.txt create mode 100755 results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-4.txt diff --git a/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-1.txt b/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-1.txt new file mode 100755 index 0000000..7d33b44 --- /dev/null +++ b/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-1.txt @@ -0,0 +1,196 @@ +➜ logback-perf git:(master) ✗ java -jar target/benchmarks.jar ".*FileAppenderBenchmark.*" -f 1 -tu ms -wi 2 -i 4 -to 3 -t 1 +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 1 thread, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.log4j2AsyncFile + +# Run progress: 0.00% complete, ETA 00:06:00 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +3215.446 ops/ms +# Warmup Iteration 2: 2889.386 ops/ms +Iteration 1: 3000.786 ops/ms +Iteration 2: 3084.032 ops/ms +Iteration 3: 3019.224 ops/ms +Iteration 4: 2910.935 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.log4j2AsyncFile": + 3003.744 ±(99.9%) 461.601 ops/ms [Average] + (min, avg, max) = (2910.935, 3003.744, 3084.032), stdev = 71.433 + CI (99.9%): [2542.143, 3465.345] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 1 thread, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.logbackFile + +# Run progress: 16.67% complete, ETA 00:05:02 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +About to delete [target/test-output/logback-async-perf.log] +About to delete [target/test-output/log4j2-async-perf.log] +About to delete [target/test-output/log4j-async-perf.log] +4921.062 ops/ms +# Warmup Iteration 2: 5285.604 ops/ms +Iteration 1: 4850.742 ops/ms +Iteration 2: 4100.518 ops/ms +Iteration 3: 3903.918 ops/ms +Iteration 4: 3823.438 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.logbackFile": + 4169.654 ±(99.9%) 3028.969 ops/ms [Average] + (min, avg, max) = (3823.438, 4169.654, 4850.742), stdev = 468.736 + CI (99.9%): [1140.685, 7198.623] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 1 thread, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.reload4jFile + +# Run progress: 33.33% complete, ETA 00:04:02 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +About to delete [target/test-output/logback-async-perf.log] +About to delete [target/test-output/log4j2-async-perf.log] +About to delete [target/test-output/log4j-async-perf.log] +2621.364 ops/ms +# Warmup Iteration 2: 2623.160 ops/ms +Iteration 1: 2649.261 ops/ms +Iteration 2: 2515.900 ops/ms +Iteration 3: 2439.778 ops/ms +Iteration 4: 2430.602 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.reload4jFile": + 2508.885 ±(99.9%) 653.253 ops/ms [Average] + (min, avg, max) = (2430.602, 2508.885, 2649.261), stdev = 101.092 + CI (99.9%): [1855.633, 3162.138] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 1 thread, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.log4j2File + +# Run progress: 50.00% complete, ETA 00:03:02 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +3507.556 ops/ms +# Warmup Iteration 2: 3657.267 ops/ms +Iteration 1: 3533.396 ops/ms +Iteration 2: 3638.140 ops/ms +Iteration 3: 3536.143 ops/ms +Iteration 4: 3518.328 ops/ms + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.log4j2File": + 3556.502 ±(99.9%) 355.318 ops/ms [Average] + (min, avg, max) = (3518.328, 3556.502, 3638.140), stdev = 54.986 + CI (99.9%): [3201.183, 3911.820] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 1 thread, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.logbackFile + +# Run progress: 66.67% complete, ETA 00:02:01 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +3642.238 ops/ms +# Warmup Iteration 2: 3690.707 ops/ms +Iteration 1: 3631.691 ops/ms +Iteration 2: 3396.009 ops/ms +Iteration 3: 3130.448 ops/ms +Iteration 4: 3130.841 ops/ms + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.logbackFile": + 3322.247 ±(99.9%) 1559.021 ops/ms [Average] + (min, avg, max) = (3130.448, 3322.247, 3631.691), stdev = 241.260 + CI (99.9%): [1763.226, 4881.268] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 1 thread, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.reload4jFile + +# Run progress: 83.33% complete, ETA 00:01:00 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +3070.578 ops/ms +# Warmup Iteration 2: 3078.580 ops/ms +Iteration 1: 3025.116 ops/ms +Iteration 2: 2854.915 ops/ms +Iteration 3: 2674.043 ops/ms +Iteration 4: 2619.029 ops/ms + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.reload4jFile": + 2793.276 ±(99.9%) 1192.277 ops/ms [Average] + (min, avg, max) = (2619.029, 2793.276, 3025.116), stdev = 184.506 + CI (99.9%): [1600.999, 3985.552] (assumes normal distribution) + + +# Run complete. Total time: 00:06:04 + +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. + +Benchmark Mode Cnt Score Error Units +AsyncWithFileAppenderBenchmark.log4j2AsyncFile thrpt 4 3003.744 ± 461.601 ops/ms +AsyncWithFileAppenderBenchmark.logbackFile thrpt 4 4169.654 ± 3028.969 ops/ms +AsyncWithFileAppenderBenchmark.reload4jFile thrpt 4 2508.885 ± 653.253 ops/ms +FileAppenderBenchmark.log4j2File thrpt 4 3556.502 ± 355.318 ops/ms +FileAppenderBenchmark.logbackFile thrpt 4 3322.247 ± 1559.021 ops/ms +FileAppenderBenchmark.reload4jFile thrpt 4 2793.276 ± 1192.277 ops/ms diff --git a/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-16.txt b/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-16.txt new file mode 100755 index 0000000..372964d --- /dev/null +++ b/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-16.txt @@ -0,0 +1,456 @@ +➜ logback-perf git:(master) ✗ java -jar target/benchmarks.jar ".*FileAppenderBenchmark.*" -f 1 -tu ms -wi 2 -i 4 -to 3 -t 16 +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 16 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.log4j2AsyncFile + +# Run progress: 0.00% complete, ETA 00:06:00 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +About to delete [target/test-output/logback-async-perf.log] +About to delete [target/test-output/log4j2-async-perf.log] +About to delete [target/test-output/log4j-async-perf.log] +3028.096 ops/ms +# Warmup Iteration 2: 3053.559 ops/ms +Iteration 1: 3086.943 ops/ms +Iteration 2: 2995.746 ops/ms +Iteration 3: 2645.227 ops/ms +Iteration 4: 2685.078 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.log4j2AsyncFile": + 2853.249 ±(99.9%) 1427.856 ops/ms [Average] + (min, avg, max) = (2645.227, 2853.249, 3086.943), stdev = 220.962 + CI (99.9%): [1425.393, 4281.104] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 16 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.logbackFile + +# Run progress: 16.67% complete, ETA 00:05:04 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +About to delete [target/test-output/logback-async-perf.log] +About to delete [target/test-output/log4j2-async-perf.log] +About to delete [target/test-output/log4j-async-perf.log] +2835.976 ops/ms +# Warmup Iteration 2: 2781.253 ops/ms +Iteration 1: 2798.996 ops/ms +Iteration 2: 2795.579 ops/ms +Iteration 3: 2723.013 ops/ms +Iteration 4: 2581.680 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.logbackFile": + 2724.817 ±(99.9%) 656.893 ops/ms [Average] + (min, avg, max) = (2581.680, 2724.817, 2798.996), stdev = 101.655 + CI (99.9%): [2067.924, 3381.710] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 16 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.reload4jFile + +# Run progress: 33.33% complete, ETA 00:04:03 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +About to delete [target/test-output/logback-async-perf.log] +About to delete [target/test-output/log4j2-async-perf.log] +About to delete [target/test-output/log4j-async-perf.log] +1906.576 ops/ms +# Warmup Iteration 2: 1920.012 ops/ms +Iteration 1: 1896.489 ops/ms +Iteration 2: 1870.884 ops/ms +Iteration 3: 1881.181 ops/ms +Iteration 4: 1721.963 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.reload4jFile": + 1842.629 ±(99.9%) 524.254 ops/ms [Average] + (min, avg, max) = (1721.963, 1842.629, 1896.489), stdev = 81.129 + CI (99.9%): [1318.375, 2366.884] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 16 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.log4j2File + +# Run progress: 50.00% complete, ETA 00:03:02 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +2801.785 ops/ms +# Warmup Iteration 2: 2794.923 ops/ms +Iteration 1: 2854.647 ops/ms +Iteration 2: 2846.182 ops/ms +Iteration 3: 2847.722 ops/ms +Iteration 4: (*interrupt*) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + +java.lang.InterruptedException: sleep interrupted + at java.base/java.lang.Thread.sleep(Native Method) + at java.base/java.lang.Thread.sleep(Thread.java:337) + at java.base/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) + at ch.qos.logback.perf.jmh_generated.FileAppenderBenchmark_log4j2File_jmhTest.log4j2File_Throughput(FileAppenderBenchmark_log4j2File_jmhTest.java:113) + at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) + at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) + at java.base/java.lang.reflect.Method.invoke(Method.java:568) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:470) + at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:453) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) + at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) + at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) + at java.base/java.lang.Thread.run(Thread.java:833) + + + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.log4j2File": + 2849.517 ±(99.9%) 82.257 ops/ms [Average] + (min, avg, max) = (2846.182, 2849.517, 2854.647), stdev = 4.509 + CI (99.9%): [2767.260, 2931.774] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 16 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.logbackFile + +# Run progress: 66.67% complete, ETA 00:02:01 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +2366.511 ops/ms +# Warmup Iteration 2: 2545.603 ops/ms +Iteration 1: 2502.267 ops/ms +Iteration 2: 2358.123 ops/ms +Iteration 3: 2236.851 ops/ms +Iteration 4: 2258.909 ops/ms + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.logbackFile": + 2339.038 ±(99.9%) 781.435 ops/ms [Average] + (min, avg, max) = (2236.851, 2339.038, 2502.267), stdev = 120.928 + CI (99.9%): [1557.602, 3120.473] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 16 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.reload4jFile + +# Run progress: 83.33% complete, ETA 00:01:00 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +1461.186 ops/ms +# Warmup Iteration 2: 1565.954 ops/ms +Iteration 1: 1477.064 ops/ms +Iteration 2: 1429.629 ops/ms +Iteration 3: 1395.733 ops/ms +Iteration 4: 1390.003 ops/ms + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.reload4jFile": + 1423.107 ±(99.9%) 258.456 ops/ms [Average] + (min, avg, max) = (1390.003, 1423.107, 1477.064), stdev = 39.996 + CI (99.9%): [1164.651, 1681.563] (assumes normal distribution) + + +# Run complete. Total time: 00:06:04 + +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. + +Benchmark Mode Cnt Score Error Units +AsyncWithFileAppenderBenchmark.log4j2AsyncFile thrpt 4 2853.249 ± 1427.856 ops/ms +AsyncWithFileAppenderBenchmark.logbackFile thrpt 4 2724.817 ± 656.893 ops/ms +AsyncWithFileAppenderBenchmark.reload4jFile thrpt 4 1842.629 ± 524.254 ops/ms +FileAppenderBenchmark.log4j2File thrpt 3 2849.517 ± 82.257 ops/ms +FileAppenderBenchmark.logbackFile thrpt 4 2339.038 ± 781.435 ops/ms +FileAppenderBenchmark.reload4jFile thrpt 4 1423.107 ± 258.456 ops/ms diff --git a/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-32.txt b/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-32.txt new file mode 100755 index 0000000..866b2e9 --- /dev/null +++ b/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-32.txt @@ -0,0 +1,199 @@ +➜ logback-perf git:(master) ✗ java -jar target/benchmarks.jar ".*FileAppenderBenchmark.*" -f 1 -tu ms -wi 2 -i 4 -to 3 -t 32 +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 32 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.log4j2AsyncFile + +# Run progress: 0.00% complete, ETA 00:06:00 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +About to delete [target/test-output/logback-async-perf.log] +About to delete [target/test-output/log4j2-async-perf.log] +About to delete [target/test-output/log4j-async-perf.log] +2935.618 ops/ms +# Warmup Iteration 2: 2950.642 ops/ms +Iteration 1: 2975.070 ops/ms +Iteration 2: 2650.253 ops/ms +Iteration 3: 2554.820 ops/ms +Iteration 4: 2600.007 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.log4j2AsyncFile": + 2695.038 ±(99.9%) 1232.390 ops/ms [Average] + (min, avg, max) = (2554.820, 2695.038, 2975.070), stdev = 190.714 + CI (99.9%): [1462.647, 3927.428] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 32 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.logbackFile + +# Run progress: 16.67% complete, ETA 00:05:04 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +About to delete [target/test-output/logback-async-perf.log] +About to delete [target/test-output/log4j2-async-perf.log] +About to delete [target/test-output/log4j-async-perf.log] +2339.711 ops/ms +# Warmup Iteration 2: 2353.470 ops/ms +Iteration 1: 2387.730 ops/ms +Iteration 2: 2206.275 ops/ms +Iteration 3: 2097.293 ops/ms +Iteration 4: 2096.220 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.logbackFile": + 2196.879 ±(99.9%) 887.295 ops/ms [Average] + (min, avg, max) = (2096.220, 2196.879, 2387.730), stdev = 137.310 + CI (99.9%): [1309.585, 3084.174] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 32 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.reload4jFile + +# Run progress: 33.33% complete, ETA 00:04:03 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +About to delete [target/test-output/logback-async-perf.log] +About to delete [target/test-output/log4j2-async-perf.log] +About to delete [target/test-output/log4j-async-perf.log] +2277.861 ops/ms +# Warmup Iteration 2: 2345.966 ops/ms +Iteration 1: 2376.651 ops/ms +Iteration 2: 2254.805 ops/ms +Iteration 3: 2185.686 ops/ms +Iteration 4: 2194.361 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.reload4jFile": + 2252.876 ±(99.9%) 569.026 ops/ms [Average] + (min, avg, max) = (2185.686, 2252.876, 2376.651), stdev = 88.057 + CI (99.9%): [1683.850, 2821.902] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 32 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.log4j2File + +# Run progress: 50.00% complete, ETA 00:03:02 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +3485.121 ops/ms +# Warmup Iteration 2: 2948.973 ops/ms +Iteration 1: 2991.754 ops/ms +Iteration 2: 3002.974 ops/ms +Iteration 3: 2959.599 ops/ms +Iteration 4: 3030.833 ops/ms + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.log4j2File": + 2996.290 ±(99.9%) 190.406 ops/ms [Average] + (min, avg, max) = (2959.599, 2996.290, 3030.833), stdev = 29.466 + CI (99.9%): [2805.884, 3186.697] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 32 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.logbackFile + +# Run progress: 66.67% complete, ETA 00:02:01 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +2610.173 ops/ms +# Warmup Iteration 2: 2617.735 ops/ms +Iteration 1: 2601.945 ops/ms +Iteration 2: 2463.201 ops/ms +Iteration 3: 2311.171 ops/ms +Iteration 4: 2267.511 ops/ms + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.logbackFile": + 2410.957 ±(99.9%) 985.251 ops/ms [Average] + (min, avg, max) = (2267.511, 2410.957, 2601.945), stdev = 152.469 + CI (99.9%): [1425.706, 3396.208] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 32 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.reload4jFile + +# Run progress: 83.33% complete, ETA 00:01:00 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +1448.838 ops/ms +# Warmup Iteration 2: 1481.634 ops/ms +Iteration 1: 1479.956 ops/ms +Iteration 2: 1427.995 ops/ms +Iteration 3: 1441.683 ops/ms +Iteration 4: 1437.686 ops/ms + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.reload4jFile": + 1446.830 ±(99.9%) 147.460 ops/ms [Average] + (min, avg, max) = (1427.995, 1446.830, 1479.956), stdev = 22.820 + CI (99.9%): [1299.369, 1594.290] (assumes normal distribution) + + +# Run complete. Total time: 00:06:04 + +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. + +Benchmark Mode Cnt Score Error Units +AsyncWithFileAppenderBenchmark.log4j2AsyncFile thrpt 4 2695.038 ± 1232.390 ops/ms +AsyncWithFileAppenderBenchmark.logbackFile thrpt 4 2196.879 ± 887.295 ops/ms +AsyncWithFileAppenderBenchmark.reload4jFile thrpt 4 2252.876 ± 569.026 ops/ms +FileAppenderBenchmark.log4j2File thrpt 4 2996.290 ± 190.406 ops/ms +FileAppenderBenchmark.logbackFile thrpt 4 2410.957 ± 985.251 ops/ms +FileAppenderBenchmark.reload4jFile thrpt 4 1446.830 ± 147.460 ops/ms diff --git a/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-4.txt b/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-4.txt new file mode 100755 index 0000000..1c3e0b6 --- /dev/null +++ b/results/M2-pro-mac-os-13.2.1/results-2024-06-14T1314-4.txt @@ -0,0 +1,217 @@ +➜ logback-perf git:(master) ✗ java -jar target/benchmarks.jar ".*FileAppenderBenchmark.*" -f 1 -tu ms -wi 2 -i 4 -to 3 -t 4 +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 4 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.log4j2AsyncFile + +# Run progress: 0.00% complete, ETA 00:06:00 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +About to delete [target/test-output/logback-async-perf.log] +About to delete [target/test-output/log4j2-async-perf.log] +About to delete [target/test-output/log4j-async-perf.log] +3114.891 ops/ms +# Warmup Iteration 2: ^C% +➜ logback-perf git:(master) ✗ java -jar target/benchmarks.jar ".*FileAppenderBenchmark.*" -f 1 -tu ms -wi 2 -i 4 -to 3 -t 4 +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 4 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.log4j2AsyncFile + +# Run progress: 0.00% complete, ETA 00:06:00 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +2450.503 ops/ms +# Warmup Iteration 2: 2425.829 ops/ms +Iteration 1: 2286.265 ops/ms +Iteration 2: 2333.634 ops/ms +Iteration 3: 2353.273 ops/ms +Iteration 4: 2486.825 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.log4j2AsyncFile": + 2364.999 ±(99.9%) 555.402 ops/ms [Average] + (min, avg, max) = (2286.265, 2364.999, 2486.825), stdev = 85.949 + CI (99.9%): [1809.597, 2920.402] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 4 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.logbackFile + +# Run progress: 16.67% complete, ETA 00:05:01 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +About to delete [target/test-output/logback-async-perf.log] +About to delete [target/test-output/log4j2-async-perf.log] +About to delete [target/test-output/log4j-async-perf.log] +3217.461 ops/ms +# Warmup Iteration 2: 3249.897 ops/ms +Iteration 1: 3179.547 ops/ms +Iteration 2: 2883.515 ops/ms +Iteration 3: 2867.945 ops/ms +Iteration 4: 2902.252 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.logbackFile": + 2958.315 ±(99.9%) 957.368 ops/ms [Average] + (min, avg, max) = (2867.945, 2958.315, 3179.547), stdev = 148.154 + CI (99.9%): [2000.947, 3915.683] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 4 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.reload4jFile + +# Run progress: 33.33% complete, ETA 00:04:02 +# Fork: 1 of 1 +# Warmup Iteration 1: Deleting files if existent. +About to delete [target/test-output/logback-async-perf.log] +About to delete [target/test-output/log4j2-async-perf.log] +About to delete [target/test-output/log4j-async-perf.log] +2037.943 ops/ms +# Warmup Iteration 2: 2059.679 ops/ms +Iteration 1: 2077.659 ops/ms +Iteration 2: 1962.004 ops/ms +Iteration 3: 1994.494 ops/ms +Iteration 4: 2039.589 ops/ms + + +Result "ch.qos.logback.perf.AsyncWithFileAppenderBenchmark.reload4jFile": + 2018.436 ±(99.9%) 327.649 ops/ms [Average] + (min, avg, max) = (1962.004, 2018.436, 2077.659), stdev = 50.704 + CI (99.9%): [1690.787, 2346.086] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 4 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.log4j2File + +# Run progress: 50.00% complete, ETA 00:03:02 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +3196.783 ops/ms +# Warmup Iteration 2: 2861.073 ops/ms +Iteration 1: 2914.975 ops/ms +Iteration 2: 2928.882 ops/ms +Iteration 3: 2818.363 ops/ms +Iteration 4: 2892.529 ops/ms + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.log4j2File": + 2888.687 ±(99.9%) 318.040 ops/ms [Average] + (min, avg, max) = (2818.363, 2888.687, 2928.882), stdev = 49.217 + CI (99.9%): [2570.647, 3206.728] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 4 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.logbackFile + +# Run progress: 66.67% complete, ETA 00:02:01 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +2733.330 ops/ms +# Warmup Iteration 2: 2780.007 ops/ms +Iteration 1: 2758.236 ops/ms +Iteration 2: 2596.537 ops/ms +Iteration 3: 2441.353 ops/ms +Iteration 4: 2466.399 ops/ms + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.logbackFile": + 2565.631 ±(99.9%) 938.983 ops/ms [Average] + (min, avg, max) = (2441.353, 2565.631, 2758.236), stdev = 145.309 + CI (99.9%): [1626.648, 3504.614] (assumes normal distribution) + + +# JMH version: 1.29 +# VM version: JDK 17.0.7, OpenJDK 64-Bit Server VM, 17.0.7+7-LTS +# VM invoker: /Users/mariankazimir/Library/Java/JavaVirtualMachines/corretto-17.0.7/Contents/Home/bin/java +# VM options: +# Blackhole mode: full + dont-inline hint +# Warmup: 2 iterations, 10 s each +# Measurement: 4 iterations, 10 s each +# Timeout: 3 s per iteration, ***WARNING: The timeout might be too low!*** +# Threads: 4 threads, will synchronize iterations +# Benchmark mode: Throughput, ops/time +# Benchmark: ch.qos.logback.perf.FileAppenderBenchmark.reload4jFile + +# Run progress: 83.33% complete, ETA 00:01:00 +# Fork: 1 of 1 +# Warmup Iteration 1: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. +1604.003 ops/ms +# Warmup Iteration 2: 1699.738 ops/ms +Iteration 1: 1675.263 ops/ms +Iteration 2: 1577.313 ops/ms +Iteration 3: 1514.740 ops/ms +Iteration 4: 1534.961 ops/ms + + +Result "ch.qos.logback.perf.FileAppenderBenchmark.reload4jFile": + 1575.569 ±(99.9%) 461.345 ops/ms [Average] + (min, avg, max) = (1514.740, 1575.569, 1675.263), stdev = 71.394 + CI (99.9%): [1114.225, 2036.914] (assumes normal distribution) + + +# Run complete. Total time: 00:06:03 + +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. + +Benchmark Mode Cnt Score Error Units +AsyncWithFileAppenderBenchmark.log4j2AsyncFile thrpt 4 2364.999 ± 555.402 ops/ms +AsyncWithFileAppenderBenchmark.logbackFile thrpt 4 2958.315 ± 957.368 ops/ms +AsyncWithFileAppenderBenchmark.reload4jFile thrpt 4 2018.436 ± 327.649 ops/ms +FileAppenderBenchmark.log4j2File thrpt 4 2888.687 ± 318.040 ops/ms +FileAppenderBenchmark.logbackFile thrpt 4 2565.631 ± 938.983 ops/ms +FileAppenderBenchmark.reload4jFile thrpt 4 1575.569 ± 461.345 ops/ms