Scheduling profiler updates (#19334)
* Make enableSchedulingProfiler static for profiling+experimental builds * Copied debug tracing and scheduler profiling to .new fork * Updated test @gate conditions
Brian Vaughn committed
Jul 13, 2020 at 22:20 UTC
6d7555b014513125b0c229b9c6e45c903d974ff7
10 files changed
+269
-15
packages/react-reconciler/src/ReactFiberClassComponent.new.js
+47
-1
@@ -16,6 +16,8 @@ import {Update, Snapshot} from './ReactSideEffectTags';
16
import {
17
debugRenderPhaseSideEffectsForStrictMode,
18
disableLegacyContext,
19
+ enableDebugTracing,
20
+ enableSchedulingProfiler,
21
warnAboutDeprecatedLifecycles,
22
} from 'shared/ReactFeatureFlags';
23
import ReactStrictModeWarnings from './ReactStrictModeWarnings.new';
@@ -27,7 +29,7 @@ import invariant from 'shared/invariant';
29
import {REACT_CONTEXT_TYPE, REACT_PROVIDER_TYPE} from 'shared/ReactSymbols';
30
31
import {resolveDefaultProps} from './ReactFiberLazyComponent.new';
30
-import {StrictMode} from './ReactTypeOfMode';
32
+import {DebugTracingMode, StrictMode} from './ReactTypeOfMode';
33
34
import {
35
enqueueUpdate,
@@ -55,8 +57,13 @@ import {
57
scheduleUpdateOnFiber,
58
} from './ReactFiberWorkLoop.new';
59
import {requestCurrentSuspenseConfig} from './ReactFiberSuspenseConfig';
60
+import {logForceUpdateScheduled, logStateUpdateScheduled} from './DebugTracing';
61
62
import {disableLogs, reenableLogs} from 'shared/ConsolePatchingDev';
63
+import {
64
+ markForceUpdateScheduled,
65
+ markStateUpdateScheduled,
66
+} from './SchedulingProfiler';
67
68
const fakeInternalInstance = {};
69
const isArray = Array.isArray;
@@ -203,6 +210,19 @@ const classComponentUpdater = {
210
211
enqueueUpdate(fiber, update);
212
scheduleUpdateOnFiber(fiber, lane, eventTime);
213
+
214
+ if (__DEV__) {
215
+ if (enableDebugTracing) {
216
+ if (fiber.mode & DebugTracingMode) {
217
+ const name = getComponentName(fiber.type) || 'Unknown';
218
+ logStateUpdateScheduled(name, lane, payload);
219
+ }
220
+ }
221
+ }
222
+
223
+ if (enableSchedulingProfiler) {
224
+ markStateUpdateScheduled(fiber, lane);
225
+ }
226
},
227
enqueueReplaceState(inst, payload, callback) {
228
const fiber = getInstance(inst);
@@ -223,6 +243,19 @@ const classComponentUpdater = {
243
244
enqueueUpdate(fiber, update);
245
scheduleUpdateOnFiber(fiber, lane, eventTime);
246
+
247
+ if (__DEV__) {
248
+ if (enableDebugTracing) {
249
+ if (fiber.mode & DebugTracingMode) {
250
+ const name = getComponentName(fiber.type) || 'Unknown';
251
+ logStateUpdateScheduled(name, lane, payload);
252
+ }
253
+ }
254
+ }
255
+
256
+ if (enableSchedulingProfiler) {
257
+ markStateUpdateScheduled(fiber, lane);
258
+ }
259
},
260
enqueueForceUpdate(inst, callback) {
261
const fiber = getInstance(inst);
@@ -242,6 +275,19 @@ const classComponentUpdater = {
275
276
enqueueUpdate(fiber, update);
277
scheduleUpdateOnFiber(fiber, lane, eventTime);
278
+
279
+ if (__DEV__) {
280
+ if (enableDebugTracing) {
281
+ if (fiber.mode & DebugTracingMode) {
282
+ const name = getComponentName(fiber.type) || 'Unknown';
283
+ logForceUpdateScheduled(name, lane);
284
+ }
285
+ }
286
+ }
287
+
288
+ if (enableSchedulingProfiler) {
289
+ markForceUpdateScheduled(fiber, lane);
290
+ }
291
},
292
};
293
packages/react-reconciler/src/ReactFiberHooks.new.js
+21
-2
@@ -24,9 +24,13 @@ import type {FiberRoot} from './ReactInternalTypes';
24
import type {OpaqueIDType} from './ReactFiberHostConfig';
25
26
import ReactSharedInternals from 'shared/ReactSharedInternals';
27
-import {enableNewReconciler} from 'shared/ReactFeatureFlags';
27
+import {
28
+ enableDebugTracing,
29
+ enableSchedulingProfiler,
30
+ enableNewReconciler,
31
+} from 'shared/ReactFeatureFlags';
32
29
-import {NoMode, BlockingMode} from './ReactTypeOfMode';
33
+import {NoMode, BlockingMode, DebugTracingMode} from './ReactTypeOfMode';
34
import {
35
NoLane,
36
NoLanes,
@@ -88,6 +92,8 @@ import {
92
warnAboutMultipleRenderersDEV,
93
} from './ReactMutableSource.new';
94
import {getIsRendering} from './ReactCurrentFiber';
95
+import {logStateUpdateScheduled} from './DebugTracing';
96
+import {markStateUpdateScheduled} from './SchedulingProfiler';
97
98
const {ReactCurrentDispatcher, ReactCurrentBatchConfig} = ReactSharedInternals;
99
@@ -1751,6 +1757,19 @@ function dispatchAction<S, A>(
1757
}
1758
scheduleUpdateOnFiber(fiber, lane, eventTime);
1759
}
1760
+
1761
+ if (__DEV__) {
1762
+ if (enableDebugTracing) {
1763
+ if (fiber.mode & DebugTracingMode) {
1764
+ const name = getComponentName(fiber.type) || 'Unknown';
1765
+ logStateUpdateScheduled(name, lane, action);
1766
+ }
1767
+ }
1768
+ }
1769
+
1770
+ if (enableSchedulingProfiler) {
1771
+ markStateUpdateScheduled(fiber, lane);
1772
+ }
1773
}
1774
1775
export const ContextOnlyDispatcher: Dispatcher = {
packages/react-reconciler/src/ReactFiberReconciler.new.js
+6
@@ -39,6 +39,7 @@ import {
39
} from './ReactWorkTags';
40
import getComponentName from 'shared/getComponentName';
41
import invariant from 'shared/invariant';
42
+import {enableSchedulingProfiler} from 'shared/ReactFeatureFlags';
43
import ReactSharedInternals from 'shared/ReactSharedInternals';
44
import {getPublicInstance} from './ReactFiberHostConfig';
45
import {
@@ -95,6 +96,7 @@ import {
96
setRefreshHandler,
97
findHostInstancesForRefresh,
98
} from './ReactFiberHotReloading.new';
99
+import {markRenderScheduled} from './SchedulingProfiler';
100
101
export {registerMutableSourceForHydration} from './ReactMutableSource.new';
102
export {createPortal} from './ReactPortal';
@@ -273,6 +275,10 @@ export function updateContainer(
275
const suspenseConfig = requestCurrentSuspenseConfig();
276
const lane = requestUpdateLane(current, suspenseConfig);
277
278
+ if (enableSchedulingProfiler) {
279
+ markRenderScheduled(lane);
280
+ }
281
+
282
const context = getContextForSubtree(parentComponent);
283
if (container.context === null) {
284
container.context = context;
packages/react-reconciler/src/ReactFiberThrow.new.js
+20
-1
@@ -31,7 +31,11 @@ import {
31
ForceUpdateForLegacySuspense,
32
} from './ReactSideEffectTags';
33
import {shouldCaptureSuspense} from './ReactFiberSuspenseComponent.new';
34
-import {NoMode, BlockingMode} from './ReactTypeOfMode';
34
+import {NoMode, BlockingMode, DebugTracingMode} from './ReactTypeOfMode';
35
+import {
36
+ enableDebugTracing,
37
+ enableSchedulingProfiler,
38
+} from 'shared/ReactFeatureFlags';
39
import {createCapturedValue} from './ReactCapturedValue';
40
import {
41
enqueueCapturedUpdate,
@@ -54,6 +58,8 @@ import {
58
pingSuspendedRoot,
59
} from './ReactFiberWorkLoop.new';
60
import {logCapturedError} from './ReactFiberErrorLogger';
61
+import {logComponentSuspended} from './DebugTracing';
62
+import {markComponentSuspended} from './SchedulingProfiler';
63
64
import {
65
SyncLane,
@@ -190,6 +196,19 @@ function throwException(
196
// This is a wakeable.
197
const wakeable: Wakeable = (value: any);
198
199
+ if (__DEV__) {
200
+ if (enableDebugTracing) {
201
+ if (sourceFiber.mode & DebugTracingMode) {
202
+ const name = getComponentName(sourceFiber.type) || 'Unknown';
203
+ logComponentSuspended(name, wakeable);
204
+ }
205
+ }
206
+ }
207
+
208
+ if (enableSchedulingProfiler) {
209
+ markComponentSuspended(sourceFiber, wakeable);
210
+ }
211
+
212
if ((sourceFiber.mode & BlockingMode) === NoMode) {
213
// Reset the memoizedState to what it was before we attempted
214
// to render it.
packages/react-reconciler/src/ReactFiberWorkLoop.new.js
+147
@@ -27,6 +27,8 @@ import {
27
warnAboutUnmockedScheduler,
28
deferRenderPhaseUpdateToNextBatch,
29
decoupleUpdatePriorityFromScheduler,
30
+ enableDebugTracing,
31
+ enableSchedulingProfiler,
32
enableScopeAPI,
33
} from 'shared/ReactFeatureFlags';
34
import ReactSharedInternals from 'shared/ReactSharedInternals';
@@ -47,6 +49,27 @@ import {
49
flushSyncCallbackQueue,
50
scheduleSyncCallback,
51
} from './SchedulerWithReactIntegration.new';
52
+import {
53
+ logCommitStarted,
54
+ logCommitStopped,
55
+ logLayoutEffectsStarted,
56
+ logLayoutEffectsStopped,
57
+ logPassiveEffectsStarted,
58
+ logPassiveEffectsStopped,
59
+ logRenderStarted,
60
+ logRenderStopped,
61
+} from './DebugTracing';
62
+import {
63
+ markCommitStarted,
64
+ markCommitStopped,
65
+ markLayoutEffectsStarted,
66
+ markLayoutEffectsStopped,
67
+ markPassiveEffectsStarted,
68
+ markPassiveEffectsStopped,
69
+ markRenderStarted,
70
+ markRenderYielded,
71
+ markRenderStopped,
72
+} from './SchedulingProfiler';
73
74
// The scheduler is imported here *only* to detect whether it's been mocked
75
import * as Scheduler from 'scheduler';
@@ -1509,6 +1532,16 @@ function renderRootSync(root: FiberRoot, lanes: Lanes) {
1532
1533
const prevInteractions = pushInteractions(root);
1534
1535
+ if (__DEV__) {
1536
+ if (enableDebugTracing) {
1537
+ logRenderStarted(lanes);
1538
+ }
1539
+ }
1540
+
1541
+ if (enableSchedulingProfiler) {
1542
+ markRenderStarted(lanes);
1543
+ }
1544
+
1545
do {
1546
try {
1547
workLoopSync();
@@ -1534,6 +1567,16 @@ function renderRootSync(root: FiberRoot, lanes: Lanes) {
1567
);
1568
}
1569
1570
+ if (__DEV__) {
1571
+ if (enableDebugTracing) {
1572
+ logRenderStopped();
1573
+ }
1574
+ }
1575
+
1576
+ if (enableSchedulingProfiler) {
1577
+ markRenderStopped();
1578
+ }
1579
+
1580
// Set this to null to indicate there's no in-progress render.
1581
workInProgressRoot = null;
1582
workInProgressRootRenderLanes = NoLanes;
@@ -1564,6 +1607,16 @@ function renderRootConcurrent(root: FiberRoot, lanes: Lanes) {
1607
1608
const prevInteractions = pushInteractions(root);
1609
1610
+ if (__DEV__) {
1611
+ if (enableDebugTracing) {
1612
+ logRenderStarted(lanes);
1613
+ }
1614
+ }
1615
+
1616
+ if (enableSchedulingProfiler) {
1617
+ markRenderStarted(lanes);
1618
+ }
1619
+
1620
do {
1621
try {
1622
workLoopConcurrent();
@@ -1580,12 +1633,25 @@ function renderRootConcurrent(root: FiberRoot, lanes: Lanes) {
1633
popDispatcher(prevDispatcher);
1634
executionContext = prevExecutionContext;
1635
1636
+ if (__DEV__) {
1637
+ if (enableDebugTracing) {
1638
+ logRenderStopped();
1639
+ }
1640
+ }
1641
+
1642
// Check if the tree has completed.
1643
if (workInProgress !== null) {
1644
// Still work remaining.
1645
+ if (enableSchedulingProfiler) {
1646
+ markRenderYielded();
1647
+ }
1648
return RootIncomplete;
1649
} else {
1650
// Completed the tree.
1651
+ if (enableSchedulingProfiler) {
1652
+ markRenderStopped();
1653
+ }
1654
+
1655
// Set this to null to indicate there's no in-progress render.
1656
workInProgressRoot = null;
1657
workInProgressRootRenderLanes = NoLanes;
@@ -1868,7 +1934,28 @@ function commitRootImpl(root, renderPriorityLevel) {
1934
1935
const finishedWork = root.finishedWork;
1936
const lanes = root.finishedLanes;
1937
+
1938
+ if (__DEV__) {
1939
+ if (enableDebugTracing) {
1940
+ logCommitStarted(lanes);
1941
+ }
1942
+ }
1943
+
1944
+ if (enableSchedulingProfiler) {
1945
+ markCommitStarted(lanes);
1946
+ }
1947
+
1948
if (finishedWork === null) {
1949
+ if (__DEV__) {
1950
+ if (enableDebugTracing) {
1951
+ logCommitStopped();
1952
+ }
1953
+ }
1954
+
1955
+ if (enableSchedulingProfiler) {
1956
+ markCommitStopped();
1957
+ }
1958
+
1959
return null;
1960
}
1961
root.finishedWork = null;
@@ -2159,6 +2246,16 @@ function commitRootImpl(root, renderPriorityLevel) {
2246
}
2247
2248
if ((executionContext & LegacyUnbatchedContext) !== NoContext) {
2249
+ if (__DEV__) {
2250
+ if (enableDebugTracing) {
2251
+ logCommitStopped();
2252
+ }
2253
+ }
2254
+
2255
+ if (enableSchedulingProfiler) {
2256
+ markCommitStopped();
2257
+ }
2258
+
2259
// This is a legacy edge case. We just committed the initial mount of
2260
// a ReactDOM.render-ed root inside of batchedUpdates. The commit fired
2261
// synchronously, but layout updates should be deferred until the end
@@ -2169,6 +2266,16 @@ function commitRootImpl(root, renderPriorityLevel) {
2266
// If layout work was scheduled, flush it now.
2267
flushSyncCallbackQueue();
2268
2269
+ if (__DEV__) {
2270
+ if (enableDebugTracing) {
2271
+ logCommitStopped();
2272
+ }
2273
+ }
2274
+
2275
+ if (enableSchedulingProfiler) {
2276
+ markCommitStopped();
2277
+ }
2278
+
2279
return null;
2280
}
2281
@@ -2300,6 +2407,16 @@ function commitMutationEffects(root: FiberRoot, renderPriorityLevel) {
2407
}
2408
2409
function commitLayoutEffects(root: FiberRoot, committedLanes: Lanes) {
2410
+ if (__DEV__) {
2411
+ if (enableDebugTracing) {
2412
+ logLayoutEffectsStarted(committedLanes);
2413
+ }
2414
+ }
2415
+
2416
+ if (enableSchedulingProfiler) {
2417
+ markLayoutEffectsStarted(committedLanes);
2418
+ }
2419
+
2420
// TODO: Should probably move the bulk of this function to commitWork.
2421
while (nextEffect !== null) {
2422
setCurrentDebugFiberInDEV(nextEffect);
@@ -2326,6 +2443,16 @@ function commitLayoutEffects(root: FiberRoot, committedLanes: Lanes) {
2443
resetCurrentDebugFiberInDEV();
2444
nextEffect = nextEffect.nextEffect;
2445
}
2446
+
2447
+ if (__DEV__) {
2448
+ if (enableDebugTracing) {
2449
+ logLayoutEffectsStopped();
2450
+ }
2451
+ }
2452
+
2453
+ if (enableSchedulingProfiler) {
2454
+ markLayoutEffectsStopped();
2455
+ }
2456
}
2457
2458
export function flushPassiveEffects() {
@@ -2415,6 +2542,16 @@ function flushPassiveEffectsImpl() {
2542
'Cannot flush passive effects while already rendering.',
2543
);
2544
2545
+ if (__DEV__) {
2546
+ if (enableDebugTracing) {
2547
+ logPassiveEffectsStarted(lanes);
2548
+ }
2549
+ }
2550
+
2551
+ if (enableSchedulingProfiler) {
2552
+ markPassiveEffectsStarted(lanes);
2553
+ }
2554
+
2555
if (__DEV__) {
2556
isFlushingPassiveEffects = true;
2557
}
@@ -2571,6 +2708,16 @@ function flushPassiveEffectsImpl() {
2708
isFlushingPassiveEffects = false;
2709
}
2710
2711
+ if (__DEV__) {
2712
+ if (enableDebugTracing) {
2713
+ logPassiveEffectsStopped();
2714
+ }
2715
+ }
2716
+
2717
+ if (enableSchedulingProfiler) {
2718
+ markPassiveEffectsStopped();
2719
+ }
2720
+
2721
executionContext = prevExecutionContext;
2722
2723
flushSyncCallbackQueue();
packages/react-reconciler/src/ReactFiberWorkLoop.old.js
+1
-1
@@ -1361,7 +1361,7 @@ function handleError(root, thrownValue): void {
1361
// sibling, or the parent if there are no siblings. But since the root
1362
// has no siblings nor a parent, we set it to null. Usually this is
1363
// handled by `completeUnitOfWork` or `unwindWork`, but since we're
1364
- // interntionally not calling those, we need set it here.
1364
+ // intentionally not calling those, we need set it here.
1365
// TODO: Consider calling `unwindWork` to pop the contexts.
1366
workInProgress = null;
1367
return;
packages/react-reconciler/src/__tests__/SchedulingProfiler-test.internal.js
+24
-6
@@ -351,8 +351,14 @@ describe('SchedulingProfiler', () => {
351
expect(Scheduler).toFlushUntilNextPaint([]);
352
}).toErrorDev('Cannot update during an existing state transition');
353
354
- expect(marks.map(normalizeCodeLocInfo)).toContain(
355
- '--schedule-state-update-1024-Example-\n in Example (at **)',
354
+ gate(({old}) =>
355
+ old
356
+ ? expect(marks.map(normalizeCodeLocInfo)).toContain(
357
+ '--schedule-state-update-1024-Example-\n in Example (at **)',
358
+ )
359
+ : expect(marks.map(normalizeCodeLocInfo)).toContain(
360
+ '--schedule-state-update-512-Example-\n in Example (at **)',
361
+ ),
362
);
363
});
364
@@ -378,8 +384,14 @@ describe('SchedulingProfiler', () => {
384
expect(Scheduler).toFlushUntilNextPaint([]);
385
}).toErrorDev('Cannot update during an existing state transition');
386
381
- expect(marks.map(normalizeCodeLocInfo)).toContain(
382
- '--schedule-forced-update-1024-Example-\n in Example (at **)',
387
+ gate(({old}) =>
388
+ old
389
+ ? expect(marks.map(normalizeCodeLocInfo)).toContain(
390
+ '--schedule-forced-update-1024-Example-\n in Example (at **)',
391
+ )
392
+ : expect(marks.map(normalizeCodeLocInfo)).toContain(
393
+ '--schedule-forced-update-512-Example-\n in Example (at **)',
394
+ ),
395
);
396
});
397
@@ -461,8 +473,14 @@ describe('SchedulingProfiler', () => {
473
ReactTestRenderer.create(<Example />, {unstable_isConcurrent: true});
474
});
475
464
- expect(marks.map(normalizeCodeLocInfo)).toContain(
465
- '--schedule-state-update-1024-Example-\n in Example (at **)',
476
+ gate(({old}) =>
477
+ old
478
+ ? expect(marks.map(normalizeCodeLocInfo)).toContain(
479
+ '--schedule-state-update-1024-Example-\n in Example (at **)',
480
+ )
481
+ : expect(marks.map(normalizeCodeLocInfo)).toContain(
482
+ '--schedule-state-update-512-Example-\n in Example (at **)',
483
+ ),
484
);
485
});
486
});
packages/shared/ReactFeatureFlags.js
+1
-1
@@ -17,7 +17,7 @@ export const enableDebugTracing = false;
17
18
// Adds user timing marks for e.g. state updates, suspense, and work loop stuff,
19
// for an experimental scheduling profiler tool.
20
-export const enableSchedulingProfiler = false;
20
+export const enableSchedulingProfiler = __PROFILE__ && __EXPERIMENTAL__;
21
22
// Helps identify side effects in render-phase lifecycle hooks and setState
23
// reducers by double invoking them in Strict Mode.
packages/shared/forks/ReactFeatureFlags.www-dynamic.js
+1
-2
@@ -19,9 +19,8 @@ export const enableFilterEmptyStringAttributesDOM = __VARIANT__;
19
export const enableLegacyFBSupport = __VARIANT__;
20
export const decoupleUpdatePriorityFromScheduler = __VARIANT__;
21
22
-// TODO: These features do not currently exist in the new reconciler fork.
22
+// TODO: This feature does not currently exist in the new reconciler fork.
23
export const enableDebugTracing = !__VARIANT__;
24
-export const enableSchedulingProfiler = !__VARIANT__ && __PROFILE__;
24
25
// This only has an effect in the new reconciler. But also, the new reconciler
26
// is only enabled when __VARIANT__ is true. So this is set to the opposite of
packages/shared/forks/ReactFeatureFlags.www.js
+1
-1
@@ -26,7 +26,6 @@ export const {
26
deferRenderPhaseUpdateToNextBatch,
27
decoupleUpdatePriorityFromScheduler,
28
enableDebugTracing,
29
- enableSchedulingProfiler,
29
enableFormEventDelegation,
30
} = dynamicFeatureFlags;
31
@@ -35,6 +34,7 @@ export const {
34
35
export const enableProfilerTimer = __PROFILE__;
36
export const enableProfilerCommitHooks = __PROFILE__;
37
+export const enableSchedulingProfiler = __PROFILE__;
38
39
// Note: we'll want to remove this when we to userland implementation.
40
// For now, we'll turn it on for everyone because it's *already* on for everyone in practice.