Logging Performance Comparison(blog.sebastian-daschner.com)
blog.sebastian-daschner.com
Logging Performance Comparison
https://blog.sebastian-daschner.com/entries/logging-performance-comparison
11 comments
for (; counter < 1_000; counter++) {
// ... I know this doesn't make much sense :)
}
This makes "No Logging" result not quite a fair comparison; maybe something like the sum of 1000 random numbers do some actual work in the loop.
Exactly my thoughts when reading the article. A bad micro-benchmark that puts everything in bad context as a result. I have numbers on the impact of logging from other articles that show a significant impact, but nothing at this scale.
In many C/C++ optimizing compiler, this is replaced with `counter = 1000;`.
I have no idea how java handle this.. Does the AOT compiler do any optimization? Would this defer to the JIT?
I have no idea how java handle this.. Does the AOT compiler do any optimization? Would this defer to the JIT?
I wonder if the no logging case actually tested what the author intended, or if the compiler simply optimized away the empty loop that was supposed to stand in for doing useful work in a transaction.
Now compare the efficiency of minimal logging compared to lotsa logging (even if most of it is only conditionally enabled), when optimising for dev time spent on troubleshooting :)
The one thing from modern Java logging I love and miss in other languages is being able to set log levels on specific loggers while the app is running.
Yeah it involves JMX, which has an annoying protocol that insists on domain names that you can resolve, making it a PITA with K8s from your local terminal, but it's such a QoL feature.
The one thing from modern Java logging I love and miss in other languages is being able to set log levels on specific loggers while the app is running.
Yeah it involves JMX, which has an annoying protocol that insists on domain names that you can resolve, making it a PITA with K8s from your local terminal, but it's such a QoL feature.
> Now compare the efficiency of minimal logging compared to lotsa logging (even if most of it is only conditionally enabled), when optimising for dev time spent on troubleshooting :)
Or even for successful requests per second averaged over spans of time including normal outages, degradations, and other indignities of life. It doesn't take many minutes at zero throughput to drag those averages down, so every minute shaved off by more illuminating logging is a performance benefit.
Or even for successful requests per second averaged over spans of time including normal outages, degradations, and other indignities of life. It doesn't take many minutes at zero throughput to drag those averages down, so every minute shaved off by more illuminating logging is a performance benefit.
Both Log4j2 and Logback support automatic reloading of the configuration file at a regular interval - just update the file and the log library picks it up after X seconds.
Should work well with K8s config map mounted as volume.
Should work well with K8s config map mounted as volume.
Huh, the GH repo contains a logback-async test case, but the article omits it. I've found it to be pretty fast in the past.
I really hope no one takes this analysis to heart. If I was moved onto a project without logging for this reason I would be pretty pissed. If you already have the quarkus project, why not get some metrics in real use-cases, instead of a weird do-nothing loop?
This only makes sense when logging is a substantial portion of the wall-clock time of a transaction. The moment you do any other I/O, even if that is just to hit a database this difference becomes completely irrelevant.
The tests he created effectively made logging dominate the request active time so it's rather deceptive in that manner.
His non-logging case was probably entirely optimized away by Hotspot unless he is running these benchmarks under JMH and properly disabled optimizations for that loop.
The tests he created effectively made logging dominate the request active time so it's rather deceptive in that manner.
His non-logging case was probably entirely optimized away by Hotspot unless he is running these benchmarks under JMH and properly disabled optimizations for that loop.
Remember: System.out is a PrintStream which is a synchronized class. So multiple threads writing large amounts to System.out will block each other for sure
Interesting. I noticed massive performance improvements when I went to a decent buffered logger in Clojure and Go projects. IIRC, there was no distinguishable difference from the “no logging” scenario for real world workloads (where the buffered channel never fills completely). This makes me want to revisit those tests and see if I’m misremembering, though.
Really liked the data driven approach of this article
Yes, but the methodology is completely broken. He uses microbenchmarks on a JVM which can eliminate these instantly. It's inconsistent with findings from other logging benchmarks (especially the last bit).
Isn't buffered log writer prone to error (read not flushing to output) in case of ie. Premature container termination?
Yes, as he says:
> The downside of this approach is that if the system crashes without a chance to flush the buffer, the last lines might not have been written and may be lost.
> The downside of this approach is that if the system crashes without a chance to flush the buffer, the last lines might not have been written and may be lost.
You might think “that’s ok, it still shows me the overhead of logging.” This is subtly wrong, though, because you can’t necessarily talk about the overhead of logging without saying how much logging, from how many threads, with how much other work.
Take the simplest case, stdout. Writing to stdout requires a lock. If logging is sufficiently rare, most of the time, there’s no wait. As logging increases in frequency, there is more contention. Doubling the number of writes more than doubles the time spent logging, because of that contention.
To benchmark this properly, you’d[0] want to have a test where the total number of requests/second without logging and the number of logs/request as independent variables. That would show you the regions where logging becomes a bottleneck, and regions where it’s not.
[0] At a minimum. I’m not saying this would be an ideal benchmark—if you’re not doing marketing, benchmarks aren’t about “let’s find the biggest number”, but accurately modeling a phenomenon so that you can make predictions. That means you might need to do a lot of experimentation.