Interpreting PerformanceProfiler output

View: New views
3 Messages — Rating Filter:   Alert me  

Interpreting PerformanceProfiler output

by Gschwind, Doug :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

Hello everyone,

I have the EclipseLink 1.0.1 PerformanceProfiler engaged and am
getting useful information from it. I am wondering how to interpret
"unqualified" Profile blocks of the following form though :

Profile(ReadAllQuery,
        class=com.demos.Employee,
        number of objects=1,
        total time=189,
        local time=79,
        profiling time=327,
        DescriptorEvents=79,
        object building=79,
        time/object=189,
        objects/second=5,
)
}End profile
Profile(
        total time=15,
        local time=15,
        register=15,
)
Profile(
        total time=16,
        local time=16,
        register=16,
)
Profile(
        total time=31,
        local time=31,
        cache=31,
)
Profile(
        total time=31,
        local time=31,
        register=31,
)

What I am referring to is the last four Profile sections that do not
indicate the query type (e.g. ReadAllQuery, ReadObjectQuery), nor does
it indicate the fully qualified binary class name (e.g.
class=com.demos.employee.domain.Employee).

So, are those "unqualified" Profile blocks that are missing query
type and class information accounted for in terms of EclipseLink
interaction time by the "qualified" Profile block that precedes or
follows it? e.g. In my example above, are the 15+16+31+31 = 93
milliseconds elapsed time in the "unqualified" Profile blocks already
counted/accounted for in the 189 milliseconds required by the Employee
ReadAllQuery? If not, what is taking place to attribute that additional
93 milliseconds of interaction time?

Thank you,

Doug






The contents of this electronic mail message and any attachments are confidential, possibly privileged and intended
for the addressee(s) only. Only the addressee(s) may read, disseminate, retain or otherwise use this message. If
received in error, please immediately inform the sender and then delete this message without disclosing its contents
to anyone.

_______________________________________________
eclipselink-users mailing list
eclipselink-users@...
https://dev.eclipse.org/mailman/listinfo/eclipselink-users

Re: Interpreting PerformanceProfiler output

by James Sutherland :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

The unqualified block seem to be a UOW regsiterObject() call (could be EntityManager persist() or merge()).  What did you execute to get the output?  Did you execute the read query, then call a register?

Potentially is could be when a read query is executed in the UOW it profiles the query and register separately, I don't think the time is included in the query profile.


Gschwind, Doug wrote:
Hello everyone,

I have the EclipseLink 1.0.1 PerformanceProfiler engaged and am
getting useful information from it. I am wondering how to interpret
"unqualified" Profile blocks of the following form though :

Profile(ReadAllQuery,
        class=com.demos.Employee,
        number of objects=1,
        total time=189,
        local time=79,
        profiling time=327,
        DescriptorEvents=79,
        object building=79,
        time/object=189,
        objects/second=5,
)
}End profile
Profile(
        total time=15,
        local time=15,
        register=15,
)
Profile(
        total time=16,
        local time=16,
        register=16,
)
Profile(
        total time=31,
        local time=31,
        cache=31,
)
Profile(
        total time=31,
        local time=31,
        register=31,
)

What I am referring to is the last four Profile sections that do not
indicate the query type (e.g. ReadAllQuery, ReadObjectQuery), nor does
it indicate the fully qualified binary class name (e.g.
class=com.demos.employee.domain.Employee).

So, are those "unqualified" Profile blocks that are missing query
type and class information accounted for in terms of EclipseLink
interaction time by the "qualified" Profile block that precedes or
follows it? e.g. In my example above, are the 15+16+31+31 = 93
milliseconds elapsed time in the "unqualified" Profile blocks already
counted/accounted for in the 189 milliseconds required by the Employee
ReadAllQuery? If not, what is taking place to attribute that additional
93 milliseconds of interaction time?

Thank you,

Doug






The contents of this electronic mail message and any attachments are confidential, possibly privileged and intended
for the addressee(s) only. Only the addressee(s) may read, disseminate, retain or otherwise use this message. If
received in error, please immediately inform the sender and then delete this message without disclosing its contents
to anyone.

RE: Interpreting PerformanceProfiler output

by Gschwind, Doug :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

