easelog(1)基础C++日志功能实现

EaseLog(1)基础C++日志功能实现

Author: Once Day Date: 2025年2月22日

一位热衷于Linux学习和开发的菜鸟，试图谱写一场冒险之旅，也许终点只是一场白日梦…

漫漫长路，有人对你微笑过嘛…

注：本简易日志组件代码实现参考了Google Chrome Log和moduo Log(作者陈硕)源码。

全系列文章可参考专栏: Linux实践记录_Once-Day的博客-CSDN博客

参考文章:

Google Code Archive - Long-term storage for Google Code Project Hosting.
emilk/loguru: A lightweight C++ logging library
OnceDay11/easelog

文章目录

EaseLog(1)基础C++日志功能实现
- - - 1. 功能定义
    - 2. 实现分析
    - 3. 实际测试
    - 4. 源码文件

1. 功能定义

(1) 支持日志级别分类：DEBUG、INFO、WARNING、ERROR，可选支持FATAL。

(2) 输出信息类别：时间戳、进程ID、线程ID、函数名、代码行号和日志信息(支持不定参数)。

(3) 支持多线程：要求时间戳不能乱序，性能方面没有特别要求。

2. 实现分析

一般常见的日志是Debug日志，或者说程序错误日志，典型代表是Linux环境下的syslog接口，其满足上述的要求。多线程依靠锁来避免时序问题，性能一般，但拓展性和可读性很好，以文本的形式保存和呈现。

还有一类是写到数据库的日志，具有严格定义的字段和值说明，对性能要求极高，在多线程场景下，需要通过Per-Core数据结构和无锁操作(原子指令)来优化性能，但相应的代码会复杂很多。

这里实现的日志库为普通的程序Debug日志，通过互斥锁来避免并发时序问题。虽然看起来互斥锁在多线程环境下性能一般，但是程序Debug日志是文本类日志，其文本格式化本身需要消耗较大性能，日志量也不可能太大。对于性能敏感型的多线程应用，一般会使用数据库日志来记录相关信息。

在实现上，一般采用分层设计，如下所示：

在这里插入图片描述

这里面最核心的部分就是日志格式化处理，一般提供的API函数只有一个，然后通过宏包装扩展到各式各样的日志接口。

程序debug日志底层接口基本都支持自定义的回调函数，然后回调函数里再写入到syslog中，同时也可以直接输出到标准输出或者标准错误(STDOUT/STDERR)。程序很少会自己写日志文件，像rsyslog这类标准库更适合拿来就有，毕竟整理和打包大量应用的日志文件，是一件复杂的事情。

Chrome和muduo里面的日志组件代码，写文件的时候会上锁，其他输出方式则都是无锁。这点很有意思，它们在格式化时间戳时都存在时序问题，也就是时间戳乱序，但开发者似乎并不在意。

syslog接口输出的日志时间戳不会乱序(至少rsyslog如此)，syslog日志文件里面的时间戳并不在程序Log函数中格式化，而是rsyslogd进程收集到所有日志消息后统一格式化。

本日志库实现要求中，需要在程序Log函数里格式化时间戳，这意味着在格式化日志时就需要上锁，性能会存在一些影响。这种实现方式比较简单，如下所示:

在这里插入图片描述

这个日志组件实现的问题在于锁的粒度太大了，并发线程较多的情况下，debug日志会互相堵塞，拖慢程序执行。一种可行的优化方式是通过多生产者+单消费者的无锁环形队列配合互斥锁实现更小的锁粒度，如下:

在这里插入图片描述

通过无锁队列，可以将普通参数信息的格式化剥离出来，但是所有线程仍然会去抢锁写入日志，正常情况是不同线程轮流负责日志写入，串行化写入可以保证时间戳获取点和写入点的顺序一致，从而避免乱序。

想再提高性能，最好的方式是异步日志(上面有一定异步化，但不够彻底)，直接使用单独的日志线程，这个实现起来更加简单，而且无需互斥锁，直接通过无锁队列实现。

本日志组件最终实现两种模式：

低并发度下采取上述的互斥锁方法，这样节省线程资源，性能相对也会更好(减少线程切换)。
高并发度下采取单独日志线程的方法，优先保证业务的并发处理能力，避免日志堵塞，全局效果更优。

3. 实际测试

目前只实现了基础功能：低并发度下采取互斥锁，更上层的复杂日志宏API暂未实现。

测试方面通过创建三个线程来模拟并发日志写入，为了更容易触发乱序，引入随机Sleep操作，在日志格式化和实际写入操作之间，如下所示:

// 用于构造并发时序, 随机等待 10-50ms
void RandomSleep()
{if (g_log_enable_random_sleep) {std::this_thread::sleep_for(std::chrono::milliseconds(10 + rand() % 40));}
}// 创建的线程重复20次输出日志
std::thread t1([]() {pthread_setname_np(pthread_self(), "thread1");for (int i = 0; i < REPEAT_TIMES; i++) {LOG(INFO) << "log message test: " << i;}
});// 没有锁保护下的直接日志写入
if (ShouldLogToStderr(severity_)) {// 生成时间戳std::string timestamp;LogSyslogPrefixTimestamp(log_settings, timestamp);// 引入随机延迟RandomSleep();// 写入日志信息WriteToFd(STDERR_FILENO, timestamp.data(), timestamp.size());WriteToFd(STDERR_FILENO, str_newline.data(), str_newline.size());
}

运行后，可以在输出日志里发现明显的乱序情况，如下:

在这里插入图片描述

引入互斥锁后，可以避免乱序:

if (ShouldLogToStderr(severity_)) {std::lock_guard< std::mutex > lock(g_log_mutex);// 生成时间戳std::string timestamp;LogSyslogPrefixTimestamp(log_settings, timestamp);RandomSleep();// 写入日志信息WriteToFd(STDERR_FILENO, timestamp.data(), timestamp.size());WriteToFd(STDERR_FILENO, str_newline.data(), str_newline.size());
}

运行截图如下:

在这里插入图片描述