编写合格的C代码(2):实现简易日志库

目录

• 需求
• step1: 打印功能的封装
• step2：定制logging的输出行格式
  • step2.1 不同logging等级显示不同颜色
  • step2.2 显示当前运行时刻
  • step2.3 显示行号和文件名
• step3: 控制输出
• step4 多线程安全
• reference

需求

最简单暴力的调试方法是printf()输出变量的值，对于检查发现异常情况很有帮助。

但并非所有时候都需要这些打印出来的信息，例如：太多的打印信息影响算法性能，暴露算法或业务逻辑细节机密，Release模式希望关闭log信息保持干净，etc。

手动增删printf()语句是一种刀耕火种的做法，费力、不容易管理、影响coding状态。换言之，用于调试的打印信息应当可控，想输出就输出，想不输出就不输出：

• 能够输出信息到屏幕或文件：用printf、fprintf可以做到
• 能够控制何时输出何时不输出：需要封装打印功能，根据Debug/Release模式或其他条件来控制是否打印
• 能够增加更多的打印信息：除了打印需要的变量的值，还能打印运行时间、行号、文件名、log等级等信息
• 能够输出到文件，并且多线程安全

通过几个步骤，渐进的实现一个简易的logging库。

step1: 打印功能的封装

可以通过宏定义的方式封装printf()，但宏定义写起来并不如函数好写。

在函数中调用vfprintf()则可以实现打印功能的封装，支持任意多个参数，相当于自己实现了一个printf()，好处是可以定制。
(需要注意的是，并不能在函数中调用printf()来实现一个自己的printf()，因为__VA_ARGS__(...)和va_list并不一样。)

nc_log()函数近似实现了printf()的功能：

#include <stdio.h>
#include <stdarg.h>

void nc_log(const char* fmt, ...) {

    printf("[Nc Log] "); //定制输出：增加[Nc Log]作为log的TAG，区别于其他printf输出

    va_list args;
    va_start(args, fmt); //解析fmt后的可变参数

    vfprintf(stdout, fmt, args); //以fmt作为格式川，打印可变参数

    va_end(args);
}

int main(){

    nc_log("hello nc log, %s\n", "nice"); //调用logging函数

    printf("hello nc log, %s\n", "nice"); //调用标准的printf()

    return 0;
}

测试nc_log函数和标准的printf()函数的输出：

[Nc Log] hello nc log, nice
hello nc log, nice

step2：定制logging的输出行格式

考虑每一行logging输出的格式，除了用户调用时提供的打印参数，通常还可以添加的额外信息可以包括：

• 不同的错误等级，显示不同的颜色
• 当前运行时刻
• 调用logging处的行号、文件名

例如：

具体的格式可以自行定制，这里分别考虑每种额外信息的打印实现。

step2.1 不同logging等级显示不同颜色

