apache / logging-log4cxx

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

Reduce logging overhead #333

Closed swebb2066 closed 10 months ago

swebb2066 commented 10 months ago
Ths PR improves benchmarks (on Windows) from: Benchmark Time CPU Iterations
Testing disabled logging request 2.70 ns 0.391 ns 1000000000
Testing disabled logging request/threads:4 0.989 ns 1.58 ns 663703704
Logging 5 char string using MessageBuffer, pattern: %m%n 678 ns 258 ns 2357895
Logging 5 char string using MessageBuffer, pattern: %m%n/threads:4 466 ns 733 ns 1258332
Logging 49 char string using MessageBuffer, pattern: %m%n 780 ns 305 ns 1947826
Logging 49 char string using MessageBuffer, pattern: %m%n/threads:4 498 ns 753 ns 746668
Logging int value using MessageBuffer, pattern: %m%n 1703 ns 750 ns 896000
Logging int value using MessageBuffer, pattern: %m%n/threads:4 697 ns 1445 ns 400000
Logging int+float using MessageBuffer, pattern: %m%n 3170 ns 1151 ns 746667
Logging int+float using MessageBuffer, pattern: %m%n/threads:4 1298 ns 2668 ns 298668
Logging int value using MessageBuffer, pattern: [%d] %m%n 1703 ns 771 ns 1115023
Logging int value using MessageBuffer, pattern: [%d] [%c] [%p] %m%n 1710 ns 774 ns 746667
Logging 49 char string using FMT, pattern: %m%n 765 ns 356 ns 2635294
Logging 49 char string using FMT, pattern: %m%n/threads:4 442 ns 867 ns 1280000
Logging int value using FMT, pattern: %m%n 741 ns 364 ns 2357895
Logging int value using FMT, pattern: %m%n/threads:4 475 ns 596 ns 943156
Logging int+float using FMT, pattern: %m%n 1096 ns 544 ns 1120000
Logging int+float using FMT, pattern: %m%n/threads:4 501 ns 997 ns 814544
Async, int value using MessageBuffer, pattern: %m%n 1712 ns 837 ns 896000

to

