Logging Performance Comparison
blog.sebastian-daschner.com
Logging Performance Comparison
1–10 of 20 posts
Re: Logging Performance Comparison
#2Huh, 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.
Re: Logging Performance Comparison
#3Really liked the data driven approach of this article
Re: Logging Performance Comparison
#4I 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.
Re: Logging Performance Comparison
#5Interesting. 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.
Re: Logging Performance Comparison
#6This 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.
Re: Logging Performance Comparison
#7Agreeing with others—these benchmarks are not quite telling us what we want to know. The problem is that the endpoints aren’t doing any work, so logging dominates.
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.
Re: Logging Performance Comparison
#8 for (; counter 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.
Re: Logging Performance Comparison
#9for (; counter I think the JVM would optimise away this loop because it doesn't do anything. e.g. if the loop optimisation method is to unroll the loop into 1000 inline statements, there's nothing there. 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.
Re: Logging Performance Comparison
#10for (; counter I think the JVM would optimise away this loop because it doesn't do anything. e.g. if the loop optimisation method is to unroll the loop into 1000 inline statements, there's nothing there. 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.
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?