UtilBox(ub)基础组件 -- Log日志(1)

      文章内容和代码为作者原创，转载请说明 ^_^

      这篇文章主要介绍一下log组件，平时大家调试程序和记录程序异常，这是最常用的。比如调试小程序的正确性，有些同学就在代码里放一堆的printf，可是这样带来的后果就是想去掉这写debug用的printf很麻烦(这个可以用宏来代替，比如类似ASSERT，通过开关来控制)。还有，如果程序写成了daemon，放到后台，printf的作用就没了。所以，日志才是万能的，即方便追查程序也方便日后帮你统计数据，并且每行日志也可以加入文件行号、时间等有用信息。

      log虽然能带来不少好处，但也会有不好的地方，比如程序每次写日志都会带来性能损耗(写入pagecache会好一点)，我的程序统计过，一个proxy程序不断打日志的话，会带来10%~20%的性能损耗，所以日志不是随便打，没用的信息就不要打出来，而且日志要分级(DEBUG/TRACE/WARNING/FATAL四级)，方便以后把不需要的级别的日志过滤掉，比如开发时候DEBUG级别的日志需要打出来，上了线就不要打DEBUG了，只打印WARNING的一些重要信息就好了。

      作为日志，还有一点比较叫重要的功能就是要做日志的切分，比如日志文件大于2G时就需要重新new一个文件，还有比如我们需要一个小时切分一个日志文件，方便以后查询。OK，下面就看看log组件需要的接口函数：

      对日志进行初始化，如果filepath是NULL的话就用stdout，相当于printf了，第二个参数是是否要做DIRECT_IO的方式，说明一下directio是write时直接“写穿”到磁盘，而不像一般情况下，会写入到linux的pagecache(pdflush会定时batch flush到磁盘上)，所以非directio在只有机器掉电的情况下会丢失一些日志的，directio不会，它会保证内容写到磁盘才返回。一般情况下，只要这写日志不作为redo_log或者binlog这种需要重放磁盘数据的，就不要用directio，因为性能会收到很大影响。

/**
 * @brief  : initial log handler with path , indicate use direct io or not
 * 
 * @params : [in] filepath  : which file to be written . if NULL "stdout" will be set
 * @params : [in] flag      : file mask set         
 *
 * @return : pointer to the log_t structure . if failed , it's NULL
 */
log_t* log4c_init(const char* filepath, int direct_io);

      带切分的初始化(上面的init不切分)，可以按时间ts，也可以按内容ss，或者两者都有，如果某项不需要的话就为0

/**
 * @brief  : initial log handler with path , direct io , and split strategy 
 * 
 * @params : [in] filepath  : which file to be written . if NULL "stdout" will be set
 * @params : [in] flag      : file mask set         
 * @params : [in] ts        : span time of split file , 0 means no split 
 * @params : [in] ss        : content size of split file , 0 means no split 
 *
 * @return : pointer to the log_t structure . if failed , it's NULL
 */
log_t* log4c_split_init(const char* filepath, int direct_io,unsigned long long ts, size_t ss);

      销毁日志句柄，没什么可说的了。最初设计成log4c_destroy(log*)这种，可是每次log4c_write时候需要用户穿一个句柄进来就的显得累赘，而且一般用户也不会有两个日志句柄，所以就放到内部了。

_/**
 * @brief  : destroy log handle 
 */
void log4c_destroy();

        针对不同级别的log进行写入，说明一下，DEBUG和TRACE级别会写入.log文件，而WARNING和FATAL日志会写入.log.wf文件，查起来方便。其实就是个宏来调用write，这里用宏的原因就是没行日志有当前的文件名和行号，所以用宏。

/**
 * @brief :  write log with LEVEL 
 *
 * @params : [in] log : log handle 
 * @params : [in] buf : buffer to be written 
 */
#define LOG4C_DEBUG(buf) do{\
    log4c_write(DEBUG,__FILE__,__LINE__,buf);\
}while(0)

#define LOG4C_TRACE(buf) do{\
    log4c_write(TRACE,__FILE__,__LINE__,buf);\
}while(0)

#define LOG4C_WARNNING(buf) do{\
    log4c_write(WARNNING,__FILE__,__LINE__,buf);\
}while(0)

