Skip to content

Commit e77b14f

Browse files
sebmarkbagesebmarkbage
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 a657a3a commit e77b14f

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
@@ -493,6 +493,7 @@ export function logBlockingStart(
493493
isSpawnedUpdate: boolean,
494494
renderStartTime: number,
495495
lanes: Lanes,
496+
debugTask: null | ConsoleTask, // DEV-only
496497
): void {
497498
if (supportsUserTiming) {
498499
currentTrack = 'Blocking';
@@ -502,14 +503,29 @@ export function logBlockingStart(
502503
if (eventTime > 0 && eventType !== null) {
503504
// Log the time from the event timeStamp until we called setState.
504505
const color = eventIsRepeat ? 'secondary-light' : 'warning';
505-
console.timeStamp(
506-
eventIsRepeat ? '' : 'Event: ' + eventType,
507-
eventTime,
508-
updateTime > 0 ? updateTime : renderStartTime,
509-
currentTrack,
510-
LANES_TRACK_GROUP,
511-
color,
512-
);
506+
if (__DEV__ && debugTask) {
507+
debugTask.run(
508+
// $FlowFixMe[method-unbinding]
509+
console.timeStamp.bind(
510+
console,
511+
eventIsRepeat ? '' : 'Event: ' + eventType,
512+
eventTime,
513+
updateTime > 0 ? updateTime : renderStartTime,
514+
currentTrack,
515+
LANES_TRACK_GROUP,
516+
color,
517+
),
518+
);
519+
} else {
520+
console.timeStamp(
521+
eventIsRepeat ? '' : 'Event: ' + eventType,
522+
eventTime,
523+
updateTime > 0 ? updateTime : renderStartTime,
524+
currentTrack,
525+
LANES_TRACK_GROUP,
526+
color,
527+
);
528+
}
513529
}
514530
if (updateTime > 0) {
515531
// Log the time from when we called setState until we started rendering.
@@ -518,18 +534,37 @@ export function logBlockingStart(
518534
: includesOnlyHydrationOrOffscreenLanes(lanes)
519535
? 'tertiary-light'
520536
: 'primary-light';
521-
console.timeStamp(
522-
isSpawnedUpdate
523-
? 'Cascading Update'
524-
: renderStartTime - updateTime > 5
525-
? 'Update Blocked'
526-
: 'Update',
527-
updateTime,
528-
renderStartTime,
529-
currentTrack,
530-
LANES_TRACK_GROUP,
531-
color,
532-
);
537+
if (__DEV__ && debugTask) {
538+
debugTask.run(
539+
// $FlowFixMe[method-unbinding]
540+
console.timeStamp.bind(
541+
console,
542+
isSpawnedUpdate
543+
? 'Cascading Update'
544+
: renderStartTime - updateTime > 5
545+
? 'Update Blocked'
546+
: 'Update',
547+
updateTime,
548+
renderStartTime,
549+
currentTrack,
550+
LANES_TRACK_GROUP,
551+
color,
552+
),
553+
);
554+
} else {
555+
console.timeStamp(
556+
isSpawnedUpdate
557+
? 'Cascading Update'
558+
: renderStartTime - updateTime > 5
559+
? 'Update Blocked'
560+
: 'Update',
561+
updateTime,
562+
renderStartTime,
563+
currentTrack,
564+
LANES_TRACK_GROUP,
565+
color,
566+
);
567+
}
533568
}
534569
}
535570
}
@@ -541,6 +576,7 @@ export function logTransitionStart(
541576
eventType: null | string,
542577
eventIsRepeat: boolean,
543578
renderStartTime: number,
579+
debugTask: null | ConsoleTask, // DEV-only
544580
): void {
545581
if (supportsUserTiming) {
546582
currentTrack = 'Transition';
@@ -553,36 +589,82 @@ export function logTransitionStart(
553589
: updateTime > 0
554590
? updateTime
555591
: renderStartTime;
556-
console.timeStamp(
557-
eventIsRepeat ? '' : 'Event: ' + eventType,
558-
eventTime,
559-
endTime,
560-
currentTrack,
561-
LANES_TRACK_GROUP,
562-
color,
563-
);
592+
if (__DEV__ && debugTask) {
593+
debugTask.run(
594+
// $FlowFixMe[method-unbinding]
595+
console.timeStamp.bind(
596+
console,
597+
eventIsRepeat ? '' : 'Event: ' + eventType,
598+
eventTime,
599+
endTime,
600+
currentTrack,
601+
LANES_TRACK_GROUP,
602+
color,
603+
),
604+
);
605+
} else {
606+
console.timeStamp(
607+
eventIsRepeat ? '' : 'Event: ' + eventType,
608+
eventTime,
609+
endTime,
610+
currentTrack,
611+
LANES_TRACK_GROUP,
612+
color,
613+
);
614+
}
564615
}
565616
if (startTime > 0) {
566617
// Log the time from when we started an async transition until we called setState or started rendering.
567-
console.timeStamp(
568-
'Action',
569-
startTime,
570-
updateTime > 0 ? updateTime : renderStartTime,
571-
currentTrack,
572-
LANES_TRACK_GROUP,
573-
'primary-dark',
574-
);
618+
// TODO: Ideally this would use the debugTask of the startTransition call perhaps.
619+
if (__DEV__ && debugTask) {
620+
debugTask.run(
621+
// $FlowFixMe[method-unbinding]
622+
console.timeStamp.bind(
623+
console,
624+
'Action',
625+
startTime,
626+
updateTime > 0 ? updateTime : renderStartTime,
627+
currentTrack,
628+
LANES_TRACK_GROUP,
629+
'primary-dark',
630+
),
631+
);
632+
} else {
633+
console.timeStamp(
634+
'Action',
635+
startTime,
636+
updateTime > 0 ? updateTime : renderStartTime,
637+
currentTrack,
638+
LANES_TRACK_GROUP,
639+
'primary-dark',
640+
);
641+
}
575642
}
576643
if (updateTime > 0) {
577644
// Log the time from when we called setState until we started rendering.
578-
console.timeStamp(
579-
renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update',
580-
updateTime,
581-
renderStartTime,
582-
currentTrack,
583-
LANES_TRACK_GROUP,
584-
'primary-light',
585-
);
645+
if (__DEV__ && debugTask) {
646+
debugTask.run(
647+
// $FlowFixMe[method-unbinding]
648+
console.timeStamp.bind(
649+
console,
650+
renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update',
651+
updateTime,
652+
renderStartTime,
653+
currentTrack,
654+
LANES_TRACK_GROUP,
655+
'primary-light',
656+
),
657+
);
658+
} else {
659+
console.timeStamp(
660+
renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update',
661+
updateTime,
662+
renderStartTime,
663+
currentTrack,
664+
LANES_TRACK_GROUP,
665+
'primary-light',
666+
);
667+
}
586668
}
587669
}
588670
}

‎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)