Skip to content
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

fix(android,ios): performance record inaccurate when engine reuse #4094

Merged
merged 1 commit into from
Oct 29, 2024
Merged
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
12 changes: 6 additions & 6 deletions dom/include/dom/dom_manager.h
Original file line number Diff line number Diff line change
Expand Up @@ -133,10 +133,10 @@ class DomManager : public std::enable_shared_from_this<DomManager> {
static byte_string GetSnapShot(const std::shared_ptr<RootNode>& root_node);
bool SetSnapShot(const std::shared_ptr<RootNode>& root_node, const byte_string& buffer);

void RecordDomStartTimePoint();
void RecordDomEndTimePoint();
inline auto GetDomStartTimePoint() { return dom_start_time_point_; }
inline auto GetDomEndTimePoint() { return dom_end_time_point_; }
void RecordDomStartTimePoint(uint32_t root_id);
void RecordDomEndTimePoint(uint32_t root_id);
inline auto GetDomStartTimePoint(uint32_t root_id) { return dom_start_time_point_[root_id]; }
inline auto GetDomEndTimePoint(uint32_t root_id) { return dom_end_time_point_[root_id]; }

private:
friend class DomNode;
Expand All @@ -152,8 +152,8 @@ class DomManager : public std::enable_shared_from_this<DomManager> {
std::shared_ptr<TaskRunner> task_runner_;
std::shared_ptr<Worker> worker_;

footstone::TimePoint dom_start_time_point_;
footstone::TimePoint dom_end_time_point_;
std::unordered_map<uint32_t, footstone::TimePoint> dom_start_time_point_;
std::unordered_map<uint32_t, footstone::TimePoint> dom_end_time_point_;
};

} // namespace dom
Expand Down
14 changes: 7 additions & 7 deletions dom/src/dom/dom_manager.cc
Original file line number Diff line number Diff line change
Expand Up @@ -272,16 +272,16 @@ bool DomManager::SetSnapShot(const std::shared_ptr<RootNode>& root_node, const b
return true;
}

