Optimizing applications and why sampling profilers for java fail en

By ACM on Thursday 11 November 2010 20:55 - Comments (15)
Category: Development, Views: 10.828

Today I found out why sampling profilers for Java applications don't necessarily yield correct results. As an introduction, I start with some general text about discovering performance issues for (web)applications :)

If you pay attention to the performance of your site, you can commonly find points in your code that can be optimized to reduce run time of your application. At Tweakers.net we keep an eye on the site's performance. We (try to) find and optimize slow pages and the overall (perceived) speed of the site. And as you probably know, we did that way before Google started to use page speed as a component of their ranking ;)

Like many players in this world, we also found parts of the code that couldn't easily be optimized much further in either the database, the php-code or the apache-webserver.
Depending on the situation we took different approaches to optimize that: We started using memcached to reduce the number of queries and processing involved with fetching common data. We introduced a message queue in our set-up, allowing asynchronous execution of certain parts of the code. We installed reverse caching proxies, completely eliminating most repeated php-processing involved with semi-dynamic images. And we started using our "pricewatch engine", a internal "service" written in Java to exploit its better performance, more advanced memory management and ability to keep lots of data efficiently in memory.

All those ideas came from some form of profiling. A lot of the optimizations involved reduce or replace queries to our mysql-databases. Choosing which to optimize is mostly a matter of digging through logs, common sense and earlier optimization experiences. That reasonably works well, but only gets you so far. The tools, specifically designed for this, I've used so far for identifying which queries require optimization didn't seem to help much. It is very common for us to see a query being fast in most cases, but with some parameters being relatively slow. Apart from that, we see occasional, but major, slowdowns in queries that are normally very fast. Both situations aren't handled too well by such generic tools.

For our php code it is the same story. Its mostly common sense and very raw profiling using timers. A profiler like xdebug simply introduces way to much overhead (i.e. the "observer effect") to be used in production. Some other tools have evolved nowadays, but they're normally quite costly and I'm not very convinced they help us much in identifying actual bottlenecks. That's mainly because of the simple notion that most of the php-time is spent waiting on resources. In the cases where php was actually a hot spot, it was normally relatively easy to find. The ones we didn't find are probably not too important, as we've no real complaints about our website's performance.

We've also rewritten parts of our code in Java. A Java server application normally has much better performance and the ability to cache large amounts of data with very low latency. I.e. serializing and unserializing data to and from memcached into php is very costly compared to what we do in Java. That is one of the reasons our category pages in the pricewatch are still much faster than before the switch, even though we added several new features and the amount of products and specifications has grown over time.
Finding hot spots in Java code is much harder than in php. Due to compilation and the required restarting of services the overhead of introducing a timer somewhere is very high compared to a properly set up php test site. And to make matters worse, by restarting and/or introducing timing code you may impact the performance of your code much more than with php or sql; the JVM's hot spot optimization in Java is not very easy to predict for normal developers.

Luckily, for Java there are a bunch of profilers available that can be connected to (live) programs to introduce light weight collection of timing data. There are basically two types; sampling profilers and instrumenting profilers. Sampling profilers simply wait a bit, take a snapshot of the call trees and do the same thing again untill stopped. Instrumenting profilers use Java's dynamic code abilities to alter methods of selected classes to add some tiny bit of data collection code at the start and end of a method body.
The instrumentation variant has a major drawback; it introduces a huge overhead that severly impacts the way the JVM will do its work. Basically you're simply profiling a different application. To prevent this overhead, most profilers allow you to select which classes and/or methods should get instrumentation code and which not. This has the advantage of having much less overhead, but may prevent you from detecting a actual hot spot.

The sampling profiler does not have this disadvantage. The only disadvantage most people are aware of is that it may not sample often enough to actually capture very short method calls. But given enough time and a sufficiently small sampling interval, basic statistics suggests that shouldn't be much of a problem. As I can simply re-play the access logs (40M entries currently readily available for me) from our Tomcat application servers, its easy to pound a test environment with hours worth of requests.
Still, the sampling profilers I used didn't necessarily produce hot spot lists I agreed with. And I didn't really understand why. After many thousands of requests to Tomcat, you'd expect it to be able to collect numerous samples and thus easily pinpoint actual hot spots. But it doesn't always work that way.

According to this study it has to do with the fact that profilers don't really sample at the given intervals and at the same time should more randomly distribute the intervals. The intervals are more of a guide for when to take a sample, the actual samples seem to be taken at the next "yield point" (i.e. a point in the executable code at which the JVM allows preemptive switching to another thread). Ironically, those yield points are optimized by the JVM for better performance, potentially keeping them out of the hot spots in your code... The randomization issue also has to do with the yield points. When you switch at an exact interval, you are in sync with any other regular interval in the JVM or OS including thread schedulers. And, annoyingly, even the sampling profilers introduce a bit of an observer effect to the application (they do have to collect the data and such), albeit a much smaller one than those for the instrumentation profilers.
Given all that, you can't really trust the current Java profilers (I know of) too well. This makes it actually quite hard to optimize details in your code as you may not really know which methods are really consuming your cpu time. The general parts of your code (higher up the call-tree) are probably identified mostly correctly, so you will still get a sense of where to look.

I don't really have a solution for any of these issues, but I'd appreciate anyone's opinion or hint for proper tooling on any of the platforms discussed here. For now, its mostly still common sense and a bit of an art to optimize a application ;)