From 1d856c2cb349315d3a66d87b33b85a649ff7901e Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Mon, 2 Jun 2025 15:41:37 -0400 Subject: [PATCH 1/8] Test immediately resolved non-native thenable This turns into a cycle but it's fine as long as we just ignore it since it doesn't depend on I/O. --- .../ReactFlightAsyncDebugInfo-test.js | 57 +++++++++++++++++++ 1 file changed, 57 insertions(+) diff --git a/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js b/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js index da2fc898b93b5..80d900794b41b 100644 --- a/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js +++ b/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js @@ -466,4 +466,61 @@ describe('ReactFlightAsyncDebugInfo', () => { `); } }); + + it('can ingores the start of I/O when immediately resolved non-native promise is awaited', async () => { + async function Component() { + return await { + then(callback) { + callback('hi'); + }, + }; + } + + const stream = ReactServerDOMServer.renderToPipeableStream(); + + const readable = new Stream.PassThrough(streamOptions); + + const result = ReactServerDOMClient.createFromNodeStream(readable, { + moduleMap: {}, + moduleLoading: {}, + }); + stream.pipe(readable); + + expect(await result).toBe('hi'); + if ( + __DEV__ && + gate( + flags => + flags.enableComponentPerformanceTrack && flags.enableAsyncDebugInfo, + ) + ) { + expect(getDebugInfo(result)).toMatchInlineSnapshot(` + [ + { + "time": 0, + }, + { + "env": "Server", + "key": null, + "name": "Component", + "owner": null, + "props": {}, + "stack": [ + [ + "Object.", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 479, + 109, + 470, + 94, + ], + ], + }, + { + "time": 0, + }, + ] + `); + } + }); }); From 5d70c74f117d1614c1ebf3dafb00158ed5bcb1ef Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Mon, 2 Jun 2025 19:58:27 -0400 Subject: [PATCH 2/8] Explicitly type Resolved vs Unresolved Promises One thing that's a bit confusing is that an UnresolvedAwaitNode can resolve after its children since it's resolved after the then() function is invoked. --- .../src/ReactFlightAsyncSequence.js | 31 +++++++++- .../react-server/src/ReactFlightServer.js | 26 +++++++-- .../src/ReactFlightServerConfigDebugNode.js | 56 ++++++++++++++----- 3 files changed, 93 insertions(+), 20 deletions(-) diff --git a/packages/react-server/src/ReactFlightAsyncSequence.js b/packages/react-server/src/ReactFlightAsyncSequence.js index b36fb551091ee..b1fbdf2ed3c57 100644 --- a/packages/react-server/src/ReactFlightAsyncSequence.js +++ b/packages/react-server/src/ReactFlightAsyncSequence.js @@ -12,6 +12,8 @@ import type {ReactComponentInfo} from 'shared/ReactTypes'; export const IO_NODE = 0; export const PROMISE_NODE = 1; export const AWAIT_NODE = 2; +export const UNRESOLVED_PROMISE_NODE = 3; +export const UNRESOLVED_AWAIT_NODE = 4; export type IONode = { tag: 0, @@ -20,7 +22,7 @@ export type IONode = { start: number, // start time when the first part of the I/O sequence started end: number, // we typically don't use this. only when there's no promise intermediate. awaited: null, // I/O is only blocked on external. - previous: null | AwaitNode, // the preceeding await that spawned this new work + previous: null | AwaitNode | UnresolvedAwaitNode, // the preceeding await that spawned this new work }; export type PromiseNode = { @@ -43,4 +45,29 @@ export type AwaitNode = { previous: null | AsyncSequence, // the sequence that was blocking us from awaiting in the first place }; -export type AsyncSequence = IONode | PromiseNode | AwaitNode; +export type UnresolvedPromiseNode = { + tag: 3, + owner: null | ReactComponentInfo, + stack: Error, // callsite that created the Promise + start: number, // start time when the Promise was created + end: -1.1, // set when we resolve. + awaited: null | AsyncSequence, // the thing that ended up resolving this promise + previous: null, // where we created the promise is not interesting since creating it doesn't mean waiting. +}; + +export type UnresolvedAwaitNode = { + tag: 4, + owner: null | ReactComponentInfo, + stack: Error, // callsite that awaited (using await, .then(), Promise.all(), ...) + start: number, // when we started blocking. This might be later than the I/O started. + end: -1.1, // set when we resolve. + awaited: null | AsyncSequence, // the promise we were waiting on + previous: null | AsyncSequence, // the sequence that was blocking us from awaiting in the first place +}; + +export type AsyncSequence = + | IONode + | PromiseNode + | AwaitNode + | UnresolvedPromiseNode + | UnresolvedAwaitNode; diff --git a/packages/react-server/src/ReactFlightServer.js b/packages/react-server/src/ReactFlightServer.js index e5c6043652c85..b523a54d1f4aa 100644 --- a/packages/react-server/src/ReactFlightServer.js +++ b/packages/react-server/src/ReactFlightServer.js @@ -149,7 +149,13 @@ import binaryToComparableString from 'shared/binaryToComparableString'; import {SuspenseException, getSuspendedThenable} from './ReactFlightThenable'; -import {IO_NODE, PROMISE_NODE, AWAIT_NODE} from './ReactFlightAsyncSequence'; +import { + IO_NODE, + PROMISE_NODE, + AWAIT_NODE, + UNRESOLVED_AWAIT_NODE, + UNRESOLVED_PROMISE_NODE, +} from './ReactFlightAsyncSequence'; // DEV-only set containing internal objects that should not be limited and turned into getters. const doNotLimit: WeakSet = __DEV__ ? new WeakSet() : (null: any); @@ -1879,6 +1885,9 @@ function visitAsyncNode( case IO_NODE: { return node; } + case UNRESOLVED_PROMISE_NODE: { + return null; + } case PROMISE_NODE: { if (node.end < cutOff) { // This was already resolved when we started this sequence. It must have been @@ -1914,22 +1923,29 @@ function visitAsyncNode( } return null; } + case UNRESOLVED_AWAIT_NODE: + // We could be inside the .then() which is about to resolve this node. + // TODO: We could call emitAsyncSequence in a microtask to avoid this issue. + // Fallthrough to the resolved path. case AWAIT_NODE: { const awaited = node.awaited; if (awaited !== null) { const ioNode = visitAsyncNode(request, task, awaited, cutOff, visited); if (ioNode !== null) { - if (node.end < 0) { + let endTime: number; + if (node.tag === UNRESOLVED_AWAIT_NODE) { // If we haven't defined an end time, use the resolve of the inner Promise. // This can happen because the ping gets invoked before the await gets resolved. if (ioNode.end < node.start) { // If we're awaiting a resolved Promise it could have finished before we started. - node.end = node.start; + endTime = node.start; } else { - node.end = ioNode.end; + endTime = ioNode.end; } + } else { + endTime = node.end; } - if (node.end < cutOff) { + if (endTime < cutOff) { // This was already resolved when we started this sequence. It must have been // part of a different component. // TODO: Think of some other way to exclude irrelevant data since if we awaited diff --git a/packages/react-server/src/ReactFlightServerConfigDebugNode.js b/packages/react-server/src/ReactFlightServerConfigDebugNode.js index 7a86231ed9a5c..4370596c06495 100644 --- a/packages/react-server/src/ReactFlightServerConfigDebugNode.js +++ b/packages/react-server/src/ReactFlightServerConfigDebugNode.js @@ -11,10 +11,18 @@ import type { AsyncSequence, IONode, PromiseNode, + UnresolvedPromiseNode, AwaitNode, + UnresolvedAwaitNode, } from './ReactFlightAsyncSequence'; -import {IO_NODE, PROMISE_NODE, AWAIT_NODE} from './ReactFlightAsyncSequence'; +import { + IO_NODE, + PROMISE_NODE, + UNRESOLVED_PROMISE_NODE, + AWAIT_NODE, + UNRESOLVED_AWAIT_NODE, +} from './ReactFlightAsyncSequence'; import {resolveOwner} from './flight/ReactFlightCurrentOwner'; import {createHook, executionAsyncId} from 'async_hooks'; import {enableAsyncDebugInfo} from 'shared/ReactFeatureFlags'; @@ -46,17 +54,17 @@ export function initAsyncDebugInfo(): void { // If the thing we're waiting on is another Await we still track that sequence // so that we can later pick the best stack trace in user space. node = ({ - tag: AWAIT_NODE, + tag: UNRESOLVED_AWAIT_NODE, owner: resolveOwner(), stack: new Error(), start: performance.now(), end: -1.1, // set when resolved. awaited: trigger, // The thing we're awaiting on. Might get overrriden when we resolve. previous: current === undefined ? null : current, // The path that led us here. - }: AwaitNode); + }: UnresolvedAwaitNode); } else { node = ({ - tag: PROMISE_NODE, + tag: UNRESOLVED_PROMISE_NODE, owner: resolveOwner(), stack: new Error(), start: performance.now(), @@ -66,7 +74,7 @@ export function initAsyncDebugInfo(): void { ? null // It might get overridden when we resolve. : trigger, previous: null, - }: PromiseNode); + }: UnresolvedPromiseNode); } } else if ( type !== 'Microtask' && @@ -84,7 +92,10 @@ export function initAsyncDebugInfo(): void { awaited: null, previous: null, }: IONode); - } else if (trigger.tag === AWAIT_NODE) { + } else if ( + trigger.tag === AWAIT_NODE || + trigger.tag === UNRESOLVED_AWAIT_NODE + ) { // We have begun a new I/O sequence after the await. node = ({ tag: IO_NODE, @@ -110,13 +121,32 @@ export function initAsyncDebugInfo(): void { pendingOperations.set(asyncId, node); }, promiseResolve(asyncId: number): void { - const resolvedNode = pendingOperations.get(asyncId); - if (resolvedNode !== undefined) { - if (resolvedNode.tag === IO_NODE) { - // eslint-disable-next-line react-internal/prod-error-codes - throw new Error( - 'A Promise should never be an IO_NODE. This is a bug in React.', - ); + const node = pendingOperations.get(asyncId); + if (node !== undefined) { + let resolvedNode: AwaitNode | PromiseNode; + switch (node.tag) { + case UNRESOLVED_AWAIT_NODE: { + const awaitNode: AwaitNode = (node: any); + awaitNode.tag = AWAIT_NODE; + resolvedNode = awaitNode; + break; + } + case UNRESOLVED_PROMISE_NODE: { + const promiseNode: PromiseNode = (node: any); + promiseNode.tag = PROMISE_NODE; + resolvedNode = promiseNode; + break; + } + case IO_NODE: + // eslint-disable-next-line react-internal/prod-error-codes + throw new Error( + 'A Promise should never be an IO_NODE. This is a bug in React.', + ); + default: + // eslint-disable-next-line react-internal/prod-error-codes + throw new Error( + 'A Promise should never be resolved twice. This is a bug in React or Node.js.', + ); } // Log the end time when we resolved the promise. resolvedNode.end = performance.now(); From e9e20249f9f330695756fcaf367d5ace01213112 Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Mon, 2 Jun 2025 20:31:38 -0400 Subject: [PATCH 3/8] Collect any _debugInfo expando that is assigned to the Promise before it resolves Since this expando can't be assigned before it has been constructed, we can't do it in init. Unfortunately, we don't get passed the instance in promiseResolve() so we need to retain the instance. We must use a WeakRef since otherwise an infinite Promise that never resolves can't be GC:ed. If it does resolve, then it must be retained by the runtime until it finishes resolving at least. After that it might be too late so we have to then extract the information. A possible alternative strategy would be to install a setter on the Promise. --- .eslintrc.js | 1 + .../src/ReactFlightAsyncSequence.js | 11 ++++++++++- .../src/ReactFlightServerConfigDebugNode.js | 17 ++++++++++++++++- scripts/rollup/validate/eslintrc.cjs.js | 1 + scripts/rollup/validate/eslintrc.cjs2015.js | 1 + scripts/rollup/validate/eslintrc.esm.js | 1 + scripts/rollup/validate/eslintrc.fb.js | 1 + scripts/rollup/validate/eslintrc.rn.js | 1 + 8 files changed, 32 insertions(+), 2 deletions(-) diff --git a/.eslintrc.js b/.eslintrc.js index 1bb4e868d0694..d9397dda8e729 100644 --- a/.eslintrc.js +++ b/.eslintrc.js @@ -561,6 +561,7 @@ module.exports = { ConsoleTask: 'readonly', // TOOD: Figure out what the official name of this will be. ReturnType: 'readonly', AnimationFrameID: 'readonly', + WeakRef: 'readonly', // For Flow type annotation. Only `BigInt` is valid at runtime. bigint: 'readonly', BigInt: 'readonly', diff --git a/packages/react-server/src/ReactFlightAsyncSequence.js b/packages/react-server/src/ReactFlightAsyncSequence.js index b1fbdf2ed3c57..215af7f7953b3 100644 --- a/packages/react-server/src/ReactFlightAsyncSequence.js +++ b/packages/react-server/src/ReactFlightAsyncSequence.js @@ -7,7 +7,7 @@ * @flow */ -import type {ReactComponentInfo} from 'shared/ReactTypes'; +import type {ReactDebugInfo, ReactComponentInfo} from 'shared/ReactTypes'; export const IO_NODE = 0; export const PROMISE_NODE = 1; @@ -15,10 +15,15 @@ export const AWAIT_NODE = 2; export const UNRESOLVED_PROMISE_NODE = 3; export const UNRESOLVED_AWAIT_NODE = 4; +type PromiseWithDebugInfo = interface extends Promise { + _debugInfo?: ReactDebugInfo, +}; + export type IONode = { tag: 0, owner: null | ReactComponentInfo, stack: Error, // callsite that spawned the I/O + debugInfo: null, // not used on I/O start: number, // start time when the first part of the I/O sequence started end: number, // we typically don't use this. only when there's no promise intermediate. awaited: null, // I/O is only blocked on external. @@ -28,6 +33,7 @@ export type IONode = { export type PromiseNode = { tag: 1, owner: null | ReactComponentInfo, + debugInfo: null | ReactDebugInfo, // forwarded debugInfo from the Promise stack: Error, // callsite that created the Promise start: number, // start time when the Promise was created end: number, // end time when the Promise was resolved. @@ -38,6 +44,7 @@ export type PromiseNode = { export type AwaitNode = { tag: 2, owner: null | ReactComponentInfo, + debugInfo: null | ReactDebugInfo, // forwarded debugInfo from the Promise stack: Error, // callsite that awaited (using await, .then(), Promise.all(), ...) start: number, // when we started blocking. This might be later than the I/O started. end: number, // when we unblocked. This might be later than the I/O resolved if there's CPU time. @@ -48,6 +55,7 @@ export type AwaitNode = { export type UnresolvedPromiseNode = { tag: 3, owner: null | ReactComponentInfo, + debugInfo: WeakRef, // holds onto the Promise until we can extract debugInfo when it resolves stack: Error, // callsite that created the Promise start: number, // start time when the Promise was created end: -1.1, // set when we resolve. @@ -58,6 +66,7 @@ export type UnresolvedPromiseNode = { export type UnresolvedAwaitNode = { tag: 4, owner: null | ReactComponentInfo, + debugInfo: WeakRef, // holds onto the Promise until we can extract debugInfo when it resolves stack: Error, // callsite that awaited (using await, .then(), Promise.all(), ...) start: number, // when we started blocking. This might be later than the I/O started. end: -1.1, // set when we resolve. diff --git a/packages/react-server/src/ReactFlightServerConfigDebugNode.js b/packages/react-server/src/ReactFlightServerConfigDebugNode.js index 4370596c06495..8893a6505d539 100644 --- a/packages/react-server/src/ReactFlightServerConfigDebugNode.js +++ b/packages/react-server/src/ReactFlightServerConfigDebugNode.js @@ -38,7 +38,12 @@ const pendingOperations: Map = export function initAsyncDebugInfo(): void { if (__DEV__ && enableAsyncDebugInfo) { createHook({ - init(asyncId: number, type: string, triggerAsyncId: number): void { + init( + asyncId: number, + type: string, + triggerAsyncId: number, + resource: any, + ): void { const trigger = pendingOperations.get(triggerAsyncId); let node: AsyncSequence; if (type === 'PROMISE') { @@ -56,6 +61,7 @@ export function initAsyncDebugInfo(): void { node = ({ tag: UNRESOLVED_AWAIT_NODE, owner: resolveOwner(), + debugInfo: new WeakRef((resource: Promise)), stack: new Error(), start: performance.now(), end: -1.1, // set when resolved. @@ -66,6 +72,7 @@ export function initAsyncDebugInfo(): void { node = ({ tag: UNRESOLVED_PROMISE_NODE, owner: resolveOwner(), + debugInfo: new WeakRef((resource: Promise)), stack: new Error(), start: performance.now(), end: -1.1, // Set when we resolve. @@ -86,6 +93,7 @@ export function initAsyncDebugInfo(): void { node = ({ tag: IO_NODE, owner: resolveOwner(), + debugInfo: null, stack: new Error(), // This is only used if no native promises are used. start: performance.now(), end: -1.1, // Only set when pinged. @@ -100,6 +108,7 @@ export function initAsyncDebugInfo(): void { node = ({ tag: IO_NODE, owner: resolveOwner(), + debugInfo: null, stack: new Error(), start: performance.now(), end: -1.1, // Only set when pinged. @@ -150,6 +159,12 @@ export function initAsyncDebugInfo(): void { } // Log the end time when we resolved the promise. resolvedNode.end = performance.now(); + // The Promise can be garbage collected after this so we should extract debugInfo first. + const promise = node.debugInfo.deref(); + resolvedNode.debugInfo = + promise === undefined || promise._debugInfo === undefined + ? null + : promise._debugInfo; const currentAsyncId = executionAsyncId(); if (asyncId !== currentAsyncId) { // If the promise was not resolved by itself, then that means that diff --git a/scripts/rollup/validate/eslintrc.cjs.js b/scripts/rollup/validate/eslintrc.cjs.js index 65fd6129904e6..e7e172599d0e6 100644 --- a/scripts/rollup/validate/eslintrc.cjs.js +++ b/scripts/rollup/validate/eslintrc.cjs.js @@ -14,6 +14,7 @@ module.exports = { Symbol: 'readonly', WeakMap: 'readonly', WeakSet: 'readonly', + WeakRef: 'readonly', Int8Array: 'readonly', Uint8Array: 'readonly', diff --git a/scripts/rollup/validate/eslintrc.cjs2015.js b/scripts/rollup/validate/eslintrc.cjs2015.js index fa0b471330f4a..5e4feb64da8e8 100644 --- a/scripts/rollup/validate/eslintrc.cjs2015.js +++ b/scripts/rollup/validate/eslintrc.cjs2015.js @@ -14,6 +14,7 @@ module.exports = { Symbol: 'readonly', WeakMap: 'readonly', WeakSet: 'readonly', + WeakRef: 'readonly', Int8Array: 'readonly', Uint8Array: 'readonly', diff --git a/scripts/rollup/validate/eslintrc.esm.js b/scripts/rollup/validate/eslintrc.esm.js index a5ea7afb972e7..bef26bbd67efb 100644 --- a/scripts/rollup/validate/eslintrc.esm.js +++ b/scripts/rollup/validate/eslintrc.esm.js @@ -14,6 +14,7 @@ module.exports = { Symbol: 'readonly', WeakMap: 'readonly', WeakSet: 'readonly', + WeakRef: 'readonly', Int8Array: 'readonly', Uint8Array: 'readonly', diff --git a/scripts/rollup/validate/eslintrc.fb.js b/scripts/rollup/validate/eslintrc.fb.js index afee2f1199eb1..b8b556d8b7b2e 100644 --- a/scripts/rollup/validate/eslintrc.fb.js +++ b/scripts/rollup/validate/eslintrc.fb.js @@ -14,6 +14,7 @@ module.exports = { Proxy: 'readonly', WeakMap: 'readonly', WeakSet: 'readonly', + WeakRef: 'readonly', Int8Array: 'readonly', Uint8Array: 'readonly', diff --git a/scripts/rollup/validate/eslintrc.rn.js b/scripts/rollup/validate/eslintrc.rn.js index 2420898bebecd..2ee825dd77414 100644 --- a/scripts/rollup/validate/eslintrc.rn.js +++ b/scripts/rollup/validate/eslintrc.rn.js @@ -14,6 +14,7 @@ module.exports = { Proxy: 'readonly', WeakMap: 'readonly', WeakSet: 'readonly', + WeakRef: 'readonly', Int8Array: 'readonly', Uint8Array: 'readonly', From 562a0b65d14c19ad38119d79f1c2f8f120982afa Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Mon, 2 Jun 2025 20:47:48 -0400 Subject: [PATCH 4/8] Forward any debugInfo found on visited Promises We do this whether this was blocked by I/O or not. This lets you create virtual nodes that behave like I/O. --- .../react-server/src/ReactFlightServer.js | 99 ++++++++++++------- .../ReactFlightAsyncDebugInfo-test.js | 90 +++++++++++++++++ 2 files changed, 151 insertions(+), 38 deletions(-) diff --git a/packages/react-server/src/ReactFlightServer.js b/packages/react-server/src/ReactFlightServer.js index b523a54d1f4aa..4dce24bd2c4ab 100644 --- a/packages/react-server/src/ReactFlightServer.js +++ b/packages/react-server/src/ReactFlightServer.js @@ -1897,6 +1897,7 @@ function visitAsyncNode( return null; } const awaited = node.awaited; + let match = null; if (awaited !== null) { const ioNode = visitAsyncNode(request, task, awaited, cutOff, visited); if (ioNode !== null) { @@ -1916,12 +1917,19 @@ function visitAsyncNode( // If we haven't defined an end time, use the resolve of the outer Promise. ioNode.end = node.end; } - return ioNode; + match = ioNode; + } else { + match = node; } - return node; } } - return null; + // We need to forward after we visit awaited nodes because what ever I/O we requested that's + // the thing that generated this node and its virtual children. + const debugInfo = node.debugInfo; + if (debugInfo !== null) { + forwardDebugInfo(request, task.id, debugInfo); + } + return match; } case UNRESOLVED_AWAIT_NODE: // We could be inside the .then() which is about to resolve this node. @@ -1929,6 +1937,7 @@ function visitAsyncNode( // Fallthrough to the resolved path. case AWAIT_NODE: { const awaited = node.awaited; + let match = null; if (awaited !== null) { const ioNode = visitAsyncNode(request, task, awaited, cutOff, visited); if (ioNode !== null) { @@ -1950,45 +1959,59 @@ function visitAsyncNode( // part of a different component. // TODO: Think of some other way to exclude irrelevant data since if we awaited // a cached promise, we should still log this component as being dependent on that data. - return null; - } - - const stack = filterStackTrace( - request, - parseStackTrace(node.stack, 1), - ); - if (stack.length === 0) { - // If this await was fully filtered out, then it was inside third party code - // such as in an external library. We return the I/O node and try another await. - return ioNode; - } - // Outline the IO node. - serializeIONode(request, ioNode); - // We log the environment at the time when the last promise pigned ping which may - // be later than what the environment was when we actually started awaiting. - const env = (0, request.environmentName)(); - if (node.start <= cutOff) { - // If this was an await that started before this sequence but finished after, - // then we clamp it to the start of this sequence. We don't need to emit a time - // TODO: Typically we'll already have a previous time stamp with the cutOff time - // so we shouldn't need to emit another one. But not always. - emitTimingChunk(request, task.id, cutOff); } else { - emitTimingChunk(request, task.id, node.start); + const stack = filterStackTrace( + request, + parseStackTrace(node.stack, 1), + ); + if (stack.length === 0) { + // If this await was fully filtered out, then it was inside third party code + // such as in an external library. We return the I/O node and try another await. + match = ioNode; + } else { + // Outline the IO node. + serializeIONode(request, ioNode); + // We log the environment at the time when the last promise pigned ping which may + // be later than what the environment was when we actually started awaiting. + const env = (0, request.environmentName)(); + if (node.start <= cutOff) { + // If this was an await that started before this sequence but finished after, + // then we clamp it to the start of this sequence. We don't need to emit a time + // TODO: Typically we'll already have a previous time stamp with the cutOff time + // so we shouldn't need to emit another one. But not always. + emitTimingChunk(request, task.id, cutOff); + } else { + emitTimingChunk(request, task.id, node.start); + } + // Then emit a reference to us awaiting it in the current task. + request.pendingChunks++; + emitDebugChunk(request, task.id, { + awaited: ((ioNode: any): ReactIOInfo), // This is deduped by this reference. + env: env, + owner: node.owner, + stack: stack, + }); + emitTimingChunk(request, task.id, node.end); + } } - // Then emit a reference to us awaiting it in the current task. - request.pendingChunks++; - emitDebugChunk(request, task.id, { - awaited: ((ioNode: any): ReactIOInfo), // This is deduped by this reference. - env: env, - owner: node.owner, - stack: stack, - }); - emitTimingChunk(request, task.id, node.end); } } - // If we had awaited anything we would have written it now. - return null; + // We need to forward after we visit awaited nodes because what ever I/O we requested that's + // the thing that generated this node and its virtual children. + let debugInfo: null | ReactDebugInfo; + if (node.tag === UNRESOLVED_AWAIT_NODE) { + const promise = node.debugInfo.deref(); + debugInfo = + promise === undefined || promise._debugInfo === undefined + ? null + : promise._debugInfo; + } else { + debugInfo = node.debugInfo; + } + if (debugInfo !== null) { + forwardDebugInfo(request, task.id, debugInfo); + } + return match; } default: { // eslint-disable-next-line react-internal/prod-error-codes diff --git a/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js b/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js index 80d900794b41b..95ecfd1a1a512 100644 --- a/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js +++ b/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js @@ -523,4 +523,94 @@ describe('ReactFlightAsyncDebugInfo', () => { `); } }); + + it('forwards debugInfo from awaited Promises', async () => { + async function Component() { + let resolve; + const promise = new Promise(r => (resolve = r)); + promise._debugInfo = [ + {time: performance.now()}, + { + name: 'Virtual Component', + }, + {time: performance.now()}, + ]; + resolve('hi'); + const promise2 = promise.then(value => value); + promise2._debugInfo = [ + {time: performance.now()}, + { + name: 'Virtual Component2', + }, + {time: performance.now()}, + ]; + const result = await promise2; + return result.toUpperCase(); + } + + const stream = ReactServerDOMServer.renderToPipeableStream(); + + const readable = new Stream.PassThrough(streamOptions); + + const result = ReactServerDOMClient.createFromNodeStream(readable, { + moduleMap: {}, + moduleLoading: {}, + }); + stream.pipe(readable); + + expect(await result).toBe('HI'); + if ( + __DEV__ && + gate( + flags => + flags.enableComponentPerformanceTrack && flags.enableAsyncDebugInfo, + ) + ) { + expect(getDebugInfo(result)).toMatchInlineSnapshot(` + [ + { + "time": 0, + }, + { + "env": "Server", + "key": null, + "name": "Component", + "owner": null, + "props": {}, + "stack": [ + [ + "Object.", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 552, + 109, + 527, + 50, + ], + ], + }, + { + "time": 0, + }, + { + "name": "Virtual Component", + }, + { + "time": 0, + }, + { + "time": 0, + }, + { + "name": "Virtual Component2", + }, + { + "time": 0, + }, + { + "time": 0, + }, + ] + `); + } + }); }); From ae6c463fde570f1169af704b3d5e054cc21e0557 Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Mon, 2 Jun 2025 22:19:19 -0400 Subject: [PATCH 5/8] Treat performWork as a root task That ensures that work spawned from the resulting render isn't included in the sequence. This helps isolate one render from another. TODO: We should probably mark startFlowing and abort too. --- packages/react-server/src/ReactFlightServer.js | 3 +++ .../react-server/src/ReactFlightServerConfigDebugNode.js | 9 +++++++++ .../react-server/src/ReactFlightServerConfigDebugNoop.js | 1 + 3 files changed, 13 insertions(+) diff --git a/packages/react-server/src/ReactFlightServer.js b/packages/react-server/src/ReactFlightServer.js index 4dce24bd2c4ab..506bccd5726f7 100644 --- a/packages/react-server/src/ReactFlightServer.js +++ b/packages/react-server/src/ReactFlightServer.js @@ -89,6 +89,7 @@ import { requestStorage, createHints, initAsyncDebugInfo, + markAsyncSequenceRootTask, getCurrentAsyncSequence, parseStackTrace, supportsComponentStorage, @@ -4552,6 +4553,8 @@ function tryStreamTask(request: Request, task: Task): void { } function performWork(request: Request): void { + markAsyncSequenceRootTask(); + const prevDispatcher = ReactSharedInternals.H; ReactSharedInternals.H = HooksDispatcher; const prevRequest = currentRequest; diff --git a/packages/react-server/src/ReactFlightServerConfigDebugNode.js b/packages/react-server/src/ReactFlightServerConfigDebugNode.js index 8893a6505d539..3bf84962bbed0 100644 --- a/packages/react-server/src/ReactFlightServerConfigDebugNode.js +++ b/packages/react-server/src/ReactFlightServerConfigDebugNode.js @@ -185,6 +185,15 @@ export function initAsyncDebugInfo(): void { } } +export function markAsyncSequenceRootTask(): void { + if (__DEV__ && enableAsyncDebugInfo) { + // Whatever Task we're running now is spawned by React itself to perform render work. + // Don't track any cause beyond this task. We may still track I/O that was started outside + // React but just not the cause of entering the render. + pendingOperations.delete(executionAsyncId()); + } +} + export function getCurrentAsyncSequence(): null | AsyncSequence { if (!__DEV__ || !enableAsyncDebugInfo) { return null; diff --git a/packages/react-server/src/ReactFlightServerConfigDebugNoop.js b/packages/react-server/src/ReactFlightServerConfigDebugNoop.js index b0f71c9697a74..7418aaef18310 100644 --- a/packages/react-server/src/ReactFlightServerConfigDebugNoop.js +++ b/packages/react-server/src/ReactFlightServerConfigDebugNoop.js @@ -11,6 +11,7 @@ import type {AsyncSequence} from './ReactFlightAsyncSequence'; // Exported for runtimes that don't support Promise instrumentation for async debugging. export function initAsyncDebugInfo(): void {} +export function markAsyncSequenceRootTask(): void {} export function getCurrentAsyncSequence(): null | AsyncSequence { return null; } From c1e3fe03bf5bf288cb349d2698d5341e06ca3c54 Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Mon, 2 Jun 2025 22:35:02 -0400 Subject: [PATCH 6/8] Set the end time of an IONode if we end up using it --- packages/react-server/src/ReactFlightServer.js | 3 +++ 1 file changed, 3 insertions(+) diff --git a/packages/react-server/src/ReactFlightServer.js b/packages/react-server/src/ReactFlightServer.js index 506bccd5726f7..b1d3a91dc0b7e 100644 --- a/packages/react-server/src/ReactFlightServer.js +++ b/packages/react-server/src/ReactFlightServer.js @@ -1971,6 +1971,9 @@ function visitAsyncNode( match = ioNode; } else { // Outline the IO node. + if (ioNode.end < 0) { + ioNode.end = endTime; + } serializeIONode(request, ioNode); // We log the environment at the time when the last promise pigned ping which may // be later than what the environment was when we actually started awaiting. From 79aca0f77c81120888d1d32701f2666a5172bed6 Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Mon, 2 Jun 2025 23:51:06 -0400 Subject: [PATCH 7/8] Wrap fake ReactPromise in a real Promise to allow it to forward debugInfo --- .../react-client/src/ReactFlightClient.js | 21 +++++++++++++++++++ 1 file changed, 21 insertions(+) diff --git a/packages/react-client/src/ReactFlightClient.js b/packages/react-client/src/ReactFlightClient.js index 41421edb2a32a..78a2d85eea287 100644 --- a/packages/react-client/src/ReactFlightClient.js +++ b/packages/react-client/src/ReactFlightClient.js @@ -266,6 +266,27 @@ ReactPromise.prototype.then = function ( initializeModuleChunk(chunk); break; } + if (__DEV__ && enableAsyncDebugInfo) { + // Because only native Promises get picked up when we're awaiting we need to wrap + // this in a native Promise in DEV. This means that these callbacks are no longer sync + // but the lazy initialization is still sync and the .value can be inspected after, + // allowing it to be read synchronously anyway. + const resolveCallback = resolve; + const rejectCallback = reject; + const wrapperPromise: Promise = new Promise((res, rej) => { + resolve = value => { + // $FlowFixMe + wrapperPromise._debugInfo = this._debugInfo; + res(value); + }; + reject = reason => { + // $FlowFixMe + wrapperPromise._debugInfo = this._debugInfo; + rej(reason); + }; + }); + wrapperPromise.then(resolveCallback, rejectCallback); + } // The status might have changed after initialization. switch (chunk.status) { case INITIALIZED: From 3e749b9560f958b9c8119ff4bb42d5692515143c Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Mon, 2 Jun 2025 22:49:11 -0400 Subject: [PATCH 8/8] Test --- .../ReactFlightAsyncDebugInfo-test.js | 405 ++++++++++++++++-- 1 file changed, 368 insertions(+), 37 deletions(-) diff --git a/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js b/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js index 95ecfd1a1a512..d1c84f9cc272c 100644 --- a/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js +++ b/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js @@ -117,6 +117,23 @@ describe('ReactFlightAsyncDebugInfo', () => { }); } + function fetchThirdParty(Component) { + const stream = ReactServerDOMServer.renderToPipeableStream( + , + {}, + { + environmentName: 'third-party', + }, + ); + const readable = new Stream.PassThrough(streamOptions); + const result = ReactServerDOMClient.createFromNodeStream(readable, { + moduleMap: {}, + moduleLoading: {}, + }); + stream.pipe(readable); + return result; + } + it('can track async information when awaited', async () => { async function getData() { await delay(1); @@ -163,9 +180,9 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "Object.", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 133, + 150, 109, - 120, + 137, 50, ], ], @@ -188,9 +205,9 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "Object.", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 133, + 150, 109, - 120, + 137, 50, ], ], @@ -207,17 +224,17 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "getData", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 122, + 139, 13, - 121, + 138, 5, ], [ "Component", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 129, + 146, 26, - 128, + 145, 5, ], ], @@ -234,9 +251,9 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "Object.", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 133, + 150, 109, - 120, + 137, 50, ], ], @@ -245,17 +262,17 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "getData", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 122, + 139, 13, - 121, + 138, 5, ], [ "Component", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 129, + 146, 26, - 128, + 145, 5, ], ], @@ -281,9 +298,9 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "Object.", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 133, + 150, 109, - 120, + 137, 50, ], ], @@ -300,17 +317,17 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "getData", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 123, + 140, 21, - 121, + 138, 5, ], [ "Component", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 129, + 146, 20, - 128, + 145, 5, ], ], @@ -327,9 +344,9 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "Object.", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 133, + 150, 109, - 120, + 137, 50, ], ], @@ -338,17 +355,17 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "getData", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 124, + 141, 21, - 121, + 138, 5, ], [ "Component", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 129, + 146, 20, - 128, + 145, 5, ], ], @@ -410,9 +427,9 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "Object.", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 380, + 397, 109, - 367, + 384, 67, ], ], @@ -435,9 +452,9 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "Object.", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 380, + 397, 109, - 367, + 384, 67, ], ], @@ -446,9 +463,9 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "Component", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 370, + 387, 7, - 368, + 385, 5, ], ], @@ -509,9 +526,9 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "Object.", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 479, + 496, 109, - 470, + 487, 94, ], ], @@ -535,7 +552,6 @@ describe('ReactFlightAsyncDebugInfo', () => { }, {time: performance.now()}, ]; - resolve('hi'); const promise2 = promise.then(value => value); promise2._debugInfo = [ {time: performance.now()}, @@ -544,6 +560,7 @@ describe('ReactFlightAsyncDebugInfo', () => { }, {time: performance.now()}, ]; + resolve('hi'); const result = await promise2; return result.toUpperCase(); } @@ -581,9 +598,9 @@ describe('ReactFlightAsyncDebugInfo', () => { [ "Object.", "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", - 552, + 568, 109, - 527, + 544, 50, ], ], @@ -613,4 +630,318 @@ describe('ReactFlightAsyncDebugInfo', () => { `); } }); + + it('forwards async debug info one environment to the next', async () => { + async function getData() { + await delay(1); + await delay(2); + return 'hi'; + } + + async function ThirdPartyComponent() { + const data = await getData(); + return data; + } + + async function Component() { + const data = await fetchThirdParty(ThirdPartyComponent); + return data.toUpperCase(); + } + + const stream = ReactServerDOMServer.renderToPipeableStream(); + + const readable = new Stream.PassThrough(streamOptions); + + const result = ReactServerDOMClient.createFromNodeStream(readable, { + moduleMap: {}, + moduleLoading: {}, + }); + stream.pipe(readable); + + expect(await result).toBe('HI'); + if ( + __DEV__ && + gate( + flags => + flags.enableComponentPerformanceTrack && flags.enableAsyncDebugInfo, + ) + ) { + expect(getDebugInfo(result)).toMatchInlineSnapshot(` + [ + { + "time": 0, + }, + { + "env": "Server", + "key": null, + "name": "Component", + "owner": null, + "props": {}, + "stack": [ + [ + "Object.", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 651, + 109, + 634, + 63, + ], + ], + }, + { + "time": 0, + }, + { + "env": "third-party", + "key": null, + "name": "ThirdPartyComponent", + "owner": null, + "props": {}, + "stack": [ + [ + "fetchThirdParty", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 122, + 40, + 120, + 3, + ], + [ + "Component", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 647, + 24, + 646, + 5, + ], + ], + }, + { + "time": 0, + }, + { + "awaited": { + "end": 0, + "env": "third-party", + "name": "delay", + "owner": { + "env": "third-party", + "key": null, + "name": "ThirdPartyComponent", + "owner": null, + "props": {}, + "stack": [ + [ + "fetchThirdParty", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 122, + 40, + 120, + 3, + ], + [ + "Component", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 647, + 24, + 646, + 5, + ], + ], + }, + "stack": [ + [ + "delay", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 115, + 12, + 114, + 3, + ], + [ + "getData", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 636, + 13, + 635, + 5, + ], + [ + "ThirdPartyComponent", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 642, + 24, + 641, + 5, + ], + ], + "start": 0, + }, + "env": "third-party", + "owner": { + "env": "third-party", + "key": null, + "name": "ThirdPartyComponent", + "owner": null, + "props": {}, + "stack": [ + [ + "fetchThirdParty", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 122, + 40, + 120, + 3, + ], + [ + "Component", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 647, + 24, + 646, + 5, + ], + ], + }, + "stack": [ + [ + "getData", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 636, + 13, + 635, + 5, + ], + [ + "ThirdPartyComponent", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 642, + 24, + 641, + 5, + ], + ], + }, + { + "time": 0, + }, + { + "time": 0, + }, + { + "awaited": { + "end": 0, + "env": "third-party", + "name": "delay", + "owner": { + "env": "third-party", + "key": null, + "name": "ThirdPartyComponent", + "owner": null, + "props": {}, + "stack": [ + [ + "fetchThirdParty", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 122, + 40, + 120, + 3, + ], + [ + "Component", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 647, + 24, + 646, + 5, + ], + ], + }, + "stack": [ + [ + "delay", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 115, + 12, + 114, + 3, + ], + [ + "getData", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 637, + 13, + 635, + 5, + ], + [ + "ThirdPartyComponent", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 642, + 18, + 641, + 5, + ], + ], + "start": 0, + }, + "env": "third-party", + "owner": { + "env": "third-party", + "key": null, + "name": "ThirdPartyComponent", + "owner": null, + "props": {}, + "stack": [ + [ + "fetchThirdParty", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 122, + 40, + 120, + 3, + ], + [ + "Component", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 647, + 24, + 646, + 5, + ], + ], + }, + "stack": [ + [ + "getData", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 637, + 13, + 635, + 5, + ], + [ + "ThirdPartyComponent", + "/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js", + 642, + 18, + 641, + 5, + ], + ], + }, + { + "time": 0, + }, + { + "time": 0, + }, + { + "time": 0, + }, + ] + `); + } + }); });