OpenHarmony开发者论坛

标题: 【SUBJECT技术】OpenHarmony Hilog系列之(二)使用宏、std::bind 巧妙实现进出函数日志打印 [打印本页]

作者: 诚迈_雨哥    时间: 2023-12-25 20:57
标题: 【SUBJECT技术】OpenHarmony Hilog系列之(二)使用宏、std::bind 巧妙实现进出函数日志打印
[md]# 背景

我们始终渴望了解模块的调用、时序逻辑,每个人都会轻易地想到在函数的入口打印一条进入 enter相关的日志,在函数的出口打印一条离开 leave 相关的日志。不能有遗漏,我们会复制这条日志到所有关心的函数中,为了表明是哪个模块,哪个类和哪个函数我们需要逐个将这些参数写入。
这样不可避免地出现第一个问题,每个函数至少添加两条日志,第二个问题当一个函数有多个出口(return),我们将要打印多条 leave用以区分。
如果碰到复杂模块,我们仍然简单地这样操作,工作量会让你崩溃,这根本不是一个开发者的追求。有什么简单易行、以逸待劳的好办法?

# 一、打印函数进出日志的原理

如何在函数的入口只打印一条日志,出口不用打印,却自动产生进入、离开两条日志?我们知道函数内部变量的生命周期遵循的是先进后出原则。进入函数首先就定义一个局部对象,在离开这个函数的时刻自动释放这个对象。如果这个对象是类对象,则在定义时会进入构造函数,离开时进入析构函数。于是在构造函数和析构函数分别打印进出日志,测试结果表明的确是这样。
如何区分来自哪个模块、哪个类、哪个函数?很简单,将模块的id、类名称Tag作为参数传入,函数名则用系统宏 `__FUNCTION__`即可。
经过一番操作,发现所有的进出函数日志名称、参数写的一模一样,低级重复不是一个开发者的追求,能不能不写参数。于是用一个宏去代替这条日志函数,参数仅写一次,最终效果达到预期......
如果能够管控不同级别的进出日志,就更加完美了。神奇的std::bind()函数就能实现原函数的二次封装,在重新包装原函数成新接口(新规范)能力方面,这个功能特别有用。下面将对原理提及的知识点逐步进行讲解。

# 二、实现函数进出打印功能

## 第一步,日志类在共用头文件里面实现

例如,sensors模块就在 utils\common 目录下的sensors_errors.h文件
.\base\sensors\miscdevice\utils\common\include\sensors_errors.h

## 第二步,实现一个简易的只包含构造和析构函数的类

里面会调用HiviewDFX日志模块HiLog:ebug()函数,包含 #include "hilog/log.h"

```
#include "hilog/log.h"
class InnerFunctionTracer {
public:
    InnerFunctionTracer(const OHOS::HiviewDFX::HiLogLabel &label, const char *func)
        : label_ { label }, func_ { func }
    {
        OHOS::HiviewDFX::HiLog:ebug(label_, "wyyxiu in %{public}s, enter_func", func_);
    }
    ~InnerFunctionTracer()
    {
        OHOS::HiviewDFX::HiLog:ebug(label_, "wyyxiu in %{public}s, leave_func", func_);
    }
private:
    const OHOS::HiviewDFX::HiLogLabel &label_;
    const char *func_ { nullptr };
};
```

## 第三步,InnerFunctionTracer的构造函数参数是通过下面定义对象时将参数传入的

#define CALL_LOG_ENTER   InnerFunctionTracer `___innerFuncTracer___` { LABEL, `__FUNCTION__` }
LABEL: 是通过宏CALL_LOG_ENTER替换时传入的
`__FUNCTION__`: 是通过宏CALL_LOG_ENTER替换时传入的

## 第四步,调用 CALL_LOG_ENTER 宏就会打印出这个函数进出日志

LABEL: 需要按照给定格式声明,最后一个字符串一般为该类名
`__FUNCTION__`: 是调用者的函数名称

```
// 首先,包含声明宏的头文件 sensors_errors.h;
#include "sensors_errors.h"

namespace Sensors {
using namespace OHOS::HiviewDFX;

namespace {
// 其次,声明 LABEL;
constexpr HiLogLabel LABEL = { LOG_CORE, MISC_LOG_DOMAIN, "MiscdeviceServiceStub" };
}  // namespace

// 最后,将 CALL_LOG_ENTER放置在需要打印进出日志的那个函数开头;
int32_t MiscdeviceServiceStub:layPatternStub(MessageParcel &data, MessageParcel &reply)
{
    CALL_LOG_ENTER;
    // ......
    return PlayPattern(pattern.value(), usage, parameter.value());
}
```

# 三、现在,看一个更加复杂一点的进出日志函数实现

## 参考示例的头文件如下

.\base\msdp\device_status\utils\common\include\fi_log.h,或者
.\foundation\multimodalinput\input\util\common\include\mmi_log.h

## 有两个显著不同点

1. 在构造和析构函数中可以打印任意级别的日志,它是将日志函数作为参数传入的,赋值给 logfn_
2. 通过日志系统函数HiLogIsLoggable(),过滤允许级别的日志

```
class InnerFunctionTracer {
public:
    using HilogFunc = std::function<int(const char *)>;

public:
    InnerFunctionTracer(HilogFunc logfn, const char* tag, LogLevel level)
        : logfn_ { logfn }, tag_ { tag }, level_ { level }
    {
        if (HiLogIsLoggable(OHOS::MMI::MMI_LOG_DOMAIN, tag_, level_)) {
            if (logfn_ != nullptr) {
                logfn_("wyyxiu in %{public}s, enter_func");
            }
        }
    }
    ~InnerFunctionTracer()
    {
        if (HiLogIsLoggable(OHOS::MMI::MMI_LOG_DOMAIN, tag_, level_)) {
            if (logfn_ != nullptr) {
                logfn_("wyyxiu in %{public}s, leave_func");
            }
        }
    }
private:
    HilogFunc logfn_ { nullptr };
    const char* tag_ { nullptr };
    LogLevel level_ { LOG_LEVEL_MIN };
};
```

