Domů > Performance > VisualVM - tool for profiling Java applications

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:

VisualVM Monitor

VisualVM Monitor

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:

VisualVM Profiler

VisualVM Profiler

At first I left all settings as set by default except Start profiling from classes, where I put com.spekacek.boulder.**. Then 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

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 in AWT-EventQueue-1 thread. Look at Self time item right beneath 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 starting from 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

VisualVM Profiler snapshot

Now you can see that inside GamePanel.paintLevelData() method the biggest spender is SunGraphics2D.drawImage() method. It was called 313218 times and sum of the times spent calling it is 21622 miliseconds.

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 number of SunGraphics2D.drawImage() calls or find a faster alternative. But this is not the topic of this article.

Conclusion

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! :)

Some links

Jan Šmuk Performance

  1. 15.10.2012 na 15:37 | #1

    I have also had trouble with the satlcbiliay of TPTP when profiling an RCP app. I also ultimately chose to use YourKit, which does not appear to suffer from the same satlcbiliay problems. I did change my filter in TPTP to only do execution time analysis on com.mycompany.*, but apparently that is still too much data, because when I start to profile, and the Profile perspective shows it has recorded about 1gig of data, it comes to a grinding halt and I have to kill Eclipse and the app that was launched.When I use YourKit, I launch it standalone (not within Eclipse), and simultaneously launch my app with the -agent parameter, then connect the two together.

  1. Žádné zpětné odkazy
Musíte být přihlášen k poslání komentáře.