Scheduling profiler tweaks (#20215)
Brian Vaughn committed
Nov 12, 2020 at 09:47 UTC
760d9ab57a0fbffe8caf1d15c40efaa0a3592733
4 files changed
+149
-77
packages/react-reconciler/src/SchedulingProfiler.js
+63
-31
@@ -20,31 +20,63 @@ import getComponentName from 'shared/getComponentName';
20
* require.
21
*/
22
const supportsUserTiming =
23
- typeof performance !== 'undefined' && typeof performance.mark === 'function';
23
+ typeof performance !== 'undefined' &&
24
+ typeof performance.mark === 'function' &&
25
+ typeof performance.clearMarks === 'function';
26
+
27
+let supportsUserTimingV3 = false;
28
+if (enableSchedulingProfiler) {
29
+ if (supportsUserTiming) {
30
+ const CHECK_V3_MARK = '__v3';
31
+ const markOptions = {};
32
+ // $FlowFixMe: Ignore Flow complaining about needing a value
33
+ Object.defineProperty(markOptions, 'startTime', {
34
+ get: function() {
35
+ supportsUserTimingV3 = true;
36
+ return 0;
37
+ },
38
+ set: function() {},
39
+ });
40
+
41
+ try {
42
+ // $FlowFixMe: Flow expects the User Timing level 2 API.
43
+ performance.mark(CHECK_V3_MARK, markOptions);
44
+ } catch (error) {
45
+ // Ignore
46
+ } finally {
47
+ performance.clearMarks(CHECK_V3_MARK);
48
+ }
49
+ }
50
+}
51
52
function formatLanes(laneOrLanes: Lane | Lanes): string {
53
return ((laneOrLanes: any): number).toString();
54
}
55
56
+function markAndClear(name) {
57
+ performance.mark(name);
58
+ performance.clearMarks(name);
59
+}
60
+
61
// Create a mark on React initialization
62
if (enableSchedulingProfiler) {
31
- if (supportsUserTiming) {
32
- performance.mark(`--react-init-${ReactVersion}`);
63
+ if (supportsUserTimingV3) {
64
+ markAndClear(`--react-init-${ReactVersion}`);
65
}
66
}
67
68
export function markCommitStarted(lanes: Lanes): void {
69
if (enableSchedulingProfiler) {
38
- if (supportsUserTiming) {
39
- performance.mark(`--commit-start-${formatLanes(lanes)}`);
70
+ if (supportsUserTimingV3) {
71
+ markAndClear(`--commit-start-${formatLanes(lanes)}`);
72
}
73
}
74
}
75
76
export function markCommitStopped(): void {
77
if (enableSchedulingProfiler) {
46
- if (supportsUserTiming) {
47
- performance.mark('--commit-stop');
78
+ if (supportsUserTimingV3) {
79
+ markAndClear('--commit-stop');
80
}
81
}
82
}
@@ -63,14 +95,14 @@ function getWakeableID(wakeable: Wakeable): number {
95
96
export function markComponentSuspended(fiber: Fiber, wakeable: Wakeable): void {
97
if (enableSchedulingProfiler) {
66
- if (supportsUserTiming) {
98
+ if (supportsUserTimingV3) {
99
const id = getWakeableID(wakeable);
100
const componentName = getComponentName(fiber.type) || 'Unknown';
101
// TODO Add component stack id
70
- performance.mark(`--suspense-suspend-${id}-${componentName}`);
102
+ markAndClear(`--suspense-suspend-${id}-${componentName}`);
103
wakeable.then(
72
- () => performance.mark(`--suspense-resolved-${id}-${componentName}`),
73
- () => performance.mark(`--suspense-rejected-${id}-${componentName}`),
104
+ () => markAndClear(`--suspense-resolved-${id}-${componentName}`),
105
+ () => markAndClear(`--suspense-rejected-${id}-${componentName}`),
106
);
107
}
108
}
@@ -78,74 +110,74 @@ export function markComponentSuspended(fiber: Fiber, wakeable: Wakeable): void {
110
111
export function markLayoutEffectsStarted(lanes: Lanes): void {
112
if (enableSchedulingProfiler) {
81
- if (supportsUserTiming) {
82
- performance.mark(`--layout-effects-start-${formatLanes(lanes)}`);
113
+ if (supportsUserTimingV3) {
114
+ markAndClear(`--layout-effects-start-${formatLanes(lanes)}`);
115
}
116
}
117
}
118
119
export function markLayoutEffectsStopped(): void {
120
if (enableSchedulingProfiler) {
89
- if (supportsUserTiming) {
90
- performance.mark('--layout-effects-stop');
121
+ if (supportsUserTimingV3) {
122
+ markAndClear('--layout-effects-stop');
123
}
124
}
125
}
126
127
export function markPassiveEffectsStarted(lanes: Lanes): void {
128
if (enableSchedulingProfiler) {
97
- if (supportsUserTiming) {
98
- performance.mark(`--passive-effects-start-${formatLanes(lanes)}`);
129
+ if (supportsUserTimingV3) {
130
+ markAndClear(`--passive-effects-start-${formatLanes(lanes)}`);
131
}
132
}
133
}
134
135
export function markPassiveEffectsStopped(): void {
136
if (enableSchedulingProfiler) {
105
- if (supportsUserTiming) {
106
- performance.mark('--passive-effects-stop');
137
+ if (supportsUserTimingV3) {
138
+ markAndClear('--passive-effects-stop');
139
}
140
}
141
}
142
143
export function markRenderStarted(lanes: Lanes): void {
144
if (enableSchedulingProfiler) {
113
- if (supportsUserTiming) {
114
- performance.mark(`--render-start-${formatLanes(lanes)}`);
145
+ if (supportsUserTimingV3) {
146
+ markAndClear(`--render-start-${formatLanes(lanes)}`);
147
}
148
}
149
}
150
151
export function markRenderYielded(): void {
152
if (enableSchedulingProfiler) {
121
- if (supportsUserTiming) {
122
- performance.mark('--render-yield');
153
+ if (supportsUserTimingV3) {
154
+ markAndClear('--render-yield');
155
}
156
}
157
}
158
159
export function markRenderStopped(): void {
160
if (enableSchedulingProfiler) {
129
- if (supportsUserTiming) {
130
- performance.mark('--render-stop');
161
+ if (supportsUserTimingV3) {
162
+ markAndClear('--render-stop');
163
}
164
}
165
}
166
167
export function markRenderScheduled(lane: Lane): void {
168
if (enableSchedulingProfiler) {
137
- if (supportsUserTiming) {
138
- performance.mark(`--schedule-render-${formatLanes(lane)}`);
169
+ if (supportsUserTimingV3) {
170
+ markAndClear(`--schedule-render-${formatLanes(lane)}`);
171
}
172
}
173
}
174
175
export function markForceUpdateScheduled(fiber: Fiber, lane: Lane): void {
176
if (enableSchedulingProfiler) {
145
- if (supportsUserTiming) {
177
+ if (supportsUserTimingV3) {
178
const componentName = getComponentName(fiber.type) || 'Unknown';
179
// TODO Add component stack id
148
- performance.mark(
180
+ markAndClear(
181
`--schedule-forced-update-${formatLanes(lane)}-${componentName}`,
182
);
183
}
@@ -154,10 +186,10 @@ export function markForceUpdateScheduled(fiber: Fiber, lane: Lane): void {
186
187
export function markStateUpdateScheduled(fiber: Fiber, lane: Lane): void {
188
if (enableSchedulingProfiler) {
157
- if (supportsUserTiming) {
189
+ if (supportsUserTimingV3) {
190
const componentName = getComponentName(fiber.type) || 'Unknown';
191
// TODO Add component stack id
160
- performance.mark(
192
+ markAndClear(
193
`--schedule-state-update-${formatLanes(lane)}-${componentName}`,
194
);
195
}
packages/react-reconciler/src/__tests__/SchedulingProfiler-test.internal.js
+82
-45
@@ -18,22 +18,56 @@ describe('SchedulingProfiler', () => {
18
let ReactNoop;
19
let Scheduler;
20
21
+ let clearedMarks;
22
+ let featureDetectionMarkName = null;
23
let marks;
24
25
function createUserTimingPolyfill() {
26
+ featureDetectionMarkName = null;
27
+
28
+ clearedMarks = [];
29
+ marks = [];
30
+
31
// This is not a true polyfill, but it gives us enough to capture marks.
32
// Reference: https://developer.mozilla.org/en-US/docs/Web/API/User_Timing_API
33
return {
27
- mark(markName) {
34
+ clearMarks(markName) {
35
+ clearedMarks.push(markName);
36
+ marks = marks.filter(mark => mark !== markName);
37
+ },
38
+ mark(markName, markOptions) {
39
+ if (featureDetectionMarkName === null) {
40
+ featureDetectionMarkName = markName;
41
+ }
42
marks.push(markName);
43
+ if (markOptions != null) {
44
+ // This is triggers the feature detection.
45
+ markOptions.startTime++;
46
+ }
47
},
48
};
49
}
50
51
+ function clearPendingMarks() {
52
+ clearedMarks.splice(0);
53
+ }
54
+
55
+ function expectMarksToContain(expectedMarks) {
56
+ expect(clearedMarks).toContain(expectedMarks);
57
+ }
58
+
59
+ function expectMarksToEqual(expectedMarks) {
60
+ expect(
61
+ clearedMarks[0] === featureDetectionMarkName
62
+ ? clearedMarks.slice(1)
63
+ : clearedMarks,
64
+ ).toEqual(expectedMarks);
65
+ }
66
+
67
beforeEach(() => {
68
jest.resetModules();
69
+
70
global.performance = createUserTimingPolyfill();
36
- marks = [];
71
72
React = require('react');
73
@@ -45,25 +79,28 @@ describe('SchedulingProfiler', () => {
79
});
80
81
afterEach(() => {
82
+ // Verify all logged marks also get cleared.
83
+ expect(marks).toHaveLength(0);
84
+
85
delete global.performance;
86
});
87
88
// @gate !enableSchedulingProfiler
89
it('should not mark if enableSchedulingProfiler is false', () => {
90
ReactTestRenderer.create(<div />);
54
- expect(marks).toEqual([]);
91
+ expectMarksToEqual([]);
92
});
93
94
// @gate enableSchedulingProfiler
95
it('should log React version on initialization', () => {
59
- expect(marks).toEqual([`--react-init-${ReactVersion}`]);
96
+ expectMarksToEqual([`--react-init-${ReactVersion}`]);
97
});
98
99
// @gate enableSchedulingProfiler
100
it('should mark sync render without suspends or state updates', () => {
101
ReactTestRenderer.create(<div />);
102
66
- expect(marks).toEqual([
103
+ expectMarksToEqual([
104
`--react-init-${ReactVersion}`,
105
'--schedule-render-1',
106
'--render-start-1',
@@ -79,16 +116,16 @@ describe('SchedulingProfiler', () => {
116
it('should mark concurrent render without suspends or state updates', () => {
117
ReactTestRenderer.create(<div />, {unstable_isConcurrent: true});
118
82
- expect(marks).toEqual([
119
+ expectMarksToEqual([
120
`--react-init-${ReactVersion}`,
121
'--schedule-render-512',
122
]);
123
87
- marks.splice(0);
124
+ clearPendingMarks();
125
126
expect(Scheduler).toFlushUntilNextPaint([]);
127
91
- expect(marks).toEqual([
128
+ expectMarksToEqual([
129
'--render-start-512',
130
'--render-stop',
131
'--commit-start-512',
@@ -114,7 +151,7 @@ describe('SchedulingProfiler', () => {
151
// Do one step of work.
152
expect(ReactNoop.flushNextYield()).toEqual(['Foo']);
153
117
- expect(marks).toEqual([
154
+ expectMarksToEqual([
155
`--react-init-${ReactVersion}`,
156
'--schedule-render-512',
157
'--render-start-512',
@@ -135,7 +172,7 @@ describe('SchedulingProfiler', () => {
172
</React.Suspense>,
173
);
174
138
- expect(marks).toEqual([
175
+ expectMarksToEqual([
176
`--react-init-${ReactVersion}`,
177
'--schedule-render-1',
178
'--render-start-1',
@@ -147,10 +184,10 @@ describe('SchedulingProfiler', () => {
184
'--commit-stop',
185
]);
186
150
- marks.splice(0);
187
+ clearPendingMarks();
188
189
await fakeSuspensePromise;
153
- expect(marks).toEqual(['--suspense-resolved-0-Example']);
190
+ expectMarksToEqual(['--suspense-resolved-0-Example']);
191
});
192
193
// @gate enableSchedulingProfiler
@@ -166,7 +203,7 @@ describe('SchedulingProfiler', () => {
203
</React.Suspense>,
204
);
205
169
- expect(marks).toEqual([
206
+ expectMarksToEqual([
207
`--react-init-${ReactVersion}`,
208
'--schedule-render-1',
209
'--render-start-1',
@@ -178,10 +215,10 @@ describe('SchedulingProfiler', () => {
215
'--commit-stop',
216
]);
217
181
- marks.splice(0);
218
+ clearPendingMarks();
219
220
await expect(fakeSuspensePromise).rejects.toThrow();
184
- expect(marks).toEqual(['--suspense-rejected-0-Example']);
221
+ expectMarksToEqual(['--suspense-rejected-0-Example']);
222
});
223
224
// @gate enableSchedulingProfiler
@@ -198,16 +235,16 @@ describe('SchedulingProfiler', () => {
235
{unstable_isConcurrent: true},
236
);
237
201
- expect(marks).toEqual([
238
+ expectMarksToEqual([
239
`--react-init-${ReactVersion}`,
240
'--schedule-render-512',
241
]);
242
206
- marks.splice(0);
243
+ clearPendingMarks();
244
245
expect(Scheduler).toFlushUntilNextPaint([]);
246
210
- expect(marks).toEqual([
247
+ expectMarksToEqual([
248
'--render-start-512',
249
'--suspense-suspend-0-Example',
250
'--render-stop',
@@ -217,10 +254,10 @@ describe('SchedulingProfiler', () => {
254
'--commit-stop',
255
]);
256
220
- marks.splice(0);
257
+ clearPendingMarks();
258
259
await fakeSuspensePromise;
223
- expect(marks).toEqual(['--suspense-resolved-0-Example']);
260
+ expectMarksToEqual(['--suspense-resolved-0-Example']);
261
});
262
263
// @gate enableSchedulingProfiler
@@ -237,16 +274,16 @@ describe('SchedulingProfiler', () => {
274
{unstable_isConcurrent: true},
275
);
276
240
- expect(marks).toEqual([
277
+ expectMarksToEqual([
278
`--react-init-${ReactVersion}`,
279
'--schedule-render-512',
280
]);
281
245
- marks.splice(0);
282
+ clearPendingMarks();
283
284
expect(Scheduler).toFlushUntilNextPaint([]);
285
249
- expect(marks).toEqual([
286
+ expectMarksToEqual([
287
'--render-start-512',
288
'--suspense-suspend-0-Example',
289
'--render-stop',
@@ -256,10 +293,10 @@ describe('SchedulingProfiler', () => {
293
'--commit-stop',
294
]);
295
259
- marks.splice(0);
296
+ clearPendingMarks();
297
298
await expect(fakeSuspensePromise).rejects.toThrow();
262
- expect(marks).toEqual(['--suspense-rejected-0-Example']);
299
+ expectMarksToEqual(['--suspense-rejected-0-Example']);
300
});
301
302
// @gate enableSchedulingProfiler
@@ -276,16 +313,16 @@ describe('SchedulingProfiler', () => {
313
314
ReactTestRenderer.create(<Example />, {unstable_isConcurrent: true});
315
279
- expect(marks).toEqual([
316
+ expectMarksToEqual([
317
`--react-init-${ReactVersion}`,
318
'--schedule-render-512',
319
]);
320
284
- marks.splice(0);
321
+ clearPendingMarks();
322
323
expect(Scheduler).toFlushUntilNextPaint([]);
324
288
- expect(marks).toEqual([
325
+ expectMarksToEqual([
326
'--render-start-512',
327
'--render-stop',
328
'--commit-start-512',
@@ -313,16 +350,16 @@ describe('SchedulingProfiler', () => {
350
351
ReactTestRenderer.create(<Example />, {unstable_isConcurrent: true});
352
316
- expect(marks).toEqual([
353
+ expectMarksToEqual([
354
`--react-init-${ReactVersion}`,
355
'--schedule-render-512',
356
]);
357
321
- marks.splice(0);
358
+ clearPendingMarks();
359
360
expect(Scheduler).toFlushUntilNextPaint([]);
361
325
- expect(marks).toEqual([
362
+ expectMarksToEqual([
363
'--render-start-512',
364
'--render-stop',
365
'--commit-start-512',
@@ -351,12 +388,12 @@ describe('SchedulingProfiler', () => {
388
389
ReactTestRenderer.create(<Example />, {unstable_isConcurrent: true});
390
354
- expect(marks).toEqual([
391
+ expectMarksToEqual([
392
`--react-init-${ReactVersion}`,
393
'--schedule-render-512',
394
]);
395
359
- marks.splice(0);
396
+ clearPendingMarks();
397
398
expect(() => {
399
expect(Scheduler).toFlushUntilNextPaint([]);
@@ -364,8 +401,8 @@ describe('SchedulingProfiler', () => {
401
402
gate(({old}) =>
403
old
367
- ? expect(marks).toContain('--schedule-state-update-1024-Example')
368
- : expect(marks).toContain('--schedule-state-update-512-Example'),
404
+ ? expectMarksToContain('--schedule-state-update-1024-Example')
405
+ : expectMarksToContain('--schedule-state-update-512-Example'),
406
);
407
});
408
@@ -383,12 +420,12 @@ describe('SchedulingProfiler', () => {
420
421
ReactTestRenderer.create(<Example />, {unstable_isConcurrent: true});
422
386
- expect(marks).toEqual([
423
+ expectMarksToEqual([
424
`--react-init-${ReactVersion}`,
425
'--schedule-render-512',
426
]);
427
391
- marks.splice(0);
428
+ clearPendingMarks();
429
430
expect(() => {
431
expect(Scheduler).toFlushUntilNextPaint([]);
@@ -396,8 +433,8 @@ describe('SchedulingProfiler', () => {
433
434
gate(({old}) =>
435
old
399
- ? expect(marks).toContain('--schedule-forced-update-1024-Example')
400
- : expect(marks).toContain('--schedule-forced-update-512-Example'),
436
+ ? expectMarksToContain('--schedule-forced-update-1024-Example')
437
+ : expectMarksToContain('--schedule-forced-update-512-Example'),
438
);
439
});
440
@@ -413,16 +450,16 @@ describe('SchedulingProfiler', () => {
450
451
ReactTestRenderer.create(<Example />, {unstable_isConcurrent: true});
452
416
- expect(marks).toEqual([
453
+ expectMarksToEqual([
454
`--react-init-${ReactVersion}`,
455
'--schedule-render-512',
456
]);
457
421
- marks.splice(0);
458
+ clearPendingMarks();
459
460
expect(Scheduler).toFlushUntilNextPaint([]);
461
425
- expect(marks).toEqual([
462
+ expectMarksToEqual([
463
'--render-start-512',
464
'--render-stop',
465
'--commit-start-512',
@@ -451,7 +488,7 @@ describe('SchedulingProfiler', () => {
488
ReactTestRenderer.create(<Example />, {unstable_isConcurrent: true});
489
});
490
454
- expect(marks).toEqual([
491
+ expectMarksToEqual([
492
`--react-init-${ReactVersion}`,
493
'--schedule-render-512',
494
'--render-start-512',
@@ -486,8 +523,8 @@ describe('SchedulingProfiler', () => {
523
524
gate(({old}) =>
525
old
489
- ? expect(marks).toContain('--schedule-state-update-1024-Example')
490
- : expect(marks).toContain('--schedule-state-update-512-Example'),
526
+ ? expectMarksToContain('--schedule-state-update-1024-Example')
527
+ : expectMarksToContain('--schedule-state-update-512-Example'),
528
);
529
});
530
});
packages/shared/forks/ReactFeatureFlags.www-dynamic.js
+2
@@ -25,6 +25,8 @@ export const decoupleUpdatePriorityFromScheduler = __VARIANT__;
25
// NOTE: This feature will only work in DEV mode; all callsights are wrapped with __DEV__.
26
export const enableDebugTracing = __EXPERIMENTAL__;
27
28
+export const enableSchedulingProfiler = __VARIANT__;
29
+
30
// This only has an effect in the new reconciler. But also, the new reconciler
31
// is only enabled when __VARIANT__ is true. So this is set to the opposite of
32
// __VARIANT__ so that it's `false` when running against the new reconciler.
packages/shared/forks/ReactFeatureFlags.www.js
+2
-1
@@ -40,7 +40,8 @@ export const enableProfilerNestedUpdateScheduledHook =
40
__PROFILE__ && dynamicFeatureFlags.enableProfilerNestedUpdateScheduledHook;
41
42
// Logs additional User Timing API marks for use with an experimental profiling tool.
43
-export const enableSchedulingProfiler = __PROFILE__;
43
+export const enableSchedulingProfiler =
44
+ __PROFILE__ && dynamicFeatureFlags.enableSchedulingProfiler;
45
46
// Note: we'll want to remove this when we to userland implementation.
47
// For now, we'll turn it on for everyone because it's *already* on for everyone in practice.