Skip to content

Commit

Permalink
feat(perf): add logs to pinpoint performance issues
Browse files Browse the repository at this point in the history
  • Loading branch information
@ruifanyuan @hippy-actions
ruifanyuan authored and hippy-actions[bot] committed Oct 17, 2023
1 parent 0658dc3 commit ed206ed
Show file tree
Hide file tree
Showing 8 changed files with 126 additions and 7 deletions.
13 changes: 13 additions & 0 deletions dom/src/dom/root_node.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -67,9 +67,12 @@ void RootNode::RemoveEventListener(const std::string& name, uint64_t listener_id
void RootNode::ReleaseResources() {}

void RootNode::CreateDomNodes(std::vector<std::shared_ptr<DomInfo>>&& nodes) {
HP_PERF_LOG("CreateDomNodes Begin");

for (const auto& interceptor : interceptors_) {
interceptor->OnDomNodeCreate(nodes);
}
HP_PERF_LOG("CreateDomNodes Interceptor callback done");
std::vector<std::shared_ptr<DomNode>> nodes_to_create;
for (const auto& node_info : nodes) {
auto& node = node_info->dom_node;
Expand All @@ -85,6 +88,7 @@ void RootNode::CreateDomNodes(std::vector<std::shared_ptr<DomInfo>>&& nodes) {
node->HandleEvent(event);
OnDomNodeCreated(node);
}
HP_PERF_LOG("CreateDomNodes Nodes created and finished callback");
for (const auto& node : nodes_to_create) {
node->SetRenderInfo({node->GetId(), node->GetPid(), node->GetSelfIndex()});
}
Expand All @@ -94,6 +98,7 @@ void RootNode::CreateDomNodes(std::vector<std::shared_ptr<DomInfo>>&& nodes) {
if (!nodes_to_create.empty()) {
dom_operations_.push_back({DomOperation::Op::kOpCreate, nodes_to_create});
}
HP_PERF_LOG("CreateDomNodes End");
}

void RootNode::UpdateDomNodes(std::vector<std::shared_ptr<DomInfo>>&& nodes) {
Expand Down Expand Up @@ -272,14 +277,21 @@ void RootNode::CallFunction(uint32_t id, const std::string& name, const DomArgum
}

void RootNode::SyncWithRenderManager(const std::shared_ptr<RenderManager>& render_manager) {
HP_PERF_LOG("RootNode::SyncWithRenderManager");
unsigned long cnt = dom_operations_.size();
FlushDomOperations(render_manager);
HP_PERF_LOG("RootNode::FlushDomOperations Done, dom op count:%lld", cnt);
cnt = event_operations_.size();
FlushEventOperations(render_manager);
HP_PERF_LOG("RootNode::FlushEventOperations Done, event op count:%d",cnt);
DoAndFlushLayout(render_manager);
HP_PERF_LOG("RootNode::DoAndFlushLayout Done");
auto dom_manager = dom_manager_.lock();
if (dom_manager) {
dom_manager->RecordDomEndTimePoint();
}
render_manager->EndBatch(GetWeakSelf());
HP_PERF_LOG("RootNode::SyncWithRenderManager End");
}

void RootNode::AddEvent(uint32_t id, const std::string& event_name) {
Expand Down Expand Up @@ -422,6 +434,7 @@ void RootNode::DoAndFlushLayout(const std::shared_ptr<RenderManager>& render_man

void RootNode::FlushDomOperations(const std::shared_ptr<RenderManager>& render_manager) {
for (auto& dom_operation : dom_operations_) {
HP_PERF_LOG("RootNode::FlushDomOperations dom_operation.op cnt:%lld", dom_operation.nodes.size());
MarkLayoutNodeDirty(dom_operation.nodes);
switch (dom_operation.op) {
case DomOperation::Op::kOpCreate:
Expand Down
33 changes: 32 additions & 1 deletion driver/js/src/modules/scene_builder_module.cc
View file
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
/*
/*
*
* Tencent is pleased to support the open source community by making
* Hippy available.
Expand Down Expand Up @@ -27,6 +27,7 @@
#include "driver/modules/scene_builder_module.h"
#include "driver/modules/ui_manager_module.h"
#include "driver/scope.h"
#include "footstone/logging.h"
#include "footstone/string_view.h"
#include "footstone/string_view_utils.h"

Expand Down Expand Up @@ -419,12 +420,15 @@ std::shared_ptr<ClassTemplate<SceneBuilder>> RegisterSceneBuilder(const std::wea
size_t argument_count,
const std::shared_ptr<CtxValue> arguments[],
std::shared_ptr<CtxValue>&) -> std::shared_ptr<CtxValue> {
HP_PERF_LOG("SceneBuilder.create()");
auto scope = weak_scope.lock();
if (!scope) {
HP_PERF_LOG("SceneBuilder.create() exit with error");
return nullptr;
}
auto ret = HandleJsValue(scope->GetContext(), arguments[0], scope);
SceneBuilder::Create(scope->GetDomManager(), scope->GetRootNode(), std::move(std::get<2>(ret)));
HP_PERF_LOG("SceneBuilder.create() End");
return nullptr;
};
class_template.functions.emplace_back(std::move(create_func_def));
Expand All @@ -436,12 +440,16 @@ std::shared_ptr<ClassTemplate<SceneBuilder>> RegisterSceneBuilder(const std::wea
size_t argument_count,
const std::shared_ptr<CtxValue> arguments[],
std::shared_ptr<CtxValue>&) -> std::shared_ptr<CtxValue> {
HP_PERF_LOG("SceneBuilder.update()");
auto scope = weak_scope.lock();
if (!scope) {
HP_PERF_LOG("SceneBuilder.update() exit with error");
return nullptr;
}
auto ret = HandleJsValue(scope->GetContext(), arguments[0], scope);
SceneBuilder::Update(scope->GetDomManager(), scope->GetRootNode(), std::move(std::get<2>(ret)));
HP_PERF_LOG("SceneBuilder.update() End");

return nullptr;
};
class_template.functions.emplace_back(std::move(update_func_def));
Expand All @@ -452,8 +460,11 @@ std::shared_ptr<ClassTemplate<SceneBuilder>> RegisterSceneBuilder(const std::wea
const std::shared_ptr<CtxValue> arguments[],
std::shared_ptr<CtxValue>&)
-> std::shared_ptr<CtxValue> {
HP_PERF_LOG("SceneBuilder.move()");

auto scope = weak_scope.lock();
if (!scope) {
HP_PERF_LOG("SceneBuilder.move() exit with error");
return nullptr;
}
auto weak_dom_manager = scope->GetDomManager();
Expand All @@ -469,11 +480,13 @@ std::shared_ptr<ClassTemplate<SceneBuilder>> RegisterSceneBuilder(const std::wea
auto node = context->CopyArrayElement(info, 0);
auto id_tuple = GetNodeId(context, node);
if (!std::get<0>(id_tuple)) {
HP_PERF_LOG("SceneBuilder.move() exit with error");
return nullptr;
}

auto pid_tuple = GetNodePid(context, node);
if (!std::get<0>(pid_tuple)) {
HP_PERF_LOG("SceneBuilder.move() exit with error");
return nullptr;
}
if (length >= 2) {
Expand All @@ -489,6 +502,7 @@ std::shared_ptr<ClassTemplate<SceneBuilder>> RegisterSceneBuilder(const std::wea
}
}
SceneBuilder::Move(weak_dom_manager, scope->GetRootNode(), std::move(dom_infos));
HP_PERF_LOG("SceneBuilder.move() End");
return nullptr;
};
class_template.functions.emplace_back(std::move(move_func_def));
Expand All @@ -500,8 +514,11 @@ std::shared_ptr<ClassTemplate<SceneBuilder>> RegisterSceneBuilder(const std::wea
size_t argument_count,
const std::shared_ptr<CtxValue> arguments[],
std::shared_ptr<CtxValue>&) -> std::shared_ptr<CtxValue> {
HP_PERF_LOG("SceneBuilder.delete()");

auto scope = weak_scope.lock();
if (!scope) {
HP_PERF_LOG("SceneBuilder.delete() exit with error");
return nullptr;
}
auto nodes = arguments[0];
Expand All @@ -521,6 +538,8 @@ std::shared_ptr<ClassTemplate<SceneBuilder>> RegisterSceneBuilder(const std::wea

auto pid_tuple = GetNodePid(context, node);
if (!std::get<0>(pid_tuple)) {
HP_PERF_LOG("SceneBuilder.delete() exit with error");

return nullptr;
}
dom_infos.push_back(std::make_shared<DomInfo>(
Expand All @@ -532,6 +551,8 @@ std::shared_ptr<ClassTemplate<SceneBuilder>> RegisterSceneBuilder(const std::wea
}
}
SceneBuilder::Delete(scope->GetDomManager(), scope->GetRootNode(), std::move(dom_infos));
HP_PERF_LOG("SceneBuilder.delete() End");

return nullptr;
};
class_template.functions.emplace_back(std::move(delete_func_def));
Expand All @@ -543,14 +564,17 @@ std::shared_ptr<ClassTemplate<SceneBuilder>> RegisterSceneBuilder(const std::wea
size_t argument_count,
const std::shared_ptr<CtxValue> arguments[],
std::shared_ptr<CtxValue>&) -> std::shared_ptr<CtxValue> {
HP_PERF_LOG("SceneBuilder.addEventListener()");
auto scope = weak_scope.lock();
if (!scope) {
HP_PERF_LOG("SceneBuilder.addEventListener() exit with error");
return nullptr;
}
Scope::EventListenerInfo listener_info;
HandleEventListenerInfo(scope->GetContext(), argument_count, arguments, listener_info);
auto dom_listener_info = scope->AddListener(listener_info);
SceneBuilder::AddEventListener(scope->GetDomManager(), scope->GetRootNode(), dom_listener_info);
HP_PERF_LOG("SceneBuilder.addEventListener() End");
return nullptr;
};
class_template.functions.emplace_back(std::move(add_event_listener_def));
Expand All @@ -562,14 +586,18 @@ std::shared_ptr<ClassTemplate<SceneBuilder>> RegisterSceneBuilder(const std::wea
size_t argument_count,
const std::shared_ptr<CtxValue> arguments[],
std::shared_ptr<CtxValue>&) -> std::shared_ptr<CtxValue> {
HP_PERF_LOG("SceneBuilder.removeEventListener()");

auto scope = weak_scope.lock();
if (!scope) {
HP_PERF_LOG("SceneBuilder.removeEventListener() exit with error");
return nullptr;
}
Scope::EventListenerInfo listener_info;
HandleEventListenerInfo(scope->GetContext(), argument_count, arguments, listener_info);
auto dom_listener_info = scope->RemoveListener(listener_info);
SceneBuilder::RemoveEventListener(scope->GetDomManager(), scope->GetRootNode(), dom_listener_info);
HP_PERF_LOG("SceneBuilder.removeEventListener() End");
return nullptr;
};
class_template.functions.emplace_back(std::move(remove_event_listener_def));
Expand All @@ -582,11 +610,14 @@ std::shared_ptr<ClassTemplate<SceneBuilder>> RegisterSceneBuilder(const std::wea
size_t argument_count,
const std::shared_ptr<CtxValue> arguments[],
std::shared_ptr<CtxValue>&) -> std::shared_ptr<CtxValue> {
HP_PERF_LOG("SceneBuilder.build()");
auto scope = weak_scope.lock();
if (!scope) {
HP_PERF_LOG("SceneBuilder.build() exit with error");
return nullptr;
}
SceneBuilder::Build(scope->GetDomManager(), scope->GetRootNode());
HP_PERF_LOG("SceneBuilder.build() End");
return nullptr;
};
class_template.functions.emplace_back(std::move(build_func_def));
Expand Down
19 changes: 16 additions & 3 deletions driver/js/src/napi/jsc/jsc_ctx.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,7 @@
#include "driver/vm/native_source_code.h"
#include "driver/vm/jsc/jsc_vm.h"


namespace hippy {
inline namespace driver {
inline namespace napi {
Expand Down Expand Up @@ -665,8 +666,8 @@ bool JSCCtx::IsObject(const std::shared_ptr<CtxValue>& value) {
}

string_view JSCCtx::CopyFunctionName(const std::shared_ptr<CtxValue>& function) {
FOOTSTONE_UNIMPLEMENTED();
return "";
FOOTSTONE_UNIMPLEMENTED();
return "";
}

bool JSCCtx::GetEntriesFromObject(const std::shared_ptr<CtxValue>& value,
Expand Down Expand Up @@ -892,25 +893,31 @@ std::shared_ptr<CtxValue> JSCCtx::CallFunction(const std::shared_ptr<CtxValue>&
const std::shared_ptr<CtxValue> argv[]) {
auto function_value = std::static_pointer_cast<JSCCtxValue>(function);
JSValueRef exception = nullptr;
HP_PERF_LOG("JSCCtx::CallFunction");
auto function_object = JSValueToObject(context_, function_value->value_, &exception);
if (exception) {
SetException(std::make_shared<JSCCtxValue>(context_, exception));
HP_PERF_LOG("JSCCtx::CallFunction End with exception");

return nullptr;
}

auto receiver_value = std::static_pointer_cast<JSCCtxValue>(receiver);
auto receiver_object = JSValueToObject(context_, receiver_value->value_, &exception);
if (exception) {
SetException(std::make_shared<JSCCtxValue>(context_, exception));
HP_PERF_LOG("JSCCtx::CallFunction End with exception");
return nullptr;
}

if (argc <= 0) {
auto ret_value_ref = JSObjectCallAsFunction(context_, function_object, receiver_object, 0, nullptr, &exception);
if (exception) {
SetException(std::make_shared<JSCCtxValue>(context_, exception));
HP_PERF_LOG("JSCCtx::CallFunction End with exception");
return nullptr;
}
HP_PERF_LOG("JSCCtx::CallFunction End with exception");
return std::make_shared<JSCCtxValue>(context_, ret_value_ref);
}

Expand All @@ -923,12 +930,15 @@ std::shared_ptr<CtxValue> JSCCtx::CallFunction(const std::shared_ptr<CtxValue>&
auto ret_value_ref = JSObjectCallAsFunction(context_, function_object, receiver_object, argc, values, &exception);
if (exception) {
SetException(std::make_shared<JSCCtxValue>(context_, exception));
HP_PERF_LOG("JSCCtx::CallFunction End with exception");
return nullptr;
}

if (!ret_value_ref) {
HP_PERF_LOG("JSCCtx::CallFunction End with exception");
return nullptr;
}
HP_PERF_LOG("JSCCtx::CallFunction End with exception");

return std::make_shared<JSCCtxValue>(context_, ret_value_ref);
}
Expand Down Expand Up @@ -1124,6 +1134,7 @@ std::shared_ptr<CtxValue> JSCCtx::RunScript(const string_view& data,
if (StringViewUtils::IsEmpty(data)) {
return nullptr;
}
HP_PERF_LOG("JSCCtx::RunScript");

JSStringRef js = JSCVM::CreateJSCString(data);
JSValueRef exception = nullptr;
Expand All @@ -1139,13 +1150,15 @@ std::shared_ptr<CtxValue> JSCCtx::RunScript(const string_view& data,

if (exception) {
SetException(std::make_shared<JSCCtxValue>(context_, exception));
HP_PERF_LOG("JSCCtx::RunScript Error");
return nullptr;
}

if (!value) {
HP_PERF_LOG("JSCCtx::RunScript Error");
return nullptr;
}

HP_PERF_LOG("JSCCtx::RunScript End");
return std::make_shared<JSCCtxValue>(context_, value);
}

Expand Down
42 changes: 41 additions & 1 deletion modules/footstone/include/footstone/logging.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,8 @@

#pragma once

#if defined(__cplusplus)

#include <cassert>
#include <codecvt>
#include <mutex>
Expand Down Expand Up @@ -105,7 +107,29 @@ class LogMessage {
}
delegate_ = delegate;
}

inline static void LogWithFormat(const char * file, int line, const char *format, ...){
char *log_msg = NULL;
va_list args;
va_start(args, format);
int ret = vasprintf(&log_msg, format, args);
va_end(args);

if (ret <= 0 && log_msg == NULL) {
return;
}

std::ostringstream s;
s<<"thread:"<<pthread_self()<<", "<<log_msg<<std::endl;

if (LogMessage::delegate_) {
delegate_(s, TDF_LOG_WARNING);
} else {
default_delegate_(s, TDF_LOG_WARNING);
}

free(log_msg);
}

std::ostringstream& stream() { return stream_; }

private:
Expand Down Expand Up @@ -186,3 +210,19 @@ bool ShouldCreateLogMessage(LogSeverity severity);
do { \
(void)(expr); \
} while (0)

#endif

inline void HPDoPerfLog( const char* file, int line, const char *format, ...){
va_list args;
va_start(args, format);
footstone::LogMessage::LogWithFormat(file, line, format, args);
va_end(args);
}

void HPDoPerfLog( const char *, int, const char *format, ...);
#define HP_PERF_LOG(format, ...) \
HPDoPerfLog(__FILE_NAME__, __LINE__, "[HP PERF]" \
" " format, \
##__VA_ARGS__)

2 changes: 2 additions & 0 deletions modules/footstone/src/platform/ios/logging.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -90,6 +90,8 @@ LogMessage::~LogMessage() {
}
}



int GetVlogVerbosity() { return std::max(-1, LOG_INFO - GetMinLogLevel()); }

bool ShouldCreateLogMessage(LogSeverity severity) { return severity >= GetMinLogLevel(); }
Expand Down
2 changes: 2 additions & 0 deletions modules/ios/base/HPLog.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@
* See the License for the specific language governing permissions and
* limitations under the License.
*/
# if defined(__OBJC__)

#import <Foundation/Foundation.h>

Expand Down Expand Up @@ -134,3 +135,4 @@ HP_EXTERN void HPPerformBlockWithLogPrefix(void (^block)(void), NSString *prefix

HP_EXTERN void HPLogNativeInternal(HPLogLevel, const char *, int, NSDictionary *, NSString *, ...) NS_FORMAT_FUNCTION(5, 6);

#endif // defined(__OBJC__)
Loading

0 comments on commit ed206ed

Please sign in to comment.