This is an automated email from the ASF dual-hosted git repository.
pkarwasz pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/logging-log4j-transform.git
The following commit(s) were added to refs/heads/main by this push:
new 88f720d Add benchmark results
88f720d is described below
commit 88f720db5fe8e87e29c8c4334cc4c6cb7682802b
Author: Piotr P. Karwasz <[email protected]>
AuthorDate: Tue May 2 23:55:29 2023 +0200
Add benchmark results
---
log4j-transform-maven-plugin/README.adoc | 46 ++++++++++++++++++++++++++++++--
1 file changed, 44 insertions(+), 2 deletions(-)
diff --git a/log4j-transform-maven-plugin/README.adoc
b/log4j-transform-maven-plugin/README.adoc
index 46442d6..10fe289 100644
--- a/log4j-transform-maven-plugin/README.adoc
+++ b/log4j-transform-maven-plugin/README.adoc
@@ -19,6 +19,48 @@
The Transform Plugin is used to postprocess the compiled classes of your
project and replace all Log4j 2.x API calls with
https://logging.apache.org/log4j/2.x/log4j-api/apidocs/org/apache/logging/log4j/LogBuilder.html[`LogBuilder`]
calls with a statically precomputed location.
This allows you to use location information in your logs without incurring in
the *expensive* runtime calls usually used to acquire it.
+== Why do we need it
+
+Finding the location of a logging call is a very expensive operation (a couple
of microseconds).
+
+Running a single threaded
xref:../log4j-transform-perf/src/main/java/org/apache/logging/log4j/transform/perf/LocationBenchmark.java[`LocationBenchmark`]
on a Ryzen 7 2700U laptop with Java 17 gives the following results:
+
+[cols="1,1,1,1,1"]
+|===
+|Logging interface|Precomputed location|Score|Error|Units
+
+|https://logging.apache.org/log4j/2.x/log4j-api/apidocs/org/apache/logging/log4j/LogBuilder.html[`LogBuilder`]
+|yes
+|202343,624
+|±719,875
+|ops/s
+
+|https://logging.apache.org/log4j/2.x/log4j-api/apidocs/org/apache/logging/log4j/Logger.html[`Logger`]
+|yes
+|202579,793
+|±547,961
+|ops/s
+
+|https://logging.apache.org/log4j/2.x/log4j-api/apidocs/org/apache/logging/log4j/LogBuilder.html[`LogBuilder`]
+|no
+|68449,813
+|±5086,148
+|ops/s
+
+|https://logging.apache.org/log4j/2.x/log4j-api/apidocs/org/apache/logging/log4j/Logger.html[`Logger`]
+|no
+|100105,246
+|±13748,554
+|ops/s
+
+|===
+
+The figures show a performance bump of around 5 µs per logging statement when
+https://logging.apache.org/log4j/2.x/log4j-api/apidocs/org/apache/logging/log4j/Logger.html[`Logger`]
+is used and a bump of around 9 µs per logging statement when
+https://logging.apache.org/log4j/2.x/log4j-api/apidocs/org/apache/logging/log4j/LogBuilder.html[`LogBuilder`]
+is used.
+
== How it works
The working principle is very simple: every call to the Log4j 2.x API like
@@ -28,7 +70,7 @@ public void helloLog() {
logger.info(MarkerManager.getMarker("NET"), "Sending {} bytes of data.",
1000);
}
----
-is rewritten at a bytecode levelinto an equivalent `LogBuilder` call:
+is rewritten at a bytecode level into an equivalent `LogBuilder` call:
[source,java]
----
private static final StackTraceElement[] locations = {
@@ -43,7 +85,7 @@ public void helloLog() {
}
----
-In the current implementation locations are stored in classes whose name ends
in `$$Log4j2$$Cache`, so they can not accidentally be used by XML/JSON
serializers.
+In the current implementation locations are stored in classes whose name ends
in `+++$$Log4j2$$Cache+++`, so they can not accidentally be used by XML/JSON
serializers.
== Goals
