Ark运行时日志不打印问题分析报告

鸿蒙使小强 2023-03-13 17:39:41

1 关键字

ark; LOG_ECMA; 日志;

2 问题描述

开发板型号:rk3568

OH版本:OpenHarmony 3.1 Release

问题现象:hilog中搜不到 LOG_ECMA 的输出(ark/runtime_core/libpandabase/utils/logger.h)日志

测试步骤:

  1. 烧镜像
  2. 终端输入hilog | grep Ark
  3. eco跑一个demo

日志输出空

3 问题原因

3.1 正常机制

日志中出现如下格式的日志 ,有 Ark 函数名 行号

03900/Ace: [jsi_declarative_engine.cpp(PrintLog)-(0)] Ark ecmascript::GenerateProgram Line:77 GenerateProgram /data/storage/el1/bundle/com.example.entry/assets/js/MainAbility/app.abc

3.2 异常机制

Ark 关键字的日志为空

4 解决方案

通过下面方式可以看到ark的日志输出

方法一:

修改ark\runtime_core\libpandabase\utils\logger.h文件的WriteMobileLog方法,将is_mlog_opened_的判断去掉,is_mlog_opened_此时的值是false,在判断里面会直接return,不会执行后面的打印日志流程。

if (mlog_buf_print == nullptr || !is_mlog_opened_) {
    return;
}

改为

if (mlog_buf_print == nullptr) {
    return;
}

方法二:

注释源码里面所有的Logger::SetMobileLogOpenFlag(false);

按照上面的方法可以在全量日志里看到ark相关的日志

img

img

5 定位过程

  1. 根据LOG_ECMA查找LOG_ECMA的定义
    定义地方ark\js_runtime\ecmascript\ecma_macros.h
#define LOG_ECMA(type) \
LOG(type, ECMASCRIPT) << __func__ << " Line:" << __LINE__ << " "  // NOLINT(bugprone-lambda-function-name)

可以得出日志是以 方法名 Line:行号的 的形式输出。

  1. 再跟LOG到ark\runtime_core\libpandabase\utils\logger.h 文件中
    最后调用的是
#define _LOG(level, component, p)
panda::Logger::IsLoggingOnOrAbort(panda::Logger::Level::level, panda::Logger::Component::component) && panda::Logger::Message(panda::Logger::Level::level, panda::Logger::Component::component, p).GetStream()
  1. 跟踪上步中的Message对象
class Message {
    public:
        Message(Level level, Component component, bool print_system_error): 
        level_(level), 
        component_(component),print_system_error_(print_system_error)
    {
    }

    ~Message();

    std::ostream &GetStream()
    {
        return stream_;
    }

    private:
        Level level_;
        Component component_;
        bool print_system_error_;
        std::ostringstream stream_;

        NO_COPY_SEMANTIC(Message);
        NO_MOVE_SEMANTIC(Message);
};
Logger::Message::~Message()
{
    if (print_system_error_) {
        stream_ << ": " << os::Error(errno).ToString();
    }
   
    Logger::Log(level_, component_, stream_.str());
   
    if (level_ == Level::FATAL) {
        std::abort();
    }
}

在析构函数中看到了Logger::Log(level_, component_, stream_.str());

  1. 跟踪Logger::Log函数发现该函数中调用了WriteMobileLog方法。

  2. 跟踪WriteMobileLog方法

void WriteMobileLog(Level level, const char *component, const char *message)
    {
        if (mlog_buf_print == nullptr || !is_mlog_opened_) {
            return;
    }
    PandaLog2MobileLog mlog_level = PandaLog2MobileLog::UNKNOWN;
    switch (level) {
        case Level::DEBUG:
            mlog_level = PandaLog2MobileLog::DEBUG;
        break;
        case Level::INFO:
            mlog_level = PandaLog2MobileLog::INFO;
        break;
        case Level::ERROR:
            mlog_level = PandaLog2MobileLog::ERROR;
        break;
        case Level::FATAL:
            mlog_level = PandaLog2MobileLog::FATAL;
        break;
        case Level::WARNING:
            mlog_level = PandaLog2MobileLog::WARN;
        break;
        default:
        UNREACHABLE();
    }
    std::string panda_component = "Ark " + std::string(component);
    mlog_buf_print(LOG_ID_MAIN, mlog_level, panda_component.c_str(), "%s", message);
}
  • 有个判断条件 is_mlog_opened_ 日志控制开关
  • mlog_buf_print函数执行打印日志
  1. 跟踪mlog_buf_print赋值的地方
  • ark\runtime_core\libpandabase\utils\logger.hSetMobileLogPrintEntryPointByPtr方法
  static void SetMobileLogPrintEntryPointByPtr(void *mlog_buf_print_ptr)
      {
          mlog_buf_print = reinterpret_cast<FUNC_MOBILE_LOG_PRINT>(mlog_buf_print_ptr);
      }
  • ark\js_runtime\ecmascript\napi\jsnapi.cpp中调用SetMobileLogPrintEntryPointByPtr方法的地方
