Skip to content

Commit 508f7aa

Browse files
authored
[Fiber] Switch back to using performance.measure for trigger logs (facebook#33659)
Stacked on facebook#33658. Unfortunately `console.timeStamp` has the same bug that `performance.measure` used to have where equal start/end times stack in call order instead of reverse call-order. We rely on that in general so we should really switch back all. But there is one case in particular where we always add the same start/time and that's for the "triggers" - Mount/Unmount/Reconnect/Disconnect. Switching to `console.timeStamp` broke this because they now showed below the thing that mounted. After: <img width="726" alt="Screenshot 2025-06-27 at 3 31 16 PM" src="https://github.com/user-attachments/assets/422341c8-bef6-4909-9403-933d76b71508" /> Also fixed a bug where clamped update times could end up logging zero width entries that stacked up on top of each other causing a two row scheduler lane which should always be one row.
1 parent e104795 commit 508f7aa

File tree

1 file changed

+24
-32
lines changed

1 file changed

+24
-32
lines changed

packages/react-reconciler/src/ReactFiberPerformanceTrack.js

Lines changed: 24 additions & 32 deletions
Original file line numberDiff line numberDiff line change
@@ -101,28 +101,22 @@ function logComponentTrigger(
101101
trigger: string,
102102
) {
103103
if (supportsUserTiming) {
104+
reusableComponentOptions.start = startTime;
105+
reusableComponentOptions.end = endTime;
106+
reusableComponentDevToolDetails.color = 'warning';
107+
reusableComponentDevToolDetails.properties = null;
104108
const debugTask = fiber._debugTask;
105109
if (__DEV__ && debugTask) {
106110
debugTask.run(
107-
console.timeStamp.bind(
108-
console,
111+
// $FlowFixMe[method-unbinding]
112+
performance.measure.bind(
113+
performance,
109114
trigger,
110-
startTime,
111-
endTime,
112-
COMPONENTS_TRACK,
113-
undefined,
114-
'warning',
115+
reusableComponentOptions,
115116
),
116117
);
117118
} else {
118-
console.timeStamp(
119-
trigger,
120-
startTime,
121-
endTime,
122-
COMPONENTS_TRACK,
123-
undefined,
124-
'warning',
125-
);
119+
performance.measure(trigger, reusableComponentOptions);
126120
}
127121
}
128122
}
@@ -578,7 +572,8 @@ export function logBlockingStart(
578572
// If a blocking update was spawned within render or an effect, that's considered a cascading render.
579573
// If you have a second blocking update within the same event, that suggests multiple flushSync or
580574
// setState in a microtask which is also considered a cascade.
581-
if (eventTime > 0 && eventType !== null) {
575+
const eventEndTime = updateTime > 0 ? updateTime : renderStartTime;
576+
if (eventTime > 0 && eventType !== null && eventEndTime > eventTime) {
582577
// Log the time from the event timeStamp until we called setState.
583578
const color = eventIsRepeat ? 'secondary-light' : 'warning';
584579
if (__DEV__ && debugTask) {
@@ -588,7 +583,7 @@ export function logBlockingStart(
588583
console,
589584
eventIsRepeat ? '' : 'Event: ' + eventType,
590585
eventTime,
591-
updateTime > 0 ? updateTime : renderStartTime,
586+
eventEndTime,
592587
currentTrack,
593588
LANES_TRACK_GROUP,
594589
color,
@@ -598,14 +593,14 @@ export function logBlockingStart(
598593
console.timeStamp(
599594
eventIsRepeat ? '' : 'Event: ' + eventType,
600595
eventTime,
601-
updateTime > 0 ? updateTime : renderStartTime,
596+
eventEndTime,
602597
currentTrack,
603598
LANES_TRACK_GROUP,
604599
color,
605600
);
606601
}
607602
}
608-
if (updateTime > 0) {
603+
if (updateTime > 0 && renderStartTime > updateTime) {
609604
// Log the time from when we called setState until we started rendering.
610605
const color = isSpawnedUpdate
611606
? 'error'
@@ -658,23 +653,19 @@ export function logTransitionStart(
658653
): void {
659654
if (supportsUserTiming) {
660655
currentTrack = 'Transition';
661-
if (eventTime > 0 && eventType !== null) {
656+
const eventEndTime =
657+
startTime > 0 ? startTime : updateTime > 0 ? updateTime : renderStartTime;
658+
if (eventTime > 0 && eventEndTime > eventTime && eventType !== null) {
662659
// Log the time from the event timeStamp until we started a transition.
663660
const color = eventIsRepeat ? 'secondary-light' : 'warning';
664-
const endTime =
665-
startTime > 0
666-
? startTime
667-
: updateTime > 0
668-
? updateTime
669-
: renderStartTime;
670661
if (__DEV__ && debugTask) {
671662
debugTask.run(
672663
// $FlowFixMe[method-unbinding]
673664
console.timeStamp.bind(
674665
console,
675666
eventIsRepeat ? '' : 'Event: ' + eventType,
676667
eventTime,
677-
endTime,
668+
eventEndTime,
678669
currentTrack,
679670
LANES_TRACK_GROUP,
680671
color,
@@ -684,14 +675,15 @@ export function logTransitionStart(
684675
console.timeStamp(
685676
eventIsRepeat ? '' : 'Event: ' + eventType,
686677
eventTime,
687-
endTime,
678+
eventEndTime,
688679
currentTrack,
689680
LANES_TRACK_GROUP,
690681
color,
691682
);
692683
}
693684
}
694-
if (startTime > 0) {
685+
const startEndTime = updateTime > 0 ? updateTime : renderStartTime;
686+
if (startTime > 0 && startEndTime > startTime) {
695687
// Log the time from when we started an async transition until we called setState or started rendering.
696688
// TODO: Ideally this would use the debugTask of the startTransition call perhaps.
697689
if (__DEV__ && debugTask) {
@@ -701,7 +693,7 @@ export function logTransitionStart(
701693
console,
702694
'Action',
703695
startTime,
704-
updateTime > 0 ? updateTime : renderStartTime,
696+
startEndTime,
705697
currentTrack,
706698
LANES_TRACK_GROUP,
707699
'primary-dark',
@@ -711,14 +703,14 @@ export function logTransitionStart(
711703
console.timeStamp(
712704
'Action',
713705
startTime,
714-
updateTime > 0 ? updateTime : renderStartTime,
706+
startEndTime,
715707
currentTrack,
716708
LANES_TRACK_GROUP,
717709
'primary-dark',
718710
);
719711
}
720712
}
721-
if (updateTime > 0) {
713+
if (updateTime > 0 && renderStartTime > updateTime) {
722714
// Log the time from when we called setState until we started rendering.
723715
if (__DEV__ && debugTask) {
724716
debugTask.run(

0 commit comments

Comments
 (0)