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

Vojtech Szocs vszocs at redhat.com
Mon Aug 11 14:17:37 UTC 2014



----- Original Message -----
> From: "Vojtech Szocs" <vszocs at redhat.com>
> To: "Eli Mesika" <emesika at redhat.com>
> Cc: devel at 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 at redhat.com>
> > To: "Greg Sheremeta" <gshereme at redhat.com>
> > Cc: devel at 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 at redhat.com>
> > > To: devel at 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.

Wiki updated, doc patch submitted: http://gerrit.ovirt.org/#/c/31342/

> 
> Vojtech
> 
> > 
> > Thanks
> > 
> > 
> > > 
> > > ----- Original Message -----
> > > > From: "Vojtech Szocs" <vszocs at redhat.com>
> > > > To: devel at ovirt.org
> > > > Cc: awels at redhat.com, ecohen at redhat.com, gshereme at 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 at redhat.com>
> > > > > To: vszocs at redhat.com
> > > > > Cc: ecohen at redhat.com, gshereme at 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 at ovirt.org
> > > http://lists.ovirt.org/mailman/listinfo/devel
> > > 
> > _______________________________________________
> > Devel mailing list
> > Devel at ovirt.org
> > http://lists.ovirt.org/mailman/listinfo/devel
> > 
> _______________________________________________
> Devel mailing list
> Devel at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/devel
> 



More information about the Devel mailing list