Profiler actualDuration bugfix #13313
Conversation
|
ReactDOM: size: 0.0%, gzip: -0.0% Details of bundled changes.Comparing: b179bae...ccc4f31 react-dom
react-art
react-test-renderer
react-reconciler
react-native-renderer
Generated by 🚫 dangerJS |
| if (profilerStartTime >= 0) { | ||
| const elapsedTime = now() - profilerStartTime; | ||
| fiber.actualDuration += elapsedTime; | ||
| if (overrideBaseTime) { |
There was a problem hiding this comment.
Base time is a little awkward to handle. Before, we were only including "begin" phase work in the base time value– and this PR continues that behavior, because I wasn't sure how to preserve the behavior we wanted otherwise (without adding an additional field).
The behavior is, essentially:
- When cloning a fiber, copy the base time from the previous render.
- If the fiber bails out, leave that value in place.
- If the fiber renders, override the base time value.
- When the fiber completes, bubble up base times from its children.
Since we are using a single timer to track both the "actual duration" and "base duration" values, and this timer wraps both the "begin" and "render" phases– I opted to only update base time during render (since we know definitively whether we have bailed out or not during that phase).
If this is silly for some reason, or you know of a better way to achieve this, let's chat! I don't think it's a very big deal, since completeWork doesn't really include any time spent in user component code.
| // If replayFailedUnitOfWorkWithInvokeGuardedCallback is enbaled, ThrowsError is replayed. | ||
| expect(mountCall[2]).toBe(flagEnabled && __DEV__ ? 27 : 17); | ||
| // We don't count the time spent in replaying the failed unit of work (ThrowsError) | ||
| expect(mountCall[2]).toBe(17); |
There was a problem hiding this comment.
This PR changes the timing so that we override the actual time spent during the failure with the time spent while retrying it (only for that particular fiber)– but I think that's fine. This particular detail was kind of arbitrary anyway.
| <AdvanceTime byAmount={10}> | ||
| <AdvanceTime byAmount={10} shouldComponentUpdate={false} /> | ||
| <AdvanceTime byAmount={4}> | ||
| <AdvanceTime byAmount={7} shouldComponentUpdate={false} /> |
There was a problem hiding this comment.
This change was an unnecessary one but made the test a little stronger since 10 & 10 could give a false positive.
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.
bvaughn
force-pushed
the
profiler-timer-bugfix
branch
from
c771d23 to
cc714c4
Compare
| nextRenderExpirationTime, | ||
| ); | ||
| if (enableProfilerTimer) { | ||
| if (workInProgress.mode & ProfileMode) { |
There was a problem hiding this comment.
Nit: Can you combine the enableProfilerTimer check with these inner checks? Or do we not trust the build system to strip out the dead code?
There was a problem hiding this comment.
Nope, this is just something subjective I've done because it seems to read more clearly that the outer conditional is a feature flag. Happy to combine them if you have a preference.
To be fair, there's precedent for this in a lot of other places– but again, I don't feel strongly about it. If you do, I will change it.
bvaughn
force-pushed
the
profiler-timer-bugfix
branch
from
cc714c4 to
6f996da
Compare
bvaughn
changed the title
|
Friendly ping 😄 |
While testing the new DevTools profiler, I noticed that sometimes– in larger, more complicated applications– an incorrect value was being reported for
actualDuration(often too large, occasionally negative).Unfortunately I was unable to capture the problem in a test, but I believe it has something to do with the way I was tracking render times across different priorities and roots. So this PR replaces the old approach with a simpler one that I believe is more robust.
Anecdotally, the timing problems I was able to reproduce before in my test app(s) are no longer happening after this change. I think the code is also easier to read and reason about now.
Resolves #13309