Skip to content

Commit a3e2b11

Browse files
committed
Track a task at the callsite of setState et al
We then run the "Update" entries in that task. That way you can find the callsite of the first setState and therefore the "cause" of a render starting.
1 parent fd7e449 commit a3e2b11

File tree

6 files changed

+153
-53
lines changed

6 files changed

+153
-53
lines changed

packages/react-reconciler/src/ReactFiberClassComponent.js

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -180,7 +180,7 @@ const classComponentUpdater = {
180180

181181
const root = enqueueUpdate(fiber, update, lane);
182182
if (root !== null) {
183-
startUpdateTimerByLane(lane);
183+
startUpdateTimerByLane(lane, 'this.setState()');
184184
scheduleUpdateOnFiber(root, fiber, lane);
185185
entangleTransitions(root, fiber, lane);
186186
}
@@ -206,7 +206,7 @@ const classComponentUpdater = {
206206

207207
const root = enqueueUpdate(fiber, update, lane);
208208
if (root !== null) {
209-
startUpdateTimerByLane(lane);
209+
startUpdateTimerByLane(lane, 'this.replaceState()');
210210
scheduleUpdateOnFiber(root, fiber, lane);
211211
entangleTransitions(root, fiber, lane);
212212
}
@@ -232,7 +232,7 @@ const classComponentUpdater = {
232232

233233
const root = enqueueUpdate(fiber, update, lane);
234234
if (root !== null) {
235-
startUpdateTimerByLane(lane);
235+
startUpdateTimerByLane(lane, 'this.forceUpdate()');
236236
scheduleUpdateOnFiber(root, fiber, lane);
237237
entangleTransitions(root, fiber, lane);
238238
}

packages/react-reconciler/src/ReactFiberHooks.js

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -3495,7 +3495,7 @@ function refreshCache<T>(fiber: Fiber, seedKey: ?() => T, seedValue: T): void {
34953495
const refreshUpdate = createLegacyQueueUpdate(lane);
34963496
const root = enqueueLegacyQueueUpdate(provider, refreshUpdate, lane);
34973497
if (root !== null) {
3498-
startUpdateTimerByLane(lane);
3498+
startUpdateTimerByLane(lane, 'refresh()');
34993499
scheduleUpdateOnFiber(root, provider, lane);
35003500
entangleLegacyQueueTransitions(root, provider, lane);
35013501
}
@@ -3564,7 +3564,7 @@ function dispatchReducerAction<S, A>(
35643564
} else {
35653565
const root = enqueueConcurrentHookUpdate(fiber, queue, update, lane);
35663566
if (root !== null) {
3567-
startUpdateTimerByLane(lane);
3567+
startUpdateTimerByLane(lane, 'dispatch()');
35683568
scheduleUpdateOnFiber(root, fiber, lane);
35693569
entangleTransitionUpdate(root, queue, lane);
35703570
}
@@ -3598,7 +3598,7 @@ function dispatchSetState<S, A>(
35983598
lane,
35993599
);
36003600
if (didScheduleUpdate) {
3601-
startUpdateTimerByLane(lane);
3601+
startUpdateTimerByLane(lane, 'setState()');
36023602
}
36033603
markUpdateInDevTools(fiber, lane, action);
36043604
}
@@ -3760,7 +3760,7 @@ function dispatchOptimisticSetState<S, A>(
37603760
// will never be attempted before the optimistic update. This currently
37613761
// holds because the optimistic update is always synchronous. If we ever
37623762
// change that, we'll need to account for this.
3763-
startUpdateTimerByLane(lane);
3763+
startUpdateTimerByLane(lane, 'setOptimistic()');
37643764
scheduleUpdateOnFiber(root, fiber, lane);
37653765
// Optimistic updates are always synchronous, so we don't need to call
37663766
// entangleTransitionUpdate here.

packages/react-reconciler/src/ReactFiberPerformanceTrack.js

Lines changed: 126 additions & 44 deletions
Original file line numberDiff line numberDiff line change
@@ -512,6 +512,7 @@ export function logBlockingStart(
512512
isSpawnedUpdate: boolean,
513513
renderStartTime: number,
514514
lanes: Lanes,
515+
debugTask: null | ConsoleTask, // DEV-only
515516
): void {
516517
if (supportsUserTiming) {
517518
currentTrack = 'Blocking';
@@ -521,14 +522,29 @@ export function logBlockingStart(
521522
if (eventTime > 0 && eventType !== null) {
522523
// Log the time from the event timeStamp until we called setState.
523524
const color = eventIsRepeat ? 'secondary-light' : 'warning';
524-
console.timeStamp(
525-
eventIsRepeat ? '' : 'Event: ' + eventType,
526-
eventTime,
527-
updateTime > 0 ? updateTime : renderStartTime,
528-
currentTrack,
529-
LANES_TRACK_GROUP,
530-
color,
531-
);
525+
if (__DEV__ && debugTask) {
526+
debugTask.run(
527+
// $FlowFixMe[method-unbinding]
528+
console.timeStamp.bind(
529+
console,
530+
eventIsRepeat ? '' : 'Event: ' + eventType,
531+
eventTime,
532+
updateTime > 0 ? updateTime : renderStartTime,
533+
currentTrack,
534+
LANES_TRACK_GROUP,
535+
color,
536+
),
537+
);
538+
} else {
539+
console.timeStamp(
540+
eventIsRepeat ? '' : 'Event: ' + eventType,
541+
eventTime,
542+
updateTime > 0 ? updateTime : renderStartTime,
543+
currentTrack,
544+
LANES_TRACK_GROUP,
545+
color,
546+
);
547+
}
532548
}
533549
if (updateTime > 0) {
534550
// Log the time from when we called setState until we started rendering.
@@ -537,18 +553,37 @@ export function logBlockingStart(
537553
: includesOnlyHydrationOrOffscreenLanes(lanes)
538554
? 'tertiary-light'
539555
: 'primary-light';
540-
console.timeStamp(
541-
isSpawnedUpdate
542-
? 'Cascading Update'
543-
: renderStartTime - updateTime > 5
544-
? 'Update Blocked'
545-
: 'Update',
546-
updateTime,
547-
renderStartTime,
548-
currentTrack,
549-
LANES_TRACK_GROUP,
550-
color,
551-
);
556+
if (__DEV__ && debugTask) {
557+
debugTask.run(
558+
// $FlowFixMe[method-unbinding]
559+
console.timeStamp.bind(
560+
console,
561+
isSpawnedUpdate
562+
? 'Cascading Update'
563+
: renderStartTime - updateTime > 5
564+
? 'Update Blocked'
565+
: 'Update',
566+
updateTime,
567+
renderStartTime,
568+
currentTrack,
569+
LANES_TRACK_GROUP,
570+
color,
571+
),
572+
);
573+
} else {
574+
console.timeStamp(
575+
isSpawnedUpdate
576+
? 'Cascading Update'
577+
: renderStartTime - updateTime > 5
578+
? 'Update Blocked'
579+
: 'Update',
580+
updateTime,
581+
renderStartTime,
582+
currentTrack,
583+
LANES_TRACK_GROUP,
584+
color,
585+
);
586+
}
552587
}
553588
}
554589
}
@@ -560,6 +595,7 @@ export function logTransitionStart(
560595
eventType: null | string,
561596
eventIsRepeat: boolean,
562597
renderStartTime: number,
598+
debugTask: null | ConsoleTask, // DEV-only
563599
): void {
564600
if (supportsUserTiming) {
565601
currentTrack = 'Transition';
@@ -572,36 +608,82 @@ export function logTransitionStart(
572608
: updateTime > 0
573609
? updateTime
574610
: renderStartTime;
575-
console.timeStamp(
576-
eventIsRepeat ? '' : 'Event: ' + eventType,
577-
eventTime,
578-
endTime,
579-
currentTrack,
580-
LANES_TRACK_GROUP,
581-
color,
582-
);
611+
if (__DEV__ && debugTask) {
612+
debugTask.run(
613+
// $FlowFixMe[method-unbinding]
614+
console.timeStamp.bind(
615+
console,
616+
eventIsRepeat ? '' : 'Event: ' + eventType,
617+
eventTime,
618+
endTime,
619+
currentTrack,
620+
LANES_TRACK_GROUP,
621+
color,
622+
),
623+
);
624+
} else {
625+
console.timeStamp(
626+
eventIsRepeat ? '' : 'Event: ' + eventType,
627+
eventTime,
628+
endTime,
629+
currentTrack,
630+
LANES_TRACK_GROUP,
631+
color,
632+
);
633+
}
583634
}
584635
if (startTime > 0) {
585636
// Log the time from when we started an async transition until we called setState or started rendering.
586-
console.timeStamp(
587-
'Action',
588-
startTime,
589-
updateTime > 0 ? updateTime : renderStartTime,
590-
currentTrack,
591-
LANES_TRACK_GROUP,
592-
'primary-dark',
593-
);
637+
// TODO: Ideally this would use the debugTask of the startTransition call perhaps.
638+
if (__DEV__ && debugTask) {
639+
debugTask.run(
640+
// $FlowFixMe[method-unbinding]
641+
console.timeStamp.bind(
642+
console,
643+
'Action',
644+
startTime,
645+
updateTime > 0 ? updateTime : renderStartTime,
646+
currentTrack,
647+
LANES_TRACK_GROUP,
648+
'primary-dark',
649+
),
650+
);
651+
} else {
652+
console.timeStamp(
653+
'Action',
654+
startTime,
655+
updateTime > 0 ? updateTime : renderStartTime,
656+
currentTrack,
657+
LANES_TRACK_GROUP,
658+
'primary-dark',
659+
);
660+
}
594661
}
595662
if (updateTime > 0) {
596663
// Log the time from when we called setState until we started rendering.
597-
console.timeStamp(
598-
renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update',
599-
updateTime,
600-
renderStartTime,
601-
currentTrack,
602-
LANES_TRACK_GROUP,
603-
'primary-light',
604-
);
664+
if (__DEV__ && debugTask) {
665+
debugTask.run(
666+
// $FlowFixMe[method-unbinding]
667+
console.timeStamp.bind(
668+
console,
669+
renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update',
670+
updateTime,
671+
renderStartTime,
672+
currentTrack,
673+
LANES_TRACK_GROUP,
674+
'primary-light',
675+
),
676+
);
677+
} else {
678+
console.timeStamp(
679+
renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update',
680+
updateTime,
681+
renderStartTime,
682+
currentTrack,
683+
LANES_TRACK_GROUP,
684+
'primary-light',
685+
);
686+
}
605687
}
606688
}
607689
}

packages/react-reconciler/src/ReactFiberReconciler.js

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -441,7 +441,7 @@ function updateContainerImpl(
441441

442442
const root = enqueueUpdate(rootFiber, update, lane);
443443
if (root !== null) {
444-
startUpdateTimerByLane(lane);
444+
startUpdateTimerByLane(lane, 'root.render()');
445445
scheduleUpdateOnFiber(root, rootFiber, lane);
446446
entangleTransitions(root, rootFiber, lane);
447447
}

packages/react-reconciler/src/ReactFiberWorkLoop.js

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -262,6 +262,7 @@ import {
262262
import {
263263
blockingClampTime,
264264
blockingUpdateTime,
265+
blockingUpdateTask,
265266
blockingEventTime,
266267
blockingEventType,
267268
blockingEventIsRepeat,
@@ -270,6 +271,7 @@ import {
270271
transitionClampTime,
271272
transitionStartTime,
272273
transitionUpdateTime,
274+
transitionUpdateTask,
273275
transitionEventTime,
274276
transitionEventType,
275277
transitionEventIsRepeat,
@@ -1912,6 +1914,7 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber {
19121914
blockingSpawnedUpdate,
19131915
renderStartTime,
19141916
lanes,
1917+
blockingUpdateTask,
19151918
);
19161919
clearBlockingTimers();
19171920
}
@@ -1948,6 +1951,7 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber {
19481951
transitionEventType,
19491952
transitionEventIsRepeat,
19501953
renderStartTime,
1954+
transitionUpdateTask,
19511955
);
19521956
clearTransitionTimers();
19531957
}

packages/react-reconciler/src/ReactProfilerTimer.js

Lines changed: 15 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -41,6 +41,13 @@ import * as Scheduler from 'scheduler';
4141

4242
const {unstable_now: now} = Scheduler;
4343

44+
const createTask =
45+
// eslint-disable-next-line react-internal/no-production-logging
46+
__DEV__ && console.createTask
47+
? // eslint-disable-next-line react-internal/no-production-logging
48+
console.createTask
49+
: (name: string) => null;
50+
4451
export let renderStartTime: number = -0;
4552
export let commitStartTime: number = -0;
4653
export let commitEndTime: number = -0;
@@ -54,6 +61,7 @@ export let componentEffectErrors: null | Array<CapturedValue<mixed>> = null;
5461

5562
export let blockingClampTime: number = -0;
5663
export let blockingUpdateTime: number = -1.1; // First sync setState scheduled.
64+
export let blockingUpdateTask: null | ConsoleTask = null; // First sync setState's stack trace.
5765
export let blockingEventTime: number = -1.1; // Event timeStamp of the first setState.
5866
export let blockingEventType: null | string = null; // Event type of the first setState.
5967
export let blockingEventIsRepeat: boolean = false;
@@ -63,6 +71,7 @@ export let blockingSuspendedTime: number = -1.1;
6371
export let transitionClampTime: number = -0;
6472
export let transitionStartTime: number = -1.1; // First startTransition call before setState.
6573
export let transitionUpdateTime: number = -1.1; // First transition setState scheduled.
74+
export let transitionUpdateTask: null | ConsoleTask = null; // First transition setState's stack trace.
6675
export let transitionEventTime: number = -1.1; // Event timeStamp of the first transition.
6776
export let transitionEventType: null | string = null; // Event type of the first transition.
6877
export let transitionEventIsRepeat: boolean = false;
@@ -79,13 +88,14 @@ export function startYieldTimer(reason: SuspendedReason) {
7988
yieldReason = reason;
8089
}
8190

82-
export function startUpdateTimerByLane(lane: Lane): void {
91+
export function startUpdateTimerByLane(lane: Lane, method: string): void {
8392
if (!enableProfilerTimer || !enableComponentPerformanceTrack) {
8493
return;
8594
}
8695
if (isSyncLane(lane) || isBlockingLane(lane)) {
8796
if (blockingUpdateTime < 0) {
8897
blockingUpdateTime = now();
98+
blockingUpdateTask = createTask(method);
8999
if (isAlreadyRendering()) {
90100
blockingSpawnedUpdate = true;
91101
}
@@ -108,6 +118,7 @@ export function startUpdateTimerByLane(lane: Lane): void {
108118
} else if (isTransitionLane(lane)) {
109119
if (transitionUpdateTime < 0) {
110120
transitionUpdateTime = now();
121+
transitionUpdateTask = createTask(method);
111122
if (transitionStartTime < 0) {
112123
const newEventTime = resolveEventTimeStamp();
113124
const newEventType = resolveEventType();
@@ -155,6 +166,7 @@ export function trackSuspendedTime(lanes: Lanes, renderEndTime: number) {
155166

156167
export function clearBlockingTimers(): void {
157168
blockingUpdateTime = -1.1;
169+
blockingUpdateTask = null;
158170
blockingSuspendedTime = -1.1;
159171
blockingEventIsRepeat = true;
160172
blockingSpawnedUpdate = false;
@@ -194,6 +206,7 @@ export function startActionStateUpdate(): void {
194206
}
195207
if (transitionUpdateTime < 0) {
196208
transitionUpdateTime = ACTION_STATE_MARKER;
209+
transitionUpdateTask = null;
197210
}
198211
}
199212

@@ -204,6 +217,7 @@ export function clearAsyncTransitionTimer(): void {
204217
export function clearTransitionTimers(): void {
205218
transitionStartTime = -1.1;
206219
transitionUpdateTime = -1.1;
220+
transitionUpdateTask = null;
207221
transitionSuspendedTime = -1.1;
208222
transitionEventIsRepeat = true;
209223
}

0 commit comments

Comments
 (0)