☰
自研高性能日志库:异步架构、格式化链路与批量写盘实战
2026/10/14 5:30:26 网站建设 项目流程

最近一个月,我一直在跟一个网关服务的性能压测死磕。业务线程优化到一定程度以后,CPU负载却始终降不下来,排查下来发现日志库吃掉了差不多三成CPU。这个结果让我下定决心,把手里的通用日志库换成自己实现的一套高性能日志库。如果你也在考虑自研日志库,或者想给现有日志库做深度优化,这篇文章应该能帮你少走不少弯路。

我先说结论:日志库的性能问题,绝大多数不在“写日志”这件事本身,而在“每一次写日志时附带的系统调用、锁竞争、内存分配和格式化成本”。真正的高性能实现,核心就三件事——异步架构、格式化链路优化、批量写盘策略。下面我会把每一块的关键设计逻辑、代码结构和实测方法都拆开来讲,顺便把我踩过的坑一并交代。

1. 日志开销被低估:自研高性能日志库的动机与边界

1.1 日志为什么成了压测瓶颈

很多服务在低QPS下根本察觉不到日志库的存在,但一旦并发上来,日志库的缺陷会被无限放大。我之前压测的那个网关服务,日志是同步写到文件的,每处理一笔请求就要拼接字符串、取系统时间、调用write系统调用。压测峰值大概每秒处理8000笔请求,每笔请求只记两条日志,合在一起就是每秒1.6万次write,每次write还带一次格式化。结果就是,业务线程卡在文件IO上,而文件系统缓存也很快被打满,延迟直接飙升。

这里要理解一个底层事实:一次不带fsync的write,看起来快,但它仍然要进入内核态,经过VFS层、页缓存,而且如果写入量超过页缓存回写速度,写入线程就会被阻塞在内存回收上。同步日志每行一次write,等于把日志库变成了一个高频系统调用发生器。在高并发服务里,这跟性能灾难没什么区别。

所以我在设计时定的第一原则就是:业务线程绝不允许直接碰文件IO。

1.2 现成日志库的问题与自研边界

你可能要问,现成的开源日志库也有高性能的,为什么要自己写?我之前确实先用过一个比较流行的异步日志库,基础性能不错,但它有两点让我难受。一是定制化扩展麻烦,比如我想把同一份日志同时送到远端采集通道,它内部不提供干净的接入点,只能靠自己再写一个消费者把日志转发出去,等于多了一次拷贝;二是它对依赖项的掌控太弱,某些版本为了跨平台引了一堆小依赖,在严格的构建环境下非常难受。

但我也必须说清楚自研的边界。如果你的场景只是普通的后端服务,日志量一天几GB,用成熟日志库完全够用。自己实现日志库,适合下面几类情况:

  • 明确以每秒几十万条日志为设计目标,且对大促、压测场景有硬性性能要求;
  • 需要对日志格式、采集接口、落盘策略做深度定制;
  • 需要跨平台或受限环境,想彻底掌控依赖;
  • 想深入理解日志系统性能本质,顺便锻炼底层工程能力。

如果你没有这些诉求,真没必要重造轮子。

1.3 先定性能指标再做架构

自研之前,我按目标服务压测数据倒推了几个硬指标:

  • 目标吞吐:单进程每秒写入50万行短日志(每行80字节左右);
  • 峰值延迟:业务线程从调用写日志接口到返回,P99不超过10微秒;
  • CPU占用:日志系统整体CPU占用不超过单核的60%;
  • 文件维度:日志文件按大小滚动,单文件上限1GB,磁盘顺序写利用率不能低于70%。

这些指标决定了架构必须彻底异步化,也就是业务线程只把日志放到内存队列,由后台线程批量刷盘。

2. 异步写入架构:环形队列与双缓冲的真实取舍

2.1 为什么单写多读模式必须异步

日志系统的生产端是多个工作线程,消费端只有一个后台写入线程。如果让每个工作线程自己完成格式化加写入,压力会集中在文件的竞争锁和页缓存上。异步后,工作线程的任务变成两件事:拷贝日志内容到缓冲区、在极短时间内通知消费线程。所有文件IO集中在消费线程,天然规避了多线程写文件的锁竞争。

在架构选型时,我对比过两种主流方案:有锁的双缓冲队列和无锁环形队列。实际上,两者并不是非此即彼的关系,关键看生产强度。

