Matthias,
If the issue is in bean, it should show up in my analysis. Also
getProperty is only 40% CPU, there is additional 45% cpu consumed by
rest of the trinidad classes totaling 85% total CPU, all within
org.apache.myfaces.* classes
Ravi
Matthias Wessendorf wrote:
Ravi,
spoke to a guy that does performance testing/improvement for Oracle
Applications. He said that there is some % CPU in Trindad but I would
not give it more them 20%. The heavy hitters is getClientId (Blake -
see dev@ thread - is doing some optimization there).
Now if getProperty is some el expression and expression is expensive
the problem is in expression not in Trinidad (perhaps that is the case
where you have el epression but beans behind it are not that good).
-Matthias
On Mon, Jan 11, 2010 at 6:45 AM, Ravi Kapoor <ravikapoor...@gmail.com> wrote:
Hi Jan-Kees,
You are right, the getProperty method is only taking 2K units. However if I
dig deeper, I find that most of the cumulative time is being spent within
Trinidad classes. The final call to java getters consumes negligible time.
I was unable to create thread structure like you showed (JProbe keeps
getting crashed). But I took another screenshot that shows almost similar
details you are looking for. It highlights the classes that are taking
maximum time (cumulative time again) but as you can see, all the classes are
just trinidad classes.
http://docs.google.com/Doc?docid=0AbuQsSDG0X9_ZGhraHFwejJfNGRjcGNiN2hk&hl=en
Regards,
Ravi
On Sun, Jan 10, 2010 at 12:54 PM, Jan-Kees van Andel <
jankeesvanan...@gmail.com> wrote:
Hey Ravi,
Looking at your JProbe screenshots for the second time, I think you're
misinterpreting the graphs (but I haven't used JProbe before, so I
might be mistaking ;-) ).
In your first screenshot (upper left corner) you can see the total
time the getProperty method takes.
This includes its self time and the time taken by its children. Its
self time is 2781 and the child time is 29609.
A large portion (around 85%) comes from the getLocalProperty and
ValueBinding.getValue methods.
However, these two methods don't do much, since they delegate to other
methods to do the real work. Maybe even invoking application code,
like managed beans.
Can you provide a more detailed call tree with more info about the
child methods that are invoked? I'm especially interested in the
methods that are called by getLocalProperty and ValueBinding.getValue
and their children. I'm not that familiar with JProbe, but I'm sure it
supports something like a call tree
(
http://www.ej-technologies.com/products/jprofiler/images/whatsnew/exceptional_methods_calltree.png
),
so you can see the problematic method.
Regards,
Jan-Kees
2010/1/10 Ravi <ravikapoor...@gmail.com>:
Matthias, I think websphere 6.1 does not support JSF 1.2. I will
doublecheck, let me know if this is incorrect. This mans I cannot try
trinidad version 1.2.12
I will try out 1.0.11 release, but that is a minor release update and I
seriously doubt if it will fix such a performance issue.
What other options do we have? Is there a way we can get somebody
familiar
with trinidad architecture/code to look at this issue? This can even be a
paid assignment.
Regards
Ravi
Matthias Wessendorf wrote:
Hello Ravi,
I wonder what our last release for JSF 1.1 (1.0.11) does?
Not sure, perhaps you may also try the JSF 1.2 version ? (1.2.12)
The JSF 1.2 version is the one that is best supported, these days.
Trinidad 2.0 is now in alpha stage, and I can understand that you
don't want to update on that version, now
-Matthias
On Sun, Jan 10, 2010 at 4:56 AM, Ravi <ravikapoor...@gmail.com> wrote:
Scott, we do not have CPUs available. The time trinidad is consuming is
supposed to be doing some other work. Hence this is costing us real
dollars
and hence our time and effort to resolve this.
This is not initial hit of page. I always ignore the first hit on all
pages,
I am only measuring CPU from 2nd hit onwards.
Ravi
Scott O'Bryan wrote:
I don't know. I'm of the camp that if the CPU time is available, use
it. That said, is this load consistant or are you just testing an
initial hit of each page.
Sent from my iPhone
On Jan 8, 2010, at 11:25 PM, Ravi <ravikapoor...@gmail.com> wrote:
Hi Jan-Kees,
Now that I am reading your message again, I do want to answer your
questions in detail. First I agree reflection is cheap, that is why
reflection is not my concern. Time being spent in reflection is
almost negligible compared to time being spent in trinidad classes.
Secondly IO and locking etc contribute to clock time but not to CPU
time. e.g. for IO, the thread may be in a wait state waiting for
data to arrive. In this case, the clock keeps ticking but such a
wait does not need CPU. My numbers are specifically CPU time. Which
means trinidad is not waiting but executing CPU instructions.
This is why the user load is also irrelevant (high load leads to
adding clock time but not to CPU time). But since you asked, to get
these numbers, I am not doing a load testing. I am simply loading 4
screens 4 times in order (total 16 screens).
Regards
Ravi
Jan-Kees van Andel wrote:
I'm not sure, but I doubt the mailing list supports attachments.
Maybe you could provide a link to some image hosting site?
My first thought, reflection is darn cheap, especially since Java 5
and even more since Java 6. I'm no IBM JVM specialist, but I don't
think there are major differences with HotSpot... Compared with SQL
queries, backend transactions, web service calls, etc. reflective
method invocations really don't make a difference.
Having said that, what kind of application are you testing? Does
this
application have any I/O, locking or other expensive things that may
be the cause of the CPU-time imbalance?
Also, what kind of load are you simulating on your application? Long
sessions with not much users? Lots of short sessions? Hyperactive
users without any pauses?
/JK
Ps. How did you configure your profiler? Sampling or
tracing/instrumentation? Although I don't think it makes a
difference
in this case, sampling is less accurate...
2010/1/8 Ravi Kapoor <ravikapoor...@gmail.com>:
The actual call to getter method is only using 2% CPU. Rest 38% is
being
used within trinidad classes.
I am attaching two screenshots to give you more details.
In first screenshot, you can see at the top left corner, total CPU
units
taken by getProperty are 32391
getProperty calls javax.faces.el.ValueBinding.getValue which calls
org.apache.myfaces.el.PropertyResolverImpl.getValue which calls
org.apache.myfaces.el.PropertyResolverImpl.getProperty which calls
java.lang.reflect.Method.invoke.
In second screenshot you can see that Method.invoke is using only
1781 units
of CPU. Rest of the time is being spent within trinidad classes.
Does this help? Also the rest of trinidad using 45% CPU usage is
also highly
concerning.
Thanks
Ravi
On Fri, Jan 8, 2010 at 1:47 PM, Jan-Kees van Andel
<jankeesvanan...@gmail.com> wrote:
Hey,
Is it possible that the getProperty indirectly invokes some
expensive
computation? For example, do you have lots of logic inside your
getters?
Regards,
Jan-Kees
2010/1/8 Ravi Kapoor <ravikapoor...@gmail.com>:
Hi Matthias,
Here are the details:
Server: Websphere 6.1
Trinidad version: 1.0.7 (We cant upgrade to 2.0 until we upgrade
websphere
which will happen in due course. Even then if this issue has not
been
addressed, the problem may exist in 2.0 as well.)
OS: Windows (Even though I am measuring numbers on windows but I
do not
think this is OS specific)
Let me know if you need to know anything else.
Regards
Ravi
On Fri, Jan 8, 2010 at 1:09 AM, Matthias Wessendorf
<mat...@apache.org>wrote:
Hello Ravi,
some more background would be good, e.g. what version of
Trinidad etc.
-Matthias
On Thu, Jan 7, 2010 at 11:25 PM, Ravi Kapoor
<ravikapoor...@gmail.com
wrote:
Has anybody done performance tests on trinidad application. I
have an
application and it appears that it is taking 80-90% of CPU in
my
application, thus killing performance.
We ran load tests and our CPU went to 100% usage. At this
point we
measured
how much time was being taken by each class/method. Here are
some
interesting figures:
CPU usage by all Trinidad + myfaces classes = 80-90%
Myfaces CPU usage (without trinidad) = 8% (which implies
trinidad is
taking
70-80% of CPU)
Total time taken by one method
(org.apache.myfaces.trinidad.bean.FacesBeanImpl.getProperty) =
40%
Can anybody confirm that they have seen this behavior?
Or if somebody can confirm that this does not happen in their
performance
tests, that should help too.
Thanks
Ravi
--
Matthias Wessendorf
blog: http://matthiaswessendorf.wordpress.com/
sessions: http://www.slideshare.net/mwessendorf
twitter: http://twitter.com/mwessendorf
