Skip to content

Commit bb6c9d5

Browse files
[Flight] Log aborted await and component renders (#33641)
<img width="926" alt="Screenshot 2025-06-25 at 1 02 14 PM" src="https://github.com/user-attachments/assets/1877d13d-5259-4cc4-8f48-12981e3073fe" /> The I/O entry doesn't show as aborted in the Server Request track because technically it wasn't. The end time is just made up. It's still going. It's not aborted until the abort signal propagates and if we do get that signal wired up before it emits, it instead would show up as rejected. --------- Co-authored-by: Hendrik Liebau <[email protected]>
1 parent 123ff13 commit bb6c9d5

File tree

3 files changed

+150
-9
lines changed

3 files changed

+150
-9
lines changed

packages/react-client/src/ReactFlightClient.js

Lines changed: 46 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -77,10 +77,12 @@ import {
7777
markAllTracksInOrder,
7878
logComponentRender,
7979
logDedupedComponentRender,
80+
logComponentAborted,
8081
logComponentErrored,
8182
logIOInfo,
8283
logIOInfoErrored,
8384
logComponentAwait,
85+
logComponentAwaitAborted,
8486
logComponentAwaitErrored,
8587
} from './ReactFlightPerformanceTrack';
8688

@@ -1812,6 +1814,12 @@ function ResponseInstance(
18121814
this._replayConsole = replayConsole;
18131815
this._rootEnvironmentName = rootEnv;
18141816
}
1817+
if (enableProfilerTimer && enableComponentPerformanceTrack) {
1818+
// Since we don't know when recording of profiles will start and stop, we have to
1819+
// mark the order over and over again.
1820+
markAllTracksInOrder();
1821+
}
1822+
18151823
// Don't inline this call because it causes closure to outline the call above.
18161824
this._fromJSON = createFromJSONCallback(this);
18171825
}
@@ -3291,6 +3299,44 @@ function flushComponentPerformance(
32913299
}
32923300
}
32933301
}
3302+
} else {
3303+
// Anything between the end and now was aborted if it has no end time.
3304+
// Either because the client stream was aborted reading it or the server stream aborted.
3305+
endTime = time; // If we don't find anything else the endTime is the start time.
3306+
for (let j = debugInfo.length - 1; j > i; j--) {
3307+
const candidateInfo = debugInfo[j];
3308+
if (typeof candidateInfo.name === 'string') {
3309+
if (componentEndTime > childrenEndTime) {
3310+
childrenEndTime = componentEndTime;
3311+
}
3312+
// $FlowFixMe: Refined.
3313+
const componentInfo: ReactComponentInfo = candidateInfo;
3314+
const env = response._rootEnvironmentName;
3315+
logComponentAborted(
3316+
componentInfo,
3317+
trackIdx,
3318+
time,
3319+
componentEndTime,
3320+
childrenEndTime,
3321+
env,
3322+
);
3323+
componentEndTime = time; // The end time of previous component is the start time of the next.
3324+
// Track the root most component of the result for deduping logging.
3325+
result.component = componentInfo;
3326+
isLastComponent = false;
3327+
} else if (candidateInfo.awaited) {
3328+
// If we don't have an end time for an await, that means we aborted.
3329+
const asyncInfo: ReactAsyncInfo = candidateInfo;
3330+
const env = response._rootEnvironmentName;
3331+
if (asyncInfo.awaited.end > endTime) {
3332+
endTime = asyncInfo.awaited.end; // Take the end time of the I/O as the await end.
3333+
}
3334+
if (endTime > childrenEndTime) {
3335+
childrenEndTime = endTime;
3336+
}
3337+
logComponentAwaitAborted(asyncInfo, trackIdx, time, endTime, env);
3338+
}
3339+
}
32943340
}
32953341
endTime = time; // The end time of the next entry is this time.
32963342
endTimeIdx = i;

packages/react-client/src/ReactFlightPerformanceTrack.js

Lines changed: 97 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -247,6 +247,53 @@ export function logComponentRender(
247247
}
248248
}
249249

250+
export function logComponentAborted(
251+
componentInfo: ReactComponentInfo,
252+
trackIdx: number,
253+
startTime: number,
254+
endTime: number,
255+
childrenEndTime: number,
256+
rootEnv: string,
257+
): void {
258+
if (supportsUserTiming) {
259+
const env = componentInfo.env;
260+
const name = componentInfo.name;
261+
const isPrimaryEnv = env === rootEnv;
262+
const entryName =
263+
isPrimaryEnv || env === undefined ? name : name + ' [' + env + ']';
264+
if (__DEV__) {
265+
const properties = [
266+
[
267+
'Aborted',
268+
'The stream was aborted before this Component finished rendering.',
269+
],
270+
];
271+
performance.measure(entryName, {
272+
start: startTime < 0 ? 0 : startTime,
273+
end: childrenEndTime,
274+
detail: {
275+
devtools: {
276+
color: 'warning',
277+
track: trackNames[trackIdx],
278+
trackGroup: COMPONENTS_TRACK,
279+
tooltipText: entryName + ' Aborted',
280+
properties,
281+
},
282+
},
283+
});
284+
} else {
285+
console.timeStamp(
286+
entryName,
287+
startTime < 0 ? 0 : startTime,
288+
childrenEndTime,
289+
trackNames[trackIdx],
290+
COMPONENTS_TRACK,
291+
'warning',
292+
);
293+
}
294+
}
295+
}
296+
250297
export function logComponentErrored(
251298
componentInfo: ReactComponentInfo,
252299
trackIdx: number,
@@ -352,6 +399,54 @@ function getIOColor(
352399
}
353400
}
354401

