Tuesday, December 6, 2011

How slow getStackTrace() is?

Today during discussion about usage of low level Java tricks I was told that Throwable.getStackTrace() is a very heavy operation. So, I decided to check this fact myself and perform benchmark comparison of Throwable.getStackTrace() with other widely used in java operations.
I wrote loop that calls some code snippets 10 million times. I believe this statistics is good enough. Here are the results.

ActionTime (milliseconds)Comment
new Throwable().getStacktrace()19081
Thread.currentThread().getStacktrace()24334Added later, tested on other environment, so the value here is calculated relatively to new Throwable().getStacktrace()
Create object and invoke its hashCode()548
new Thread()8898
new Thread().start()804*1000Used 10000 iterations here. 10 millions take ages...
file print1647
file print (long lines)6673

We can see that getStackTrace() is really heavy action comparing with ordinary method call. But it can be easily compared with time that is needed to print 60 characters long line to file located on the local hard drive and it is much lighter than starting a new thread.

This means that the nice formatted log record that contains the source method name is twice heavier than log record that does not print method name. But starting new thread is 40 times heavier.

Recently I found out that there is yet another way to retrieve current stack trace: Thread.currentThread().getStacktrace(). I decided to test this method relatively to new Throwable().getStackTrace() and found that it 20% heavier. Code investigation showed that the reason is probably in yet another security check (invocation of security manager) done in code of Thread.getStackTrace().


Throwable.getStackTrace()is relatively heavy but there are other operations that take approximately the same or even more time. So, we can use it when we need but should be careful.

I want to thank Vladi Bar On that caused me to perform this investigation.