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 <[email protected]>: > > 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 <[email protected]> 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 <[email protected]> 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 <[email protected]>: >>>>>>> >>>>>>> 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 >>>>>>> <[email protected]> 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 <[email protected]>: >>>>>>>>> >>>>>>>>> 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 >>>>>>>>> <[email protected]>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 >>>>>>>>>> <[email protected] >>>>>>>>>> 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 >>>>>>>>>> >>> >> >> >> > >
