Analyze React+Redux perf timings using recording analysis

[markerikson]

This PR:

• Adds a new "React+Redux Perf" sidebar panel
• Adds a button that, when clicked:
  • Finds all Redux dispatches
  • Finds all calls to useSelector
  • Finds all unique selector functions passed to useSelector
  • Finds all individual calls to each selector function and calculates their durations
  • Sums up the total execution time for each selector function
  • Finds all calls to notify React-Redux subscribers and checks the time spent notifying subscribers
  • Finds all calls to re-render a React component
  • Buckets the data by dispatch() start/end times, and groups all the selector calls, notification calls, and queued re-renders triggered by that dispatch

In other words, this is a major first step towards a useful React+Redux perf analysis tool.

Caveats:

• Right now I'm just logging the grouped data, and haven't tried to display or visualize any of this yet
• It currently takes ~30s to calculate the results for a 2s focus region with ~40 dispatches. The most expensive parts are running evaluations to find all the selector functions, and calling Debugger.findStepOutTarget to determine the execution time for a couple thousand function calls.

It's very likely that the execution speed would be faster if we moved this into a backend postprocessing routine, and also added some additional backend APIs to allow requesting step-out results in batches instead of individual requests.

Here's an example of what the output looks like for a given dispatch in our own front-end codebase:

That one dispatch:

• did queue a re-render (by scheduling one component to update)
• we spent 15.3ms notifying subscribers
• we cascaded through 10 nested connect components notifying their children
• we ran 114 separate selector calls
• of those, only 14 selector calls had a meaningful non-zero duration
• total time of selectors was 0.3ms, which means that there's 15.0ms of subscriber overhead (!)

[vercel]

The latest updates on your projects. Learn more about Vercel for Git ↗︎

Name	Status	Preview	Comments	Updated (UTC)
devtools	✅ Ready (Inspect)	Visit Preview	💬 Add feedback	Sep 27, 2023 6:05pm

[replay-io]

E2E Tests

75 replays were recorded for fa1db6b.

0 Failed

75 Passed

• authenticated/test-suites/library-test-runs
• authenticated/test-suites/library-tests-list
• breakpoints-01: Test basic breakpoint functionality
• breakpoints-02: Test unhandled divergence while evaluating at a breakpoint
• breakpoints-03: Test stepping forward through breakpoints when rewound before the first one
• breakpoints-04: catch, finally, generators, and async/await
• breakpoints-05: Test interaction of breakpoints with debugger statements
• breakpoints-06: Test log point in a sourcemapped file
• breakpoints-07: rewind and seek using command bar and console messages
• breakpoints-08: should be temporarily disabled
• console_async: support console evaluations in async frames
• console_dock_node: Should show the correct docking behavior for recordings without video
• console_dock: Should show the correct docking behavior for recordings with video
• console_errors: Test that errors and warnings from various sources are shown in the console
• console_eval: support console evaluations
• console_warp-01: should support warping to console messages
• console_warp-02: support pausing, warping, stepping and evaluating console messages
• console-expressions-01: should cache input eager eval and terminal expressions per instance
• cypress-04: Test Step buttons and menu item
• focus_mode-01: should filter messages as regions based on the active focus mode
• highlighter: element highlighter works everywhere
• inspector-computed-01: Basic computed styles can be viewed
• inspector-elements-01: Basic DOM tree node display
• inspector-elements-02_node-picker: element picker and iframe behavior
• inspector-elements-03: Nested node picker and selection behavior
• inspector-elements-04: Keyboard shortcuts should select the right DOM nodes
• inspector-rules-01: Basic CSS rules should be viewed
• inspector-rules-02: Sourcemapped rules should be viewed
• inspector-rules-03: Shorthand CSS rules should be viewed
• jump-to-code-01: Test basic jumping functionality
• logpoints-01: log-points appear in the correct order and allow time warping
• logpoints-02: conditional log-points
• logpoints-03_chromium: should display event properties in the console
• logpoints-03: should display event properties in the console
• logpoints-04: should display exceptions in the console
• logpoints-05: should auto-complete based on log point location
• logpoints-06: should be temporarily disabled
• logpoints-07: should use the correct scope in auto-complete
• logpoints-08: should support jumping directly to a hit point via the capsule input
• logpoints-09: should support pending edits
• logpoints-10: too-many-points-to-find UX
• logpoints-11: too-many-points-to-run-analysis UX
• node_console-01: Basic node console behavior
• node_console-02: uncaught exceptions should show up
• node_control_flow: catch, finally, generators, and async/await
• node_logpoint-01: Basic node logpoints
• node_logpoint-02: Node exception logpoints
• node_object_preview: Showing console objects in node
• node_spawn: Basic subprocess spawning
• node_stepping-01: Test stepping in async frames and async call stacks
• node_worker-01: make sure node workers don't cause crashes
• object_preview-01: expressions in the console after time warping
• object_preview-02: should allow objects in scope to be inspected
• object_preview-03: Test previews when switching between frames and stepping
• object_preview-04: Test scope mapping and switching between generated/original sources
• object_preview-05: Should support logging objects as values
• quick_open_modal-01: Test basic searching functionality
• react_devtools 01: Basic RDT behavior (Chromium)
• react_devtools 01: Basic RDT behavior (FF)
• react_devtools 02: RDT integrations (Chromium)
• redux_devtools: Test Redux DevTools.
• fe-1875 :: verify that steps go to the right point in time
• repaint: repaints the screen screen when stepping over code that modifies the DOM
• resizable-panels-01: Left side Toolbar should be collapsible
• restart debugging session
• scopes_rerender: Test that scopes are rerendered
• sourcemap_stacktrace: Test that stacktraces are sourcemapped
• stacking: Element highlighter selects the correct element when they overlap
• stepping-01: Test basic step-over/back functionality
• stepping-02: Test fixes for some simple stepping bugs
• stepping-03: Stepping past the beginning or end of a frame should act like a step-out
• stepping-04: Test stepping in a frame other than the top frame
• stepping-05_chromium: Test stepping in pretty-printed code
• stepping-05: Test stepping in pretty-printed code
• stepping-06: Test stepping in async frames and async call stacks

