search

apache / logging-log4cxx

Apache Log4cxx is a C++ port of Apache Log4j
http://logging.apache.org/log4cxx
Apache License 2.0
278 stars 123 forks source link

Reduce overhead of commonly used logging macros #337

Closed swebb2066 closed 10 months ago

swebb2066 commented 10 months ago

The function scope static variable access in Level::getInfo()etc has unnecessary overhead (10% of logging a message on Windows).

The new benchmarks for Ubuntu gcc 11 are:

Benchmark Time CPU Iterations
Testing disabled logging request 0.472 ns 0.472 ns 1000000000
Testing disabled logging request/threads:16 0.094 ns 1.01 ns 676137360
Logging 5 char string using MessageBuffer, pattern: %m%n 300 ns 300 ns 2327642
Logging 5 char string using MessageBuffer, pattern: %m%n/threads:16 511 ns 4127 ns 173408
Logging 49 char string using MessageBuffer, pattern: %m%n 321 ns 321 ns 2163479
Logging 49 char string using MessageBuffer, pattern: %m%n/threads:16 500 ns 4030 ns 166160
Logging int value using MessageBuffer, pattern: %m%n 512 ns 512 ns 1474939
Logging int value using MessageBuffer, pattern: %m%n/threads:16 449 ns 3666 ns 165344
Logging int+float using MessageBuffer, pattern: %m%n 975 ns 975 ns 718422
Logging int+float using MessageBuffer, pattern: %m%n/threads:16 534 ns 4401 ns 176896
Logging int value using MessageBuffer, pattern: [%d] %m%n 518 ns 518 ns 1348124
Logging int value using MessageBuffer, pattern: [%d] [%c] [%p] %m%n 520 ns 520 ns 1333224
Logging 49 char string using FMT, pattern: %m%n 314 ns 314 ns 2237700
Logging 49 char string using FMT, pattern: %m%n/threads:16 448 ns 3624 ns 206080
Logging int value using FMT, pattern: %m%n 313 ns 313 ns 2235338
Logging int value using FMT, pattern: %m%n/threads:16 380 ns 3039 ns 239872
Logging int+float using FMT, pattern: %m%n 463 ns 463 ns 1509341
Logging int+float using FMT, pattern: %m%n/threads:16 487 ns 3924 ns 208816
Async, int value using MessageBuffer, pattern: %m%n 510 ns 510 ns 1484667
Async, int value using MessageBuffer, pattern: %m%n/threads:16 440 ns 3579 ns 193056
swebb2066 commented 10 months ago

The new benchmarks for Windos are:

Benchmark Time CPU Iterations
Testing disabled logging request 2.41 ns 1.16 ns 1000000000
Testing disabled logging request/threads:4 0.813 ns 1.81 ns 448000000
Logging 5 char string using MessageBuffer, pattern: %m%n 570 ns 336 ns 2090667
Logging 5 char string using MessageBuffer, pattern: %m%n/threads:4 383 ns 934 ns 853332
Logging 49 char string using MessageBuffer, pattern: %m%n 683 ns 381 ns 1723077
Logging 49 char string using MessageBuffer, pattern: %m%n/threads:4 417 ns 948 ns 955732
Logging int value using MessageBuffer, pattern: %m%n 1568 ns 928 ns 640000
Logging int value using MessageBuffer, pattern: %m%n/threads:4 1460 ns 1325 ns 448000
Logging int+float using MessageBuffer, pattern: %m%n 3096 ns 1842 ns 407273
Logging int+float using MessageBuffer, pattern: %m%n/threads:4 1342 ns 3444 ns 358400
Logging int value using MessageBuffer, pattern: [%d] %m%n 1639 ns 1060 ns 560000
Logging int value using MessageBuffer, pattern: [%d] [%c] [%p] %m%n 1637 ns 1046 ns 896000
Logging 49 char string using FMT, pattern: %m%n 662 ns 420 ns 1600000
Logging 49 char string using FMT, pattern: %m%n/threads:4 427 ns 961 ns 943156
Logging int value using FMT, pattern: %m%n 620 ns 377 ns 1866667
Logging int value using FMT, pattern: %m%n/threads:4 402 ns 815 ns 1054116
Logging int+float using FMT, pattern: %m%n 923 ns 600 ns 1120000
Logging int+float using FMT, pattern: %m%n/threads:4 500 ns 1193 ns 746668
Async, int value using MessageBuffer, pattern: %m%n 1594 ns 889 ns 896000
Async, int value using MessageBuffer, pattern: %m%n/threads:4 615 ns 1360 ns 448000