The only thing I can see that is different about the calls to dequeue, are that dequeue has a call to wait() inside it.
It actually does very little other than being a queue of objects.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
What about that output is odd? It's not uncommon to see the same method appear multiple times in the "Most expensive methods (by net time)" section. There are a number of reasons that this might happen; multiple calls to the same method within a thread or calls to the same method from different threads.
For a lot of people, the first time they see this section they immediately notice that the percent times add up to a number greater than 100%. This is because the percent time is per-thread rather than for the whole process. Maybe it would be helpful to have time expressed as a percent of the total process time in addition to the total thread time? You tell me. If so, I can add it to the feature request list.
The percentage and total times seemed rather excessive for a method that did very little.
The time sitting in "wait()" isn't using CPU, so I wasn't expecting it to be included. It throws off the numbers rather severely for several methods.
I have some methods that do processing, and also have a wait(). When they show up high in the summary, I have to do quite a bit of work to figure out if they were waiting, or doing something.
It really would be helpful to have a way to exclude wait() time.
I do see that it has been reported as a possible enhancement.
For me, I don't even really need to be able to see both wait() and non-wait times. Just having a way to exclude wait() time would be extremely helpful. (We have a lot of async threads waiting on each other.)
Thanks for the quick response!
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I've modified JIP so that most blocking operations will now be excluded from a method's net time. The kinds of calls that will be excluded are:
Object.wait
Thread.sleep
Thread.join
Thread.yield
as well as "calling" synchronized.
This feature will be in 1.1 beta 2 which should be available within the next week. The changes are in CVS, so if you're the adventurous type, you can grab them, run "ant dist" and you should be ready to go.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I forgot to mention, being able to have the times expressed as a % of total process time instead of per-thread would be VERY helpful. That would make it much easier to spot the CPU hog.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I've been using JIP on a large java program I work with. It's a really nice tool.
I do wonder why I get certain odd reports in the output, like this:
Count Time Pct Location
===== ==== === ========
1 6364.8 36.3 com.myrio.common.util.BoundedBuffer:dequeue
1 5405.3 30.8 com.myrio.common.util.BoundedBuffer:dequeue
1 3996.5 27.9 com.myrio.common.util.BoundedBuffer:dequeue
1 3792.9 21.6 com.myrio.common.util.BoundedBuffer:dequeue
1 3499.1 24.5 com.myrio.common.util.BoundedBuffer:dequeue
1 3437.8 24.0 com.myrio.common.util.BoundedBuffer:dequeue
1 2167.7 15.2 com.myrio.common.util.BoundedBuffer:dequeue
1 1973.3 11.2 com.myrio.common.util.BoundedBuffer:dequeue
1 1094.8 7.7 com.myrio.common.util.BoundedBuffer:dequeue
2 78.1 0.5 mclient.screen.UItext:preDraw
The only thing I can see that is different about the calls to dequeue, are that dequeue has a call to wait() inside it.
It actually does very little other than being a queue of objects.
What about that output is odd? It's not uncommon to see the same method appear multiple times in the "Most expensive methods (by net time)" section. There are a number of reasons that this might happen; multiple calls to the same method within a thread or calls to the same method from different threads.
For a lot of people, the first time they see this section they immediately notice that the percent times add up to a number greater than 100%. This is because the percent time is per-thread rather than for the whole process. Maybe it would be helpful to have time expressed as a percent of the total process time in addition to the total thread time? You tell me. If so, I can add it to the feature request list.
For methods that call wait(), the time spent waiting is counted as part of their net execution time. This is a known issue (see http://sourceforge.net/tracker/index.php?func=detail&aid=1502989&group_id=148701&atid=772418\)
If there is something else that's odd that I'm missing, please let me know.
Thanks,
Andrew
The percentage and total times seemed rather excessive for a method that did very little.
The time sitting in "wait()" isn't using CPU, so I wasn't expecting it to be included. It throws off the numbers rather severely for several methods.
I have some methods that do processing, and also have a wait(). When they show up high in the summary, I have to do quite a bit of work to figure out if they were waiting, or doing something.
It really would be helpful to have a way to exclude wait() time.
I do see that it has been reported as a possible enhancement.
For me, I don't even really need to be able to see both wait() and non-wait times. Just having a way to exclude wait() time would be extremely helpful. (We have a lot of async threads waiting on each other.)
Thanks for the quick response!
I've modified JIP so that most blocking operations will now be excluded from a method's net time. The kinds of calls that will be excluded are:
Object.wait
Thread.sleep
Thread.join
Thread.yield
as well as "calling" synchronized.
This feature will be in 1.1 beta 2 which should be available within the next week. The changes are in CVS, so if you're the adventurous type, you can grab them, run "ant dist" and you should be ready to go.
Thanks! I await beta 2 with bated breath...
I forgot to mention, being able to have the times expressed as a % of total process time instead of per-thread would be VERY helpful. That would make it much easier to spot the CPU hog.
I think that's a good idea, although I'm hesitant to replace the per-thread metric. Maybe I'll do per-process in addition to per-thread? Or maybe there could be a parameter that specifies which way to do the reporting? I've added a feature request for this: http://sourceforge.net/tracker/index.php?func=detail&aid=1700765&group_id=148701&atid=772418
I can't say if this will be in 1.1 or a subsequent release, but I hope to be able to get to this one soon.
Thanks again for your input!
Andrew.