void DomManager::RecordDomStartTimePoint() {
if (dom_start_time_point_.ToEpochDelta() == TimeDelta::Zero()) {
dom_start_time_point_ = footstone::TimePoint::SystemNow();
void DomManager::RecordDomStartTimePoint(uint32_t root_id) {
if (dom_start_time_point_[root_id].ToEpochDelta() == TimeDelta::Zero()) {
dom_start_time_point_[root_id] = footstone::TimePoint::SystemNow();
}
}

void DomManager::RecordDomEndTimePoint() {
if (dom_end_time_point_.ToEpochDelta() == TimeDelta::Zero()
&& dom_start_time_point_.ToEpochDelta() != TimeDelta::Zero()) {
dom_end_time_point_ = footstone::TimePoint::SystemNow();
void DomManager::RecordDomEndTimePoint(uint32_t root_id) {
if (dom_end_time_point_[root_id].ToEpochDelta() == TimeDelta::Zero()
&& dom_start_time_point_[root_id].ToEpochDelta() != TimeDelta::Zero()) {
dom_end_time_point_[root_id] = footstone::TimePoint::SystemNow();
}
}

Expand Down
2 changes: 1 addition & 1 deletion dom/src/dom/root_node.cc
Original file line number Diff line number Diff line change
Expand Up @@ -333,7 +333,7 @@ void RootNode::SyncWithRenderManager(const std::shared_ptr<RenderManager>& rende
TDF_PERF_LOG("RootNode::DoAndFlushLayout Done");
auto dom_manager = dom_manager_.lock();
if (dom_manager) {
dom_manager->RecordDomEndTimePoint();
dom_manager->RecordDomEndTimePoint(this->GetId());
}
render_manager->EndBatch(GetWeakSelf());
TDF_PERF_LOG("RootNode::SyncWithRenderManager End");
Expand Down
8 changes: 4 additions & 4 deletions dom/src/dom/scene_builder.cc
Original file line number Diff line number Diff line change
Expand Up @@ -19,9 +19,8 @@
*/

#include "dom/scene_builder.h"

#include "dom/dom_listener.h"

#include "dom/root_node.h"
#include "footstone/logging.h"
#include "footstone/string_view_utils.h"

Expand All @@ -33,8 +32,9 @@ void SceneBuilder::Create(const std::weak_ptr<DomManager>& weak_dom_manager,
std::vector<std::shared_ptr<DomInfo>>&& nodes,
bool needSortByIndex) {
auto dom_manager = weak_dom_manager.lock();
if (dom_manager) {
dom_manager->RecordDomStartTimePoint();
auto rootNode = root_node.lock();
if (dom_manager && rootNode) {
dom_manager->RecordDomStartTimePoint(rootNode->GetId());
dom_manager->CreateDomNodes(root_node, std::move(nodes), needSortByIndex);
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -87,7 +87,7 @@ void SetDomManager(JNIEnv* j_env,

void OnNativeInitEnd(JNIEnv* j_env, jobject j_object, jint j_scope_id, jlong startTime, jlong endTime);

void OnFirstPaintEnd(JNIEnv* j_env, jobject j_object, jint j_scope_id, jlong time);
void OnFirstPaintEnd(JNIEnv* j_env, jobject j_object, jint j_scope_id, jlong time, jint j_root_id);

void OnFirstContentfulPaintEnd(JNIEnv* j_env, jobject j_object, jint j_scope_id, jlong time);

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -112,7 +112,7 @@ REGISTER_JNI("com/openhippy/connector/JsDriver", // NOLINT(cert-err58-cpp)

REGISTER_JNI("com/openhippy/connector/JsDriver", // NOLINT(cert-err58-cpp)
"onFirstPaintEnd",
"(IJ)V",
"(IJI)V",
OnFirstPaintEnd)

REGISTER_JNI("com/openhippy/connector/JsDriver", // NOLINT(cert-err58-cpp)
Expand Down Expand Up @@ -192,7 +192,7 @@ void OnNativeInitEnd(JNIEnv* j_env, jobject j_object, jint j_scope_id, jlong sta
}
}

void OnFirstPaintEnd(JNIEnv* j_env, jobject j_object, jint j_scope_id, jlong time) {
void OnFirstPaintEnd(JNIEnv* j_env, jobject j_object, jint j_scope_id, jlong time, jint j_root_id) {
auto scope = GetScope(j_scope_id);
if (!scope) {
return;
Expand All @@ -204,7 +204,7 @@ void OnFirstPaintEnd(JNIEnv* j_env, jobject j_object, jint j_scope_id, jlong tim
auto runner = engine->GetJsTaskRunner();
if (runner) {
std::weak_ptr<Scope> weak_scope = scope;
auto task = [weak_scope, time]() {
auto task = [weak_scope, time, j_root_id]() {
auto scope = weak_scope.lock();
if (!scope) {
return;
Expand All @@ -214,10 +214,10 @@ void OnFirstPaintEnd(JNIEnv* j_env, jobject j_object, jint j_scope_id, jlong tim
return;
}
auto entry = scope->GetPerformance()->PerformanceNavigation("hippyInit");
entry->SetHippyRunApplicationEnd(dom_manager->GetDomStartTimePoint());
entry->SetHippyDomStart(dom_manager->GetDomStartTimePoint());
entry->SetHippyDomEnd(dom_manager->GetDomEndTimePoint());
entry->SetHippyFirstFrameStart(dom_manager->GetDomEndTimePoint());
entry->SetHippyRunApplicationEnd(dom_manager->GetDomStartTimePoint(j_root_id));
entry->SetHippyDomStart(dom_manager->GetDomStartTimePoint(j_root_id));
entry->SetHippyDomEnd(dom_manager->GetDomEndTimePoint(j_root_id));
entry->SetHippyFirstFrameStart(dom_manager->GetDomEndTimePoint(j_root_id));
entry->SetHippyFirstFrameEnd(footstone::TimePoint::FromEpochDelta(footstone::TimeDelta::FromMilliseconds(time)));
};
runner->PostTask(std::move(task));
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -73,8 +73,8 @@ public void recordNativeInitEndTime(long startTime, long endTime) {
onNativeInitEnd(mInstanceId, startTime, endTime);
}

public void recordFirstPaintEndTime(long time) {
onFirstPaintEnd(mInstanceId, time);
public void recordFirstPaintEndTime(long time, int rootId) {
onFirstPaintEnd(mInstanceId, time, rootId);
}

public void recordFirstContentfulPaintEndTime(long time) {
Expand Down Expand Up @@ -170,7 +170,7 @@ private native void callFunction(int instanceId, String action, NativeCallback c

private native void onNativeInitEnd(int instanceId, long startTime, long endTime);

private native void onFirstPaintEnd(int instanceId, long time);
private native void onFirstPaintEnd(int instanceId, long time, int rootId);

private native void onFirstContentfulPaintEnd(int instanceId, long time);

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -234,8 +234,8 @@ protected void onDestroyEngine() {
}

@Override
public void onFirstPaint() {
mEngineContext.getJsDriver().recordFirstPaintEndTime(System.currentTimeMillis());
public void onFirstPaint(int rootId) {
mEngineContext.getJsDriver().recordFirstPaintEndTime(System.currentTimeMillis(), rootId));
mEngineContext.getMonitor().addPoint(TimeMonitor.MONITOR_GROUP_PAINT,
TimeMonitor.MONITOR_POINT_FIRST_CONTENTFUL_PAINT);
mGlobalConfigs.getEngineMonitorAdapter().onFirstPaintCompleted(mEngineContext.getComponentName());
Expand Down
9 changes: 8 additions & 1 deletion framework/ios/base/bridge/HippyBridge+PerformanceAPI.h
Original file line number Diff line number Diff line change
Expand Up @@ -29,11 +29,18 @@ NS_ASSUME_NONNULL_BEGIN
@interface HippyBridge (PerformanceAPI)

/// Update perf records of FP, DOM_START/DOM_END etc.
- (void)updatePerfRecordsOnRootContentDidAppear;
/// - Parameter rootTag: Tag of rootView
- (void)updatePerfRecordsOnRootContentDidAppear:(NSNumber *)rootTag;

/// Update FCP perf record.
- (void)updatePerfRecordOnFirstContentfulPaintEnd;

/// Get all perf data
- (NSDictionary *)getHippyInitPerformanceData;

/// Get fcp perf data
- (nullable NSDictionary *)getFCPPerformanceData;

@end

NS_ASSUME_NONNULL_END
80 changes: 71 additions & 9 deletions framework/ios/base/bridge/HippyBridge+PerformanceAPI.mm
Original file line number Diff line number Diff line change
Expand Up @@ -24,10 +24,13 @@
#import "HippyJSExecutor+Internal.h"
#import "HippyLog.h"
#import "driver/scope.h"
#import "footstone/string_view_utils.h"

using namespace footstone;

@implementation HippyBridge (PerformanceAPI)

- (void)updatePerfRecordsOnRootContentDidAppear {
- (void)updatePerfRecordsOnRootContentDidAppear:(NSNumber *)rootTag {
std::shared_ptr<hippy::Scope> scope = self.javaScriptExecutor.pScope;
if (!scope) {
return;
Expand All @@ -39,18 +42,19 @@ - (void)updatePerfRecordsOnRootContentDidAppear {
if (!entry) {
return;
}
entry->SetHippyRunApplicationEnd(domManager->GetDomStartTimePoint());
entry->SetHippyDomStart(domManager->GetDomStartTimePoint());
entry->SetHippyDomEnd(domManager->GetDomEndTimePoint());
entry->SetHippyFirstFrameStart(domManager->GetDomEndTimePoint());
uint32_t rootId = rootTag.unsignedIntValue;
entry->SetHippyRunApplicationEnd(domManager->GetDomStartTimePoint(rootId));
entry->SetHippyDomStart(domManager->GetDomStartTimePoint(rootId));
entry->SetHippyDomEnd(domManager->GetDomEndTimePoint(rootId));
entry->SetHippyFirstFrameStart(domManager->GetDomEndTimePoint(rootId));
entry->SetHippyFirstFrameEnd(footstone::TimePoint::SystemNow());

#if HIPPY_DEBUG
int64_t totalFPTime = (entry->GetHippyFirstFrameEnd() - entry->GetHippyNativeInitStart()).ToMilliseconds();
auto nativeInit = (entry->GetHippyNativeInitEnd() - entry->GetHippyNativeInitStart()).ToMilliseconds();
auto runApplication = (entry->GetHippyRunApplicationEnd() - entry->GetHippyRunApplicationStart()).ToMilliseconds();
auto domCreate = (entry->GetHippyDomEnd() - entry->GetHippyDomStart()).ToMilliseconds();
auto firstFrame = (entry->GetHippyFirstFrameEnd() - entry->GetHippyFirstFrameStart()).ToMilliseconds();
int64_t nativeInit = (entry->GetHippyNativeInitEnd() - entry->GetHippyNativeInitStart()).ToMilliseconds();
int64_t runApplication = (entry->GetHippyRunApplicationEnd() - entry->GetHippyRunApplicationStart()).ToMilliseconds();
int64_t domCreate = (entry->GetHippyDomEnd() - entry->GetHippyDomStart()).ToMilliseconds();
int64_t firstFrame = (entry->GetHippyFirstFrameEnd() - entry->GetHippyFirstFrameStart()).ToMilliseconds();
HippyLogTrace(@"Hippy FP=%lld, detail: %lld, %lld, %lld, %lld", totalFPTime, nativeInit, runApplication, domCreate, firstFrame);
#endif /* HIPPY_DEBUG */
}
Expand All @@ -72,4 +76,62 @@ - (void)updatePerfRecordOnFirstContentfulPaintEnd {
}
}

- (NSDictionary *)getHippyInitPerformanceData {
std::shared_ptr<hippy::Scope> scope = self.javaScriptExecutor.pScope;
if (!scope) {
return @{};
}
auto domManager = scope->GetDomManager().lock();
auto performance = scope->GetPerformance();
if (domManager && performance) {
auto entry = performance->PerformanceNavigation(hippy::kPerfNavigationHippyInit);
if (!entry) {
return @{};
}

NSMutableDictionary *dic = [NSMutableDictionary dictionary];
int64_t totalFPTime = (entry->GetHippyFirstFrameEnd() - entry->GetHippyNativeInitStart()).ToMilliseconds();
int64_t nativeInit = (entry->GetHippyNativeInitEnd() - entry->GetHippyNativeInitStart()).ToMilliseconds();
int64_t jsEngineInit = (entry->GetHippyJsEngineInitEnd() - entry->GetHippyJsEngineInitStart()).ToMilliseconds();
int64_t runApplication = (entry->GetHippyRunApplicationEnd() - entry->GetHippyRunApplicationStart()).ToMilliseconds();
int64_t domCreate = (entry->GetHippyDomEnd() - entry->GetHippyDomStart()).ToMilliseconds();
int64_t firstFrame = (entry->GetHippyFirstFrameEnd() - entry->GetHippyFirstFrameStart()).ToMilliseconds();
dic[@"0.FP"] = @(totalFPTime);
dic[@"1.NativeInit"] = @(nativeInit);
dic[@"2.JsEngineInit"] = @(jsEngineInit);
dic[@"3.RunApplication"] = @(runApplication);
dic[@"4.DomCreate"] = @(domCreate);
dic[@"5.FirstFrame"] = @(firstFrame);

auto bundle_info_array = entry->GetBundleInfoArray();
for (size_t i = 0; i < bundle_info_array.size(); ++i) {
auto& info = bundle_info_array[i];
auto url = StringViewUtils::ToStdString(StringViewUtils::ConvertEncoding(info.url_, string_view::Encoding::Utf8).utf8_value());
NSString *urlStr = [NSString stringWithCString:url.c_str() encoding:[NSString defaultCStringEncoding]];
int64_t exeTime = (info.execute_source_end_ - info.execute_source_start_).ToMilliseconds();
[dic setObject:@(exeTime) forKey:urlStr.lastPathComponent];
}
return dic;
}
return @{};
}

- (NSDictionary *)getFCPPerformanceData {
std::shared_ptr<hippy::Scope> scope = self.javaScriptExecutor.pScope;
if (!scope) {
return nil;
}
auto domManager = scope->GetDomManager().lock();
auto performance = scope->GetPerformance();
if (domManager && performance) {
auto entry = performance->PerformanceNavigation(hippy::kPerfNavigationHippyInit);
if (!entry) {
return nil;
}
int64_t fcpTime = (entry->GetHippyFirstContentfulPaintEnd() - entry->GetHippyNativeInitStart()).ToMilliseconds();
return @{ @"FCP" : @(fcpTime) };
}
return nil;
}

@end
Original file line number Diff line number Diff line change
Expand Up @@ -63,7 +63,7 @@ public void onViewAdded(View child) {
firstViewAdded = true;
NativeRender nativeRenderer = NativeRendererManager.getNativeRenderer(getContext());
if (nativeRenderer != null) {
nativeRenderer.onFirstPaint();
nativeRenderer.onFirstPaint(getId());
}
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -53,7 +53,7 @@ public interface FrameworkProxy {

int getEngineId();

void onFirstPaint();
void onFirstPaint(int rootId);

void onFirstContentfulPaint();

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -97,7 +97,7 @@ public interface NativeRender extends RenderExceptionHandler, RenderLogHandler {
VirtualNode createVirtualNode(int rootId, int id, int pid, int index, @NonNull String className,
@Nullable Map<String, Object> props);

void onFirstPaint();
void onFirstPaint(int rootId);

void onFirstContentfulPaint();

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -373,10 +373,10 @@ public View getRootView(@NonNull View view) {
}

@Override
public void onFirstPaint() {
public void onFirstPaint(int rootId) {
FrameworkProxy frameworkProxy = getFrameworkProxy();
if (frameworkProxy != null) {
frameworkProxy.onFirstPaint();
frameworkProxy.onFirstPaint(rootId);
}
}

Expand Down
2 changes: 1 addition & 1 deletion renderer/native/ios/renderer/HippyRootView.mm
Original file line number Diff line number Diff line change
Expand Up @@ -424,7 +424,7 @@ - (void)insertHippySubview:(UIView *)subview atIndex:(NSInteger)atIndex {
if (strongSelf && !strongSelf->_contentHasAppeared) {
strongSelf->_contentHasAppeared = YES;
static NSString *const kHippyContentAppearCostKey = @"cost";
[[(HippyRootView *)strongSelf.superview bridge] updatePerfRecordsOnRootContentDidAppear];
[[(HippyRootView *)strongSelf.superview bridge] updatePerfRecordsOnRootContentDidAppear:self.hippyTag];
[[NSNotificationCenter defaultCenter] postNotificationName:HippyContentDidAppearNotification
object:self.superview userInfo:@{
kHippyContentAppearCostKey : @(CACurrentMediaTime() * 1000 - strongSelf.startTimpStamp)
Expand Down
Loading