Skip to main content


Eclipse Community Forums
Forum Search:

Search      Help    Register    Login    Home
Home » Archived » Test and Performance Tools Platform (TPTP) » Understanding the Execution Statistics view, Method Invocation panel
Understanding the Execution Statistics view, Method Invocation panel [message #101358] Wed, 20 June 2007 19:51 Go to next message
Eclipse UserFriend
Originally posted by: ahadsell+eclipse.mtdiablo.com

I'm profiling a Java application and seeing something that I don't
understand in the Method Invocation Details panel: There are methods
displayed in the "Selected method invokes" list which the source code
indicates are not invoked directly by the selected method. The methods
shown ARE invoked indirectly by the selected method (i.e. the selected
method invokes another method, which invokes another method..., which
invokes the method that shows up in the "Selected method invokes" list.

So, maybe I'm misunderstanding what's supposed to show up in this list.
I thought that _only_ direct descendants of the selected method in the
call tree would show up.

Using Eclipse 3.2.2, TPTP 4.3.1 and the Integrated Agent Controller.

1) All filtering is turned off

2) Only the "Execution time analysis" feature is turned on in the
"Monitor" tab

3) The options set for Execution Time Analysis are:

a) Collect method CPU time information is ON
b) Collect boundary classes... is ON
c) Boundary class depth is 1
d) Show execution statistics (compressed data) is ON
e) Automatically calculate polling frequency is ON
f) Show execution flow graphical details is OFF
g) Collect instance level information is OFF
Re: Understanding the Execution Statistics view, Method Invocation panel [message #101380 is a reply to message #101358] Thu, 21 June 2007 06:11 Go to previous messageGo to next message
Asaf Yaffe is currently offline Asaf YaffeFriend
Messages: 333
Registered: July 2009
Senior Member
Alan,

Based on your description, I assume you are using the "old" JVMPI
profiler. If this is the case and no filters are applied, then what you
see is likely to happen because of method inlining.

Assume, for example, that you have the following call-chain in your code:

methodA() {
methodB() ;
}

methodB() {
methodC() ;
}

Now, suppose that during runtime, the JVM decides to inline methodB()
into methodA(). When this happens, the profiler will not get the
METHOD_ENTER/METHOD_EXIT JVMPI event notifications for methodB(), and
the resulting execution flow will show that methodA invokes methodC.

HTH,
Asaf

--
Asaf Yaffe
Eclipse TPTP Committer, JVMTI Profiler
Re: Understanding the Execution Statistics view, Method Invocation panel [message #101405 is a reply to message #101380] Thu, 21 June 2007 16:49 Go to previous messageGo to next message
Eclipse UserFriend
Originally posted by: ahadsell+eclipse.mtdiablo.com

Asaf Yaffe wrote:

> Based on your description, I assume you are using the "old" JVMPI
> profiler.

First, thanks for your reply.

I'm using Sun JRE 1.5.0_11. As I understand it, this JRE supports both
JVMPI and JVMTI. However, I'm also using the Integrated Agent
Controller, and launching the target program directly from Eclipse. I
believe the Integrated Agent Controller uses JVMPI.

I would prefer to use the new tech profiler, but so far the instructions
for using it have defeated me; I have not managed to get it working.

> If this is the case and no filters are applied, then what you
> see is likely to happen because of method inlining.
>
> Assume, for example, that you have the following call-chain in your code:
>
> methodA() {
> methodB() ;
> }
>
> methodB() {
> methodC() ;
> }
>
> Now, suppose that during runtime, the JVM decides to inline methodB()
> into methodA(). When this happens, the profiler will not get the
> METHOD_ENTER/METHOD_EXIT JVMPI event notifications for methodB(), and
> the resulting execution flow will show that methodA invokes methodC.

The situation's not nearly that simple, and I somehow doubt that
inlining's responsible unless the inlining is a lot smarter than I think
it is.

The actual situation's like this:

The top level method's purpose is to parse an XML data stream and
dispatching to lower-level methods to handle individual elements of the
data stream. There are 4 kinds of elements (add, change, delete and
list) and multiple subtypes within each of these kinds (add a product,
add an order, etc.)

Let's call the top-level method, which is the "selected method" in the
Execution Statistics view, "Class1.methodA()", and the method that I'm
seeing in the "Selected Method Invokes" list Class4.methodZ().

1) Class1.methodA() first picks out all the delete requests, then the
adds, then the changes, and then the list requests. For each group it
iterates over the elements it picks, calling
Class1.methodBDelete(element), Class1.methodBAdd(element),
Class1.methodBChange(element) or Class1.methodBList(element) for each one.

2) The methodB*() methods each look up an object in a list of
processors. The lookup is based on the type of the request (Delete,
Add, Change or List) and the type of the current element (product,
order, etc). In other words, it's implementing a classical double
dispatch. Each of the methodB*()s then calls
Class1.methodC(processor,element).

3) Class1.methodC(processor,element) performs some preprocessing,
extracting the element's attributes into a hash. It then calls
processor.methodD(element, attrHash).

4) processor.methodD() calls Class2.methodE(), which calls
Class3.methodF(), which calls Class3.methodG(), which calls
Class4.methodH, which calls Class4.methodZ().

The JIT compiler could certainly inline methodB() and methodC() inside
methodA(). I have difficulty believing that it would inline the call to
methodD(), since it is based on a lookup in a table populated at runtime.

I also should note that processor.methodD() shows up in the "Selected
Method Invokes" list, so it seems unlikely that it's being inlined in
methodA().

So it seems to me that:

1) Maybe this is a bug in the analysis
2) Maybe I'm still misunderstanding the meaning of the "Selected
method invokes" list

If I can get the JVMTI-based profiler working, would it help to
straighten this out? What other tests can I run that would be helpful?

Thanks again,

--
Alan Hadsell
Re: Understanding the Execution Statistics view, Method Invocation panel [message #101582 is a reply to message #101405] Mon, 25 June 2007 07:39 Go to previous message
Asaf Yaffe is currently offline Asaf YaffeFriend
Messages: 333
Registered: July 2009
Senior Member
Alan,

Thanks for your detailed explanation. Given the description at hand, I
also doubt that what you see in the analysis views are the result of
method inlining.

You may want to try the new JVMTI profiler and see if you get different
results. The new profiler has a new "Call Tree" view which shows you the
entire call-chain in a tree-like structure.

To use the JVMTI Profiler, please download TPTP 4.4 (Release Candidate).
Note that it requires Eclipse 3.3. See the Prerequisites section on the
4.4 download page for more information.

If you have any questions on how to use the profiler, please post them
here and we'll do our best to help.

HTH,
Asaf

--
Asaf Yaffe
Eclipse TPTP Committer, JVMTI Profiler
Previous Topic:How to Write to a Datapool?
Next Topic:Slow profiling
Goto Forum:
  


Current Time: Sat Apr 20 02:18:51 GMT 2024

Powered by FUDForum. Page generated in 0.03980 seconds
.:: Contact :: Home ::.

Powered by: FUDforum 3.0.2.
Copyright ©2001-2010 FUDforum Bulletin Board Software

Back to the top