[Research Story]: Audit the efficiency of rendering and painting on the screen

[cherdman]

What? Analyze Venia pages and components to see if they re-render unnecessarily or too frequently, or in general if they run repetitive code unintentially.

Why? React UIs are easy to quickly make, but in exchange, certain patterns can make React do more work than necessary to repaint the UI. This causes bad performance, slow response times due to "layout thrashing", and high energy consumption on battery-powered devices. Auditing our rendering and painting on the screen will allow us to identify possible real and perceptual performance gains, enabling us to improve actual user experience.

How?

• Use performance profilers in Chrome dev tools and other browsers, including Safari in the iOS Simulator
• Record profile information while using all storefront UI behaviors: navigation, selection, filtering, cart, checkout
• Identify areas where many re-renders from high up in the render tree are occurring in a short time
• Investigate any common patterns which cause excessive re-render

Acceptance Criteria

• Write-up of audit results and proposed changes
• Actions and next steps created in the form of GitHub issues

[supernova-at]

Results

Metrics Affected

• First Contentful Paint
• First Meaningful Paint
• Time to Interactive
• Speed Index
• First CPU Idle
• Max Potential First Input Delay
• Time to First Byte

How to Measure

Production Artifact

• Lighthouse Audit
• WebPageTest

Development

• Profile React Components

Best Practices

• [x] Use React in Production mode
• [x] Load images progressively with something like https://github.com/verlok/lazyload Issue Opened: https://github.com/magento/pwa-studio/issues/1708
• [ ] Minimize the number of critical resources
• [ ] Test / simulate / measure against an "Average phone". Industry standard right now is the Moto G4.
• [x] Update sales demo folks to use http://venia.magento.com/ to avoid the redirect
• [x] Route-based code splitting Issue Opened: https://github.com/magento/pwa-studio/issues/1709
• [ ] Ensure CSS is minified for production

Profile Baseline

Lighthouse Audit

Problems Identified / Proposed Changes

• Enable Text Compression

• Eliminate render-blocking resources

• Serve images in next-gen formats

• Ensure text remains visible during webfont load

WebPageTest

See the full results at https://webpagetest.org/result/190918_P5_28f85fa75f8be29a254107ae2a6c645e/.

This test was run using the following settings:

1. From: Dulles, VA
2. Device: Moto G4
3. Browser: Chrome
4. Connection: Cable

Problems Identified / Proposed Changes

Leverage browser caching of static assets

• WARNING - (2.0 hours) - https://js-agent.newrelic.com/nr-1130.min.js
• WARNING - (24.0 hours) - https://fonts.googleapis.com/css?family=Muli:300

React Performance Profiler

This profile was generated according to best practices:

1. development mode with all browser extensions disabled
2. CPU throttled 4x (to simulate Moto G4)

We're doing a good job memoizing our expensive functions. This is just one component example but the pattern is common. Here you can see the initial mount time, followed by the timing of additional mounts later on. Note that subsequent mounts are much faster than the initial one.

Immediately after our first render there is a cascading update:

We should investigate MagentoRouteHandler.componentDidMount and HeadTag.componentDidMount, the latter of which scheduled a cascading update.

CICD

Should Do

• WebPageTest Action
• Page Speed Reporting

Can't Do

• Lighthouse Bot. Requires TravisCI.

Additional Resources

• JS Startup Optimization
• React Profiler Walkthrough
• React Profiler Tutorial (video)
• Website Performance Optimization Course
• Using WebPageTest Book

[supernova-at]

• [x] Write-up of audit results and proposed changes
• [x] Actions and next steps created in the form of GitHub issues

[supernova-at]

Well it turns out I did mostly the wrong kind of investigation on this one.

Re-opening to dive back into React-specific performance (via the React Profiler).

[supernova-at]

Audit Results

The following audit was performed according to our audit guidelines against the release/4.0 branch.

Initial Page Load

📝 Application "site data" cleared before running this audit.

Metrics

📝 Browser events such as DOMContentLoaded, First Paint, etc. not recorded here since we're in development mode and purposefully throttling the CPU.

We have three areas of significant CPU burn (horizontal red bars below):

I don't believe there is anything actionable about them, from left to right they are:

1. Webpack Dev Server
2. The Browser parsing and executing JS, including React writing to the DOM for the first time
3. DOM Garbage Collector

Timeline

Here we can see the full timeline for Venia to mount (no user interactions performed).

Let's zoom in on each significant burst of activity. From left to right they are:

Initial Mounts

Here we can see Venia mounting for the first time.

Clicking the React Tree Reconciliation: Completed Root segment and sorting by "Self Time (descending)" highlights components that are good targets for optimization:

Let's take a closer look at the ones that are an order of magnitude higher than the rest (>10ms):

Self Time	Component	Notes
23.4ms	Query (mount)	This call occurs in the Footer here1
16.5ms	adapter_VeniaAdapter (mount)	Here is the VeniaAdapter component. It has to initialize a lot of Apollo things, but perhaps that can be done more efficiently (or beforehand)?
15.1ms	Route (mount)	If we drill down into this one2 we can see that it is the Route call from Header3
12.5ms	Menu (mount)	This is actually Menu from react-feather and it is expensive because it is wrapped in NavTrigger, a component that is connected to Redux. It may already be fixed on develop.

