Skip to content

Commit

Permalink
fix(android,ios): performance record inaccurate when engine reuse
Browse files Browse the repository at this point in the history
  • Loading branch information
wwwcg committed Oct 29, 2024
1 parent 6bea97a commit 950a782
Show file tree
Hide file tree
Showing 15 changed files with 116 additions and 47 deletions.
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

0 comments on commit 950a782

Please sign in to comment.