## 奇妙的地方是采用了 std::bind()函数,将不同级别日志函数作为参数传入类中

需要过滤将日志级别LogLevel传入,关于 std::bind() 用法如后所述

```
#define CALL_DEBUG_ENTER        ::OHOS::MMI::InnerFunctionTracer ___innerFuncTracer_Debug___    \
    { std::bind(&::OHOS::HiviewDFX::HiLog:ebug, LABEL, std::placeholders::_1, __FUNCTION__), LABEL.tag, LOG_DEBUG }

#define CALL_INFO_TRACE         ::OHOS::MMI::InnerFunctionTracer ___innerFuncTracer_Info___     \
    { std::bind(&::OHOS::HiviewDFX::HiLog::Info, LABEL, std::placeholders::_1, __FUNCTION__), LABEL.tag, LOG_INFO }
```

## HiLogIsLoggable()函数的系统实现

* 只有系统使能了模块DEBUG 日志,这类 CALL_DEBUG_ENTER 才被打印输出。
* 以多模输入为例,需要在 hdc shell 窗口输入 `hilog -b I -D 0xD002800`,使能 DEBUG级别,0xD002800 代表 `OHOS::MMI::MMI_LOG_DOMAIN`。[hdc 的使用参照这个链接]()。
* 如果有编译环境,有一个省事的方法,将HiLog:ebug改为 HiLog::Info,LOG_DEBUG修改为LOG_INFO,该日志一般都会被打印出来,如 CALL_INFO_TRACE 所示。
* HiLogIsLoggable()函数的实现在这个文件: .\base\hiviewdfx\hilog\frameworks\libhilog\hilog_printf.cpp

.\base\hiviewdfx\hilog\frameworks\libhilog\hilog_printf.cpp

```
/**
* @brief Check whether log of a specified domain, tag and level can be printed.
*
* @param domain macroOG_DOMAIN
* @param tag macroOG_TAG
* @param level enumogLevel
*/
bool HiLogIsLoggable(unsigned int domain, const char *tag, LogLevel level)
{
    if ((level <= LOG_LEVEL_MIN) || (level >= LOG_LEVEL_MAX) || (tag == nullptr) || (domain >= DOMAIN_OS_MAX)) {
        return false;
    }
    if (level < GetFinalLevel(domain, tag)) {
        return false;
    }
    return true;
}
```

# 四、std::bind()函数的用法

## c++11 及以上支持 std::bind

## 包含头文件 `#include <functional>`

## 使用示例

1. std::bind 就是一个对原函数和函数参数的重新绑定。
2. std::placeholders 是新函数的占位符标记。
3. std::placeholders::_n 中的,_n表示的是新函数的第n个参数,将代替原函数声明位置时的参数。
4. 未出现 std::placeholders 的原函数位置,必须有默认值。

```
#include <iostream>
#include <functional>
using namespace std;

int TestFunc(int i, char c, float f)
{
    cout << i << endl;
    cout << c << endl;
    cout << f << endl;

    return i;
}

int main()
{
    auto bindFunc1 = bind(TestFunc, std::placeholders::_1, 'A', 999.9);
    bindFunc1(16);
    auto bindFunc2 = bind(TestFunc, std::placeholders::_2, std::placeholders::_1, 999.9);
    bindFunc2('B', 16);
    auto bindFunc3 = bind(TestFunc, std::placeholders::_2, std::placeholders::_3, std::placeholders::_1);
    auto ret = bindFunc3(999.9, 32, 'C');
    cout << ret << endl;
    return 0;
}
```

# 五、预期效果

为了方便查找进出日志,加入了特别字段,例如 "_func"  和 "wyyxiu"。

* 首先出现 enter_func, 然后出现 leave_func, enter_func 和 leave_func 成对出现,打印出的日志片段如下:
  ![enter_leavelog.PNG](https://forums-obs.openharmony.c ... lklce2ze7lrebbh.png "enter_leavelog.PNG")
* 如果止步于看到日志,还有一点可惜。按照日志名称、出现规律,经过一番操作,很容易从日志文件整理出函数调用的时序图。
  ![enter_leavesequence.PNG](https://forums-obs.openharmony.c ... pubdbc8pb16by1c.png "enter_leavesequence.PNG")
* 如何快速将日志文件整理出函数调用的时序图,关注我、等待后续文章。

# 六、总结

本文巧妙使用了三个知识点完成了函数进出日志打印。首先利用函数局部类对象实现在函数的入口只打印一条日志,出口不用打印,却自动产生进入、离开两条日志的目的;其次利用宏替换将模块id、类名称Tag、函数名称写在宏函数中,实现了所有参数只写一次的目的;最后利用 std::bind()函数管控不同级别进出日志打印。

# 七、相关链接

【TOOLS使用】用IPOP调试 OpenHarmony 内核 https://forums.openharmony.cn/fo ... thread&tid=1532
【TOOLS使用】(一) OpenHarmony hilog组件在交互时应用指南 https://forums.openharmony.cn/fo ... thread&tid=1470
【TOOLS使用】OpenHarmony命令行工具hdc安装应用指南 https://forums.openharmony.cn/fo ... thread&tid=1458
[/md]




欢迎光临 OpenHarmony开发者论坛 (https://forums.openharmony.cn/) Powered by Discuz! X3.5