View test run on Replay ↗︎

Snapshot Tests

90 replays were recorded for fa1db6b.

0 Failed

90 Passed

• should add true/false keywords to the list of suggestions
• should add this keyword to the list of suggestions
• should be able to toggle side filter menu open and closed
• should be filterable on complex content
• should be filterable
• should be searchable on complex content
• should be searchable
• should display list of messages
• should display toggleable stack for errors
• should display toggleable stack for exceptions
• should display toggleable stack for traces
• should display toggleable stack for warnings
• should escape object expressions in terminal expressions
• should evaluate and render invalid terminal expressions
• should evaluate terminal expressions at an execution point
• should evaluate terminal expressions without an execution point
• should expand and inspect arrays
• should expand and inspect objects
• should hide node_modules (and unpkg) if toggled
• should log events in the console
• should re-focus the search input when CMD+F is used again
• should re-focus the terminal input when search input is hidden
• should refine string tokens to avoid unnecessarily escaping quotation marks
• should remember filter toggle preferences between reloads
• should show a button to clear terminal expressions
• should show error object stacks by default
• should show the context menu on top of other messages and the current time indicator
• should suggest type-ahead options from prototype objects as well
• should support seeking to a message execution point
• should support setting focus range via the context menu
• should support terminal expressions with line breaks
• should render nested, recursive values (as ellipses) without crashing
• should copy arrays
• should copy dates
• should copy deep arrays
• should copy deep objects and their nested properties
• should copy errors
• should copy functions
• should copy html elements and text
• should copy maps
• should copy objects
• should copy primitive client values
• should copy regular expressions
• should copy sets
• should properly bucket properties for an overflowing array
• should render and inspect a Promise
• should render and inspect a Proxy
• should render and inspect arrays
• should render and inspect functions
• should render and inspect HTML elements
• should render and inspect maps
• should render and inspect objects
• should render and inspect regular expressions
• should render and inspect sets
• should render dates
• should render errors
• should render getters and setters correctly
• should render simple values
• should render sections correctly
• should show/hide object and array previews when toggled
• should include log points when filtering data
• should not allow saving log points with invalid conditional
• should not allow saving log points with invalid content
• should not erase break point when logging is toggled
• should not erase log point content when breaking is toggled
• should overflow long log point text (without wrapping)
• should remember search results count per source
• should render search results properly for lines with multiple breakable column positions
• should run local analysis for log points
• should run remote analysis for log points
• should scroll to line and column
• should show different background color and edit icon when log point disabled
• should show preview popup for instance properties
• should support break points
• should support conditional log points
• should support continue to next and previous functionality
• should support custom badge styles for log points
• should support fuzzy file search
• should support jumping to a line in the active source file
• should support new lines in log points
• should support text search in the active source file
• should update the current time when the next/previous log point buttons are clicked
• should render headers for complex data correctly
• should render primitive data correctly
• display an overflow message
• should expand and collapse sources
• should find matches in multiple sources
• should include or exclude external modules as requested
• should open a source and scroll to the correct line
• should reset collapsed state if search changes

