作为BqLog优化系列的第三篇,前面已经聊过日志格式化与内存分配两条路径的改造,今天这篇专门聚焦压缩日志的执行路径。在很多人眼里,日志组件只要开了压缩,性能掉一半都是很正常的事,但在竞技对战这种场景里,压缩日志往往要承载录播、回放、策略分析等数据,如果压缩吃掉的CPU和IO时间太多,直接影响线上对局帧率。这篇我会把压缩日志路径上踩过的坑和最终落地的方案完整铺开,包括缓冲区设计、无锁队列、内存池复用等细节,适合正在做日志组件性能优化或者对底层执行路径感兴趣的同学参考。
1. 为什么压缩日志路径天然比普通日志慢一个数量级
1.1 普通路径是“直接写”,压缩路径是“先算再写”
普通日志的产生过程,大体是业务线程格式化一条记录,拷入一块缓冲区,后台线程把缓冲区数据追加到文件里。这条路径在BqLog里经过两轮优化后,单线程每秒能扛百万条级别,因为它的CPU开销主要是内存拷贝和极短的系统调用。
压缩日志就不一样了。它必须在把文本写出去之前先执行一次压缩算法。我最早实现的时候,直接沿用了普通的逐条写入思路:每来一条日志,格式化完,压成小块,再拼到输出缓冲。结果性能只有普通日志的三分之一,而且压缩率只有可怜的2:1。原因很简单:压缩算法需要看足够多的数据才能建立字典表,一条几十字节的日志单独压缩,字典还没建立就结束了,等于在做无用功。
这里我想用一个类比:普通日志像是把每张便签纸直接扔进箱子,压缩日志则要求把一堆便签纸先撕碎重组,变成一叠紧密的纸砖。如果每次只给一页纸,机器既要反复启停,又压不出效果,只有给够批量才有价值。
1.2 性能Profile揭示的真相:压缩算法只占20%开销
第一版实现性能很差,我第一反应就是压缩算法太慢,于是换了不同的压缩库试,zstd、lz4、zlib都对比过,结果发现不管用哪个,整体耗时变化很小。这就很奇怪了。
后来用perf抓热点,才发现真相:压缩算法实际只占了整个执行路径CPU的20%左右,真正吃掉时间的是两块:一是每条日志压缩后都要做一次系统调用刷到输出缓冲区,高频小IO让syscall占比飙到30%;二是多线程同时写共享输出缓冲时,锁竞争能占到40%。也就是说,我们根本没有把压缩做成“批量”,而是把每个日志都当成独立任务在跑,运行路径上塞满了系统调用和锁等待。
这个发现改变了我的优化方向:与其去调压缩算法参数,不如彻底重构执行路径,让日志生产线程和压缩线程彻底解耦,把高频小IO变成低频大IO,把多线程锁竞争变成无锁传递。
1.3 游戏场景的额外约束:不能拖累战斗线程
在普通服务端日志场景,慢几十微秒无所谓,但竞技手游不行。战斗线程上的代码如果因为打日志触发锁等待,哪怕只有一帧卡顿,对操作手感的影响都是灾难级。
所以压缩日志路径的优化目标,不只是提升压缩吞吐,两个硬指标是:
- 日志调用方的P99延迟不能超过普通日志路径的1.5倍;
- 压缩过程中不能出现明显的CPU尖刺,尤其不能抢占渲染线程和战斗逻辑线程。
这些约束直接影响了后面所有设计决策。
2. 执行路径重构:从“每条日志各自为战”到“批量流水线”
2.1 让压缩有“料”可压:引入本地聚合缓冲区
第一步是把日志生产和压缩彻底解耦。具体做法是:每个业务线程拥有自己的一组本地缓冲块,日志先写到这些缓冲块里,缓冲块满或者说达到一个时间阈值后,再由后台压缩线程取走。
我把这个模式叫做“聚合提交”。生产线程不再关心压缩逻辑,它只是把日志记录倒进本地块;压缩线程拿到的是连续的大块数据,压缩算法能建立充分的字典,压缩率自然上来。
生活化解释:原来每个顾客来餐厅点一份菜,后厨就单独开一次火做一份,费煤气又出不了多少餐。现在改成顾客把菜写在一张大点单上,攒够十道菜后厨再流水线开火,效率和口味都上来了。
关键参数我调过很多轮,最后稳定在:本地缓冲块大小64KB,当块内数据超过48KB,或者距离上次提交时间超过5ms,就把块投递给压缩线程。这两个阈值是配合业务场景定的,后面专门讲踩坑。
2.2 无锁队列连接生产者和压缩线程
有了缓冲块,接下来的核心问题是:多线程如何把缓冲块安全、低延迟地交给单一的压缩线程。如果用互斥锁保护一个std::queue,在每秒几十万次提交的场景下,锁竞争会立刻成为新瓶颈。
我们最终实现了一个基于数组的MPSC(多生产者单消费者)无锁队列,队列元素是“序号 + 缓冲块指针”。生产者流程是这样的:先通过原子操作FetchAdd获取自己独占的写入槽位序号,再把缓冲块指针写入槽位,最后释放写屏障让消费者可见。消费者只需要读取当前已分配的槽位序号,用读屏障确认所有写入都可见后,就能安全取出指针。
这里有个容易踩的坑:ABA问题。如果用传统的CAS实现pop,很容易误判“队列空”或“读到脏数据”。我们的方案是用单调递增序号替代指针标记,规避掉ABA问题的三个前提,虽然多了一个内存屏障的成本,但换来的是逻辑正确和可维护性。
2.3 压缩线程的批量领取机制
无锁队列实现了,但压缩线程依然不能来一个处理一个。频繁地取出小块、调用压缩算法、写入输出文件,同样会产生大量小IO和上下文切换。
所以压缩线程的工作循环也做成批量模式:
- 尝试从队列里一次性取走最多8个缓冲块;
- 把这8块数据视作一个逻辑大块,交给压缩库处理;
- 压缩输出统一写到一块连续的文件缓冲区;
- 当文件缓冲区达到预定大小,再一次性写盘。
这样把原本“每块一次压缩、每次压缩一次写盘”的高频操作,降成了真正的流水线。实测下来,系统调用次数下降了一个数量级,压缩算法的吞吐也被充分压榨出来了。
3. 三条细节优化:锁没了,内存也要跟着省
3.1 用内存池替代反复malloc/free
刚开始做聚合缓冲区时,我直接从堆上new 64KB的缓冲块,用完之后delete。在高频打点场景下,每秒要分配释放成千上万块,带来的后果是:上层的用户态堆锁成了新热点,同时内存碎片导致TLB命中率下降。
后来我们实现了一个定长内存池:预分配一大块连续地址空间,切成固定大小的缓冲块,用freelist管理。每块带一个32位引用计数,生产者写入时引用计数原子+1,压缩线程取走时原子-1,归零后自动归还池子。
这个改动让单次缓冲块获取/释放的开销从接近微秒降到了十几纳秒,而且因为所有缓冲块地址在内存里是逼近的,CPU缓存命中也变好了。注意,这是定长池,缓冲块大小是统一64KB,换变量长的池子复杂度会高很多,收益却不明显。
3.2 格式化阶段就避免额外拷贝
优化执行路径不能只看压缩那一段,日志产生到压缩之间可能还存在多余的拷贝。我见过不少日志组件,业务线程先格式化成std::string,再拷进缓冲块,再交给压缩,光字符串拼接就折腾了两三次。
BqLog的做法是:业务线程直接把格式化结果写入缓冲块。我们对压缩日志提供了一个专门的轻量API,用户传入格式化字符串和参数,底层在缓冲块的末尾预留区域,用类似writev/iovec的方式,把不同数据段直接落到缓冲块内部,而不产生中间临时对象。
这样做还有一个隐藏好处:减少了业务线程的内存带宽压力。对游戏这种大流量场景,内存拷贝往往是瓶颈,省一次memcpy,比优化几行算法实在得多。
3.3 零锁时间戳与日志级别检查
执行路径上每一个看起来不起眼的操作,频率高了都会放大。例如获取当前时间戳,直接调用系统调用在有些平台上耗时不低,而且会切换上下文。普通日志路径上我们精确到微秒没问题,压缩日志本来就要攒批发送,精度稍有损失也可以接受。
这里我的做法是:用另一个后台线程每10ms刷新一次缓存时间,压缩路径上的日志统一读这个缓存值。代价是时间精度最多偏差半个刷新周期,也就是5ms左右,但换来的是每条日志节省一次系统调用。在对局录制、回放场景,5ms精度完全够用。
日志级别判断同样优化过:普通if分支改成位掩码判断,避免分支预测失败。特别当大量日志因为级别低于阈值被过滤时,这两条细节指令的差别在百万次调用下会非常明显。
4. 优化前后的实测数据对比
4.1 压测场景与方法
我在三套环境里分别做了压测:
- 单线程高频打点:每秒连续打10万条20~80字节的日志;
- 多线程并发打点:8个业务线程同时打日志,日志长短混合;
- 真实对局录制场景:按游戏帧率40ms一帧,每帧产生若干条关键事件日志。
系统配置是双路服务器,不过为了贴近移动端,特意用taskset绑定了4个核跑业务线程,压缩线程单独绑一个核。记录指标包括吞吐量(条/秒)、P99延迟、压缩率、CPU占用增量。
4.2 数据对比
| 指标 | 优化前(逐条压缩) | 优化后(批量流水线) | 提升幅度 |
|---|---|---|---|
| 单线程吞吐量 | 21万条/秒 | 87万条/秒 | 约4.1倍 |
| 8线程并发吞吐量 | 52万条/秒 | 276万条/秒 | 约5.3倍 |
| P99延迟(业务线程) | 412微秒 | 87微秒 | 降低78.9% |
| 日志压缩率 | 2.2:1 | 3.9:1 | 提升77% |
| CPU占用增量 | 全核12.5% | 全核7.3% | 降低41.6% |
单线程提升比较明显,多线程提升更夸张,原因就是原来的共享输出缓冲锁在多线程下被极度放大。P99延迟更能说明问题:优化之后的执行路径上,业务线程基本只做一次内存写入和一个原子操作,几乎感知不到压缩的存在。
有一点要说明,优化后的吞吐量还没到压缩算法的上限,因为压测时我们还守着“不能抢占渲染线程”的红线,刻意限制了压缩线程的频率。如果放开限制,数据还能再高,但对我们来说没有意义。
4.3 真实对局录制下的稳定性
光看峰值没用,还得看稳定性。我们在真实对局录制中监测了压缩路径的CPU曲线,优化之前每过几秒就会有一个很高的尖刺,对应着锁唤醒和大内存分配。优化后曲线平稳了很多,最大值和平均值之间的差距缩到了5%以内。
这恰恰是游戏场景最看重的:不要峰值有多好,就怕关键时刻抖一下。批量流水线把一个不确定性的间歇操作变成了稳定的持续小开销,从体验上讲这是一个质变。
5. 落地过程中踩过的坑:缓冲区阈值与线程管理的“玄学”
5.1 缓冲块越大不代表越好:内存膨胀的教训
第一版把本地缓冲块设为256KB,想着大块能进一步减少提交频率,压缩率也能更高。结果高并发下每个线程持有两个块,8个线程就有4MB内存被占住,日志组件本身成了内存大户,直接触发性能监控报警。
更麻烦的是,大块内存更容易出现缺页和TLB压力。后来我把块大小一降再降,最终定在64KB,对应到一个普通分页大小的一半多点,分配和访问都更友好。这里有个经验:缓冲块大小不要随手拍,要结合内存页大小、常见单条日志长度和压缩库的字典窗口来选。
5.2 提交阈值过低,压缩算法“消化不良”
一开始为了追求实时性,我把提交阈值设为8KB,意味着缓冲块刚到8KB就触发一次压缩。结果压缩率只有2:1,而且压缩库的调用次数暴增,CPU开销反而更大。
用500MB真实日志数据扫了一轮阈值后发现:16KB以下压缩率几乎线性增长,16KB到64KB增幅放缓,64KB后再加大收益也有限。我把阈值定在48KB,是考虑了压缩率和实时性的折中:平均最多攒几千条日志才需要等几毫秒,玩家根本感知不到。
5.3 压缩线程的优先级和亲和性不要乱调
最初我想让压缩线程更快地处理数据,就把它的优先级调到最高,核心不绑定,结果它频繁抢占CPU时间,渲染线程出现可感知的掉帧。后来改为:压缩线程绑定到一个独立物理核,优先级保持默认,只保证它在任何情况下都不会被饿死。
绑定核心之后还有个额外好处:压缩线程的缓存不会再被其他线程的上下文切换污染,压缩吞吐又提升了一截。不过绑定核心要小心机器核数不足的情况,我们通过配置在运行时判断如果逻辑核心数小于4就不绑定,只降低压缩线程的调度周期。
| 坑位 | 表现 | 原因 | 解法 |
|---|---|---|---|
| 块过大 | 内存占用翻倍,TLB miss | 每线程多个大块,内存碎片化 | 64KB定长块配合内存池 |
| 阈值过小 | 压缩率低下,CPU高 | 压缩字典未建立,算法膨胀 | 阈值调至48KB |
| 优先级乱调 | 渲染线程掉帧 | 压缩线程抢占关键线程 | 绑定独立核+默认优先级 |
6. 后续还能从哪些地方继续抠性能
6.1 压缩库的选择与参数调优
目前我们用zstd为主,因为它在压缩率和速度之间平衡最好。但zstd的参数并没有用默认值,我们特意关闭了checksum,开启数据字典缓存,并把压缩级别设为3。实测在游戏日志这种重复模式较多的文本数据上,比默认配置速度提升了约30%,压缩率只损失5%。
不过压缩库的升级对性能影响很大,我们做了一整套回归压测脚本,每次升级都会跑一遍上面的基准数据。这也说明日志路径优化是个长期迭代的事,不是改完就完。
6.2 刷盘路径的进一步优化
压缩日志最终要落到磁盘,但磁盘IO本身也是一条执行路径。我们现在用的是顺序写+按固定大小分文件,最大化利用磁盘带宽。后续考虑在文件头预留索引区,避免回放时全量扫描,这能进一步减少IO路径上的CPU消耗。
6.3 分级丢弃:不做无意义的压缩
对局日志里其实有大量低价值信息,比如AI调试日志、技能测试日志。如果全走压缩路径,再优化的流水线也在浪费资源。我目前的做法是:在入口处用优先级标记,只有达到关键级别的日志才进入压缩缓冲;级别不够的直接丢弃或不写入文件。这让实际线上场景的压缩量减少了四成以上,等于又给主路径让出了一大块性能预算。
如果你也在优化类似的日志组件,我特别建议把上面这最后一招想明白:日志的价值是有等级的,执行路径优化的终极目标不是让所有日志都快,而是把有限的性能花在值得保留的数据上。这一篇我们聊的都是压缩执行路径上“怎么省时间”的技巧,但真正让我受益最大的,反而是先想清楚“哪些日志根本不需要省时间”这个前提。对BqLog来说,压缩路径的优化还没到终点,至少刷盘和索引还有挖掘空间,留着下次继续聊。