@samitouri / QOS-React / commits / 13965b4d30

Interaction tracking ref-counting bug fixes (WIP) (#13590)

* Added new (failing) suspense+interaction tests * Add new tracing+suspense test harness fixture * Refactored interaction tracing to fix ref counting bug

Brian Vaughn committed Sep 25, 2018 at 09:27 UTC 13965b4d3016de0ed28e73a38e60c18259bc2c23
7 files changed +925 -225
fixtures/tracing/test.html new
+21
@@ -0,0 +1,21 @@
1 +<!DOCTYPE html>
2 +<html style="width: 100%; height: 100%;">
3 + <head>
4 + <meta charset="utf-8">
5 + <title>Test tracing UMD</title>
6 + <style>
7 + body {
8 + font-family: sans-serif;
9 + }
10 + </style>
11 + </head>
12 + <body>
13 + <div id="root"></div>
14 + <!-- Load the tracing API before react to test that it's lazily evaluated -->
15 + <script src="../../build/node_modules/scheduler/umd/scheduler.development.js"></script>
16 + <script src="../../build/node_modules/scheduler/umd/scheduler-tracing.development.js"></script>
17 + <script src="../../build/node_modules/react/umd/react.development.js"></script>
18 + <script src="../../build/node_modules/react-dom/umd/react-dom.development.js"></script>
19 + <script src="./test.js"></script>
20 + </body>
21 +</html>
fixtures/tracing/test.js new
+103
@@ -0,0 +1,103 @@
1 +const {createElement, Component, Placeholder} = React;
2 +const {unstable_createRoot: createRoot} = ReactDOM;
3 +const {
4 + unstable_subscribe: subscribe,
5 + unstable_trace: trace,
6 + unstable_wrap: wrap,
7 +} = SchedulerTracing;
8 +
9 +const createLogger = (backgroundColor, color, enabled) => (
10 + message,
11 + ...args
12 +) => {
13 + if (enabled === false) return;
14 + console.groupCollapsed(
15 + `%c${message}`,
16 + `background-color: ${backgroundColor}; color: ${color}; padding: 2px 4px;`,
17 + ...args
18 + );
19 + console.log(
20 + new Error('stack').stack
21 + .split('\n')
22 + .slice(2)
23 + .join('\n')
24 + );
25 + console.groupEnd();
26 +};
27 +
28 +window.log = {
29 + app: createLogger('#37474f', '#fff'),
30 + interaction: createLogger('#6a1b9a', '#fff'),
31 + react: createLogger('#ff5722', '#fff'),
32 + tracing: createLogger('#2962ff', '#fff'),
33 + work: createLogger('#e1bee7', '#000'),
34 +};
35 +
36 +// Fake suspense
37 +const resolvedValues = {};
38 +const read = key => {
39 + if (!resolvedValues[key]) {
40 + log.app(`Suspending for "${key}" ...`);
41 + throw new Promise(
42 + wrap(resolve => {
43 + setTimeout(
44 + wrap(() => {
45 + log.app(`Loaded "${key}" ...`);
46 + resolvedValues[key] = true;
47 + resolve(key);
48 + }),
49 + 1000
50 + );
51 + })
52 + );
53 + }
54 + return key;
55 +};
56 +
57 +const TestApp = () =>
58 + createElement(
59 + Placeholder,
60 + {delayMs: 100, fallback: createElement(PlaceholderText)},
61 + createElement(SuspendingChild, {text: 'foo'}),
62 + createElement(SuspendingChild, {text: 'bar'}),
63 + createElement(SuspendingChild, {text: 'baz'})
64 + );
65 +
66 +const PlaceholderText = () => 'Loading ...';
67 +
68 +const SuspendingChild = ({text}) => {
69 + const resolvedValue = read(text);
70 + return resolvedValue;
71 +};
72 +
73 +subscribe({
74 + onInteractionScheduledWorkCompleted: interaction =>
75 + log.interaction(
76 + 'onInteractionScheduledWorkCompleted',
77 + JSON.stringify(interaction)
78 + ),
79 + onInteractionTraced: interaction =>
80 + log.interaction('onInteractionTraced', JSON.stringify(interaction)),
81 + onWorkCanceled: interactions =>
82 + log.work('onWorkCanceled', JSON.stringify(Array.from(interactions))),
83 + onWorkScheduled: interactions =>
84 + log.work('onWorkScheduled', JSON.stringify(Array.from(interactions))),
85 + onWorkStarted: interactions =>
86 + log.work('onWorkStarted', JSON.stringify(Array.from(interactions))),
87 + onWorkStopped: interactions =>
88 + log.work('onWorkStopped', JSON.stringify(Array.from(interactions))),
89 +});
90 +
91 +const element = document.getElementById('root');
92 +trace('initial_render', performance.now(), () => {
93 + const root = createRoot(element);
94 + const batch = root.createBatch();
95 + log.app('batch.render()');
96 + batch.render(createElement(TestApp));
97 + batch.then(
98 + wrap(() => {
99 + log.app('batch.commit()');
100 + batch.commit();
101 + })
102 + );
103 +});
packages/react-reconciler/src/ReactFiberBeginWork.js
+9
@@ -41,6 +41,7 @@ import {
41 Update,
42 Ref,
43 } from 'shared/ReactSideEffectTags';
44 +import {captureWillSyncRenderPlaceholder} from './ReactFiberScheduler';
45 import ReactSharedInternals from 'shared/ReactSharedInternals';
46 import {
47 enableGetDerivedStateFromCatch,
@@ -48,6 +49,7 @@ import {
49 debugRenderPhaseSideEffects,
50 debugRenderPhaseSideEffectsForStrictMode,
51 enableProfilerTimer,
52 + enableSchedulerTracing,
53 } from 'shared/ReactFeatureFlags';
54 import invariant from 'shared/invariant';
55 import getComponentName from 'shared/getComponentName';
@@ -825,6 +827,13 @@ function updatePlaceholderComponent(
827
828 let nextDidTimeout;
829 if (current !== null && workInProgress.updateQueue !== null) {
830 + if (enableSchedulerTracing) {
831 + // Handle special case of rendering a Placeholder for a sync, suspended tree.
832 + // We flag this to properly trace and count interactions.
833 + // Otherwise interaction pending count will be decremented too many times.
834 + captureWillSyncRenderPlaceholder();
835 + }
836 +
837 // We're outside strict mode. Something inside this Placeholder boundary
838 // suspended during the last commit. Switch to the placholder.
839 workInProgress.updateQueue = null;
packages/react-reconciler/src/ReactFiberScheduler.js
+93 -107
@@ -260,7 +260,8 @@ let interruptedBy: Fiber | null = null;
260
261 // Do not decrement interaction counts in the event of suspense timeouts.
262 // This would lead to prematurely calling the interaction-complete hook.
263 -let suspenseDidTimeout: boolean = false;
263 +// Instead we wait until the suspended promise has resolved.
264 +let nextRenderIncludesTimedOutPlaceholder: boolean = false;
265
266 let stashedWorkInProgressProperties;
267 let replayUnitOfWork;
@@ -566,31 +567,11 @@ function commitRoot(root: FiberRoot, finishedWork: Fiber): void {
567 markCommittedPriorityLevels(root, earliestRemainingTimeBeforeCommit);
568
569 let prevInteractions: Set<Interaction> = (null: any);
569 - let committedInteractions: Array<Interaction> = enableSchedulerTracing
570 - ? []
571 - : (null: any);
570 if (enableSchedulerTracing) {
571 // Restore any pending interactions at this point,
572 // So that cascading work triggered during the render phase will be accounted for.
573 prevInteractions = __interactionsRef.current;
574 __interactionsRef.current = root.memoizedInteractions;
577 -
578 - // We are potentially finished with the current batch of interactions.
579 - // So we should clear them out of the pending interaction map.
580 - // We do this at the start of commit in case cascading work is scheduled by commit phase lifecycles.
581 - // In that event, interaction data may be added back into the pending map for a future commit.
582 - // We also store the interactions we are about to commit so that we can notify subscribers after we're done.
583 - // These are stored as an Array rather than a Set,
584 - // Because the same interaction may be pending for multiple expiration times,
585 - // In which case it's important that we decrement the count the right number of times after finishing.
586 - root.pendingInteractionMap.forEach(
587 - (scheduledInteractions, scheduledExpirationTime) => {
588 - if (scheduledExpirationTime <= committedExpirationTime) {
589 - committedInteractions.push(...Array.from(scheduledInteractions));
590 - root.pendingInteractionMap.delete(scheduledExpirationTime);
591 - }
592 - },
593 - );
575 }
576
577 // Reset this to null before calling lifecycles
@@ -789,27 +770,41 @@ function commitRoot(root: FiberRoot, finishedWork: Fiber): void {
770 unhandledError = error;
771 }
772 } finally {
792 - // Don't update interaction counts if we're frozen due to suspense.
793 - // In this case, we can skip the completed-work check entirely.
794 - if (!suspenseDidTimeout) {
795 - // Now that we're done, check the completed batch of interactions.
796 - // If no more work is outstanding for a given interaction,
797 - // We need to notify the subscribers that it's finished.
798 - committedInteractions.forEach(interaction => {
799 - interaction.__count--;
800 - if (subscriber !== null && interaction.__count === 0) {
801 - try {
802 - subscriber.onInteractionScheduledWorkCompleted(interaction);
803 - } catch (error) {
804 - // It's not safe for commitRoot() to throw.
805 - // Store the error for now and we'll re-throw in finishRendering().
806 - if (!hasUnhandledError) {
807 - hasUnhandledError = true;
808 - unhandledError = error;
809 - }
773 + if (!nextRenderIncludesTimedOutPlaceholder) {
774 + // Clear completed interactions from the pending Map.
775 + // Unless the render was suspended or cascading work was scheduled,
776 + // In which case– leave pending interactions until the subsequent render.
777 + const pendingInteractionMap = root.pendingInteractionMap;
778 + pendingInteractionMap.forEach(
779 + (scheduledInteractions, scheduledExpirationTime) => {
780 + // Only decrement the pending interaction count if we're done.
781 + // If there's still work at the current priority,
782 + // That indicates that we are waiting for suspense data.
783 + if (
784 + earliestRemainingTimeAfterCommit === NoWork ||
785 + scheduledExpirationTime < earliestRemainingTimeAfterCommit
786 + ) {
787 + pendingInteractionMap.delete(scheduledExpirationTime);
788 +
789 + scheduledInteractions.forEach(interaction => {
790 + interaction.__count--;
791 +
792 + if (subscriber !== null && interaction.__count === 0) {
793 + try {
794 + subscriber.onInteractionScheduledWorkCompleted(interaction);
795 + } catch (error) {
796 + // It's not safe for commitRoot() to throw.
797 + // Store the error for now and we'll re-throw in finishRendering().
798 + if (!hasUnhandledError) {
799 + hasUnhandledError = true;
800 + unhandledError = error;
801 + }
802 + }
803 + }
804 + });
805 }
811 - }
812 - });
806 + },
807 + );
808 }
809 }
810 }
@@ -1174,14 +1169,6 @@ function renderRoot(
1169
1170 const expirationTime = root.nextExpirationTimeToWorkOn;
1171
1177 - let prevInteractions: Set<Interaction> = (null: any);
1178 - if (enableSchedulerTracing) {
1179 - // We're about to start new traced work.
1180 - // Restore pending interactions so cascading work triggered during the render phase will be accounted for.
1181 - prevInteractions = __interactionsRef.current;
1182 - __interactionsRef.current = root.memoizedInteractions;
1183 - }
1184 -
1172 // Check if we're starting from a fresh stack, or if we're resuming from
1173 // previously yielded work.
1174 if (
@@ -1201,6 +1188,11 @@ function renderRoot(
1188 root.pendingCommitExpirationTime = NoWork;
1189
1190 if (enableSchedulerTracing) {
1191 + // Reset this flag once we start rendering a new root or at a new priority.
1192 + // This might indicate that suspended work has completed.
1193 + // If not, the flag will be reset.
1194 + nextRenderIncludesTimedOutPlaceholder = false;
1195 +
1196 // Determine which interactions this batch of work currently includes,
1197 // So that we can accurately attribute time spent working on it,
1198 // And so that cascading work triggered during the render phase will be associated with it.
@@ -1244,6 +1236,14 @@ function renderRoot(
1236 }
1237 }
1238
1239 + let prevInteractions: Set<Interaction> = (null: any);
1240 + if (enableSchedulerTracing) {
1241 + // We're about to start new traced work.
1242 + // Restore pending interactions so cascading work triggered during the render phase will be accounted for.
1243 + prevInteractions = __interactionsRef.current;
1244 + __interactionsRef.current = root.memoizedInteractions;
1245 + }
1246 +
1247 let didFatal = false;
1248
1249 startWorkLoopTimer(nextUnitOfWork);
@@ -1403,6 +1403,9 @@ function renderRoot(
1403
1404 if (enableSuspense && !isExpired && nextLatestAbsoluteTimeoutMs !== -1) {
1405 // The tree was suspended.
1406 + if (enableSchedulerTracing) {
1407 + nextRenderIncludesTimedOutPlaceholder = true;
1408 + }
1409 const suspendedExpirationTime = expirationTime;
1410 markSuspendedPriorityLevel(root, suspendedExpirationTime);
1411
@@ -1600,6 +1603,7 @@ function retrySuspendedRoot(
1603 if (isPriorityLevelSuspended(root, suspendedTime)) {
1604 // Ping at the original level
1605 retryTime = suspendedTime;
1606 +
1607 markPingedPriorityLevel(root, retryTime);
1608 } else {
1609 // Placeholder already timed out. Compute a new expiration time
@@ -1611,18 +1615,7 @@ function retrySuspendedRoot(
1615 scheduleWorkToRoot(fiber, retryTime);
1616 const rootExpirationTime = root.expirationTime;
1617 if (rootExpirationTime !== NoWork) {
1614 - if (enableSchedulerTracing) {
1615 - // Restore previous interactions so that new work is associated with them.
1616 - let prevInteractions = __interactionsRef.current;
1617 - __interactionsRef.current = root.memoizedInteractions;
1618 - // Because suspense timeouts do not decrement the interaction count,
1619 - // Continued suspense work should also not increment the count.
1620 - storeInteractionsForExpirationTime(root, rootExpirationTime, false);
1621 - requestWork(root, rootExpirationTime);
1622 - __interactionsRef.current = prevInteractions;
1623 - } else {
1624 - requestWork(root, rootExpirationTime);
1625 - }
1618 + requestWork(root, rootExpirationTime);
1619 }
1620 }
1621 }
@@ -1677,49 +1670,6 @@ function scheduleWorkToRoot(fiber: Fiber, expirationTime): FiberRoot | null {
1670 return null;
1671 }
1672
1680 -function storeInteractionsForExpirationTime(
1681 - root: FiberRoot,
1682 - expirationTime: ExpirationTime,
1683 - updateInteractionCounts: boolean,
1684 -): void {
1685 - if (!enableSchedulerTracing) {
1686 - return;
1687 - }
1688 -
1689 - const interactions = __interactionsRef.current;
1690 - if (interactions.size > 0) {
1691 - const pendingInteractions = root.pendingInteractionMap.get(expirationTime);
1692 - if (pendingInteractions != null) {
1693 - interactions.forEach(interaction => {
1694 - if (updateInteractionCounts && !pendingInteractions.has(interaction)) {
1695 - // Update the pending async work count for previously unscheduled interaction.
1696 - interaction.__count++;
1697 - }
1698 -
1699 - pendingInteractions.add(interaction);
1700 - });
1701 - } else {
1702 - root.pendingInteractionMap.set(expirationTime, new Set(interactions));
1703 -
1704 - // Update the pending async work count for the current interactions.
1705 - if (updateInteractionCounts) {
1706 - interactions.forEach(interaction => {
1707 - interaction.__count++;
1708 - });
1709 - }
1710 - }
1711 -
1712 - const subscriber = __subscriberRef.current;
1713 - if (subscriber !== null) {
1714 - const threadID = computeThreadID(
1715 - expirationTime,
1716 - root.interactionThreadID,
1717 - );
1718 - subscriber.onWorkScheduled(interactions, threadID);
1719 - }
1720 - }
1721 -}
1722 -
1673 function scheduleWork(fiber: Fiber, expirationTime: ExpirationTime) {
1674 recordScheduleUpdate();
1675
@@ -1742,7 +1692,37 @@ function scheduleWork(fiber: Fiber, expirationTime: ExpirationTime) {
1692 }
1693
1694 if (enableSchedulerTracing) {
1745 - storeInteractionsForExpirationTime(root, expirationTime, true);
1695 + const interactions = __interactionsRef.current;
1696 + if (interactions.size > 0) {
1697 + const pendingInteractionMap = root.pendingInteractionMap;
1698 + const pendingInteractions = pendingInteractionMap.get(expirationTime);
1699 + if (pendingInteractions != null) {
1700 + interactions.forEach(interaction => {
1701 + if (!pendingInteractions.has(interaction)) {
1702 + // Update the pending async work count for previously unscheduled interaction.
1703 + interaction.__count++;
1704 + }
1705 +
1706 + pendingInteractions.add(interaction);
1707 + });
1708 + } else {
1709 + pendingInteractionMap.set(expirationTime, new Set(interactions));
1710 +
1711 + // Update the pending async work count for the current interactions.
1712 + interactions.forEach(interaction => {
1713 + interaction.__count++;
1714 + });
1715 + }
1716 +
1717 + const subscriber = __subscriberRef.current;
1718 + if (subscriber !== null) {
1719 + const threadID = computeThreadID(
1720 + expirationTime,
1721 + root.interactionThreadID,
1722 + );
1723 + subscriber.onWorkScheduled(interactions, threadID);
1724 + }
1725 + }
1726 }
1727
1728 if (
@@ -1935,9 +1915,8 @@ function onTimeout(root, finishedWork, suspendedExpirationTime) {
1915 if (enableSchedulerTracing) {
1916 // Don't update pending interaction counts for suspense timeouts,
1917 // Because we know we still need to do more work in this case.
1938 - suspenseDidTimeout = true;
1918 + nextRenderIncludesTimedOutPlaceholder = true;
1919 flushRoot(root, suspendedExpirationTime);
1940 - suspenseDidTimeout = false;
1920 } else {
1921 flushRoot(root, suspendedExpirationTime);
1922 }
@@ -2508,6 +2487,12 @@ function flushControlled(fn: () => mixed): void {
2487 }
2488 }
2489
2490 +function captureWillSyncRenderPlaceholder() {
2491 + if (enableSchedulerTracing) {
2492 + nextRenderIncludesTimedOutPlaceholder = true;
2493 + }
2494 +}
2495 +
2496 export {
2497 requestCurrentTime,
2498 computeExpirationForFiber,
@@ -2530,4 +2515,5 @@ export {
2515 interactiveUpdates,
2516 flushInteractiveUpdates,
2517 computeUniqueAsyncExpiration,
2518 + captureWillSyncRenderPlaceholder,
2519 };
packages/react-reconciler/src/ReactFiberUnwindWork.js
+9
@@ -36,6 +36,7 @@ import {
36 import {
37 enableGetDerivedStateFromCatch,
38 enableSuspense,
39 + enableSchedulerTracing,
40 } from 'shared/ReactFeatureFlags';
41 import {StrictMode, AsyncMode} from './ReactTypeOfMode';
42
@@ -60,6 +61,7 @@ import {
61 markLegacyErrorBoundaryAsFailed,
62 isAlreadyFailedLegacyErrorBoundary,
63 retrySuspendedRoot,
64 + captureWillSyncRenderPlaceholder,
65 } from './ReactFiberScheduler';
66 import {Sync} from './ReactFiberExpirationTime';
67
@@ -236,6 +238,13 @@ function throwException(
238 if ((workInProgress.mode & StrictMode) === NoEffect) {
239 workInProgress.effectTag |= UpdateEffect;
240
241 + if (enableSchedulerTracing) {
242 + // Handles the special case of unwinding a suspended sync render.
243 + // We flag this to properly trace and count interactions.
244 + // Otherwise interaction pending count will be decremented too many times.
245 + captureWillSyncRenderPlaceholder();
246 + }
247 +
248 // Unmount the source fiber's children
249 const nextChildren = null;
250 reconcileChildren(
packages/react/src/__tests__/ReactProfiler-test.internal.js
+516 -118
@@ -46,7 +46,9 @@ function loadModules({
46
47 if (useNoopRenderer) {
48 ReactNoop = require('react-noop-renderer');
49 + ReactTestRenderer = null;
50 } else {
51 + ReactNoop = null;
52 ReactTestRenderer = require('react-test-renderer');
53 ReactTestRenderer.unstable_setNowImplementation(mockNow);
54 }
@@ -1229,11 +1231,13 @@ describe('Profiler', () => {
1231 const getWorkForReactThreads = mockFn =>
1232 mockFn.mock.calls.filter(([interactions, threadID]) => threadID > 0);
1233
1232 - beforeEach(() => {
1234 + function loadModulesForTracing(params) {
1235 jest.resetModules();
1236
1237 loadModules({
1238 + enableSuspense: true,
1239 enableSchedulerTracing: true,
1240 + ...params,
1241 });
1242
1243 throwInOnInteractionScheduledWorkCompleted = false;
@@ -1273,7 +1277,9 @@ describe('Profiler', () => {
1277 onWorkStarted,
1278 onWorkStopped,
1279 });
1276 - });
1280 + }
1281 +
1282 + beforeEach(() => loadModulesForTracing());
1283
1284 describe('error handling', () => {
1285 it('should cover errors thrown in onWorkScheduled', () => {
@@ -1404,6 +1410,34 @@ describe('Profiler', () => {
1410 });
1411 });
1412
1413 + it('should properly trace work scheduled during the begin render phase', () => {
1414 + const callback = jest.fn();
1415 + let wrapped;
1416 + const Component = jest.fn(() => {
1417 + wrapped = SchedulerTracing.unstable_wrap(callback);
1418 + return null;
1419 + });
1420 +
1421 + let interaction;
1422 + SchedulerTracing.unstable_trace('event', mockNow(), () => {
1423 + const interactions = SchedulerTracing.unstable_getCurrent();
1424 + expect(interactions.size).toBe(1);
1425 + interaction = Array.from(interactions)[0];
1426 + ReactTestRenderer.create(<Component />);
1427 + });
1428 +
1429 + expect(Component).toHaveBeenCalledTimes(1);
1430 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
1431 + expect(callback).not.toHaveBeenCalled();
1432 +
1433 + wrapped();
1434 + expect(callback).toHaveBeenCalledTimes(1);
1435 + expect(onInteractionScheduledWorkCompleted).toHaveBeenCalledTimes(1);
1436 + expect(
1437 + onInteractionScheduledWorkCompleted,
1438 + ).toHaveBeenLastNotifiedOfInteraction(interaction);
1439 + });
1440 +
1441 it('should associate traced events with their subsequent commits', () => {
1442 let instance = null;
1443
@@ -2115,24 +2149,12 @@ describe('Profiler', () => {
2149 ]);
2150 });
2151
2118 - it('traces both the temporary placeholder and the finished render for an interaction', async () => {
2119 - jest.resetModules();
2120 -
2121 - loadModules({
2122 - useNoopRenderer: true,
2123 - enableSuspense: true,
2124 - enableSchedulerTracing: true,
2125 - });
2126 -
2127 - // Re-register since we've reloaded modules
2128 - SchedulerTracing.unstable_subscribe({
2129 - onInteractionScheduledWorkCompleted,
2130 - onInteractionTraced,
2131 - onWorkCanceled,
2132 - onWorkScheduled,
2133 - onWorkStarted,
2134 - onWorkStopped,
2135 - });
2152 + describe('suspense', () => {
2153 + let AsyncText;
2154 + let Text;
2155 + let TextResource;
2156 + let cache;
2157 + let resourcePromise;
2158
2159 function awaitableAdvanceTimers(ms) {
2160 jest.advanceTimersByTime(ms);
@@ -2142,124 +2164,500 @@ describe('Profiler', () => {
2164 });
2165 }
2166
2145 - const SimpleCacheProvider = require('simple-cache-provider');
2146 - let cache;
2147 - function invalidateCache() {
2148 - cache = SimpleCacheProvider.createCache(invalidateCache);
2167 + function yieldForRenderer(value) {
2168 + if (ReactNoop) {
2169 + ReactNoop.yield(value);
2170 + } else {
2171 + ReactTestRenderer.unstable_yield(value);
2172 + }
2173 }
2150 - invalidateCache();
2151 - const TextResource = SimpleCacheProvider.createResource(
2152 - ([text, ms = 0]) => {
2153 - return new Promise((resolve, reject) => {
2174 +
2175 + beforeEach(() => {
2176 + const SimpleCacheProvider = require('simple-cache-provider');
2177 + function invalidateCache() {
2178 + cache = SimpleCacheProvider.createCache(invalidateCache);
2179 + }
2180 + invalidateCache();
2181 +
2182 + resourcePromise = null;
2183 +
2184 + TextResource = SimpleCacheProvider.createResource(([text, ms = 0]) => {
2185 + resourcePromise = new Promise((resolve, reject) =>
2186 setTimeout(() => {
2155 - ReactNoop.yield(`Promise resolved [${text}]`);
2187 + yieldForRenderer(`Promise resolved [${text}]`);
2188 resolve(text);
2157 - }, ms);
2158 - });
2159 - },
2160 - ([text, ms]) => text,
2161 - );
2189 + }, ms),
2190 + );
2191 + return resourcePromise;
2192 + }, ([text, ms]) => text);
2193 +
2194 + AsyncText = ({ms, text}) => {
2195 + try {
2196 + TextResource.read(cache, [text, ms]);
2197 + yieldForRenderer(`AsyncText [${text}]`);
2198 + return text;
2199 + } catch (promise) {
2200 + if (typeof promise.then === 'function') {
2201 + yieldForRenderer(`Suspend [${text}]`);
2202 + } else {
2203 + yieldForRenderer(`Error [${text}]`);
2204 + }
2205 + throw promise;
2206 + }
2207 + };
2208
2163 - function Text(props) {
2164 - ReactNoop.yield(props.text);
2165 - return <span prop={props.text} />;
2166 - }
2209 + Text = ({text}) => {
2210 + yieldForRenderer(`Text [${text}]`);
2211 + return text;
2212 + };
2213 + });
2214
2168 - function span(prop) {
2169 - return {type: 'span', children: [], prop};
2170 - }
2215 + it('traces both the temporary placeholder and the finished render for an interaction', async () => {
2216 + loadModulesForTracing({useNoopRenderer: true});
2217 +
2218 + const interaction = {
2219 + id: 0,
2220 + name: 'initial render',
2221 + timestamp: mockNow(),
2222 + };
2223 +
2224 + const onRender = jest.fn();
2225 + SchedulerTracing.unstable_trace(interaction.name, mockNow(), () => {
2226 + ReactNoop.render(
2227 + <React.unstable_Profiler id="test-profiler" onRender={onRender}>
2228 + <React.Placeholder fallback={<Text text="Loading..." />}>
2229 + <AsyncText text="Async" ms={20000} />
2230 + </React.Placeholder>
2231 + <Text text="Sync" />
2232 + </React.unstable_Profiler>,
2233 + );
2234 + });
2235 +
2236 + expect(onInteractionTraced).toHaveBeenCalledTimes(1);
2237 + expect(onInteractionTraced).toHaveBeenLastNotifiedOfInteraction(
2238 + interaction,
2239 + );
2240 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2241 + expect(getWorkForReactThreads(onWorkStarted)).toHaveLength(0);
2242 + expect(getWorkForReactThreads(onWorkStopped)).toHaveLength(0);
2243 +
2244 + expect(ReactNoop.flush()).toEqual([
2245 + 'Suspend [Async]',
2246 + 'Text [Loading...]',
2247 + 'Text [Sync]',
2248 + ]);
2249 + // The update hasn't expired yet, so we commit nothing.
2250 + expect(ReactNoop.getChildren()).toEqual([]);
2251 + expect(onRender).not.toHaveBeenCalled();
2252 +
2253 + // Advance both React's virtual time and Jest's timers by enough to expire
2254 + // the update, but not by enough to flush the suspending promise.
2255 + ReactNoop.expire(10000);
2256 + await awaitableAdvanceTimers(10000);
2257 + // No additional rendering work is required, since we already prepared
2258 + // the placeholder.
2259 + expect(ReactNoop.flushExpired()).toEqual([]);
2260 + // Should have committed the placeholder.
2261 + expect(ReactNoop.getChildren()).toEqual([
2262 + {text: 'Loading...'},
2263 + {text: 'Sync'},
2264 + ]);
2265 + expect(onRender).toHaveBeenCalledTimes(1);
2266 +
2267 + let call = onRender.mock.calls[0];
2268 + expect(call[0]).toEqual('test-profiler');
2269 + expect(call[6]).toMatchInteractions(
2270 + ReactFeatureFlags.enableSchedulerTracing ? [interaction] : [],
2271 + );
2272 +
2273 + expect(onInteractionTraced).toHaveBeenCalledTimes(1);
2274 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2275 +
2276 + // Once the promise resolves, we render the suspended view
2277 + await awaitableAdvanceTimers(10000);
2278 + expect(ReactNoop.flush()).toEqual([
2279 + 'Promise resolved [Async]',
2280 + 'AsyncText [Async]',
2281 + ]);
2282 + expect(ReactNoop.getChildren()).toEqual([
2283 + {text: 'Async'},
2284 + {text: 'Sync'},
2285 + ]);
2286 + expect(onRender).toHaveBeenCalledTimes(2);
2287 +
2288 + call = onRender.mock.calls[1];
2289 + expect(call[0]).toEqual('test-profiler');
2290 + expect(call[6]).toMatchInteractions(
2291 + ReactFeatureFlags.enableSchedulerTracing ? [interaction] : [],
2292 + );
2293 +
2294 + expect(onInteractionTraced).toHaveBeenCalledTimes(1);
2295 + expect(onInteractionScheduledWorkCompleted).toHaveBeenCalledTimes(1);
2296 + expect(
2297 + onInteractionScheduledWorkCompleted,
2298 + ).toHaveBeenLastNotifiedOfInteraction(interaction);
2299 + });
2300 +
2301 + it('does not prematurely complete for suspended sync renders', async () => {
2302 + const interaction = {
2303 + id: 0,
2304 + name: 'initial render',
2305 + timestamp: mockNow(),
2306 + };
2307 +
2308 + const onRender = jest.fn();
2309 + SchedulerTracing.unstable_trace(
2310 + interaction.name,
2311 + interaction.timestamp,
2312 + () => {
2313 + ReactTestRenderer.create(
2314 + <React.unstable_Profiler id="app" onRender={onRender}>
2315 + <React.Placeholder
2316 + delayMs={1000}
2317 + fallback={<Text text="loading" />}>
2318 + <AsyncText text="loaded" ms={2000} />
2319 + </React.Placeholder>
2320 + </React.unstable_Profiler>,
2321 + );
2322 + },
2323 + );
2324 +
2325 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2326 +
2327 + jest.runAllTimers();
2328 + await resourcePromise;
2329 +
2330 + expect(onInteractionScheduledWorkCompleted).toHaveBeenCalledTimes(1);
2331 + expect(
2332 + onInteractionScheduledWorkCompleted,
2333 + ).toHaveBeenLastNotifiedOfInteraction(interaction);
2334 + });
2335 +
2336 + it('traces cascading work after suspended sync renders', async () => {
2337 + let wrappedCascadingFn;
2338 + class AsyncComponentWithCascadingWork extends React.Component {
2339 + state = {
2340 + hasMounted: false,
2341 + };
2342 +
2343 + componentDidMount() {
2344 + wrappedCascadingFn = SchedulerTracing.unstable_wrap(() => {
2345 + this.setState({hasMounted: true});
2346 + });
2347 + }
2348
2172 - function AsyncText(props) {
2173 - const text = props.text;
2174 - try {
2175 - TextResource.read(cache, [props.text, props.ms]);
2176 - ReactNoop.yield(text);
2177 - return <span prop={text} />;
2178 - } catch (promise) {
2179 - if (typeof promise.then === 'function') {
2180 - ReactNoop.yield(`Suspend! [${text}]`);
2181 - } else {
2182 - ReactNoop.yield(`Error! [${text}]`);
2349 + render() {
2350 + const {ms, text} = this.props;
2351 + TextResource.read(cache, [text, ms]);
2352 + return <span prop={text}>{this.state.hasMounted}</span>;
2353 }
2184 - throw promise;
2354 }
2186 - }
2355
2188 - const interaction = {
2189 - id: 0,
2190 - name: 'initial render',
2191 - timestamp: mockNow(),
2192 - };
2356 + const interaction = {
2357 + id: 0,
2358 + name: 'initial render',
2359 + timestamp: mockNow(),
2360 + };
2361
2194 - const onRender = jest.fn();
2195 - SchedulerTracing.unstable_trace(interaction.name, mockNow(), () => {
2196 - ReactNoop.render(
2197 - <React.unstable_Profiler id="test-profiler" onRender={onRender}>
2198 - <React.Placeholder fallback={<Text text="Loading..." />}>
2199 - <AsyncText text="Async" ms={20000} />
2200 - </React.Placeholder>
2201 - <Text text="Sync" />
2202 - </React.unstable_Profiler>,
2362 + const onRender = jest.fn();
2363 + SchedulerTracing.unstable_trace(
2364 + interaction.name,
2365 + interaction.timestamp,
2366 + () => {
2367 + ReactTestRenderer.create(
2368 + <React.unstable_Profiler id="app" onRender={onRender}>
2369 + <React.Placeholder
2370 + delayMs={1000}
2371 + fallback={<Text text="loading" />}>
2372 + <AsyncComponentWithCascadingWork text="loaded" ms={2000} />
2373 + </React.Placeholder>
2374 + </React.unstable_Profiler>,
2375 + );
2376 + },
2377 );
2378 +
2379 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2380 +
2381 + jest.runAllTimers();
2382 + await resourcePromise;
2383 +
2384 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2385 +
2386 + wrappedCascadingFn();
2387 +
2388 + expect(onInteractionScheduledWorkCompleted).toHaveBeenCalledTimes(1);
2389 + expect(
2390 + onInteractionScheduledWorkCompleted,
2391 + ).toHaveBeenLastNotifiedOfInteraction(interaction);
2392 });
2393
2206 - expect(onInteractionTraced).toHaveBeenCalledTimes(1);
2207 - expect(onInteractionTraced).toHaveBeenLastNotifiedOfInteraction(
2208 - interaction,
2209 - );
2210 - expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2211 - expect(getWorkForReactThreads(onWorkStarted)).toHaveLength(0);
2212 - expect(getWorkForReactThreads(onWorkStopped)).toHaveLength(0);
2394 + it('does not prematurely complete for suspended renders that have exceeded their deadline', async () => {
2395 + const interaction = {
2396 + id: 0,
2397 + name: 'initial render',
2398 + timestamp: mockNow(),
2399 + };
2400
2214 - expect(ReactNoop.flush()).toEqual([
2215 - 'Suspend! [Async]',
2216 - 'Loading...',
2217 - 'Sync',
2218 - ]);
2219 - // The update hasn't expired yet, so we commit nothing.
2220 - expect(ReactNoop.getChildren()).toEqual([]);
2221 - expect(onRender).not.toHaveBeenCalled();
2401 + const onRender = jest.fn();
2402 + let renderer;
2403 + SchedulerTracing.unstable_trace(
2404 + interaction.name,
2405 + interaction.timestamp,
2406 + () => {
2407 + renderer = ReactTestRenderer.create(
2408 + <React.unstable_Profiler id="app" onRender={onRender}>
2409 + <React.Placeholder
2410 + delayMs={1000}
2411 + fallback={<Text text="loading" />}>
2412 + <AsyncText text="loaded" ms={2000} />
2413 + </React.Placeholder>
2414 + </React.unstable_Profiler>,
2415 + {
2416 + unstable_isAsync: true,
2417 + },
2418 + );
2419 + },
2420 + );
2421
2223 - // Advance both React's virtual time and Jest's timers by enough to expire
2224 - // the update, but not by enough to flush the suspending promise.
2225 - ReactNoop.expire(10000);
2226 - await awaitableAdvanceTimers(10000);
2227 - // No additional rendering work is required, since we already prepared
2228 - // the placeholder.
2229 - expect(ReactNoop.flushExpired()).toEqual([]);
2230 - // Should have committed the placeholder.
2231 - expect(ReactNoop.getChildren()).toEqual([
2232 - span('Loading...'),
2233 - span('Sync'),
2234 - ]);
2235 - expect(onRender).toHaveBeenCalledTimes(1);
2422 + advanceTimeBy(1500);
2423 + await awaitableAdvanceTimers(1500);
2424
2237 - let call = onRender.mock.calls[0];
2238 - expect(call[0]).toEqual('test-profiler');
2239 - expect(call[6]).toMatchInteractions(
2240 - ReactFeatureFlags.enableSchedulerTracing ? [interaction] : [],
2241 - );
2425 + expect(renderer).toFlushAll(['Suspend [loaded]', 'Text [loading]']);
2426 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2427
2243 - expect(onInteractionTraced).toHaveBeenCalledTimes(1);
2244 - expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2428 + advanceTimeBy(2500);
2429 + await awaitableAdvanceTimers(2500);
2430
2246 - // Once the promise resolves, we render the suspended view
2247 - await awaitableAdvanceTimers(10000);
2248 - expect(ReactNoop.flush()).toEqual(['Promise resolved [Async]', 'Async']);
2249 - expect(ReactNoop.getChildren()).toEqual([span('Async'), span('Sync')]);
2250 - expect(onRender).toHaveBeenCalledTimes(2);
2431 + expect(renderer).toFlushAll(['AsyncText [loaded]']);
2432 + expect(onInteractionScheduledWorkCompleted).toHaveBeenCalledTimes(1);
2433 + expect(
2434 + onInteractionScheduledWorkCompleted,
2435 + ).toHaveBeenLastNotifiedOfInteraction(interaction);
2436 + });
2437
2252 - call = onRender.mock.calls[1];
2253 - expect(call[0]).toEqual('test-profiler');
2254 - expect(call[6]).toMatchInteractions(
2255 - ReactFeatureFlags.enableSchedulerTracing ? [interaction] : [],
2256 - );
2438 + it('decrements interaction count correctly if suspense loads before placeholder is shown', async () => {
2439 + const interaction = {
2440 + id: 0,
2441 + name: 'initial render',
2442 + timestamp: mockNow(),
2443 + };
2444
2258 - expect(onInteractionTraced).toHaveBeenCalledTimes(1);
2259 - expect(onInteractionScheduledWorkCompleted).toHaveBeenCalledTimes(1);
2260 - expect(
2261 - onInteractionScheduledWorkCompleted,
2262 - ).toHaveBeenLastNotifiedOfInteraction(interaction);
2445 + const onRender = jest.fn();
2446 + let renderer;
2447 + SchedulerTracing.unstable_trace(
2448 + interaction.name,
2449 + interaction.timestamp,
2450 + () => {
2451 + renderer = ReactTestRenderer.create(
2452 + <React.unstable_Profiler id="app" onRender={onRender}>
2453 + <React.Placeholder
2454 + delayMs={2000}
2455 + fallback={<Text text="loading" />}>
2456 + <AsyncText text="loaded" ms={1000} />
2457 + </React.Placeholder>
2458 + </React.unstable_Profiler>,
2459 + {unstable_isAsync: true},
2460 + );
2461 + },
2462 + );
2463 + renderer.unstable_flushAll();
2464 +
2465 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2466 +
2467 + jest.advanceTimersByTime(1000);
2468 + await resourcePromise;
2469 + renderer.unstable_flushAll();
2470 +
2471 + expect(onInteractionScheduledWorkCompleted).toHaveBeenCalledTimes(1);
2472 + expect(
2473 + onInteractionScheduledWorkCompleted,
2474 + ).toHaveBeenLastNotifiedOfInteraction(interaction);
2475 + });
2476 +
2477 + it('handles high-pri renderers between suspended and resolved (sync) trees', async () => {
2478 + const initialRenderInteraction = {
2479 + id: 0,
2480 + name: 'initial render',
2481 + timestamp: mockNow(),
2482 + };
2483 +
2484 + const onRender = jest.fn();
2485 + let renderer;
2486 + SchedulerTracing.unstable_trace(
2487 + initialRenderInteraction.name,
2488 + initialRenderInteraction.timestamp,
2489 + () => {
2490 + renderer = ReactTestRenderer.create(
2491 + <React.unstable_Profiler id="app" onRender={onRender}>
2492 + <React.Placeholder
2493 + delayMs={2000}
2494 + fallback={<Text text="loading" />}>
2495 + <AsyncText text="loaded" ms={1000} />
2496 + </React.Placeholder>
2497 + <Text text="initial" />
2498 + </React.unstable_Profiler>,
2499 + );
2500 + },
2501 + );
2502 + expect(renderer.toJSON()).toEqual(['loading', 'initial']);
2503 +
2504 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2505 + expect(onRender).toHaveBeenCalledTimes(2); // Sync null commit, placeholder commit
2506 + expect(onRender.mock.calls[0][6]).toMatchInteractions([
2507 + initialRenderInteraction,
2508 + ]);
2509 + onRender.mockClear();
2510 +
2511 + const highPriUpdateInteraction = {
2512 + id: 1,
2513 + name: 'hiPriUpdate',
2514 + timestamp: mockNow(),
2515 + };
2516 +
2517 + const originalPromise = resourcePromise;
2518 +
2519 + renderer.unstable_flushSync(() => {
2520 + SchedulerTracing.unstable_trace(
2521 + highPriUpdateInteraction.name,
2522 + highPriUpdateInteraction.timestamp,
2523 + () => {
2524 + renderer.update(
2525 + <React.unstable_Profiler id="app" onRender={onRender}>
2526 + <React.Placeholder
2527 + delayMs={2000}
2528 + fallback={<Text text="loading" />}>
2529 + <AsyncText text="loaded" ms={1000} />
2530 + </React.Placeholder>
2531 + <Text text="updated" />
2532 + </React.unstable_Profiler>,
2533 + );
2534 + },
2535 + );
2536 + });
2537 + expect(renderer.toJSON()).toEqual(['loading', 'updated']);
2538 +
2539 + expect(onRender).toHaveBeenCalledTimes(2); // Sync null commit, placeholder commit
2540 + expect(onRender.mock.calls[0][6]).toMatchInteractions([
2541 + initialRenderInteraction,
2542 + highPriUpdateInteraction,
2543 + ]);
2544 + onRender.mockClear();
2545 +
2546 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2547 +
2548 + advanceTimeBy(1000);
2549 + jest.advanceTimersByTime(1000);
2550 + await originalPromise;
2551 + expect(renderer.toJSON()).toEqual(['loaded', 'updated']);
2552 +
2553 + expect(onRender).toHaveBeenCalledTimes(2);
2554 + expect(onRender.mock.calls[0][6]).toMatchInteractions([
2555 + initialRenderInteraction,
2556 + highPriUpdateInteraction,
2557 + ]);
2558 +
2559 + expect(onInteractionScheduledWorkCompleted).toHaveBeenCalledTimes(2);
2560 + expect(
2561 + onInteractionScheduledWorkCompleted.mock.calls[0][0],
2562 + ).toMatchInteraction(initialRenderInteraction);
2563 + expect(
2564 + onInteractionScheduledWorkCompleted.mock.calls[1][0],
2565 + ).toMatchInteraction(highPriUpdateInteraction);
2566 + });
2567 +
2568 + it('handles high-pri renderers between suspended and resolved (async) trees', async () => {
2569 + const initialRenderInteraction = {
2570 + id: 0,
2571 + name: 'initial render',
2572 + timestamp: mockNow(),
2573 + };
2574 +
2575 + const onRender = jest.fn();
2576 + let renderer;
2577 + SchedulerTracing.unstable_trace(
2578 + initialRenderInteraction.name,
2579 + initialRenderInteraction.timestamp,
2580 + () => {
2581 + renderer = ReactTestRenderer.create(
2582 + <React.unstable_Profiler id="app" onRender={onRender}>
2583 + <React.Placeholder
2584 + delayMs={2000}
2585 + fallback={<Text text="loading" />}>
2586 + <AsyncText text="loaded" ms={1000} />
2587 + </React.Placeholder>
2588 + <Text text="initial" />
2589 + </React.unstable_Profiler>,
2590 + {unstable_isAsync: true},
2591 + );
2592 + },
2593 + );
2594 + expect(renderer).toFlushAll([
2595 + 'Suspend [loaded]',
2596 + 'Text [loading]',
2597 + 'Text [initial]',
2598 + ]);
2599 +
2600 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
2601 + expect(onRender).not.toHaveBeenCalled();
2602 +
2603 + advanceTimeBy(500);
2604 + jest.advanceTimersByTime(500);
2605 +
2606 + const highPriUpdateInteraction = {
2607 + id: 1,
2608 + name: 'hiPriUpdate',
2609 + timestamp: mockNow(),
2610 + };
2611 +
2612 + const originalPromise = resourcePromise;
2613 +
2614 + renderer.unstable_flushSync(() => {
2615 + SchedulerTracing.unstable_trace(
2616 + highPriUpdateInteraction.name,
2617 + highPriUpdateInteraction.timestamp,
2618 + () => {
2619 + renderer.update(
2620 + <React.unstable_Profiler id="app" onRender={onRender}>
2621 + <React.Placeholder
2622 + delayMs={2000}
2623 + fallback={<Text text="loading" />}>
2624 + <AsyncText text="loaded" ms={1000} />
2625 + </React.Placeholder>
2626 + <Text text="updated" />
2627 + </React.unstable_Profiler>,
2628 + );
2629 + },
2630 + );
2631 + });
2632 + expect(renderer.toJSON()).toEqual(['loading', 'updated']);
2633 +
2634 + expect(onRender).toHaveBeenCalledTimes(1);
2635 + expect(onRender.mock.calls[0][6]).toMatchInteractions([
2636 + highPriUpdateInteraction,
2637 + ]);
2638 + onRender.mockClear();
2639 +
2640 + expect(onInteractionScheduledWorkCompleted).toHaveBeenCalledTimes(1);
2641 + expect(
2642 + onInteractionScheduledWorkCompleted,
2643 + ).toHaveBeenLastNotifiedOfInteraction(highPriUpdateInteraction);
2644 +
2645 + advanceTimeBy(500);
2646 + jest.advanceTimersByTime(500);
2647 + await originalPromise;
2648 + expect(renderer).toFlushAll(['AsyncText [loaded]']);
2649 + expect(renderer.toJSON()).toEqual(['loaded', 'updated']);
2650 +
2651 + expect(onRender).toHaveBeenCalledTimes(1);
2652 + expect(onRender.mock.calls[0][6]).toMatchInteractions([
2653 + initialRenderInteraction,
2654 + ]);
2655 +
2656 + expect(onInteractionScheduledWorkCompleted).toHaveBeenCalledTimes(2);
2657 + expect(
2658 + onInteractionScheduledWorkCompleted,
2659 + ).toHaveBeenLastNotifiedOfInteraction(initialRenderInteraction);
2660 + });
2661 });
2662 });
2663 });
packages/react/src/__tests__/ReactProfilerDOM-test.internal.js new
+174
@@ -0,0 +1,174 @@
1 +/**
2 + * Copyright (c) Facebook, Inc. and its affiliates.
3 + *
4 + * This source code is licensed under the MIT license found in the
5 + * LICENSE file in the root directory of this source tree.
6 + *
7 + * @emails react-core
8 + */
9 +
10 +'use strict';
11 +
12 +let React;
13 +let ReactFeatureFlags;
14 +let ReactDOM;
15 +let SchedulerTracing;
16 +let SimpleCacheProvider;
17 +
18 +function initEnvForAsyncTesting() {
19 + // Boilerplate copied from ReactDOMRoot-test
20 + // TODO pull this into helper method, reduce repetition.
21 + const originalDateNow = Date.now;
22 + global.Date.now = function() {
23 + return originalDateNow();
24 + };
25 + global.requestAnimationFrame = function(cb) {
26 + return setTimeout(() => {
27 + cb(Date.now());
28 + });
29 + };
30 + const originalAddEventListener = global.addEventListener;
31 + let postMessageCallback;
32 + global.addEventListener = function(eventName, callback, useCapture) {
33 + if (eventName === 'message') {
34 + postMessageCallback = callback;
35 + } else {
36 + originalAddEventListener(eventName, callback, useCapture);
37 + }
38 + };
39 + global.postMessage = function(messageKey, targetOrigin) {
40 + const postMessageEvent = {source: window, data: messageKey};
41 + if (postMessageCallback) {
42 + postMessageCallback(postMessageEvent);
43 + }
44 + };
45 +}
46 +
47 +function loadModules() {
48 + ReactFeatureFlags = require('shared/ReactFeatureFlags');
49 + ReactFeatureFlags.debugRenderPhaseSideEffects = false;
50 + ReactFeatureFlags.debugRenderPhaseSideEffectsForStrictMode = false;
51 + ReactFeatureFlags.enableProfilerTimer = true;
52 + ReactFeatureFlags.enableSchedulerTracing = true;
53 + ReactFeatureFlags.enableSuspense = true;
54 +
55 + React = require('react');
56 + SchedulerTracing = require('scheduler/tracing');
57 + ReactDOM = require('react-dom');
58 + SimpleCacheProvider = require('simple-cache-provider');
59 +}
60 +
61 +describe('ProfilerDOM', () => {
62 + let TextResource;
63 + let cache;
64 + let resourcePromise;
65 + let onInteractionScheduledWorkCompleted;
66 + let onInteractionTraced;
67 +
68 + beforeEach(() => {
69 + initEnvForAsyncTesting();
70 + loadModules();
71 +
72 + onInteractionScheduledWorkCompleted = jest.fn();
73 + onInteractionTraced = jest.fn();
74 +
75 + // Verify interaction subscriber methods are called as expected.
76 + SchedulerTracing.unstable_subscribe({
77 + onInteractionScheduledWorkCompleted,
78 + onInteractionTraced,
79 + onWorkCanceled: () => {},
80 + onWorkScheduled: () => {},
81 + onWorkStarted: () => {},
82 + onWorkStopped: () => {},
83 + });
84 +
85 + cache = SimpleCacheProvider.createCache(() => {});
86 +
87 + resourcePromise = null;
88 +
89 + TextResource = SimpleCacheProvider.createResource(([text, ms = 0]) => {
90 + resourcePromise = new Promise(
91 + SchedulerTracing.unstable_wrap((resolve, reject) => {
92 + setTimeout(
93 + SchedulerTracing.unstable_wrap(() => {
94 + resolve(text);
95 + }),
96 + ms,
97 + );
98 + }),
99 + );
100 + return resourcePromise;
101 + }, ([text, ms]) => text);
102 + });
103 +
104 + const AsyncText = ({ms, text}) => {
105 + TextResource.read(cache, [text, ms]);
106 + return text;
107 + };
108 +
109 + const Text = ({text}) => text;
110 +
111 + it('should correctly trace interactions for async roots', async done => {
112 + let batch, element, interaction;
113 +
114 + SchedulerTracing.unstable_trace('initial_event', performance.now(), () => {
115 + const interactions = SchedulerTracing.unstable_getCurrent();
116 + expect(interactions.size).toBe(1);
117 + interaction = Array.from(interactions)[0];
118 +
119 + element = document.createElement('div');
120 + const root = ReactDOM.unstable_createRoot(element);
121 + batch = root.createBatch();
122 + batch.render(
123 + <React.Placeholder delayMS={100} fallback={<Text text="Loading..." />}>
124 + <AsyncText text="Text" ms={200} />
125 + </React.Placeholder>,
126 + );
127 + batch.then(
128 + SchedulerTracing.unstable_wrap(() => {
129 + batch.commit();
130 +
131 + expect(element.textContent).toBe('Loading...');
132 + expect(onInteractionTraced).toHaveBeenCalledTimes(1);
133 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
134 +
135 + resourcePromise.then(
136 + SchedulerTracing.unstable_wrap(() => {
137 + jest.runAllTimers();
138 +
139 + expect(element.textContent).toBe('Text');
140 + expect(onInteractionTraced).toHaveBeenCalledTimes(1);
141 + expect(
142 + onInteractionScheduledWorkCompleted,
143 + ).not.toHaveBeenCalled();
144 +
145 + // Evaluate in an unwrapped callback,
146 + // Because trace/wrap won't decrement the count within the wrapped callback.
147 + setImmediate(() => {
148 + expect(onInteractionTraced).toHaveBeenCalledTimes(1);
149 + expect(
150 + onInteractionScheduledWorkCompleted,
151 + ).toHaveBeenCalledTimes(1);
152 + expect(
153 + onInteractionScheduledWorkCompleted,
154 + ).toHaveBeenLastNotifiedOfInteraction(interaction);
155 +
156 + expect(interaction.__count).toBe(0);
157 +
158 + done();
159 + });
160 + }),
161 + );
162 + }),
163 + );
164 + });
165 +
166 + expect(onInteractionTraced).toHaveBeenCalledTimes(1);
167 + expect(onInteractionTraced).toHaveBeenLastNotifiedOfInteraction(
168 + interaction,
169 + );
170 + expect(onInteractionScheduledWorkCompleted).not.toHaveBeenCalled();
171 +
172 + jest.runAllTimers();
173 + });
174 +});