Stacked on #32736.
That way you can find the owner stack of each component that rerendered
for context.
In addition to the JSX callsite tasks that we already track, I also
added tracking of the first `setState` call before rendering.
We then run the "Update" entries in that task. That way you can find the
callsite of the first setState and therefore the "cause" of a render
starting by selecting the "Update" track.
Unfortunately this is blocked on bugs in Chrome that makes it so that
these stacks are not reliable in the Performance tab. It basically just
doesn't work.
This fixes two bugs with commit phase effect tracking.
I missed, or messed up the rebase for, deletion effects when a subtree
was deleted and for passive disconnects when a subtree was hidden.
The other bug is that when I started using self time
(componentEffectDuration) for color and for determining whether to
bother logging an entry, I didn't consider that the component with
effects can have children which end up resetting this duration before we
log. Which lead to most effects not having their components logged since
they almost always have children.
We don't necessarily have to push/pop but we have to store at least one
thing on the stack unfortunately. That's because we have to do the
actual log after the children to get the right end time. So might as
well use the push/pop strategy like the rest of them.
This tracks commit phase errors and marks the component that errored as
red. These also get the errors attached to the entry.
<img width="1505" alt="Screenshot 2024-12-20 at 2 40 14 PM"
src="https://github.com/user-attachments/assets/cac3ead7-a024-4e33-ab27-2e95293c4299"
/>
In the render phase I just mark the Error Boundary that caught the
error. We don't have access to the actual error since it's locked behind
closures in the update queue. We could probably expose that someway.
<img width="949" alt="Screenshot 2024-12-20 at 1 49 05 PM"
src="https://github.com/user-attachments/assets/3032455d-d9f2-462b-9c07-7be23663ecd3"
/>
Follow ups:
Since the Error Boundary doesn't commit its attempted render, we don't
log those. If we did then maybe we should just mark the errored
component like I do for the commit phase. We could potentially walk the
list of errors and log the captured fibers and just log their entries as
children.
We could also potentially walk the uncommitted Fiber tree by stashing it
somewhere or even getting it from the alternate. This could be done on
Suspense boundaries too to track failed hydrations.
---------
Co-authored-by: Ricky <rickhanlonii@gmail.com>
A common source of performance problems is due to cascading renders from
calling `setState` in `useLayoutEffect` or `useEffect`. This marks the
entry from the update to when we start the render as red and `"Cascade"`
to highlight this.
<img width="964" alt="Screenshot 2024-12-19 at 10 54 59 PM"
src="https://github.com/user-attachments/assets/2bfa91e6-1dc1-4b7f-a659-50aaf2a97e83"
/>
In addition to this case, there's another case where you call `setState`
multiple times in the same event causing multiple renders. This might be
due to multiple `flushSync`, or spawned a microtasks from a
`useLayoutEffect`. In theory it could also be from a microtask scheduled
after the first `setState`. This one we can only detect if it's from an
event that has a `window.event` since otherwise it's hard to know if
we're still in the same event.
<img width="1210" alt="Screenshot 2024-12-19 at 11 38 44 PM"
src="https://github.com/user-attachments/assets/ee188bc4-8ebb-4e95-b5a5-4d724856c27d"
/>
I decided against making a ping in a microtask considered a cascade.
Because that should ideally be using the Suspense Optimization and so
wouldn't be considered multi-pass.
<img width="1284" alt="Screenshot 2024-12-19 at 11 07 30 PM"
src="https://github.com/user-attachments/assets/2d173750-a475-41a0-b6cf-679d15c4ca97"
/>
We might consider making the whole render phase and maybe commit phase
red but that should maybe reserved for actual errors. The "Blocked"
phase really represents the `setState` and so will have the stack trace
of the first update.
This ensures that we mark the time from ping until we render as
"Blocked".
We intentionally don't want to show the event time even if it's
something like "load" because it draws attention away from interactions
etc.
<img width="577" alt="Screenshot 2024-11-21 at 7 22 39 PM"
src="https://github.com/user-attachments/assets/70cca2e8-bd5e-489f-98f0-b4dfee5940af">
This avoid re-emitting the yellow "Event" log when we ping inside the
original event. Instead of treating events as repeated when we get
repeated updates, we treat them as repeated if we've ever logged out
this event before.
Additionally, in the case the prerender sibling flag is on we need to
ensure that if a render gets interrupted when it has been suspended we
treat that as "Prewarm" instead of "Interrupted Render".
Before:
<img width="539" alt="Screenshot 2024-11-19 at 2 39 44 PM"
src="https://github.com/user-attachments/assets/190ca50c-5168-40d8-a6fd-6b9a583af1f0">
After:
<img width="1004" alt="Screenshot 2024-11-21 at 4 53 16 PM"
src="https://github.com/user-attachments/assets/0c441ada-1ed1-412c-8935-aaf040c25dfe">
Stacked on #31552. Must be tested with `enableSiblingPrerendering` off
since the `use()` optimization is not on there yet.
This adds a span to the Components track when we yield in the middle of
the event loop. In this scenario, the "Render" span continues through
out the Scheduler track. So you can see that the Component itself might
not take a long time but yielding inside of it might.
This lets you see if something was blocking the React render loop while
yielding. If we're blocked 1ms or longer we log that as "Blocked".
If we're yielding due to suspending in the middle of the work loop we
log this as "Suspended".
<img width="837" alt="Screenshot 2024-11-16 at 1 15 14 PM"
src="https://github.com/user-attachments/assets/45a858ea-17e6-416c-af1a-78c126e033f3">
If the render doesn't commit because it restarts due to some other
prewarming or because some non-`use()` suspends, it doesn't have from
context components.
<img width="971" alt="Screenshot 2024-11-16 at 1 13 55 PM"
src="https://github.com/user-attachments/assets/a67724f8-702e-4e7d-9499-9ffc09541a61">
The `useActionState` path doesn't work yet because the `use()`
optimization doesn't work there for some reason. But the idea is that it
should mark the time that the component is blocked as Action instead of
Suspended.
When we suspend the render with delay, we won't do any more work until
we get some kind of another update/ping. It's because conceptually
something is suspended and then will update later. We need to highlight
this period to show why it's not doing any work. We fill the empty space
with "Suspended". This stops whenever the same lane group starts
rendering again. Clamped by the preceeding start time/event time/update
time.
<img width="902" alt="Screenshot 2024-11-15 at 1 01 29 PM"
src="https://github.com/user-attachments/assets/acf9dc9a-8fc3-4367-a8b0-d19f9c9eac73">
Ideally we would instead start the next render and suspend the work loop
at all places we suspend. In that mode this will instead show up as a
very long "Render" with a "Suspended" period instead highlighted in the
Components track as one component is suspended. We'll soon have that for
`use()` but not all updates so this covers the rest.
One issue with `useActionState` is that it is implemented as suspending
at the point of the `useActionState` which means that the period of the
Action shows up as a suspended render instead of as an Action which
happens for raw actions. This is not really how you conceptually think
about it so we need some special case for `useActionState`. In the
screenshot above, the first "Suspended" is actually awaiting an Action
and the second "Suspended" is awaiting the data from it.
This includes:
- `Interrupted Render`: Interrupted Renders (setState or ping at higher
priority)
- `Prewarm`: Suspended Renders outside a Suspense boundary
(RootSuspendedWithDelay/RootSuspendedAtTheShell)
- `Errored Render`: Render that errored somewhere in the tree (Fatal or
Not) (which may or may not be retried and then complete)
- `Teared Render`: Due to useSyncExternalStore not matching (which will
do another sync attempt)
Suspended Commit:
<img width="893" alt="Screenshot 2024-11-14 at 11 47 40 PM"
src="https://github.com/user-attachments/assets/b25a6a8b-a5e9-4d66-b325-57aef4bf9dad">
Errored with a second recovery attempt that also errors:
<img width="976" alt="Screenshot 2024-11-15 at 12 09 06 AM"
src="https://github.com/user-attachments/assets/9ce52cbb-b587-4f1e-8b67-e51d9073ae5b">
When you schedule a microtask from render or effect and then call
setState (or ping) from there, the "event" is the event that React
scheduled (which will be a postMessage). The event time of this new
render will be before the last render finished.
We usually clamp these but in this scenario the update doesn't happen
while a render is happening. Causing overlapping events.
Before:
<img width="1229" alt="Screenshot 2024-11-12 at 11 01 30 PM"
src="https://github.com/user-attachments/assets/9652cf3b-b358-453c-b295-1239cbb15952">
Therefore when we finalize a render we need to store the end of the last
render so when we a new update comes in later with an event time earlier
than that, we know to clamp it.
There's also a special case here where when we enter the
`RootDidNotComplete` or `RootSuspendedWithDelay` case we neither leave
the root as in progress nor commit it. Those needs to finalize too.
Really this should be modeled as a suspended track that we haven't added
yet. That's the gap between "Blocked" and "message" below.
After:
<img width="1471" alt="Screenshot 2024-11-13 at 12 31 34 AM"
src="https://github.com/user-attachments/assets/b24f994e-9055-4b10-ad29-ad9b36302ffc">
I also fixed an issue where we may log the same event name multiple
times if we're rendering more than once in the same event. In this case
I just leave a blank trace between the last commit and the next update.
I also adding ignoring of the "message" event at all in these cases when
the event is from React's scheduling itself.
This reverts commit d3bf32a958 which was
part of #30983
When you have very deep trees this trick can cause the top levels to
skew way too much from the real numbers. Creating unbalanced trees.
The bug should have been fixed in Chrome Canary now so that entries
added later are sorted to go first which should've addressed this issue.
A slight behavior change here too is that I now mark the start of the
commit phase before the BeforeMutationEffect phase. This affects
`<Profiler>` too.
The named sequences are as follows:
Render -> Suspended or Throttled -> Commit -> Waiting for Paint ->
Remaining Effects
The Suspended phase is only logged if we delay the Commit due to CSS /
images.
The Throttled phase is only logged if we delay the commit due to the
Suspense throttling timer.
<img width="1246" alt="Screenshot 2024-09-20 at 9 14 23 PM"
src="https://github.com/user-attachments/assets/8d01f444-bb85-472b-9b42-6157d92c81b4">
I don't yet log render phases that don't complete. I think I also need
to special case renders that or don't commit after being suspended.
This tracks the current window.event.timeStamp the first time we
setState or call startTransition. For either the blocking track or
transition track. We can use this to show how long we were blocked by
other events or overhead from when the user interacted until we got
called into React.
Then we track the time we start awaiting a Promise returned from
startTransition. We can use this track how long we waited on an Action
to complete before setState was called.
Then finally we track when setState was called so we can track how long
we were blocked by other word before we could actually start rendering.
For a Transition this might be blocked by Blocking React render work.
We only log these once a subsequent render actually happened. If no
render was actually scheduled, then we don't log these. E.g. if an
isomorphic Action doesn't call startTransition there's no render so we
don't log it.
We only log the first event/update/transition even if multiple are
batched into it later. If multiple Actions are entangled they're all
treated as one until an update happens. If no update happens and all
entangled actions finish, we clear the transition so that the next time
a new sequence starts we can log it.
We also clamp these (start the track later) if they were scheduled
within a render/commit. Since we share a single track we don't want to
create overlapping tracks.
The purpose of this is not to show every event/action that happens but
to show a prelude to how long we were blocked before a render started.
So you can follow the first event to commit.
<img width="674" alt="Screenshot 2024-09-20 at 1 59 58 AM"
src="https://github.com/user-attachments/assets/151ba9e8-6b3c-4fa1-9f8d-e3602745eeb7">
I still need to add the rendering/suspended phases to the timeline which
why this screenshot has a gap.
<img width="993" alt="Screenshot 2024-09-20 at 12 50 27 AM"
src="https://github.com/user-attachments/assets/155b6675-b78a-4a22-a32b-212c15051074">
In this case it's a Form Action which started a render into the form
which then suspended on the action. The action then caused a refresh,
which interrupts with its own update that's blocked before rendering.
Suspended roots like this is interesting because we could in theory
start working on a different root in the meantime which makes this
timeline less linear.
Stacked on #30981. Same as #30967 but for effects.
This logs a tree of components using `performance.measure()`.
In addition to the previous render phase this logs one tree for each
commit phase:
- Mutation Phase
- Layout Effect
- Passive Unmounts
- Passive Mounts
I currently skip the Before Mutation phase since the snapshots are so
unusual it's not worth creating trees for those.
The mechanism is that I reuse the timings we track for
`enableProfilerCommitHooks`. I track first and last effect timestamp
within each component subtree. Then on the way up do we log the entry.
This means that we don't include overhead to find our way down to a
component and that we don't need to add any additional overhead by
reading timestamps.
To ensure that the entries get ordered correctly we need to ensure that
the start time of each parent is slightly before the inner one.
Stacked on #30979.
The problem with the previous approach is that it recursively walked the
tree up to propagate the resulting time from recording a layout effect.
Instead, we keep a running count of the effect duration on the module
scope. Then we reset it when entering a nested Profiler and then we add
its elapsed count when we exit the Profiler.
This also fixes a bug where we weren't previously including unmount
times for some detached trees since they couldn't bubble up to find the
profiler.
Stacked on #30960 and #30966. Behind the enableComponentPerformanceTrack
flag.
This is the first step of performance logging. This logs the start and
end time of a component render in the passive effect phase. We use the
data we're already tracking on components when the Profiler component or
DevTools is active in the Profiling or Dev builds. By backdating this
after committing we avoid adding more overhead in the hot path. By only
logging things that actually committed, we avoid the costly unwinding of
an interrupted render which was hard to maintain in earlier versions.
We already have the start time but we don't have the end time. That's
because `actualStartTime + actualDuration` isn't enough since
`actualDuration` counts the actual CPU time excluding yields and
suspending in the render.
Instead, we infer the end time to be the start time of the next sibling
or the complete time of the whole root if there are no more siblings. We
need to pass this down the passive effect tree. This will mean that any
overhead and yields are attributed to this component's span. In a follow
up, we'll need to start logging these yields to make it clear that this
is not part of the component's self-time.
In follow ups, I'll do the same for commit phases. We'll also need to
log more information about the phases in the top track. We'll also need
to filter out more components from the trees that we don't need to
highlight like the internal Offscreen components. It also needs polish
on colors etc.
Currently, I place the components into separate tracks depending on
which lane currently committed. That way you can see what was blocking
Transitions or Suspense etc. One problem that I've hit with the new
performance.measure extensions is that these tracks show up in the order
they're used which is not the order of priority that we use. Even when
you add fake markers they have to actually be within the performance run
since otherwise the calls are noops so it's not enough to do that once.
However, I think this visualization is actually not good because these
trees end up so large that you can't see any other lanes once you expand
one. Therefore, I think in a follow up I'll actually instead switch to a
model where Components is a single track regardless of lane since we
don't currently have overlap anyway. Then the description about what is
actually rendering can be separate lanes.
<img width="1512" alt="Screenshot 2024-09-15 at 10 55 55 PM"
src="https://github.com/user-attachments/assets/5ca3fa74-97ce-40c7-97f7-80c1dd7d6470">
<img width="1512" alt="Screenshot 2024-09-15 at 10 56 27 PM"
src="https://github.com/user-attachments/assets/557ad65b-4190-465f-843c-0bc6cbb9326d">
Nit: I don't trust flags in hot code. While it can take somewhat longer
to compile two functions and JIT them. After that they don't need to
check branches. Also makes it clearer the purpose.
We've heard from multiple contributors that the Reconciler forking
mechanism was confusing and/or annoying to deal with. Since it's
currently unused and there's no immediate plans to start using it again,
this removes the forking.
Fully removing the fork is split into 2 steps to preserve file history:
**#25774 previous PR that did the bulk of the work:**
- remove `enableNewReconciler` feature flag.
- remove `unstable_isNewReconciler` export
- remove eslint rules for cross fork imports
- remove `*.new.js` files and update imports
- merge non-suffixed files into `*.old` files where both exist
(sometimes types were defined there)
**This PR**
- rename `*.old` files
* Rename lower case isomorphic default exports modules to upper case named exports
We're somewhat inconsistent here between e.g. ReactLazy and memo.
Let's pick one.
This also moves the responder, fundamental, scope creators from shared
since they're isomorphic and same as the other creators.
* Move some files that are specific to the react-reconciler from shared
Individual renderers are allowed to deep require into the reconciler.
* Move files specific to react-dom from shared
react-interactions is right now dom specific (it wasn't before) so we can
type check it together with other dom stuff. Avoids the need for
a shared ReactDOMTypes to be checked by RN for example.
* Move ReactWorkTags to the reconciler
* Move createPortal to export from reconciler
Otherwise Noop can't access it since it's not allowed deep requires.
* Implemented Profiler onCommit() and onPostCommit() hooks
* Added enableProfilerCommitHooks feature flag for commit hooks
* Moved onCommit and onPassiveCommit behind separate feature flag
* Update Flow to 0.84
* Fix violations
* Use inexact object syntax in files from fbsource
* Fix warning extraction to use a modern parser
* Codemod inexact objects to new syntax
* Tighten types that can be exact
* Revert unintentional formatting changes from codemod
* Import Scheduler directly, not via host config
We currently schedule asynchronous tasks via the host config. (The host
config is a static/build-time dependency injection system that varies
across different renderers — DOM, native, test, and so on.) Instead of
calling platform APIs like `requestIdleCallback` directly, each renderer
implements a method called `scheduleDeferredCallback`.
We've since discovered that when scheduling tasks, it's crucial that
React work is placed in the same queue as other, non-React work on the
main thread. Otherwise, you easily end up in a starvation scenario where
rendering is constantly interrupted by less important tasks. You need a
centralized coordinator that is used both by React and by other
frameworks and application code. This coordinator must also have a
consistent API across all the different host environments, for
convention's sake and so product code is portable — e.g. so the same
component can work in both React Native and React Native Web.
This turned into the Scheduler package. We will have different builds of
Scheduler for each of our target platforms. With this approach, we treat
Scheduler like a built-in platform primitive that exists wherever React
is supported.
Now that we have this consistent interface, the indirection of the host
config no longer makes sense for the purpose of scheduling tasks. In
fact, we explicitly do not want renderers to scheduled task via any
system except the Scheduler package.
So, this PR removes `scheduleDeferredCallback` and its associated
methods from the host config in favor of directly importing Scheduler.
* Missed an extraneous export
* Simplified profiler actualDuration timing
While testing the new DevTools profiler, I noticed that sometimes– in larger, more complicated applications– the actualDuration value was incorrect (either too large, or sometimes negative). I was not able to reproduce this in a smaller application or test (which sucks) but I assume it has something to do with the way I was tracking render times across priorities/roots. So this PR replaces the previous approach with a simpler one.
* Changed bubbling logic after chatting out of band with Andrew
* Replaced __PROFILE__ with feature-flag conditionals in test
* Updated test comment
* Use %s in the console calls
* Add shared/warningWithStack
* Convert some warning callsites to warningWithStack
* Use warningInStack in shared utilities and remove unnecessary checks
* Replace more warning() calls with warningWithStack()
* Fixes after rebase + use warningWithStack in react
* Make warning have stack by default; warningWithoutStack opts out
* Forbid builds that may not use internals
* Revert newly added stacks
I changed my mind and want to keep this PR without functional changes. So we won't "fix" any warnings that are already missing stacks. We'll do it in follow-ups instead.
* Fix silly find/replace mistake
* Reorder imports
* Add protection against warning argument count mismatches
* Address review
* Fix getComponentName() for types with nested $$typeof
* Temporarily remove Profiler ID from messages
* Change getComponentName() signature to take just type
It doesn't actually need the whole Fiber.
* Remove getComponentName() forks in isomorphic and SSR
* Remove unnecessary .type access where we already have a type
* Remove unused type
This is an unobservable change to all but the (under development) DevTools Profiler plugin. It is being done so that the plugin can safely feature detect a version of React that supports it. The profiler API has existed since the 16.4.0 release, but it did not support the DevTools plugin prior to PR #13058.
Side note: I am not a big fan of the term "base duration". Both it and "actual duration" are kind of awkward and vague. If anyone has suggestions for better names– this is the best time to bikeshed about them.
* Reset ReactProfilerTimer's DEV-only Fiber stack after an error
* Added ReactNoop functionality to error during "complete" phase
* Added failing profiler stack unwinding test
* Potential fix for unwinding time bug
* Renamed test
* Don't record time until complete phase succeeds. Simplifies unwinding.
* Expanded ReactProfilerDevToolsIntegration-test coverage a bit
* Added unstable_flushWithoutCommitting method to noop renderer
* Added failing multi-root/batch test to ReactProfiler-test
* Beefed up tests a bit and added some TODOs
* Profiler timer differentiates between batched commits and in-progress async work
This was a two-part change:
1) Don't count time spent working on a batched commit against yielded async work.
2) Don't assert an empty stack after processing a batched commit (because there may be yielded async work)
This is kind of a hacky solution, and may have problems that I haven't thought of yet. I need to commit this so I can mentally clock out for a bit without worrying about it. I will think about it more when I'm back from PTO. In the meanwhile, input is welcome.
* Removed TODO
* Replaced FiberRoot map with boolean
* Removed unnecessary whitespace edit
* Moved actual time fields from Profiler stateNode to Fiber
* Record actual time for all Fibers within a ProfileMode tree
* Changed how profiler accumulates time
This change gives up on accumulating time across renders of different priority, but in exchange- simplifies how the commit phase (reset) code works, and perhaps also makes the profiling code more compatible with future resuming behavior
* Added start time parameter to Profiler onRender callback
* Profiler also captures commit time
* Only init Profiler stateNode if enableProfilerTimer feature flag enabled
* Extract base Jest config
This makes it easier to change the source config without affecting the build test config.
* Statically import the host config
This changes react-reconciler to import HostConfig instead of getting it through a function argument.
Rather than start with packages like ReactDOM that want to inline it, I started with React Noop and ensured that *custom* renderers using react-reconciler package still work. To do this, I'm making HostConfig module in the reconciler look at a global variable by default (which, in case of the react-reconciler npm package, ends up being the host config argument in the top-level scope).
This is still very broken.
* Add scaffolding for importing an inlined renderer
* Fix the build
* ES exports for renderer methods
* ES modules for host configs
* Remove closures from the reconciler
* Check each renderer's config with Flow
* Fix uncovered Flow issue
We know nextHydratableInstance doesn't get mutated inside this function, but Flow doesn't so it thinks it may be null.
Help Flow.
* Prettier
* Get rid of enable*Reconciler flags
They are not as useful anymore because for almost all cases (except third party renderers) we *know* whether it supports mutation or persistence.
This refactoring means react-reconciler and react-reconciler/persistent third-party packages now ship the same thing.
Not ideal, but this seems worth how simpler the code becomes. We can later look into addressing it by having a single toggle instead.
* Prettier again
* Fix Flow config creation issue
* Fix imprecise Flow typing
* Revert accidental changes
Add a new component type, Profiler, that can be used to collect new render time metrics. Since this is a new, experimental API, it will be exported as React.unstable_Profiler initially.
Most of the functionality for this component has been added behind a feature flag, enableProfileModeMetrics. When the feature flag is disabled, the component will just render its children with no additional behavior. When the flag is enabled, React will also collect timing information and pass it to the onRender function (as described below).
Sebastian MarkbågeandGitHub
Jan KassensandGitHub
Andrew Clark
Sebastian MarkbågeandGitHub
Brian VaughnandGitHub
Dan AbramovandGitHub
Héctor RamosandGitHub
Brian VaughnandGitHub