是说在终端下让logging输出具有各种颜色，原理就是在需要打印的内容之外，用转义字符来包围，终端本身会将这些转义字符解释为颜色然后输出。现在的Linux/MacOS的终端都支持ANSI颜色转义规则，也就是使用\x1b[%dm作为起始、用\x1b[0m作为结束。看看所有的ASCII字符都能被转义为什么样子：

#include <stdio.h>
int main() {
    for(int i=0; i<256; i++) {
        printf("\x1b[%dm %3d \x1b[0m ", i, i);
        if (i%16==15) {
            printf("\n");
        }
    }
    return 0;
}

显然，有颜色的是少数，没有颜色的是多数；颜色又包括前景字体颜色、背景颜色，并且有普通彩色和加亮彩色。挑选自己喜欢的颜色，然后定义几个自己觉得必要的logging等级，每个等级分别对应一种颜色（对应的颜色转义码），则容易得到每种logging等级的颜色输出：

#include <stdio.h>
#include <stdarg.h>

typedef enum NcLogLevel {
    NC_LOG_LEVEL_BEGIN=-1,

    TRACE,
    DEBUG,
    INFO,
    WARN,
    ERROR,
    FATAL,

    NC_LOG_LEVEL_END
} NcLogLevel;

static const char* level_names[] = {
    "TRACE", "DEBUG", "INFO", "WARN", "ERROR", "FATAL"
};

static const char* level_colors[] = {
    "\x1b[94m", "\x1b[36m",  "\x1b[32m","\x1b[33m", "\x1b[31m", "\x1b[35m"
};

void nc_log(NcLogLevel level, const char* fmt, ...) {
    if (level<=NC_LOG_LEVEL_BEGIN || level>=NC_LOG_LEVEL_END) {
        return;
    }

    fprintf(stdout, "%s[%-5s]\x1b[0m", level_colors[level], level_names[level]);

    va_list args;
    va_start(args, fmt);

    vfprintf(stdout, fmt, args);

    va_end(args);
}

int main(){

    for(int level=NC_LOG_LEVEL_BEGIN+1; level<NC_LOG_LEVEL_END; level++) {
        nc_log(level, "test trace\n");
    }

    return 0;
}

终端颜色输出的通用性
考虑到通用性，测试发现我的Win10的cmd已经默认支持ANSI颜色转义了，而如果是Win7（也许包括老一些版本的win10？），则可以通过安装ANSICON来解决。

step2.2 显示当前运行时刻

使用C标准库函数localtime()获取当前时刻，通过C标准库函数strftime()格式化当前时刻为指定格式的字符串输出，格式说明见strftime。个人认为必要的格式包括：时区、年月日、时分秒。这里需要注意的是，时区的显示如果使用了locale则不容易处理，因此直接显示数字格式的时区偏移量(使用%z替代%Z)。尝试输出：

#include <stdio.h>
#include <stdlib.h>
#include <time.h>

int main() {
    time_t t = time(NULL);
    struct tm* lt = localtime(&lt);
    char now[100];
    now[strftime(now, sizeof(now), "%z %Y-%m-%d %H:%M:%S", lt)] = '\0';
    printf("now: %s\n", now);
}

集成到nc_log()函数中：

now[strftime(now, sizeof(now), "%Y-%m-%d %H:%M:%S", lt)] = '\0';
fprintf(stdout, "%s %s[%-5s]\x1b[0m ", now, level_colors[level], level_names[level])

step2.3 显示行号和文件名

原理是：利用C语言内置宏__LINE__表示行号，__FILE__表示文件名。
需要注意的是，需要把“调用logging打印函数的那行代码的所在行、所在文件”输出，而不是在logging函数中的vfprintf()调用的那一行、那个文件输出。因此应该把__FILE__、__LINE__作为参数传给logging函数：

void nc_log(NcLogLevel level, const char* file, int line, const char* fmt, ...);

调用logging函数的地方传入行号、文件名：

c_log(level, __FILE__, __LINE__, "test log\n");

输出效果：

每次打log需要手动传__FILE__和__LINE__未免效率低下，考虑到用宏封装。对于传入不定个数参数的宏，用...和__VA_ARGS__分别表示需要替代的不定个数参数、传给对应函数的不定个数参数；为了方便，将原来的nc_log函数重命名为nc_log_log函数，定义nc_log,nc_log_trace等宏：

#define nc_log(level, ...)  nc_log_log(level, __FILE__, __LINE__, __VA_ARGS__)
#define nc_log_trace(...)   nc_log_log(NC_LOG_TRACE, __FILE__, __LINE__, __VA_ARGS__)
#define nc_log_debug(...)   nc_log_log(NC_LOG_DEBUG, __FILE__, __LINE__, __VA_ARGS__)
#define nc_log_info(...)    nc_log_log(NC_LOG_INFO,  __FILE__, __LINE__, __VA_ARGS__)
#define nc_log_warn(...)    nc_log_log(NC_LOG_WARN,  __FILE__, __LINE__, __VA_ARGS__)
#define nc_log_error(...)   nc_log_log(NC_LOG_ERROR, __FILE__, __LINE__, __VA_ARGS__)
#define nc_log_fatal(...)   nc_log_log(NC_LOG_FATAL, __FILE__, __LINE__, __VA_ARGS__)

step3: 控制输出

按前面的代码，vfprintf(stdout,...)，显然是输出到屏幕终端上。一个合格的logging库应当能够控制输出：

• 是否输出到屏幕:
  vsprintf(stdout,...)即可
• 是否输出到文件:
  vsprintf(logger.fp,...)即可，注意fflush
• 控制输出level的粒度:
  粒度可以设定level范围：只运行[min, max]范围内level的logging打印；粒度也可以设置为单个level。

我采用的是单个level控制粒度，支持如下函数：

//默认不设定level，会开启所有level的log

//设定level开启的范围：范围内的level被开启，范围外的level都被关闭
nc_log_set_level_range(int min_level, int max_level);

//开启单个level
nc_log_set_level_on(int level);

//关闭单个level
nc_log_set_level_off(int level);

输出到文件的设定：

//默认不输出到文件

//设定输出到文件
nc_log_set_fp(FILE* fp);

输出到屏幕终端的设定：

// 默认是logging到屏幕的，开启quiet则不输出到屏幕
void nc_log_set_quiet(int enable);

step4 多线程安全

当logging到文件时，需要考虑线程安全。

ref: https://github.com/rxi/log.c/issues/1

reference

stdlib and colored output in C
log.c
Getting colored output working on Windows