@samitouri / QOS-React-1 / commits / 4c9c109cea

[Fiber] Try to give a stack trace to every entry in the Scheduler Performance Track (#34123)

For "render" and "commit" phases we don't give any specific stack atm. This tries to always provide something useful to say the cause of the render. For normal renders this will now show the same thing as the "Event" and "Update" entries already showed. We stash the task that was used for those and use them throughout the render and commit phases. For Suspense (Retry lane) and Idle (Offscreen lane), we don't have any updates. Instead for those there's a component that left work behind in previous passes. For those I use the debugTask of the `<Suspense>` or `<Activity>` boundary to indicate that this was the root of the render. Similarly when an Action is invoked on a `<form action={...}>` component using the built-in submit handler, there's no actionable stack in user space that called it. So we use the stack of the JSX for the form instead.

Sebastian Markbåge committed Aug 7, 2025 at 10:26 UTC 4c9c109cea9be3622d9d70f81f96e72528bdad16
6 files changed +546 -144
packages/react-reconciler/src/ReactFiberBeginWork.js
+37
@@ -158,6 +158,7 @@ import {
158 DefaultHydrationLane,
159 SomeRetryLane,
160 includesSomeLane,
161 + includesOnlyRetries,
162 laneToLanes,
163 removeLanes,
164 mergeLanes,
@@ -269,6 +270,7 @@ import {
270 scheduleUpdateOnFiber,
271 renderDidSuspendDelayIfPossible,
272 markSkippedUpdateLanes,
273 + markRenderDerivedCause,
274 getWorkInProgressRoot,
275 peekDeferredLane,
276 } from './ReactFiberWorkLoop';
@@ -946,6 +948,13 @@ function updateDehydratedActivityComponent(
948 // but after we've already committed once.
949 warnIfHydrating();
950
951 + if (includesSomeLane(renderLanes, (OffscreenLane: Lane))) {
952 + // If we're rendering Offscreen and we're entering the activity then it's possible
953 + // that the only reason we rendered was because this boundary left work. Provide
954 + // it as a cause if another one doesn't already exist.
955 + markRenderDerivedCause(workInProgress);
956 + }
957 +
958 if (
959 // TODO: Factoring is a little weird, since we check this right below, too.
960 !didReceiveUpdate
@@ -1132,6 +1141,16 @@ function updateActivityComponent(
1141 children: nextChildren,
1142 };
1143
1144 + if (
1145 + includesSomeLane(renderLanes, (OffscreenLane: Lane)) &&
1146 + includesSomeLane(renderLanes, current.lanes)
1147 + ) {
1148 + // If we're rendering Offscreen and we're entering the activity then it's possible
1149 + // that the only reason we rendered was because this boundary left work. Provide
1150 + // it as a cause if another one doesn't already exist.
1151 + markRenderDerivedCause(workInProgress);
1152 + }
1153 +
1154 const primaryChildFragment = updateWorkInProgressOffscreenFiber(
1155 currentChild,
1156 offscreenChildProps,
@@ -2515,6 +2534,17 @@ function updateSuspenseComponent(
2534 workInProgress.memoizedState = SUSPENDED_MARKER;
2535 return fallbackChildFragment;
2536 } else {
2537 + if (
2538 + prevState !== null &&
2539 + includesOnlyRetries(renderLanes) &&
2540 + includesSomeLane(renderLanes, current.lanes)
2541 + ) {
2542 + // If we're rendering Retry lanes and we're entering the primary content then it's possible
2543 + // that the only reason we rendered was because we left this boundary to be warmed up but
2544 + // nothing else scheduled an update. If so, use it as the cause of the render.
2545 + markRenderDerivedCause(workInProgress);
2546 + }
2547 +
2548 pushPrimaryTreeSuspenseHandler(workInProgress);
2549
2550 const nextPrimaryChildren = nextProps.children;
@@ -2873,6 +2903,13 @@ function updateDehydratedSuspenseComponent(
2903 // but after we've already committed once.
2904 warnIfHydrating();
2905
2906 + if (includesSomeLane(renderLanes, (OffscreenLane: Lane))) {
2907 + // If we're rendering Offscreen and we're entering the activity then it's possible
2908 + // that the only reason we rendered was because this boundary left work. Provide
2909 + // it as a cause if another one doesn't already exist.
2910 + markRenderDerivedCause(workInProgress);
2911 + }
2912 +
2913 if (isSuspenseInstanceFallback(suspenseInstance)) {
2914 // This boundary is in a permanent fallback state. In this case, we'll never
2915 // get an update and we'll never be able to hydrate the final content. Let's just try the
packages/react-reconciler/src/ReactFiberHooks.js
+6 -1
@@ -122,7 +122,10 @@ import {
122 markStateUpdateScheduled,
123 setIsStrictModeForDevtools,
124 } from './ReactFiberDevToolsHook';
125 -import {startUpdateTimerByLane} from './ReactProfilerTimer';
125 +import {
126 + startUpdateTimerByLane,
127 + startHostActionTimer,
128 +} from './ReactProfilerTimer';
129 import {createCache} from './ReactFiberCacheComponent';
130 import {
131 createUpdate as createLegacyQueueUpdate,
@@ -3239,6 +3242,8 @@ export function startHostTransition<F>(
3242 BasicStateAction<Thenable<TransitionStatus> | TransitionStatus>,
3243 > = stateHook.queue;
3244
3245 + startHostActionTimer(formFiber);
3246 +
3247 startTransition(
3248 formFiber,
3249 queue,
packages/react-reconciler/src/ReactFiberPerformanceTrack.js
+363 -114
@@ -609,6 +609,7 @@ export function logBlockingStart(
609 eventType: null | string,
610 eventIsRepeat: boolean,
611 isSpawnedUpdate: boolean,
612 + isPingedUpdate: boolean,
613 renderStartTime: number,
614 lanes: Lanes,
615 debugTask: null | ConsoleTask, // DEV-only
@@ -658,11 +659,13 @@ export function logBlockingStart(
659 // $FlowFixMe[method-unbinding]
660 console.timeStamp.bind(
661 console,
661 - isSpawnedUpdate
662 - ? 'Cascading Update'
663 - : renderStartTime - updateTime > 5
664 - ? 'Update Blocked'
665 - : 'Update',
662 + isPingedUpdate
663 + ? 'Promise Resolved'
664 + : isSpawnedUpdate
665 + ? 'Cascading Update'
666 + : renderStartTime - updateTime > 5
667 + ? 'Update Blocked'
668 + : 'Update',
669 updateTime,
670 renderStartTime,
671 currentTrack,
@@ -672,11 +675,13 @@ export function logBlockingStart(
675 );
676 } else {
677 console.timeStamp(
675 - isSpawnedUpdate
676 - ? 'Cascading Update'
677 - : renderStartTime - updateTime > 5
678 - ? 'Update Blocked'
679 - : 'Update',
678 + isPingedUpdate
679 + ? 'Promise Resolved'
680 + : isSpawnedUpdate
681 + ? 'Cascading Update'
682 + : renderStartTime - updateTime > 5
683 + ? 'Update Blocked'
684 + : 'Update',
685 updateTime,
686 renderStartTime,
687 currentTrack,
@@ -694,6 +699,7 @@ export function logTransitionStart(
699 eventTime: number,
700 eventType: null | string,
701 eventIsRepeat: boolean,
702 + isPingedUpdate: boolean,
703 renderStartTime: number,
704 debugTask: null | ConsoleTask, // DEV-only
705 ): void {
@@ -763,7 +769,11 @@ export function logTransitionStart(
769 // $FlowFixMe[method-unbinding]
770 console.timeStamp.bind(
771 console,
766 - renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update',
772 + isPingedUpdate
773 + ? 'Promise Resolved'
774 + : renderStartTime - updateTime > 5
775 + ? 'Update Blocked'
776 + : 'Update',
777 updateTime,
778 renderStartTime,
779 currentTrack,
@@ -773,7 +783,11 @@ export function logTransitionStart(
783 );
784 } else {
785 console.timeStamp(
776 - renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update',
786 + isPingedUpdate
787 + ? 'Promise Resolved'
788 + : renderStartTime - updateTime > 5
789 + ? 'Update Blocked'
790 + : 'Update',
791 updateTime,
792 renderStartTime,
793 currentTrack,
@@ -789,23 +803,43 @@ export function logRenderPhase(
803 startTime: number,
804 endTime: number,
805 lanes: Lanes,
806 + debugTask: null | ConsoleTask,
807 ): void {
808 if (supportsUserTiming) {
809 + if (endTime <= startTime) {
810 + return;
811 + }
812 const color = includesOnlyHydrationOrOffscreenLanes(lanes)
813 ? 'tertiary-dark'
814 : 'primary-dark';
797 - console.timeStamp(
798 - includesOnlyOffscreenLanes(lanes)
799 - ? 'Prepared'
800 - : includesOnlyHydrationLanes(lanes)
801 - ? 'Hydrated'
802 - : 'Render',
803 - startTime,
804 - endTime,
805 - currentTrack,
806 - LANES_TRACK_GROUP,
807 - color,
808 - );
815 + const label = includesOnlyOffscreenLanes(lanes)
816 + ? 'Prepared'
817 + : includesOnlyHydrationLanes(lanes)
818 + ? 'Hydrated'
819 + : 'Render';
820 + if (__DEV__ && debugTask) {
821 + debugTask.run(
822 + // $FlowFixMe[method-unbinding]
823 + console.timeStamp.bind(
824 + console,
825 + label,
826 + startTime,
827 + endTime,
828 + currentTrack,
829 + LANES_TRACK_GROUP,
830 + color,
831 + ),
832 + );
833 + } else {
834 + console.timeStamp(
835 + label,
836 + startTime,
837 + endTime,
838 + currentTrack,
839 + LANES_TRACK_GROUP,
840 + color,
841 + );
842 + }
843 }
844 }
845
@@ -813,23 +847,43 @@ export function logInterruptedRenderPhase(
847 startTime: number,
848 endTime: number,
849 lanes: Lanes,
850 + debugTask: null | ConsoleTask,
851 ): void {
852 if (supportsUserTiming) {
853 + if (endTime <= startTime) {
854 + return;
855 + }
856 const color = includesOnlyHydrationOrOffscreenLanes(lanes)
857 ? 'tertiary-dark'
858 : 'primary-dark';
821 - console.timeStamp(
822 - includesOnlyOffscreenLanes(lanes)
823 - ? 'Prewarm'
824 - : includesOnlyHydrationLanes(lanes)
825 - ? 'Interrupted Hydration'
826 - : 'Interrupted Render',
827 - startTime,
828 - endTime,
829 - currentTrack,
830 - LANES_TRACK_GROUP,
831 - color,
832 - );
859 + const label = includesOnlyOffscreenLanes(lanes)
860 + ? 'Prewarm'
861 + : includesOnlyHydrationLanes(lanes)
862 + ? 'Interrupted Hydration'
863 + : 'Interrupted Render';
864 + if (__DEV__ && debugTask) {
865 + debugTask.run(
866 + // $FlowFixMe[method-unbinding]
867 + console.timeStamp.bind(
868 + console,
869 + label,
870 + startTime,
871 + endTime,
872 + currentTrack,
873 + LANES_TRACK_GROUP,
874 + color,
875 + ),
876 + );
877 + } else {
878 + console.timeStamp(
879 + label,
880 + startTime,
881 + endTime,
882 + currentTrack,
883 + LANES_TRACK_GROUP,
884 + color,
885 + );
886 + }
887 }
888 }
889
@@ -837,19 +891,38 @@ export function logSuspendedRenderPhase(
891 startTime: number,
892 endTime: number,
893 lanes: Lanes,
894 + debugTask: null | ConsoleTask,
895 ): void {
896 if (supportsUserTiming) {
897 + if (endTime <= startTime) {
898 + return;
899 + }
900 const color = includesOnlyHydrationOrOffscreenLanes(lanes)
901 ? 'tertiary-dark'
902 : 'primary-dark';
845 - console.timeStamp(
846 - 'Prewarm',
847 - startTime,
848 - endTime,
849 - currentTrack,
850 - LANES_TRACK_GROUP,
851 - color,
852 - );
903 + if (__DEV__ && debugTask) {
904 + debugTask.run(
905 + // $FlowFixMe[method-unbinding]
906 + console.timeStamp.bind(
907 + console,
908 + 'Prewarm',
909 + startTime,
910 + endTime,
911 + currentTrack,
912 + LANES_TRACK_GROUP,
913 + color,
914 + ),
915 + );
916 + } else {
917 + console.timeStamp(
918 + 'Prewarm',
919 + startTime,
920 + endTime,
921 + currentTrack,
922 + LANES_TRACK_GROUP,
923 + color,
924 + );
925 + }
926 }
927 }
928
@@ -857,20 +930,39 @@ export function logSuspendedWithDelayPhase(
930 startTime: number,
931 endTime: number,
932 lanes: Lanes,
933 + debugTask: null | ConsoleTask,
934 ): void {
935 // This means the render was suspended and cannot commit until it gets unblocked.
936 if (supportsUserTiming) {
937 + if (endTime <= startTime) {
938 + return;
939 + }
940 const color = includesOnlyHydrationOrOffscreenLanes(lanes)
941 ? 'tertiary-dark'
942 : 'primary-dark';
866 - console.timeStamp(
867 - 'Suspended',
868 - startTime,
869 - endTime,
870 - currentTrack,
871 - LANES_TRACK_GROUP,
872 - color,
873 - );
943 + if (__DEV__ && debugTask) {
944 + debugTask.run(
945 + // $FlowFixMe[method-unbinding]
946 + console.timeStamp.bind(
947 + console,
948 + 'Suspended',
949 + startTime,
950 + endTime,
951 + currentTrack,
952 + LANES_TRACK_GROUP,
953 + color,
954 + ),
955 + );
956 + } else {
957 + console.timeStamp(
958 + 'Suspended',
959 + startTime,
960 + endTime,
961 + currentTrack,
962 + LANES_TRACK_GROUP,
963 + color,
964 + );
965 + }
966 }
967 }
968
@@ -880,8 +972,12 @@ export function logRecoveredRenderPhase(
972 lanes: Lanes,
973 recoverableErrors: Array<CapturedValue<mixed>>,
974 hydrationFailed: boolean,
975 + debugTask: null | ConsoleTask,
976 ): void {
977 if (supportsUserTiming) {
978 + if (endTime <= startTime) {
979 + return;
980 + }
981 if (__DEV__) {
982 const properties: Array<[string, string]> = [];
983 for (let i = 0; i < recoverableErrors.length; i++) {
@@ -897,7 +993,7 @@ export function logRecoveredRenderPhase(
993 String(error);
994 properties.push(['Recoverable Error', message]);
995 }
900 - performance.measure('Recovered', {
996 + const options = {
997 start: startTime,
998 end: endTime,
999 detail: {
@@ -911,7 +1007,15 @@ export function logRecoveredRenderPhase(
1007 properties,
1008 },
1009 },
914 - });
1010 + };
1011 + if (debugTask) {
1012 + debugTask.run(
1013 + // $FlowFixMe[method-unbinding]
1014 + performance.measure.bind(performance, 'Recovered', options),
1015 + );
1016 + } else {
1017 + performance.measure('Recovered', options);
1018 + }
1019 } else {
1020 console.timeStamp(
1021 'Recovered',
@@ -929,68 +1033,144 @@ export function logErroredRenderPhase(
1033 startTime: number,
1034 endTime: number,
1035 lanes: Lanes,
1036 + debugTask: null | ConsoleTask,
1037 ): void {
1038 if (supportsUserTiming) {
934 - console.timeStamp(
935 - 'Errored',
936 - startTime,
937 - endTime,
938 - currentTrack,
939 - LANES_TRACK_GROUP,
940 - 'error',
941 - );
1039 + if (endTime <= startTime) {
1040 + return;
1041 + }
1042 + if (__DEV__ && debugTask) {
1043 + debugTask.run(
1044 + // $FlowFixMe[method-unbinding]
1045 + console.timeStamp.bind(
1046 + console,
1047 + 'Errored',
1048 + startTime,
1049 + endTime,
1050 + currentTrack,
1051 + LANES_TRACK_GROUP,
1052 + 'error',
1053 + ),
1054 + );
1055 + } else {
1056 + console.timeStamp(
1057 + 'Errored',
1058 + startTime,
1059 + endTime,
1060 + currentTrack,
1061 + LANES_TRACK_GROUP,
1062 + 'error',
1063 + );
1064 + }
1065 }
1066 }
1067
1068 export function logInconsistentRender(
1069 startTime: number,
1070 endTime: number,
1071 + debugTask: null | ConsoleTask,
1072 ): void {
1073 if (supportsUserTiming) {
950 - console.timeStamp(
951 - 'Teared Render',
952 - startTime,
953 - endTime,
954 - currentTrack,
955 - LANES_TRACK_GROUP,
956 - 'error',
957 - );
1074 + if (endTime <= startTime) {
1075 + return;
1076 + }
1077 + if (__DEV__ && debugTask) {
1078 + debugTask.run(
1079 + // $FlowFixMe[method-unbinding]
1080 + console.timeStamp.bind(
1081 + console,
1082 + 'Teared Render',
1083 + startTime,
1084 + endTime,
1085 + currentTrack,
1086 + LANES_TRACK_GROUP,
1087 + 'error',
1088 + ),
1089 + );
1090 + } else {
1091 + console.timeStamp(
1092 + 'Teared Render',
1093 + startTime,
1094 + endTime,
1095 + currentTrack,
1096 + LANES_TRACK_GROUP,
1097 + 'error',
1098 + );
1099 + }
1100 }
1101 }
1102
1103 export function logSuspenseThrottlePhase(
1104 startTime: number,
1105 endTime: number,
1106 + debugTask: null | ConsoleTask,
1107 ): void {
1108 // This was inside a throttled Suspense boundary commit.
1109 if (supportsUserTiming) {
967 - console.timeStamp(
968 - 'Throttled',
969 - startTime,
970 - endTime,
971 - currentTrack,
972 - LANES_TRACK_GROUP,
973 - 'secondary-light',
974 - );
1110 + if (endTime <= startTime) {
1111 + return;
1112 + }
1113 + if (__DEV__ && debugTask) {
1114 + debugTask.run(
1115 + // $FlowFixMe[method-unbinding]
1116 + console.timeStamp.bind(
1117 + console,
1118 + 'Throttled',
1119 + startTime,
1120 + endTime,
1121 + currentTrack,
1122 + LANES_TRACK_GROUP,
1123 + 'secondary-light',
1124 + ),
1125 + );
1126 + } else {
1127 + console.timeStamp(
1128 + 'Throttled',
1129 + startTime,
1130 + endTime,
1131 + currentTrack,
1132 + LANES_TRACK_GROUP,
1133 + 'secondary-light',
1134 + );
1135 + }
1136 }
1137 }
1138
1139 export function logSuspendedCommitPhase(
1140 startTime: number,
1141 endTime: number,
1142 + debugTask: null | ConsoleTask,
1143 ): void {
1144 // This means the commit was suspended on CSS or images.
1145 if (supportsUserTiming) {
1146 + if (endTime <= startTime) {
1147 + return;
1148 + }
1149 // TODO: Include the exact reason and URLs of what resources suspended.
1150 // TODO: This might also be Suspended while waiting on a View Transition.
986 - console.timeStamp(
987 - 'Suspended on CSS or Images',
988 - startTime,
989 - endTime,
990 - currentTrack,
991 - LANES_TRACK_GROUP,
992 - 'secondary-light',
993 - );
1151 + if (__DEV__ && debugTask) {
1152 + debugTask.run(
1153 + // $FlowFixMe[method-unbinding]
1154 + console.timeStamp.bind(
1155 + console,
1156 + 'Suspended on CSS or Images',
1157 + startTime,
1158 + endTime,
1159 + currentTrack,
1160 + LANES_TRACK_GROUP,
1161 + 'secondary-light',
1162 + ),
1163 + );
1164 + } else {
1165 + console.timeStamp(
1166 + 'Suspended on CSS or Images',
1167 + startTime,
1168 + endTime,
1169 + currentTrack,
1170 + LANES_TRACK_GROUP,
1171 + 'secondary-light',
1172 + );
1173 + }
1174 }
1175 }
1176
@@ -999,8 +1179,12 @@ export function logCommitErrored(
1179 endTime: number,
1180 errors: Array<CapturedValue<mixed>>,
1181 passive: boolean,
1182 + debugTask: null | ConsoleTask,
1183 ): void {
1184 if (supportsUserTiming) {
1185 + if (endTime <= startTime) {
1186 + return;
1187 + }
1188 if (__DEV__) {
1189 const properties: Array<[string, string]> = [];
1190 for (let i = 0; i < errors.length; i++) {
@@ -1016,7 +1200,7 @@ export function logCommitErrored(
1200 String(error);
1201 properties.push(['Error', message]);
1202 }
1019 - performance.measure('Errored', {
1203 + const options = {
1204 start: startTime,
1205 end: endTime,
1206 detail: {
@@ -1030,7 +1214,15 @@ export function logCommitErrored(
1214 properties,
1215 },
1216 },
1033 - });
1217 + };
1218 + if (debugTask) {
1219 + debugTask.run(
1220 + // $FlowFixMe[method-unbinding]
1221 + performance.measure.bind(performance, 'Errored', options),
1222 + );
1223 + } else {
1224 + performance.measure('Errored', options);
1225 + }
1226 } else {
1227 console.timeStamp(
1228 'Errored',
@@ -1048,20 +1240,39 @@ export function logCommitPhase(
1240 startTime: number,
1241 endTime: number,
1242 errors: null | Array<CapturedValue<mixed>>,
1243 + debugTask: null | ConsoleTask,
1244 ): void {
1245 if (errors !== null) {
1053 - logCommitErrored(startTime, endTime, errors, false);
1246 + logCommitErrored(startTime, endTime, errors, false, debugTask);
1247 return;
1248 }
1249 if (supportsUserTiming) {
1057 - console.timeStamp(
1058 - 'Commit',
1059 - startTime,
1060 - endTime,
1061 - currentTrack,
1062 - LANES_TRACK_GROUP,
1063 - 'secondary-dark',
1064 - );
1250 + if (endTime <= startTime) {
1251 + return;
1252 + }
1253 + if (__DEV__ && debugTask) {
1254 + debugTask.run(
1255 + // $FlowFixMe[method-unbinding]
1256 + console.timeStamp.bind(
1257 + console,
1258 + 'Commit',
1259 + startTime,
1260 + endTime,
1261 + currentTrack,
1262 + LANES_TRACK_GROUP,
1263 + 'secondary-dark',
1264 + ),
1265 + );
1266 + } else {
1267 + console.timeStamp(
1268 + 'Commit',
1269 + startTime,
1270 + endTime,
1271 + currentTrack,
1272 + LANES_TRACK_GROUP,
1273 + 'secondary-dark',
1274 + );
1275 + }
1276 }
1277 }
1278
@@ -1069,16 +1280,35 @@ export function logPaintYieldPhase(
1280 startTime: number,
1281 endTime: number,
1282 delayedUntilPaint: boolean,
1283 + debugTask: null | ConsoleTask,
1284 ): void {
1285 if (supportsUserTiming) {
1074 - console.timeStamp(
1075 - delayedUntilPaint ? 'Waiting for Paint' : '',
1076 - startTime,
1077 - endTime,
1078 - currentTrack,
1079 - LANES_TRACK_GROUP,
1080 - 'secondary-light',
1081 - );
1286 + if (endTime <= startTime) {
1287 + return;
1288 + }
1289 + if (__DEV__ && debugTask) {
1290 + debugTask.run(
1291 + // $FlowFixMe[method-unbinding]
1292 + console.timeStamp.bind(
1293 + console,
1294 + delayedUntilPaint ? 'Waiting for Paint' : '',
1295 + startTime,
1296 + endTime,
1297 + currentTrack,
1298 + LANES_TRACK_GROUP,
1299 + 'secondary-light',
1300 + ),
1301 + );
1302 + } else {
1303 + console.timeStamp(
1304 + delayedUntilPaint ? 'Waiting for Paint' : '',
1305 + startTime,
1306 + endTime,
1307 + currentTrack,
1308 + LANES_TRACK_GROUP,
1309 + 'secondary-light',
1310 + );
1311 + }
1312 }
1313 }
1314
@@ -1086,19 +1316,38 @@ export function logPassiveCommitPhase(
1316 startTime: number,
1317 endTime: number,
1318 errors: null | Array<CapturedValue<mixed>>,
1319 + debugTask: null | ConsoleTask,
1320 ): void {
1321 if (errors !== null) {
1091 - logCommitErrored(startTime, endTime, errors, true);
1322 + logCommitErrored(startTime, endTime, errors, true, debugTask);
1323 return;
1324 }
1325 if (supportsUserTiming) {
1095 - console.timeStamp(
1096 - 'Remaining Effects',
1097 - startTime,
1098 - endTime,
1099 - currentTrack,
1100 - LANES_TRACK_GROUP,
1101 - 'secondary-dark',
1102 - );
1326 + if (endTime <= startTime) {
1327 + return;
1328 + }
1329 + if (__DEV__ && debugTask) {
1330 + debugTask.run(
1331 + // $FlowFixMe[method-unbinding]
1332 + console.timeStamp.bind(
1333 + console,
1334 + 'Remaining Effects',
1335 + startTime,
1336 + endTime,
1337 + currentTrack,
1338 + LANES_TRACK_GROUP,
1339 + 'secondary-dark',
1340 + ),
1341 + );
1342 + } else {
1343 + console.timeStamp(
1344 + 'Remaining Effects',
1345 + startTime,
1346 + endTime,
1347 + currentTrack,
1348 + LANES_TRACK_GROUP,
1349 + 'secondary-dark',
1350 + );
1351 + }
1352 }
1353 }
packages/react-reconciler/src/ReactFiberReconciler.js
+1
@@ -346,6 +346,7 @@ export function createHydrationContainer(
346 update.callback =
347 callback !== undefined && callback !== null ? callback : null;
348 enqueueUpdate(current, update, lane);
349 + startUpdateTimerByLane(lane, 'hydrateRoot()');
350 scheduleInitialHydrationOnRoot(root, lane);
351
352 return root;
packages/react-reconciler/src/ReactFiberWorkLoop.js
+76 -9
@@ -266,15 +266,16 @@ import {
266 blockingClampTime,
267 blockingUpdateTime,
268 blockingUpdateTask,
269 + blockingUpdateType,
270 blockingEventTime,
271 blockingEventType,
272 blockingEventIsRepeat,
272 - blockingSpawnedUpdate,
273 blockingSuspendedTime,
274 transitionClampTime,
275 transitionStartTime,
276 transitionUpdateTime,
277 transitionUpdateTask,
278 + transitionUpdateType,
279 transitionEventTime,
280 transitionEventType,
281 transitionEventIsRepeat,
@@ -301,6 +302,8 @@ import {
302 startPingTimerByLanes,
303 recordEffectError,
304 resetCommitErrors,
305 + PINGED_UPDATE,
306 + SPAWNED_UPDATE,
307 } from './ReactProfilerTimer';
308
309 // DEV stuff
@@ -482,6 +485,9 @@ export function getWorkInProgressTransitions(): null | Array<Transition> {
485 return workInProgressTransitions;
486 }
487
488 +// The first setState call that eventually caused the current render.
489 +let workInProgressUpdateTask: null | ConsoleTask = null;
490 +
491 let currentPendingTransitionCallbacks: PendingTransitionCallbacks | null = null;
492 let currentEndTime: number | null = null;
493
@@ -1104,7 +1110,11 @@ export function performWorkOnRoot(
1110 ) {
1111 if (enableProfilerTimer && enableComponentPerformanceTrack) {
1112 setCurrentTrackFromLanes(lanes);
1107 - logInconsistentRender(renderStartTime, renderEndTime);
1113 + logInconsistentRender(
1114 + renderStartTime,
1115 + renderEndTime,
1116 + workInProgressUpdateTask,
1117 + );
1118 finalizeRender(lanes, renderEndTime);
1119 }
1120 // A store was mutated in an interleaved event. Render again,
@@ -1130,7 +1140,12 @@ export function performWorkOnRoot(
1140 if (errorRetryLanes !== NoLanes) {
1141 if (enableProfilerTimer && enableComponentPerformanceTrack) {
1142 setCurrentTrackFromLanes(lanes);
1133 - logErroredRenderPhase(renderStartTime, renderEndTime, lanes);
1143 + logErroredRenderPhase(
1144 + renderStartTime,
1145 + renderEndTime,
1146 + lanes,
1147 + workInProgressUpdateTask,
1148 + );
1149 finalizeRender(lanes, renderEndTime);
1150 }
1151 lanes = errorRetryLanes;
@@ -1161,7 +1176,12 @@ export function performWorkOnRoot(
1176 if (exitStatus === RootFatalErrored) {
1177 if (enableProfilerTimer && enableComponentPerformanceTrack) {
1178 setCurrentTrackFromLanes(lanes);
1164 - logErroredRenderPhase(renderStartTime, renderEndTime, lanes);
1179 + logErroredRenderPhase(
1180 + renderStartTime,
1181 + renderEndTime,
1182 + lanes,
1183 + workInProgressUpdateTask,
1184 + );
1185 finalizeRender(lanes, renderEndTime);
1186 }
1187 prepareFreshStack(root, NoLanes);
@@ -1302,7 +1322,12 @@ function finishConcurrentRender(
1322 // until we receive more data.
1323 if (enableProfilerTimer && enableComponentPerformanceTrack) {
1324 setCurrentTrackFromLanes(lanes);
1305 - logSuspendedRenderPhase(renderStartTime, renderEndTime, lanes);
1325 + logSuspendedRenderPhase(
1326 + renderStartTime,
1327 + renderEndTime,
1328 + lanes,
1329 + workInProgressUpdateTask,
1330 + );
1331 finalizeRender(lanes, renderEndTime);
1332 trackSuspendedTime(lanes, renderEndTime);
1333 }
@@ -1867,18 +1892,22 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber {
1892 previousRenderStartTime,
1893 renderStartTime,
1894 lanes,
1895 + workInProgressUpdateTask,
1896 );
1897 } else {
1898 logInterruptedRenderPhase(
1899 previousRenderStartTime,
1900 renderStartTime,
1901 lanes,
1902 + workInProgressUpdateTask,
1903 );
1904 }
1905 finalizeRender(workInProgressRootRenderLanes, renderStartTime);
1906 }
1907
1908 + workInProgressUpdateTask = null;
1909 if (includesSyncLane(lanes) || includesBlockingLane(lanes)) {
1910 + workInProgressUpdateTask = blockingUpdateTask;
1911 const clampedUpdateTime =
1912 blockingUpdateTime >= 0 && blockingUpdateTime < blockingClampTime
1913 ? blockingClampTime
@@ -1898,6 +1927,7 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber {
1927 ? clampedUpdateTime
1928 : renderStartTime,
1929 lanes,
1930 + workInProgressUpdateTask,
1931 );
1932 }
1933 logBlockingStart(
@@ -1905,7 +1935,8 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber {
1935 clampedEventTime,
1936 blockingEventType,
1937 blockingEventIsRepeat,
1908 - blockingSpawnedUpdate,
1938 + blockingUpdateType === SPAWNED_UPDATE,
1939 + blockingUpdateType === PINGED_UPDATE,
1940 renderStartTime,
1941 lanes,
1942 blockingUpdateTask,
@@ -1913,6 +1944,7 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber {
1944 clearBlockingTimers();
1945 }
1946 if (includesTransitionLane(lanes)) {
1947 + workInProgressUpdateTask = transitionUpdateTask;
1948 const clampedStartTime =
1949 transitionStartTime >= 0 && transitionStartTime < transitionClampTime
1950 ? transitionClampTime
@@ -1936,6 +1968,7 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber {
1968 ? clampedUpdateTime
1969 : renderStartTime,
1970 lanes,
1971 + workInProgressUpdateTask,
1972 );
1973 }
1974 logTransitionStart(
@@ -1944,6 +1977,7 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber {
1977 clampedEventTime,
1978 transitionEventType,
1979 transitionEventIsRepeat,
1980 + transitionUpdateType === PINGED_UPDATE,
1981 renderStartTime,
1982 transitionUpdateTask,
1983 );
@@ -2227,6 +2261,21 @@ function popAsyncDispatcher(prevAsyncDispatcher: any) {
2261 ReactSharedInternals.A = prevAsyncDispatcher;
2262 }
2263
2264 +export function markRenderDerivedCause(fiber: Fiber): void {
2265 + if (enableProfilerTimer && enableComponentPerformanceTrack) {
2266 + if (__DEV__) {
2267 + if (workInProgressUpdateTask === null) {
2268 + // If we don't have a cause associated with this render, it's likely because some
2269 + // other render left work behind on this Fiber. The real cause is this Fiber itself.
2270 + // We use its debugTask as the cause for this render. This might not be the only
2271 + // one when multiple siblings are rendered but they ideally shouldn't be.
2272 + workInProgressUpdateTask =
2273 + fiber._debugTask == null ? null : fiber._debugTask;
2274 + }
2275 + }
2276 + }
2277 +}
2278 +
2279 export function markCommitTimeOfFallback() {
2280 globalMostRecentFallbackTime = now();
2281 }
@@ -3239,6 +3288,7 @@ function commitRoot(
3288 completedRenderStartTime,
3289 completedRenderEndTime,
3290 lanes,
3291 + workInProgressUpdateTask,
3292 );
3293 } else if (recoverableErrors !== null) {
3294 const hydrationFailed =
@@ -3252,9 +3302,15 @@ function commitRoot(
3302 lanes,
3303 recoverableErrors,
3304 hydrationFailed,
3305 + workInProgressUpdateTask,
3306 );
3307 } else {
3257 - logRenderPhase(completedRenderStartTime, completedRenderEndTime, lanes);
3308 + logRenderPhase(
3309 + completedRenderStartTime,
3310 + completedRenderEndTime,
3311 + lanes,
3312 + workInProgressUpdateTask,
3313 + );
3314 }
3315 }
3316
@@ -3425,9 +3481,17 @@ function commitRoot(
3481 recordCommitTime();
3482 if (enableComponentPerformanceTrack) {
3483 if (suspendedCommitReason === SUSPENDED_COMMIT) {
3428 - logSuspendedCommitPhase(completedRenderEndTime, commitStartTime);
3484 + logSuspendedCommitPhase(
3485 + completedRenderEndTime,
3486 + commitStartTime,
3487 + workInProgressUpdateTask,
3488 + );
3489 } else if (suspendedCommitReason === THROTTLED_COMMIT) {
3430 - logSuspenseThrottlePhase(completedRenderEndTime, commitStartTime);
3490 + logSuspenseThrottlePhase(
3491 + completedRenderEndTime,
3492 + commitStartTime,
3493 + workInProgressUpdateTask,
3494 + );
3495 }
3496 }
3497 }
@@ -3672,6 +3736,7 @@ function flushSpawnedWork(): void {
3736 : commitStartTime,
3737 commitEndTime,
3738 commitErrors,
3739 + workInProgressUpdateTask,
3740 );
3741 }
3742
@@ -4147,6 +4212,7 @@ function flushPassiveEffectsImpl(wasDelayedCommit: void | boolean) {
4212 commitEndTime,
4213 passiveEffectStartTime,
4214 !!wasDelayedCommit,
4215 + workInProgressUpdateTask,
4216 );
4217 }
4218
@@ -4182,6 +4248,7 @@ function flushPassiveEffectsImpl(wasDelayedCommit: void | boolean) {
4248 passiveEffectStartTime,
4249 passiveEffectsEndTime,
4250 commitErrors,
4251 + workInProgressUpdateTask,
4252 );
4253 finalizeRender(lanes, passiveEffectsEndTime);
4254 }
packages/react-reconciler/src/ReactProfilerTimer.js
+63 -20
@@ -48,6 +48,11 @@ const createTask =
48 console.createTask
49 : (name: string) => null;
50
51 +export const REGULAR_UPDATE: UpdateType = 0;
52 +export const SPAWNED_UPDATE: UpdateType = 1;
53 +export const PINGED_UPDATE: UpdateType = 2;
54 +export opaque type UpdateType = 0 | 1 | 2;
55 +
56 export let renderStartTime: number = -0;
57 export let commitStartTime: number = -0;
58 export let commitEndTime: number = -0;
@@ -62,15 +67,16 @@ export let componentEffectErrors: null | Array<CapturedValue<mixed>> = null;
67 export let blockingClampTime: number = -0;
68 export let blockingUpdateTime: number = -1.1; // First sync setState scheduled.
69 export let blockingUpdateTask: null | ConsoleTask = null; // First sync setState's stack trace.
70 +export let blockingUpdateType: UpdateType = 0;
71 export let blockingEventTime: number = -1.1; // Event timeStamp of the first setState.
72 export let blockingEventType: null | string = null; // Event type of the first setState.
73 export let blockingEventIsRepeat: boolean = false;
68 -export let blockingSpawnedUpdate: boolean = false;
74 export let blockingSuspendedTime: number = -1.1;
75 // TODO: This should really be one per Transition lane.
76 export let transitionClampTime: number = -0;
77 export let transitionStartTime: number = -1.1; // First startTransition call before setState.
78 export let transitionUpdateTime: number = -1.1; // First transition setState scheduled.
79 +export let transitionUpdateType: UpdateType = 0;
80 export let transitionUpdateTask: null | ConsoleTask = null; // First transition setState's stack trace.
81 export let transitionEventTime: number = -1.1; // Event timeStamp of the first transition.
82 export let transitionEventType: null | string = null; // Event type of the first transition.
@@ -97,7 +103,7 @@ export function startUpdateTimerByLane(lane: Lane, method: string): void {
103 blockingUpdateTime = now();
104 blockingUpdateTask = createTask(method);
105 if (isAlreadyRendering()) {
100 - blockingSpawnedUpdate = true;
106 + blockingUpdateType = SPAWNED_UPDATE;
107 }
108 const newEventTime = resolveEventTimeStamp();
109 const newEventType = resolveEventType();
@@ -110,7 +116,7 @@ export function startUpdateTimerByLane(lane: Lane, method: string): void {
116 // If this is a second update in the same event, we treat it as a spawned update.
117 // This might be a microtask spawned from useEffect, multiple flushSync or
118 // a setState in a microtask spawned after the first setState. Regardless it's bad.
113 - blockingSpawnedUpdate = true;
119 + blockingUpdateType = SPAWNED_UPDATE;
120 }
121 blockingEventTime = newEventTime;
122 blockingEventType = newEventType;
@@ -135,6 +141,54 @@ export function startUpdateTimerByLane(lane: Lane, method: string): void {
141 }
142 }
143
144 +export function startHostActionTimer(fiber: Fiber): void {
145 + if (!enableProfilerTimer || !enableComponentPerformanceTrack) {
146 + return;
147 + }
148 + // This schedules an update on both the blocking lane for the pending state and on the
149 + // transition lane for the action update. Using the debug task from the host fiber.
150 + if (blockingUpdateTime < 0) {
151 + blockingUpdateTime = now();
152 + blockingUpdateTask =
153 + __DEV__ && fiber._debugTask != null ? fiber._debugTask : null;
154 + if (isAlreadyRendering()) {
155 + blockingUpdateType = SPAWNED_UPDATE;
156 + }
157 + const newEventTime = resolveEventTimeStamp();
158 + const newEventType = resolveEventType();
159 + if (
160 + newEventTime !== blockingEventTime ||
161 + newEventType !== blockingEventType
162 + ) {
163 + blockingEventIsRepeat = false;
164 + } else if (newEventType !== null) {
165 + // If this is a second update in the same event, we treat it as a spawned update.
166 + // This might be a microtask spawned from useEffect, multiple flushSync or
167 + // a setState in a microtask spawned after the first setState. Regardless it's bad.
168 + blockingUpdateType = SPAWNED_UPDATE;
169 + }
170 + blockingEventTime = newEventTime;
171 + blockingEventType = newEventType;
172 + }
173 + if (transitionUpdateTime < 0) {
174 + transitionUpdateTime = now();
175 + transitionUpdateTask =
176 + __DEV__ && fiber._debugTask != null ? fiber._debugTask : null;
177 + if (transitionStartTime < 0) {
178 + const newEventTime = resolveEventTimeStamp();
179 + const newEventType = resolveEventType();
180 + if (
181 + newEventTime !== transitionEventTime ||
182 + newEventType !== transitionEventType
183 + ) {
184 + transitionEventIsRepeat = false;
185 + }
186 + transitionEventTime = newEventTime;
187 + transitionEventType = newEventType;
188 + }
189 + }
190 +}
191 +
192 export function startPingTimerByLanes(lanes: Lanes): void {
193 if (!enableProfilerTimer || !enableComponentPerformanceTrack) {
194 return;
@@ -145,10 +199,14 @@ export function startPingTimerByLanes(lanes: Lanes): void {
199 if (includesSyncLane(lanes) || includesBlockingLane(lanes)) {
200 if (blockingUpdateTime < 0) {
201 blockingClampTime = blockingUpdateTime = now();
202 + blockingUpdateTask = createTask('Promise Resolved');
203 + blockingUpdateType = PINGED_UPDATE;
204 }
205 } else if (includesTransitionLane(lanes)) {
206 if (transitionUpdateTime < 0) {
207 transitionClampTime = transitionUpdateTime = now();
208 + transitionUpdateTask = createTask('Promise Resolved');
209 + transitionUpdateType = PINGED_UPDATE;
210 }
211 }
212 }
@@ -166,10 +224,9 @@ export function trackSuspendedTime(lanes: Lanes, renderEndTime: number) {
224
225 export function clearBlockingTimers(): void {
226 blockingUpdateTime = -1.1;
169 - blockingUpdateTask = null;
227 + blockingUpdateType = 0;
228 blockingSuspendedTime = -1.1;
229 blockingEventIsRepeat = true;
172 - blockingSpawnedUpdate = false;
230 }
231
232 export function startAsyncTransitionTimer(): void {
@@ -196,20 +253,6 @@ export function hasScheduledTransitionWork(): boolean {
253 return transitionUpdateTime > -1;
254 }
255
199 -// We use this marker to indicate that we have scheduled a render to be performed
200 -// but it's not an explicit state update.
201 -const ACTION_STATE_MARKER = -0.5;
202 -
203 -export function startActionStateUpdate(): void {
204 - if (!enableProfilerTimer || !enableComponentPerformanceTrack) {
205 - return;
206 - }
207 - if (transitionUpdateTime < 0) {
208 - transitionUpdateTime = ACTION_STATE_MARKER;
209 - transitionUpdateTask = null;
210 - }
211 -}
212 -
256 export function clearAsyncTransitionTimer(): void {
257 transitionStartTime = -1.1;
258 }
@@ -217,7 +260,7 @@ export function clearAsyncTransitionTimer(): void {
260 export function clearTransitionTimers(): void {
261 transitionStartTime = -1.1;
262 transitionUpdateTime = -1.1;
220 - transitionUpdateTask = null;
263 + transitionUpdateType = 0;
264 transitionSuspendedTime = -1.1;
265 transitionEventIsRepeat = true;
266 }