Ravi, To your question: Can you explain little bit how lack of synchronization can add to CPU?
I don't know exactly, but maybe it is possible that the internal structure of a Map (e.g. HashMap) can be destroyed when there are multiple change operations (put, remove, clear) at the same time, because of lack of synchronization. But that's really just a guess! Regards, Jakob 2010/1/11 Ravi Kapoor <ravikapoor...@gmail.com> > Jakob, > > I did install VisualVM but it is not capturing org.apache.* classes or > com.mycompany.* classes. I did not find a setting on how to enable > capturing > data for all the classes I want. Can you tell me where to specity the > packages for which I want to capture CPU usage? > > Vinay > > > On Mon, Jan 11, 2010 at 4:05 PM, Ravi Kapoor <ravikapoor...@gmail.com > >wrote: > > > Jakob, > > > > The beans are not big. Also these tests have been performed under a > single > > user to measure the CPU timing. So I doubt locking/synchronization is an > > issue. > > > > I would think that if there is synchronization, then the threads could be > > waiting for long time, but lack of synchronization can only lead to > corrupt > > data not to higher CPU. Can you explain little bit how lack of > > synchronization can add to CPU? > > > > I have never used VisualVM, I can try it sometime this week. I am > assuming > > it will work with Websphere 6.1 > > > > Regards > > Ravi > > > > > > On Mon, Jan 11, 2010 at 3:03 PM, Jan-Kees van Andel < > > jankeesvanan...@gmail.com> wrote: > > > >> Hi Ravi, > >> > >> Just a stupid question. Are your beans extremely big? Since FacesBean > >> doesn't do much locking/synchronizing (none if I'm correctly), the > >> only reason I can imagine it to eat CPU cycles is because of its > >> size... > >> > >> Also, is it possible for you to do a profiling run using VisualVM? > >> I've been profiling Trinidad with VisualVM myself and maybe we can > >> compare numbers... Using the same tool might make it easier to > >> compare... > >> > >> /JK > >> > >> > >> 2010/1/11 Ravi Kapoor <ravikapoor...@gmail.com>: > >> > I am thinking if that was the case, I would see high CPU in > >> > java.util.HashMap instead of org.apache.faces.* > >> > > >> > If you disagree, please explain and I can try using HashTable to store > >> data > >> > and get fresh numbers. > >> > > >> > > >> > On Mon, Jan 11, 2010 at 10:00 AM, Jakob Korherr < > >> jakob.korh...@gmail.com>wrote: > >> > > >> >> Maybe it happens when accessing the value from the Map with > >> >> "#{bean.get['memid']}", because the Map is not properly synchronized, > >> thus > >> >> its internal structure is broken and thus it is running in infinite > >> loops. > >> >> > >> >> Are your resources properly synchronized? > >> >> > >> >> Just a guess in the blue... > >> >> > >> >> Regards, > >> >> Jakob Korherr > >> >> > >> >> 2010/1/11 Ravi Kapoor <ravikapoor...@gmail.com> > >> >> > >> >> > Another thing, most of our EL expressions are one of the following > >> types > >> >> > > >> >> > "#{bean.active}" > >> >> > or > >> >> > "#{bean.get['memid']}" > >> >> > > >> >> > Parsing of these expressions probably happens within > >> org.apache.myfaces.* > >> >> > classes. These are fairly basic EL expressions and should not be > >> taking > >> >> > much > >> >> > time. We know, the final getter method is not taking much time. > >> >> > > >> >> > Do you know if the page (and EL expressions) are parsed each time a > >> page > >> >> is > >> >> > rendered? If pages are parsed only once, then the parsing time > should > >> >> also > >> >> > be almost negligible. > >> >> > > >> >> > - Ravi > >> >> > > >> >> > On Mon, Jan 11, 2010 at 8:28 AM, Ravi <ravikapoor...@gmail.com> > >> wrote: > >> >> > > >> >> > > > >> >> > > 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 > >> >> > >>>>>>>>>>>>>> > >> >> > >>>>>>>>>>>>>> > >> >> > >>>>>> > >> >> > >>>>>> > >> >> > >>>>> > >> >> > >> > >> >> > >> > >> >> > >> > >> >> > > > >> >> > > >> >> > >> > > >> > > > > >