Skip to content

Commit 35719f2

Browse files
committed
Explicitly track end time
advanceTaskTime should be used before an operation to advance time before emitting that operation. markOperationEndTime should be used as its own marker after an operation. This needs to always be emitted even if it doesn't advance time.
1 parent 4e8a250 commit 35719f2

File tree

3 files changed

+110
-73
lines changed

3 files changed

+110
-73
lines changed

packages/react-client/src/__tests__/ReactFlight-test.js

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -2834,7 +2834,8 @@ describe('ReactFlight', () => {
28342834
stack: ' in Object.<anonymous> (at **)',
28352835
props: {},
28362836
},
2837-
{time: gate(flags => flags.enableAsyncDebugInfo) ? 25 : 23}, // This last one is when the promise resolved into the first party.
2837+
{time: 22},
2838+
{time: 23}, // This last one is when the promise resolved into the first party.
28382839
]
28392840
: undefined,
28402841
);
@@ -2849,7 +2850,7 @@ describe('ReactFlight', () => {
28492850
stack: ' in myLazy (at **)\n in lazyInitializer (at **)',
28502851
props: {},
28512852
},
2852-
{time: gate(flags => flags.enableAsyncDebugInfo) ? 23 : 24},
2853+
{time: 22},
28532854
]
28542855
: undefined,
28552856
);
@@ -2864,7 +2865,7 @@ describe('ReactFlight', () => {
28642865
stack: ' in Object.<anonymous> (at **)',
28652866
props: {},
28662867
},
2867-
{time: gate(flags => flags.enableAsyncDebugInfo) ? 24 : 25},
2868+
{time: 22},
28682869
]
28692870
: undefined,
28702871
);
@@ -2974,6 +2975,7 @@ describe('ReactFlight', () => {
29742975
stack: ' in Object.<anonymous> (at **)',
29752976
props: {},
29762977
},
2978+
{time: 19},
29772979
]
29782980
: undefined,
29792981
);

packages/react-server/src/ReactFlightServer.js

Lines changed: 20 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1995,7 +1995,7 @@ function visitAsyncNode(
19951995
owner: node.owner,
19961996
stack: stack,
19971997
});
1998-
advanceTaskTime(request, task, endTime);
1998+
markOperationEndTime(request, task, endTime);
19991999
}
20002000
}
20012001
}
@@ -2035,7 +2035,7 @@ function emitAsyncSequence(
20352035
awaited: ((awaitedNode: any): ReactIOInfo), // This is deduped by this reference.
20362036
env: env,
20372037
});
2038-
advanceTaskTime(request, task, awaitedNode.end);
2038+
markOperationEndTime(request, task, awaitedNode.end);
20392039
}
20402040
}
20412041

@@ -4255,7 +4255,7 @@ function forwardDebugInfo(
42554255
// When forwarding time we need to ensure to convert it to the time space of the payload.
42564256
// We clamp the time to the starting render of the current component. It's as if it took
42574257
// no time to render and await if we reuse cached content.
4258-
advanceTaskTime(request, task, info.time);
4258+
markOperationEndTime(request, task, info.time);
42594259
} else {
42604260
if (typeof info.name === 'string') {
42614261
// We outline this model eagerly so that we can refer to by reference as an owner.
@@ -4352,6 +4352,20 @@ function advanceTaskTime(
43524352
task.timed = true;
43534353
}
43544354

4355+
function markOperationEndTime(request: Request, task: Task, timestamp: number) {
4356+
if (!enableProfilerTimer || !enableComponentPerformanceTrack) {
4357+
return;
4358+
}
4359+
// This is like advanceTaskTime() but always emits a timing chunk even if it doesn't advance.
4360+
// This ensures that the end time of the previous entry isn't implied to be the start of the next one.
4361+
if (timestamp > task.time) {
4362+
emitTimingChunk(request, task.id, timestamp);
4363+
task.time = timestamp;
4364+
} else {
4365+
emitTimingChunk(request, task.id, task.time);
4366+
}
4367+
}
4368+
43554369
function emitChunk(
43564370
request: Request,
43574371
task: Task,
@@ -4443,7 +4457,7 @@ function emitChunk(
44434457
function erroredTask(request: Request, task: Task, error: mixed): void {
44444458
if (enableProfilerTimer && enableComponentPerformanceTrack) {
44454459
if (task.timed) {
4446-
advanceTaskTime(request, task, performance.now());
4460+
markOperationEndTime(request, task, performance.now());
44474461
}
44484462
}
44494463
task.status = ERRORED;
@@ -4526,7 +4540,7 @@ function retryTask(request: Request, task: Task): void {
45264540
// We've finished rendering. Log the end time.
45274541
if (enableProfilerTimer && enableComponentPerformanceTrack) {
45284542
if (task.timed) {
4529-
advanceTaskTime(request, task, performance.now());
4543+
markOperationEndTime(request, task, performance.now());
45304544
}
45314545
}
45324546

@@ -4653,7 +4667,7 @@ function abortTask(task: Task, request: Request, errorId: number): void {
46534667
// Track when we aborted this task as its end time.
46544668
if (enableProfilerTimer && enableComponentPerformanceTrack) {
46554669
if (task.timed) {
4656-
advanceTaskTime(request, task, performance.now());
4670+
markOperationEndTime(request, task, performance.now());
46574671
}
46584672
}
46594673
// Instead of emitting an error per task.id, we emit a model that only

0 commit comments

Comments
 (0)