Skip to content

Commit 6b05a59

Browse files
rubennortefacebook-github-bot
rubennorte
authored and
facebook-github-bot
committed
Extend PerformanceEventTiming with taskEndTime (react#53199)
Summary: Pull Request resolved: react#53199 Changelog: [internal] This adds a new `taskEndTime` field in the internal C++ representation of `PerformanceEventTiming` so we can distinguish events that waited for mount (because they triggered changes) and events that didn't, so report INP correctly. Reviewed By: rshest Differential Revision: D79894702 fbshipit-source-id: f7472bfaecaa69f2126719d0dc3d3b251e3a8f68
1 parent 94623ca commit 6b05a59

9 files changed

Lines changed: 47 additions & 5 deletions

File tree

‎packages/react-native/ReactCommon/react/performance/timeline/PerformanceEntry.h‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -46,6 +46,10 @@ struct PerformanceEventTiming : AbstractPerformanceEntry {
4646
static constexpr PerformanceEntryType entryType = PerformanceEntryType::EVENT;
4747
HighResTimeStamp processingStart;
4848
HighResTimeStamp processingEnd;
49+
// Custom RN extension not exposed to JS for now.
50+
// It's the same "taskEndTime" defined in the spec for the Event Loop:
51+
// https://html.spec.whatwg.org/multipage/webappapis.html#event-loop-processing-model
52+
HighResTimeStamp taskEndTime;
4953
PerformanceEntryInteractionId interactionId;
5054
};
5155

‎packages/react-native/ReactCommon/react/performance/timeline/PerformanceEntryReporter.cpp‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -247,6 +247,7 @@ void PerformanceEntryReporter::reportEvent(
247247
HighResDuration duration,
248248
HighResTimeStamp processingStart,
249249
HighResTimeStamp processingEnd,
250+
HighResTimeStamp taskEndTime,
250251
uint32_t interactionId) {
251252
eventCounts_[name]++;
252253

@@ -260,6 +261,7 @@ void PerformanceEntryReporter::reportEvent(
260261
{.name = name, .startTime = startTime, .duration = duration},
261262
processingStart,
262263
processingEnd,
264+
taskEndTime,
263265
interactionId};
264266

265267
{

‎packages/react-native/ReactCommon/react/performance/timeline/PerformanceEntryReporter.h‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -105,6 +105,7 @@ class PerformanceEntryReporter {
105105
HighResDuration duration,
106106
HighResTimeStamp processingStart,
107107
HighResTimeStamp processingEnd,
108+
HighResTimeStamp taskEndTime,
108109
uint32_t interactionId);
109110

110111
void reportLongTask(HighResTimeStamp startTime, HighResDuration duration);

‎packages/react-native/ReactCommon/react/performance/timeline/tests/PerformanceObserverTest.cpp‎

Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -96,20 +96,23 @@ TEST(PerformanceObserver, PerformanceObserverTestFilterMulti) {
9696
HighResDuration::fromMilliseconds(10),
9797
timeOrigin,
9898
timeOrigin,
99+
timeOrigin,
99100
0);
100101
reporter->reportEvent(
101102
"test2",
102103
timeOrigin + HighResDuration::fromMilliseconds(10),
103104
HighResDuration::fromMilliseconds(10),
104105
timeOrigin,
105106
timeOrigin,
107+
timeOrigin,
106108
0);
107109
reporter->reportEvent(
108110
"test3",
109111
timeOrigin + HighResDuration::fromMilliseconds(10),
110112
HighResDuration::fromMilliseconds(10),
111113
timeOrigin,
112114
timeOrigin,
115+
timeOrigin,
113116
0);
114117

115118
ASSERT_EQ(observer->takeRecords().size(), 0);
@@ -155,20 +158,23 @@ TEST(PerformanceObserver, PerformanceObserverTestFilterMultiCallbackNotCalled) {
155158
HighResDuration::fromMilliseconds(10),
156159
timeOrigin,
157160
timeOrigin,
161+
timeOrigin,
158162
0);
159163
reporter->reportEvent(
160164
"test2",
161165
timeOrigin + HighResDuration::fromMilliseconds(10),
162166
HighResDuration::fromMilliseconds(10),
163167
timeOrigin,
164168
timeOrigin,
169+
timeOrigin,
165170
0);
166171
reporter->reportEvent(
167172
"off3",
168173
timeOrigin + HighResDuration::fromMilliseconds(10),
169174
HighResDuration::fromMilliseconds(10),
170175
timeOrigin,
171176
timeOrigin,
177+
timeOrigin,
172178
0);
173179

174180
ASSERT_FALSE(callbackCalled);
@@ -230,20 +236,23 @@ TEST(PerformanceObserver, PerformanceObserverTestObserveDurationThreshold) {
230236
HighResDuration::fromMilliseconds(50),
231237
timeOrigin,
232238
timeOrigin,
239+
timeOrigin,
233240
0);
234241
reporter->reportEvent(
235242
"test2",
236243
timeOrigin,
237244
HighResDuration::fromMilliseconds(100),
238245
timeOrigin,
239246
timeOrigin,
247+
timeOrigin,
240248
0);
241249
reporter->reportEvent(
242250
"off1",
243251
timeOrigin,
244252
HighResDuration::fromMilliseconds(40),
245253
timeOrigin,
246254
timeOrigin,
255+
timeOrigin,
247256
0);
248257
reporter->reportMark(
249258
"off2", timeOrigin + HighResDuration::fromMilliseconds(100));
@@ -253,6 +262,7 @@ TEST(PerformanceObserver, PerformanceObserverTestObserveDurationThreshold) {
253262
HighResDuration::fromMilliseconds(60),
254263
timeOrigin,
255264
timeOrigin,
265+
timeOrigin,
256266
0);
257267

258268
const std::vector<PerformanceEntry> expected = {
@@ -262,20 +272,23 @@ TEST(PerformanceObserver, PerformanceObserverTestObserveDurationThreshold) {
262272
.duration = HighResDuration::fromMilliseconds(50)},
263273
timeOrigin,
264274
timeOrigin,
275+
timeOrigin,
265276
0},
266277
PerformanceEventTiming{
267278
{.name = "test2",
268279
.startTime = timeOrigin,
269280
.duration = HighResDuration::fromMilliseconds(100)},
270281
timeOrigin,
271282
timeOrigin,
283+
timeOrigin,
272284
0},
273285
PerformanceEventTiming{
274286
{.name = "test3",
275287
.startTime = timeOrigin,
276288
.duration = HighResDuration::fromMilliseconds(60)},
277289
timeOrigin,
278290
timeOrigin,
291+
timeOrigin,
279292
0},
280293
};
281294

@@ -295,27 +308,31 @@ TEST(PerformanceObserver, PerformanceObserverTestObserveBuffered) {
295308
HighResDuration::fromMilliseconds(50),
296309
timeOrigin,
297310
timeOrigin,
311+
timeOrigin,
298312
0);
299313
reporter->reportEvent(
300314
"test2",
301315
timeOrigin,
302316
HighResDuration::fromMilliseconds(100),
303317
timeOrigin,
304318
timeOrigin,
319+
timeOrigin,
305320
0);
306321
reporter->reportEvent(
307322
"test3",
308323
timeOrigin,
309324
HighResDuration::fromMilliseconds(40),
310325
timeOrigin,
311326
timeOrigin,
327+
timeOrigin,
312328
0);
313329
reporter->reportEvent(
314330
"test4",
315331
timeOrigin,
316332
HighResDuration::fromMilliseconds(100),
317333
timeOrigin,
318334
timeOrigin,
335+
timeOrigin,
319336
0);
320337

321338
auto observer =
@@ -332,20 +349,23 @@ TEST(PerformanceObserver, PerformanceObserverTestObserveBuffered) {
332349
.duration = HighResDuration::fromMilliseconds(50)},
333350
timeOrigin,
334351
timeOrigin,
352+
timeOrigin,
335353
0},
336354
PerformanceEventTiming{
337355
{.name = "test2",
338356
.startTime = timeOrigin,
339357
.duration = HighResDuration::fromMilliseconds(100)},
340358
timeOrigin,
341359
timeOrigin,
360+
timeOrigin,
342361
0},
343362
PerformanceEventTiming{
344363
{.name = "test4",
345364
.startTime = timeOrigin,
346365
.duration = HighResDuration::fromMilliseconds(100)},
347366
timeOrigin,
348367
timeOrigin,
368+
timeOrigin,
349369
0},
350370
};
351371

@@ -378,13 +398,15 @@ TEST(PerformanceObserver, PerformanceObserverTestMultiple) {
378398
HighResDuration::fromMilliseconds(100),
379399
timeOrigin,
380400
timeOrigin,
401+
timeOrigin,
381402
0);
382403
reporter->reportEvent(
383404
"event2",
384405
timeOrigin,
385406
HighResDuration::fromMilliseconds(40),
386407
timeOrigin,
387408
timeOrigin,
409+
timeOrigin,
388410
0);
389411
reporter->reportMark(
390412
"mark1", timeOrigin + HighResDuration::fromMilliseconds(100));
@@ -394,6 +416,7 @@ TEST(PerformanceObserver, PerformanceObserverTestMultiple) {
394416
HighResDuration::fromMilliseconds(60),
395417
timeOrigin,
396418
timeOrigin,
419+
timeOrigin,
397420
0);
398421

399422
const std::vector<PerformanceEntry> expected1 = {
@@ -403,13 +426,15 @@ TEST(PerformanceObserver, PerformanceObserverTestMultiple) {
403426
.duration = HighResDuration::fromMilliseconds(100)},
404427
timeOrigin,
405428
timeOrigin,
429+
timeOrigin,
406430
0},
407431
PerformanceEventTiming{
408432
{.name = "event3",
409433
.startTime = timeOrigin,
410434
.duration = HighResDuration::fromMilliseconds(60)},
411435
timeOrigin,
412436
timeOrigin,
437+
timeOrigin,
413438
0},
414439
};
415440