Benchmark Time CPU Iterations
Testing disabled logging request 3.03 ns 1.29 ns 640000000
Testing disabled logging request/threads:4 1.11 ns 2.04 ns 298666668
Logging 5 char string using MessageBuffer, pattern: %m%n 758 ns 263 ns 3446154
Logging 5 char string using MessageBuffer, pattern: %m%n/threads:4 503 ns 753 ns 995556
Logging 49 char string using MessageBuffer, pattern: %m%n 775 ns 300 ns 1929846
Logging 49 char string using MessageBuffer, pattern: %m%n/threads:4 579 ns 957 ns 995556
Logging int value using MessageBuffer, pattern: %m%n 1666 ns 739 ns 1120000
Logging int value using MessageBuffer, pattern: %m%n/threads:4 710 ns 1090 ns 573440
Logging int+float using MessageBuffer, pattern: %m%n 3122 ns 1465 ns 640000
Logging int+float using MessageBuffer, pattern: %m%n/threads:4 1331 ns 2921 ns 358400
Logging int value using MessageBuffer, pattern: [%d] %m%n 1727 ns 816 ns 746667
Logging int value using MessageBuffer, pattern: [%d] [%c] [%p] %m%n 1686 ns 688 ns 1000000
Logging 49 char string using FMT, pattern: %m%n 773 ns 368 ns 1866667
Logging 49 char string using FMT, pattern: %m%n/threads:4 487 ns 767 ns 814544
Logging int value using FMT, pattern: %m%n 730 ns 353 ns 2036364
Logging int value using FMT, pattern: %m%n/threads:4 504 ns 1004 ns 995556
Logging int+float using FMT, pattern: %m%n 1074 ns 500 ns 1000000
Logging int+float using FMT, pattern: %m%n/threads:4 533 ns 1080 ns 853332
Async, int value using MessageBuffer, pattern: %m%n 1719 ns 673 ns 1115023
Async, int value using MessageBuffer, pattern: %m%n/threads:4 789 ns 1360 ns 448000
swebb2066 commented 10 months ago
On Ubuntu gcc 9, benchmarks improve from: Benchmark Time CPU Iterations
Testing disabled logging request 0.474 ns 0.474 ns 1000000000
Testing disabled logging request/threads:16 0.093 ns 1.01 ns 681895600
Logging 5 char string using MessageBuffer, pattern: %m%n 413 ns 413 ns 1700177
Logging 5 char string using MessageBuffer, pattern: %m%n/threads:16 977 ns 7913 ns 91360
Logging 49 char string using MessageBuffer, pattern: %m%n 435 ns 435 ns 1606003
Logging 49 char string using MessageBuffer, pattern: %m%n/threads:16 980 ns 7856 ns 92928
Logging int value using MessageBuffer, pattern: %m%n 608 ns 607 ns 1198654
Logging int value using MessageBuffer, pattern: %m%n/threads:16 1000 ns 8050 ns 88992
Logging int+float using MessageBuffer, pattern: %m%n 1068 ns 1068 ns 656795
Logging int+float using MessageBuffer, pattern: %m%n/threads:16 946 ns 7671 ns 86656
Logging int value using MessageBuffer, pattern: [%d] %m%n 633 ns 633 ns 1106264
Logging int value using MessageBuffer, pattern: [%d] [%c] [%p] %m%n 631 ns 631 ns 1112696
Logging 49 char string using FMT, pattern: %m%n 404 ns 404 ns 1728028
Logging 49 char string using FMT, pattern: %m%n/threads:16 982 ns 7914 ns 91152
Logging int value using FMT, pattern: %m%n 429 ns 429 ns 1629010
Logging int value using FMT, pattern: %m%n/threads:16 982 ns 7928 ns 90304
Logging int+float using FMT, pattern: %m%n 623 ns 623 ns 1124386
Logging int+float using FMT, pattern: %m%n/threads:16 984 ns 7928 ns 88768
Async, int value using MessageBuffer, pattern: %m%n 605 ns 605 ns 1206157
Async, int value using MessageBuffer, pattern: %m%n/threads:16 1007 ns 8162 ns 89472
to: Benchmark Time CPU Iterations
Testing disabled logging request 0.474 ns 0.474 ns 1000000000
Testing disabled logging request/threads:16 0.092 ns 1.01 ns 674458208
Logging 5 char string using MessageBuffer, pattern: %m%n 416 ns 416 ns 1682651
Logging 5 char string using MessageBuffer, pattern: %m%n/threads:16 993 ns 7991 ns 91584
Logging 49 char string using MessageBuffer, pattern: %m%n 443 ns 443 ns 1579432
Logging 49 char string using MessageBuffer, pattern: %m%n/threads:16 973 ns 7863 ns 92608
Logging int value using MessageBuffer, pattern: %m%n 606 ns 606 ns 1162348
Logging int value using MessageBuffer, pattern: %m%n/threads:16 990 ns 8046 ns 88832
Logging int+float using MessageBuffer, pattern: %m%n 1092 ns 1092 ns 637467
Logging int+float using MessageBuffer, pattern: %m%n/threads:16 991 ns 8016 ns 85456
Logging int value using MessageBuffer, pattern: [%d] %m%n 595 ns 595 ns 1174665
Logging int value using MessageBuffer, pattern: [%d] [%c] [%p] %m%n 594 ns 594 ns 1175265
Logging 49 char string using FMT, pattern: %m%n 409 ns 409 ns 1714238
Logging 49 char string using FMT, pattern: %m%n/threads:16 961 ns 7729 ns 94400
Logging int value using FMT, pattern: %m%n 436 ns 436 ns 1604155
Logging int value using FMT, pattern: %m%n/threads:16 970 ns 7807 ns 93296
Logging int+float using FMT, pattern: %m%n 578 ns 578 ns 1210732
Logging int+float using FMT, pattern: %m%n/threads:16 981 ns 7910 ns 92160
Async, int value using MessageBuffer, pattern: %m%n 605 ns 605 ns 1171481
Async, int value using MessageBuffer, pattern: %m%n/threads:16 997 ns 8010 ns 89648