You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by sw...@apache.org on 2025/09/15 05:13:33 UTC

(logging-log4cxx) 01/01: Include sample performance measurement data in web-site information

This is an automated email from the ASF dual-hosted git repository.

swebb2066 pushed a commit to branch add_benchmark_timing_data
in repository https://gitbox.apache.org/repos/asf/logging-log4cxx.git

commit 4ef3134e40a9736f33501e504c44ec886a4567d9
Author: Stephen Webb <sw...@gmail.com>
AuthorDate: Mon Sep 15 15:13:03 2025 +1000

    Include sample performance measurement data in web-site information
---
 src/site/markdown/performance.md | 59 ++++++++++++++++++++++++++++++++--------
 1 file changed, 48 insertions(+), 11 deletions(-)

diff --git a/src/site/markdown/performance.md b/src/site/markdown/performance.md
index f64655c4..200fe9d0 100644
--- a/src/site/markdown/performance.md
+++ b/src/site/markdown/performance.md
@@ -21,23 +21,17 @@ Log4cxx Performance {#performance}
  limitations under the License.
 -->
 
-One important question with a logging library is: is it fast enough?  While
-Log4cxx may not be the fastest logging implementation, it is more than fast
+One important question with a logging library is: is it fast enough?
+While Log4cxx may not be the fastest logging implementation, it is more than fast
 enough for the vast majority of cases.
 
-In performance testing done on a developer's system(utilising an Intel
-i5-8400 processor and a virtual machine), it is possible for Log4cxx to handle
-over 2,000,000 messages/second in a single-threaded application.  Since
-Log4cxx is designed to be multithread-safe, logging from multiple threads makes
-this throughput much lower.  Delays in writing messages to disk can also
-greatly decrease performance, depending on how much data is being logged.
-
-If the logging of a particular level is disabled, performance can also be
-a lot better.  While Log4cxx can generate 2,000,000 log messages/second,
+While Log4cxx can generate 2,000,000 log messages/second,
 skipping a disabled logging request requires only a few nano-seconds,
 so application performance is not affected when
 logging requests are not removed from the release build.
 
+Benchmark testing shows MessageBuffer (i.e. std::stringstream) filling
+consumes the majority of CPU time when the logging request is not disabled.
 For the best performance, use the `LOG4CXX_[level]_FMT` series of macros,
 as the [{fmt}](https://fmt.dev/latest/index.html) library
 they use is significantly faster
@@ -65,3 +59,46 @@ The throughput tests may be built by
 specifying `BUILD_THROUGHPUT` with CMake when building Log4cxx.
 The benckmark tests require Google's [Benchmark](https://github.com/google/benchmark) library
 and may be built by specifying `BUILD_BENCHMARK_CHECKS` with CMake when building Log4cxx.
+
+The following table shows some timings from the tests that use Googles's benchmarking library.
+
+    g++ (Ubuntu 11.4.0-1ubuntu1~22.04.2) 11.4.0
+	Run on (8 X 2328.61 MHz CPU s)
+	CPU Caches:
+	  L1 Data 32 KiB (x4)
+	  L1 Instruction 32 KiB (x4)
+	  L2 Unified 256 KiB (x4)
+	  L3 Unified 6144 KiB (x1)
+	Load Average: 0.07, 0.03, 0.01
+
+| Benchmark    | Time         | CPU          |   Iterations |
+| :----------- | -----------: | -----------: | -----------: |
+| Testing disabled logging request | 0.473 ns | 0.473 ns | 1000000000 |
+| Testing disabled logging request/threads:6 | 0.130 ns | 0.777 ns | 816416202 |
+| Appending 5 char string using MessageBuffer, pattern: \%m\%n | 346 ns | 346 ns | 2014476 |
+| Appending 5 char string using MessageBuffer, pattern: \%m\%n/threads:6 | 450 ns | 2522 ns | 287886 |
+| Appending 49 char string using MessageBuffer, pattern: \%m\%n | 387 ns | 387 ns | 1805660 |
+| Appending 49 char string using MessageBuffer, pattern: \%m\%n/threads:6 | 490 ns | 2691 ns | 235698 |
+| Appending int value using MessageBuffer, pattern: \%m\%n | 538 ns | 538 ns | 1301436 |
+| Appending int value using MessageBuffer, pattern: \%m\%n/threads:6 | 496 ns | 2775 ns | 238962 |
+| Appending int+float using MessageBuffer, pattern: \%m\%n | 921 ns | 921 ns | 762785 |
+| Appending int+float using MessageBuffer, pattern: \%m\%n/threads:6 | 576 ns | 3324 ns | 201900 |
+| Appending int value using MessageBuffer, pattern: [\%d] \%m\%n | 566 ns | 566 ns | 1233924 |
+| Appending int value using MessageBuffer, pattern: [\%d] [\%c] [\%p] \%m\%n | 624 ns | 624 ns | 1122040 |
+| Appending 49 char string using FMT, pattern: \%m\%n | 360 ns | 360 ns | 1945236 |
+| Appending 49 char string using FMT, pattern: \%m\%n/threads:6 | 489 ns | 2666 ns | 248046 |
+| Appending int value using FMT, pattern: \%m\%n | 388 ns | 388 ns | 1804423 |
+| Appending int value using FMT, pattern: \%m\%n/threads:6 | 496 ns | 2720 ns | 253938 |
+| Appending int+float using FMT, pattern: \%m\%n | 519 ns | 519 ns | 1352503 |
+| Appending int+float using FMT, pattern: \%m\%n/threads:6 | 515 ns | 2900 ns | 229374 |
+| Async, Sending int+float using MessageBuffer | 1113 ns | 1113 ns | 633889 |
+| Async, Sending int+float using MessageBuffer/threads:6 | 545 ns | 3254 ns | 211344 |
+| Logging int+float using MessageBuffer, pattern: \%d \%m\%n | 1079 ns | 1078 ns | 641626 |
+| Logging int+float using MessageBuffer, pattern: \%d \%m\%n/threads:6 | 1036 ns | 4715 ns | 144528 |
+| Logging int+float using MessageBuffer, JSON | 1446 ns | 1446 ns | 487967 |
+| Logging int+float using MessageBuffer, JSON/threads:6 | 2181 ns | 7102 ns | 85848 |
+| Multiprocess logging int+float using MessageBuffer, pattern: \%d \%m\%n | 3456 ns | 3456 ns | 203235 |
+
+-# The "Appending" benchmarks just format the message (using PatternLayout) then discard the result.
+-# The "Async" benchmarks test AsyncAppender throughput, with logging events discarded in the background thread. 
+-# The "Logging" benchmarks write to a file using buffered output.