VisualVM - tool for profiling Java applications
VisualVM is tool for profiling Java applications made by Sun. Today I would like to write about my experience with it.
Some time ago I was experimenting with game programming in Java. I wrote
clone of famous Boulder Dash game. When playing the game on different machines
I found out that it eats terrible amount of CPU time. What? The original was
running nicely on 8bits ZX Spectrum ;). I started looking into the code and
optimize it. Some hours later the performance got better but still not good
enough. I came to the point where I could
not proceed any further. All my algorithms looked nice and clean. I delayed the solution and left it as it was.
Recently I have heard about VisualVM and I decided to give it a try.
Making it run
Installation was smooth. I just downloaded the zip archive from https://visualvm.dev.java.net/, extracted it and run. The first run of VisualVM resulted into warning message: Local Applications Cannot Be Detected. But the issue is nicely documented directly on VisualVM site and the solution took me only few seconds (see https://visualvm.dev.java.net/…hooting.html#… for details).
Finding a big spender
After I started-up the game i was able to see it as local java application in VisualVM applications panel to the left:
As you can see it is using up to 80% of my 2.4GHz Sempron which is quite a lot. I was going to find out what is eating so much performance so i clicked on Profiler tab and opened the settings by checking the checkbox to the right:
At first I left all settings as set by default except Start profiling
from classes, where I put
I started up CPU profiling. Then I was playing the game for few moments –
profiling slows everything down so it was not a big fun. Then I hit
Snapshot button and I got following report:
VisualVM Profiler snapshot
In CPU snapshot view you can see how much time did it take to process each
method. In the case of my game the obvious winner is
GamePanel.paintLevelData() method. It was called 3858 times and
sum of the times spent calling it is 38865 miliseconds which is 70.2% of time
AWT-EventQueue-1 thread. Look at
Self time item
GamePanel.paintLevelData(). This is time spend
calling not instrumented methods – methods which don't match with the
settings we did before starting the profiling.
To be able to look more deeply into what is going on in
GamePanel.paintLevelData() I started-up new profiling session.
this time I set Start profiling from classes to
com.spekacek.boulder.view.GamePanel and cleared everything in
Do not profile classes setting – I want to profile everything
com.spekacek.boulder.view.GamePanel and I don't want
any exclusions. Then I started-up the CPU profiling again and after a while of
playing the game I made another snapshot. This is what I got:
VisualVM Profiler snapshot
Now you can see that inside
the biggest spender is
SunGraphics2D.drawImage() method. It was
called 313218 times and sum of the times spent calling it is
So now I know where the problem lies and I can focus myself on fixing it.
I know that I have to paint game levels faster. I can try either to reduce
SunGraphics2D.drawImage() calls or find a faster
alternative. But this is not the topic of this article.
I like this tool. It is very simple an intuitive – not very different from highly advanced JProfiler. It can do much more than I described in this humble article including memory profiling, heap viewer, etc. In short it can help you to find weak spots in your application for free. Good job guys! :)
- https://visualvm.dev.java.net/ – VisualVM Homepage
- http://en.wikipedia.org/…Boulder_Dash – some information about Boulder Dash, the best game ever.
- http://boulder.spekacek.com/ – Java Dash homepage, including still not fully optimized Boulder Dash clone ;)