¹ We should consider making some GraphQL calls at build time. (Devil's advocate: how often is the app going to build relative to how often the GraphQL result will change?) ^{2 3} We should not lazy load (React.lazy / Suspense) anything we know we need for the initial load.

Post-Mount Updates

The bulk of this activity is the componentDidMount function on the HeadTag, MagentoRouteHandler, and Query components:

HeadTag

There is a warning (⛔️) that HeadTag.componentDidMount scheduled a cascading update. From Dan Abramov:

"Cascading" means an update inside an update. React first reconciles the tree by calling render, then commits DOM changes, then calls lifecycle hooks. If you call setState in componentDidMount, you are causing React to repeat the cycle: reconcile the tree, commit DOM changes, and call the hooks. This is wasteful.

Unfortunately this occurs in a third-party (react-head) component.

MagentoRouteHandler

MagentoRouteHandler's componentDidMount does schedule a cascading update (leads to setting state here).

Query

The Query component at 14.3 ms is the most concerning, but we already have plans to replace it with Apollo useQuery hooks in #1657 .

Lazy Load Search Bar Resolution

This one is primarily the SearchBar component mounting but I don't understand why Suspense would have updated and told it to mount in the first place. Remember, there were no user interactions performed. The search bar was never opened.

Here's the relevant code from header.js:

<Suspense fallback={searchOpen ? suspenseFallback : null}>
    <Route
        render={({ history, location }) => (
            <SearchBar
                isOpen={searchOpen}
                history={history}
                location={location}
            />
        )}
    />
</Suspense>

Provider update

I believe Provider refers to an internal component of react-apollo's ApolloProvider. We already have plans to replace this in #1657 .

Hopefully that will clear up the rest of the bursts of activity since they all start with a Provider or Query component update:

Add to Cart

Flow:

1. Tops
2. Valeria Two-Layer Tank
3. Lilac, Large, Add to Cart

The Category Page

The Product Page

Once #1661 is complete we may see a marked improvement here (no GraphQL delay).

As far as the rest of the PDP, I see:

1. A repeated Suspense > Options update. We can shave time by resolving that.
2. Expensive Items update (10.3 ms) the first time you select an option (size, color)
3. Another Header update that includes a Suspense update to SearchBar

Add to Cart

1. The MiniCart gets three updates: two directly from Provider and one from Provider > App > VeniaHeadProvider > HeadProvider

Cart Interactions

📝 All interactions start with a single Valeria Two-Layer Tank already in the cart. Start from the homepage and `Empty Cache and Hard Reload". Then start recording.

Open the Cart Drawer

This is after clicking the shopping cart icon to open the cart drawer.

Transitioning to open Cart drawer

Here is the timing chart before we get the details of the cart:

There's not much that jumps out as taking orders of magnitude longer than others, but it does seem suspect that some things are included at all:

1. Why does opening the cart drawer update VeniaHeadProvider, HeadProvider, and Footer?
2. Suspense > Route > SearchBar
3. CartTrigger
4. HeadProvider > Container

These things are included under a Provider update, which I believe stems from a call to getCartDetails when we open the cart drawer. We may be able to eliminate some of these.

Updating the Cart after we receive Data

The UI that we'd most expect to get updated here is the MiniCart.

MiniCart

Sorted by Total Time

Notably, the bulk of the time spent updating MiniCart is spent mounting Product.

Sorted by Self Time:

Again, three of the top six items are image / icon components. Improvement here will definitely speed things up across the board.

Not MiniCart

There's more than just the MiniCart getting updated here though. We should look into Provider > Header > ...

1. navTrigger_Trigger
2. SearchTrigger
3. Suspense > Route > SearchBar

Perhaps this will disappear when we move away from ApolloProvider > Provider. We should definitely look into the SearchBar though, that keeps appearing in every update.

Add to Favorites

This update looks good. It only updates the Product and Kebab.

Edit Item

Again I would only expect the MiniCart to update here. I'm not sure why the Header is updating at all.

Remove Item

This update looks good. Only Product is updated.

Checkout

📝 Checkout begins with a single Valeria Two-Layer Tank already in the cart.

Checkout Drawer Appears

I'm surprised to see the MiniCart > Body update here.

Address Form Appears

This update looks good.

Address Form Submit

It seems like we may be rendering twice when we submit the address. These two update trees are almost identical.

We do also get repeated Flow > Form updates here. There is one for each field in the form.

Payments Form Open

This update looks good.

Payments Form Submit

Again we see a Flow > Form update for each field in the form. The actual submission looks good.

Shipping Method Open

Looks good.

Shipping Method Submit

There are two Flow > Form updates here. We can probably drop one. The actual submit update looks good.

---

• [x] Use performance profilers in Chrome dev tools and other browsers, including Safari in the iOS Simulator Kind of: didn't use iOS simulator
• [x] Record profile information while using all storefront UI behaviors: navigation, selection, filtering, cart, checkout Kind of: didn't do filtering
• [x] Identify areas where many re-renders from high up in the render tree are occurring in a short time
• [x] Investigate any common patterns which cause excessive re-render

Resources

React

https://kentcdodds.com/blog/fix-the-slow-render-before-you-fix-the-re-render

Redux

https://reactrocket.com/post/react-redux-optimization/ https://itnext.io/redux-ruins-you-react-app-performance-you-are-doing-something-wrong-82e28ec96cf5 https://redux.js.org/faq/performance

[supernova-at]

Issues created and added to performance milestone https://github.com/magento/pwa-studio/milestone/20