作为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:13.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来说压缩路径的优化还没到终点至少刷盘和索引还有挖掘空间留着下次继续聊。