[Fiber] Track Event Time, startTransition Time and setState Time (#31008

)

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.

packages/react-art/src/ReactFiberConfigART.js

@@ -363,6 +363,14 @@ export function resolveUpdatePriority(): EventPriority {
   return currentUpdatePriority || DefaultEventPriority;
 }
 
+export function resolveEventType(): null | string {
+  return null;
+}
+
+export function resolveEventTimeStamp(): number {
+  return -1.1;
+}
+
 export function shouldAttemptEagerTransition() {
   return false;
 }

packages/react-dom-bindings/src/client/ReactFiberConfigDOM.js

@@ -606,6 +606,16 @@ export function shouldAttemptEagerTransition(): boolean {
   return false;
 }
 
+export function resolveEventType(): null | string {
+  const event = window.event;
+  return event ? event.type : null;
+}
+
+export function resolveEventTimeStamp(): number {
+  const event = window.event;
+  return event ? event.timeStamp : -1.1;
+}
+
 export const isPrimaryRenderer = true;
 export const warnsIfNotActing = true;
 // This initialization code may run even on server environments

packages/react-native-renderer/src/ReactFiberConfigFabric.js

@@ -372,6 +372,14 @@ export function resolveUpdatePriority(): EventPriority {
   return DefaultEventPriority;
 }
 
+export function resolveEventType(): null | string {
+  return null;
+}
+
+export function resolveEventTimeStamp(): number {
+  return -1.1;
+}
+
 export function shouldAttemptEagerTransition(): boolean {
   return false;
 }

packages/react-native-renderer/src/ReactFiberConfigNative.js

@@ -288,6 +288,14 @@ export function resolveUpdatePriority(): EventPriority {
   return DefaultEventPriority;
 }
 
+export function resolveEventType(): null | string {
+  return null;
+}
+
+export function resolveEventTimeStamp(): number {
+  return -1.1;
+}
+
 export function shouldAttemptEagerTransition(): boolean {
   return false;
 }

packages/react-noop-renderer/src/createReactNoop.js

@@ -533,6 +533,14 @@ function createReactNoop(reconciler: Function, useMutation: boolean) {
       return currentEventPriority;
     },
 
+    resolveEventType(): null | string {
+      return null;
+    },
+
+    resolveEventTimeStamp(): number {
+      return -1.1;
+    },
+
     shouldAttemptEagerTransition(): boolean {
       return false;
     },

packages/react-reconciler/src/ReactFiberAsyncAction.js

@@ -17,6 +17,14 @@ import type {BatchConfigTransition} from './ReactFiberTracingMarkerComponent';
 
 import {requestTransitionLane} from './ReactFiberRootScheduler';
 import {NoLane} from './ReactFiberLane';
+import {
+  hasScheduledTransitionWork,
+  clearAsyncTransitionTimer,
+} from './ReactProfilerTimer';
+import {
+  enableComponentPerformanceTrack,
+  enableProfilerTimer,
+} from 'shared/ReactFeatureFlags';
 
 // If there are multiple, concurrent async actions, they are entangled. All
 // transition updates that occur while the async action is still in progress
