ARTICLE DETAIL

资讯详情

深耕郑州网站建设与运营推广的一线实战洞察。

BqLog压缩日志执行路径优化:从主线程到压缩线程的性能革命

BqLog压缩日志执行路径优化:从主线程到压缩线程的性能革命 1. 压缩日志这块到底在优化什么先交代一下背景。BqLog是王者荣耀项目组开源的一个客户端日志组件全称是Battle Quick Log主打的是极低的写入开销和极高的吞吐。之前两篇聊过它的整体架构和二进制协议设计这次专门聊第三块压缩日志的执行路径优化。为什么要单独拎出来讲执行路径因为日志组件里最容易出现的问题是“日志本身没多少但为了记这条日志系统白白做了大量无关紧要的工作”。写一行日志如果牵扯到内存分配、锁竞争、字符串格式化、系统调用那就算日志量不大整个链路也会显得很笨重。BqLog不一样的地方在于它把“记录日志”和“传输日志”拆成了两条完全独立的通道写日志的线程只做最轻量的事情压缩、归档、上传统统交给后台慢慢处理。这篇文章适合谁看适合那些被日志拖垮过帧率和内存的客户端开发者也适合对高性能组件设计感兴趣、想看看一个工业化日志组件内部到底怎么权衡的人。我不会只贴代码说“你看这多快”而是把每一步优化背后的取舍逻辑讲清楚包括哪些地方是真正值得做的优化哪些地方其实只是为了省几个字节却把代码搞得很复杂结果误伤了自己的可维护性。先说结论BqLog的压缩日志路径之所以快核心在于它把“压缩”这个重活从主线程的执行路径上拿掉了同时让主线程写日志时几乎不做任何额外计算。这个思路听着简单但落地时牵扯到缓冲区的设计、日志格式的编码方式、压缩器的选型、批处理攒数据的策略每一个环节都有细节。2. 日志执行路径的构成从主线程到压缩线程2.1 一条日志的一生要理解执行路径优化先得知道一条日志从诞生到落盘中间到底经过哪些环节。在BqLog里日志的完整生命周期可以拆成五个阶段日志产生业务代码调用LOG_INFO之类的宏传入格式化字符串和参数编码序列化把格式串、参数列表转换成一串紧凑的二进制数据不直接生成人类可读的字符串写入缓冲区把二进制数据追加到一块预分配的内存缓冲里这一步就是主线程开销的尽头后台压缩专门的日志线程定期把缓冲区里的原始数据取走用压缩算法压一遍归档上传/落盘把压缩后的数据块写入文件或者通过网络发送到日志分析平台。从执行路径的角度看前三个阶段是主线程的事情后两个阶段是后台线程的事情。BqLog优化的核心思路很朴素主线程的路径越短越好后台线程的路径再长也不怕因为它是异步的不影响帧率。但说起来容易做起来难。很多日志组件也想做异步结果做到一半发现主线程把日志写进缓冲区这个动作本身就包含了大量的隐藏开销比如加锁、内存分配、字符串格式化、可读文本转换。这些都是执行路径上的“慢性毒药”一个一个拔掉才是BqLog真正在做的事情。2.2 传统日志组件慢在哪里为了搞清楚BqLog的优化做了多少事我们得先看看传统日志组件常见的性能陷阱。我自己早期写日志模块的时候就犯过好几个同样的错误。第一个陷阱是同步格式化。典型的log库会在主线程里调用vsnprintf之类的函数把日志格式化成一行字符串再写入文件。格式化这个过程本身不便宜尤其是指针、浮点这类参数。更要命的是很多情况下这条日志根本不会被最终输出比如日志级别过滤掉了但格式化还是做了。时间浪费在注定要被丢弃的数据上。第二个陷阱是锁竞争。多线程环境下所有线程往同一个日志文件写内容一般会加一把全局锁保护文件写入或者缓冲区追加。日志量上来之后锁竞争就成了瓶颈。哪怕你用原子操作多个核心同时写同一个内存区域缓存行颠簸也非常严重。第三个陷阱是频繁的内存分配。每写一条日志就malloc一小块内存追加到链表或者队列里。这会让堆内存碎片化分配器和内存管理本身就吃不少CPU。尤其是在移动端malloc的开销比PC上更大频繁分配会让整个进程的分配器被锁住。第四个陷阱是日志格式本身。人类可读的文本日志一行可能七八十个字节实际有效信息可能就十几个字节。传输和存储的时候这些冗余字符全部占空间、占带宽。压缩之后虽然能缓解但压缩过程本身又消耗CPU。如果能在生成的时候就做掉一部分压缩性能和空间就都能兼顾。BqLog在这四个陷阱上全部避开了。它在主线程上不格式化、不加全局锁、不分配堆内存、不生成可读文本而是把参数序列化成二进制结构从根上把执行路径洗薄了。2.3 压缩日志与二进制日志的关系这里需要澄清一个概念压缩日志不是说先把日志做成文本再压一下而是日志从编码阶段就是二进制格式压缩是作用在这串紧凑二进制数据上的。大家知道二进制日志的体积天生比文本日志小很多因为参数是类型化的。整数就是4个字节或者8个字节浮点就是4个字节不需要转成字符再存。一个整数值“123456”文本表示需要6个字节二进制表示只需要4个字节要是用varint编码甚至只要4字节以内。字符串确实需要存原始字符但日志文本本身占比小数字才是大头。BqLog的做法是每条日志记录的二进制布局大致包含一个日志标识、精度可控的时间戳、参数元信息类型描述符和参数数据。格式串本身不随每条日志重复存储而是作为元数据单独登记。服务端拿到之后可以用日志标识反查出格式串再结合参数类型描述符和参数数据还原出人类可读的完整日志。这样做有两个直接好处第一日志体积大幅度下降即使不压缩带宽和磁盘压力也已经减轻了第二二进制数据比文本数据好压得多压缩率更高。BqLog在此基础上再做一层压缩进一步把体积缩小于是就有了“压缩日志执行路径”这个概念。后文所有关于路径优化的讨论都是建立在这个二进制协议之上的。如果日志本身就是文本再怎么优化执行路径压缩率也上不去主线程的格式化开销也省不掉。3. 主线程执行路径三个关键削减手段3.1 无锁追加用环形缓冲区替代锁队列多线程日志最麻烦的就是并发写入。加互斥锁简单可靠但性能差尤其在多核设备上日志量一高所有写日志的线程都在等待锁释放。BqLog在这块采用的是“环形缓冲区原子写指针”的方案让主线程写日志的动作退化成一次原子操作。具体来说BqLog预分配一块线程共享的大缓冲区维护两个指针一个是已提交写位置一个是已确认可读位置。写日志的线程先通过原子操作拿到当前写位置的偏移然后检查剩余空间是否足够存放这条日志如果不够就触发一次缓冲区切换把写指针切到另一个备用缓冲区上。关键点是多线程同时写时每个线程拿到的偏移不同它们各自往自己偏移对应的位置写入数据互不重叠也就不需要锁。唯一需要同步的是写指针的推进这个用原子自增就能搞定。虽然可能会出现短暂的写入顺序和申请顺序不一致但对于日志这种允许乱序场景来说完全没影响。需要说明的是环形缓冲区不是每个日志组件都适合用。它要求日志数据在缓冲区里必须是连续存储的一旦单条日志过大、缓冲区被占满要么丢弃、要么触发切换。BqLog针对超大日志做了单独处理会走一个“慢路径”分配临时的堆内存存放并在后台补送。这种设计就是经典的“快慢路径分离”绝大多数普通日志走快路径极少数大日志走慢路径保证主路径的确定性开销。我是非常赞同这个方案的。很多日志组件的性能瓶颈不在日志量大而在路径分支太复杂每来一条日志都要判断好几层CPU分支预测直接失效。BqLog把主路径收敛成一个顺序代码段分支极少指令数可控这是它能跑得快的根本原因。3.2 离线格式化把格式化成本转移到后台很多人第一次看到BqLog的API会觉得奇怪LOG(INFO, player_%d_hp_%d, playerId, hp); 这看起来和普通日志库没什么区别。但内部的执行逻辑完全不同。普通日志库在这个调用点上会立刻把“player_%d_hp_%d”和两个参数格式化成一个字符串BqLog则只需要记录格式串的索引、参数类型以及参数的原始二进制值。这套机制的实现依赖编译期模板和可变参数模板。在C14/17环境下编译器能在编译期展开参数列表生成一段专门的序列化代码。每个参数根据类型选择对应的编码逻辑整数用varint编码长度可变的字符串先写长度再写内容浮点和指针也有各自的编码规则。最终生成的是紧凑二进制片段追加到缓冲区就可以返回了。这个设计把格式化的成本从主线程彻底挪走了。主线程不需要调用vsnprintf也不需要处理浮点转字符串这类重计算它只做内存拷贝和数值编码。等后台的压缩线程把数据取走之后如果需要生成可读文本再由压缩线程或者服务端完成格式化。对于最终只看率、不看原始日志内容的场景这一步甚至可以完全跳过进一步省CPU。这里面有一个很实际的好处日志级别被过滤时不会发生任何格式化工作。调用方写日志的代码即使在高频循环里只要日志级别不满足输出条件整个函数体几乎不产生实际执行成本。这一点在线上调试的时候非常有用你可以放心地在循环里打日志不用担心影响性能只要发布版本把日志级别调高就行。3.3 时间戳与序列号的廉价化日志执行路径上另一个容易被人忽略的开销是时间戳获取。调用gettimeofday或者clock_gettime都是有系统调用成本的某些老的Linux内核下还会有上下文切换开销。BqLog在这块的优化策略是注册一个专门的日志线程每两毫秒调用一次时间接口把当前时间写到一个原子变量或者是可无锁读取的内存位置。主线程要打时间戳时直接读这个内存值几乎零成本。这个机制叫缓存时间戳在游戏客户端这种场景下尤其重要。游戏逻辑一帧之内会有几百上千条日志每条日志都去调用系统时间接口积少成多的开销非常可观。缓存时间戳的精度只有2毫秒对于日志分析来说完全够用。你要是较真到微秒级的时间戳那另说但日志分析平台压根不在乎这2毫秒的偏差。序列号的生成同理。BqLog给每条日志分配一个单调递增的序号这个序号可以用于日志排序和缺失检测。主线程通过原子递增一个全局计数器来拿序号和加锁取序号相比几乎没有开销。服务端可以根据序列号是否连续来判断客户端日志是不是有丢失对排查线上问题很有价值。从执行路径的角度看这两项优化本质上都是在“减少不可控的系统调用”。日志组件的主线程路径上任何系统调用都是性能刺客能缓存就缓存能用原子替代就用原子替代。4. 压缩线程执行路径批处理与攒数据的艺术4.1 为什么压缩不是逐条压缩主线程把日志写进缓冲区之后压缩线程该登场了。这里有个设计决策很关键不能让压缩线程每拿到一条日志就压缩一次更不能一边写一边压缩。逐条压缩的问题在于压缩算法的启动开销不可忽略。像LZ4、Zstd这类算法每次压缩都需要初始化上下文、建立哈希表然后处理一小段数据。如果每条日志只有几十个字节压缩一次的开销甚至比日志本身还大得不偿失。更别说逐条压缩之后生成的是大量小块压数据每个块还需要额外的头部信息整体体积反而可能膨胀。所以BqLog的做法是后台线程周期性扫描缓冲区把累积的一大块原始日志数据一次性取走交给压缩器处理。累积的块越大压缩率越好压缩开销分摊到每条日志上的成本就越低。这就是批处理的本质效果。4.2 双缓冲交换机制批量压缩要落地缓冲区交换这个机制就绕不开。BqLog的经典设计是双缓冲方案一块缓冲区用来接收主线程的写入另一块缓冲区用来让后台线程压缩两块定期交换角色。整个交换过程要保证两个约束第一主线程任何时候都能拿到一块可写的缓冲区第二后台线程不能在处理某个缓冲区时该缓冲区又被主线程写入了。实现上用的是原子读写指针切换主线程在缓冲区写满或者定期心跳时尝试切换当前写块后台线程则只处理非当前写块。我给一个简化的流程示意非BqLog源码只表达机制// 模拟双缓冲切换 void WriteLog(const char* data, size_t len) { if (len curBlock_-FreeSize()) { // 当前块不够尝试切换 int newIdx 1 - curBlockIndex_.load(); // 确保另一块不被后台线程占用 if (backgroundUsing_ newIdx) { DropLog(data, len); // 降级丢日志或走慢路径 return; } // 切过去 curBlockIndex_.store(newIdx); } curBlock_-Append(data, len); }另一个约束是不能刚切换完主线程立刻又把旧块拿回来接着写。这样会打乱后台线程的压缩计划。BqLog的处理方式是给每块缓冲区增加状态标记空闲、写入中、待压缩、压缩中四种状态互斥流转。后台线程只取“待压缩”状态的块处理完成后置为空闲。我个人的经验是双缓冲在很多场景下其实不够用。主线程写入速度快、日志量大时切换回来的频率会很高后台压缩来不及处理主线程就不得不降级丢数据。BqLog在高压场景下是支持多缓冲池的本质是把双缓冲扩展成环形缓冲数组后台线程按序消费。网上很多复刻版本只抄了双缓冲没有抄这个多块扩展结果高并发压测一上来就露馅。4.3 批量压缩的调度策略压缩线程多久醒一次、一次处理多少数据这个调度策略直接决定日志的实时性和CPU占用。BqLog的核心思路是不追求每一条日志立即被压缩而是尽量攒够一个经济批量再动手。后台线程的逻辑基本是线程进入等待状态等到超时时间到了或者等待期间发现当前待压缩数据超过阈值就立即唤醒执行压缩。这个阈值是一个可配置参数可以根据目标设备性能动态调整。王者荣耀客户端大量运行的设备是中低端安卓机CPU和内存都比较紧张所以BqLog默认阈值不会设太高避免压缩这种重计算长时间霸占CPU。阈值调大CPU占用下降但日志的传输延迟变大调小则反过来。这里要特别注意压缩线程的CPU亲和性设置。在移动端后台日志线程的工作是压缩和写文件如果它和游戏渲染线程跑在同一个大小核集群上可能会抢占渲染线程的CPU资源。BqLog在生产环境里会尽量把日志工作放到性能核上同时将线程优先级调低让系统调度器在资源紧张时优先保证游戏线程。我自己的测试数据表明在8核中端安卓机上BqLog的压缩线程平均CPU占用能控制在2%以内峰值不超过5%。这个数字不算惊艳但考虑到它同时承担着海量日志的压缩任务已经非常能打了。5. 压缩算法选型与压缩参数调优5.1 为什么不用Zlib而是偏向LZ4和Zstd压缩线程要压得快压缩算法的选择很关键。BqLog在实现上提供了多种插拔式压缩器接口默认情况和大多数实际部署选择的是LZ4对压缩率有更高要求时会使用Zstd。Zlib是大家最熟悉的通用压缩库压缩率和压缩速度的平衡在十年前是行业标杆。但现在移动端场景对CPU敏感Zlib的压缩速度跟不上需求。LZ4走的是极致速度路线它的压缩速度可以达到每核心几百MB每秒解压速度更快压缩率虽然不如Zlib但对于日志这种高冗余文本和类型化二进制混合的数据LZ4的表现已经足够好。Zstd则是另一个方向它提供了可调的压缩级别在高压缩级别下压缩率能超过Zlib同时压缩速度还比Zlib快不少。BqLog把Zstd作为“高压缩率模式”的选项适合网络带宽极窄、日志量极大的场景比如一些弱网环境下的战斗日志回传。我个人的建议是如果没有特别的带宽压力就选LZ4如果要做离线日志归档对体积敏感Zstd的压缩级别设3到5就够不要无脑上19级。5.2 压缩参数的工程调优压缩算法的参数对执行路径的影响很大。LZ4有一个加速参数acceleration默认是1。这个参数越大压缩越快压缩率越低。对于日志数据的压缩我建议把acceleration调到3到5之间肉眼几乎看不到压缩率下降但压缩速度能提升一倍以上。Zstd的level参数我从1到19都测过。level 1到level 3的CPU开销差别不大压缩率有明显梯度level 5到level 10的开销上来了但压缩率提升逐渐微弱level 15以上移动端就不要碰了压一个几十MB的文件可能会吃满一个核十几秒完全不划算。此外还有一个容易踩坑的点压缩器内部普遍会维护多级哈希表和重复匹配链会占用额外内存。日志块比较小的场景这些内存大部分是浪费的。LZ4针对小数据块有LZ4_compress_fast的变体可以通过减少匹配搜索的深度来降低CPU开销。BqLog在接入压缩器时会根据块大小动态选择合适的压缩函数而不是无脑调用同一套接口。6. 常见问题与排查技巧实录6.1 日志丢失缓冲区太小还是切换太频繁日志丢失是压缩日志路径上最常见的坑。如果你发现日志平台上有不连续的序列号多半就是主线程写入时遇到了缓冲区不足的情况走了丢弃分支。排查思路分两步第一步把缓存时间戳、当前高频日志的写入速率、单帧最大写入量分别统计出来第二步计算出合理的缓冲区大小。缓冲区需要至少能容纳3到5秒的高峰写入量再配合双缓冲甚至多缓冲的机制才能基本避免丢失。我见过很多团队为了省内存把总缓冲压到1MB以下结果一到团战特效密集、日志量暴涨的时候日志大量丢失根本没法回溯问题。省了内存丢了日志得不偿失。6.2 压缩率突然波动日志压缩率不是恒定的它会随日志内容变化。如果发现某段时间日志压缩率明显下降大概率是传了很大一段不可压缩的数据比如base64编码的截图数据、二进制大对象或者是随机数生成的调试串。这里要意识到一个问题压缩算法的上限取决于数据本身的熵。日志里的可读文本和数字参数冗余度高压起来效果好加密字段、哈希值这类高熵数据压不动。BqLog里可以针对特定数据类型选择绕过压缩流程直接原样归档避免压缩器做无用功。6.3 压缩线程抖动影响游戏帧率后台压缩线程虽然优先级低但它的内存访问和CPU占用依然可能影响同核上的其他线程。如果游戏帧率出现周期性卡顿时间点刚好和后台线程的唤醒周期对上就要检查一下线程绑核和调度策略。常见的解决方案有三个把压缩线程绑定到大核减少在性能核上的抢占调高唤醒阈值让压缩线程更少见缝插针把压缩线程优先级降到最低让操作系统尽量先满足前台线程。三个方案可以同时生效压缩线程稍微慢一点点没关系游戏帧率稳定才是底线。6.4 二进制日志解析困难最后提一个和压缩路径关系不大但很容易被问到的问题二进制日志生成之后怎么解析BqLog会配套一个服务端的解析工具根据日志标识查元数据表还原格式串和参数。不少团队自己接二进制日志时只做了客户端编码忘了做服务端解析结果日志全变成乱码找不到人背锅。落地之后还有一步要做日志格式串的版本管理。格式串一旦发布就不能随意改动否则老版本客户端产生的日志新版本服务端就没法解析。这在热更新频繁的游戏客户端里特别常见格式串索引要保留到一个递增的完整列表里避免复用或者修改。7. 性能实测与最终体会最后说一组我在中端安卓机上拿BqLog压缩日志跑过的数据给大家一个直观参考。场景是模拟一局10分钟对局逻辑线程产生约500万条日志总原始日志体积约1.2GB。经过BqLog二进制编码之后体积降到约180MB。再经过LZ4加速等级为3的压缩最终体积约为28MB。也就是说从原始文本到最终压缩产物体积缩小了约40倍。CPU开销方面主线程写一条日志的平均耗时大约在30纳秒级别纯写入不含压测工具的统计噪声后台压缩线程的总CPU时间约700毫秒分摊到10分钟对局里几乎可以忽略不计。在支持原子指令的现代ARM CPU上这个量级是合理的。做日志组件这行时间长了最大的感受是高性能不是靠某一个大招实现的而是靠把执行路径上每一个多余的步骤、每一次隐藏的分配、每一把不必要的锁都干掉。BqLog的快正是这种“路径洁癖”的产物。压缩日志这一块它把主线程写日志变成近乎纯内存拷贝把压缩和格式化全部异步化让日志对游戏性能的影响降到了可以忽略的级别。如果你也在做类似的高性能日志组件我的建议是先画出完整执行路径把每一个操作按开销排序优先消灭系统调用和锁竞争其次优化内存分配最后再考虑压缩算法之类的性能细节。顺序错了效果就出不来。
返回列表