
最近团队里来了个新人第一次看到BqLog这个名字问我“你们是不是又在造轮子日志库不就是printf加个文件追加写吗”我没急着反驳第二天给他看了一台测试机上某次对局结束后的日志目录——一局20分钟的常规对局原始日志量接近两百MB。他沉默了几秒补了一句“那玩家手机存储怎么扛得住”这就是BqLog最早被逼出来的场景。王者荣耀这种大型多人在线对战游戏战斗同步、技能结算、视野逻辑、AI行为、资源加载全要记录常规对局几十MB到一百多MB的日志是常态加上多模块同时打点峰值还会更高。BqLog不是什么“为了做组件而做组件”的产物它要解决的核心问题很朴素日志能不能在写进闪存之前就完成压缩把磁盘占用、写入带宽、上传成本一口气降下来。这个系列的第一篇我就先把BqLog高性能实时压缩这条主链路拆开讲。内容会涉及为什么必须在写入路径上动刀、压缩怎么嵌入异步日志模型、算法为什么选LZ4而不是压缩率更高的Zstd以及我们在上线过程中踩过的几个经典坑。对游戏客户端、移动端基础组件或者任何一个需要处理日志体积问题的场景这些思路应该都能直接抄作业。1. 日志膨胀的现实代价为什么非要在写入路径上动刀先说一个反常识的事实日志系统在大多数项目里是被遗忘的直到“存储满了”或“崩溃问题追溯不到”才有人想起来。做BqLog的第一件事不是写代码而是把日志膨胀的代价量化给各方看。1.1 三个环环相扣的代价第一个代价是磁盘占用。现在中低端玩家的手机存储依然以64GB、128GB为主游戏本体加更新包已经占掉一半再让日志每局吃掉100MB玩家打不了几天就会被系统提示“存储空间不足”。存储占用是性价比极低的流失隐患——玩家不会因为你做得好而留下但会因为手机卡顿、空间告警而卸载。第二个代价是闪存写入带宽。移动端闪存的写入带宽和写寿命都是稀缺资源日志高频小I/O会跟资源加载、存档写入、合入更新时的解包操作争抢IO。早年我们试过在日志全量打开的情况下跑整局测试能直接从帧率曲线的P99上看到毛刺。日志系统引起的掉帧说出去都丢人但它真实发生过。第三个代价是上传分析成本。玩家遇到问题后要把日志传回后台原始日志一张上百MB弱网环境下传个几十分钟都正常绝大多数玩家会在进度条卡住时直接放弃。日志进不到后台崩溃问题和卡顿问题就全部失去现场这个损失比日志占空间本身更致命。因为相比存储告警更糟的是你手里根本没有可供分析的数据。这三个代价叠加结论就很清晰了日志必须在写盘之前就瘦身。哪怕压缩会额外消耗一点CPU只要CPU开销可控换来的存储、IO、上传三方面收益都是实打实的。1.2 离线压缩、透明压缩、实时压缩三条路的取舍如果只是嫌日志文件大最直觉的方案是“先全量写明文退出时后台统一压缩”。这个方案的优点是实现简单缺点是写入路径上的IO一点没省磁盘峰值占用依然处于爆炸状态。更麻烦的是时间窗口不可控玩家打完一局可能直接杀进程后台压缩任务根本等不到执行时机偏偏问题最多的对局日志量往往也最大。这个方案很快被否了。还有一种方案是依赖文件系统层的透明压缩某些ROM的存储优化功能会默认压缩文件。但它的致命问题在于压缩策略完全不受应用控制我们没法指定按固定块压缩、没法加入日志时间索引、没法保证分析端拿到的文件解压方式一致。说白了做日志组件最怕的是管道下游不可控透明压缩这个黑盒不适合作为正式方案。剩下就是实时压缩日志还在内存里的时候按块累积到一定大小触发一次压缩把压缩后的数据再写进文件。BqLog走的是这一条。它把“写原始大文件”的IO和磁盘成本真正降了下来代价是占用少量CPU。CPU能不能省回来后文专门讲优化。先记住这个大方向实时压缩的本质是用可预测的小额CPU去换大头IO和磁盘。2. 实时压缩的载体BqLog写入链路的四段式设计光有压缩算法不行关键是怎么把它嵌进日志写入链路又不拖累业务线程。2.1 从业务线程到压缩线程一次日志的完整旅程BqLog把一次日志写入拆成四段业务线程调用BqLog接口把日志格式化成一条带时间戳、模块ID、等级信息的记录写入该模块专属的SPSC匿名环形缓冲。这里用的是无锁队列读端和写端各自只操作自己的head/tail索引。后台压缩线程作为消费端从环形缓冲批量取出原始字节流追加到一小块内存累积区。之所以强调“批量”是因为单次要尽量多取减少线程唤醒次数。累积区塞满一个Block默认64KB压缩线程一次性把它压成压缩块带上块头信息投递到文件写入队列。文件写入线程从队列拿到完整压缩块追加写盘必要时做刷盘。为什么不让调用线程直接压缩很简单的道理——日志接口可能被战斗逻辑、AI系统、网络模块在任意时间高频调用压缩是个有状态的重计算放进调用路径等于把不可控的延迟塞进游戏线程。用独立线程即使在低端机上压缩耗时也是被“藏”在后台的。这是异步日志组件的基本盘BqLog只是把压缩也完整搬到了这个异步模型里。2.2 为什么按“块”压缩而不是按“条”或按“流”按条压缩是最直觉的做法但没人会这么干每条日志几十到几百字节压缩头开销占比高一条条压压缩率也上不去纯属浪费CPU。按整个文件流压缩倒是压缩率最高但有两个隐患一是流式压缩一旦在某个位置写坏整条流从坏点往后全部解不出来二是想读取某个时间段的日志必须从文件头解压到目标位置日志文件越大定位成本越离谱。BqLog选择的是固定块压缩原始日志累积到64KB一压块与块之间完全独立。这个设计带来的好处是连锁的损坏隔离某一块的CRC校验失败只丢这一块日志前后块照常可解并行解压分析端拿到压缩文件后可以开N个线程同时解压N个块时间索引每个块天然带时间范围按时间范围定位只需找到对应块不需要全量解压内存可控最坏情况只需要准备一块原始大小加一块压缩产物大小的缓冲不会出现“解压整个100MB文件”的内存放大。块独立性这个决策直接决定了后续所有功能——索引、跳读、并行分析、局部损坏容错——都建在一个稳定的地基上。所以这块边界一定不要随手选它是日志组件一辈子的地基。2.3 空间阈值时间阈值双重触发保证“实时”不落空光有“64KB满就压”还不够实际运行里日志速率起伏很大。战斗高峰期几秒钟就能填满一个块但空载场景下可能一分钟都攒不够64KB。如果只按空间触发那些凑不满一块的日志就会长时间悬在内存里进程一旦被杀就全丢了。所以BqLog在空间阈值之外加了时间阈值默认1秒内即使没凑满64KB也会把现有原始数据强制压缩落盘。这个1秒既是延迟红线也是数据可靠性红线——最坏情况下崩溃前最多丢约1秒的日志尾巴。实际调优时把阈值放在0.5~2秒之间都可以看项目对日志实时性和内存占用两者的侧重。块大小也是同理64KB是我们在对局日志文本特征下折中的结果调到32KB可以让首块更快产生但压缩率会下降且块头占比变高调到128KB压缩率更好代价是解压单块时的内存峰值更大。3. 算法选型实录LZ4、Snappy、Zstd与Deflate的同场对比实时压缩的核心矛盾是CPU和压缩率的权衡。算法选型这一步我们真刀真枪用真实对局日志做过一轮基准测试。3.1 一份1GB真实对局日志的压测结果测试方法不复杂取一场接近真实对局的训练营日志剔除二进制大字段后约1GB的文本日志固定测试机型骁龙8系某工程机单线程跑压缩统计完整压缩耗时和产物大小。四种候选算法LZ4acceleration1、Snappy、Zstdlevel3、Deflatezlib level6。实测数据如下数值会随日志内容波动但量级有参考意义算法压缩率单线程压缩吞吐(MB/s)解压吞吐(MB/s)综合感受LZ4 (acc1)2.61x4621560压缩极快压缩率可接受Snappy2.67x386890表现稳定解压速度拉开差距Zstd (level3)3.42x2841120压缩率领先CPU开销偏高Deflate (level6)3.18x73286低端机小核基本跑不动一个很容易被忽略的细节游戏日志是文本模板堆出来的“进入对局”“退出对局”“坐标同步”这类重复串特别多所以LZ4的压缩率并没有比Zstd拉开想象中那么大的差距。如果日志里二进制数据占比升高双方差距还会进一步缩小。3.2 从实测到选型为什么最终选了LZ4表面上看Zstd压缩率领先明显3.42倍对比2.61倍但落到游戏场景里这个差距经不起推敲。第一CPU预算是硬约束。日志压缩线程不能占用超过一个后台小核20%~30%的算力否则低端机上会跟其他后台任务互相踩踏。Zstd在level3时已经是小半个核心的消耗量一旦进入高负载战场压缩线程很可能成为帧率波动的新变量。第二压缩率的“性价比”不够。LZ4的2.6倍已经解决了磁盘占用和上传体积的核心痛点从200MB降到76MB是质变从76MB再降到58MB是量变为了这点量变去冒帧率风险不划算。第三工程和维护成本。LZ4 block模式是BSD许可解压实现极其简单几十KB的代码做块级容错和处理部分解压很方便。Zstd的功能更强但框架状态也多嵌入一个需要长期稳定运行的客户端日志组件里引入的复杂度远大于压缩率收益。3.3 我们讨论过的“双算法方案”和最终放弃中途有同事提过一个折中高配机用Zstd、低配机用LZ4各取所长。这个方案听起来优雅落地时却发现是给自己挖坑文件格式要区分算法ID、各业务系统的解析端要维护两套解压链路、测试矩阵也要翻倍。日志组件从客户端到分析端是一条完整管道任何一端都要为每一个分支付出维护成本。最终我们决定统一使用LZ4把“格式恒定”当作高于极限性能的工程原则。这算是一个重要的取舍思路统一比极致更值钱。4. 把CPU开销压到最低的三层优化选完算法只是开始真正让“多花一点CPU”变成“基本感知不到”靠的是下面三层细节优化。这部分阅读起来可能比选型还重要因为坑都埋在这里。4.1 缓冲区池化所有权清晰的复用实时压缩一开最直接的内存压力来自压缩块缓冲区。如果每条日志来了都临时malloc再频繁还给系统GC和分配器开销会比压缩本身还贵。BqLog的做法是建两个对象池原始数据缓冲池和压缩产物缓冲池。启动时按默认上限预分配池内缓冲区通过状态机流转业务线程拿原始缓冲写入日志数据压缩线程从池中取原始缓冲填满后压缩产物放入产物缓冲原始缓冲在压缩完成后立刻还池压缩产物缓冲则由文件写入线程真正调用write()之后才还池。这里有一条核心原则谁最后用完谁负责归还。别在生产方“生产完”就还池。我们为此吃过不小的亏后面坑二会展开说。池化之后日志写入路径上的分配次数从每条一次降到接近零GC压力也大幅缓解。4.2 线程调度与大小核避让不能跟战斗线程抢CPU移动端的大小核架构让“后台线程”这个说法变得很暧昧。真后台线程和普通线程在同一个CPU簇上抢占资源照样会把帧率拖出毛刺。BqLog的做法是iOS上把压缩线程设为QOS_CLASS_BACKGROUNDAndroid上通过setPriority(THREAD_PRIORITY_BACKGROUND)放进后台组同时初始化时读取当前设备的CPU簇拓扑尽可能把压缩线程绑定到小核/低功耗核上避免和战斗线程抢大核。再加一个运行时看门狗如果压缩线程的平均处理耗时连续3秒超过预设阈值就自动把块阈值从64KB上调到128KB等负载降下来再恢复。这个动态退让机制专门防低端机高负载场景下的连锁反应——压缩变慢→内存积压→磁盘写入不及时→日志丢更多。在压测时我们对“开压缩”和“关压缩”两种状态做同场帧率对比P99差距控制在1ms以内才敢说这个方案对游戏体验无感。4.3 块索引表让压缩文件可以跳着读实时压缩省了运行时的开销但解压侧的成本也要管。一个100MB的压缩日志如果每次排查问题都要全量解压一遍分析效率会很差。BqLog的做法是每滚动生成一个日志文件时在文件末尾追加一个块索引表记录每个压缩块的文件偏移、原始长度、压缩长度、时间范围以及等级位图。这个索引表让分析端可以“跳着读”比如排查12:00:03~12:00:05之间的日志先二分定位时间范围命中哪几个块然后只解压目标块。实测定位时间从“解压整个文件”变成“解压十几个64KB块”快了不止一个数量级。而对写入端来说索引表只在滚动文件关闭时生成一次成本可以忽略。5. 实测数据与排障实录三个让人印象深刻的坑设计再完善实战里还是会踩坑。这一节先放一组我们实测的前后对比再讲三个把我逼到凌晨的坑。5.1 同场景下开启实时压缩的前后对比用同一段20分钟对局回放脚本在同一台工程机上做对比日志目录体积原始模式约218MBBqLog实时压缩后约76MB压缩比约2.9倍平均写盘带宽从约38MB/s降到约13MB/s压缩线程CPU约占0.3个后台小核模拟弱网8Mbps下的日志上传从约3分半降到约1分20秒。数据会随日志内容浮动但量级和趋势非常稳定。实时压缩没有引入新的掉帧热点P99帧率对比控制在1ms内这算是BqLog第一个版本能上线的基础。5.2 坑一块头只记压缩后长度解析端直接无能为力第一版块头结构很简单magic压缩后长度CRC。当时觉得足够用了结果写解析工具那天直接翻车——LZ4解压必须知道原始长度否则不知道解压目标缓冲区该开多大。虽然可以按一个上界硬开内存但那会浪费大量内存而且和块的实际原始长度对不上时CRC校验也会误导定位。后来块头统一改成定长20字节把原始长度、压缩长度、算法ID、标志位全部放进headertypedef struct { uint32_t magic; // BqLG uint16_t version; // 当前版本1 uint8_t algorithm; // 0: LZ4 Block uint8_t flags; // bit0: 首块, bit1: 末块, bit2: 加密预留 uint32_t orig_len; // 压缩前原始数据长度 uint32_t comp_len; // 压缩后数据长度 uint32_t crc32; // 压缩前原始数据的CRC32 } BqLogBlockHeader; // 固定20字节这个教训的核心是任何自描述格式头部字段宁多勿缺。特别是长度类信息少一个字段下游解析端就得靠猜。5.3 坑二池化缓冲区被过早还池导出文件大量损坏这是整个开发过程中最折磨人的一个问题。现象很奇葩单线程复现永远不出现多模块并发压测一段时间后日志文件里随机出现CRC mismatch而且损坏位置没有规律。排查链路很长最后聚焦到缓冲区的生命周期上。问了一个很简单的问题压缩线程压完数据、把压缩产物入队之后那个缓冲区去哪了答案是它立刻被还池了。但文件写入线程从队列里取到的是一个指针它还没来得及把这个缓冲区里的数据write到磁盘压缩线程的下一轮任务已经把这个缓冲区抢走去写新数据了——等IO线程真正落盘时内存里的内容已经被覆盖。修复方案也验证了这个判断压缩产物缓冲区的所有权明确归文件写入线程写入线程拿到队列节点、执行write()、确认数据不再被引用之后才允许还池。这之后CRC mismatch彻底消失。这件事让我对“内存复用”和“跨线程生命周期”的敬畏加深了不少日志组件里的每一个buffer必须能说清楚它在哪个线程手上、什么时候释放。5.4 坑三第一个压缩块比想象中慢冷启动窗口没覆盖上线前压测发现一个细节冷启动后第一条日志写入到实际落盘延迟比稳定态高出一个量级偶发能到300ms。一开始以为是系统IO抖动后来定位发现是压缩线程第一次跑压缩任务时对象池还没完成预分配触发了大量page fault加上压缩线程本身是低优先级被其它后台任务抢占就会更慢。解决手段也直接日志库初始化阶段用一份dummy数据把整条压缩链路完整跑一遍把池子的物理内存真正触碰一次而不是只做mmap等虚拟内存预留。这个预热动作把冷启动首块延迟拉回到正常水平。实时压缩里的“实时”必须覆盖冷启动窗口——只调优化参数是不够的温启动和冷启动完全是两个世界。写到这里BqLog关于实时压缩的主线基本算讲透了。说实话这个组件里的很多经验不是坐在工位上设计出来的而是被线上问题一步一步逼出来的。下一篇准备接着聊日志写入路径上的另一个大头——格式化与序列化为什么同样的日志代码在不同机器上性能差好几倍再后面还会展开崩溃缓冲区、日志加密这些话题。如果你也在自己的日志组件里折腾类似的事情欢迎一起聊。