Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Reduce MultiprocessRollingFileAppender overhead #443

Merged
merged 7 commits into from
Dec 17, 2024

Conversation

swebb2066
Copy link
Contributor

@swebb2066 swebb2066 commented Dec 15, 2024

The benchmark on Ubuntu 22.04 gcc 11.4 are

Benchmark Time CPU Iterations
Testing disabled logging request 0.474 ns 0.474 ns 1000000000
Testing disabled logging request/threads:6 0.139 ns 0.835 ns 819039978
Appending 5 char string using MessageBuffer, pattern: %m%n 342 ns 342 ns 2045248
Appending 5 char string using MessageBuffer, pattern: %m%n/threads:6 418 ns 2350 ns 293568
Appending 49 char string using MessageBuffer, pattern: %m%n 387 ns 387 ns 1803925
Appending 49 char string using MessageBuffer, pattern: %m%n/threads:6 496 ns 2717 ns 229734
Appending int value using MessageBuffer, pattern: %m%n 530 ns 530 ns 1340650
Appending int value using MessageBuffer, pattern: %m%n/threads:6 504 ns 2809 ns 250008
Appending int+float using MessageBuffer, pattern: %m%n 1041 ns 1041 ns 669224
Appending int+float using MessageBuffer, pattern: %m%n/threads:6 625 ns 3597 ns 190068
Appending int value using MessageBuffer, pattern: [%d] %m%n 569 ns 569 ns 1229368
Appending int value using MessageBuffer, pattern: [%d] [%c] [%p] %m%n 629 ns 629 ns 1117287
Appending 49 char string using FMT, pattern: %m%n 358 ns 358 ns 1941068
Appending 49 char string using FMT, pattern: %m%n/threads:6 481 ns 2638 ns 265746
Appending int value using FMT, pattern: %m%n 407 ns 407 ns 1760876
Appending int value using FMT, pattern: %m%n/threads:6 482 ns 2669 ns 256482
Appending int+float using FMT, pattern: %m%n 536 ns 536 ns 1320202
Appending int+float using FMT, pattern: %m%n/threads:6 509 ns 2883 ns 236166
Async, Sending int+float using MessageBuffer 1221 ns 1221 ns 573362
Async, Sending int+float using MessageBuffer/threads:6 579 ns 3458 ns 202482
Logging int+float using MessageBuffer, pattern: %d %m%n 1203 ns 1203 ns 584099
Logging int+float using MessageBuffer, pattern: %d %m%n/threads:6 982 ns 4584 ns 150492
Multiprocess logging int+float using MessageBuffer, pattern: %d %m%n 3496 ns 3496 ns 198909

@swebb2066
Copy link
Contributor Author

The benchmarks on Windows 11 Visual Studio 2022 are:

Benchmark Time CPU Iterations
Testing disabled logging request 3.41 ns 3.26 ns 263529412
Testing disabled logging request/threads:4 0.960 ns 3.84 ns 179200000
Appending 5 char string using MessageBuffer, pattern: %m%n 324 ns 315 ns 2036364
Appending 5 char string using MessageBuffer, pattern: %m%n/threads:4 293 ns 1116 ns 448000
Appending 49 char string using MessageBuffer, pattern: %m%n 396 ns 396 ns 1659259
Appending 49 char string using MessageBuffer, pattern: %m%n/threads:4 347 ns 1289 ns 400000
Appending int value using MessageBuffer, pattern: %m%n 697 ns 656 ns 1000000
Appending int value using MessageBuffer, pattern: %m%n/threads:4 541 ns 2128 ns 448000
Appending int+float using MessageBuffer, pattern: %m%n 1147 ns 1099 ns 640000
Appending int+float using MessageBuffer, pattern: %m%n/threads:4 812 ns 3139 ns 298668
Appending int value using MessageBuffer, pattern: [%d] %m%n 709 ns 698 ns 1120000
Appending int value using MessageBuffer, pattern: [%d] [%c] [%p] %m%n 767 ns 767 ns 1120000
Async, Sending int+float using MessageBuffer 1503 ns 1444 ns 497778
Async, Sending int+float using MessageBuffer/threads:4 1275 ns 4883 ns 224000
Logging int+float using MessageBuffer, pattern: %d %m%n 1394 ns 1381 ns 407273
Logging int+float using MessageBuffer, pattern: %d %m%n/threads:4 1951 ns 6810 ns 162908
Multiprocess logging int+float using MessageBuffer, pattern: %d %m%n 30028 ns 29681 ns 19478

@swebb2066
Copy link
Contributor Author

This PR onlly reduced the overhead by about 4% on Ubuntu gcc.

Note that the benchmarks set BufferedIO=true

@swebb2066
Copy link
Contributor Author

To improve performance on Windows, it would be necessary to use ReadDirectoryChangesW with a FILE_NOTIFY_CHANGE_FILE_NAME filter and poll for changes using WaitForMultipleObjects.

Seems a bit too much code to add given the level of usage of the appender.

@swebb2066 swebb2066 merged commit 4b50a6f into master Dec 17, 2024
32 checks passed
@swebb2066 swebb2066 deleted the reduce_multiprocessrollingfileappender_overhead branch December 17, 2024 02:32
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants