Skip to content

PerformanceEntryReporter::getMarkTime to return optional DOMHighResTimeStamp #51389

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 2 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -130,15 +130,46 @@ double NativePerformance::markWithResult(
}

std::tuple<double, double> NativePerformance::measureWithResult(
jsi::Runtime& rt,
jsi::Runtime& runtime,
std::string name,
double startTime,
double endTime,
std::optional<double> duration,
std::optional<std::string> startMark,
std::optional<std::string> endMark) {
auto entry = PerformanceEntryReporter::getInstance()->reportMeasure(
name, startTime, endTime, duration, startMark, endMark);
auto reporter = PerformanceEntryReporter::getInstance();

DOMHighResTimeStamp startTimeValue = startTime;
// If the start time mark name is specified, it takes precedence over the
// startTime parameter, which can be set to 0 by default from JavaScript.
if (startMark) {
if (auto startMarkBufferedTime = reporter->getMarkTime(*startMark)) {
startTimeValue = *startMarkBufferedTime;
} else {
throw jsi::JSError(
runtime, "The mark " + *startMark + " does not exist.");
}
}

DOMHighResTimeStamp endTimeValue = endTime;
// If the end time mark name is specified, it takes precedence over the
// startTime parameter, which can be set to 0 by default from JavaScript.
if (endMark) {
if (auto endMarkBufferedTime = reporter->getMarkTime(*endMark)) {
endTimeValue = *endMarkBufferedTime;
} else {
throw jsi::JSError(
runtime, "The mark " + *startMark + " does not exist.");
}
} else if (duration) {
endTimeValue = startTimeValue + *duration;
} else if (endTimeValue < startTimeValue) {
// The end time is not specified, take the current time, according to the
// standard
endTimeValue = reporter->getCurrentTimeStamp();
}

auto entry = reporter->reportMeasure(name, startTime, endTime);
return std::tuple{entry.startTime, entry.duration};
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -199,28 +199,14 @@ PerformanceMeasure PerformanceEntryReporter::reportMeasure(
const std::string& name,
DOMHighResTimeStamp startTime,
DOMHighResTimeStamp endTime,
const std::optional<DOMHighResTimeStamp>& duration,
const std::optional<std::string>& startMark,
const std::optional<std::string>& endMark,
const std::optional<jsinspector_modern::DevToolsTrackEntryPayload>&
trackMetadata) {
DOMHighResTimeStamp startTimeVal =
startMark ? getMarkTime(*startMark) : startTime;
DOMHighResTimeStamp endTimeVal = endMark ? getMarkTime(*endMark) : endTime;

if (!endMark && endTime < startTimeVal) {
// The end time is not specified, take the current time, according to the
// standard
endTimeVal = getCurrentTimeStamp();
}

DOMHighResTimeStamp durationVal =
duration ? *duration : endTimeVal - startTimeVal;
DOMHighResTimeStamp duration = endTime - startTime;

const auto entry = PerformanceMeasure{
{.name = std::string(name),
.startTime = startTimeVal,
.duration = durationVal}};
.startTime = startTime,
.duration = duration}};

traceMeasure(entry);

Expand All @@ -235,16 +221,16 @@ PerformanceMeasure PerformanceEntryReporter::reportMeasure(
return entry;
}

