Access stacktraces with good performance?

Question

We recently applied a caching solution that is used by almost all application modules/components (approx. 50 projects). To get a better understanding which cache operations are executed on the different system "places", we added logging for the currently performed cache operations including a stack trace to exactly know what triggered the cache operation.

Our current approach looks like this: We take the stack trace from new Throwable(), filter the irrelevant lines and log the remaining stack trace. Creating a new exception to log regretfully is no cheap operation though. Since we do not use the cache directly but through hibernate it's not so easy to find out which caller triggered the operation without having access to the stack trace.

My question thus is: Is there a more performant solution to access the current stacktrace then Throwable().getStackTrace or Thread.currentThread().getStackTrace()?

Answer 1

Actually getting an exception stack trace is not such slow:

• only 10% time is spent collecting the backtrace - this is done in Throwable() constructor;
• other 90% time is spent converting the backtrace from the internal format to a readable StackTraceElement[] array - this is done in getStackTrace().

This means, if you don't need to process the stack trace synchronously, you can just call new Exception() (this is more or less fast operation), and then invoke e.getStackTrace() later or asynchronously in another thread.

Moreover, sometimes (like in your situation) the full stack trace is not needed. You may skip some stack frames and decode only those you are interested in. The magic sun.misc.SharedSectets class will help.

E.g. to get only frames 2 to 5, use

Exception e = new Exception();
int depth = Math.min(5, SharedSecrets.getJavaLangAccess().getStackTraceDepth(e));

for (int frame = 2; frame < depth; frame++) {
    StackTraceElement elem = SharedSecrets.getJavaLangAccess().getStackTraceElement(e, frame);
    System.out.println(elem);
}

Answer 2

Thread.currentThread().getStackTrace() is basically the same thing as @apangin points out, but it could be faster in future if it avoided creating a Throwable.

However, you might find sub-sampling will give you the improvement you need. Instead of recording every access, record every N-th access. If you record every 10th access you can reduce the overhead by up to 90% and if you have a high number of accesses it will be almost as accurate.

Another option is to use a profiler like YourKit which can do this much more efficiently. This can show you how much different callers to a method and their stack traces (typically it records every 10th)

Answer 3

What more you can do is to implement a java agent. That will instrument properly the code fragment you want to trace.

Here you will find how to start