Strange results from hprof

[JK]

Hi everyone,

I have a stand-alone application that spends (or should spend)
most of its time waiting for network packets. However, it
consistently uses upwards of 20% of the CPU time on a
1.8GHz Pentium M/2GB RAM/WinXP laptop.

I have run it for 24 hours with hprof sampling enabled:

java -agentlib:hprof=cpu=samples my.MainClass

(If I run it with "cpu=times" it runs far too slowly to
react promptly to the network events of interest, so profiling
actual CPU time usage is not feasible.)

The resulting profile data shows that the top CPU users are:

1 37.44% 37.44% 142475377 300285
sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0
2 12.48% 49.91% 47492232 300210
java.net.PlainDatagramSocketImpl.receive0
3 12.48% 62.39% 47492137 300348
java.net.PlainSocketImpl.socketAccept
4 12.48% 74.87% 47492136 300347
java.net.PlainDatagramSocketImpl.receive0
5 12.48% 87.35% 47492125 300342
sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0
6 12.48% 99.83% 47490216 300355
sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0
7 0.17% 100.00% 650911 300344
java.net.NetworkInterface.isUp0

And even after a 24-hour run, using 20% of the CPU the whole
time, these are the *only* stack traces that show up in the
profile data. Since my selects are called with 1000ms
timeouts, and datagrams arrive at the socket only perhaps
a couple of times per second at most (verified via Ethereal),
I would expect most of the time in all of these methods to be
spent sleeping. I cannot see any reason why socketAccept(),
for example, would be using anything close to even 1% of the
CPU; I would expect that call to spend most of its time blocked
in the Windows kernel. And NetworkInterface.isUp() is called
only every ten seconds, and returns almost instantaneously;
its presence in the profiling data baffles me. I see nothing
here that could account for 20% CPU utilization.

So, questions:

(0) Am I completely misinterpreting this data?

(1) I would expect hprof to ignore samples taken from
blocked and/or sleeping threads. Is that the case?

(2) Is there a profiler other than hprof that I would be
better-advised to use? I need one that will not have too
serious an impact on performance, since when a packet
arrives my software must react to it and send a response
within approximately 100 ms. Also, open-source is vastly
preferable, since if I have to buy a commercial profiler,
it is going to take me weeks to get that approved

Any input would be appreciated.

Many thanks,

-- JK

 

[Neil Coffey]

I would expect most of the time in all of these methods to be

spent sleeping.

Actually, the selector implementation (or at least, before Java 5--
think it was improved a bit) does burn some CPU. If I recall
correctly, when you called select, there was a part in the native
code that on each call created a brand new copy of an
array containing the list of connections to poll. If you were
processing a lot of connections (i.e. hundreds or thousands), then
the CPU usage could become significant-- as I say, at least pre
Java 5.

(2) Is there a profiler other than hprof that I would be
better-advised to use? I need one that will not have too
serious an impact on performance, since when a packet
arrives my software must react to it and send a response
within approximately 100 ms.

If you're on Java 5 onwards, you could consider using the
performance and management framework. (Yes, you have to write
a little bit of code rather than using a "magic profiling tool",
but you'll end up with something more flexible that does exactly
what you need.) On a long-running server, you can probably get
away with polling very infrequently to get your profiling
statistics (over a period of time). In my
experience, doing it this way has a very negligible impact on
performance and you can safely leave it running on your live
server.

Neil

 

[Robert Klemme]

Actually, the selector implementation (or at least, before Java 5--
think it was improved a bit) does burn some CPU. If I recall
correctly, when you called select, there was a part in the native
code that on each call created a brand new copy of an
array containing the list of connections to poll. If you were
processing a lot of connections (i.e. hundreds or thousands), then
the CPU usage could become significant-- as I say, at least pre
Java 5.

That's interesting information.

If you're on Java 5 onwards, you could consider using the
performance and management framework. (Yes, you have to write
a little bit of code rather than using a "magic profiling tool",
but you'll end up with something more flexible that does exactly
what you need.) On a long-running server, you can probably get
away with polling very infrequently to get your profiling
statistics (over a period of time). In my
experience, doing it this way has a very negligible impact on
performance and you can safely leave it running on your live
server.

Eclipse profiler might also be a checp alternative.

Kind regards

robert

 

[JK]

Actually, the selector implementation (or at least, before Java 5--
think it was improved a bit) does burn some CPU. If I recall
correctly, when you called select, there was a part in the native
code that on each call created a brand new copy of an
array containing the list of connections to poll. If you were
processing a lot of connections (i.e. hundreds or thousands), then
the CPU usage could become significant-- as I say, at least pre
Java 5.

Well, ick. But I'm only handling on the order of ten
UDP sockets, and I'm on Java 1.6, so this is unlikely
to be the issue.

If you're on Java 5 onwards, you could consider using the
performance and management framework. (Yes, you have to write
a little bit of code rather than using a "magic profiling tool",
but you'll end up with something more flexible that does exactly
what you need.) On a long-running server, you can probably get
away with polling very infrequently to get your profiling
statistics (over a period of time). In my
experience, doing it this way has a very negligible impact on
performance and you can safely leave it running on your live
server.

This approach sounds interesting...

And wow, it *is* interesting. I didn't know about Jconsole.
Five minutes with it was a very enlightening experience.
I'm still digesting the data, but I think just Jconsole by
itself might answer a few of my performance-related prayers.

Many thanks,

-- JK