1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18 package org.apache.logging.log4j.perf.jmh;
19
20 import java.io.File;
21 import java.util.concurrent.TimeUnit;
22
23 import org.apache.logging.log4j.LogManager;
24 import org.apache.logging.log4j.Logger;
25 import org.apache.logging.log4j.core.LifeCycle;
26 import org.openjdk.jmh.annotations.BenchmarkMode;
27 import org.openjdk.jmh.annotations.GenerateMicroBenchmark;
28 import org.openjdk.jmh.annotations.Level;
29 import org.openjdk.jmh.annotations.Mode;
30 import org.openjdk.jmh.annotations.OutputTimeUnit;
31 import org.openjdk.jmh.annotations.Scope;
32 import org.openjdk.jmh.annotations.Setup;
33 import org.openjdk.jmh.annotations.State;
34 import org.openjdk.jmh.annotations.TearDown;
35
36
37
38
39
40
41
42
43
44
45
46
47 @State(Scope.Thread)
48 public class FormatterLoggerBenchmark {
49
50 Logger logger;
51 Logger formatterLogger;
52
53 @Setup(Level.Trial)
54 public void up() {
55 new File("perftest.log").delete();
56 System.setProperty("log4j.configurationFile", "perf3PlainNoLoc.xml");
57 logger = LogManager.getLogger(getClass());
58 formatterLogger = LogManager.getLogger("formatter");
59 }
60
61 @TearDown(Level.Trial)
62 public void down() {
63 ((LifeCycle) LogManager.getContext(false)).stop();
64 new File("perftest.log").delete();
65 }
66
67 @GenerateMicroBenchmark
68 @BenchmarkMode(Mode.Throughput)
69 @OutputTimeUnit(TimeUnit.SECONDS)
70 public boolean throughputBaseline() {
71 return logger.isInfoEnabled();
72 }
73
74 @GenerateMicroBenchmark
75 @BenchmarkMode(Mode.Throughput)
76 @OutputTimeUnit(TimeUnit.SECONDS)
77 public void throughputLoggerString() {
78 logger.info("Message with {} parameter", "string");
79 }
80
81 @GenerateMicroBenchmark
82 @BenchmarkMode(Mode.Throughput)
83 @OutputTimeUnit(TimeUnit.SECONDS)
84 public void throughputLoggerDouble() {
85 logger.info("Message with double param: {}", Math.PI);
86 }
87
88 @GenerateMicroBenchmark
89 @BenchmarkMode(Mode.Throughput)
90 @OutputTimeUnit(TimeUnit.SECONDS)
91 public void throughputFormatterLoggerString() {
92 formatterLogger.info("Message with %s parameter", "string");
93 }
94
95 @GenerateMicroBenchmark
96 @BenchmarkMode(Mode.Throughput)
97 @OutputTimeUnit(TimeUnit.SECONDS)
98 public void throughputFormatterLoggerDouble() {
99 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 }