再谈日志系统

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 吗？有这种可能，但是也可能是调用者出了问题。