@@ -64,24 +72,34 @@ export function entangleAsyncAction<S>(
 }
 
 function pingEngtangledActionScope() {
-  if (
-    currentEntangledListeners !== null &&
-    --currentEntangledPendingCount === 0
-  ) {
-    // All the actions have finished. Close the entangled async action scope
-    // and notify all the listeners.
-    if (currentEntangledActionThenable !== null) {
-      const fulfilledThenable: FulfilledThenable<void> =
-        (currentEntangledActionThenable: any);
-      fulfilledThenable.status = 'fulfilled';
+  if (--currentEntangledPendingCount === 0) {
+    if (enableProfilerTimer && enableComponentPerformanceTrack) {
+      if (!hasScheduledTransitionWork()) {
+        // If we have received no updates since we started the entangled Actions
+        // that means it didn't lead to a Transition being rendered. We need to
+        // clear the timer so that if we start another entangled sequence we use
+        // the next start timer instead of appearing like we were blocked the
+        // whole time. We currently don't log a track for Actions that don't
+        // render a Transition.
+        clearAsyncTransitionTimer();
+      }
     }
-    const listeners = currentEntangledListeners;
-    currentEntangledListeners = null;
-    currentEntangledLane = NoLane;
-    currentEntangledActionThenable = null;
-    for (let i = 0; i < listeners.length; i++) {
-      const listener = listeners[i];
-      listener();
+    if (currentEntangledListeners !== null) {
+      // All the actions have finished. Close the entangled async action scope
+      // and notify all the listeners.
+      if (currentEntangledActionThenable !== null) {
+        const fulfilledThenable: FulfilledThenable<void> =
+          (currentEntangledActionThenable: any);
+        fulfilledThenable.status = 'fulfilled';
+      }
+      const listeners = currentEntangledListeners;
+      currentEntangledListeners = null;
+      currentEntangledLane = NoLane;
+      currentEntangledActionThenable = null;
+      for (let i = 0; i < listeners.length; i++) {
+        const listener = listeners[i];
+        listener();
+      }
     }
   }
 }

packages/react-reconciler/src/ReactFiberClassComponent.js

@@ -72,6 +72,7 @@ import {
   markStateUpdateScheduled,
   setIsStrictModeForDevtools,
 } from './ReactFiberDevToolsHook';
+import {startUpdateTimerByLane} from './ReactProfilerTimer';
 
 const fakeInternalInstance = {};
 
@@ -194,6 +195,7 @@ const classComponentUpdater = {
 
     const root = enqueueUpdate(fiber, update, lane);
     if (root !== null) {
+      startUpdateTimerByLane(lane);
       scheduleUpdateOnFiber(root, fiber, lane);
       entangleTransitions(root, fiber, lane);
     }
@@ -228,6 +230,7 @@ const classComponentUpdater = {
 
     const root = enqueueUpdate(fiber, update, lane);
     if (root !== null) {
+      startUpdateTimerByLane(lane);
       scheduleUpdateOnFiber(root, fiber, lane);
       entangleTransitions(root, fiber, lane);
     }
@@ -262,6 +265,7 @@ const classComponentUpdater = {
 
     const root = enqueueUpdate(fiber, update, lane);
     if (root !== null) {
+      startUpdateTimerByLane(lane);
       scheduleUpdateOnFiber(root, fiber, lane);
       entangleTransitions(root, fiber, lane);
     }

packages/react-reconciler/src/ReactFiberHooks.js

@@ -131,6 +131,7 @@ import {
   markStateUpdateScheduled,
   setIsStrictModeForDevtools,
 } from './ReactFiberDevToolsHook';
+import {startUpdateTimerByLane} from './ReactProfilerTimer';
 import {createCache} from './ReactFiberCacheComponent';
 import {
   createUpdate as createLegacyQueueUpdate,
@@ -3019,7 +3020,12 @@ function startTransition<S>(
     dispatchOptimisticSetState(fiber, false, queue, pendingState);
   } else {
     ReactSharedInternals.T = null;
-    dispatchSetState(fiber, queue, pendingState);
+    dispatchSetStateInternal(
+      fiber,
+      queue,
+      pendingState,
+      requestUpdateLane(fiber),
+    );
     ReactSharedInternals.T = currentTransition;
   }
 
@@ -3062,13 +3068,28 @@ function startTransition<S>(
           thenable,
           finishedState,
         );
-        dispatchSetState(fiber, queue, (thenableForFinishedState: any));
+        dispatchSetStateInternal(
+          fiber,
+          queue,
+          (thenableForFinishedState: any),
+          requestUpdateLane(fiber),
+        );
       } else {
-        dispatchSetState(fiber, queue, finishedState);
+        dispatchSetStateInternal(
+          fiber,
+          queue,
+          finishedState,
+          requestUpdateLane(fiber),
+        );
       }
     } else {
       // Async actions are not enabled.
-      dispatchSetState(fiber, queue, finishedState);
+      dispatchSetStateInternal(
+        fiber,
+        queue,
+        finishedState,
+        requestUpdateLane(fiber),
+      );
       callback();
     }
   } catch (error) {
@@ -3081,7 +3102,12 @@ function startTransition<S>(
         status: 'rejected',
         reason: error,
       };
-      dispatchSetState(fiber, queue, rejectedThenable);
+      dispatchSetStateInternal(
+        fiber,
+        queue,
+        rejectedThenable,
+        requestUpdateLane(fiber),
+      );
     } else {
       // The error rethrowing behavior is only enabled when the async actions
       // feature is on, even for sync actions.
@@ -3253,7 +3279,12 @@ export function requestFormReset(formFiber: Fiber) {
   const newResetState = {};
   const resetStateHook: Hook = (stateHook.next: any);
   const resetStateQueue = resetStateHook.queue;
-  dispatchSetState(formFiber, resetStateQueue, newResetState);
+  dispatchSetStateInternal(
+    formFiber,
+    resetStateQueue,
+    newResetState,
+    requestUpdateLane(formFiber),
+  );
 }
 
 function mountTransition(): [
@@ -3385,6 +3416,7 @@ function refreshCache<T>(fiber: Fiber, seedKey: ?() => T, seedValue: T): void {
         const refreshUpdate = createLegacyQueueUpdate(lane);
         const root = enqueueLegacyQueueUpdate(provider, refreshUpdate, lane);
         if (root !== null) {
+          startUpdateTimerByLane(lane);
           scheduleUpdateOnFiber(root, provider, lane);
           entangleLegacyQueueTransitions(root, provider, lane);
         }
@@ -3450,6 +3482,7 @@ function dispatchReducerAction<S, A>(
   } else {
     const root = enqueueConcurrentHookUpdate(fiber, queue, update, lane);
     if (root !== null) {
+      startUpdateTimerByLane(lane);
       scheduleUpdateOnFiber(root, fiber, lane);
       entangleTransitionUpdate(root, queue, lane);
     }
@@ -3474,7 +3507,24 @@ function dispatchSetState<S, A>(
   }
 
   const lane = requestUpdateLane(fiber);
+  const didScheduleUpdate = dispatchSetStateInternal(
+    fiber,
+    queue,
+    action,
+    lane,
+  );
+  if (didScheduleUpdate) {
+    startUpdateTimerByLane(lane);
+  }
+  markUpdateInDevTools(fiber, lane, action);
+}
 
+function dispatchSetStateInternal<S, A>(
+  fiber: Fiber,
+  queue: UpdateQueue<S, A>,
+  action: A,
+  lane: Lane,
+): boolean {
   const update: Update<S, A> = {
     lane,
     revertLane: NoLane,
@@ -3518,7 +3568,7 @@ function dispatchSetState<S, A>(
             // time the reducer has changed.
             // TODO: Do we still need to entangle transitions in this case?
             enqueueConcurrentHookUpdateAndEagerlyBailout(fiber, queue, update);
-            return;
+            return false;
           }
         } catch (error) {
           // Suppress the error. It will throw again in the render phase.
@@ -3534,10 +3584,10 @@ function dispatchSetState<S, A>(
     if (root !== null) {
       scheduleUpdateOnFiber(root, fiber, lane);
       entangleTransitionUpdate(root, queue, lane);
+      return true;
     }
   }
-
-  markUpdateInDevTools(fiber, lane, action);
+  return false;
 }
 
 function dispatchOptimisticSetState<S, A>(
@@ -3619,6 +3669,7 @@ function dispatchOptimisticSetState<S, A>(
       // will never be attempted before the optimistic update. This currently
       // holds because the optimistic update is always synchronous. If we ever
       // change that, we'll need to account for this.
+      startUpdateTimerByLane(SyncLane);
       scheduleUpdateOnFiber(root, fiber, SyncLane);
       // Optimistic updates are always synchronous, so we don't need to call
       // entangleTransitionUpdate here.

packages/react-reconciler/src/ReactFiberLane.js

@@ -592,6 +592,10 @@ export function includesSyncLane(lanes: Lanes): boolean {
   return (lanes & (SyncLane | SyncHydrationLane)) !== NoLanes;
 }
 
+export function isSyncLane(lanes: Lanes): boolean {
+  return (lanes & (SyncLane | SyncHydrationLane)) !== NoLanes;
+}
+
 export function includesNonIdleWork(lanes: Lanes): boolean {
   return (lanes & NonIdleLanes) !== NoLanes;
 }
@@ -608,6 +612,10 @@ export function includesOnlyTransitions(lanes: Lanes): boolean {
   return (lanes & TransitionLanes) === lanes;
 }
 
+export function includesTransitionLane(lanes: Lanes): boolean {
+  return (lanes & TransitionLanes) !== NoLanes;
+}
+
 export function includesBlockingLane(lanes: Lanes): boolean {
   const SyncDefaultLanes =
     InputContinuousHydrationLane |
@@ -623,6 +631,15 @@ export function includesExpiredLane(root: FiberRoot, lanes: Lanes): boolean {
   return (lanes & root.expiredLanes) !== NoLanes;
 }
 
+export function isBlockingLane(lane: Lane): boolean {
+  const SyncDefaultLanes =
+    InputContinuousHydrationLane |
+    InputContinuousLane |
+    DefaultHydrationLane |
+    DefaultLane;
+  return (lane & SyncDefaultLanes) !== NoLanes;
+}
+
 export function isTransitionLane(lane: Lane): boolean {
   return (lane & TransitionLanes) !== NoLanes;
 }