From 982e62543e241e0610eeaf0ef9e010b93743843c Mon Sep 17 00:00:00 2001 From: Luna Ruan Date: Tue, 13 Sep 2022 13:55:56 -0400 Subject: [PATCH] [Transition Tracing] More Accurate End Time (#25105) add more accurate end time for transitions and update host configs with `requestPostPaintCallback` function and move post paint logic to another module and use it in the work loop --- packages/react-art/src/ReactARTHostConfig.js | 4 + .../src/client/ReactDOMHostConfig.js | 11 +- .../src/ReactFabricHostConfig.js | 4 + .../src/ReactNativeHostConfig.js | 4 + .../src/createReactNoop.js | 5 + .../src/ReactFiberWorkLoop.new.js | 55 +++-- .../src/ReactFiberWorkLoop.old.js | 55 +++-- .../src/ReactPostPaintCallback.js | 26 ++ .../ReactFiberHostContext-test.internal.js | 2 + .../__tests__/ReactTransitionTracing-test.js | 227 ++++++++++++++++++ .../src/forks/ReactFiberHostConfig.custom.js | 1 + .../src/ReactTestHostConfig.js | 4 + 12 files changed, 367 insertions(+), 31 deletions(-) create mode 100644 packages/react-reconciler/src/ReactPostPaintCallback.js diff --git a/packages/react-art/src/ReactARTHostConfig.js b/packages/react-art/src/ReactARTHostConfig.js index 47bced8a1274a..dbaba801b185a 100644 --- a/packages/react-art/src/ReactARTHostConfig.js +++ b/packages/react-art/src/ReactARTHostConfig.js @@ -451,3 +451,7 @@ export function preparePortalMount(portalInstance: any): void { export function detachDeletedInstance(node: Instance): void { // noop } + +export function requestPostPaintCallback(callback: (time: number) => void) { + // noop +} diff --git a/packages/react-dom/src/client/ReactDOMHostConfig.js b/packages/react-dom/src/client/ReactDOMHostConfig.js index 4510efe2b892c..c9c6e11fdfe00 100644 --- a/packages/react-dom/src/client/ReactDOMHostConfig.js +++ b/packages/react-dom/src/client/ReactDOMHostConfig.js @@ -377,7 +377,10 @@ export const cancelTimeout: any = typeof clearTimeout === 'function' ? clearTimeout : (undefined: any); export const noTimeout = -1; const localPromise = typeof Promise === 'function' ? Promise : undefined; - +const localRequestAnimationFrame = + typeof requestAnimationFrame === 'function' + ? requestAnimationFrame + : scheduleTimeout; // ------------------- // Microtasks // ------------------- @@ -1379,3 +1382,9 @@ export function setupIntersectionObserver( }, }; } + +export function requestPostPaintCallback(callback: (time: number) => void) { + localRequestAnimationFrame(() => { + localRequestAnimationFrame(time => callback(time)); + }); +} diff --git a/packages/react-native-renderer/src/ReactFabricHostConfig.js b/packages/react-native-renderer/src/ReactFabricHostConfig.js index 3ae1d00e27177..3c66e0ad8cd0b 100644 --- a/packages/react-native-renderer/src/ReactFabricHostConfig.js +++ b/packages/react-native-renderer/src/ReactFabricHostConfig.js @@ -611,3 +611,7 @@ export function preparePortalMount(portalInstance: Instance): void { export function detachDeletedInstance(node: Instance): void { // noop } + +export function requestPostPaintCallback(callback: (time: number) => void) { + // noop +} diff --git a/packages/react-native-renderer/src/ReactNativeHostConfig.js b/packages/react-native-renderer/src/ReactNativeHostConfig.js index 37e88d8b2747b..c26c5c389c1e9 100644 --- a/packages/react-native-renderer/src/ReactNativeHostConfig.js +++ b/packages/react-native-renderer/src/ReactNativeHostConfig.js @@ -510,3 +510,7 @@ export function preparePortalMount(portalInstance: Instance): void { export function detachDeletedInstance(node: Instance): void { // noop } + +export function requestPostPaintCallback(callback: (time: number) => void) { + // noop +} diff --git a/packages/react-noop-renderer/src/createReactNoop.js b/packages/react-noop-renderer/src/createReactNoop.js index f2b6fc8b255e9..66919fc89239d 100644 --- a/packages/react-noop-renderer/src/createReactNoop.js +++ b/packages/react-noop-renderer/src/createReactNoop.js @@ -473,6 +473,11 @@ function createReactNoop(reconciler: Function, useMutation: boolean) { logRecoverableError() { // no-op }, + + requestPostPaintCallback(callback) { + const endTime = Scheduler.unstable_now(); + callback(endTime); + }, }; const hostConfig = useMutation diff --git a/packages/react-reconciler/src/ReactFiberWorkLoop.new.js b/packages/react-reconciler/src/ReactFiberWorkLoop.new.js index 6f62aa4b1c0b1..ca6bbcae278ab 100644 --- a/packages/react-reconciler/src/ReactFiberWorkLoop.new.js +++ b/packages/react-reconciler/src/ReactFiberWorkLoop.new.js @@ -261,6 +261,7 @@ import { suspendedThenableDidResolve, isTrackingSuspendedThenable, } from './ReactFiberWakeable.new'; +import {schedulePostPaintCallback} from './ReactPostPaintCallback'; const ceil = Math.ceil; @@ -361,6 +362,7 @@ export function getWorkInProgressTransitions() { } let currentPendingTransitionCallbacks: PendingTransitionCallbacks | null = null; +let currentEndTime: number | null = null; export function addTransitionStartCallbackToPendingTransition( transition: Transition, @@ -2643,6 +2645,36 @@ function commitRootImpl( markCommitStopped(); } + if (enableTransitionTracing) { + // We process transitions during passive effects. However, passive effects can be + // processed synchronously during the commit phase as well as asynchronously after + // paint. At the end of the commit phase, we schedule a callback that will be called + // after the next paint. If the transitions have already been processed (passive + // effect phase happened synchronously), we will schedule a callback to process + // the transitions. However, if we don't have any pending transition callbacks, this + // means that the transitions have yet to be processed (passive effects processed after paint) + // so we will store the end time of paint so that we can process the transitions + // and then call the callback via the correct end time. + const prevRootTransitionCallbacks = root.transitionCallbacks; + if (prevRootTransitionCallbacks !== null) { + schedulePostPaintCallback(endTime => { + const prevPendingTransitionCallbacks = currentPendingTransitionCallbacks; + if (prevPendingTransitionCallbacks !== null) { + currentPendingTransitionCallbacks = null; + scheduleCallback(IdleSchedulerPriority, () => { + processTransitionCallbacks( + prevPendingTransitionCallbacks, + endTime, + prevRootTransitionCallbacks, + ); + }); + } else { + currentEndTime = endTime; + } + }); + } + } + return null; } @@ -2784,28 +2816,21 @@ function flushPassiveEffectsImpl() { if (enableTransitionTracing) { const prevPendingTransitionCallbacks = currentPendingTransitionCallbacks; const prevRootTransitionCallbacks = root.transitionCallbacks; + const prevEndTime = currentEndTime; if ( prevPendingTransitionCallbacks !== null && - prevRootTransitionCallbacks !== null + prevRootTransitionCallbacks !== null && + prevEndTime !== null ) { - // TODO(luna) Refactor this code into the Host Config - // TODO(luna) The end time here is not necessarily accurate - // because passive effects could be called before paint - // (synchronously) or after paint (normally). We need - // to come up with a way to get the correct end time for both cases. - // One solution is in the host config, if the passive effects - // have not yet been run, make a call to flush the passive effects - // right after paint. - const endTime = now(); currentPendingTransitionCallbacks = null; - - scheduleCallback(IdleSchedulerPriority, () => + currentEndTime = null; + scheduleCallback(IdleSchedulerPriority, () => { processTransitionCallbacks( prevPendingTransitionCallbacks, - endTime, + prevEndTime, prevRootTransitionCallbacks, - ), - ); + ); + }); } } diff --git a/packages/react-reconciler/src/ReactFiberWorkLoop.old.js b/packages/react-reconciler/src/ReactFiberWorkLoop.old.js index 414e2e3343ed0..4715d3fdf4df9 100644 --- a/packages/react-reconciler/src/ReactFiberWorkLoop.old.js +++ b/packages/react-reconciler/src/ReactFiberWorkLoop.old.js @@ -261,6 +261,7 @@ import { suspendedThenableDidResolve, isTrackingSuspendedThenable, } from './ReactFiberWakeable.old'; +import {schedulePostPaintCallback} from './ReactPostPaintCallback'; const ceil = Math.ceil; @@ -361,6 +362,7 @@ export function getWorkInProgressTransitions() { } let currentPendingTransitionCallbacks: PendingTransitionCallbacks | null = null; +let currentEndTime: number | null = null; export function addTransitionStartCallbackToPendingTransition( transition: Transition, @@ -2643,6 +2645,36 @@ function commitRootImpl( markCommitStopped(); } + if (enableTransitionTracing) { + // We process transitions during passive effects. However, passive effects can be + // processed synchronously during the commit phase as well as asynchronously after + // paint. At the end of the commit phase, we schedule a callback that will be called + // after the next paint. If the transitions have already been processed (passive + // effect phase happened synchronously), we will schedule a callback to process + // the transitions. However, if we don't have any pending transition callbacks, this + // means that the transitions have yet to be processed (passive effects processed after paint) + // so we will store the end time of paint so that we can process the transitions + // and then call the callback via the correct end time. + const prevRootTransitionCallbacks = root.transitionCallbacks; + if (prevRootTransitionCallbacks !== null) { + schedulePostPaintCallback(endTime => { + const prevPendingTransitionCallbacks = currentPendingTransitionCallbacks; + if (prevPendingTransitionCallbacks !== null) { + currentPendingTransitionCallbacks = null; + scheduleCallback(IdleSchedulerPriority, () => { + processTransitionCallbacks( + prevPendingTransitionCallbacks, + endTime, + prevRootTransitionCallbacks, + ); + }); + } else { + currentEndTime = endTime; + } + }); + } + } + return null; } @@ -2784,28 +2816,21 @@ function flushPassiveEffectsImpl() { if (enableTransitionTracing) { const prevPendingTransitionCallbacks = currentPendingTransitionCallbacks; const prevRootTransitionCallbacks = root.transitionCallbacks; + const prevEndTime = currentEndTime; if ( prevPendingTransitionCallbacks !== null && - prevRootTransitionCallbacks !== null + prevRootTransitionCallbacks !== null && + prevEndTime !== null ) { - // TODO(luna) Refactor this code into the Host Config - // TODO(luna) The end time here is not necessarily accurate - // because passive effects could be called before paint - // (synchronously) or after paint (normally). We need - // to come up with a way to get the correct end time for both cases. - // One solution is in the host config, if the passive effects - // have not yet been run, make a call to flush the passive effects - // right after paint. - const endTime = now(); currentPendingTransitionCallbacks = null; - - scheduleCallback(IdleSchedulerPriority, () => + currentEndTime = null; + scheduleCallback(IdleSchedulerPriority, () => { processTransitionCallbacks( prevPendingTransitionCallbacks, - endTime, + prevEndTime, prevRootTransitionCallbacks, - ), - ); + ); + }); } } diff --git a/packages/react-reconciler/src/ReactPostPaintCallback.js b/packages/react-reconciler/src/ReactPostPaintCallback.js new file mode 100644 index 0000000000000..a52623caa089b --- /dev/null +++ b/packages/react-reconciler/src/ReactPostPaintCallback.js @@ -0,0 +1,26 @@ +/** + * Copyright (c) Facebook, Inc. and its affiliates. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + * + * @flow + */ +import {requestPostPaintCallback} from './ReactFiberHostConfig'; + +let postPaintCallbackScheduled = false; +let callbacks = []; + +export function schedulePostPaintCallback(callback: (endTime: number) => void) { + callbacks.push(callback); + if (!postPaintCallbackScheduled) { + postPaintCallbackScheduled = true; + requestPostPaintCallback(endTime => { + for (let i = 0; i < callbacks.length; i++) { + callbacks[i](endTime); + } + postPaintCallbackScheduled = false; + callbacks = []; + }); + } +} diff --git a/packages/react-reconciler/src/__tests__/ReactFiberHostContext-test.internal.js b/packages/react-reconciler/src/__tests__/ReactFiberHostContext-test.internal.js index 82e23de9965da..19ddc6c8262f4 100644 --- a/packages/react-reconciler/src/__tests__/ReactFiberHostContext-test.internal.js +++ b/packages/react-reconciler/src/__tests__/ReactFiberHostContext-test.internal.js @@ -67,6 +67,7 @@ describe('ReactFiberHostContext', () => { return DefaultEventPriority; }, supportsMutation: true, + requestPostPaintCallback: function() {}, }); const container = Renderer.createContainer( @@ -129,6 +130,7 @@ describe('ReactFiberHostContext', () => { getCurrentEventPriority: function() { return DefaultEventPriority; }, + requestPostPaintCallback: function() {}, supportsMutation: true, }); diff --git a/packages/react-reconciler/src/__tests__/ReactTransitionTracing-test.js b/packages/react-reconciler/src/__tests__/ReactTransitionTracing-test.js index a6637b55977c9..45dba5cd3c8a2 100644 --- a/packages/react-reconciler/src/__tests__/ReactTransitionTracing-test.js +++ b/packages/react-reconciler/src/__tests__/ReactTransitionTracing-test.js @@ -2273,4 +2273,231 @@ describe('ReactInteractionTracing', () => { }); expect(Scheduler).toHaveYielded(['Hidden Text']); }); + + // @gate enableTransitionTracing + it('discrete events', async () => { + const transitionCallbacks = { + onTransitionStart: (name, startTime) => { + Scheduler.unstable_yieldValue( + `onTransitionStart(${name}, ${startTime})`, + ); + }, + onTransitionProgress: (name, startTime, endTime, pending) => { + const suspenseNames = pending.map(p => p.name || '').join(', '); + Scheduler.unstable_yieldValue( + `onTransitionProgress(${name}, ${startTime}, ${endTime}, [${suspenseNames}])`, + ); + }, + onTransitionComplete: (name, startTime, endTime) => { + Scheduler.unstable_yieldValue( + `onTransitionComplete(${name}, ${startTime}, ${endTime})`, + ); + }, + }; + + function App() { + return ( + } + unstable_name="suspense page"> + + + ); + } + + const root = ReactNoop.createRoot({ + unstable_transitionCallbacks: transitionCallbacks, + }); + + await act(async () => { + ReactNoop.discreteUpdates(() => + startTransition(() => root.render(), {name: 'page transition'}), + ); + ReactNoop.expire(1000); + await advanceTimers(1000); + }); + + expect(Scheduler).toHaveYielded([ + 'Suspend [Page Two]', + 'Loading...', + 'onTransitionStart(page transition, 0)', + 'onTransitionProgress(page transition, 0, 1000, [suspense page])', + ]); + await act(async () => { + ReactNoop.discreteUpdates(() => resolveText('Page Two')); + ReactNoop.expire(1000); + await advanceTimers(1000); + }); + + expect(Scheduler).toHaveYielded([ + 'Page Two', + 'onTransitionProgress(page transition, 0, 2000, [])', + 'onTransitionComplete(page transition, 0, 2000)', + ]); + }); + + // @gate enableTransitionTracing + it('multiple commits happen before a paint', async () => { + const transitionCallbacks = { + onTransitionStart: (name, startTime) => { + Scheduler.unstable_yieldValue( + `onTransitionStart(${name}, ${startTime})`, + ); + }, + onTransitionProgress: (name, startTime, endTime, pending) => { + const suspenseNames = pending.map(p => p.name || '').join(', '); + Scheduler.unstable_yieldValue( + `onTransitionProgress(${name}, ${startTime}, ${endTime}, [${suspenseNames}])`, + ); + }, + onTransitionComplete: (name, startTime, endTime) => { + Scheduler.unstable_yieldValue( + `onTransitionComplete(${name}, ${startTime}, ${endTime})`, + ); + }, + }; + + function App() { + const [, setRerender] = useState(false); + React.useLayoutEffect(() => { + resolveText('Text'); + setRerender(true); + }); + return ( + <> + }> + + + }> + + + + ); + } + + const root = ReactNoop.createRoot({ + unstable_transitionCallbacks: transitionCallbacks, + }); + + await act(() => { + startTransition(() => root.render(), {name: 'transition'}); + ReactNoop.expire(1000); + advanceTimers(1000); + }); + + expect(Scheduler).toHaveYielded([ + 'Suspend [Text]', + 'Loading...', + 'Suspend [Text Two]', + 'Loading Two...', + 'Text', + 'Suspend [Text Two]', + 'Loading Two...', + 'onTransitionStart(transition, 0)', + 'onTransitionProgress(transition, 0, 1000, [two])', + ]); + + await act(() => { + resolveText('Text Two'); + ReactNoop.expire(1000); + advanceTimers(1000); + }); + expect(Scheduler).toHaveYielded([ + 'Text Two', + 'onTransitionProgress(transition, 0, 2000, [])', + 'onTransitionComplete(transition, 0, 2000)', + ]); + }); + + // @gate enableTransitionTracing + it('transition callbacks work for multiple roots', async () => { + const getTransitionCallbacks = transitionName => { + return { + onTransitionStart: (name, startTime) => { + Scheduler.unstable_yieldValue( + `onTransitionStart(${name}, ${startTime}) /${transitionName}/`, + ); + }, + onTransitionProgress: (name, startTime, endTime, pending) => { + const suspenseNames = pending.map(p => p.name || '').join(', '); + Scheduler.unstable_yieldValue( + `onTransitionProgress(${name}, ${startTime}, ${endTime}, [${suspenseNames}]) /${transitionName}/`, + ); + }, + onTransitionComplete: (name, startTime, endTime) => { + Scheduler.unstable_yieldValue( + `onTransitionComplete(${name}, ${startTime}, ${endTime}) /${transitionName}/`, + ); + }, + }; + }; + + function App({name}) { + return ( + <> + }> + + + + ); + } + + const rootOne = ReactNoop.createRoot({ + unstable_transitionCallbacks: getTransitionCallbacks('root one'), + }); + + const rootTwo = ReactNoop.createRoot({ + unstable_transitionCallbacks: getTransitionCallbacks('root two'), + }); + + await act(() => { + startTransition(() => rootOne.render(), { + name: 'transition one', + }); + startTransition(() => rootTwo.render(), { + name: 'transition two', + }); + ReactNoop.expire(1000); + advanceTimers(1000); + }); + + expect(Scheduler).toHaveYielded([ + 'Suspend [Text one]', + 'Loading one...', + 'Suspend [Text two]', + 'Loading two...', + 'onTransitionStart(transition one, 0) /root one/', + 'onTransitionProgress(transition one, 0, 1000, [one]) /root one/', + 'onTransitionStart(transition two, 0) /root two/', + 'onTransitionProgress(transition two, 0, 1000, [two]) /root two/', + ]); + + await act(() => { + caches[0].resolve('Text one'); + ReactNoop.expire(1000); + advanceTimers(1000); + }); + + expect(Scheduler).toHaveYielded([ + 'Text one', + 'onTransitionProgress(transition one, 0, 2000, []) /root one/', + 'onTransitionComplete(transition one, 0, 2000) /root one/', + ]); + + await act(() => { + resolveText('Text two'); + ReactNoop.expire(1000); + advanceTimers(1000); + }); + + expect(Scheduler).toHaveYielded([ + 'Text two', + 'onTransitionProgress(transition two, 0, 3000, []) /root two/', + 'onTransitionComplete(transition two, 0, 3000) /root two/', + ]); + }); }); diff --git a/packages/react-reconciler/src/forks/ReactFiberHostConfig.custom.js b/packages/react-reconciler/src/forks/ReactFiberHostConfig.custom.js index 9bb5d6e271c49..517b45ead8fc1 100644 --- a/packages/react-reconciler/src/forks/ReactFiberHostConfig.custom.js +++ b/packages/react-reconciler/src/forks/ReactFiberHostConfig.custom.js @@ -67,6 +67,7 @@ export const prepareScopeUpdate = $$$hostConfig.prepareScopeUpdate; export const getInstanceFromScope = $$$hostConfig.getInstanceFromScope; export const getCurrentEventPriority = $$$hostConfig.getCurrentEventPriority; export const detachDeletedInstance = $$$hostConfig.detachDeletedInstance; +export const requestPostPaintCallback = $$$hostConfig.requestPostPaintCallback; // ------------------- // Microtasks diff --git a/packages/react-test-renderer/src/ReactTestHostConfig.js b/packages/react-test-renderer/src/ReactTestHostConfig.js index b452893ab2a9e..dfccf3e9ef0fc 100644 --- a/packages/react-test-renderer/src/ReactTestHostConfig.js +++ b/packages/react-test-renderer/src/ReactTestHostConfig.js @@ -317,3 +317,7 @@ export function detachDeletedInstance(node: Instance): void { export function logRecoverableError(error: mixed): void { // noop } + +export function requestPostPaintCallback(callback: (time: number) => void) { + // noop +}