Re: [ovirt-devel] [ATTN] GWT Debug mode is now 2x faster!

From: "Vojtech Szocs" <vszocs(a)redhat.com&gt; To: "Eli Mesika" <emesika(a)redhat.com&gt; Cc: devel(a)ovirt.org Sent: Monday, August 11, 2014 3:40:41 PM Subject: Re: [ovirt-devel] [ATTN] GWT Debug mode is now 2x faster! ----- Original Message ----- > From: "Eli Mesika" <emesika(a)redhat.com&gt; > To: "Greg Sheremeta" <gshereme(a)redhat.com&gt; > Cc: devel(a)ovirt.org > Sent: Sunday, August 10, 2014 11:23:14 AM > Subject: Re: [ovirt-devel] [ATTN] GWT Debug mode is now 2x faster! > > > > ----- Original Message ----- > > From: "Greg Sheremeta" <gshereme(a)redhat.com&gt; > > To: devel(a)ovirt.org > > Sent: Wednesday, August 6, 2014 3:09:03 PM > > Subject: [ovirt-devel] [ATTN] GWT Debug mode is now 2x faster! > > > > [changing the subject to be more noticeable] > > > > All, > > > > Alexander did some great work making GWT debug mode at least 2x faster. > > It is now *very* usable. > > > > I have previously avoided it, but now it's pretty awesome. If you have > > avoided > > it like me, give it a try! > > > > Tip: > > make gwt-debug DEBUG_MODULE=webadmin > > DEV_EXTRA_BUILD_FLAGS_GWT_DEFAULTS="-Dgwt.cssResourceStyle=pretty" > > will un-obfuscate CSS classes for you. Very helpful with debugging UI > > stuff. > > > > Greg > > Hi > Well done > Can the README.developer file be modified with this information? I think that using DEV_EXTRA_BUILD_FLAGS to define "gwt.cssResourceStyle" Maven property would work as well, not sure why DEV_EXTRA_BUILD_FLAGS_GWT_DEFAULTS is needed here: $ make gwt-debug DEBUG_MODULE=webadmin DEV_EXTRA_BUILD_FLAGS="-Dgwt.cssResourceStyle=pretty" AFAIK, DEV_EXTRA_BUILD_FLAGS_GWT_DEFAULTS exists only to define default target browser (Firefox only) for GWT compilation. I'll update http://www.ovirt.org/DebugFrontend and submit patch to update README.developer file.

