Reset profiler timer correctly after errors #13123
Conversation
|
Should we add the ability to run our tests against a profiler+DevTools type bundle? I found the 2nd bug by doing that locally. |
|
ReactDOM: size: -0.2%, gzip: 0.0% Details of bundled changes.Comparing: 85fe4dd...def0b6c react-dom
react-art
react-test-renderer
react-noop-renderer
react-reconciler
react-native-renderer
Generated by 🚫 dangerJS |
|
The way batched roots and yielded async roots interleave is tricky. I'm posting PR #13145 as a temporary alternative to this PR that disables the auto-profiling behavior when DevTools are present. Once I've identified a fix for the 3rd case mentioned in the PR description, we can back that change out (assuming the PR has been merged). I just don't want this issue to block a potential FB sync. |
|
(ce694c9) The profiler timer now differentiates between batched commits and in-progress async work. This required a two-part change:
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. Edit: I realized after pushing the previous Map solution that I could fix the problem with a boolean, so I pushed an update (004538c). |
| @@ -1784,7 +1799,7 @@ function flushRoot(root: FiberRoot, expirationTime: ExpirationTime) { | |||
| performWorkOnRoot(root, expirationTime, false); | |||
| // Flush any sync work that was scheduled by lifecycles | |||
| performSyncWork(); | |||
| finishRendering(); | |||
There was a problem hiding this comment.
This change wasn't strictly necessary, but I noticed while tracing through that this finishRendering call was redundant, since performWork (called by performSyncWork) also calls finishRendering.
| @@ -55,6 +56,7 @@ if (__DEV__) { | |||
| fiberStack = []; | |||
| } | |||
|
|
|||
| let rootStartTimes: Map<FiberRoot | null, number> = new Map(); | |||
There was a problem hiding this comment.
I think I can replace this Map with a batchStartTime number field. The only case we really need to handle is processing a batch commit while async work is yielded. Other root changes will unwind the yielded work, which w already handled.
This was just a hacky first attempt to make tests pass. 😄
… 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.
bvaughn
force-pushed
the
reset-profiler-timer-fiber-stack-after-error
branch
from
004538c
to
def0b6c
Compare
|
|
||
| function span(prop) { | ||
| return {type: 'span', children: [], prop}; | ||
| } |
There was a problem hiding this comment.
This was dead code so I just removed it ^
| @@ -1892,7 +1906,7 @@ function flushRoot(root: FiberRoot, expirationTime: ExpirationTime) { | |||
| performWorkOnRoot(root, expirationTime, true); | |||
| // Flush any sync work that was scheduled by lifecycles | |||
| performSyncWork(); | |||
| finishRendering(); | |||
There was a problem hiding this comment.
This was unnecessary, since performWork (called by performSyncWork) calls finishRendering at the end.
| failInBeginPhase = true; | ||
| try { | ||
| fn(); | ||
| } finally { | ||
| failInBeginPhase = false; | ||
| } | ||
| }, | ||
|
|
||
| simulateErrorInHostConfigDuringCompletePhase(fn: () => void) { |
There was a problem hiding this comment.
This new method was necessary to write a test that mimicked RN's Text/View nesting validation.
| // Certain renderers may error during this phase (i.e. ReactNative View/Text nesting validation). | ||
| // If an error occurs, we'll mark the time while unwinding. | ||
| // This simplifies the unwinding logic and ensures consistency. | ||
| recordElapsedActualRenderTime(workInProgress); |
There was a problem hiding this comment.
Moving this to the end of completeWork was necessary to avoid double-popping in the event of an error (like RN's Text/View validation).
| @@ -1817,7 +1831,7 @@ function performWork(minExpirationTime: ExpirationTime, dl: Deadline | null) { | |||
| findHighestPriorityRoot(); | |||
|
|
|||
| if (enableProfilerTimer) { | |||
| resumeActualRenderTimerIfPaused(); | |||
| resumeActualRenderTimerIfPaused(minExpirationTime === Sync); | |||
There was a problem hiding this comment.
Letting the profiler timer know when it's processing sync work enables it to deduct that time from pending async work (by adding it onto the total pause time later). This ensures we don't count time spent processing a batch commit against yielded async work.
|
|
||
| // Reset the DEV fiber stack in case we're profiling roots. | ||
| // (We do this for profiling bulds when DevTools is detected.) | ||
| resetActualRenderTimerStackAfterFatalErrorInDev(); |
There was a problem hiding this comment.
This clears out the host root from the profiler timer's DEV-only fiberStack in the event of an error (which prevents us from incorrectly warning on the next render).
| } | ||
|
|
||
| function resumeActualRenderTimerIfPaused(): void { |
There was a problem hiding this comment.
This method didn't really feel necessary, so I removed it.
|
I don't think the fix for number 3 is correct (or maybe I don't fully understand it) but I'm going to merge it anyway to unblock this week's sync. Let's discuss once you get back from vacation. |
|
Sure thing! Much appreciated. Happy to explain my train of thought for this one on Monday. I think it makes sense, but maybe you know of a use case I haven't considered. (Or maybe I just need to add better inline documentation...) |
I see what you did there 😛
|
I discovered a couple of problems with the profiler timer "unwinding" behavior while testing the DevTools profiler.
It's probably worth noting that the first issue below was the result of #13058, but the other two are present when using the
unstable_Profilercomponent (even without the root-profiling changes from #13058).1: An error while profiling the host root
When the DevTools hook is present, host roots are automatically opted into profiling mode in order to support the DevTools profiler UI.
However, in the event of an error, the in-progress root is just nulled out without its render timer being stopped. In DEV mode, this will cause the subsequent render to warn about a non-empty stack.
I think the most straight forward solution here is to just add an explicit, DEV-only reset method (similar to what we do in
ReactFiberStack). See commit a94b1b7.2: Failures during "complete" phase
React Native does special
View/Textnesting validation during the "complete" phase. If this fails, our unwinding logic previously recorded the elapsed duration twice– once at the start of the "complete" phase (before the error) and once while unwinding (after the error).I've updated the noop renderer to support triggering this behavior intentionally, and I've added a new test for it as well. Initially, I tried tracking completion in the scheduler but this felt hacky. I think the best solution here is to move the actual time recording to the end of
completeWorkso that it won't be called twice in the event of an error. See commit 0b40c11.3: Interleaved batched and yielded async work
There is one additional case in which the profiler stack isn't being emptied correctly:
At this point, the profiler's DEV fiber stack contains the in-progress fibers (from the yielded async render), so we shouldn't assert that the stack is empty. The in-progress time measurements for the yielded fibers are also incorrect because they include the time spent finishing up the batched commit.
I believe the appropriate way to fix the first issue is to only check for an empty stack when we don't have any remaining, yielded async fibers. I think the best way to fix the second issue is to explicitly not count time spent processing batch work (or any sync work) against yielded async fibers. See commit 08febda.
Other changes
I also added a couple of new APIs to the noop renderer to support new tests:
Text/Viewnesting logic) - ca91139flushWithoutCommittingAPI to mimic React DOM's batched commits - 2aa075d