DOMHighResTimeStamp PerformanceEntryReporter::getMarkTime(
std::optional<DOMHighResTimeStamp> PerformanceEntryReporter::getMarkTime(
const std::string& markName) const {
std::shared_lock lock(buffersMutex_);

if (auto it = markBuffer_.find(markName); it) {
return std::visit(
[](const auto& entryData) { return entryData.startTime; }, *it);
} else {
return 0.0;
}

return std::nullopt;
}

void PerformanceEntryReporter::reportEvent(
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -80,6 +80,8 @@ class PerformanceEntryReporter {
return eventCounts_;
}

std::optional<double> getMarkTime(const std::string& markName) const;

PerformanceMark reportMark(
const std::string& name,
const std::optional<DOMHighResTimeStamp>& startTime = std::nullopt);
Expand All @@ -88,9 +90,6 @@ class PerformanceEntryReporter {
const std::string& name,
double startTime,
double endTime,
const std::optional<double>& duration = std::nullopt,
const std::optional<std::string>& startMark = std::nullopt,
const std::optional<std::string>& endMark = std::nullopt,
const std::optional<jsinspector_modern::DevToolsTrackEntryPayload>&
trackMetadata = std::nullopt);

Expand Down Expand Up @@ -129,8 +128,6 @@ class PerformanceEntryReporter {

std::function<double()> timeStampProvider_ = nullptr;

double getMarkTime(const std::string& markName) const;

const inline PerformanceEntryBuffer& getBuffer(
PerformanceEntryType entryType) const {
switch (entryType) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -108,38 +108,21 @@ TEST(PerformanceEntryReporter, PerformanceEntryReporterTestReportMeasures) {
reporter->reportMark("mark2", 2);

reporter->reportMeasure("measure0", 0, 2);
reporter->reportMeasure("measure1", 0, 2, 4);
reporter->reportMeasure("measure2", 0, 0, std::nullopt, "mark1", "mark2");
reporter->reportMeasure("measure3", 0, 0, 5, "mark1");
reporter->reportMeasure(
"measure4", 1.5, 0, std::nullopt, std::nullopt, "mark2");

reporter->setTimeStampProvider([]() { return 3.5; });
reporter->reportMeasure("measure5", 0, 0, std::nullopt, "mark2");
reporter->reportMeasure("measure1", 0, 3);

reporter->reportMark("mark3", 2.5);
reporter->reportMeasure("measure6", 2.0, 2.0);
reporter->reportMark("mark4", 2.1);
reporter->reportMeasure("measure2", 2.0, 2.0);
reporter->reportMark("mark4", 3.0);
// Uses the last reported time for mark4
reporter->reportMeasure("measure7", 0, 0, std::nullopt, "mark1", "mark4");

const auto entries = toSorted(reporter->getEntries());

const std::vector<PerformanceEntry> expected = {
PerformanceMark{{.name = "mark0", .startTime = 0, .duration = 0}},
PerformanceMeasure{{.name = "measure0", .startTime = 0, .duration = 2}},
PerformanceMeasure{{.name = "measure1", .startTime = 0, .duration = 4}},
PerformanceMeasure{{.name = "measure1", .startTime = 0, .duration = 3}},
PerformanceMark{{.name = "mark1", .startTime = 1, .duration = 0}},
PerformanceMeasure{{.name = "measure2", .startTime = 1, .duration = 1}},
PerformanceMeasure{{.name = "measure7", .startTime = 1, .duration = 2}},
PerformanceMeasure{{.name = "measure3", .startTime = 1, .duration = 5}},
PerformanceMeasure{
{.name = "measure4", .startTime = 1.5, .duration = 0.5}},
PerformanceMark{{.name = "mark2", .startTime = 2, .duration = 0}},
PerformanceMeasure{{.name = "measure6", .startTime = 2, .duration = 0}},
PerformanceMeasure{{.name = "measure5", .startTime = 2, .duration = 1.5}},
PerformanceMark{{.name = "mark4", .startTime = 2.1, .duration = 0}},
PerformanceMeasure{{.name = "measure2", .startTime = 2, .duration = 0}},
PerformanceMark{{.name = "mark3", .startTime = 2.5, .duration = 0}},
PerformanceMark{{.name = "mark4", .startTime = 3, .duration = 0}}};

Expand All @@ -160,24 +143,21 @@ TEST(PerformanceEntryReporter, PerformanceEntryReporterTestGetEntries) {
reporter->reportMark("mark2", 2);

reporter->reportMeasure("common_name", 0, 2);
reporter->reportMeasure("measure1", 0, 2, 4);
reporter->reportMeasure("measure2", 0, 0, std::nullopt, "mark1", "mark2");
reporter->reportMeasure("measure3", 0, 0, 5, "mark1");
reporter->reportMeasure(
"measure4", 1.5, 0, std::nullopt, std::nullopt, "mark2");
reporter->reportMeasure("measure1", 0, 3);
reporter->reportMeasure("measure2", 1, 6);
reporter->reportMeasure("measure3", 1.5, 2);

{
const auto allEntries = toSorted(reporter->getEntries());
const std::vector<PerformanceEntry> expected = {
PerformanceMark{{.name = "common_name", .startTime = 0, .duration = 0}},
PerformanceMeasure{
{.name = "common_name", .startTime = 0, .duration = 2}},
PerformanceMeasure{{.name = "measure1", .startTime = 0, .duration = 4}},
PerformanceMeasure{{.name = "measure1", .startTime = 0, .duration = 3}},
PerformanceMark{{.name = "mark1", .startTime = 1, .duration = 0}},
PerformanceMeasure{{.name = "measure2", .startTime = 1, .duration = 1}},
PerformanceMeasure{{.name = "measure3", .startTime = 1, .duration = 5}},
PerformanceMeasure{{.name = "measure2", .startTime = 1, .duration = 5}},
PerformanceMeasure{
{.name = "measure4", .startTime = 1.5, .duration = 0.5}},
{.name = "measure3", .startTime = 1.5, .duration = 0.5}},
PerformanceMark{{.name = "mark2", .startTime = 2, .duration = 0}}};
ASSERT_EQ(expected, allEntries);
}
Expand All @@ -198,11 +178,10 @@ TEST(PerformanceEntryReporter, PerformanceEntryReporterTestGetEntries) {
const std::vector<PerformanceEntry> expected = {
PerformanceMeasure{
{.name = "common_name", .startTime = 0, .duration = 2}},
PerformanceMeasure{{.name = "measure1", .startTime = 0, .duration = 4}},
PerformanceMeasure{{.name = "measure2", .startTime = 1, .duration = 1}},
PerformanceMeasure{{.name = "measure3", .startTime = 1, .duration = 5}},
PerformanceMeasure{{.name = "measure1", .startTime = 0, .duration = 3}},
PerformanceMeasure{{.name = "measure2", .startTime = 1, .duration = 5}},
PerformanceMeasure{
{.name = "measure4", .startTime = 1.5, .duration = 0.5}}};
{.name = "measure3", .startTime = 1.5, .duration = 0.5}}};
ASSERT_EQ(expected, measures);
}

Expand Down Expand Up @@ -233,11 +212,9 @@ TEST(PerformanceEntryReporter, PerformanceEntryReporterTestClearMarks) {
reporter->reportMark("mark2", 2);

reporter->reportMeasure("common_name", 0, 2);
reporter->reportMeasure("measure1", 0, 2, 4);
reporter->reportMeasure("measure2", 0, 0, std::nullopt, "mark1", "mark2");
reporter->reportMeasure("measure3", 0, 0, 5, "mark1");
reporter->reportMeasure(
"measure4", 1.5, 0, std::nullopt, std::nullopt, "mark2");
reporter->reportMeasure("measure1", 0, 3);
reporter->reportMeasure("measure2", 1, 6);
reporter->reportMeasure("measure3", 1.5, 2);

reporter->clearEntries(PerformanceEntryType::MARK, "common_name");

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ add_library(react_renderer_observers_events OBJECT ${react_renderer_observers_ev

target_include_directories(react_renderer_observers_events PUBLIC ${REACT_COMMON_DIR})
target_link_libraries(react_renderer_observers_events
react_debug
react_performance_timeline
react_timing
react_renderer_core
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -7,8 +7,10 @@

#include "EventPerformanceLogger.h"

#include <react/debug/react_native_assert.h>
#include <react/featureflags/ReactNativeFeatureFlags.h>
#include <react/timing/primitives.h>

#include <unordered_map>

namespace facebook::react {
Expand Down Expand Up @@ -127,7 +129,7 @@ EventTag EventPerformanceLogger::onEventStart(
{
std::lock_guard lock(eventsInFlightMutex_);
eventsInFlight_.emplace(
eventTag, EventEntry{reportedName, target, timeStamp, 0.0});
eventTag, EventEntry{reportedName, target, timeStamp});
}
return eventTag;
}
Expand Down Expand Up @@ -163,6 +165,9 @@ void EventPerformanceLogger::onEventProcessingEnd(EventTag tag) {
}

auto& entry = it->second;
react_native_assert(
entry.processingStartTime.has_value() &&
"Attempting to set processingEndTime while processingStartTime is not set.");
entry.processingEndTime = timeStamp;
}
}
Expand All @@ -188,12 +193,18 @@ void EventPerformanceLogger::dispatchPendingEventTimingEntries(
entry.isWaitingForMount = true;
++it;
} else {
react_native_assert(
entry.processingStartTime.has_value() &&
"Attempted to report PerformanceEventTiming, which did not have processingStartTime defined.");
react_native_assert(
entry.processingEndTime.has_value() &&
"Attempted to report PerformanceEventTiming, which did not have processingEndTime defined.");
performanceEntryReporter->reportEvent(
std::string(entry.name),
entry.startTime,
performanceEntryReporter->getCurrentTimeStamp() - entry.startTime,
entry.processingStartTime,
entry.processingEndTime,
entry.processingStartTime.value(),
entry.processingEndTime.value(),
entry.interactionId);
it = eventsInFlight_.erase(it);
}
Expand All @@ -214,12 +225,18 @@ void EventPerformanceLogger::shadowTreeDidMount(
const auto& entry = it->second;
if (entry.isWaitingForMount &&
isTargetInRootShadowNode(entry.target, rootShadowNode)) {
react_native_assert(
entry.processingStartTime.has_value() &&
"Attempted to report PerformanceEventTiming, which did not have processingStartTime defined.");
react_native_assert(
entry.processingEndTime.has_value() &&
"Attempted to report PerformanceEventTiming, which did not have processingEndTime defined.");
performanceEntryReporter->reportEvent(
std::string(entry.name),
entry.startTime,
mountTime - entry.startTime,
entry.processingStartTime,
entry.processingEndTime,
entry.processingStartTime.value(),
entry.processingEndTime.value(),
entry.interactionId);
it = eventsInFlight_.erase(it);
} else {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@
#include <react/renderer/core/EventLogger.h>
#include <react/renderer/runtimescheduler/RuntimeSchedulerEventTimingDelegate.h>
#include <react/renderer/uimanager/UIManagerMountHook.h>

#include <memory>
#include <mutex>
#include <optional>
Expand Down Expand Up @@ -52,9 +53,9 @@ class EventPerformanceLogger : public EventLogger,
struct EventEntry {
std::string_view name;
SharedEventTarget target{nullptr};
DOMHighResTimeStamp startTime{0.0};
DOMHighResTimeStamp processingStartTime{0.0};
DOMHighResTimeStamp processingEndTime{0.0};
DOMHighResTimeStamp startTime;
std::optional<DOMHighResTimeStamp> processingStartTime;
std::optional<DOMHighResTimeStamp> processingEndTime;

bool isWaitingForMount{false};

Expand All @@ -63,7 +64,7 @@ class EventPerformanceLogger : public EventLogger,
PerformanceEntryInteractionId interactionId{0};

bool isWaitingForDispatch() {
return processingEndTime == 0.0;
return !processingEndTime.has_value();
}
};

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@ import type {
} from './PerformanceEntry';
import type {DetailType, PerformanceMarkOptions} from './UserTiming';

import DOMException from '../errors/DOMException';
import {setPlatformObject} from '../webidl/PlatformObjects';
import {EventCounts} from './EventTiming';
import {
Expand Down Expand Up @@ -192,15 +193,22 @@ export default class Performance {
let computedDuration = duration;

if (NativePerformance?.measureWithResult) {
[computedStartTime, computedDuration] =
NativePerformance.measureWithResult(
measureName,
startTime,
endTime,
duration,
startMarkName,
endMarkName,
try {
[computedStartTime, computedDuration] =
NativePerformance.measureWithResult(
measureName,
startTime,
endTime,
duration,
startMarkName,
endMarkName,
);
} catch (error) {
throw new DOMException(
"Failed to execute 'measure' on 'Performance': " + error.message,
'SyntaxError',
);
}
} else {
warnNoNativePerformance();
}
Expand Down
Loading