实现一个简单的日志收集程序

背景

之前定位过一个fclose导致的性能问题，最终结论是日志收集程序的主线程调用fclose函数，触发操作系统sync磁盘操作，导致上游业务程序被阻塞在某条随机的打印日志语句里，最终扰乱业务。
当时为了规避问题，将日志收集程序在系统启动脚本里注释掉了，并提醒业务同事尽快重构日志收集程序，没想到业务的同事一直不改，直到最近因为另一个业务问题，牵扯到驱动，于是我决定替他们重构。

解决方案

思路

1. 触发sync磁盘操作的fclose必须挪到子线程。
2. 主线程的写日志操作不能被子线程的fclose卡住，否则拆分线程无意义。
3. 使用乒乓操作，第一个文件被主线程写满时，立即切换到第二个文件，然后将第一个文件写入磁盘，第二个文件写满时再切换到第一个，以此类推。
4. 切换过程要加锁，写日志也要加锁。
5. 对上游业务程序的接口保持不变

乒乓操作简介

一开始，主线程将日志写入椭圆形对应的文件

等dumper线程检测到椭圆形文件写满limit字节，则获取锁，并让act file指向圆角矩形对应的文件，然后释放锁，最后关闭椭圆形文件，触发sync

等dumper线程检测到圆角矩形文件也写满，则再次获取锁，并让act file指向椭圆形对应的文件，然后释放锁，最后关闭圆角矩形文件，触发sync

以此类推。

注意

整个乒乓操作期间，sync都只阻塞dumper线程，不会阻塞主线程，从而保证主线程不会丢log。
另外线程锁保证了act file和bak file交换操作的原子性，log永远不会被主线程写到bak file。

接口

日志收集程序LogLimiter的用法：
从标准输入读入一行字符串，然后输出到用户指定的日志文件，如果日志文件的体积大于某个limit，则写入备用文件，如果备用文件也写满了，再写入原始文件。

PowerAnalyzer | ./LogLimiter 1024 /var/log/PowerAnalyzer.log

1. 参数1，limit，表示日志文件不能超过多少KB，上例表示不超过1024KB，即1MB
2. 参数2，log_file，表示输出日志文件的路径

代码

自定义结构体

struct log_fd {
    FILE *stream;
    char *path;
};
struct thread_info {    /* Used as argument to thread_start() */
   pthread_t thread_id;        /* ID returned by pthread_create() */
   char     *argv_string;      /* From command-line argument */
   struct log_fd    active;
   struct log_fd    backup;
};

static struct thread_info tinfo;

• log_fd结构体将stream和对应的文件路径绑定起来，这样可以实现乒乓操作的整体切换
• 记录文件路径是为了重新以只写方式打开，这样能清空文件内容。

主线程main

    limit = atof(argv[1]) * 1000.0f;
    
    char bak_name[512];
    sprintf(bak_name, "%s.bak", argv[2]);

    FILE* fp = fopen(argv[2], "r+");
    fseek(fp, 0, SEEK_END);
    tinfo.active.stream = fp;
    tinfo.active.path = argv[2];
    tinfo.backup.stream = NULL;
    tinfo.backup.path = &bak_name[0];
    
    pthread_mutex_init(&mut,NULL);
    ret = pthread_create(&tinfo.thread_id, NULL, dump_log, &tinfo);

    while (1)
    {
        static char buffer[MAX_BUFF_SIZE];

        if (fgets(buffer, sizeof(buffer), stdin))
        {
            struct timeval tv;
            gettimeofday(&tv, NULL);
            
            pthread_mutex_lock(&mut);
            fprintf(tinfo.active.stream, "[%s.%.6ld] %s", FormatTime(tv.tv_sec), tv.tv_usec, buffer);
            pthread_mutex_unlock(&mut);
        }
    }

注意，向当前日志文件写日志前，需要获取锁，因为可能当前日志文件正在被替换成备份日志文件。

子线程dump_log

static void * dump_log(void *arg)
{
    struct thread_info *ptinfo = arg;

    while (1) {
        if (ftell(ptinfo->active.stream) >= limit)
        {
            ptinfo->backup.stream = fopen(ptinfo->backup.path, "w");

            pthread_mutex_lock(&mut);
            swap_log_fd(&ptinfo->active, &ptinfo->backup);
            pthread_mutex_unlock(&mut);

            fclose(ptinfo->backup.stream);
        }
        usleep(1000); // sleep 1ms
    }
}

• 子线程在交换日志文件前，必须获取锁，因为主线程可能正在使用当前日志文件输出日志
• 以只写方式打开文件路径，相当于将写指针指向文件开头，并清空文件内容。
• 接上条，如果用fseek或rewind设置写指针到文件头，则会导致文件头的内容比文件尾还新的现象，不利于开发人员用tail命令查看最近日志

切换函数swap_log_fd

void swap_log_fd(struct log_fd *act, struct log_fd *bak) {
   struct log_fd temp;
   temp.stream = act->stream;
   temp.path = act->path;
   act->stream = bak->stream;
   act->path = bak->path;
   bak->stream = temp.stream;
   bak->path = temp.path;
}

总结

• 日志系统的水很深，最好使用系统自带的日志接口。
• 如果非要用自己的，最好有个中间件团队，维护此类应用程序。