402+
export function logComponentAwaitAborted(
403+
asyncInfo: ReactAsyncInfo,
404+
trackIdx: number,
405+
startTime: number,
406+
endTime: number,
407+
rootEnv: string,
408+
): void {
409+
if (supportsUserTiming && endTime > 0) {
410+
const env = asyncInfo.env;
411+
const name = asyncInfo.awaited.name;
412+
const isPrimaryEnv = env === rootEnv;
413+
const entryName =
414+
'await ' +
415+
(isPrimaryEnv || env === undefined ? name : name + ' [' + env + ']');
416+
const debugTask = asyncInfo.debugTask || asyncInfo.awaited.debugTask;
417+
if (__DEV__ && debugTask) {
418+
const properties = [
419+
['Aborted', 'The stream was aborted before this Promise resolved.'],
420+
];
421+
debugTask.run(
422+
// $FlowFixMe[method-unbinding]
423+
performance.measure.bind(performance, entryName, {
424+
start: startTime < 0 ? 0 : startTime,
425+
end: endTime,
426+
detail: {
427+
devtools: {
428+
color: 'warning',
429+
track: trackNames[trackIdx],
430+
trackGroup: COMPONENTS_TRACK,
431+
properties,
432+
tooltipText: entryName + ' Aborted',
433+
},
434+
},
435+
}),
436+
);
437+
} else {
438+
console.timeStamp(
439+
entryName,
440+
startTime < 0 ? 0 : startTime,
441+
endTime,
442+
trackNames[trackIdx],
443+
COMPONENTS_TRACK,
444+
'warning',
445+
);
446+
}
447+
}
448+
}
449+
355450
export function logComponentAwaitErrored(
356451
asyncInfo: ReactAsyncInfo,
357452
trackIdx: number,
@@ -367,7 +462,7 @@ export function logComponentAwaitErrored(
367462
const entryName =
368463
'await ' +
369464
(isPrimaryEnv || env === undefined ? name : name + ' [' + env + ']');
370-
const debugTask = asyncInfo.debugTask;
465+
const debugTask = asyncInfo.debugTask || asyncInfo.awaited.debugTask;
371466
if (__DEV__ && debugTask) {
372467
const message =
373468
typeof error === 'object' &&
@@ -423,7 +518,7 @@ export function logComponentAwait(
423518
const entryName =
424519
'await ' +
425520
(isPrimaryEnv || env === undefined ? name : name + ' [' + env + ']');
426-
const debugTask = asyncInfo.debugTask;
521+
const debugTask = asyncInfo.debugTask || asyncInfo.awaited.debugTask;
427522
if (__DEV__ && debugTask) {
428523
const properties: Array<[string, string]> = [];
429524
if (typeof value === 'object' && value !== null) {

packages/react-server/src/ReactFlightServer.js

Lines changed: 7 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -2151,9 +2151,7 @@ function visitAsyncNode(
21512151
});
21522152
// Mark the end time of the await. If we're aborting then we don't emit this
21532153
// to signal that this never resolved inside this render.
2154-
if (request.status !== ABORTING) {
2155-
markOperationEndTime(request, task, endTime);
2156-
}
2154+
markOperationEndTime(request, task, endTime);
21572155
}
21582156
}
21592157
}
@@ -2216,10 +2214,8 @@ function emitAsyncSequence(
22162214
emitDebugChunk(request, task.id, debugInfo);
22172215
// Mark the end time of the await. If we're aborting then we don't emit this
22182216
// to signal that this never resolved inside this render.
2219-
if (request.status !== ABORTING) {
2220-
// If we're currently aborting, then this never resolved into user space.
2221-
markOperationEndTime(request, task, awaitedNode.end);
2222-
}
2217+
// If we're currently aborting, then this never resolved into user space.
2218+
markOperationEndTime(request, task, awaitedNode.end);
22232219
}
22242220
}
22252221

@@ -4808,6 +4804,10 @@ function markOperationEndTime(request: Request, task: Task, timestamp: number) {
48084804
}
48094805
// This is like advanceTaskTime() but always emits a timing chunk even if it doesn't advance.
48104806
// This ensures that the end time of the previous entry isn't implied to be the start of the next one.
4807+
if (request.status === ABORTING) {
4808+
// If we're aborting then we don't emit any end times that happened after.
4809+
return;
4810+
}
48114811
if (timestamp > task.time) {
48124812
emitTimingChunk(request, task.id, timestamp);
48134813
task.time = timestamp;

0 commit comments

Comments
 (0)