有锁双缓冲的模式是很多现代日志库的经典做法:前端buffer供业务线程写入,后端buffer供IO线程刷写;当前端满了,就交换两个buffer的指针。这个方案里锁只保护指针交换动作,业务线程往buffer里写的时候不持锁。好处是极端简单、稳定,且对线程数不敏感。

无锁环形队列则适合SPSC(单生产者单消费者)场景,但在MPSC(多生产者单消费者)下,要么用CAS循环控制写入位置,要么做Striped机制削减竞争。一个很容易被忽略的问题是,环形队列的容量不好设置——太小容易丢日志,太大占用内存,而且业务线程写入时CAS失败重试的开销,在高竞争场景下并不比锁低多少。

2.2 双缓冲实现的细节与代码骨架

我最终的方案是以双缓冲为主,队列机制只用来传递buffer指针。

class AsyncLogger { public: AsyncLogger(size_t buffer_size) : buffer_size_(buffer_size), current_(new Buffer(buffer_size)), next_(new Buffer(buffer_size)), io_thread_(std::thread(&AsyncLogger::Loop, this)) {} void Append(const char* msg, size_t len) { std::lock_guard<std::mutex> lock(mutex_); // 当前buffer空间不足时,先交换到待写队列 if (current_->Available() < len) { pending_.push(current_.release()); // 如果备用buffer存在,直接用备用,否则新建 if (next_) { current_.reset(next_.release()); } else { current_.reset(new Buffer(buffer_size_)); } cond_.notify_one(); } current_->Append(msg, len); } private: void Loop() { std::unique_ptr<Buffer> write_buffer(new Buffer(buffer_size_)); while (!stop_) { std::unique_lock<std::mutex> lock(mutex_); cond_.wait_for(lock, std::chrono::milliseconds(100), [this] { return !pending_.empty() || current_->Size() > 0; }); // 把当前buffer也拿走,腾出新的current pending_.push(current_.release()); current_.reset(next_.release() ? next_.release() : new Buffer(buffer_size_)); swap(write_buffer, pending_.front()); // 取出一个待写buffer pending_.pop(); lock.unlock(); FlushBuffer(write_buffer.get()); } } size_t buffer_size_; std::unique_ptr<Buffer> current_; std::unique_ptr<Buffer> next_; std::queue<std::unique_ptr<Buffer>> pending_; std::mutex mutex_; std::condition_variable cond_; bool stop_{false}; std::thread io_thread_; };

注意几个关键点。

第一,Append()中对next_的处理。经典的双缓冲只留两个buffer,但如果业务线程写入太快,IO线程还没刷完,current_满的时候next_可能还在别处,所以需要一个pending_队列做缓冲池。这是从“双缓冲”退化为“缓冲池”的过程,但好处是留有足够的积压空间应对突发流量。

第二,wait_for的超时时间。我设了100毫秒,作用不是延迟落盘,而是兜底。正常情况下只要当前buffer不空或者pending里有人,条件变量会立刻唤醒;超时只发生在长时间没有任何日志的场景,避免消费线程空转。

第三,swap(write_buffer, pending_.front())这一步,目的是让IO线程自己复用待写buffer。每次刷完,write_buffer里存的是排队等待写入的那块内存,下次循环再从pending里取新buffer,可以把内存分配次数降到最低。

2.3 为什么我没有直接上无锁队列

在早期版本里,我尝试过把生产者写入做成无锁环形队列,日志内容直接以“长度+字节”的形式压入队列。当时测出来的P99延迟大概能比带锁版本低10%,但因为业务线程要CAS抢占写位置,峰值吞吐反而不如缓冲区交换模式,而且头部缓存行竞争严重。

后来想明白一个问题:日志场景里,生产者的写入粒度往往是“一段连续内存”,先格式化完再入队;而双缓冲模式下,业务线程直接在内存里追加连续内容,天然没有头部竞争。对日志这种“多生产者、单消费者、写多读少”的场景来说,有锁双缓冲比无锁队列更符合直觉。

当然,如果你的日志行很长、而且并发线程很多,缓冲池模式的锁竞争会上升。这时可以考虑把单个mutext替换成Striped锁或shard结构,也就是按线程哈希分片,每片一个双缓冲。这个优化我留到了压测后,后面会提到。

3. 格式化链路优化:毫秒时间戳与零拷贝字符串

3.1 时间戳是第一个隐藏瓶颈

很多日志库慢,慢在每次格式化都要调用localtime_r、sprintf。一个微不足道的细节是,localtime_r内部要处理时区规则、锁、线程本地缓存,实际耗时可观。在我的压测环境里,一次完整的localtime_r加snprintf,比整个日志拷贝进buffer还要贵。

常规做法是缓存秒级时间,但毫秒怎么做?正确思路是每次调用std::chrono::system_clock::now()拿到当前时间点,然后把它拆成“秒+当前秒内的毫秒部分”。因为epoch到now的纳秒总数是单调递增的,当前秒内的毫秒数等于“总纳秒除以1e6再对1000取余”,这个计算只需要除法和取模。

时间字符串的格式化为:先把缓存好的日期字符串(到秒级)作为前缀,再计算毫秒部分,最后填充后三位。

thread_local time_t cached_second = 0; thread_local char cached_time_str[32] = {0}; void FormatTimestamp(char* buf) { auto now = std::chrono::system_clock::now(); auto us = std::chrono::duration_cast<std::chrono::microseconds>(now.time_since_epoch()).count(); time_t seconds = static_cast<time_t>(us / 1000000); auto micros_in_second = static_cast<int>(us % 1000000); if (seconds != cached_second) { struct tm tm_val; localtime_r(&seconds, &tm_val); snprintf(cached_time_str, sizeof(cached_time_str), "%04d-%02d-%02d %02d:%02d:%02d", tm_val.tm_year + 1900, tm_val.tm_mon + 1, tm_val.tm_mday, tm_val.tm_hour, tm_val.tm_min, tm_val.tm_sec); cached_second = seconds; } memcpy(buf, cached_time_str, 19); buf[19] = ','; // 微秒占6位,如果精度要求毫秒则写3位 int ms = micros_in_second / 1000; buf[20] = static_cast<char>('0' + ms / 100); buf[21] = static_cast<char>('0' + (ms / 10) % 10); buf[22] = static_cast<char>('0' + ms % 10); buf[23] = ' '; }

这里有几个细节值得说。

线程局部缓存cached_second,每过一整秒才重新调一次localtime_r,每秒内的所有日志都共享同一个日期前缀。这样做的收益不只是省掉多次系统调用,更重要的是避免了每次格式化时的字符串拼接操作,时间戳变成了纯粹的memcpy。

注意不要直接把整个时间戳格式化成“小时:分钟:秒.毫秒”然后每次都snprintf。虽然也能跑,但在每秒几十万的日志量下,哪怕节省一个分支,对总耗时影响都很大。

3.2 整数转字符串:不要用sprintf的默认实现

日志内容里最常见的是各种ID、计数、耗时数字。把整数转成字符串,如果用sprintf,每次都要解析格式化字符串,开销很大。手写一个数字转ASCII的函数很便宜。

inline void AppendUInt64(char*& p, uint64_t v) { char tmp[20]; int len = 0; do { tmp[len++] = static_cast<char>('0' + v % 10); v /= 10; } while (v); while (len) { *p++ = tmp[--len]; } }

如果目标平台支持std::to_chars并且编版本够新,直接用std::to_chars(p, p + 20, v)更好,它在多数编译器上的性能已经接近手写版本,而且不容易出错。我的代码里在需要极低延迟的热路径上用了手写版本,在非热路径(比如JSON序列化)上统一用std::to_chars。

3.3 避免堆分配:线程局部日志槽

这是异步日志库性能的另一个支柱。业务线程不能因为写日志就触发malloc,更不能触发锁内部的std::string扩容。

我的做法是为每个业务线程预留一个线程局部变量,存放一个固定大小的字节数组,以及一个指向当前写入位置的指针。业务线程调用日志接口时,直接把格式化的内容填进这块线程局部内存,然后整体提交给缓冲池。关键收益是零堆分配,并且因为数据是连续写入的,双缓冲的memcpy拷贝效率很高。

线程局部缓存的一块内存可以反复使用,只在当前日志槽被提交给缓冲区后保留待用。需要注意的是,如果业务线程内部还有别的地方也用了同样名字的thread_local变量,容易产生命名碰撞,所以我把它们放到命名空间内并通过__thread或thread_local关键字限定。

3.4 线程号与级别跳转的微优化

线程号获取通常要调用syscall(SYS_gettid),一次约几百纳秒。对高频短日志来说,这也不便宜。正确做法是从第一次调用线程号时缓存到thread_local里,之后直接用缓存值。这里不用考虑进程内线程号复用的问题,因为thread_local生命周期就是单线程,缓存值天然正确。

日志级别判断也要前置。我在接口签名上用了模板加宏的形态,把“判断级别是不是足够”放在参数表达式计算之前:

#define LOG_INFO(fmt, ...) \ do { \ if (Logger::Instance().ShouldLog(LogLevel::INFO)) { \ Logger::Instance().AppendMessage<char>(LogLevel::INFO, __FILE__, __LINE__, fmt, ##__VA_ARGS__); \ } \ } while (0)

这样业务代码里计算日志参数的表达式(比如某个构造成本较高的对象)只有在日志级别开启时才会执行,这在跟踪大量DEBUG日志时能省下不少CPU。

3.5 为什么不用std::ostringstream做格式化

很多日志库用operator<<重载,方便是方便,但每次写日志会创建std::ostringstream,内部涉及动态内存、locale处理、虚函数调用。即使关闭同步,性能也远差于基于纯C风格的格式化。

所以我的日志库对外接口一律是“printf-like”或变参模板。用户提供格式字符串和参数,内部走手写解析。

当需要输出结构体或自定义类型时,用户需要自行提供格式化回调,我固定用toChars风格的接口,避免对象生命周期参与日志内存管理。

4. 文件落地细节:批量写盘、滚动规则与崩溃恢复

4.1 刷盘策略:批量写和fsync的平衡

IO线程拿到一个满的buffer后,不能直接一把write。我观望了好几种策略:

  • 每块buffer一次write,缓冲池清空;
  • 每N块buffer一次write;
  • 合并多个小块成一个更大的大buffer再写。

实测结果是,一次写入的数据块越大,顺序写的吞吐越高。但日志文件在传统机械盘或SSD上的特性不同,现代SSD即使小写也很快,但考虑低延迟场景和系统调用次数,我仍然倾向一次写入至少256KB以上的连续数据。

fsync不能每条日志都调。我按两个触发条件调fsync:

  • 时间上:每1秒或每5秒执行一次强制刷盘;
  • 数据量上:写入累计超过某个阈值(比如32MB)时执行一次强制刷盘。

这个阈值可以根据业务对数据安全的要求调整。对于重要日志,可以每100ms强制一次,代价是写入性能下降,但依然比同步写快很多。

4.2 滚动规则与文件名设计

日志文件按大小或时间滚动。我按大小滚动,单个文件限1GB,达到上限后切换下一个文件。文件名带上时间点序号,比如app-20240612-001.log,便于运维侧做归档和清理。

滚动要格外注意两个问题。

第一,滚动动作本身不能阻塞业务线程。我的方案是由IO线程在落盘buffer时发现当前文件已经达到阈值,先申请新文件名,切换文件描述符,旧文件延迟到后台异步关闭。因为写日志是异步的,这个切换不影响生产端。

第二,不能丢失滚动前的尾部数据。在切换文件描述符前,一定要确保旧文件的所有buffer都写完了。简单做法是先刷完当前所有排队的buffer,再用rename或直接以新fd继续写。我采取的是:切换前先把pending队列所有buffer批量刷进旧文件,再打开新文件,这样能保证文件内日志行按顺序完整。

4.3 进程内的安全退出与信号处理

异步日志库有一个天然风险:业务进程崩溃或正常退出时,内存队列里还有不少没落盘的日志。如果是核心服务,这往往是排查问题的最后一根稻草,不能丢。

我分了两层处理。

正常退出时,调用Logger::Stop(),IO线程会刷完队列里所有buffer再退出,正常退出不丢数据。

异常崩溃时,比如段错误、abort,此时业务线程已不可信,但IO线程通常还活着。如果来不及优雅退出,可以注册信号处理器,在信号处理函数里尝试调用write()直接刷当前buffer。这种方案的局限性是信号处理函数里能做的事很有限,不能加锁、不能动态内存,所以我实现了一个专门的“紧急落盘”路径,内部用预先分配好的连续内存来承接当前buffer,然后直接write到文件描述符。实测下来对常见信号基本有效,但要知道这不是银弹,它至少能保留最后几秒的日志。

4.4 丢日志的实时性设计

在某些场景,比如异常追查,你可能想把日志从异步调成同步。我对外暴露了一个SetAsync(bool)的控制开关,切换由配置中心推送,不需要重启进程。同步模式下,业务线程写完当前buffer后会主动调用一次刷盘接口,而异步模式下则完全交给IO线程。

这个设计看似简单,却能解决一个重要问题:当线上服务发生诡异问题时,运维可以一键切换成同步模式,确认日志是不是丢在异步队列里。

5. 基准测试与调优收敛:数据不会说谎

5.1 设计一套公平的性能测试方案

日志库的性能如果只压测“写一行短日志”,很容易自嗨。我建议至少覆盖四种场景:

  • 单线程写短日志:测试纯格式化加异步提交的最优情况;
  • 8线程写短日志:模拟后端业务并发;
  • 4线程写长日志(每行4KB):模拟协议跟踪、报文快照场景;
  • 混合场景:2/3短日志、1/3长日志。

测试时要把日志输出到临时目录或内存盘,排除磁盘瓶颈。我在一台普通的SSD机器上测,数据写/tmp目录,用/tmp其实已经比系统盘快很多,但要注意测试线程本身不能跟业务线程混跑导致CPU抢占。

跑基准脚本时,每个场景跑30秒,取稳定后的指标。

5.2 关键指标与测试数据

下面是我在测试机上观察到的典型数据。

场景日志行/s业务线程P99延迟(μs)IO线程CPU(%)备注
1线程短日志(80B)约280万3.212纯格式化为主
8线程短日志(80B)约780万6.855锁竞争开始显现
4线程长日志(4KB)约150万9.421写盘吞吐为主
混合场景约310万7.233综合

需要说明的是,日志行/s并不等于写入磁盘行的吞吐边界,因为buffer刷盘速度取决于磁盘写入带宽。短日志场景下,瓶颈主要在CPU和锁;长日志场景下,瓶颈变成内存拷贝和磁盘顺序写带宽。

测试机配置我简单列一下:8核16线程,SSD,Linux 5.x,编译器启用-O2。这个绝对数值不重要,重要的是横向对比不同策略时能不能复现。

5.3 实测中暴露出的三个意外坑

你可能想不到,初版跑压测时最让我头疼的不是格式化,而是三个看似无关的细节。

第一个坑是std::endl。我一开始在消费端打印提示日志时用了带std::endl的写法,结果IO线程每次刷完buffer都被强制flush一次,吞吐直接掉了约35%。排查时把打印语句改成\n就恢复了。这个坑在日志库性能测试里特别经典,几乎所有高性能IO代码都忌讳std::endl。

第二个坑是条件变量唤醒频率。默认策略是每个buffer swap都notify_one(),如果每毫秒有几十次swap,IO线程频繁切换上下文吃掉不少CPU。我改成合并通知:只有连续两次swap时间间隔小于500微秒时,才用一次唤醒覆盖多个待写buffer。这个优化在8线程场景下,IO线程的CPU占用下降了约20%。

第三个坑是无意中对文件描述符的O_APPEND使用。O_APPEND在Linux上会额外进行一次锁操作,对多线程写同一文件影响非常大。我的IO线程是单线程写文件,完全可以不带O_APPEND,靠单线程的顺序写保证追加语义,少了不必要的锁。

5.4 调参收敛的经验值

经过几轮压测,我把参数收敛在了下面这组组合上:

  • 单个buffer大小:4MB;
  • pending队列上限:初始32个buffer,超额后生产端短暂阻塞;
  • IO线程唤醒条件:buffer非空或等待超时2ms;
  • 刷盘阈值:32MB;
  • 强制fsync周期:1秒一次;
  • 消息格式模板:时间戳+级别+线程号+文件名+行号+消息体+分隔符。

这个组合在混合场景下达到约310万行/s,业务线程P99延迟稳定在7微秒上下,IO线程CPU占33%左右。如果你要调的话,先把单个buffer调大到8MB试试,如果发现业务线程偶尔被阻塞,说明buffer太大会带来额外的内存拷贝成本,反而得不偿失。

5.5 想继续压榨性能还能做什么

如果你还想再往前一步,可以考虑做分片日志池,也就是按线程哈希把日志分流到多个双缓冲结构,每个分片有自己的IO线程。这样能显著降低全局锁竞争,8线程场景可能还可以再提升20%到30%。

不过要提醒一句,多IO线程可能导致日志在文件里的顺序不可控。如果你依赖乱序日志来还原事件时间线,就必须在最前面打上时间戳和序号,并在落盘后做外部排序。很多分布式系统的日志采集通道就是这么实现的,但做了之后系统的复杂度会明显上升。

我自己的判断是,对大多数单机服务来说,双缓冲加分片优化已经足够,再继续往多IO线程方向走,性价比很低。

如果你在尝试实现过程中也发现一些诡异瓶颈,建议先压测再优化,不要凭感觉改代码。日志库的性能瓶颈往往不在你最初怀疑的地方,而在那些不起眼的细节里。

需要专业的网站建设服务?

联系我们获取免费的网站建设咨询和方案报价,让我们帮助您实现业务目标

立即咨询