View test run on Replay ↗︎

[ryota-murakami]

@markerikson packages/replay-next meant Next.js exclusive package?

[markerikson]

@ryota-murakami : no. All our app source code originally lived in the src folder. When Brian began rewriting some of the pieces using newer React techniques like Suspense, he created a packages/bvaughn-architecture folder and put the new code there. Later, we renamed it to packages/replay-next, to indicate that it's "the next generation of Replay app source code".

[markerikson]

I just updated this to capture details on the start and end of the related React commit, plus counts of how many function and class components got rendered overall:

as well as inspecting the rendered components and determining the details for each unique component type:

This gives us a foundation for being able to do real-world React render performance analysis, on production apps, no further profiling setup needed!

[ryota-murakami]

@markerikson Great Job!

Brian began rewriting some of the pieces

Might be this tweet 😅 https://twitter.com/brian_d_vaughn/status/1674214956668014593

[bvaughn]

Is this worth keeping open as a draft or was it just something you wanted to test/share?

[markerikson]

Keep it as a draft for now. Like the other "React Render" panel, it's something I intend to merge and feature flag, but I need to do some cleanup before it's ready to at least have in the codebase.

[bvaughn]

Cleaning up the PR queue by closing old/stale PRs. Re-open it once it's ready to be reviewed :)

[markerikson]

Time to play with this again...

[markerikson]

There's a lot of conceptual overlap between what I was doing in the first iteration of this "Redux+React Perf Profiler" PR, and what I did in the original POC for the "React Render Timeline" panel.

Both rely on fetching hit points for internals. Both require fetching points for the current focus window. And my POC for the Redux perf work wanted to know when React had rendered, and when we queued renders, so that we could know if the dispatch did actually result in components rendering.

Over this weekend, I've updated this PR:

• Rebased against main
• Extracted the basic Redux dispatch() checks and timings as an interval cache
• Made improvements to the function detail formatting logic
• And tonight I rewrote the React Render Timeline to also use an interval cache, use the new Session.getPointStack API for stack frames, and rewrote the items as a virtualized list.

The result is that the React Render Timeline is showing up significantly faster (5-10s for several hundred hits), whereas before it would take seemingly forever for values to slowly come in.

I don't have any UI for the Redux data yet, but that should be trivial to add now that I've got the cache for the values.

From there, the next step would be to start adding logic to query for perf stats related to a given dispatch: was a render queued, how long did it take, how many components rendered, how long did those take, which ones were most expensive, and what selectors ran and their timings. Rather than fetch all of that up front, fetching it for just one render ought to be reasonably faster.

Here's what the render timeline looks like atm:

[replay-delta]

1 snapshot changes from primary branch

[markerikson]

I've finally built out some UI for the Redux Dispatch Perf panel:

things I can now do with this info:

• set focus ranges from the timestamps
• determine if any React renders were queued by the notifications
• fetch info about selectors, although that gets trickier because I really need to know what selectors were in use prior to the dispatch

and similarly, with React renders, I could pull together info on:

• which components rendered
• how long those each took

I know there's all kinds of caveats on sync renders vs concurrent rendering, components being thrown away, etc. Not anywhere close to being a "real" profiler. But I've got demo code (even if commented out atm) that shows I can get plausible interpretations of that info. So it's a starting point.

[markerikson]

Superseded by #9775 . The Redux perf half went into #9776 , but we've decided not to merge that into the codebase for now. I'll rebase it, then close the PR.