Repository: logging-log4j2 Updated Branches: refs/heads/master b647427bd -> 17e04f1ad
LOG4J2-844: Update JMH to 1.1 from 0.7.2. Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/17e04f1a Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/17e04f1a Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/17e04f1a Branch: refs/heads/master Commit: 17e04f1ad4e61a3ef312c26175cf0b9c7c4cb3b2 Parents: b647427 Author: rpopma <[email protected]> Authored: Sat Sep 20 23:01:23 2014 +0900 Committer: rpopma <[email protected]> Committed: Sat Sep 20 23:01:23 2014 +0900 ---------------------------------------------------------------------- log4j-perf/pom.xml | 29 ++++++++-- .../log4j/perf/jmh/AsyncLoggersBenchmark.java | 19 ++++--- .../logging/log4j/perf/jmh/ClocksBenchmark.java | 26 ++++----- .../jmh/ConfiguratorInitializeBenchmark.java | 34 ++++++------ .../log4j/perf/jmh/DebugDisabledBenchmark.java | 26 ++++----- .../perf/jmh/FormatterLoggerBenchmark.java | 26 ++++----- .../log4j/perf/jmh/JdbcAppenderBenchmark.java | 40 +++++++------- .../log4j/perf/jmh/JpaAppenderBenchmark.java | 40 +++++++------- .../perf/jmh/Log4j1AsyncAppenderBenchmark.java | 16 +++--- .../perf/jmh/Log4j2AsyncAppenderBenchmark.java | 16 +++--- .../log4j/perf/jmh/Log4jLogEventBenchmark.java | 57 ++++++++------------ .../perf/jmh/LogbackAsyncAppenderBenchmark.java | 16 +++--- .../log4j/perf/jmh/ReflectionBenchmark.java | 48 +++++++++-------- .../logging/log4j/perf/jmh/SimpleBenchmark.java | 41 +++++++------- .../log4j/perf/jmh/TimeFormatBenchmark.java | 26 ++++----- .../log4j/perf/jmh/UuidGeneratorBenchmark.java | 12 ++--- .../logging/log4j/perf/jmh/package-info.java | 1 + src/changes/changes.xml | 3 ++ 18 files changed, 244 insertions(+), 232 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/pom.xml ---------------------------------------------------------------------- diff --git a/log4j-perf/pom.xml b/log4j-perf/pom.xml index d3d8802..b5723df 100644 --- a/log4j-perf/pom.xml +++ b/log4j-perf/pom.xml @@ -15,7 +15,8 @@ See the License for the specific language governing permissions and limitations under the License. --> -<project xmlns="http://maven.apache.org/POM/4.0.0"; xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd";> +<project xmlns="http://maven.apache.org/POM/4.0.0"; xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; + xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd";> <modelVersion>4.0.0</modelVersion> <parent> <artifactId>log4j</artifactId> @@ -34,18 +35,21 @@ <log4jParentDir>${basedir}/..</log4jParentDir> <docLabel>Log4J Performance Tests</docLabel> <projectDir>/log4j-perf</projectDir> + <jmh.version>1.1</jmh.version> + <javac.target>1.6</javac.target> + <uberjar.name>benchmarks</uberjar.name> </properties> <dependencies> <dependency> <groupId>org.openjdk.jmh</groupId> <artifactId>jmh-core</artifactId> - <version>0.7.2</version> + <version>${jmh.version}</version> </dependency> <dependency> <groupId>org.openjdk.jmh</groupId> <artifactId>jmh-generator-annprocess</artifactId> - <version>0.7.2</version> + <version>${jmh.version}</version> <scope>provided</scope> </dependency> <dependency> @@ -126,8 +130,18 @@ <plugins> <plugin> <groupId>org.apache.maven.plugins</groupId> + <artifactId>maven-compiler-plugin</artifactId> + <version>3.1</version> + <configuration> + <compilerVersion>${javac.target}</compilerVersion> + <source>${javac.target}</source> + <target>${javac.target}</target> + </configuration> + </plugin> + <plugin> + <groupId>org.apache.maven.plugins</groupId> <artifactId>maven-shade-plugin</artifactId> - <version>2.0</version> + <version>2.2</version> <executions> <execution> <phase>package</phase> @@ -136,7 +150,7 @@ </goals> <configuration> <minimizeJar>false</minimizeJar> - <finalName>microbenchmarks</finalName> + <finalName>${uberjar.name}</finalName> <transformers> <transformer implementation="org.apache.maven.plugins.shade.resource.ManifestResourceTransformer"> @@ -145,6 +159,10 @@ </transformers> <filters> <filter> + <!-- + Shading signed JARs will fail without this. + http://stackoverflow.com/questions/999489/invalid-signature-file-when-attempting-to-run-a-jar + --> <artifact>*:*</artifact> <excludes> <exclude>META-INF/*.SF</exclude> @@ -179,6 +197,7 @@ <configuration> <instructions> <Export-Package>org.apache.logging.log4j.perf.jmh</Export-Package> + <Export-Package>org.apache.logging.log4j.perf.jmh.jpa</Export-Package> </instructions> </configuration> </plugin> http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/AsyncLoggersBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/AsyncLoggersBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/AsyncLoggersBenchmark.java index 8d6aa16..74d45dc 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/AsyncLoggersBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/AsyncLoggersBenchmark.java @@ -24,8 +24,8 @@ import java.util.concurrent.TimeUnit; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.core.LifeCycle; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Level; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; @@ -40,13 +40,13 @@ import org.openjdk.jmh.annotations.TearDown; // ============================== HOW TO RUN THIS TEST: ==================================== // // single thread: -// java -jar log4j-perf/target/microbenchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 +// java -jar log4j-perf/target/benchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 // // multiple threads (for example, 4 threads): -// java -jar log4j-perf/target/microbenchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 -t 4 -si true +// java -jar log4j-perf/target/benchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 -t 4 -si true // // Usage help: -// java -jar log4j-perf/target/microbenchmarks.jar -help +// java -jar log4j-perf/target/benchmarks.jar -help // @State(Scope.Thread) public class AsyncLoggersBenchmark { @@ -62,8 +62,7 @@ public class AsyncLoggersBenchmark { public void up() { new File("perftest.log").delete(); System.setProperty("log4j.configurationFile", "perf3PlainNoLoc.xml"); - System.setProperty("Log4jContextSelector", - "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector"); + System.setProperty("Log4jContextSelector", "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector"); logger = LogManager.getLogger(getClass()); } @@ -73,28 +72,28 @@ public class AsyncLoggersBenchmark { new File("perftest.log").delete(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public boolean throughputBaseline() { return logger.isInfoEnabled(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public void throughput() { logger.info(TEST); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public boolean latencyBaseline() { return logger.isInfoEnabled(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public void latency() { http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ClocksBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ClocksBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ClocksBenchmark.java index 7d0daeb..3bfe293 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ClocksBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ClocksBenchmark.java @@ -24,8 +24,8 @@ import org.apache.logging.log4j.core.util.CachedClock; import org.apache.logging.log4j.core.util.Clock; import org.apache.logging.log4j.core.util.CoarseCachedClock; import org.apache.logging.log4j.core.util.SystemClock; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Level; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; @@ -39,13 +39,13 @@ import org.openjdk.jmh.annotations.State; // ============================== HOW TO RUN THIS TEST: ==================================== // // single thread: -// java -jar log4j-perf/target/microbenchmarks.jar ".*Clocks.*" -f 1 -wi 5 -i 5 +// java -jar log4j-perf/target/benchmarks.jar ".*Clocks.*" -f 1 -wi 5 -i 5 // // multiple threads (for example, 4 threads): -// java -jar log4j-perf/target/microbenchmarks.jar ".*Clocks.*" -f 1 -wi 5 -i 5 -t 4 -si true +// java -jar log4j-perf/target/benchmarks.jar ".*Clocks.*" -f 1 -wi 5 -i 5 -t 4 -si true // // Usage help: -// java -jar log4j-perf/target/microbenchmarks.jar -help +// java -jar log4j-perf/target/benchmarks.jar -help // @State(Scope.Thread) public class ClocksBenchmark { @@ -66,55 +66,55 @@ public class ClocksBenchmark { fixedFinalClock = new FixedFinalTimeClock(System.nanoTime()); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public void baseline() { } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public long systemCurrentTimeMillis() { return System.currentTimeMillis(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public long systemClock() { return systemClock.currentTimeMillis(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public long cachedClock() { return cachedClock.currentTimeMillis(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public long oldCachedClock() { return oldCachedClock.currentTimeMillis(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public long coarseCachedClock() { return coarseCachedClock.currentTimeMillis(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public long fixedClock() { return fixedClock.currentTimeMillis(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public long fixedFinalClock() { @@ -146,7 +146,7 @@ public class ClocksBenchmark { return fixedFinalTime; } } - + private static final class OldCachedClock implements Clock { private static final int UPDATE_THRESHOLD = 0x3FF; private static volatile OldCachedClock instance; http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ConfiguratorInitializeBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ConfiguratorInitializeBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ConfiguratorInitializeBenchmark.java index 551aaea..aad69ed 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ConfiguratorInitializeBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ConfiguratorInitializeBenchmark.java @@ -24,8 +24,8 @@ import java.util.concurrent.TimeUnit; import org.apache.logging.log4j.core.LoggerContext; import org.apache.logging.log4j.core.config.ConfigurationSource; import org.apache.logging.log4j.core.config.Configurator; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; import org.openjdk.jmh.annotations.Scope; @@ -33,27 +33,25 @@ import org.openjdk.jmh.annotations.Setup; import org.openjdk.jmh.annotations.State; /** - * This benchmark demonstrates how long it takes for a simple XML configuration file to be parsed and initialize a - * new {@link org.apache.logging.log4j.core.LoggerContext} using that configuration. + * This benchmark demonstrates how long it takes for a simple XML configuration file to be parsed and initialize a new + * {@link org.apache.logging.log4j.core.LoggerContext} using that configuration. */ // TO RUN THIS TEST: -// java -jar target/microbenchmarks.jar '.*ConfiguratorInitializeBenchmark.*' +// java -jar target/benchmarks.jar '.*ConfiguratorInitializeBenchmark.*' @State(Scope.Thread) public class ConfiguratorInitializeBenchmark { - private static final String inlineConfigurationXML = - "<Configuration name='ConfiguratorInitializeTest' status='off'>" + - "<Appenders>" + - "<Console name='STDOUT'>" + - "<PatternLayout pattern='%m%n'/>" + - "</Console>" + - "</Appenders>" + - "<Loggers>" + - "<Root level='error'>" + - "<AppenderRef ref='STDOUT'/>" + - "</Root>" + - "</Loggers>" + - "</Configuration>"; + private static final String inlineConfigurationXML = "<Configuration name='ConfiguratorInitializeTest' status='off'>" + + "<Appenders>" + + "<Console name='STDOUT'>" + + "<PatternLayout pattern='%m%n'/>" + + "</Console>" + + "</Appenders>" + + "<Loggers>" + + "<Root level='error'>" + + "<AppenderRef ref='STDOUT'/>" + + "</Root>" + + "</Loggers>" + "</Configuration>"; private ConfigurationSource configurationSource; @@ -62,7 +60,7 @@ public class ConfiguratorInitializeBenchmark { configurationSource = new ConfigurationSource(new ByteArrayInputStream(inlineConfigurationXML.getBytes())); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SingleShotTime) @OutputTimeUnit(TimeUnit.MILLISECONDS) public LoggerContext initializeLoggerContext() { http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/DebugDisabledBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/DebugDisabledBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/DebugDisabledBenchmark.java index 8104456..45138b8 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/DebugDisabledBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/DebugDisabledBenchmark.java @@ -19,7 +19,7 @@ package org.apache.logging.log4j.perf.jmh; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.Scope; import org.openjdk.jmh.annotations.Setup; import org.openjdk.jmh.annotations.State; @@ -29,11 +29,11 @@ import org.slf4j.LoggerFactory; /** * Benchmarks Log4j 2, Log4j 1, and Logback using the DEBUG level which is disabled for this test. One of the primary * performance concerns of logging frameworks is adding minimal overhead when logging is disabled. Some users disable - * all logging in production, while others disable finer logging levels in production. This benchmark demonstrates - * the overhead in calling {@code logger.isDebugEnabled()} and {@code logger.debug()}. + * all logging in production, while others disable finer logging levels in production. This benchmark demonstrates the + * overhead in calling {@code logger.isDebugEnabled()} and {@code logger.debug()}. */ // HOW TO RUN THIS TEST -// java -jar target/microbenchmarks.jar ".*DebugDisabledBenchmark.*" -f 1 -i 5 -wi 5 -bm sample -tu ns +// java -jar target/benchmarks.jar ".*DebugDisabledBenchmark.*" -f 1 -i 5 -wi 5 -bm sample -tu ns @State(Scope.Thread) public class DebugDisabledBenchmark { Logger log4jLogger; @@ -60,47 +60,47 @@ public class DebugDisabledBenchmark { System.clearProperty("logback.configurationFile"); } - @GenerateMicroBenchmark + @Benchmark public boolean baseline() { return true; } - @GenerateMicroBenchmark + @Benchmark public boolean log4jIsDebugEnabled() { return log4jLogger.isDebugEnabled(); } - @GenerateMicroBenchmark + @Benchmark public boolean slf4jIsDebugEnabled() { return slf4jLogger.isDebugEnabled(); } - @GenerateMicroBenchmark + @Benchmark public boolean log4jClassicIsDebugEnabled() { return log4jClassicLogger.isDebugEnabled(); } - @GenerateMicroBenchmark + @Benchmark public void log4jDebugStringConcatenation() { log4jLogger.debug("This is a debug [" + j + "] message"); } - @GenerateMicroBenchmark + @Benchmark public void slf4jDebugStringConcatenation() { slf4jLogger.debug("This is a debug [" + j + "] message"); } - @GenerateMicroBenchmark + @Benchmark public void log4jClassicDebugStringConcatenation() { log4jClassicLogger.debug("This is a debug [" + j + "] message"); } - @GenerateMicroBenchmark + @Benchmark public void log4jDebugParameterizedString() { log4jLogger.debug("This is a debug [{}] message", j); } - @GenerateMicroBenchmark + @Benchmark public void slf4jDebugParameterizedString() { slf4jLogger.debug("This is a debug [{}] message", j); } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/FormatterLoggerBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/FormatterLoggerBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/FormatterLoggerBenchmark.java index 59230cc..60c0bb7 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/FormatterLoggerBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/FormatterLoggerBenchmark.java @@ -23,8 +23,8 @@ import java.util.concurrent.TimeUnit; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.core.LifeCycle; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Level; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; @@ -39,10 +39,10 @@ import org.openjdk.jmh.annotations.TearDown; // ============================== HOW TO RUN THIS TEST: ==================================== // // single thread: -// java -jar log4j-perf/target/microbenchmarks.jar ".*FormatterLogger.*" -f 1 -wi 5 -i 5 +// java -jar log4j-perf/target/benchmarks.jar ".*FormatterLogger.*" -f 1 -wi 5 -i 5 // // Usage help: -// java -jar log4j-perf/target/microbenchmarks.jar -help +// java -jar log4j-perf/target/benchmarks.jar -help // @State(Scope.Thread) public class FormatterLoggerBenchmark { @@ -64,70 +64,70 @@ public class FormatterLoggerBenchmark { new File("perftest.log").delete(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public boolean throughputBaseline() { return logger.isInfoEnabled(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public void throughputLoggerString() { logger.info("Message with {} parameter", "string"); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public void throughputLoggerDouble() { logger.info("Message with double param: {}", Math.PI); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public void throughputFormatterLoggerString() { formatterLogger.info("Message with %s parameter", "string"); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public void throughputFormatterLoggerDouble() { formatterLogger.info("Message with double param: %f", Math.PI); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public boolean latencyBaseline() { return logger.isInfoEnabled(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public void latencyLoggerString() { logger.info("Message with {} parameter", "string"); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public void latencyLoggerDouble() { logger.info("Message with double param: {}", Math.PI); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public void latencyFormatterLoggerString() { formatterLogger.info("Message with %s parameter", "string"); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public void latencyFormatterLoggerDouble() { http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/JdbcAppenderBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/JdbcAppenderBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/JdbcAppenderBenchmark.java index 0f58298..8893978 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/JdbcAppenderBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/JdbcAppenderBenchmark.java @@ -31,25 +31,25 @@ import org.apache.logging.log4j.core.config.ConfigurationFactory; import org.apache.logging.log4j.core.config.DefaultConfiguration; import org.apache.logging.log4j.core.util.Closer; import org.apache.logging.log4j.status.StatusLogger; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; import org.openjdk.jmh.annotations.Scope; import org.openjdk.jmh.annotations.Setup; import org.openjdk.jmh.annotations.State; import org.openjdk.jmh.annotations.TearDown; -import org.openjdk.jmh.logic.BlackHole; +import org.openjdk.jmh.infra.Blackhole; /** * Tests the overhead of a number of JDBC Appenders. */ // ============================== HOW TO RUN THIS TEST: ==================================== // -// java -jar log4j-perf/target/microbenchmarks.jar ".*JdbcAppenderBenchmark.*" -f 1 -wi 5 -i 5 +// java -jar log4j-perf/target/benchmarks.jar ".*JdbcAppenderBenchmark.*" -f 1 -wi 5 -i 5 // // Usage help: -// java -jar log4j-perf/target/microbenchmarks.jar -help +// java -jar log4j-perf/target/benchmarks.jar -help // @State(Scope.Thread) public class JdbcAppenderBenchmark { @@ -78,57 +78,57 @@ public class JdbcAppenderBenchmark { @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testThroughputH2Message(final BlackHole bh) { + @Benchmark + public void testThroughputH2Message(final Blackhole bh) { loggerH2.info("Test message"); } @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testThroughputH2Exception(final BlackHole bh) { + @Benchmark + public void testThroughputH2Exception(final Blackhole bh) { loggerH2.warn("Test message", exception); } @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.MICROSECONDS) - @GenerateMicroBenchmark - public void testResponseTimeH2Message(final BlackHole bh) { + @Benchmark + public void testResponseTimeH2Message(final Blackhole bh) { loggerH2.info("Test message"); } @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.MICROSECONDS) - @GenerateMicroBenchmark - public void testResponseTimeH2Exception(final BlackHole bh) { + @Benchmark + public void testResponseTimeH2Exception(final Blackhole bh) { loggerH2.warn("Test message", exception); } @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testThroughputHSQLDBMessage(final BlackHole bh) { + @Benchmark + public void testThroughputHSQLDBMessage(final Blackhole bh) { loggerHSQLDB.info("Test message"); } @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testThroughputHSQLDBException(final BlackHole bh) { + @Benchmark + public void testThroughputHSQLDBException(final Blackhole bh) { loggerHSQLDB.warn("Test message", exception); } @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.MICROSECONDS) - @GenerateMicroBenchmark - public void testResponseTimeHSQLDBMessage(final BlackHole bh) { + @Benchmark + public void testResponseTimeHSQLDBMessage(final Blackhole bh) { loggerHSQLDB.info("Test message"); } @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.MICROSECONDS) - @GenerateMicroBenchmark - public void testResponseTimeHSQLDBException(final BlackHole bh) { + @Benchmark + public void testResponseTimeHSQLDBException(final Blackhole bh) { loggerHSQLDB.warn("Test message", exception); } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/JpaAppenderBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/JpaAppenderBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/JpaAppenderBenchmark.java index d94aaac..d97e379 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/JpaAppenderBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/JpaAppenderBenchmark.java @@ -31,25 +31,25 @@ import org.apache.logging.log4j.core.config.ConfigurationFactory; import org.apache.logging.log4j.core.config.DefaultConfiguration; import org.apache.logging.log4j.core.util.Closer; import org.apache.logging.log4j.status.StatusLogger; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; import org.openjdk.jmh.annotations.Scope; import org.openjdk.jmh.annotations.Setup; import org.openjdk.jmh.annotations.State; import org.openjdk.jmh.annotations.TearDown; -import org.openjdk.jmh.logic.BlackHole; +import org.openjdk.jmh.infra.Blackhole; /** * Tests the overhead of a number of JPA Appenders. */ // ============================== HOW TO RUN THIS TEST: ==================================== // -// java -jar log4j-perf/target/microbenchmarks.jar ".*JdbcAppenderBenchmark.*" -f 1 -wi 5 -i 5 +// java -jar log4j-perf/target/benchmarks.jar ".*JdbcAppenderBenchmark.*" -f 1 -wi 5 -i 5 // // Usage help: -// java -jar log4j-perf/target/microbenchmarks.jar -help +// java -jar log4j-perf/target/benchmarks.jar -help // @State(Scope.Thread) public class JpaAppenderBenchmark { @@ -76,57 +76,57 @@ public class JpaAppenderBenchmark { @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testThroughputH2Message(final BlackHole bh) { + @Benchmark + public void testThroughputH2Message(final Blackhole bh) { loggerH2.info("Test message"); } @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testThroughputH2Exception(final BlackHole bh) { + @Benchmark + public void testThroughputH2Exception(final Blackhole bh) { loggerH2.warn("Test message", exception); } @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.MICROSECONDS) - @GenerateMicroBenchmark - public void testResponseTimeH2Message(final BlackHole bh) { + @Benchmark + public void testResponseTimeH2Message(final Blackhole bh) { loggerH2.info("Test message"); } @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.MICROSECONDS) - @GenerateMicroBenchmark - public void testResponseTimeH2Exception(final BlackHole bh) { + @Benchmark + public void testResponseTimeH2Exception(final Blackhole bh) { loggerH2.warn("Test message", exception); } @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testThroughputHSQLDBMessage(final BlackHole bh) { + @Benchmark + public void testThroughputHSQLDBMessage(final Blackhole bh) { loggerHSQLDB.info("Test message"); } @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testThroughputHSQLDBException(final BlackHole bh) { + @Benchmark + public void testThroughputHSQLDBException(final Blackhole bh) { loggerHSQLDB.warn("Test message", exception); } @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.MICROSECONDS) - @GenerateMicroBenchmark - public void testResponseTimeHSQLDBMessage(final BlackHole bh) { + @Benchmark + public void testResponseTimeHSQLDBMessage(final Blackhole bh) { loggerHSQLDB.info("Test message"); } @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.MICROSECONDS) - @GenerateMicroBenchmark - public void testResponseTimeHSQLDBException(final BlackHole bh) { + @Benchmark + public void testResponseTimeHSQLDBException(final Blackhole bh) { loggerHSQLDB.warn("Test message", exception); } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4j1AsyncAppenderBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4j1AsyncAppenderBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4j1AsyncAppenderBenchmark.java index 5dac75c..4915afd 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4j1AsyncAppenderBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4j1AsyncAppenderBenchmark.java @@ -22,8 +22,8 @@ import java.util.concurrent.TimeUnit; import org.apache.log4j.LogManager; import org.apache.log4j.Logger; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Level; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; @@ -38,13 +38,13 @@ import org.openjdk.jmh.annotations.TearDown; // ============================== HOW TO RUN THIS TEST: ==================================== // // single thread: -// java -jar log4j-perf/target/microbenchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 +// java -jar log4j-perf/target/benchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 // // multiple threads (for example, 4 threads): -// java -jar log4j-perf/target/microbenchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 -t 4 -si true +// java -jar log4j-perf/target/benchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 -t 4 -si true // // Usage help: -// java -jar log4j-perf/target/microbenchmarks.jar -help +// java -jar log4j-perf/target/benchmarks.jar -help // public class Log4j1AsyncAppenderBenchmark { @@ -71,28 +71,28 @@ public class Log4j1AsyncAppenderBenchmark { } } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public boolean throughputBaseline(final NormalState e) { return e.logger.isInfoEnabled(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public void throughput(final NormalState e) { e.logger.info(TEST); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public boolean latencyBaseline(final NormalState e) { return e.logger.isInfoEnabled(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public void latency(final NormalState e) { http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4j2AsyncAppenderBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4j2AsyncAppenderBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4j2AsyncAppenderBenchmark.java index f55d64d..d72288a 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4j2AsyncAppenderBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4j2AsyncAppenderBenchmark.java @@ -23,8 +23,8 @@ import java.util.concurrent.TimeUnit; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.core.LifeCycle; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Level; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; @@ -39,13 +39,13 @@ import org.openjdk.jmh.annotations.TearDown; // ============================== HOW TO RUN THIS TEST: ==================================== // // single thread: -// java -jar log4j-perf/target/microbenchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 +// java -jar log4j-perf/target/benchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 // // multiple threads (for example, 4 threads): -// java -jar log4j-perf/target/microbenchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 -t 4 -si true +// java -jar log4j-perf/target/benchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 -t 4 -si true // // Usage help: -// java -jar log4j-perf/target/microbenchmarks.jar -help +// java -jar log4j-perf/target/benchmarks.jar -help // public class Log4j2AsyncAppenderBenchmark { final static char[] CHARS = new char[500]; @@ -71,28 +71,28 @@ public class Log4j2AsyncAppenderBenchmark { } } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public boolean throughputBaseline(final NormalState e) { return e.logger.isInfoEnabled(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public void throughput(final NormalState e) { e.logger.info(TEST); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public boolean latencyBaseline(final NormalState e) { return e.logger.isInfoEnabled(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public void latency(final NormalState e) { http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4jLogEventBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4jLogEventBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4jLogEventBenchmark.java index 65be4c0..8bbe499 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4jLogEventBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4jLogEventBenchmark.java @@ -16,18 +16,18 @@ */ package org.apache.logging.log4j.perf.jmh; +import java.io.Serializable; + import org.apache.logging.log4j.Level; import org.apache.logging.log4j.core.LogEvent; import org.apache.logging.log4j.core.impl.Log4jLogEvent; import org.apache.logging.log4j.message.Message; import org.apache.logging.log4j.message.SimpleMessage; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.Scope; import org.openjdk.jmh.annotations.Setup; import org.openjdk.jmh.annotations.State; -import org.openjdk.jmh.logic.BlackHole; - -import java.io.Serializable; +import org.openjdk.jmh.infra.Blackhole; @State(Scope.Thread) public class Log4jLogEventBenchmark { @@ -40,56 +40,43 @@ public class Log4jLogEventBenchmark { ERROR = new Exception("test"); } - @GenerateMicroBenchmark - public void testBaseline(final BlackHole bh) { + @Benchmark + public void testBaseline(final Blackhole bh) { } - @GenerateMicroBenchmark + @Benchmark public LogEvent createLogEventWithoutException() { return new Log4jLogEvent("a.b.c", null, "a.b.c", Level.INFO, MESSAGE, null); } - @GenerateMicroBenchmark + @Benchmark public LogEvent createLogEventWithoutExceptionUsingBuilder() { - return Log4jLogEvent.newBuilder() - .setLoggerName("a.b.c") - .setLoggerFqcn("a.b.c") - .setLevel(Level.INFO) - .setMessage(MESSAGE) - .build(); + return Log4jLogEvent.newBuilder().setLoggerName("a.b.c").setLoggerFqcn("a.b.c").setLevel(Level.INFO) + .setMessage(MESSAGE).build(); } - @GenerateMicroBenchmark + @Benchmark public LogEvent createLogEventWithExceptionUsingBuilder() { - return Log4jLogEvent.newBuilder() - .setLoggerName("a.b.c") - .setLoggerFqcn("a.b.c") - .setLevel(Level.INFO) - .setMessage(MESSAGE) - .setThrown(ERROR) - .build(); + return Log4jLogEvent.newBuilder().setLoggerName("a.b.c").setLoggerFqcn("a.b.c").setLevel(Level.INFO) + .setMessage(MESSAGE).setThrown(ERROR).build(); } - @GenerateMicroBenchmark + @Benchmark public StackTraceElement getSourceLocationOfLogEvent() { - final LogEvent event = Log4jLogEvent.newBuilder() - .setLoggerName(this.getClass().getName()) - .setLoggerFqcn(this.getClass().getName()) - .setLevel(Level.INFO) - .setMessage(MESSAGE) - .build(); + final LogEvent event = Log4jLogEvent.newBuilder().setLoggerName(this.getClass().getName()) + .setLoggerFqcn(this.getClass().getName()).setLevel(Level.INFO).setMessage(MESSAGE).build(); event.setIncludeLocation(true); return event.getSource(); } - @GenerateMicroBenchmark + @Benchmark public Serializable createSerializableLogEventProxyWithoutException() { final Log4jLogEvent event = new Log4jLogEvent("a.b.c", null, "a.b.c", Level.INFO, MESSAGE, null); return Log4jLogEvent.serialize(event, false); } - @GenerateMicroBenchmark - public Serializable createSerializableLogEventProxyWithException(final BlackHole bh) { + @Benchmark + public Serializable createSerializableLogEventProxyWithException(final Blackhole bh) { final Log4jLogEvent event = new Log4jLogEvent("a.b.c", null, "a.b.c", Level.INFO, MESSAGE, ERROR); return Log4jLogEvent.serialize(event, false); } @@ -97,12 +84,12 @@ public class Log4jLogEventBenchmark { // ============================== HOW TO RUN THIS TEST: ==================================== // // In sampling mode (latency test): - // java -jar log4j-perf/target/microbenchmarks.jar ".*Log4jLogEventBenchmark.*" -i 5 -f 1 -wi 5 -bm sample -tu ns + // java -jar log4j-perf/target/benchmarks.jar ".*Log4jLogEventBenchmark.*" -i 5 -f 1 -wi 5 -bm sample -tu ns // // Throughput test: - // java -jar microbenchmarks.jar ".*Log4jLogEventBenchmark.*" -i 5 -f 1 -wi 5 -bm Throughput -tu ms + // java -jar benchmarks.jar ".*Log4jLogEventBenchmark.*" -i 5 -f 1 -wi 5 -bm Throughput -tu ms // // Usage help: - // java -jar log4j-perf/target/microbenchmarks.jar -help + // java -jar log4j-perf/target/benchmarks.jar -help // } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/LogbackAsyncAppenderBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/LogbackAsyncAppenderBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/LogbackAsyncAppenderBenchmark.java index 7b2403b..bc20303 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/LogbackAsyncAppenderBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/LogbackAsyncAppenderBenchmark.java @@ -20,8 +20,8 @@ import java.io.File; import java.util.Arrays; import java.util.concurrent.TimeUnit; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Level; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; @@ -40,13 +40,13 @@ import ch.qos.logback.core.spi.LifeCycle; // ============================== HOW TO RUN THIS TEST: ==================================== // // single thread: -// java -jar log4j-perf/target/microbenchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 +// java -jar log4j-perf/target/benchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 // // multiple threads (for example, 4 threads): -// java -jar log4j-perf/target/microbenchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 -t 4 -si true +// java -jar log4j-perf/target/benchmarks.jar ".*Async.*Benchmark.*" -f 1 -wi 5 -i 5 -t 4 -si true // // Usage help: -// java -jar log4j-perf/target/microbenchmarks.jar -help +// java -jar log4j-perf/target/benchmarks.jar -help // public class LogbackAsyncAppenderBenchmark { @@ -73,28 +73,28 @@ public class LogbackAsyncAppenderBenchmark { } } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public boolean throughputBaseline(final NormalState e) { return e.logger.isInfoEnabled(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) public void throughput(final NormalState e) { e.logger.info(TEST); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public boolean latencyBaseline(final NormalState e) { return e.logger.isInfoEnabled(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public void latency(final NormalState e) { http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ReflectionBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ReflectionBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ReflectionBenchmark.java index 2d98f6b..fbaaffc 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ReflectionBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ReflectionBenchmark.java @@ -23,22 +23,28 @@ import java.util.Random; import org.apache.logging.log4j.core.impl.ReflectiveCallerClassUtility; import org.apache.logging.log4j.message.Message; import org.apache.logging.log4j.message.StringFormattedMessage; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.Level; import org.openjdk.jmh.annotations.Scope; import org.openjdk.jmh.annotations.Setup; import org.openjdk.jmh.annotations.State; + import sun.reflect.Reflection; /** - * <p>Benchmarks the different ways the caller class can be obtained. - * To run this in sampling mode (latency test):</p> + * <p> + * Benchmarks the different ways the caller class can be obtained. To run this in sampling mode (latency test): + * </p> + * * <pre> - * java -jar microbenchmarks.jar ".*ReflectionBenchmark.*" -i 5 -f 1 -wi 5 -bm sample -tu ns + * java -jar benchmarks.jar ".*ReflectionBenchmark.*" -i 5 -f 1 -wi 5 -bm sample -tu ns * </pre> - * <p>To run this in throughput testing mode:</p> + * <p> + * To run this in throughput testing mode: + * </p> + * * <pre> - * java -jar microbenchmarks.jar ".*ReflectionBenchmark.*" -i 5 -f 1 -wi 5 -bm Throughput -tu ms + * java -jar benchmarks.jar ".*ReflectionBenchmark.*" -i 5 -f 1 -wi 5 -bm Throughput -tu ms * </pre> */ public class ReflectionBenchmark { @@ -56,60 +62,60 @@ public class ReflectionBenchmark { } } - @GenerateMicroBenchmark + @Benchmark public void baseline() { } - @GenerateMicroBenchmark + @Benchmark public String test01_getCallerClassNameFromStackTrace() { return new Throwable().getStackTrace()[3].getClassName(); } - @GenerateMicroBenchmark + @Benchmark public String test02_getCallerClassNameFromThreadStackTrace() { return Thread.currentThread().getStackTrace()[3].getClassName(); } - @GenerateMicroBenchmark + @Benchmark public String test03_getCallerClassNameReflectively() { return ReflectiveCallerClassUtility.getCaller(3).getName(); } - @GenerateMicroBenchmark + @Benchmark public String test04_getCallerClassNameSunReflection() { return Reflection.getCallerClass(3).getName(); } - @GenerateMicroBenchmark + @Benchmark public Class<?> test05_getStackTraceClassForClassName() throws ClassNotFoundException { return Class.forName(new Throwable().getStackTrace()[3].getClassName()); } - @GenerateMicroBenchmark + @Benchmark public Class<?> test06_getThreadStackTraceClassForClassName() throws ClassNotFoundException { return Class.forName(Thread.currentThread().getStackTrace()[3].getClassName()); } - @GenerateMicroBenchmark + @Benchmark public Class<?> test07_getReflectiveCallerClassUtility() { return ReflectiveCallerClassUtility.getCaller(3); } - @GenerateMicroBenchmark + @Benchmark public Class<?> test08_getDirectSunReflection() { return Reflection.getCallerClass(3); } - @GenerateMicroBenchmark + @Benchmark public Message test09_getMessageUsingNew(final RandomInteger rng) { return new StringFormattedMessage("Hello %i", rng.random); } - @GenerateMicroBenchmark - public Message test10_getMessageUsingReflection(final RandomInteger rng) - throws NoSuchMethodException, IllegalAccessException, InvocationTargetException, InstantiationException { + @Benchmark + public Message test10_getMessageUsingReflection(final RandomInteger rng) throws NoSuchMethodException, + IllegalAccessException, InvocationTargetException, InstantiationException { final Constructor<? extends Message> constructor = StringFormattedMessage.class.getConstructor(String.class, - Object[].class); - return constructor.newInstance("Hello %i", new Object[]{rng.random}); + Object[].class); + return constructor.newInstance("Hello %i", new Object[] { rng.random }); } } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/SimpleBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/SimpleBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/SimpleBenchmark.java index afca883..1a082a7 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/SimpleBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/SimpleBenchmark.java @@ -25,24 +25,24 @@ import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.core.LoggerContext; import org.apache.logging.log4j.core.config.Configuration; import org.apache.logging.log4j.core.config.DefaultConfiguration; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; import org.openjdk.jmh.annotations.Scope; import org.openjdk.jmh.annotations.Setup; import org.openjdk.jmh.annotations.State; -import org.openjdk.jmh.logic.BlackHole; +import org.openjdk.jmh.infra.Blackhole; /** * Tests the overhead of disabled logging. */ // ============================== HOW TO RUN THIS TEST: ==================================== // -// java -jar log4j-perf/target/microbenchmarks.jar ".*SimpleBenchmark.*" -f 1 -wi 5 -i 5 +// java -jar log4j-perf/target/benchmarks.jar ".*SimpleBenchmark.*" -f 1 -wi 5 -i 5 // // Usage help: -// java -jar log4j-perf/target/microbenchmarks.jar -help +// java -jar log4j-perf/target/benchmarks.jar -help // @State(Scope.Thread) public class SimpleBenchmark { @@ -61,56 +61,55 @@ public class SimpleBenchmark { @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testBaselineThroughput(final BlackHole bh) { + @Benchmark + public void testBaselineThroughput(final Blackhole bh) { } @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testIsDebugEnabledThroughput(final BlackHole bh) { + @Benchmark + public void testIsDebugEnabledThroughput(final Blackhole bh) { bh.consume(logger.isDebugEnabled()); } @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testIsEnabledLevelThroughput(final BlackHole bh) { + @Benchmark + public void testIsEnabledLevelThroughput(final Blackhole bh) { bh.consume(logger.isEnabled(Level.DEBUG)); } @BenchmarkMode(Mode.Throughput) @OutputTimeUnit(TimeUnit.SECONDS) - @GenerateMicroBenchmark - public void testDebugDisabledThroughput(final BlackHole bh) { + @Benchmark + public void testDebugDisabledThroughput(final Blackhole bh) { logger.debug(msg); } - @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) - @GenerateMicroBenchmark - public void testBaselineResponseTime(final BlackHole bh) { + @Benchmark + public void testBaselineResponseTime(final Blackhole bh) { } @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) - @GenerateMicroBenchmark - public void testIsDebugEnabledResponseTime(final BlackHole bh) { + @Benchmark + public void testIsDebugEnabledResponseTime(final Blackhole bh) { bh.consume(logger.isDebugEnabled()); } @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) - @GenerateMicroBenchmark - public void testIsEnabledLevelResponseTime(final BlackHole bh) { + @Benchmark + public void testIsEnabledLevelResponseTime(final Blackhole bh) { bh.consume(logger.isEnabled(Level.DEBUG)); } @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) - @GenerateMicroBenchmark - public void testDebugDisabledResponseTime(final BlackHole bh) { + @Benchmark + public void testDebugDisabledResponseTime(final Blackhole bh) { logger.debug(msg); } } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/TimeFormatBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/TimeFormatBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/TimeFormatBenchmark.java index efed142..9d500fb 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/TimeFormatBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/TimeFormatBenchmark.java @@ -24,8 +24,8 @@ import java.util.Date; import java.util.concurrent.TimeUnit; import org.apache.logging.log4j.core.util.Charsets; +import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; import org.openjdk.jmh.annotations.Scope; @@ -37,13 +37,13 @@ import org.openjdk.jmh.annotations.State; // ============================== HOW TO RUN THIS TEST: ==================================== // // single thread: -// java -jar log4j-perf/target/microbenchmarks.jar ".*TimeFormat.*" -f 1 -wi 5 -i 5 +// java -jar log4j-perf/target/benchmarks.jar ".*TimeFormat.*" -f 1 -wi 5 -i 5 // // multiple threads (for example, 4 threads): -// java -jar log4j-perf/target/microbenchmarks.jar ".*TimeFormat.*" -f 1 -wi 5 -i 5 -t 4 -si true +// java -jar log4j-perf/target/benchmarks.jar ".*TimeFormat.*" -f 1 -wi 5 -i 5 -t 4 -si true // // Usage help: -// java -jar log4j-perf/target/microbenchmarks.jar -help +// java -jar log4j-perf/target/benchmarks.jar -help // @State(Scope.Thread) public class TimeFormatBenchmark { @@ -66,7 +66,7 @@ public class TimeFormatBenchmark { } private long calcMidnightMillis(int addDays) { - //Calendar cal = Calendar.getInstance(TimeZone.getTimeZone("UCT")); + // Calendar cal = Calendar.getInstance(TimeZone.getTimeZone("UCT")); Calendar cal = Calendar.getInstance(); cal.set(Calendar.HOUR_OF_DAY, 0); cal.set(Calendar.MINUTE, 0); @@ -81,20 +81,20 @@ public class TimeFormatBenchmark { System.out.println(new TimeFormatBenchmark().customFormatString(new BufferState())); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public void baseline() { } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public String simpleDateFormatString() { return simpleDateFormat.format(new Date()); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public int simpleDateFormatBytes(BufferState state) { @@ -105,7 +105,7 @@ public class TimeFormatBenchmark { return state.buffer.position(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public String customFastFormatString(BufferState state) { @@ -114,7 +114,7 @@ public class TimeFormatBenchmark { return new String(state.buffer.array(), 0, state.buffer.position(), Charsets.UTF_8); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public int customFastFormatBytes(BufferState state) { @@ -123,7 +123,7 @@ public class TimeFormatBenchmark { return state.buffer.position(); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public String customFormatString(BufferState state) { @@ -132,7 +132,7 @@ public class TimeFormatBenchmark { return new String(state.buffer.array(), 0, state.buffer.position(), Charsets.UTF_8); } - @GenerateMicroBenchmark + @Benchmark @BenchmarkMode(Mode.SampleTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public int customFormatBytes(BufferState state) { @@ -209,7 +209,7 @@ public class TimeFormatBenchmark { int hours = ms / 3600000; ms -= 3600000 * hours; - + int minutes = ms / 60000; ms -= 60000 * minutes; http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/UuidGeneratorBenchmark.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/UuidGeneratorBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/UuidGeneratorBenchmark.java index d707b09..b388653 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/UuidGeneratorBenchmark.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/UuidGeneratorBenchmark.java @@ -20,31 +20,31 @@ package org.apache.logging.log4j.perf.jmh; import java.util.UUID; import org.apache.logging.log4j.core.util.UuidUtil; -import org.openjdk.jmh.annotations.GenerateMicroBenchmark; +import org.openjdk.jmh.annotations.Benchmark; /** * Compares random UUID generation with time-based UUID generation. */ // ============================== HOW TO RUN THIS TEST: ==================================== // -// java -jar log4j-perf/target/microbenchmarks.jar ".*UuidGeneratorBenchmark.*" -f 1 -wi 5 -i 5 +// java -jar log4j-perf/target/benchmarks.jar ".*UuidGeneratorBenchmark.*" -f 1 -wi 5 -i 5 // // Usage help: -// java -jar log4j-perf/target/microbenchmarks.jar -help +// java -jar log4j-perf/target/benchmarks.jar -help // public class UuidGeneratorBenchmark { - @GenerateMicroBenchmark + @Benchmark public UUID base() { return null; } - @GenerateMicroBenchmark + @Benchmark public UUID randomUUID() { return UUID.randomUUID(); } - @GenerateMicroBenchmark + @Benchmark public UUID timeBasedUUID() { return UuidUtil.getTimeBasedUuid(); } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/package-info.java ---------------------------------------------------------------------- diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/package-info.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/package-info.java index 3df2492..4ab865c 100644 --- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/package-info.java +++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/package-info.java @@ -21,3 +21,4 @@ * </pre> */ package org.apache.logging.log4j.perf.jmh; + http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/17e04f1a/src/changes/changes.xml ---------------------------------------------------------------------- diff --git a/src/changes/changes.xml b/src/changes/changes.xml index 3475622..be59bfe 100644 --- a/src/changes/changes.xml +++ b/src/changes/changes.xml @@ -24,6 +24,9 @@ </properties> <body> <release version="2.1" date="2014-??-??" description="Bug fixes and enhancements"> + <action issue="LOG4J2-844" dev="rpopma" type="update"> + Update JMH to 1.1 from 0.7.2. + </action> <action issue="LOG4J2-843" dev="rpopma" type="fix"> Migrate JpaHyperSqlAppenderTest JUnit performance test to log4j-perf. </action>
