Skip to content

Commit 1085e97

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 d1bb9bd commit 1085e97

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
@@ -3493,7 +3493,7 @@ function refreshCache<T>(fiber: Fiber, seedKey: ?() => T, seedValue: T): void {
34933493
const refreshUpdate = createLegacyQueueUpdate(lane);
34943494
const root = enqueueLegacyQueueUpdate(provider, refreshUpdate, lane);
34953495
if (root !== null) {
3496-
startUpdateTimerByLane(lane);
3496+
startUpdateTimerByLane(lane, 'refresh()');
34973497
scheduleUpdateOnFiber(root, provider, lane);
34983498
entangleLegacyQueueTransitions(root, provider, lane);
34993499
}
@@ -3562,7 +3562,7 @@ function dispatchReducerAction<S, A>(
35623562
} else {
35633563
const root = enqueueConcurrentHookUpdate(fiber, queue, update, lane);
35643564
if (root !== null) {
3565-
startUpdateTimerByLane(lane);
3565+
startUpdateTimerByLane(lane, 'dispatch()');
35663566
scheduleUpdateOnFiber(root, fiber, lane);
35673567
entangleTransitionUpdate(root, queue, lane);
35683568
}
@@ -3596,7 +3596,7 @@ function dispatchSetState<S, A>(
35963596
lane,
35973597
);
35983598
if (didScheduleUpdate) {
3599-
startUpdateTimerByLane(lane);
3599+
startUpdateTimerByLane(lane, 'setState()');
36003600
}
36013601
markUpdateInDevTools(fiber, lane, action);
36023602
}
@@ -3758,7 +3758,7 @@ function dispatchOptimisticSetState<S, A>(
37583758
// will never be attempted before the optimistic update. This currently
37593759
// holds because the optimistic update is always synchronous. If we ever
37603760
// change that, we'll need to account for this.
3761-
startUpdateTimerByLane(lane);
3761+
startUpdateTimerByLane(lane, 'setOptimistic()');
37623762
scheduleUpdateOnFiber(root, fiber, lane);
37633763
// Optimistic updates are always synchronous, so we don't need to call
37643764
// entangleTransitionUpdate here.

‎packages/react-reconciler/src/ReactFiberPerformanceTrack.js

Lines changed: 126 additions & 44 deletions
Original file line numberDiff line numberDiff line change
@@ -447,6 +447,7 @@ export function logBlockingStart(
447447
isSpawnedUpdate: boolean,
448448
renderStartTime: number,
449449
lanes: Lanes,
450+
debugTask: null | ConsoleTask, // DEV-only
450451
): void {
451452
if (supportsUserTiming) {
452453
currentTrack = 'Blocking';
@@ -456,14 +457,29 @@ export function logBlockingStart(
456457
if (eventTime > 0 && eventType !== null) {
457458
// Log the time from the event timeStamp until we called setState.
458459
const color = eventIsRepeat ? 'secondary-light' : 'warning';
459-
console.timeStamp(
460-
eventIsRepeat ? '' : 'Event: ' + eventType,
461-
eventTime,
462-
updateTime > 0 ? updateTime : renderStartTime,
463-
currentTrack,
464-
LANES_TRACK_GROUP,
465-
color,
466-
);
460+
if (__DEV__ && debugTask) {
461+
debugTask.run(
462+
// $FlowFixMe[method-unbinding]
463+
console.timeStamp.bind(
464+
console,
465+
eventIsRepeat ? '' : 'Event: ' + eventType,
466+
eventTime,
467+
updateTime > 0 ? updateTime : renderStartTime,
468+
currentTrack,
469+
LANES_TRACK_GROUP,
470+
color,
471+
),
472+
);
473+
} else {
474+
console.timeStamp(
475+
eventIsRepeat ? '' : 'Event: ' + eventType,
476+
eventTime,
477+
updateTime > 0 ? updateTime : renderStartTime,
478+
currentTrack,
479+
LANES_TRACK_GROUP,
480+
color,
481+
);
482+
}
467483
}
468484
if (updateTime > 0) {
469485
// Log the time from when we called setState until we started rendering.
@@ -472,18 +488,37 @@ export function logBlockingStart(
472488
: includesOnlyHydrationOrOffscreenLanes(lanes)
473489
? 'tertiary-light'
474490
: 'primary-light';
475-
console.timeStamp(
476-
isSpawnedUpdate
477-
? 'Cascading Update'
478-
: renderStartTime - updateTime > 5
479-
? 'Update Blocked'
480-
: 'Update',
481-
updateTime,
482-
renderStartTime,
483-
currentTrack,
484-
LANES_TRACK_GROUP,
485-
color,
486-
);
491+
if (__DEV__ && debugTask) {
492+
debugTask.run(
493+
// $FlowFixMe[method-unbinding]
494+
console.timeStamp.bind(
495+
console,
496+
isSpawnedUpdate
497+
? 'Cascading Update'
498+
: renderStartTime - updateTime > 5
499+
? 'Update Blocked'
500+
: 'Update',
501+
updateTime,
502+
renderStartTime,
503+
currentTrack,
504+
LANES_TRACK_GROUP,
505+
color,
506+
),
507+
);
508+
} else {
509+
console.timeStamp(
510+
isSpawnedUpdate
511+
? 'Cascading Update'
512+
: renderStartTime - updateTime > 5
513+
? 'Update Blocked'
514+
: 'Update',
515+
updateTime,
516+
renderStartTime,
517+
currentTrack,
518+
LANES_TRACK_GROUP,
519+
color,
520+
);
521+
}
487522
}
488523
}
489524
}
@@ -495,6 +530,7 @@ export function logTransitionStart(
495530
eventType: null | string,
496531
eventIsRepeat: boolean,
497532
renderStartTime: number,
533+
debugTask: null | ConsoleTask, // DEV-only
498534
): void {
499535
if (supportsUserTiming) {
500536
currentTrack = 'Transition';
@@ -507,36 +543,82 @@ export function logTransitionStart(
507543
: updateTime > 0
508544
? updateTime
509545
: renderStartTime;
510-
console.timeStamp(
511-
eventIsRepeat ? '' : 'Event: ' + eventType,
512-
eventTime,
513-
endTime,
514-
currentTrack,
515-
LANES_TRACK_GROUP,
516-
color,
517-
);
546+
if (__DEV__ && debugTask) {
547+
debugTask.run(
548+
// $FlowFixMe[method-unbinding]
549+
console.timeStamp.bind(
550+
console,
551+
eventIsRepeat ? '' : 'Event: ' + eventType,
552+
eventTime,
553+
endTime,
554+
currentTrack,
555+
LANES_TRACK_GROUP,
556+
color,
557+
),
558+
);
559+
} else {
560+
console.timeStamp(
561+
eventIsRepeat ? '' : 'Event: ' + eventType,
562+
eventTime,
563+
endTime,
564+
currentTrack,
565+
LANES_TRACK_GROUP,
566+
color,
567+
);
568+
}
518569
}
519570
if (startTime > 0) {
520571
// Log the time from when we started an async transition until we called setState or started rendering.
521-
console.timeStamp(
522-
'Action',
523-
startTime,
524-
updateTime > 0 ? updateTime : renderStartTime,
525-
currentTrack,
526-
LANES_TRACK_GROUP,
527-
'primary-dark',
528-
);
572+
// TODO: Ideally this would use the debugTask of the startTransition call perhaps.
573+
if (__DEV__ && debugTask) {
574+
debugTask.run(
575+
// $FlowFixMe[method-unbinding]
576+
console.timeStamp.bind(
577+
console,
578+
'Action',
579+
startTime,
580+
updateTime > 0 ? updateTime : renderStartTime,
581+
currentTrack,
582+
LANES_TRACK_GROUP,
583+
'primary-dark',
584+
),
585+
);
586+
} else {
587+
console.timeStamp(
588+
'Action',
589+
startTime,
590+
updateTime > 0 ? updateTime : renderStartTime,
591+
currentTrack,
592+
LANES_TRACK_GROUP,
593+
'primary-dark',
594+
);
595+
}
529596
}
530597
if (updateTime > 0) {
531598
// Log the time from when we called setState until we started rendering.
532-
console.timeStamp(
533-
renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update',
534-
updateTime,
535-
renderStartTime,
536-
currentTrack,
537-
LANES_TRACK_GROUP,
538-
'primary-light',
539-
);
599+
if (__DEV__ && debugTask) {
600+
debugTask.run(
601+
// $FlowFixMe[method-unbinding]
602+
console.timeStamp.bind(
603+
console,
604+
renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update',
605+
updateTime,
606+
renderStartTime,
607+
currentTrack,
608+
LANES_TRACK_GROUP,
609+
'primary-light',
610+
),
611+
);
612+
} else {
613+
console.timeStamp(
614+
renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update',
615+
updateTime,
616+
renderStartTime,
617+
currentTrack,
618+
LANES_TRACK_GROUP,
619+
'primary-light',
620+
);
621+
}
540622
}
541623
}
542624
}

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