@@ -420,6 +445,7 @@ TEST(PerformanceObserver, PerformanceObserverTestMultiple) {
420445
.duration = HighResDuration::fromMilliseconds(100)},
421446
timeOrigin,
422447
timeOrigin,
448+
timeOrigin,
423449
0},
424450
};
425451

‎packages/react-native/ReactCommon/react/renderer/observers/events/EventPerformanceLogger.cpp‎

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -172,6 +172,7 @@ void EventPerformanceLogger::onEventProcessingEnd(EventTag tag) {
172172
}
173173

174174
void EventPerformanceLogger::dispatchPendingEventTimingEntries(
175+
HighResTimeStamp taskEndTime,
175176
const std::unordered_set<SurfaceId>&
176177
surfaceIdsWithPendingRenderingUpdates) {
177178
auto performanceEntryReporter = performanceEntryReporter_.lock();
@@ -190,6 +191,7 @@ void EventPerformanceLogger::dispatchPendingEventTimingEntries(
190191
entry.target, surfaceIdsWithPendingRenderingUpdates)) {
191192
// We'll wait for mount to report the event
192193
entry.isWaitingForMount = true;
194+
entry.taskEndTime = taskEndTime;
193195
++it;
194196
} else {
195197
react_native_assert(
@@ -198,12 +200,14 @@ void EventPerformanceLogger::dispatchPendingEventTimingEntries(
198200
react_native_assert(
199201
entry.processingEndTime.has_value() &&
200202
"Attempted to report PerformanceEventTiming, which did not have processingEndTime defined.");
203+
201204
performanceEntryReporter->reportEvent(
202205
std::string(entry.name),
203206
entry.startTime,
204-
HighResTimeStamp::now() - entry.startTime,
207+
taskEndTime - entry.startTime,
205208
entry.processingStartTime.value(),
206209
entry.processingEndTime.value(),
210+
taskEndTime,
207211
entry.interactionId);
208212
it = eventsInFlight_.erase(it);
209213
}
@@ -236,6 +240,7 @@ void EventPerformanceLogger::shadowTreeDidMount(
236240
mountTime - entry.startTime,
237241
entry.processingStartTime.value(),
238242
entry.processingEndTime.value(),
243+
entry.taskEndTime.value(),
239244
entry.interactionId);
240245
it = eventsInFlight_.erase(it);
241246
} else {

‎packages/react-native/ReactCommon/react/renderer/observers/events/EventPerformanceLogger.h‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,7 @@ class EventPerformanceLogger : public EventLogger,
4040
#pragma mark - RuntimeSchedulerEventTimingDelegate
4141

4242
void dispatchPendingEventTimingEntries(
43+
HighResTimeStamp taskEndTime,
4344
const std::unordered_set<SurfaceId>&
4445
surfaceIdsWithPendingRenderingUpdates) override;
4546

@@ -56,6 +57,7 @@ class EventPerformanceLogger : public EventLogger,
5657
HighResTimeStamp startTime;
5758
std::optional<HighResTimeStamp> processingStartTime;
5859
std::optional<HighResTimeStamp> processingEndTime;
60+
std::optional<HighResTimeStamp> taskEndTime;
5961

6062
bool isWaitingForMount{false};
6163

‎packages/react-native/ReactCommon/react/renderer/runtimescheduler/RuntimeSchedulerEventTimingDelegate.h‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@
77

88
#pragma once
99

10+
#include <react/timing/primitives.h>
1011
#include <unordered_set>
1112

1213
namespace facebook::react {
@@ -18,6 +19,7 @@ class RuntimeSchedulerEventTimingDelegate {
1819
virtual ~RuntimeSchedulerEventTimingDelegate() = default;
1920

2021
virtual void dispatchPendingEventTimingEntries(
22+
HighResTimeStamp taskEndTime,
2123
const std::unordered_set<SurfaceId>&
2224
surfaceIdsWithPendingRenderingUpdates) = 0;
2325
};

‎packages/react-native/ReactCommon/react/renderer/runtimescheduler/RuntimeScheduler_Modern.cpp‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -319,7 +319,7 @@ void RuntimeScheduler_Modern::runEventLoopTick(
319319
reportLongTasks(task, taskStartTime, taskEndTime);
320320

321321
// "Update the rendering" step.
322-
updateRendering();
322+
updateRendering(taskEndTime);
323323

324324
currentTask_ = nullptr;
325325
}
@@ -329,15 +329,15 @@ void RuntimeScheduler_Modern::runEventLoopTick(
329329
* event loop. See
330330
* https://html.spec.whatwg.org/multipage/webappapis.html#update-the-rendering.
331331
*/
332-
void RuntimeScheduler_Modern::updateRendering() {
332+
void RuntimeScheduler_Modern::updateRendering(HighResTimeStamp taskEndTime) {
333333
TraceSection s("RuntimeScheduler::updateRendering");
334334

335335
// This is the integration of the Event Timing API in the Event Loop.
336336
// See https://w3c.github.io/event-timing/#sec-modifications-HTML
337337
const auto eventTimingDelegate = eventTimingDelegate_.load();
338338
if (eventTimingDelegate != nullptr) {
339339
eventTimingDelegate->dispatchPendingEventTimingEntries(
340-
surfaceIdsWithPendingRenderingUpdates_);
340+
taskEndTime, surfaceIdsWithPendingRenderingUpdates_);
341341
}
342342

343343
// This is the integration of the Intersection Observer API in the Event Loop.

‎packages/react-native/ReactCommon/react/renderer/runtimescheduler/RuntimeScheduler_Modern.h‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -198,7 +198,7 @@ class RuntimeScheduler_Modern final : public RuntimeSchedulerBase {
198198
Task& task,
199199
bool didUserCallbackTimeout) const;
200200

201-
void updateRendering();
201+
void updateRendering(HighResTimeStamp taskEndTime);
202202

203203
bool performingMicrotaskCheckpoint_{false};
204204
void performMicrotaskCheckpoint(jsi::Runtime& runtime);

0 commit comments

Comments
 (0)