Update user timing to record when we are about to commit (#12384)
* Update user timing to record when we are about to commit **what is the change?:** After repeatedly logging '(React Tree Reconciliation)' we vary the message slightly for the last reconciliation, which happens right before we commit. **why make this change?:** When debugging performance in the devtools it will be helpful if we can quickly see where the 'commit' happens in a potentially long list of sliced '(React Tree Reconciliation)' logs. **test plan:** Built and ran one of the fixtures. Also ran the unit test. (Flarnie will insert a screenshot) * Ran prettier * Fixes in response to code review * Update snapshot tests * Move isWorking assignment out of branches to top * Stricter type for stopWorkLoopTimer args
Flarnie Marchan committed
Apr 2, 2018 at 15:27 UTC
7a27ebd52a3025a946c67eaf84d2646fd307cb44
3 files changed
+53
-43
packages/react-reconciler/src/ReactDebugFiberPerf.js
+8
-6
@@ -369,7 +369,10 @@ export function startWorkLoopTimer(nextUnitOfWork: Fiber | null): void {
369
}
370
}
371
372
-export function stopWorkLoopTimer(interruptedBy: Fiber | null): void {
372
+export function stopWorkLoopTimer(
373
+ interruptedBy: Fiber | null,
374
+ didCompleteRoot: boolean,
375
+): void {
376
if (enableUserTimingAPI) {
377
if (!supportsUserTiming) {
378
return;
@@ -388,13 +391,12 @@ export function stopWorkLoopTimer(interruptedBy: Fiber | null): void {
391
warning = 'There were cascading updates';
392
}
393
commitCountInCurrentWorkLoop = 0;
394
+ let label = didCompleteRoot
395
+ ? '(React Tree Reconciliation: Completed Root)'
396
+ : '(React Tree Reconciliation: Yielded)';
397
// Pause any measurements until the next loop.
398
pauseTimers();
393
- endMark(
394
- '(React Tree Reconciliation)',
395
- '(React Tree Reconciliation)',
396
- warning,
397
- );
399
+ endMark(label, '(React Tree Reconciliation)', warning);
400
}
401
}
402
packages/react-reconciler/src/ReactFiberScheduler.js
+10
-2
@@ -958,12 +958,13 @@ export default function<T, P, I, TI, HI, PI, C, CC, CX, PL>(
958
} while (true);
959
960
// We're done performing work. Time to clean up.
961
- stopWorkLoopTimer(interruptedBy);
962
- interruptedBy = null;
961
+ let didCompleteRoot = false;
962
isWorking = false;
963
964
// Yield back to main thread.
965
if (didFatal) {
966
+ stopWorkLoopTimer(interruptedBy, didCompleteRoot);
967
+ interruptedBy = null;
968
// There was a fatal error.
969
if (__DEV__) {
970
stack.resetStackAfterFatalErrorInDev();
@@ -972,12 +973,17 @@ export default function<T, P, I, TI, HI, PI, C, CC, CX, PL>(
973
} else if (nextUnitOfWork === null) {
974
// We reached the root.
975
if (isRootReadyForCommit) {
976
+ didCompleteRoot = true;
977
+ stopWorkLoopTimer(interruptedBy, didCompleteRoot);
978
+ interruptedBy = null;
979
// The root successfully completed. It's ready for commit.
980
root.pendingCommitExpirationTime = expirationTime;
981
const finishedWork = root.current.alternate;
982
return finishedWork;
983
} else {
984
// The root did not complete.
985
+ stopWorkLoopTimer(interruptedBy, didCompleteRoot);
986
+ interruptedBy = null;
987
invariant(
988
false,
989
'Expired work should have completed. This error is likely caused ' +
@@ -985,6 +991,8 @@ export default function<T, P, I, TI, HI, PI, C, CC, CX, PL>(
991
);
992
}
993
} else {
994
+ stopWorkLoopTimer(interruptedBy, didCompleteRoot);
995
+ interruptedBy = null;
996
// There's more work to do, but we ran out of time. Yield back to
997
// the renderer.
998
return null;
packages/react-reconciler/src/__tests__/__snapshots__/ReactIncrementalPerf-test.internal.js.snap
+35
-35
@@ -4,7 +4,7 @@ exports[`ReactDebugFiberPerf captures all lifecycles 1`] = `
4
"⚛ (Waiting for async callback... will force flush in 5230 ms)
5
6
// Mount
7
-⚛ (React Tree Reconciliation)
7
+⚛ (React Tree Reconciliation: Completed Root)
8
⚛ AllLifecycles [mount]
9
⚛ AllLifecycles.componentWillMount
10
⚛ AllLifecycles.getChildContext
@@ -18,7 +18,7 @@ exports[`ReactDebugFiberPerf captures all lifecycles 1`] = `
18
⚛ (Waiting for async callback... will force flush in 5230 ms)
19
20
// Update
21
-⚛ (React Tree Reconciliation)
21
+⚛ (React Tree Reconciliation: Completed Root)
22
⚛ AllLifecycles [update]
23
⚛ AllLifecycles.componentWillReceiveProps
24
⚛ AllLifecycles.shouldComponentUpdate
@@ -34,7 +34,7 @@ exports[`ReactDebugFiberPerf captures all lifecycles 1`] = `
34
⚛ (Waiting for async callback... will force flush in 5230 ms)
35
36
// Unmount
37
-⚛ (React Tree Reconciliation)
37
+⚛ (React Tree Reconciliation: Completed Root)
38
39
⚛ (Committing Changes)
40
⚛ (Committing Snapshot Effects: 0 Total)
@@ -48,7 +48,7 @@ exports[`ReactDebugFiberPerf deduplicates lifecycle names during commit to reduc
48
"⚛ (Waiting for async callback... will force flush in 5230 ms)
49
50
// The commit phase should mention A and B just once
51
-⚛ (React Tree Reconciliation)
51
+⚛ (React Tree Reconciliation: Completed Root)
52
⚛ Parent [update]
53
⚛ A [update]
54
⚛ B [update]
@@ -66,7 +66,7 @@ exports[`ReactDebugFiberPerf deduplicates lifecycle names during commit to reduc
66
67
// Because of deduplication, we don't know B was cascading,
68
// but we should still see the warning for the commit phase.
69
-⚛ (React Tree Reconciliation)
69
+⚛ (React Tree Reconciliation: Completed Root)
70
⚛ Parent [update]
71
⚛ A [update]
72
⚛ B [update]
@@ -80,7 +80,7 @@ exports[`ReactDebugFiberPerf deduplicates lifecycle names during commit to reduc
80
⚛ A.componentDidUpdate
81
⚛ B.componentDidUpdate
82
83
-⚛ (React Tree Reconciliation)
83
+⚛ (React Tree Reconciliation: Completed Root)
84
⚛ B [update]
85
86
⚛ (Committing Changes)
@@ -92,7 +92,7 @@ exports[`ReactDebugFiberPerf deduplicates lifecycle names during commit to reduc
92
`;
93
94
exports[`ReactDebugFiberPerf does not schedule an extra callback if setState is called during a synchronous commit phase 1`] = `
95
-"⚛ (React Tree Reconciliation)
95
+"⚛ (React Tree Reconciliation: Completed Root)
96
⚛ Component [mount]
97
98
⛔ (Committing Changes) Warning: Lifecycle hook scheduled a cascading update
@@ -101,7 +101,7 @@ exports[`ReactDebugFiberPerf does not schedule an extra callback if setState is
101
⚛ (Calling Lifecycle Methods: 1 Total)
102
⛔ Component.componentDidMount Warning: Scheduled a cascading update
103
104
-⚛ (React Tree Reconciliation)
104
+⚛ (React Tree Reconciliation: Completed Root)
105
⚛ Component [update]
106
107
⚛ (Committing Changes)
@@ -115,7 +115,7 @@ exports[`ReactDebugFiberPerf does not treat setState from cWM or cWRP as cascadi
115
"⚛ (Waiting for async callback... will force flush in 5230 ms)
116
117
// Should not print a warning
118
-⚛ (React Tree Reconciliation)
118
+⚛ (React Tree Reconciliation: Completed Root)
119
⚛ Parent [mount]
120
⚛ NotCascading [mount]
121
⚛ NotCascading.componentWillMount
@@ -128,7 +128,7 @@ exports[`ReactDebugFiberPerf does not treat setState from cWM or cWRP as cascadi
128
⚛ (Waiting for async callback... will force flush in 5230 ms)
129
130
// Should not print a warning
131
-⚛ (React Tree Reconciliation)
131
+⚛ (React Tree Reconciliation: Completed Root)
132
⚛ Parent [update]
133
⚛ NotCascading [update]
134
⚛ NotCascading.componentWillReceiveProps
@@ -144,7 +144,7 @@ exports[`ReactDebugFiberPerf measures a simple reconciliation 1`] = `
144
"⚛ (Waiting for async callback... will force flush in 5230 ms)
145
146
// Mount
147
-⚛ (React Tree Reconciliation)
147
+⚛ (React Tree Reconciliation: Completed Root)
148
⚛ Parent [mount]
149
⚛ Child [mount]
150
@@ -156,7 +156,7 @@ exports[`ReactDebugFiberPerf measures a simple reconciliation 1`] = `
156
⚛ (Waiting for async callback... will force flush in 5230 ms)
157
158
// Update
159
-⚛ (React Tree Reconciliation)
159
+⚛ (React Tree Reconciliation: Completed Root)
160
⚛ Parent [update]
161
⚛ Child [update]
162
@@ -168,7 +168,7 @@ exports[`ReactDebugFiberPerf measures a simple reconciliation 1`] = `
168
⚛ (Waiting for async callback... will force flush in 5230 ms)
169
170
// Unmount
171
-⚛ (React Tree Reconciliation)
171
+⚛ (React Tree Reconciliation: Completed Root)
172
173
⚛ (Committing Changes)
174
⚛ (Committing Snapshot Effects: 0 Total)
@@ -181,7 +181,7 @@ exports[`ReactDebugFiberPerf measures deferred work in chunks 1`] = `
181
"⚛ (Waiting for async callback... will force flush in 5230 ms)
182
183
// Start mounting Parent and A
184
-⚛ (React Tree Reconciliation)
184
+⚛ (React Tree Reconciliation: Yielded)
185
⚛ Parent [mount]
186
⚛ A [mount]
187
⚛ Child [mount]
@@ -189,14 +189,14 @@ exports[`ReactDebugFiberPerf measures deferred work in chunks 1`] = `
189
⚛ (Waiting for async callback... will force flush in 5230 ms)
190
191
// Mount B just a little (but not enough to memoize)
192
-⚛ (React Tree Reconciliation)
192
+⚛ (React Tree Reconciliation: Yielded)
193
⚛ Parent [mount]
194
⚛ B [mount]
195
196
⚛ (Waiting for async callback... will force flush in 5230 ms)
197
198
// Complete B and Parent
199
-⚛ (React Tree Reconciliation)
199
+⚛ (React Tree Reconciliation: Completed Root)
200
⚛ Parent [mount]
201
⚛ B [mount]
202
⚛ Child [mount]
@@ -210,7 +210,7 @@ exports[`ReactDebugFiberPerf measures deferred work in chunks 1`] = `
210
211
exports[`ReactDebugFiberPerf measures deprioritized work 1`] = `
212
"// Flush the parent
213
-⚛ (React Tree Reconciliation)
213
+⚛ (React Tree Reconciliation: Completed Root)
214
⚛ Parent [mount]
215
216
⚛ (Committing Changes)
@@ -221,7 +221,7 @@ exports[`ReactDebugFiberPerf measures deprioritized work 1`] = `
221
⚛ (Waiting for async callback... will force flush in 10737418210 ms)
222
223
// Flush the child
224
-⚛ (React Tree Reconciliation)
224
+⚛ (React Tree Reconciliation: Completed Root)
225
⚛ Child [mount]
226
227
⚛ (Committing Changes)
@@ -235,13 +235,13 @@ exports[`ReactDebugFiberPerf recovers from caught errors 1`] = `
235
"⚛ (Waiting for async callback... will force flush in 5230 ms)
236
237
// Stop on Baddie and restart from Boundary
238
-⚛ (React Tree Reconciliation)
238
+⚛ (React Tree Reconciliation: Yielded)
239
⚛ Parent [mount]
240
⛔ Boundary [mount] Warning: An error was thrown inside this error boundary
241
⚛ Parent [mount]
242
⚛ Baddie [mount]
243
244
-⚛ (React Tree Reconciliation)
244
+⚛ (React Tree Reconciliation: Completed Root)
245
⚛ Parent [mount]
246
⚛ Boundary [mount]
247
@@ -250,7 +250,7 @@ exports[`ReactDebugFiberPerf recovers from caught errors 1`] = `
250
⚛ (Committing Host Effects: 2 Total)
251
⚛ (Calling Lifecycle Methods: 0 Total)
252
253
-⚛ (React Tree Reconciliation)
253
+⚛ (React Tree Reconciliation: Completed Root)
254
⚛ Boundary [update]
255
⚛ ErrorReport [mount]
256
@@ -265,11 +265,11 @@ exports[`ReactDebugFiberPerf recovers from fatal errors 1`] = `
265
"⚛ (Waiting for async callback... will force flush in 5230 ms)
266
267
// Will fatal
268
-⚛ (React Tree Reconciliation)
268
+⚛ (React Tree Reconciliation: Yielded)
269
⚛ Parent [mount]
270
⚛ Baddie [mount]
271
272
-⚛ (React Tree Reconciliation)
272
+⚛ (React Tree Reconciliation: Completed Root)
273
274
⚛ (Committing Changes)
275
⚛ (Committing Snapshot Effects: 0 Total)
@@ -279,7 +279,7 @@ exports[`ReactDebugFiberPerf recovers from fatal errors 1`] = `
279
⚛ (Waiting for async callback... will force flush in 5230 ms)
280
281
// Will reconcile from a clean state
282
-⚛ (React Tree Reconciliation)
282
+⚛ (React Tree Reconciliation: Completed Root)
283
⚛ Parent [mount]
284
⚛ Child [mount]
285
@@ -294,7 +294,7 @@ exports[`ReactDebugFiberPerf skips parents during setState 1`] = `
294
"⚛ (Waiting for async callback... will force flush in 5230 ms)
295
296
// Should include just A and B, no Parents
297
-⚛ (React Tree Reconciliation)
297
+⚛ (React Tree Reconciliation: Completed Root)
298
⚛ A [update]
299
⚛ B [update]
300
@@ -308,7 +308,7 @@ exports[`ReactDebugFiberPerf skips parents during setState 1`] = `
308
exports[`ReactDebugFiberPerf supports portals 1`] = `
309
"⚛ (Waiting for async callback... will force flush in 5230 ms)
310
311
-⚛ (React Tree Reconciliation)
311
+⚛ (React Tree Reconciliation: Completed Root)
312
⚛ Parent [mount]
313
⚛ Child [mount]
314
@@ -322,7 +322,7 @@ exports[`ReactDebugFiberPerf supports portals 1`] = `
322
exports[`ReactDebugFiberPerf supports returns 1`] = `
323
"⚛ (Waiting for async callback... will force flush in 5230 ms)
324
325
-⚛ (React Tree Reconciliation)
325
+⚛ (React Tree Reconciliation: Completed Root)
326
⚛ App [mount]
327
⚛ CoParent [mount]
328
⚛ Indirection [mount]
@@ -341,18 +341,18 @@ exports[`ReactDebugFiberPerf supports returns 1`] = `
341
exports[`ReactDebugFiberPerf warns if an in-progress update is interrupted 1`] = `
342
"⚛ (Waiting for async callback... will force flush in 5230 ms)
343
344
-⚛ (React Tree Reconciliation)
344
+⚛ (React Tree Reconciliation: Yielded)
345
⚛ Foo [mount]
346
347
⚛ (Waiting for async callback... will force flush in 5230 ms)
348
- ⛔ (React Tree Reconciliation) Warning: A top-level update interrupted the previous render
348
+ ⛔ (React Tree Reconciliation: Completed Root) Warning: A top-level update interrupted the previous render
349
⚛ Foo [mount]
350
⚛ (Committing Changes)
351
⚛ (Committing Snapshot Effects: 0 Total)
352
⚛ (Committing Host Effects: 1 Total)
353
⚛ (Calling Lifecycle Methods: 0 Total)
354
355
-⚛ (React Tree Reconciliation)
355
+⚛ (React Tree Reconciliation: Completed Root)
356
357
⚛ (Committing Changes)
358
⚛ (Committing Snapshot Effects: 0 Total)
@@ -364,7 +364,7 @@ exports[`ReactDebugFiberPerf warns if an in-progress update is interrupted 1`] =
364
exports[`ReactDebugFiberPerf warns if async work expires (starvation) 1`] = `
365
"⛔ (Waiting for async callback... will force flush in 5230 ms) Warning: React was blocked by main thread
366
367
-⚛ (React Tree Reconciliation)
367
+⚛ (React Tree Reconciliation: Completed Root)
368
⚛ Foo [mount]
369
370
⚛ (Committing Changes)
@@ -378,7 +378,7 @@ exports[`ReactDebugFiberPerf warns on cascading renders from setState 1`] = `
378
"⚛ (Waiting for async callback... will force flush in 5230 ms)
379
380
// Should print a warning
381
-⚛ (React Tree Reconciliation)
381
+⚛ (React Tree Reconciliation: Completed Root)
382
⚛ Parent [mount]
383
⚛ Cascading [mount]
384
@@ -388,7 +388,7 @@ exports[`ReactDebugFiberPerf warns on cascading renders from setState 1`] = `
388
⚛ (Calling Lifecycle Methods: 1 Total)
389
⛔ Cascading.componentDidMount Warning: Scheduled a cascading update
390
391
-⚛ (React Tree Reconciliation)
391
+⚛ (React Tree Reconciliation: Completed Root)
392
⚛ Cascading [update]
393
394
⚛ (Committing Changes)
@@ -402,7 +402,7 @@ exports[`ReactDebugFiberPerf warns on cascading renders from top-level render 1`
402
"⚛ (Waiting for async callback... will force flush in 5230 ms)
403
404
// Rendering the first root
405
-⚛ (React Tree Reconciliation)
405
+⚛ (React Tree Reconciliation: Completed Root)
406
⚛ Cascading [mount]
407
408
⛔ (Committing Changes) Warning: Lifecycle hook scheduled a cascading update
@@ -412,7 +412,7 @@ exports[`ReactDebugFiberPerf warns on cascading renders from top-level render 1`
412
⛔ Cascading.componentDidMount Warning: Scheduled a cascading update
413
414
// Scheduling another root from componentDidMount
415
-⚛ (React Tree Reconciliation)
415
+⚛ (React Tree Reconciliation: Completed Root)
416
⚛ Child [mount]
417
418
⚛ (Committing Changes)