再谈日志系统
1. 面相抽象:不直接使用 printf / std::cout
直接使用 printf 或 std::cout 的弊端在于:不够规模化,修改起来麻烦。
例如,除了想往控制台打印,还希望往文件打印; 想确保每一处打印都有 flush; 想通过 CMake Option, 用一个简单的开关来控制日志的开启和关闭。
使用专门的日志库提供的 宏/函数, 而不是直接使用 printf / std::cout, 是基本的要求。
而 Debug/Info/Warning/Error 等级的划分, 算是日志库的基本功能, 这里不探讨了。
2. 有区分度的打印:专属的 tag
在多人协作、多 SDK 集成的场景下, 所有 log 都输出到控制台时, 怎样区分不同模块的日志? 每个模块应当有自己独特的 tag, 也就是显示在日志打印的每一行的最开头部分的, 如:
[D] module1: xxxxx
[D] module2: xxxxx
这里的 module1
和 module2
就是 tag。 当程序出现 crash,根据 crash 前最后一次打印的 tag, 来判定职责在哪个模块(SDK)中,对应的开发负责人负责排查(也就是甩锅、背锅)。
3. 自证清白:API函数的进入-离开 log
当调用子模块时,子模块的某个 API 函数是否运行完毕, 决定了谁来背锅。例如有 f 和 g 两个模块, f 负责调用 g 模块的 g1(), g2() 两个 API 函数:
f1()
- g1()
- g2()
f2()
当最终的日志打印中,看到了 g2( ) 内的日志打印、没看到 f2() 的日志打印, 并且 f2() 代码中确实写了日志打印, 这时候如何裁定职责呢?
由于我负责 g 模块, 无法主导 f 模块的排查, 只能在 g1(), g2() 函数中自证清白: 在 API 函数执行的最开头、最末尾, 增加日志打印:
class AutoLogger
{
public:
AutoLogger(const char* name):
m_name(name)
{
XX_LOGD("%s begin()", name);
}
~AutoLogger()
{
XX_LOGD("%s end()", name);
}
private:
std::string m_name;
};
void g2()
{
AutoLogger logger(__FUNCTION__);
... // 原有代码
// XX_LOGD("g2() end"); // 原本有这句,但是无法保证是 g2() 最后执行的内容,因为可能有类实例的析构函数在这句之后执行
}
为了进一步简化代码,以及避免 logger
命名冲突,改为宏定义:
#define API_ENTER_LEAVE_LOG AutoLogger logger##__LINE__(__FUNCTION__)
这样一来,看到的日志一定是这两种之一:
// g 模块没crash
[D] module_g: g2() begin()
[D] module_g: .....
[D] module_g: g2() end()
crash info
// crash 在 g 模块内
[D] module_g: g2() begin()
[D] module_g: .....
crash info
4. 保存现场: 多重输出
一个合格的日志库, 应当能让调用者同时往控制台、文件写入日志,并且支持用户往其他地方写入日志,例如 Android logcat, 或 QNX 系统的 slog。
那么作为使用者,就需要这样写:
static void custom_logger(char* line, FILE* fp)
{
char buf[1024];
sprintf(buf, "%s\n", line);
fprintf(stdout, "%s", buf);
fflush(stdout);
if (!fp && fp!=stdout)
{
fprintf(fp, "%s", buf);
fflush(fp);
}
#ifdef ENABLE_SLOG
{
slog2(DEBUG1, "%s\n", buf);
}
#endif
}
static FILE* s_file = NULL;
void g_init()
{
API_ENTER_LEAVE_LOG();
if (s_file)
fclose(s_file);
s_file = fopen("xxx.log", "wt");
xx_log_register_logger(custom_logger);
}
void g_run()
{
API_ENTER_LEAVE_LOG();
...
}
5. 有效性探讨
个人认为上述 log 内容有一定正向作用,但是只能起到有限作用。 当 f 模块遇到了 "Malloc failed: xxxx" 的报错时,那看起来应该是 glibc 的作者们写 bug 了,我们应当找 glibc 的作者去修改 bug 吗?有这种可能,但是也可能是调用者出了问题。