Eclipse Community Forums
Forum Search:

Search      Help    Register    Login    Home
Home » Eclipse Projects » Test and Performance Tools Platform (TPTP) » profiling monitor: execution statistics - bug?
profiling monitor: execution statistics - bug? [message #49522] Sun, 08 January 2006 15:39 Go to next message
No real name is currently offline No real name
Messages: 4
Registered: July 2009
Junior Member
I have profile data from an embedded device, in a proprietary format.

I wrote a perl script to convert it into the XML format that is produced
when doing a tptp profile of a Java program to an external XML file.

I then import the XML file into the profiling monitor, and display the
Execution Statistics.

Problem: cumulative time seems to be wrong.
Attached is a zipped XML file that was produced by the perl script. The
time-difference between the first and last entries is less than 100 seconds,
but Exection Statistics shows cumulative time of ~ 332 seconds.

Questions:
Is this is a bug?
Am I "allowed" to hand-craft the XML file?
If not, how should I convert my non-tptp profile data to tptp-digestible
format? I searched and found no way to do this.

Thanks a lot for any help.

BTW, the tptp-produced XML is not valid against the documented DTD (checked
using Altova XML-spy).


  • Attachment: x5.txt-ec.zip
    (Size: 381.81KB, Downloaded 104 times)
Re: profiling monitor: execution statistics - bug? [message #49582 is a reply to message #49522] Mon, 09 January 2006 16:51 Go to previous messageGo to next message
Eclipse User
Originally posted by: Navid_Mehregani_nmehrega.ca.ibm.com

This is a multipart message in MIME format.
--=_alternative 005C9ECB852570F1_=
Content-Type: text/plain; charset="US-ASCII"

> The time-difference between the first and last entries is less than 100
seconds,
> but Exection Statistics shows cumulative time of ~ 332 seconds.

The cumulative time of a target method is the amount of time that the
target method takes plus the amount of time all the methods that are
called within the target method take. To make this clearer, consider
methodA below, which calls up methodB and methodC:

methodA()
{
methodB();
methodC();
}

The cumulative time of methodA is the amount of time methodA takes plus
the amount of time methodB and methodC take. So my question to you is
whether you took this into account when you calculated your cumulative
time in the raw XML file. You have to also take into account the number
of times that the method has been invoked.

The base time of methodA is just the amount of time methodA took without
taking into account methodB and methodC. This is easier to calculate from
your raw XML file, but you'll also need to take into account the number of
times the method has been invoked. The base times are added together for
each invocation of the method.


> BTW, the tptp-produced XML is not valid against the documented DTD
(checked using Altova XML-spy).

I'm not surprised. Over the years we've been adding/modifying entries to
the trace files without updating the DTD or XML schema. Pretty bad, I
know. We don't verify the DTD/Schema with the trace files produced,
probably to make things a bit faster. You're welcome to open a bug for
this: https://bugs.eclipse.org/bugs/enter_bug.cgi?product=TPTP
Be sure to specify the error messages generated by the XML parser.

Navid Mehregani
--=_alternative 005C9ECB852570F1_=
Content-Type: text/html; charset="US-ASCII"


<br><font size=2><tt>&gt; The time-difference between the first and last
entries is less than 100 seconds,<br>
&gt; but Exection Statistics shows cumulative time of ~ 332 seconds.</tt></font>
<br>
<br><font size=2 face="sans-serif">The cumulative time of a target method
is the amount of time that the target method takes plus the amount of time
all the methods that are called within the target method take. &nbsp;To
make this clearer, consider methodA below, which calls up methodB and methodC:</font>
<br>
<br><font size=2 face="sans-serif">methodA()</font>
<br><font size=2 face="sans-serif">{</font>
<br><font size=2 face="sans-serif">&nbsp; &nbsp; &nbsp; &nbsp; methodB();</font>
<br><font size=2 face="sans-serif">&nbsp; &nbsp; &nbsp; &nbsp; methodC();</font>
<br><font size=2 face="sans-serif">}</font>
<br>
<br><font size=2 face="sans-serif">The cumulative time of methodA is the
amount of time methodA takes plus the amount of time methodB and methodC
take. &nbsp;So my question to you is whether you took this into account
when you calculated your cumulative time in the raw XML file. &nbsp;You
have to also take into account the number of times that the method has
been invoked.</font>
<br>
<br><font size=2 face="sans-serif">The base time of methodA is just the
amount of time methodA took without taking into account methodB and methodC.
&nbsp;This is easier to calculate from your raw XML file, but you'll also
need to take into account the number of times the method has been invoked.
&nbsp;The base times are added together for each invocation of the method.</font>
<br>
<br>
<br><font size=2><tt>&gt; BTW, the tptp-produced XML is not valid against
the documented DTD (checked using Altova XML-spy).</tt></font>
<br>
<br><font size=2 face="sans-serif">I'm not surprised. &nbsp;Over the years
we've been adding/modifying entries to the trace files without updating
the DTD or XML schema. &nbsp;Pretty bad, I know. &nbsp;We don't verify
the DTD/Schema with the trace files produced, probably to make things a
bit faster. &nbsp;You're welcome to open a bug for this: https://bugs.eclipse.org/bugs/enter_bug.cgi?product=TPTP
&nbsp; </font>
<br><font size=2 face="sans-serif">Be sure to specify the error messages
generated by the XML parser.</font>
<br>
<br><font size=2 face="sans-serif">Navid Mehregani</font>
--=_alternative 005C9ECB852570F1_=--
Re: profiling monitor: execution statistics - bug? [message #49762 is a reply to message #49582] Tue, 10 January 2006 09:17 Go to previous messageGo to next message
No real name is currently offline No real name
Messages: 4
Registered: July 2009
Junior Member
First, thanks for the detailed response.
If:

enter A at time 1
enter B at time 2
exit B at time 3
enter C at time 4
exit C at time 5
exit A at time 6

Then I reckon:
func base cumul
A 3 5
B 1 1
C 1 1
Correct?

If so, then my previous query stands: how can cumulative be greater than
(exitTime - enterTime) ?

>
> methodA()
> {
> methodB();
> methodC();
> }
>
> You're welcome to open a bug for
> this: https://bugs.eclipse.org/bugs/enter_bug.cgi?product=TPTP
> Be sure to specify the error messages generated by the XML parser.

Good idea.
Re: profiling monitor: execution statistics - bug? [message #49882 is a reply to message #49762] Tue, 10 January 2006 20:35 Go to previous messageGo to next message
Eclipse User
Originally posted by: Navid_Mehregani_nmehrega.ca.ibm.com

This is a multipart message in MIME format.
--=_alternative 007118D6852570F2_=
Content-Type: text/plain; charset="US-ASCII"

>Then I reckon:
> func base cumul
> A 3 5
> B 1 1
> C 1 1
>Correct?


Correct, but have you taken into account the number of times that the
method has been invoked? The cumulative time of a method invoked multiple
times is the addition of all of its cumulative times for each invocation.
I've imported your trace file in my workbench and none of the methods seem
to have a cumulative time of ~332 seconds. The largest cumulative time is
98.34 seconds for handleMsg(). I'm using the TPTP-4.2.0-200512310100
driver. Can you be more specific as to which methods you're having this
problem with.

BTW, if you opened a bug for the DTD verification problem, make sure you
specify its component as Platform.Agents.JVMPI.

Navid Mehregani
--=_alternative 007118D6852570F2_=
Content-Type: text/html; charset="US-ASCII"


<br><font size=2><tt>&gt;Then I reckon:<br>
&gt; &nbsp; &nbsp;func base cumul<br>
&gt; &nbsp; &nbsp;A 3 5<br>
&gt; &nbsp; &nbsp;B 1 1<br>
&gt; &nbsp; &nbsp;C 1 1<br>
&gt;Correct?</tt></font>
<br>
<br>
<br><font size=2 face="sans-serif">Correct, but have you taken into account
the number of times that the method has been invoked? &nbsp;The cumulative
time of a method invoked multiple times is the addition of all of its cumulative
times for each invocation. &nbsp;I've imported your trace file in my workbench
and none of the methods seem to have a cumulative time of ~332 seconds.
&nbsp;The largest cumulative time is 98.34 seconds for handleMsg(). &nbsp;I'm
using the TPTP-4.2.0-200512310100 driver. &nbsp;Can you be more specific
as to which methods you're having this problem with.</font>
<br>
<br><font size=2 face="sans-serif">BTW, if you opened a bug for the DTD
verification problem, make sure you specify its component as Platform.Agents.JVMPI.<br>
</font>
<br><font size=2 face="sans-serif">Navid Mehregani</font>
--=_alternative 007118D6852570F2_=--
Re: profiling monitor: execution statistics - bug? [message #50023 is a reply to message #49882] Thu, 12 January 2006 09:15 Go to previous messageGo to next message
No real name is currently offline No real name
Messages: 4
Registered: July 2009
Junior Member
>
> Correct, but have you taken into account the number of times that the
> method has been invoked? The cumulative time of a method invoked multiple
> times is the addition of all of its cumulative times for each invocation.
> I've imported your trace file in my workbench and none of the methods seem
> to have a cumulative time of ~332 seconds. The largest cumulative time is
> 98.34 seconds for handleMsg(). I'm using the TPTP-4.2.0-200512310100
> driver. Can you be more specific as to which methods you're having this
> problem with.

I downloaded and installed tptp.sdk-TPTP-4.2.0-200512011334D.zip and the
dependent packages (although I am seeing 4.1.0 in the Help, About dialogs).

I import the file (with Show Full Data selected), click on Execution Time
Analysis, and see Execution Statistics with two collapsed entries:
(default package) 333.65... 0.022... 333.65...
java.lang 0.0000... 0.000... 0.000...

Is this what you see?
Re: profiling monitor: execution statistics - bug? [message #50112 is a reply to message #50023] Thu, 12 January 2006 17:20 Go to previous messageGo to next message
Eclipse User
Originally posted by: Navid_Mehregani_nmehrega.ca.ibm.com

This is a multipart message in MIME format.
--=_alternative 005F3F83852570F4_=
Content-Type: text/plain; charset="US-ASCII"

I found the problem, but I'm not sure why you're looking at the cumulative
times of the packages. The Execution Statistics view contains three
buttons that allow you to view the execution times of all the packages,
classes, or methods. You want to look at the execution times of all the
methods. The cumulative times of the classes are the addition of all the
cumulative times for their methods and the cumulative time of the packages
is the addition of the cumulative times of the classes within that
package. I thought I'd clarify that.

Now to get back to the problem... I imported your file with the 'Show
execution statistics (compressed data)' option and the largest cumulative
time is ~98 seconds, which I believe is correct. Now when I import the
same file with the 'Show full data (execution flow graphical details)'
option, the largest cumulative time is ~332 seconds!! This is definitely
a bug. I've opened a bug for this:
https://bugs.eclipse.org/bugs/show_bug.cgi?id=123628 Feel free to add
your email address to the CC list.

Navid Mehregani
--=_alternative 005F3F83852570F4_=
Content-Type: text/html; charset="US-ASCII"


<br><font size=2 face="sans-serif">I found the problem, but I'm not sure
why you're looking at the cumulative times of the packages. &nbsp;The Execution
Statistics view contains three buttons that allow you to view the execution
times of all the packages, classes, or methods. &nbsp;You want to look
at the execution times of all the methods. &nbsp;The cumulative times of
the classes are the addition of all the cumulative times for their methods
and the cumulative time of the packages is the addition of the cumulative
times of the classes within that package. &nbsp;I thought I'd clarify that.</font>
<br>
<br><font size=2 face="sans-serif">Now to get back to the problem... I
imported your file with the 'Show execution statistics (compressed data)'
option and the largest cumulative time is ~98 seconds, which I believe
is correct. &nbsp;Now when I import the same file with the 'Show full data
(execution flow graphical details)' option, the largest cumulative time
is ~332 seconds!! &nbsp;This is definitely a bug. &nbsp;I've opened a bug
for this: https://bugs.eclipse.org/bugs/show_bug.cgi?id=123628 &nbsp;Feel
free to add your email address to the CC list.</font>
<br>
<br><font size=2 face="sans-serif">Navid Mehregani</font>
--=_alternative 005F3F83852570F4_=--
Re: profiling monitor: execution statistics - bug? [message #50634 is a reply to message #50112] Mon, 16 January 2006 14:43 Go to previous messageGo to next message
No real name is currently offline No real name
Messages: 4
Registered: July 2009
Junior Member
This is a multi-part message in MIME format.

------=_NextPart_000_000F_01C61ABB.ECD757A0
Content-Type: text/plain;
charset="iso-8859-1"
Content-Transfer-Encoding: quoted-printable

Thanks.

What about my other original question re: profile data from a non-Java =
source?
<Navid_Mehregani_nmehrega@ca.ibm.com> wrote in message =
news:dq634n$h9q$1@utils.eclipse.org...

I found the problem ...
------=_NextPart_000_000F_01C61ABB.ECD757A0
Content-Type: text/html;
charset="iso-8859-1"
Content-Transfer-Encoding: quoted-printable

<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN">
<HTML><HEAD>
<META http-equiv=3DContent-Type content=3D"text/html; =
charset=3Diso-8859-1">
<META content=3D"MSHTML 6.00.2800.1505" name=3DGENERATOR>
<STYLE></STYLE>
</HEAD>
<BODY bgColor=3D#ffffff>
<DIV><FONT size=3D2>Thanks.</FONT></DIV>
<DIV><FONT size=3D2></FONT>&nbsp;</DIV>
<DIV><FONT size=3D2>What about my other original question re: profile =
data from a=20
non-Java source?</FONT></DIV>
<BLOCKQUOTE=20
style=3D"PADDING-RIGHT: 0px; PADDING-LEFT: 5px; MARGIN-LEFT: 5px; =
BORDER-LEFT: #000000 2px solid; MARGIN-RIGHT: 0px">
<DIV>&lt;<A=20
=
href=3D"mailto:Navid_Mehregani_nmehrega@ca.ibm.com">Navid_Mehregani_nmehr=
ega@ca.ibm.com</A>&gt;=20
wrote in message <A=20
=
href=3D"news:dq634n$h9q$1@utils.eclipse.org">news:dq634n$h9q$1@utils.ecli=
pse.org</A>...</DIV><BR><FONT=20
face=3Dsans-serif size=3D2>I found the problem =
....</FONT></BLOCKQUOTE></BODY></HTML>

------=_NextPart_000_000F_01C61ABB.ECD757A0--
Re: profiling monitor: execution statistics - bug? [message #50662 is a reply to message #50634] Mon, 16 January 2006 15:07 Go to previous message
Eclipse User
Originally posted by: Navid_Mehregani_nmehrega.ca.ibm.com

This is a multipart message in MIME format.
--=_alternative 00530FBD852570F8_=
Content-Type: text/plain; charset="US-ASCII"

> What about my other original question re: profile data from a non-Java
source?

Sorry, but I don't know what you're referring to exactly.

Navid Mehregani
--=_alternative 00530FBD852570F8_=
Content-Type: text/html; charset="US-ASCII"


<br><font size=2>&gt; What about my other original question re: profile
data from a non-Java source?<br>
</font>
<br><font size=2 face="sans-serif">Sorry, but I don't know what you're
referring to exactly.</font>
<br>
<br><font size=2 face="sans-serif">Navid Mehregani</font>
--=_alternative 00530FBD852570F8_=--
Previous Topic:Problems with statistical view in linux
Next Topic:TPTP...Using the 4.1.0 platform...
Goto Forum:
  


Current Time: Thu Oct 23 12:36:13 GMT 2014

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

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