Hi James,

Thanks for the response. Looking at other examples in the
PerformanceProfiler output I have also indicates the total time reported
in those "unqualified" profile blocks are not accounted for within
"qualified" profile blocks.

What was being executed was a JPQL query followed by another other
queries due to batch and join fetching. I don't believe an active unit
of work existed, so no registration should have been taking place as no
explicit registration is in the code being executed, and without a unit
of work in existence, shouldn't be registering any objects due to reads
via a unit of work.

Thanks,

Doug

-----Original Message-----
From: eclipselink-users-bounces@...
[mailto:eclipselink-users-bounces@...] On Behalf Of James
Sutherland
Sent: Monday, November 24, 2008 6:34 AM
To: eclipselink-users@...
Subject: Re: [eclipselink-users] Interpreting PerformanceProfiler output


The unqualified block seem to be a UOW regsiterObject() call (could be
EntityManager persist() or merge()).  What did you execute to get the
output?  Did you execute the read query, then call a register?

Potentially is could be when a read query is executed in the UOW it
profiles
the query and register separately, I don't think the time is included in
the
query profile.



Gschwind, Doug wrote:

>
> Hello everyone,
>
> I have the EclipseLink 1.0.1 PerformanceProfiler engaged and am
> getting useful information from it. I am wondering how to interpret
> "unqualified" Profile blocks of the following form though :
>
> Profile(ReadAllQuery,
> class=com.demos.Employee,
> number of objects=1,
> total time=189,
> local time=79,
> profiling time=327,
> DescriptorEvents=79,
> object building=79,
> time/object=189,
> objects/second=5,
> )
> }End profile
> Profile(
> total time=15,
> local time=15,
> register=15,
> )
> Profile(
> total time=16,
> local time=16,
> register=16,
> )
> Profile(
> total time=31,
> local time=31,
> cache=31,
> )
> Profile(
> total time=31,
> local time=31,
> register=31,
> )
>
> What I am referring to is the last four Profile sections that do not
> indicate the query type (e.g. ReadAllQuery, ReadObjectQuery), nor does
> it indicate the fully qualified binary class name (e.g.
> class=com.demos.employee.domain.Employee).
>
> So, are those "unqualified" Profile blocks that are missing query
> type and class information accounted for in terms of EclipseLink
> interaction time by the "qualified" Profile block that precedes or
> follows it? e.g. In my example above, are the 15+16+31+31 = 93
> milliseconds elapsed time in the "unqualified" Profile blocks already
> counted/accounted for in the 189 milliseconds required by the Employee
> ReadAllQuery? If not, what is taking place to attribute that
additional

> 93 milliseconds of interaction time?
>
> Thank you,
>
> Doug
>
>
>
>
>
>
> The contents of this electronic mail message and any attachments are
> confidential, possibly privileged and intended
> for the addressee(s) only. Only the addressee(s) may read,
disseminate,
> retain or otherwise use this message. If
> received in error, please immediately inform the sender and then
delete
> this message without disclosing its contents
> to anyone.
>
>


-----
---
http://wiki.eclipse.org/User:James.sutherland.oracle.com James
Sutherland
http://www.eclipse.org/eclipselink/
 EclipseLink ,  http://www.oracle.com/technology/products/ias/toplink/
TopLink
Wiki:  http://wiki.eclipse.org/EclipseLink EclipseLink ,
http://wiki.oracle.com/page/TopLink TopLink
Forums:  http://forums.oracle.com/forums/forum.jspa?forumID=48 TopLink ,

http://www.nabble.com/EclipseLink-f26430.html EclipseLink
Book:  http://en.wikibooks.org/wiki/Java_Persistence Java Persistence
--
View this message in context:
http://www.nabble.com/Interpreting-PerformanceProfiler-output-tp20605357
p20661988.html
Sent from the EclipseLink - Users mailing list archive at Nabble.com.

_______________________________________________
eclipselink-users mailing list
eclipselink-users@...
https://dev.eclipse.org/mailman/listinfo/eclipselink-users
_______________________________________________
eclipselink-users mailing list
eclipselink-users@...
https://dev.eclipse.org/mailman/listinfo/eclipselink-users