@samitouri / QOS-React-2 / commits / 9abe745aa7

[DevTools][Timeline Profiler] Component Stacks Backend (#24776)

This PR adds a component stack field to the `schedule-state-update` event. The algorithm is as follows: * During profiling, whenever a state update happens collect the parents of the fiber that caused the state update and store it in a map * After profiling finishes, post process the `schedule-state-update` event and using the parent fibers, generate the component stack by using`describeFiber`, a function that uses error throwing to get the location of the component by calling the component without props. --- Co-authored-by: Blake Friedman <blake.friedman@gmail.com>

Luna Ruan committed Jun 23, 2022 at 14:19 UTC 9abe745aa748271be170c67cc43b09f62ca5f2dc
7 files changed +167 -3
packages/react-devtools-shared/src/__tests__/TimelineProfiler-test.js
+89
@@ -9,6 +9,15 @@
9
10 'use strict';
11
12 +function normalizeCodeLocInfo(str) {
13 + return (
14 + typeof str === 'string' &&
15 + str.replace(/\n +(?:at|in) ([\S]+)[^\n]*/g, function(m, name) {
16 + return '\n in ' + name + ' (at **)';
17 + })
18 + );
19 +}
20 +
21 describe('Timeline profiler', () => {
22 let React;
23 let ReactDOMClient;
@@ -1175,6 +1184,18 @@ describe('Timeline profiler', () => {
1184 if (timelineData) {
1185 expect(timelineData).toHaveLength(1);
1186
1187 + // normalize the location for component stack source
1188 + // for snapshot testing
1189 + timelineData.forEach(data => {
1190 + data.schedulingEvents.forEach(event => {
1191 + if (event.componentStack) {
1192 + event.componentStack = normalizeCodeLocInfo(
1193 + event.componentStack,
1194 + );
1195 + }
1196 + });
1197 + });
1198 +
1199 return timelineData[0];
1200 } else {
1201 return null;
@@ -1256,6 +1277,8 @@ describe('Timeline profiler', () => {
1277 Array [
1278 Object {
1279 "componentName": "Example",
1280 + "componentStack": "
1281 + in Example (at **)",
1282 "lanes": "0b0000000000000000000000000000100",
1283 "timestamp": 10,
1284 "type": "schedule-state-update",
@@ -1263,6 +1286,8 @@ describe('Timeline profiler', () => {
1286 },
1287 Object {
1288 "componentName": "Example",
1289 + "componentStack": "
1290 + in Example (at **)",
1291 "lanes": "0b0000000000000000000000001000000",
1292 "timestamp": 10,
1293 "type": "schedule-state-update",
@@ -1270,6 +1295,8 @@ describe('Timeline profiler', () => {
1295 },
1296 Object {
1297 "componentName": "Example",
1298 + "componentStack": "
1299 + in Example (at **)",
1300 "lanes": "0b0000000000000000000000001000000",
1301 "timestamp": 10,
1302 "type": "schedule-state-update",
@@ -1277,6 +1304,8 @@ describe('Timeline profiler', () => {
1304 },
1305 Object {
1306 "componentName": "Example",
1307 + "componentStack": "
1308 + in Example (at **)",
1309 "lanes": "0b0000000000000000000000000010000",
1310 "timestamp": 10,
1311 "type": "schedule-state-update",
@@ -1614,6 +1643,8 @@ describe('Timeline profiler', () => {
1643 },
1644 Object {
1645 "componentName": "Example",
1646 + "componentStack": "
1647 + in Example (at **)",
1648 "lanes": "0b0000000000000000000000000000001",
1649 "timestamp": 20,
1650 "type": "schedule-state-update",
@@ -1741,6 +1772,8 @@ describe('Timeline profiler', () => {
1772 },
1773 Object {
1774 "componentName": "Example",
1775 + "componentStack": "
1776 + in Example (at **)",
1777 "lanes": "0b0000000000000000000000000010000",
1778 "timestamp": 10,
1779 "type": "schedule-state-update",
@@ -1872,6 +1905,8 @@ describe('Timeline profiler', () => {
1905 },
1906 Object {
1907 "componentName": "Example",
1908 + "componentStack": "
1909 + in Example (at **)",
1910 "lanes": "0b0000000000000000000000000000001",
1911 "timestamp": 21,
1912 "type": "schedule-state-update",
@@ -1934,6 +1969,8 @@ describe('Timeline profiler', () => {
1969 },
1970 Object {
1971 "componentName": "Example",
1972 + "componentStack": "
1973 + in Example (at **)",
1974 "lanes": "0b0000000000000000000000000010000",
1975 "timestamp": 21,
1976 "type": "schedule-state-update",
@@ -1982,6 +2019,8 @@ describe('Timeline profiler', () => {
2019 },
2020 Object {
2021 "componentName": "Example",
2022 + "componentStack": "
2023 + in Example (at **)",
2024 "lanes": "0b0000000000000000000000000010000",
2025 "timestamp": 20,
2026 "type": "schedule-state-update",
@@ -2065,6 +2104,8 @@ describe('Timeline profiler', () => {
2104 },
2105 Object {
2106 "componentName": "ErrorBoundary",
2107 + "componentStack": "
2108 + in ErrorBoundary (at **)",
2109 "lanes": "0b0000000000000000000000000000001",
2110 "timestamp": 20,
2111 "type": "schedule-state-update",
@@ -2177,6 +2218,8 @@ describe('Timeline profiler', () => {
2218 },
2219 Object {
2220 "componentName": "ErrorBoundary",
2221 + "componentStack": "
2222 + in ErrorBoundary (at **)",
2223 "lanes": "0b0000000000000000000000000000001",
2224 "timestamp": 30,
2225 "type": "schedule-state-update",
@@ -2441,6 +2484,52 @@ describe('Timeline profiler', () => {
2484 }
2485 `);
2486 });
2487 +
2488 + it('should generate component stacks for state update', async () => {
2489 + function CommponentWithChildren({initialRender}) {
2490 + Scheduler.unstable_yieldValue('Render ComponentWithChildren');
2491 + return <Child initialRender={initialRender} />;
2492 + }
2493 +
2494 + function Child({initialRender}) {
2495 + const [didRender, setDidRender] = React.useState(initialRender);
2496 + if (!didRender) {
2497 + setDidRender(true);
2498 + }
2499 + Scheduler.unstable_yieldValue('Render Child');
2500 + return null;
2501 + }
2502 +
2503 + renderRootHelper(<CommponentWithChildren initialRender={false} />);
2504 +
2505 + expect(Scheduler).toFlushAndYield([
2506 + 'Render ComponentWithChildren',
2507 + 'Render Child',
2508 + 'Render Child',
2509 + ]);
2510 +
2511 + const timelineData = stopProfilingAndGetTimelineData();
2512 + expect(timelineData.schedulingEvents).toMatchInlineSnapshot(`
2513 + Array [
2514 + Object {
2515 + "lanes": "0b0000000000000000000000000010000",
2516 + "timestamp": 10,
2517 + "type": "schedule-render",
2518 + "warning": null,
2519 + },
2520 + Object {
2521 + "componentName": "Child",
2522 + "componentStack": "
2523 + in Child (at **)
2524 + in CommponentWithChildren (at **)",
2525 + "lanes": "0b0000000000000000000000000010000",
2526 + "timestamp": 10,
2527 + "type": "schedule-state-update",
2528 + "warning": null,
2529 + },
2530 + ]
2531 + `);
2532 + });
2533 });
2534
2535 describe('when not profiling', () => {
packages/react-devtools-shared/src/__tests__/preprocessData-test.js
+20
@@ -9,6 +9,15 @@
9
10 'use strict';
11
12 +function normalizeCodeLocInfo(str) {
13 + return (
14 + typeof str === 'string' &&
15 + str.replace(/\n +(?:at|in) ([\S]+)[^\n]*/g, function(m, name) {
16 + return '\n in ' + name + ' (at **)';
17 + })
18 + );
19 +}
20 +
21 describe('Timeline profiler', () => {
22 let React;
23 let ReactDOM;
@@ -2134,6 +2143,15 @@ describe('Timeline profiler', () => {
2143 const data = store.profilerStore.profilingData?.timelineData;
2144 expect(data).toHaveLength(1);
2145 const timelineData = data[0];
2146 +
2147 + // normalize the location for component stack source
2148 + // for snapshot testing
2149 + timelineData.schedulingEvents.forEach(event => {
2150 + if (event.componentStack) {
2151 + event.componentStack = normalizeCodeLocInfo(event.componentStack);
2152 + }
2153 + });
2154 +
2155 expect(timelineData).toMatchInlineSnapshot(`
2156 Object {
2157 "batchUIDToMeasuresMap": Map {
@@ -2415,6 +2433,8 @@ describe('Timeline profiler', () => {
2433 },
2434 Object {
2435 "componentName": "App",
2436 + "componentStack": "
2437 + in App (at **)",
2438 "lanes": "0b0000000000000000000000000010000",
2439 "timestamp": 10,
2440 "type": "schedule-state-update",
packages/react-devtools-shared/src/backend/DevToolsFiberComponentStack.js
+1 -1
@@ -21,7 +21,7 @@ import {
21 describeClassComponentFrame,
22 } from './DevToolsComponentStackFrame';
23
24 -function describeFiber(
24 +export function describeFiber(
25 workTagMap: WorkTagMap,
26 workInProgress: Fiber,
27 currentDispatcherRef: CurrentDispatcherRef,
packages/react-devtools-shared/src/backend/profilingHooks.js
+51 -2
@@ -11,6 +11,8 @@ import type {
11 Lane,
12 Lanes,
13 DevToolsProfilingHooks,
14 + WorkTagMap,
15 + CurrentDispatcherRef,
16 } from 'react-devtools-shared/src/backend/types';
17 import type {Fiber} from 'react-reconciler/src/ReactInternalTypes';
18 import type {Wakeable} from 'shared/ReactTypes';
@@ -22,6 +24,8 @@ import type {
24 ReactMeasureType,
25 TimelineData,
26 SuspenseEvent,
27 + SchedulingEvent,
28 + ReactScheduleStateUpdateEvent,
29 } from 'react-devtools-timeline/src/types';
30
31 import isArray from 'shared/isArray';
@@ -29,6 +33,7 @@ import {
33 REACT_TOTAL_NUM_LANES,
34 SCHEDULING_PROFILER_VERSION,
35 } from 'react-devtools-timeline/src/constants';
36 +import {describeFiber} from './DevToolsFiberComponentStack';
37
38 // Add padding to the start/stop time of the profile.
39 // This makes the UI nicer to use.
@@ -98,17 +103,22 @@ export function createProfilingHooks({
103 getDisplayNameForFiber,
104 getIsProfiling,
105 getLaneLabelMap,
106 + workTagMap,
107 + currentDispatcherRef,
108 reactVersion,
109 }: {|
110 getDisplayNameForFiber: (fiber: Fiber) => string | null,
111 getIsProfiling: () => boolean,
112 getLaneLabelMap?: () => Map<Lane, string> | null,
113 + currentDispatcherRef?: CurrentDispatcherRef,
114 + workTagMap: WorkTagMap,
115 reactVersion: string,
116 |}): Response {
117 let currentBatchUID: BatchUID = 0;
118 let currentReactComponentMeasure: ReactComponentMeasure | null = null;
119 let currentReactMeasuresStack: Array<ReactMeasure> = [];
120 let currentTimelineData: TimelineData | null = null;
121 + let currentFiberStacks: Map<SchedulingEvent, Array<Fiber>> = new Map();
122 let isProfiling: boolean = false;
123 let nextRenderShouldStartNewBatch: boolean = false;
124
@@ -774,6 +784,16 @@ export function createProfilingHooks({
784 }
785 }
786
787 + function getParentFibers(fiber: Fiber): Array<Fiber> {
788 + const parents = [];
789 + let parent = fiber;
790 + while (parent !== null) {
791 + parents.push(parent);
792 + parent = parent.return;
793 + }
794 + return parents;
795 + }
796 +
797 function markStateUpdateScheduled(fiber: Fiber, lane: Lane): void {
798 if (isProfiling || supportsUserTimingV3) {
799 const componentName = getDisplayNameForFiber(fiber) || 'Unknown';
@@ -781,13 +801,17 @@ export function createProfilingHooks({
801 if (isProfiling) {
802 // TODO (timeline) Record and cache component stack
803 if (currentTimelineData) {
784 - currentTimelineData.schedulingEvents.push({
804 + const event: ReactScheduleStateUpdateEvent = {
805 componentName,
806 + // Store the parent fibers so we can post process
807 + // them after we finish profiling
808 lanes: laneToLanesArray(lane),
809 timestamp: getRelativeTime(),
810 type: 'schedule-state-update',
811 warning: null,
790 - });
812 + };
813 + currentFiberStacks.set(event, getParentFibers(fiber));
814 + currentTimelineData.schedulingEvents.push(event);
815 }
816 }
817
@@ -831,6 +855,7 @@ export function createProfilingHooks({
855 currentBatchUID = 0;
856 currentReactComponentMeasure = null;
857 currentReactMeasuresStack = [];
858 + currentFiberStacks = new Map();
859 currentTimelineData = {
860 // Session wide metadata; only collected once.
861 internalModuleSourceToRanges,
@@ -858,6 +883,30 @@ export function createProfilingHooks({
883 snapshotHeight: 0,
884 };
885 nextRenderShouldStartNewBatch = true;
886 + } else {
887 + // Postprocess Profile data
888 + if (currentTimelineData !== null) {
889 + currentTimelineData.schedulingEvents.forEach(event => {
890 + if (event.type === 'schedule-state-update') {
891 + // TODO(luna): We can optimize this by creating a map of
892 + // fiber to component stack instead of generating the stack
893 + // for every fiber every time
894 + const fiberStack = currentFiberStacks.get(event);
895 + if (fiberStack && currentDispatcherRef != null) {
896 + event.componentStack = fiberStack.reduce((trace, fiber) => {
897 + return (
898 + trace +
899 + describeFiber(workTagMap, fiber, currentDispatcherRef)
900 + );
901 + }, '');
902 + }
903 + }
904 + });
905 + }
906 +
907 + // Clear the current fiber stacks so we don't hold onto the fibers
908 + // in memory after profiling finishes
909 + currentFiberStacks.clear();
910 }
911 }
912 }
packages/react-devtools-shared/src/backend/renderer.js
+2
@@ -660,6 +660,8 @@ export function attach(
660 getDisplayNameForFiber,
661 getIsProfiling: () => isProfiling,
662 getLaneLabelMap,
663 + currentDispatcherRef: renderer.currentDispatcherRef,
664 + workTagMap: ReactTypeOfWork,
665 reactVersion: version,
666 });
667
packages/react-devtools-timeline/src/types.js
+1
@@ -51,6 +51,7 @@ export type ReactScheduleRenderEvent = {|
51 |};
52 export type ReactScheduleStateUpdateEvent = {|
53 ...BaseReactScheduleEvent,
54 + +componentStack?: string,
55 +type: 'schedule-state-update',
56 |};
57 export type ReactScheduleForceUpdateEvent = {|
packages/shared/ReactComponentStackFrame.js
+3
@@ -131,6 +131,9 @@ export function describeNativeComponentFrame(
131 } catch (x) {
132 control = x;
133 }
134 + // TODO(luna): This will currently only throw if the function component
135 + // tries to access React/ReactDOM/props. We should probably make this throw
136 + // in simple components too
137 fn();
138 }
139 } catch (sample) {