OSSForks/react
1
0
Fork 0
mirror of https://github.com/zebrajr/react.git synced 2025-12-06 00:20:04 +01:00
Code Issues Actions 5 Packages Projects Releases Wiki Activity

[Flight] Track Awaits on I/O as Debug Info (#33388)

Browse Source 
This lets us track what data each Server Component depended on. This
will be used by Performance Track and React DevTools.

We use Node.js `async_hooks`. This has a number of downside. It is
Node.js specific so this feature is not available in other runtimes
until something equivalent becomes available. It's [discouraged by
Node.js docs](https://nodejs.org/api/async_hooks.html#async-hooks). It's
also slow which makes this approach only really viable in development
mode. At least with stack traces. However, it's really the only solution
that gives us the data that we need.

The [Diagnostic
Channel](https://nodejs.org/api/diagnostics_channel.html) API is not
sufficient. Not only is many Node.js built-in APIs missing but all
libraries like databases are also missing. Were as `async_hooks` covers
pretty much anything async in the Node.js ecosystem.

However, even if coverage was wider it's not actually showing the
information we want. It's not enough to show the low level I/O that is
happening because that doesn't provide the context. We need the stack
trace in user space code where it was initiated and where it was
awaited. It's also not each low level socket operation that we want to
surface but some higher level concept which can span a sequence of I/O
operations but as far as user space is concerned.

Therefore this solution is anchored on stack traces and ignore listing
to determine what the interesting span is. It is somewhat
Promise-centric (and in particular async/await) because it allows us to
model an abstract span instead of just random I/O. Async/await points
are also especially useful because this allows Async Stacks to show the
full sequence which is not supported by random callbacks. However, if no
Promises are involved we still to our best to show the stack causing
plain I/O callbacks.

Additionally, we don't want to track all possible I/O. For example,
side-effects like logging that doesn't affect the rendering performance
doesn't need to be included. We only want to include things that
actually block the rendering output. We also need to track which data
blocks each component so that we can track which data caused a
particular subtree to suspend.

We can do this using `async_hooks` because we can track the graph of
what resolved what and then spawned what.

To track what suspended what, something has to resolve. Therefore it
needs to run to completion before we can show what it was suspended on.
So something that never resolves, won't be tracked for example.

We use the `async_hooks` in `ReactFlightServerConfigDebugNode` to build
up an `ReactFlightAsyncSequence` graph that collects the stack traces
for basically all I/O and Promises allocated in the whole app. This is
pretty heavy, especially the stack traces, but it's because we don't
know which ones we'll need until they resolve. We don't materialize the
stacks until we need them though.

Once they end up pinging the Flight runtime, we collect which current
executing task that pinged the runtime and then log the sequence that
led up until that runtime into the RSC protocol. Currently we only
include things that weren't already resolved before we started rendering
this task/component, so that we don't log the entire history each time.

Each operation is split into two parts. First a `ReactIOInfo` which
represents an I/O operation and its start/end time. Basically the start
point where it was start. This is basically represents where you called
`new Promise()` or when entering an `async function` which has an
implied Promise. It can be started in a different component than where
it's awaited and it can be awaited in multiple places. Therefore this is
global information and not associated with a specific Component.

The second part is `ReactAsyncInfo`. This represents where this I/O was
`await`:ed or `.then()` called. This is associated with a point in the
tree (usually the Promise that's a direct child of a Component). Since
you can have multiple different I/O awaited in a sequence technically it
forms a dependency graph but to simplify the model these awaits as
flattened into the `ReactDebugInfo` list. Basically it contains each
await in a sequence that affected this part from unblocking.

This means that the same `ReactAsyncInfo` can appear in mutliple
components if they all await the same `ReactIOInfo` but the same Promise
only appears once.

Promises that are only resolved by other Promises or immediately are not
considered here. Only if they're resolved by an I/O operation. We pick
the Promise basically on the border between user space code and ignored
listed code (`node_modules`) to pick the most specific span but abstract
enough to not give too much detail irrelevant to the current audience.
Similarly, the deepest `await` in user space is marked as the relevant
`await` point.

This feature is only available in the `node` builds of React. Not if you
use the `edge` builds inside of Node.js.

---------

Co-authored-by: Sebastian "Sebbie" Silbermann <silbermann.sebastian@gmail.com>
This commit is contained in:
Sebastian Markbåge 2025-06-03 14:14:40 -04:00 committed by GitHub
parent 1ae0a845bd
commit acee65d6d0
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
15 changed files with 840 additions and 76 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

41
packages/react-server/src/ReactFlightAsyncSequence.js vendored Normal file
View File

@ -0,0 +1,41 @@
/**
* Copyright (c) Meta Platforms, Inc. and affiliates.
*
* This source code is licensed under the MIT license found in the
* LICENSE file in the root directory of this source tree.
*
* @flow
*/
export const IO_NODE = 0;
export const PROMISE_NODE = 1;
export const AWAIT_NODE = 2;
export type IONode = {
tag: 0,
stack: Error, // callsite that spawned the 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.
previous: null | AwaitNode, // the preceeding await that spawned this new work
};
export type PromiseNode = {
tag: 1,
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.
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 AwaitNode = {
tag: 2,
stack: Error, // callsite that awaited (using await, .then(), Promise.all(), ...)
start: -1.1, // not used. We use the timing of the awaited promise.
end: -1.1, // not used.
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;

262
packages/react-server/src/ReactFlightServer.js vendored
View File

@ -19,6 +19,7 @@ import {
enableTaint,
enableProfilerTimer,
enableComponentPerformanceTrack,
enableAsyncDebugInfo,
} from 'shared/ReactFeatureFlags';
import {
@ -59,6 +60,7 @@ import type {
ReactDebugInfo,
ReactComponentInfo,
ReactEnvironmentInfo,
ReactIOInfo,
ReactAsyncInfo,
ReactTimeInfo,
ReactStackTrace,
@ -68,6 +70,11 @@ import type {
} from 'shared/ReactTypes';
import type {ReactElement} from 'shared/ReactElementType';
import type {LazyComponent} from 'react/src/ReactLazy';
import type {
AsyncSequence,
IONode,
PromiseNode,
} from './ReactFlightAsyncSequence';
import {
resolveClientReferenceMetadata,
@ -81,6 +88,7 @@ import {
requestStorage,
createHints,
initAsyncDebugInfo,
getCurrentAsyncSequence,
parseStackTrace,
supportsComponentStorage,
componentStorage,
@ -140,6 +148,8 @@ import binaryToComparableString from 'shared/binaryToComparableString';
import {SuspenseException, getSuspendedThenable} from './ReactFlightThenable';
import {IO_NODE, PROMISE_NODE, AWAIT_NODE} from './ReactFlightAsyncSequence';
// DEV-only set containing internal objects that should not be limited and turned into getters.
const doNotLimit: WeakSet<Reference> = __DEV__ ? new WeakSet() : (null: any);
@ -356,6 +366,7 @@ type Task = {
implicitSlot: boolean, // true if the root server component of this sequence had a null key
thenableState: ThenableState | null,
timed: boolean, // Profiling-only. Whether we need to track the completion time of this task.
time: number, // Profiling-only. The last time stamp emitted for this task.
environmentName: string, // DEV-only. Used to track if the environment for this task changed.
debugOwner: null | ReactComponentInfo, // DEV-only
debugStack: null | Error, // DEV-only
@ -529,6 +540,7 @@ function RequestInstance(
this.didWarnForKey = null;
}
let timeOrigin: number;
if (enableProfilerTimer && enableComponentPerformanceTrack) {
// We start by serializing the time origin. Any future timestamps will be
// emitted relatively to this origin. Instead of using performance.timeOrigin
@ -536,13 +548,15 @@ function RequestInstance(
// This avoids leaking unnecessary information like how long the server has
// been running and allows for more compact representation of each timestamp.
// The time origin is stored as an offset in the time space of this environment.
const timeOrigin = (this.timeOrigin = performance.now());
timeOrigin = this.timeOrigin = performance.now();
emitTimeOriginChunk(
this,
timeOrigin +
// $FlowFixMe[prop-missing]
performance.timeOrigin,
);
} else {
timeOrigin = 0;
}
const rootTask = createTask(
@ -551,6 +565,7 @@ function RequestInstance(
null,
false,
abortSet,
timeOrigin,
null,
null,
null,
@ -642,6 +657,7 @@ function serializeThenable(
task.keyPath, // the server component sequence continues through Promise-as-a-child.
task.implicitSlot,
request.abortableTasks,
enableProfilerTimer && enableComponentPerformanceTrack ? task.time : 0,
__DEV__ ? task.debugOwner : null,
__DEV__ ? task.debugStack : null,
__DEV__ ? task.debugTask : null,
@ -762,6 +778,7 @@ function serializeReadableStream(
task.keyPath,
task.implicitSlot,
request.abortableTasks,
enableProfilerTimer && enableComponentPerformanceTrack ? task.time : 0,
__DEV__ ? task.debugOwner : null,
__DEV__ ? task.debugStack : null,
__DEV__ ? task.debugTask : null,
@ -853,6 +870,7 @@ function serializeAsyncIterable(
task.keyPath,
task.implicitSlot,
request.abortableTasks,
enableProfilerTimer && enableComponentPerformanceTrack ? task.time : 0,
__DEV__ ? task.debugOwner : null,
__DEV__ ? task.debugStack : null,
__DEV__ ? task.debugTask : null,
@ -1278,7 +1296,11 @@ function renderFunctionComponent<Props>(
// Track when we started rendering this component.
if (enableProfilerTimer && enableComponentPerformanceTrack) {
task.timed = true;
emitTimingChunk(request, componentDebugID, performance.now());
emitTimingChunk(
request,
componentDebugID,
(task.time = performance.now()),
);
}
emitDebugChunk(request, componentDebugID, componentDebugInfo);
@ -1629,6 +1651,7 @@ function deferTask(request: Request, task: Task): ReactJSONValue {
task.keyPath, // unlike outlineModel this one carries along context
task.implicitSlot,
request.abortableTasks,
enableProfilerTimer && enableComponentPerformanceTrack ? task.time : 0,
__DEV__ ? task.debugOwner : null,
__DEV__ ? task.debugStack : null,
__DEV__ ? task.debugTask : null,
@ -1645,6 +1668,7 @@ function outlineTask(request: Request, task: Task): ReactJSONValue {
task.keyPath, // unlike outlineModel this one carries along context
task.implicitSlot,
request.abortableTasks,
enableProfilerTimer && enableComponentPerformanceTrack ? task.time : 0,
__DEV__ ? task.debugOwner : null,
__DEV__ ? task.debugStack : null,
__DEV__ ? task.debugTask : null,
@ -1814,10 +1838,128 @@ function renderElement(
return renderClientElement(request, task, type, key, props, validated);
}
function visitAsyncNode(
request: Request,
task: Task,
node: AsyncSequence,
cutOff: number,
visited: Set<AsyncSequence>,
): null | PromiseNode | IONode {
if (visited.has(node)) {
// It's possible to visit them same node twice when it's part of both an "awaited" path
// and a "previous" path. This also gracefully handles cycles which would be a bug.
return null;
}
visited.add(node);
// First visit anything that blocked this sequence to start in the first place.
if (node.previous !== null) {
// We ignore the return value here because if it wasn't awaited in user space, then we don't log it.
// TODO: This means that some I/O can get lost that was still blocking the sequence.
visitAsyncNode(request, task, node.previous, cutOff, visited);
}
switch (node.tag) {
case IO_NODE: {
return node;
}
case PROMISE_NODE: {
if (node.end < 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
// a cached promise, we should still log this component as being dependent on that data.
return null;
}
const awaited = node.awaited;
if (awaited !== null) {
const ioNode = visitAsyncNode(request, task, awaited, cutOff, visited);
if (ioNode !== null) {
// This Promise was blocked on I/O. That's a signal that this Promise is interesting to log.
// We don't log it yet though. We return it to be logged by the point where it's awaited.
// The ioNode might be another PromiseNode in the case where none of the AwaitNode had
// unfiltered stacks.
if (filterStackTrace(request, node.stack, 1).length === 0) {
// Typically we assume that the outer most Promise that was awaited in user space has the
// most actionable stack trace for the start of the operation. However, if this Promise
// was created inside only third party code, then try to use the inner node instead.
// This could happen if you pass a first party Promise into a third party to be awaited there.
if (ioNode.end < 0) {
// If we haven't defined an end time, use the resolve of the outer Promise.
ioNode.end = node.end;
}
return ioNode;
}
return node;
}
}
return null;
}
case AWAIT_NODE: {
const awaited = node.awaited;
if (awaited !== null) {
const ioNode = visitAsyncNode(request, task, awaited, cutOff, visited);
if (ioNode !== null) {
const stack = filterStackTrace(request, 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.
emitIOChunk(request, ioNode);
// 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.
stack: stack,
});
}
}
// If we had awaited anything we would have written it now.
return null;
}
default: {
// eslint-disable-next-line react-internal/prod-error-codes
throw new Error('Unknown AsyncSequence tag. This is a bug in React.');
}
}
}
function emitAsyncSequence(
request: Request,
task: Task,
node: AsyncSequence,
cutOff: number,
): void {
const visited: Set<AsyncSequence> = new Set();
const awaitedNode = visitAsyncNode(request, task, node, cutOff, visited);
if (awaitedNode !== null) {
// Nothing in user space (unfiltered stack) awaited this.
if (awaitedNode.end < 0) {
// If this was I/O directly without a Promise, then it means that some custom Thenable
// called our ping directly and not from a native .then(). We use the current ping time
// as the end time and treat it as an await with no stack.
// TODO: If this I/O is recurring then we really should have different entries for
// each occurrence. Right now we'll only track the first time it is invoked.
awaitedNode.end = performance.now();
}
emitIOChunk(request, awaitedNode);
request.pendingChunks++;
emitDebugChunk(request, task.id, {
awaited: ((awaitedNode: any): ReactIOInfo), // This is deduped by this reference.
});
}
}
function pingTask(request: Request, task: Task): void {
if (enableProfilerTimer && enableComponentPerformanceTrack) {
// If this was async we need to emit the time when it completes.
task.timed = true;
if (enableAsyncDebugInfo) {
const sequence = getCurrentAsyncSequence();
if (sequence !== null) {
emitAsyncSequence(request, task, sequence, task.time);
}
}
}
const pingedTasks = request.pingedTasks;
pingedTasks.push(task);
@ -1837,6 +1979,7 @@ function createTask(
keyPath: null | string,
implicitSlot: boolean,
abortSet: Set<Task>,
lastTimestamp: number, // Profiling-only
debugOwner: null | ReactComponentInfo, // DEV-only
debugStack: null | Error, // DEV-only
debugTask: null | ConsoleTask, // DEV-only
@ -1912,10 +2055,16 @@ function createTask(
thenableState: null,
}: Omit<
Task,
'timed' | 'environmentName' | 'debugOwner' | 'debugStack' | 'debugTask',
| 'timed'
| 'time'
| 'environmentName'
| 'debugOwner'
| 'debugStack'
| 'debugTask',
>): any);
if (enableProfilerTimer && enableComponentPerformanceTrack) {
task.timed = false;
task.time = lastTimestamp;
}
if (__DEV__) {
task.environmentName = request.environmentName();
@ -2062,6 +2211,9 @@ function outlineModel(request: Request, value: ReactClientValue): number {
null, // The way we use outlining is for reusing an object.
false, // It makes no sense for that use case to be contextual.
request.abortableTasks,
enableProfilerTimer && enableComponentPerformanceTrack
? performance.now() // TODO: This should really inherit the time from the task.
: 0,
null, // TODO: Currently we don't associate any debug information with
null, // this object on the server. If it ends up erroring, it won't
null, // have any context on the server but can on the client.
@ -2242,6 +2394,9 @@ function serializeBlob(request: Request, blob: Blob): string {
null,
false,
request.abortableTasks,
enableProfilerTimer && enableComponentPerformanceTrack
? performance.now() // TODO: This should really inherit the time from the task.
: 0,
null, // TODO: Currently we don't associate any debug information with
null, // this object on the server. If it ends up erroring, it won't
null, // have any context on the server but can on the client.
@ -2374,6 +2529,9 @@ function renderModel(
task.keyPath,
task.implicitSlot,
request.abortableTasks,
enableProfilerTimer && enableComponentPerformanceTrack
? task.time
: 0,
__DEV__ ? task.debugOwner : null,
__DEV__ ? task.debugStack : null,
__DEV__ ? task.debugTask : null,
@ -3335,6 +3493,82 @@ function outlineComponentInfo(
request.writtenObjects.set(componentInfo, serializeByValueID(id));
}
function outlineIOInfo(request: Request, ioInfo: ReactIOInfo): void {
if (!__DEV__) {
// These errors should never make it into a build so we don't need to encode them in codes.json
// eslint-disable-next-line react-internal/prod-error-codes
throw new Error(
'outlineIOInfo should never be called in production mode. This is a bug in React.',
);
}
if (request.writtenObjects.has(ioInfo)) {
// Already written
return;
}
// Limit the number of objects we write to prevent emitting giant props objects.
let objectLimit = 10;
if (ioInfo.stack != null) {
// Ensure we have enough object limit to encode the stack trace.
objectLimit += ioInfo.stack.length;
}
// We use the console encoding so that we can dedupe objects but don't necessarily
// use the full serialization that requires a task.
const counter = {objectLimit};
// We can't serialize the ConsoleTask/Error objects so we need to omit them before serializing.
const relativeStartTimestamp = ioInfo.start - request.timeOrigin;
const relativeEndTimestamp = ioInfo.end - request.timeOrigin;
const debugIOInfo: Omit<ReactIOInfo, 'debugTask' | 'debugStack'> = {
start: relativeStartTimestamp,
end: relativeEndTimestamp,
stack: ioInfo.stack,
};
const id = outlineConsoleValue(request, counter, debugIOInfo);
request.writtenObjects.set(ioInfo, serializeByValueID(id));
}
function emitIOChunk(request: Request, ioNode: IONode | PromiseNode): void {
if (!__DEV__) {
// These errors should never make it into a build so we don't need to encode them in codes.json
// eslint-disable-next-line react-internal/prod-error-codes
throw new Error(
'outlineIOInfo should never be called in production mode. This is a bug in React.',
);
}
if (request.writtenObjects.has(ioNode)) {
// Already written
return;
}
// Limit the number of objects we write to prevent emitting giant props objects.
let objectLimit = 10;
let stack = null;
if (ioNode.stack !== null) {
stack = filterStackTrace(request, ioNode.stack, 1);
// Ensure we have enough object limit to encode the stack trace.
objectLimit += stack.length;
}
// We use the console encoding so that we can dedupe objects but don't necessarily
// use the full serialization that requires a task.
const counter = {objectLimit};
// We can't serialize the ConsoleTask/Error objects so we need to omit them before serializing.
const relativeStartTimestamp = ioNode.start - request.timeOrigin;
const relativeEndTimestamp = ioNode.end - request.timeOrigin;
const debugIOInfo: Omit<ReactIOInfo, 'debugTask' | 'debugStack'> = {
start: relativeStartTimestamp,
end: relativeEndTimestamp,
stack: stack,
};
const id = outlineConsoleValue(request, counter, debugIOInfo);
request.writtenObjects.set(ioNode, serializeByValueID(id));
}
function emitTypedArrayChunk(
request: Request,
id: number,
@ -3842,8 +4076,22 @@ function forwardDebugInfo(
// If we had a smarter way to dedupe we might not have to do this if there ends up
// being no references to this as an owner.
outlineComponentInfo(request, (debugInfo[i]: any));
// Emit a reference to the outlined one.
emitDebugChunk(request, id, debugInfo[i]);
} else if (debugInfo[i].awaited) {
const ioInfo = debugInfo[i].awaited;
// Outline the IO info in case the same I/O is awaited in more than one place.
outlineIOInfo(request, ioInfo);
// We can't serialize the ConsoleTask/Error objects so we need to omit them before serializing.
const debugAsyncInfo: Omit<ReactAsyncInfo, 'debugTask' | 'debugStack'> =
{
awaited: ioInfo,
stack: debugInfo[i].stack,
};
emitDebugChunk(request, id, debugAsyncInfo);
} else {
emitDebugChunk(request, id, debugInfo[i]);
}
emitDebugChunk(request, id, debugInfo[i]);
}
}
}
@ -3956,7 +4204,7 @@ function emitChunk(
function erroredTask(request: Request, task: Task, error: mixed): void {
if (enableProfilerTimer && enableComponentPerformanceTrack) {
if (task.timed) {
emitTimingChunk(request, task.id, performance.now());
emitTimingChunk(request, task.id, (task.time = performance.now()));
}
}
task.status = ERRORED;
@ -4039,7 +4287,7 @@ function retryTask(request: Request, task: Task): void {
// We've finished rendering. Log the end time.
if (enableProfilerTimer && enableComponentPerformanceTrack) {
if (task.timed) {
emitTimingChunk(request, task.id, performance.now());
emitTimingChunk(request, task.id, (task.time = performance.now()));
}
}
@ -4164,7 +4412,7 @@ function abortTask(task: Task, request: Request, errorId: number): void {
// Track when we aborted this task as its end time.
if (enableProfilerTimer && enableComponentPerformanceTrack) {
if (task.timed) {
emitTimingChunk(request, task.id, performance.now());
emitTimingChunk(request, task.id, (task.time = performance.now()));
}
}
// Instead of emitting an error per task.id, we emit a model that only

129
packages/react-server/src/ReactFlightServerConfigDebugNode.js vendored
View File

@ -7,9 +7,20 @@
* @flow
*/
import {createAsyncHook, executionAsyncId} from './ReactFlightServerConfig';
import type {
AsyncSequence,
IONode,
PromiseNode,
AwaitNode,
} from './ReactFlightAsyncSequence';
import {IO_NODE, PROMISE_NODE, AWAIT_NODE} from './ReactFlightAsyncSequence';
import {createHook, executionAsyncId} from 'async_hooks';
import {enableAsyncDebugInfo} from 'shared/ReactFeatureFlags';
const pendingOperations: Map<number, AsyncSequence> =
__DEV__ && enableAsyncDebugInfo ? new Map() : (null: any);
// Initialize the tracing of async operations.
// We do this globally since the async work can potentially eagerly
// start before the first request and once requests start they can interleave.
@ -17,17 +28,123 @@ import {enableAsyncDebugInfo} from 'shared/ReactFeatureFlags';
// but given that typically this is just a live server, it doesn't really matter.
export function initAsyncDebugInfo(): void {
if (__DEV__ && enableAsyncDebugInfo) {
createAsyncHook({
createHook({
init(asyncId: number, type: string, triggerAsyncId: number): void {
// TODO
const trigger = pendingOperations.get(triggerAsyncId);
let node: AsyncSequence;
if (type === 'PROMISE') {
const currentAsyncId = executionAsyncId();
if (currentAsyncId !== triggerAsyncId) {
// When you call .then() on a native Promise, or await/Promise.all() a thenable,
// then this intermediate Promise is created. We use this as our await point
if (trigger === undefined) {
// We don't track awaits on things that started outside our tracked scope.
return;
}
const current = pendingOperations.get(currentAsyncId);
// 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,
stack: new Error(),
start: -1.1,
end: -1.1,
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);
} else {
node = ({
tag: PROMISE_NODE,
stack: new Error(),
start: performance.now(),
end: -1.1, // Set when we resolve.
awaited:
trigger === undefined
? null // It might get overridden when we resolve.
: trigger,
previous: null,
}: PromiseNode);
}
} else if (
type !== 'Microtask' &&
type !== 'TickObject' &&
type !== 'Immediate'
) {
if (trigger === undefined) {
// We have begun a new I/O sequence.
node = ({
tag: IO_NODE,
stack: new Error(), // This is only used if no native promises are used.
start: performance.now(),
end: -1.1, // Only set when pinged.
awaited: null,
previous: null,
}: IONode);
} else if (trigger.tag === AWAIT_NODE) {
// We have begun a new I/O sequence after the await.
node = ({
tag: IO_NODE,
stack: new Error(),
start: performance.now(),
end: -1.1, // Only set when pinged.
awaited: null,
previous: trigger,
}: IONode);
} else {
// Otherwise, this is just a continuation of the same I/O sequence.
node = trigger;
}
} else {
// Ignore nextTick and microtasks as they're not considered I/O operations.
// we just treat the trigger as the node to carry along the sequence.
if (trigger === undefined) {
return;
}
node = trigger;
}
pendingOperations.set(asyncId, node);
},
promiseResolve(asyncId: number): void {
// TODO
executionAsyncId();
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.',
);
}
if (resolvedNode.tag === PROMISE_NODE) {
// Log the end time when we resolved the promise.
resolvedNode.end = performance.now();
}
const currentAsyncId = executionAsyncId();
if (asyncId !== currentAsyncId) {
// If the promise was not resolved by itself, then that means that
// the trigger that we originally stored wasn't actually the dependency.
// Instead, the current execution context is what ultimately unblocked it.
const awaited = pendingOperations.get(currentAsyncId);
resolvedNode.awaited = awaited === undefined ? null : awaited;
}
}
},
destroy(asyncId: number): void {
// TODO
// If we needed the meta data from this operation we should have already
// extracted it or it should be part of a chain of triggers.
pendingOperations.delete(asyncId);
},
}).enable();
}
}
export function getCurrentAsyncSequence(): null | AsyncSequence {
if (!__DEV__ || !enableAsyncDebugInfo) {
return null;
}
const currentNode = pendingOperations.get(executionAsyncId());
if (currentNode === undefined) {
// Nothing that we tracked led to the resolution of this execution context.
return null;
}
return currentNode;
}

5
packages/react-server/src/ReactFlightServerConfigDebugNoop.js vendored
View File

@ -7,5 +7,10 @@
* @flow
*/
import type {AsyncSequence} from './ReactFlightAsyncSequence';
// Exported for runtimes that don't support Promise instrumentation for async debugging.
export function initAsyncDebugInfo(): void {}
export function getCurrentAsyncSequence(): null | AsyncSequence {
return null;
}

354
packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js vendored Normal file
View File

@ -0,0 +1,354 @@
'use strict';
const path = require('path');
import {patchSetImmediate} from '../../../../scripts/jest/patchSetImmediate';
let React;
let ReactServerDOMServer;
let ReactServerDOMClient;
let Stream;
const streamOptions = {
objectMode: true,
};
const repoRoot = path.resolve(__dirname, '../../../../');
function normalizeStack(stack) {
if (!stack) {
return stack;
}
const copy = [];
for (let i = 0; i < stack.length; i++) {
const [name, file, line, col, enclosingLine, enclosingCol] = stack[i];
copy.push([
name,
file.replace(repoRoot, ''),
line,
col,
enclosingLine,
enclosingCol,
]);
}
return copy;
}
function normalizeIOInfo(ioInfo) {
const {debugTask, debugStack, ...copy} = ioInfo;
if (ioInfo.stack) {
copy.stack = normalizeStack(ioInfo.stack);
}
if (typeof ioInfo.start === 'number') {
copy.start = 0;
}
if (typeof ioInfo.end === 'number') {
copy.end = 0;
}
return copy;
}
function normalizeDebugInfo(debugInfo) {
if (Array.isArray(debugInfo.stack)) {
const {debugTask, debugStack, ...copy} = debugInfo;
copy.stack = normalizeStack(debugInfo.stack);
if (debugInfo.owner) {
copy.owner = normalizeDebugInfo(debugInfo.owner);
}
if (debugInfo.awaited) {
copy.awaited = normalizeIOInfo(copy.awaited);
}
return copy;
} else if (typeof debugInfo.time === 'number') {
return {...debugInfo, time: 0};
} else if (debugInfo.awaited) {
return {...debugInfo, awaited: normalizeIOInfo(debugInfo.awaited)};
} else {
return debugInfo;
}
}
function getDebugInfo(obj) {
const debugInfo = obj._debugInfo;
if (debugInfo) {
const copy = [];
for (let i = 0; i < debugInfo.length; i++) {
copy.push(normalizeDebugInfo(debugInfo[i]));
}
return copy;
}
return debugInfo;
}
describe('ReactFlightAsyncDebugInfo', () => {
beforeEach(() => {
jest.resetModules();
jest.useRealTimers();
patchSetImmediate();
global.console = require('console');
jest.mock('react', () => require('react/react.react-server'));
jest.mock('react-server-dom-webpack/server', () =>
require('react-server-dom-webpack/server.node'),
);
ReactServerDOMServer = require('react-server-dom-webpack/server');
jest.resetModules();
jest.useRealTimers();
patchSetImmediate();
__unmockReact();
jest.unmock('react-server-dom-webpack/server');
jest.mock('react-server-dom-webpack/client', () =>
require('react-server-dom-webpack/client.node'),
);
React = require('react');
ReactServerDOMClient = require('react-server-dom-webpack/client');
Stream = require('stream');
});
function delay(timeout) {
return new Promise(resolve => {
setTimeout(resolve, timeout);
});
}
it('can track async information when awaited', async () => {
async function getData() {
await delay(1);
const promise = delay(2);
await Promise.all([promise]);
return 'hi';
}
async function Component() {
const result = await getData();
return result;
}
const stream = ReactServerDOMServer.renderToPipeableStream(<Component />);
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.<anonymous>",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
130,
109,
117,
50,
],
],
},
{
"awaited": {
"end": 0,
"stack": [
[
"delay",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
112,
12,
111,
3,
],
[
"getData",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
119,
13,
118,
5,
],
[
"Component",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
126,
26,
125,
5,
],
],
"start": 0,
},
"stack": [
[
"getData",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
119,
13,
118,
5,
],
[
"Component",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
126,
26,
125,
5,
],
],
},
{
"awaited": {
"end": 0,
"stack": [
[
"delay",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
112,
12,
111,
3,
],
[
"getData",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
120,
21,
118,
5,
],
[
"Component",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
126,
20,
125,
5,
],
],
"start": 0,
},
"stack": [
[
"getData",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
121,
21,
118,
5,
],
[
"Component",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
126,
20,
125,
5,
],
],
},
{
"time": 0,
},
]
`);
}
});
it('can track the start of I/O when no native promise is used', async () => {
function Component() {
const callbacks = [];
setTimeout(function timer() {
callbacks.forEach(callback => callback('hi'));
}, 5);
return {
then(callback) {
callbacks.push(callback);
},
};
}
const stream = ReactServerDOMServer.renderToPipeableStream(<Component />);
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.<anonymous>",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
291,
109,
278,
67,
],
],
},
{
"awaited": {
"end": 0,
"stack": [
[
"Component",
"/packages/react-server/src/__tests__/ReactFlightAsyncDebugInfo-test.js",
281,
7,
279,
5,
],
],
"start": 0,
},
},
{
"time": 0,
},
]
`);
}
});
});

16
packages/react-server/src/forks/ReactFlightServerConfig.dom-edge-parcel.js
View File

@ -22,20 +22,6 @@ export const supportsComponentStorage: boolean =
export const componentStorage: AsyncLocalStorage<ReactComponentInfo | void> =
supportsComponentStorage ? new AsyncLocalStorage() : (null: any);
// We use the Node version but get access to async_hooks from a global.
import type {HookCallbacks, AsyncHook} from 'async_hooks';
export const createAsyncHook: HookCallbacks => AsyncHook =
typeof async_hooks === 'object'
? async_hooks.createHook
: function () {
return ({
enable() {},
disable() {},
}: any);
};
export const executionAsyncId: () => number =
typeof async_hooks === 'object' ? async_hooks.executionAsyncId : (null: any);
export * from '../ReactFlightServerConfigDebugNode';
export * from '../ReactFlightServerConfigDebugNoop';
export * from '../ReactFlightStackConfigV8';

16
packages/react-server/src/forks/ReactFlightServerConfig.dom-edge-turbopack.js
View File

@ -22,20 +22,6 @@ export const supportsComponentStorage: boolean =
export const componentStorage: AsyncLocalStorage<ReactComponentInfo | void> =
supportsComponentStorage ? new AsyncLocalStorage() : (null: any);
// We use the Node version but get access to async_hooks from a global.
import type {HookCallbacks, AsyncHook} from 'async_hooks';
export const createAsyncHook: HookCallbacks => AsyncHook =
typeof async_hooks === 'object'
? async_hooks.createHook
: function () {
return ({
enable() {},
disable() {},
}: any);
};
export const executionAsyncId: () => number =
typeof async_hooks === 'object' ? async_hooks.executionAsyncId : (null: any);
export * from '../ReactFlightServerConfigDebugNode';
export * from '../ReactFlightServerConfigDebugNoop';
export * from '../ReactFlightStackConfigV8';

16
packages/react-server/src/forks/ReactFlightServerConfig.dom-edge.js
View File

@ -23,20 +23,6 @@ export const supportsComponentStorage: boolean =
export const componentStorage: AsyncLocalStorage<ReactComponentInfo | void> =
supportsComponentStorage ? new AsyncLocalStorage() : (null: any);
// We use the Node version but get access to async_hooks from a global.
import type {HookCallbacks, AsyncHook} from 'async_hooks';
export const createAsyncHook: HookCallbacks => AsyncHook =
typeof async_hooks === 'object'
? async_hooks.createHook
: function () {
return ({
enable() {},
disable() {},
}: any);
};
export const executionAsyncId: () => number =
typeof async_hooks === 'object' ? async_hooks.executionAsyncId : (null: any);
export * from '../ReactFlightServerConfigDebugNode';
export * from '../ReactFlightServerConfigDebugNoop';
export * from '../ReactFlightStackConfigV8';

2
packages/react-server/src/forks/ReactFlightServerConfig.dom-node-esm.js
View File

@ -23,8 +23,6 @@ export const supportsComponentStorage = __DEV__;
export const componentStorage: AsyncLocalStorage<ReactComponentInfo | void> =
supportsComponentStorage ? new AsyncLocalStorage() : (null: any);
export {createHook as createAsyncHook, executionAsyncId} from 'async_hooks';
export * from '../ReactFlightServerConfigDebugNode';
export * from '../ReactFlightStackConfigV8';

2
packages/react-server/src/forks/ReactFlightServerConfig.dom-node-parcel.js
View File

@ -23,8 +23,6 @@ export const supportsComponentStorage = __DEV__;
export const componentStorage: AsyncLocalStorage<ReactComponentInfo | void> =
supportsComponentStorage ? new AsyncLocalStorage() : (null: any);
export {createHook as createAsyncHook, executionAsyncId} from 'async_hooks';
export * from '../ReactFlightServerConfigDebugNode';
export * from '../ReactFlightStackConfigV8';

2
packages/react-server/src/forks/ReactFlightServerConfig.dom-node-turbopack.js
View File

@ -23,8 +23,6 @@ export const supportsComponentStorage = __DEV__;
export const componentStorage: AsyncLocalStorage<ReactComponentInfo | void> =
supportsComponentStorage ? new AsyncLocalStorage() : (null: any);
export {createHook as createAsyncHook, executionAsyncId} from 'async_hooks';
export * from '../ReactFlightServerConfigDebugNode';
export * from '../ReactFlightStackConfigV8';

2
packages/react-server/src/forks/ReactFlightServerConfig.dom-node.js
View File

@ -23,8 +23,6 @@ export const supportsComponentStorage = __DEV__;
export const componentStorage: AsyncLocalStorage<ReactComponentInfo | void> =
supportsComponentStorage ? new AsyncLocalStorage() : (null: any);
export {createHook as createAsyncHook, executionAsyncId} from 'async_hooks';
export * from '../ReactFlightServerConfigDebugNode';
export * from '../ReactFlightStackConfigV8';

14
packages/shared/ReactTypes.js
View File

@ -229,12 +229,22 @@ export type ReactErrorInfoDev = {
export type ReactErrorInfo = ReactErrorInfoProd | ReactErrorInfoDev;
export type ReactAsyncInfo = {
+type: string,
// The point where the Async Info started which might not be the same place it was awaited.
export type ReactIOInfo = {
+start: number, // the start time
+end: number, // the end time (this might be different from the time the await was unblocked)
+stack?: null | ReactStackTrace,
// Stashed Data for the Specific Execution Environment. Not part of the transport protocol
+debugStack?: null | Error,
+debugTask?: null | ConsoleTask,
};
export type ReactAsyncInfo = {
+awaited: ReactIOInfo,
+stack?: null | ReactStackTrace,
// Stashed Data for the Specific Execution Environment. Not part of the transport protocol
+debugStack?: null | Error,
+debugTask?: null | ConsoleTask,
};
export type ReactTimeInfo = {

15
scripts/jest/setupTests.js
View File

@ -293,3 +293,18 @@ if (process.env.REACT_CLASS_EQUIVALENCE_TEST) {
return require('internal-test-utils/ReactJSDOM.js');
});
}
// We mock createHook so that we can automatically clean it up.
let installedHook = null;
jest.mock('async_hooks', () => {
const actual = jest.requireActual('async_hooks');
return {
...actual,
createHook(config) {
if (installedHook) {
installedHook.disable();
}
return (installedHook = actual.createHook(config));
},
};
});

40
scripts/shared/inlinedHostConfigs.js
View File

@ -50,6 +50,7 @@ module.exports = [
'react-devtools-shell',
'react-devtools-shared',
'shared/ReactDOMSharedInternals',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
@ -247,6 +248,7 @@ module.exports = [
'react-dom-bindings/src/server/ReactFlightServerConfigDOM.js',
'react-dom-bindings/src/shared/ReactFlightClientConfigDOM.js',
'shared/ReactDOMSharedInternals',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
@ -274,6 +276,7 @@ module.exports = [
'react-devtools-shell',
'react-devtools-shared',
'shared/ReactDOMSharedInternals',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
@ -309,6 +312,7 @@ module.exports = [
'react-devtools-shell',
'react-devtools-shared',
'shared/ReactDOMSharedInternals',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
@ -343,6 +347,7 @@ module.exports = [
'react-devtools-shell',
'react-devtools-shared',
'shared/ReactDOMSharedInternals',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
@ -384,7 +389,7 @@ module.exports = [
'react-devtools-shell',
'react-devtools-shared',
'shared/ReactDOMSharedInternals',
'react-server/src/ReactFlightServerConfigDebugNode.js',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
@ -424,7 +429,7 @@ module.exports = [
'react-devtools-shell',
'react-devtools-shared',
'shared/ReactDOMSharedInternals',
'react-server/src/ReactFlightServerConfigDebugNode.js',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
@ -463,7 +468,7 @@ module.exports = [
'react-devtools-shell',
'react-devtools-shared',
'shared/ReactDOMSharedInternals',
'react-server/src/ReactFlightServerConfigDebugNode.js',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
@ -523,6 +528,7 @@ module.exports = [
'react-dom/src/server/ReactDOMLegacyServerBrowser.js', // react-dom/server.browser
'react-dom/src/server/ReactDOMLegacyServerNode.js', // react-dom/server.node
'shared/ReactDOMSharedInternals',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
@ -539,6 +545,7 @@ module.exports = [
'react-dom-bindings',
'react-markup',
'shared/ReactDOMSharedInternals',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
@ -558,6 +565,7 @@ module.exports = [
'react-dom-bindings',
'react-server-dom-fb',
'shared/ReactDOMSharedInternals',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
@ -566,28 +574,40 @@ module.exports = [
{
shortName: 'native',
entryPoints: ['react-native-renderer'],
paths: ['react-native-renderer'],
paths: [
'react-native-renderer',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: false,
},
{
shortName: 'fabric',
entryPoints: ['react-native-renderer/fabric'],
paths: ['react-native-renderer'],
paths: [
'react-native-renderer',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: false,
},
{
shortName: 'test',
entryPoints: ['react-test-renderer'],
paths: ['react-test-renderer'],
paths: [
'react-test-renderer',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: false,
},
{
shortName: 'art',
entryPoints: ['react-art'],
paths: ['react-art'],
paths: [
'react-art',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: false, // TODO: type it.
isServerSupported: false,
},
@ -599,7 +619,11 @@ module.exports = [
'react-server',
'react-server/flight',
],
paths: ['react-client/flight', 'react-server/flight'],
paths: [
'react-client/flight',
'react-server/flight',
'react-server/src/ReactFlightServerConfigDebugNoop.js',
],
isFlowTyped: true,
isServerSupported: true,
},