bool JSNApi::CreateRuntime(const RuntimeOption &option)
{
    ...
  
    // Dfx
    base_options::Options baseOptions("");
    baseOptions.SetLogLevel(option.GetLogLevel());
    arg_list_t logComponents;
    logComponents.emplace_back("all");
    baseOptions.SetLogComponents(logComponents);
    Logger::Initialize(baseOptions);
    if (option.GetLogBufPrint() != nullptr) {
        Logger::SetMobileLogPrintEntryPointByPtr(reinterpret_cast<void *>(option.GetLogBufPrint()));
    }
    ...
  
    return true;
}
  • foundation\ace\ace_engine\frameworks\bridge\declarative_frontend\engine\jsi\ark\ark_js_runtime.cpp中调用SetLogBufPrint方法设置打印函数
bool ArkJSRuntime::Initialize(const std::string &libraryPath, bool isDebugMode)
{
    RuntimeOption option;
    option.SetGcType(RuntimeOption::GC_TYPE::GEN_GC);
    option.SetArkProperties(SystemProperties::GetArkProperties());
    const int64_t poolSize = 0x10000000;  // 256M
    option.SetGcPoolSize(poolSize);
    option.SetLogLevel(RuntimeOption::LOG_LEVEL::ERROR);
    option.SetLogBufPrint(print_);
    option.SetDebuggerLibraryPath(libraryPath);
    libPath_ = libraryPath;
    isDebugMode_ = isDebugMode;
  
    vm_ = JSNApi::CreateJSVM(option);
    return vm_ != nullptr;
}
  1. 设置的打印函数
//文件路径 
//foundation\ace\ace_engine\frameworks\bridge\declarative_frontend\engine\jsi\ark\ark_js_runtime.cpp
void ArkJSRuntime::SetLogPrint(LOG_PRINT out)
{
    print_ = out;
}
//文件路径 
//foundation\ace\ace_engine\frameworks\bridge\declarative_frontend\engine\jsi\jsi_declarative_engine.cpp
bool JsiDeclarativeEngineInstance::InitJsEnv(bool debuggerMode,
const std::unordered_map<std::string, void*>& extraNativeObject, const shared_ptr<JsRuntime>& runtime)
{
    ...
   
    runtime_->SetLogPrint(PrintLog);
   
    ...
}
   
int PrintLog(int id, int level, const char* tag, const char* fmt, const char* message)
{
    switch (JsLogLevel(level - 3)) {
        case JsLogLevel::INFO:
            LOGI("%{public}s::%{public}s", tag, message);
            break;
        case JsLogLevel::WARNING:
            LOGW("%{public}s::%{public}s", tag, message);
            break;
        case JsLogLevel::ERROR:
            LOGE("%{public}s::%{public}s", tag, message);
            break;
        case JsLogLevel::DEBUG:
            LOGD("%{public}s::%{public}s", tag, message);
            break;
        default:
            LOGF("%{public}s::%{public}s", tag, message);
            break;
    }
    return 0;
}

​ PrintLog中使用的打印方法是ACE子系统下的日志输出方式

  1. 以上逻辑分析完,日志打印流程正常,但Ark日志没有输出,返回第5步WriteMobileLog中去掉if判断条件中对is_mlog_opened_的判断,测试发现有Ark相应的日志输出。故is_mlog_opened_值被设置成了false。
    修改方法是可以直接去掉对is_mlog_opened_的判断,或者将is_mlog_opened_更改为false的地方注释调Logger::SetMobileLogOpenFlag(false);

6 知识分享

  • ACE子系统通过函数指针设置ark日志的打印方法调用ark日志的打印
...全文
1780 回复 打赏 收藏 转发到动态 举报
写回复
用AI写文章
回复
切换为时间正序
请发表友善的回复…
发表回复

506

社区成员

发帖
与我相关
我的任务
社区描述
OpenHarmony开发者社区
其他 企业社区
社区管理员
  • csdnsqst0025
  • shewaliujingli
  • BaoWei
加入社区
  • 近7日
  • 近30日
  • 至今

试试用AI创作助手写篇文章吧