#define LOG4C_FATAL(buf) do{\
    log4c_write(FATAL,__FILE__,__LINE__,buf);\
}while(0)

      最后，来说一下log_t这个最核心的数据结构，log的句柄，里面记录了2个文件fd，以及时间的记录，和切分的时间、容量的阀值和文件掩码等信息

typedef struct __log_t
{
    //unsigned int level;   /* level of log to record : ERROR , WARNING , DBUG , ALL */
    char file_name[FILE_NAME_MAX];
    unsigned int mask;
    int direct_io;
    int normal_fd;              /* output log file */
    int error_fd;               /* output wf file */
    size_t normal_file_size;        /* file size record */
    size_t error_file_size;         /* file size record */
    size_t split_size;              /* one piece(file) max size with split */
    unsigned long long time_used;   /* total time */
    unsigned long long split_time;  /* one piece(file) time with split */
    const char* last_error;
} log_t;

       处于文章比较长哈，之后我会把全部.c文件的实现拿出来说明。大家也可以根据上面的框架自己构造一个适合自己的log，毕竟合适的才是最好的。

       先把重要的log4c_write贴出来 ：(比较重要的是__check_file_stat这个函数。用来检测时间和容量是否到了阀值如果到了，就close原来的fd，并且重新打开一个以当前时间结尾的文件，继续写入)

void log4c_write(log_level level, const char* file, unsigned int line, const char* buf)
{
    if (!my_log || !buf)
        return;

    // stdout ignore
    if ((my_log->normal_fd!=1) && (my_log->split_size!=0 || my_log->split_time!=0))
        __check_file_stat(my_log);

    int fd = -1;
    switch(level) {
        case DEBUG:
        case TRACE:
            fd = my_log->normal_fd;
            break;
        case WARNNING:
        case FATAL:
            fd = my_log->error_fd;
            break;
        default :
            fd = my_log->error_fd;
            break;
    }

    char tmp[1024] = {0};
    char *level_string = NULL;
    if (my_log->direct_io) {
        if (-1 == posix_memalign((void**)&level_string,getpagesize(),1024))
            return;
    } else
        level_string = tmp;


    int level_string_len = 0;
    // get ms
    time_t timep;
    struct tm *p;
    time(&timep);
        p=gmtime(&timep);

    switch(level) {
        case DEBUG:
            level_string_len = snprintf(level_string,FILE_NAME_MAX,"[DEBUG] [%s:%d] [%d/%d/%d:%d:%d] ",file,line,(1+p->tm_mon),p->tm_mday,p->tm_hour,p->tm_min,
            break;
        case TRACE:
            level_string_len = snprintf(level_string,FILE_NAME_MAX,"[TRACE] [%s:%d] [%d/%d/%d:%d:%d] ",file,line,(1+p->tm_mon),p->tm_mday,p->tm_hour,p->tm_min,
            break;
        case WARNNING:
            level_string_len = snprintf(level_string,FILE_NAME_MAX,"[WARNNING] [%s:%d] [%d/%d/%d:%d:%d] ",file,line,(1+p->tm_mon),p->tm_mday,p->tm_hour,p->tm_m
            break;
        case FATAL:
            level_string_len = snprintf(level_string,FILE_NAME_MAX,"[FATAL] [%s:%d] [%d/%d/%d:%d:%d] ",file,line,(1+p->tm_mon),p->tm_mday,p->tm_hour,p->tm_min,
            break;
        default :
            level_string_len = snprintf(level_string,FILE_NAME_MAX,"[UNKNOWN] [%s:%d] [%d/%d(%d:%d:%d)] ",file,line,(1+p->tm_mon),p->tm_mday,p->tm_hour,p->tm_m
            break;
    }
    int written = write(fd,level_string,level_string_len);
    size_t buf_len = strnlen(buf,512);
    written += write(fd,buf,buf_len);
    // append end "\n"
    written += write(fd,"\n",1);
    if (-1 != written) {
        size_t *file_size = (fd==my_log->error_fd) ? &my_log->error_file_size: &my_log->normal_file_size;
        *file_size += written;
        my_log->time_used += (unsigned long long)time(NULL);
    }

    if (my_log->direct_io)
        free(level_string);
}