001    /*
002     * Licensed to the Apache Software Foundation (ASF) under one or more
003     * contributor license agreements. See the NOTICE file distributed with
004     * this work for additional information regarding copyright ownership.
005     * The ASF licenses this file to You under the Apache license, Version 2.0
006     * (the "License"); you may not use this file except in compliance with
007     * the License. You may obtain a copy of the License at
008     *
009     *      http://www.apache.org/licenses/LICENSE-2.0
010     *
011     * Unless required by applicable law or agreed to in writing, software
012     * distributed under the License is distributed on an "AS IS" BASIS,
013     * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
014     * See the license for the specific language governing permissions and
015     * limitations under the license.
016     */
017    
018    package org.apache.logging.log4j.perf.jmh;
019    
020    import java.io.File;
021    import java.util.concurrent.TimeUnit;
022    
023    import org.apache.logging.log4j.LogManager;
024    import org.apache.logging.log4j.Logger;
025    import org.apache.logging.log4j.core.LifeCycle;
026    import org.openjdk.jmh.annotations.BenchmarkMode;
027    import org.openjdk.jmh.annotations.GenerateMicroBenchmark;
028    import org.openjdk.jmh.annotations.Level;
029    import org.openjdk.jmh.annotations.Mode;
030    import org.openjdk.jmh.annotations.OutputTimeUnit;
031    import org.openjdk.jmh.annotations.Scope;
032    import org.openjdk.jmh.annotations.Setup;
033    import org.openjdk.jmh.annotations.State;
034    import org.openjdk.jmh.annotations.TearDown;
035    
036    /**
037     * Tests Log4j2 Formatter Logger performance.
038     */
039    // ============================== HOW TO RUN THIS TEST: ====================================
040    //
041    // single thread:
042    // java -jar log4j-perf/target/microbenchmarks.jar ".*FormatterLogger.*" -f 1 -wi 5 -i 5
043    //
044    // Usage help:
045    // java -jar log4j-perf/target/microbenchmarks.jar -help
046    //
047    @State(Scope.Thread)
048    public class FormatterLoggerBenchmark {
049    
050        Logger logger;
051        Logger formatterLogger;
052    
053        @Setup(Level.Trial)
054        public void up() {
055            new File("perftest.log").delete();
056            System.setProperty("log4j.configurationFile", "perf3PlainNoLoc.xml");
057            logger = LogManager.getLogger(getClass());
058            formatterLogger = LogManager.getLogger("formatter");
059        }
060    
061        @TearDown(Level.Trial)
062        public void down() {
063            ((LifeCycle) LogManager.getContext(false)).stop();
064            new File("perftest.log").delete();
065        }
066    
067        @GenerateMicroBenchmark
068        @BenchmarkMode(Mode.Throughput)
069        @OutputTimeUnit(TimeUnit.SECONDS)
070        public boolean throughputBaseline() {
071            return logger.isInfoEnabled();
072        }
073    
074        @GenerateMicroBenchmark
075        @BenchmarkMode(Mode.Throughput)
076        @OutputTimeUnit(TimeUnit.SECONDS)
077        public void throughputLoggerString() {
078            logger.info("Message with {} parameter", "string");
079        }
080    
081        @GenerateMicroBenchmark
082        @BenchmarkMode(Mode.Throughput)
083        @OutputTimeUnit(TimeUnit.SECONDS)
084        public void throughputLoggerDouble() {
085            logger.info("Message with double param: {}", Math.PI);
086        }
087    
088        @GenerateMicroBenchmark
089        @BenchmarkMode(Mode.Throughput)
090        @OutputTimeUnit(TimeUnit.SECONDS)
091        public void throughputFormatterLoggerString() {
092            formatterLogger.info("Message with %s parameter", "string");
093        }
094    
095        @GenerateMicroBenchmark
096        @BenchmarkMode(Mode.Throughput)
097        @OutputTimeUnit(TimeUnit.SECONDS)
098        public void throughputFormatterLoggerDouble() {
099            formatterLogger.info("Message with double param: %f", Math.PI);
100        }
101    
102        @GenerateMicroBenchmark
103        @BenchmarkMode(Mode.SampleTime)
104        @OutputTimeUnit(TimeUnit.NANOSECONDS)
105        public boolean latencyBaseline() {
106            return logger.isInfoEnabled();
107        }
108    
109        @GenerateMicroBenchmark
110        @BenchmarkMode(Mode.SampleTime)
111        @OutputTimeUnit(TimeUnit.NANOSECONDS)
112        public void latencyLoggerString() {
113            logger.info("Message with {} parameter", "string");
114        }
115    
116        @GenerateMicroBenchmark
117        @BenchmarkMode(Mode.SampleTime)
118        @OutputTimeUnit(TimeUnit.NANOSECONDS)
119        public void latencyLoggerDouble() {
120            logger.info("Message with double param: {}", Math.PI);
121        }
122    
123        @GenerateMicroBenchmark
124        @BenchmarkMode(Mode.SampleTime)
125        @OutputTimeUnit(TimeUnit.NANOSECONDS)
126        public void latencyFormatterLoggerString() {
127            formatterLogger.info("Message with %s parameter", "string");
128        }
129    
130        @GenerateMicroBenchmark
131        @BenchmarkMode(Mode.SampleTime)
132        @OutputTimeUnit(TimeUnit.NANOSECONDS)
133        public void latencyFormatterLoggerDouble() {
134            formatterLogger.info("Message with double param: %f", Math.PI);
135        }
136    }