Skip to content

Commit acee65d

Browse files
sebmarkbageeps1lon
andauthored
[Flight] Track Awaits on I/O as Debug Info (facebook#33388)
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 <[email protected]>
1 parent 1ae0a84 commit acee65d

15 files changed

+840
-76
lines changed
Lines changed: 41 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,41 @@
1+
/**
2+
* Copyright (c) Meta Platforms, Inc. and affiliates.
3+
*
4+
* This source code is licensed under the MIT license found in the
5+
* LICENSE file in the root directory of this source tree.
6+
*
7+
* @flow
8+
*/
9+
10+
export const IO_NODE = 0;
11+
export const PROMISE_NODE = 1;
12+
export const AWAIT_NODE = 2;
13+
14+
export type IONode = {
15+
tag: 0,
16+
stack: Error, // callsite that spawned the I/O
17+
start: number, // start time when the first part of the I/O sequence started
18+
end: number, // we typically don't use this. only when there's no promise intermediate.
19+
awaited: null, // I/O is only blocked on external.
20+
previous: null | AwaitNode, // the preceeding await that spawned this new work
21+
};
22+
23+
export type PromiseNode = {
24+
tag: 1,
25+
stack: Error, // callsite that created the Promise
26+
start: number, // start time when the Promise was created
27+
end: number, // end time when the Promise was resolved.
28+
awaited: null | AsyncSequence, // the thing that ended up resolving this promise
29+
previous: null, // where we created the promise is not interesting since creating it doesn't mean waiting.
30+
};
31+
32+
export type AwaitNode = {
33+
tag: 2,
34+
stack: Error, // callsite that awaited (using await, .then(), Promise.all(), ...)
35+
start: -1.1, // not used. We use the timing of the awaited promise.
36+
end: -1.1, // not used.
37+
awaited: null | AsyncSequence, // the promise we were waiting on
38+
previous: null | AsyncSequence, // the sequence that was blocking us from awaiting in the first place
39+
};
40+
41+
export type AsyncSequence = IONode | PromiseNode | AwaitNode;

0 commit comments

Comments
 (0)