Vojtech > > Thanks > > > > > > ----- Original Message ----- > > > From: "Vojtech Szocs" <vszocs(a)redhat.com&gt; > > > To: devel(a)ovirt.org > > > Cc: awels(a)redhat.com, ecohen(a)redhat.com, gshereme(a)redhat.com > > > Sent: Wednesday, July 30, 2014 11:19:46 AM > > > Subject: Re: GWT debug slowness. > > > > > > Hi Alex, > > > > > > (adding devel list to share it with others) > > > > > > I really appreciate that you took the time to analyze GWT EventBus > > > activity! > > > > > > As we discussed on IRC, @ProxyEvent in AbstractSubTabPresenter is the > > > most > > > likely cause of overall UI slowness after successful user > > > authentication. > > > Fix for this should be rather easy and harmless, please add me as > > > reviewer > > > once you come up with the relevant patch. > > > > > > Another thing is "refresh on logout" for all (both) GWT applications. > > > This > > > is mainly due to planned SSO changes (there will be a dedicated > > > interactive > > > login page for entire Engine); for us it means that "login" section of > > > all > > > GWT applications will be unnecessary. Before that, however, we can > > > already > > > implement "refresh on logout". As a nice side effect, we can remove > > > some > > > of > > > our infra (UiCommonInitEvent & friends) to make it more simple. > > > > > > Please find some more comments below (inline). > > > > > > Thanks, > > > Vojtech > > > > > > > > > ----- Original Message ----- > > > > From: "Alexander Wels" <awels(a)redhat.com&gt; > > > > To: vszocs(a)redhat.com > > > > Cc: ecohen(a)redhat.com, gshereme(a)redhat.com > > > > Sent: Friday, July 25, 2014 7:59:56 PM > > > > Subject: Re: GWT debug slowness. > > > > > > > > On Friday, July 25, 2014 09:28:33 AM Alexander Wels wrote: > > > > > Vojtech, > > > > > > > > > > I know you suggested that maybe the event bus was getting > > > > > overloaded > > > > > with > > > > > events might be the cause of the slowness in the GWT debug mode. So > > > > > I > > > > > modified the event bus implementation to record the number of > > > > > events, > > > > > their > > > > > handlers, and the occurrences of those events. > > > > > > > > > > This is right after the login page is loaded. > > > > > +---------------------------------------------------+-----------+----------- > > > > > + > > > > > |Type |handlers > > > > > ||fired > > > > > || > > > > > +---------------------------------------------------+-----------+----------- > > > > > + > > > > > |event: ApplicationFocusChangeEvent: |0 |2 > > > > > || event: LockInteractionEvent: |2 > > > > > || |2 > > > > > | | event: NavigationEvent: |0 > > > > > | | |1 > > > > > | | event: PlaceRequestInternalEvent: |111 > > > > > | | |1 > > > > > | | event: ResetPresentersEvent: |1 > > > > > | | |1 > > > > > | | event: RevealRootLayoutContentEvent: |1 > > > > > ||1 | > > > > > +---------------------------------------------------+-----------+----------- > > > > > + > > > > > > Just for clarification: > > > > > > * ApplicationFocusChangeEvent - fired by our infra whenever > > > browser/window > > > gains or looses focus (we use this to throttle UiCommon model refresh > > > timers, i.e. when out of focus, lower the refresh rate) > > > > > > * LockInteractionEvent - fired by GWTP infra, indicates that UI > > > interaction > > > should be avoided because the application is currently in transition > > > from > > > one place to another (in practice, invisible "glass" <div> element > > > covers > > > the entire viewport during transition, see RootPresenter.RootView) > > > > > > Note: we had plans to provide some "In progress..." label (just like > > > you > > > see in Gmail) to make this obvious to end users, there's also RFE on > > > this > > > > > > * NavigationEvent - fired by GWTP infra, it's a hook we don't use > > > > > > * PlaceRequestInternalEvent - fired by GWTP infra, PlaceManagerImpl > > > fires > > > this event to ask all proxies: "which one of you can reveal a > > > presenter > > > with name token xxx" (i.e. "dataCenters-clusters") > > > > > > Note: handler count is high because EACH presenter proxy adds handler > > > for this event. > > > > > > * ResetPresentersEvent - fired by GWTP infra, after transition to new > > > place > > > is complete, trigger "onReset" lifecycle method on all presenters > > > present > > > on "reveal path" (from leaf to root) > > > > > > * RevealRootLayoutContentEvent - fired by GWTP infra, this makes GWTP > > > root > > > presenter/view reveal within the browser/window viewport > > > > > > > > > > > > > This is right after you login, and the VM main tab is displayed > > > > > +---------------------------------------------------+-----------+----------- > > > > > + > > > > > |Type |handlers > > > > > ||fired > > > > > || > > > > > +---------------------------------------------------+-----------+----------- > > > > > + > > > > > |event: UiCommonInitEvent: |715 |1 > > > > > || event: RestApiSessionAcquiredEvent: |1 > > > > > || |1 > > > > > | | event: UserLoginChangeEvent: |3 > > > > > | | |1 > > > > > | | event: ApplicationFocusChangeEvent: |80 > > > > > | | |2 > > > > > | | event: LockInteractionEvent: |2 > > > > > | | |3 > > > > > | | event: NavigationEvent: |0 > > > > > ||1 | event: PlaceRequestInternalEvent: > > > > > |||205 > > > > > | |2 | event: InitializeEvent: > > > > > | ||167 > > > > > | |170 | event: SSOTokenChangeEvent: > > > > > | ||1 > > > > > | |1 | event: ResetPresentersEvent: > > > > > | ||1 > > > > > | |1 | event: RevealRootLayoutContentEvent: > > > > > ||1 |1 | > > > > > +---------------------------------------------------+-----------+----------- > > > > > + > > > > > > Most of these events are fired by our own infra. > > > > > > UiCommonInitEvent has so many handlers due to following components: > > > > > > * TabModelProvider (access to UiCommon models) > > > * AbstractActionPanel (for each "action button" definition!) > > > * UiCommandButtonDefinition (button bound to UiCommon model "command") > > > * AbstractRefreshManager (controlling refresh of list models) > > > * ModelBoundTab (tab's properties bound to UiCommon model properties) > > > * AbstractActionTable (added recently, for search string change stuff) > > > * some more classes (UserPortalConfigurator, WebAdminConfigurator, > > > SearchPanelPresenterWidget) > > > > > > Each component mentioned above needs to be notified when relevant > > > UiCommon model changes. As you might know, on each login, current > > > CommonModel (root model) instance is thrown away (if any) and new > > > CommonModel instance is created. CommonModel in turn creates its > > > "child" models, which create their "child" models, etc. This is, > > > in my opinion, one of the BIGGEST flaws of UiCommon code design; > > > it makes models tightly coupled with all subsequent consequences. > > > > > > (As with any kind of design, once it's put to use on a bigger scale, > > > it's really hard to change in a way that's consistent, safe and not > > > too invasive.) > > > > > > I was, for a very long time, convinced that we can still have a nice > > > single-page AJAX GWT UI application that doesn't need "refresh on > > > logout", i.e. application that properly handles UiCommon. In light > > > of upcoming SSO changes, however, we should do "refresh on logout". > > > > > > This will allow us to: > > > > > > * (future) eliminate GWT login screen entirely, in favor of SSO > > > interactive login page > > > > > > * (now) eliminate complex infra (UiCommonInitEvent & friends) > > > in order to properly use UiCommon in single-page application > > > scenario > > > > > > (BTW, PlaceRequestInternalEvent handler count increased from 111 > > > to 205, not sure what is the exact cause of this, I'd have to dig > > > deeper into GWTP infra code.) > > > > > > > > > > > > > As you can see the number of events fired is not all that high, the > > > > > only > > > > > somewhat strange thing, is that there are a huge number of > > > > > UiCommonInitEvent handlers. Doing a quick search reveals that every > > > > > tab > > > > > provider, every refresh manager (refresh button) and a whole bunch > > > > > of > > > > > other > > > > > widgets all have handlers, which does explain the huge number of > > > > > handlers. > > > > > > Yup. All of this is needed to properly use UiCommon in single-page > > > scenario, i.e. UI components need to be notified whenever UiCommon > > > model instances change (typically due to UI login). > > > > > > If UiCommon wasn't designed to instantiate whole model tree right > > > on successful login (replacing old instances with new ones), we > > > wouldn't have to deal with this issue. The whole UiCommonInitEvent > > > infra is to ensure we use UiCommon in a way it was designed to be > > > used. > > > > > > > > > > > > > In short I don't think the slowness is related to the EventBus at > > > > > this > > > > > point > > > > > in time and I will have to look else where for the problem. > > > > > > > > > > > > > To respond to myself (isn't talking to yourself a sign of insanity?). > > > > > > Nah :) re-thinking what you thought previously is a good thing. > > > > > > > I did > > > > some profiling > > > > while running in GWT debug mode, and I discovered the following > > > > sequence > > > > of > > > > events > > > > which seems to be related to the huge number of UiCommonInitEvent > > > > handlers. > > > > > > > > I found that most of the time was taken during the UiCommonInitEvent > > > > firing. > > > > which > > > > led me to see which one of the handlers was taking so long. So I > > > > profiled > > > > the > > > > time each > > > > handler took to complete. I noticed something really strange, the tab > > > > providers all > > > > took between 0 and 1ms. > > > > > > It's because TabModelProvider#onCommonModelChange is not special in any > > > way. > > > > > > > But every single sub tab presenter for every single > > > > sub tab > > > > was taking between 500 and 3000ms depending on the presenter. > > > > > > It's because creation of presenter triggeres creation of view, and > > > creation > > > of view triggers HTML DOM operations which can be expensive, depending > > > on > > > the complexity of the view/HTML. > > > > > > It's very important to realize that presenter must be first created and > > > bound > > > (presenter's proxy takes care of this) and only THEN presenter is able > > > to > > > deal > > > with events such as UiCommonInitEvent. > > > > > > @ProxyEvent causes event handler to be registered on proxy itself - > > > whenever > > > such event occurs, proxy will create & bind presenter and call > > > corresponding > > > @ProxyEvent method on presenter. > > > > > > This is also why you're observing 500 .. 3000ms times. > > > > > > > Since we have > > > > like > > > > 200 of those presenters, every single one of them was being > > > > called/initialized and > > > > taking time, even if we never used them. It turns out we had a > > > > ProxyEvent > > > > on > > > > AbstractSubTabPresenter, which would cause every single sub tab > > > > presenter > > > > to > > > > load > > > > (since they were code splitted, this takes a lot of requests). > > > > > > > > @ProxyEvent > > > > public void onUiCommonInit(UiCommonInitEvent event) { > > > > ...initialize some handlers... > > > > } > > > > > > Correct! @ProxyEvent is a "lazy" programmer's trick to ensure that > > > presenter > > > never misses on any event of given type. > > > > > > The downside is that when such event (UiCommonInitEvent) happens, > > > possibly > > > TONS of presenters (and associated views) will be created & bound. > > > > > > As we discussed, we can improve this by moving relevant code into > > > onBind() > > > presenter lifecycle callback. > > > > > > > > > > > So what I did to solve the problem, I removed the @ProxyEvent, and > > > > renamed > > > > it > > > > initializeHandlers. Then instead of them being called in response to > > > > the > > > > onUiCommonInit event, I put the call in onBind of the presenter. If I > > > > understand the > > > > GWTP life cycle correctly this should have the same effect as before > > > > (the > > > > handlers are > > > > initialized before they are needed) and thus everything should work > > > > the > > > > same. > > > > > > onBind() is called once per lifetime of bound object. > > > > > > All presenters are singletons, so onBind() is called once in their > > > lifetime. > > > > > > A common trick is to do following in onBind(): > > > > > > // For any future occurences of event > > > registerHandler(eventBus.addHandler(..foo()..)); > > > > > > // For the first time, if needed > > > foo(); > > > > > > (Assuming foo() contains init logic sensitive to given event.) > > > > > > > > > > > The results that I have observed so far from these changes: > > > > - GWT debug mode login takes ~50s instead of 4:30. > > > > - The number of requests to the engine dropped from around 80 to > > > > around > > > > 20. > > > > - In compiled mode the login is much much faster. > > > > - I haven't checked the memory usage, but I am guessing it will be > > > > much > > > > lower > > > > with all > > > > presenters not being in memory until they are needed. > > > > > > Great stuff! Maybe we could squeeze this in 3.5 too :) > > > > > > > > > > > My only concern at this point, is that I am not aware of a particular > > > > sequence that > > > > requires the presenters to be present somewhere, and now they are > > > > not, > > > > and > > > > something doesn't work. > > > > > > Communication is mostly done through events, so EventBus is essentially > > > the only direct dependency between all presenters. In practice, there > > > might be exceptions, but in general, events are to decouple presenters. > > > > > > As for your concern - I don't think we should worry about it. GWTP > > > infra > > > will always load presenters when they are needed (i.e. for the reveal > > > of > > > requested place). Our code CAN load them even earlier, if needed (like > > > with @ProxyEvent). > > > > > > > In my limited testing everything worked the same as > > > > before, > > > > but obviously I haven't touched every single tab and sub tab. > > > > > > > > One more thing to note, the proxy event has been like that since > > > > before > > > > I > > > > joined Red > > > > Hat, so again this is NOT the cause for the recent slowdown, but > > > > something > > > > in > > > > the > > > > presenters could have added some time to each of them causing the > > > > huge > > > > number > > > > of > > > > them combined to have a large impact. > > > > > > The number of sub tabs (and associated UiCommon models) grew over time, > > > so there's (I think) cumulative performance impact of @ProxyEvent in > > > AbstractSubTabPresenter. > > > > > > Sure, there might be other bottlenecks, but we can improve this right > > > now and gain substantial speed/performance improvement. > > > > > > (Great job!) > > > > > > > > > > > Alexander > > > > > > > > > Alexander > > > > > > > > > > > > > _______________________________________________ > > Devel mailing list > > Devel(a)ovirt.org > > http://lists.ovirt.org/mailman/listinfo/devel > > > _______________________________________________ > Devel mailing list > Devel(a)ovirt.org > http://lists.ovirt.org/mailman/listinfo/devel > _______________________________________________ Devel mailing list Devel(a)ovirt.org http://lists.ovirt.org/mailman/listinfo/devel