Can't see my own application methods in Java VisualVM

Question

I'm trying to profile my java app, just to find out the methods in which most time is being spent. Given the poor reactions here to TPTP, I thought I'd give Java VisualVM a go.

It all seemed rather simple to use - except that I can't seem to get anything consistent or useful out of it.

I can't seem to see anything relating to MY OWN code - all I get is a whole bunch of calls to things like java.* methods.

I've tried restricting instrumentation to only my own packages, which seems to cut down the number of methods instrumented, but still I don't ever seem to see my own.

Each time I run, I get varying numbers of methods instrumented, ranging from 10's to 1000's. I've tried putting in a sleep at the start of my app, to make sure I get VisualVM up and running before my app starts to do anything interesting, to make sure it's profiling when the interesting stuff is running.

Is there something I have to do to ensure my classes get instrumented ? Are there timing issues ? ..like, have to wait for classes to be loaded etc ? I've also tried running the guts of the code twice, to make sure all the code does get exercised...

I'm just running an app, with a main, from Eclipse. I've tried using the Eclipse integration so that VisualVM starts up when I start the app - results are the same. I've also tried exporting the app as a runnable app, and running it standalone from the command line, rather than through Eclipse - same result.

My app is not a long running web app etc - just a main that calls some other of my own classes to do some processing, then quits.

I'd be grateful for any advice about what I might be doing wrong ! :)

Thanks !

Answer 1

I too am struggling with VisualVM, which is a shame because its user interface is fantastic while its profiling output seems horrific. You can seem my question here.

Java VisualVM giving bizarre results for CPU profiling - Has anyone else run into this?

I can tell you a couple of odd things that I have learned about VisualVM and the way it seems to do its profiling.

VisualVM appears to be counting the total time spent inside a method (wall-clock time). I have a thread in my application which starts a number of other threads and then immediately blocks waiting for a message on a queue. VisualVM will not register this method in the profiler until one of the other threads sends the message the first thread was waiting for (when the application terminates). Suddenly the blocking method call dominates the profiling output and is recorded as taking up more than 80% of the application time.

Other profilers, such as JProfiler and the one used by Azul do not count a blocked thread as taking up time for the profiler. This means that blocking methods which probably aren't interesting (situation dependant) for performance profiling are obscuring your view of that code that is eating your CPU time.

When I am running my profiling I end up with

sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run()

obscuring my profiling right up until that message comes back to the waiting thread and then the top spot is shared between these two totally irrelevant methods, as well as various other uninteresting methods which don't appear on other profilers.

Secondly and I think quite importantly the method filtering mechanism doesn't work as I would have expected. This means that I can't filter out the I am trying to track down what the story is with this right now.

Not a really helpful answer. The solution as I see it right now is to pay for JProfiler - VisualVM just doesn't seem trustworthy for this task.