ARTICLE DETAIL

资讯详情

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

压缩日志执行路径优化:从35微秒到6微秒的工程实践

压缩日志执行路径优化:从35微秒到6微秒的工程实践 开头先交代一下背景我之前写过两篇 BqLog 性能剖析一篇讲内存池怎么做到无锁分配一篇讲多线程写日志的批量刷盘模型。这一篇专门聊压缩日志这条执行路径。说实话刚开始我们把压缩能力接进去的时候心里是有预感的——普通日志路径再快压缩路径一进来之前省下的时间会吐回去一部分。原因不难理解压缩本质上是给日志写入链路加了一道“算力税”数据要经过压缩器的状态机、要拼装成连续字节块、还要保证解压端能还原这里每一步都是开销。但王者荣耀这种体量的线上客户端又恰恰离不开日志压缩——单局日志量动不动几十MB不压缩回传和分析的成本根本扛不住。这篇不是来介绍 BqLog 怎么用的而是把压缩日志的执行路径从“日志产生”到“压缩块落盘”整条链路拆开讲清楚每一环的时间都花在哪我们又是怎么把这条路径从“可用”压到“几乎察觉不到”的。适合正在做日志组件、或者做客户端埋点性能优化的朋友参考。1. 游戏客户端日志压缩不是选择题是必答题1.1 日志量膨胀后存储和回传先撑不住先摆一个实际场景。MOBA 类游戏一局对局客户端要记录战斗行为的细节、技能释放、伤害计算、网络同步事件、异常调试信息一场 20 分钟的对局全量日志写下来轻松突破 20MB。如果是长线运营的游戏每个版本还要面对大量玩家反馈“我这里闪退了”“我这里卡了一下”这时候日志就是唯一的证据。20MB 听着不多但放大到百万日活、每天产生 TB 级日志存储成本立刻变得扎眼。更麻烦的是回传——玩家网络环境复杂弱网用户占相当比例一个 20MB 的日志包回传服务器用户等不起服务器带宽也扛不住。压缩就成了必答题不是可选项。用通用压缩算法把 20MB 压到 5MB 左右回传时间直接砍掉四分之三这一下就把压缩日志从“加分项”变成了“硬需求”。1.2 全量压缩的三个收益与一个代价压缩日志带来的收益非常直接存储成本下降同样一个日志文件压缩后体积通常能降到原来的 25%~40%这对按容量计费的存储和日志平台来说是肉眼可见的成本节省。回传耗时缩短弱网环境下日志包传输耗时对用户体验影响很大压缩后数据量少了重传概率也降低。磁盘写入压力减轻移动端闪存写寿命有限频繁大流量写入会影响设备寿命压缩后单位时间写入字节数变少闪存压力跟着降。但代价也很明确压缩本身要消耗 CPU。在 PC 上这不算事可在手机上主线程和渲染线程 CPU 都是稀缺资源日志压缩不能抢游戏帧率。所以问题的本质变成了让日志压缩的 CPU 开销尽量低、延迟尽量小、并且不阻塞日志生产端。这也是“压缩日志执行路径优化”这一篇要解决的核心矛盾。1.3 普通路径与压缩路径的天然差异普通日志路径大致是这样一条链日志格式化 → 拷贝进内存池缓冲 → IO 线程攒批刷盘。整条路径上没有任何“算法”大量优化可以做在内存分配和批量拷贝上。压缩路径则长这样日志格式化 → 分组整理 → 压缩器编码 → 压缩块落地 → IO 刷盘。多出来的“分组整理”和“压缩器编码”这两步正是开销的放大器。另一个关键差异是普通路径的产物是“明文”大小是确定的所以环形缓冲区和固定块都能直接用压缩路径的产物是变长的压缩前你不知道这段数据到底会压成多大缓冲管理、块分割、索引组织全都变成了动态问题。这种不确定性会导致内存碎片、额外拷贝、边界判断开销——这些都是普通路径不会遇到的。所以压缩路径不是“普通路径加一个压缩函数”那么简单它是一个全新的链路设计问题。2. 压缩执行路径上的时间账单每一笔开销都要摊开看2.1 一条压缩日志的完整旅程优化之前我们先把整条路径逐段标出来用 profiler 数清楚时间到底花在哪。一条日志从产生到落盘压缩路径上的完整旅程是业务线程调用日志接口传入格式化字符串与参数。格式化把参数拼到模板里产出明文日志串。把明文日志串的字节拷贝到一个“待压缩收集区”。收集到足够数据后交给压缩器做编码。压缩器输出写入压缩块缓冲。压缩块按索引记录偏移、长度、时间范围。IO 线程把压缩块刷到磁盘。如果你直接把这套流程接进 BqLog会发现延迟账单非常离谱。我们用真实数据粗略算了一笔账一条普通 100 字节左右的日志走压缩路径平均耗时大约 35 微秒而普通路径只需要 5 微秒左右。这中间多出来的 30 微秒就是压缩路径的“时间税”。2.2 第一笔冤枉钱分片字节流的拼接拷贝先看步骤 2 到 3。游戏日志的典型特点是单条日志很小通常 30~200 字节不等但条数极多高峰期每秒钟要写几千到几万条。压缩器一次处理的数据量是有下限的——比如 LZ4 压缩 40 字节的数据光头部信息就可能占到输出的一半压缩率差到离谱。所以必须把一堆小日志收集起来拼成一个比较大的数据块再压缩。问题就出在这个“拼”上。最早我们实现时每来一条日志就把格式化后的明文串追加到一个 std::vector 或 string 后面。看起来挺简单但隐藏了两个开销vector/string 扩容时要把旧数据整体搬移一旦触发扩容这次日志写入的延迟会突然飙高产生尖刺。每条日志追加时都涉及一次字节拷贝日志条数多的时候这个拷贝总开销被放大到不可忽略。实测下来在高频写入场景下纯拼接这一步就占了压缩路径总耗时的 25%~30%。这还没算拼接区在内存里不连续、缓存命中率低的损失。那段时间我们在 profiler 里看到大量 memcpy 热点第一反应就是不能再这么拼了。2.3 第二笔冤枉钱压缩器状态机的重复初始化再看压缩本身。LZ4 和 zstd 这类压缩器都需要上下文对象context里面保存了字典、哈希表、窗口状态。如果你每次压缩一个块都重新创建一个 context立刻会踩两个坑一是内存分配。context 通常有几 KB 到几十 KB每次压缩都 malloc/free在高频小数据块压缩下malloc 的锁竞争和内存碎片会非常明显。二是状态初始化。新 context 的哈希表是空的压缩第一批数据时完全没有历史可以参考它的压缩率会明显低于“连续工作”的压缩器。这就像你每次写字都要重新铺纸研墨纸墨的重复准备时间远比写字本身还长。我们的 profiling 数据显示在高频小数据块场景下context 创建和销毁的开销能占到压缩环节总开销的 40% 以上。这个问题非常隐蔽因为单看一次 malloc 只要一两百纳秒但乘上每秒数万次的频率立刻变成 CPU 账单上的大头。2.4 第三笔冤枉钱线程模型带来的锁竞争如果压缩跑在日志生产线程里问题会更棘手。游戏的主线程、渲染线程、逻辑线程任何一个线程都可能打日志。多线程同时往“待压缩收集区”写入必然要有同步机制——互斥锁或者原子操作。互斥锁最直接但问题也很明显高并发打日志时锁竞争激烈线程会因为等待锁而阻塞这不仅拖慢日志写入还把延迟的方差拉得很大。最典型的现象是 P99 延迟飙升负责打日志的业务线程被卡在锁上进而影响游戏帧率。原子操作能解决一部分问题但收集区这种“边界不断动态变化”的结构只靠原子操作维护水位线也很别扭容易出边界竞态。压缩路径线程模型的正确做法不是“在锁上做优化”而是“绕开锁”。这个思路变化是后面优化的核心分水岭。2.5 优化前的性能基线记录一下优化前的基线数据方便后面对照。测试环境是骁龙 855 平台模拟器日志内容模拟真实游戏战斗日志单条平均 120 字节写入频率为每秒 20,000 条指标普通日志路径压缩日志路径优化前单条日志平均写入耗时5 微秒35 微秒P99 延迟12 微秒280 微秒压缩率不压缩约 3.2:1生产线程阻塞情况无偶发阻塞最长 1.2ms看这个表普通路径和压缩路径之间的差距是数量级的。压缩率 3.2:1 确实诱人但 280 微秒的 P99 延迟对游戏来说是不可接受的——一帧才 16 毫秒你一个日志打出 20% 帧预算这谁顶得住。所以压缩路径优化本质上是一道“既要压缩率、又要低延迟”的算术题。3. 三个层面的改造缓冲层、算法层、调度层3.1 缓冲层改造预分配块池 原位写入第一个改造点是去掉“拼接拷贝”。思路是不再把日志一条条 append 进一个动态增长的区域而是预先分配固定大小的块每个块 64KB块内部用一个写指针维护当前写入位置。业务线程格式化完日志后直接在块内的空闲位置原位写入写完后把写指针向前推进即可。这里有个细节值得展开固定块池的分配粒度变了。之前每条日志都要到内存池里申请一次小内存现在则是一次性拿走一块 64KB 的大内存后续几百条日志都往这块里写不再触发任何内存分配。块池本身用无锁队列维护拿块、还块都是轻量操作基本不产生锁竞争。我们还给每个生产线程配了当前活动块的缓存绝大部分日志写入连“拿块”这个动作都省了——直接写进线程自己的活动块就行。这个改造直接把路径上的“拷贝 分配”开销降到了接近零。原位写入的意思是格式化引擎直接把结果填进块里的目标位置不经过任何中间缓冲。你可以理解为以前是先把菜盛到碗里再把碗里的菜倒进大盆现在直接端着锅往大盆里倒少了一次倒手就少了一次搬运时间。固定块池还天然解决了压缩块变长的问题压缩输出按 8KB 小块切分最终一条大日志压缩后可能横跨几个 8KB 小块这些小块用链表串起来索引记录首块偏移即可。这样动态内存管理完全消失全部换成预分配。GC 没了malloc 没了内存碎片也没了。3.2 算法层选型速度优先压缩率取舍要有全局观第二个改造点是压缩器本身的选型。压缩日志场景和通用文件压缩有一个本质区别日志数据的“可压缩性”很规律——有大量重复的时间戳前缀、模块名、线程名、固定文案但正文部分又夹杂着随机变量ID、数值、坐标。这意味着我们不需要追求极限压缩率而是要找一个“在这个数据模式上又快又稳”的压缩器。我们实测对比过三套方案压缩器压缩速度压缩率适用性zlib慢高约 4.5:1CPU 开销太大不适合高频写入LZ4极快中约 3.0:1速度快但压缩率略低zstdfast 档快高约 3.8:1速度和压缩率平衡最好最终我们选了 zstd 的 fast 档压缩级别设置在 3 左右并把压缩器调成了“长期驻留会话”模式——同一个 context 反复复用字典自动积累。这样既继承了上一轮压缩的历史状态又能把压缩率稳定在 3.5:1 以上压缩速度比 zlib 快将近十倍。这里要给一个重要的提醒压缩率高不代表划算。如果你为了多 10% 的压缩率把 CPU 开销翻倍那这 10% 省下的存储成本可能还不够买功耗和帧率。对游戏客户端来说“压缩器不抢帧”永远比“多压 10%”优先级高。日志压缩追求的是在限定 CPU 预算内的最大压缩率不是绝对最大压缩率。这也是为什么我们不选 zlib 的原因——它在手机端的 CPU 账根本算不过来。3.3 调度层改造三级流水线生产线程零阻塞第三个改造点也是让 P99 从 280 微秒降到接近普通路径的关键线程模型改成三级流水线。第一级生产线程。只负责格式化日志并写入当前活动块。这里没有任何锁没有压缩没有任何可能阻塞的操作。第二级压缩线程。一个专用线程从“待压缩队列”里取块执行压缩输出压缩块。压缩线程要设置较低优先级避免和高优先级的游戏渲染抢 CPU但它又必须持续工作保证队列积压不会无限增长。第三级IO 线程。负责把压缩后的块刷到磁盘并在刷盘前维护压缩块的索引信息。这个三个线程之间用什么衔接答案是单生产者单消费者的无锁环形队列。每级之间各配一个队列队列元素是指针不拷贝数据。生产线程把活动块指针塞进队列就立刻返回压缩线程取走块后开始真正压IO 线程只认压完的块。这么做的效果非常明显日志生产端的耗时不再包含压缩耗时从原来的 35 微秒降到了大约 6 微秒。因为生产线程自己只做格式化 指针入队压缩时间被“甩”给了后台线程。这是时间账上的关键一步——不是把压缩做快了而是把压缩从“关键路径”上挪走了。关键路径一旦变短延迟的均值和方差都会大幅下降。三级流水线还有两个隐性收益。第一是 CPU 缓存友好生产线程写数据、压缩线程读数据通过队列解耦后两个线程的缓存访问模式更规律不再互相踩踏。第二是背压机制如果 IO 跟不上压缩线程会检测队列长度并放慢节奏避免内存无限增长。游戏端的内存是硬约束这个背压控制必须做。3.4 数据层微调让压缩器吃更顺口的字节流最后一个改造点不太起眼但压缩率提升明显调整日志格式化时的字段排列顺序。压缩器的工作方式是“在已见过内容中查找重复片段”。如果能让重复的内容尽量连续出现压缩率就会上升。我们观察游戏日志的格式时发现大量日志的共同前缀都包含时间戳、线程 ID、日志级别、模块名。这四个字段重复率极高但很多日志库的默认格式是“模块名: 日志正文带时间戳”把高重复字段和低重复字段穿插在一起导致压缩器刚记住一个模式就被打断。我们把格式调整为固定前缀结构时间戳 → 线程 ID → 日志级别 → 模块名 → 日志正文。这样重复性最高的前缀在字节流里就是连续的、高频出现的压缩器可以建立很长的匹配串。改动很小但压缩率大约提升了 8%~10%几乎没花额外 CPU。此外时间戳我们还做了增量编码——每条日志只存相对上一条的微秒差值而不是完整时间戳。因为同一毫秒内可能有几十条日志时间戳差值常常只有个位数这种值用很短的变长整数就能表示。这个改动进一步剪掉了字节流里的“冗余羽毛”也降低了压缩后解码端还原时间戳的复杂度。4. 实测数据与那些意料之中的取舍4.1 压测模型怎么搭所有优化做完后我们重新跑了一遍基线测试保持测试环境和数据模式完全一致骁龙 855 平台模拟器模拟真实战斗日志单条平均 120 字节每秒 20,000 条写入。同时我们额外跑了一个“高峰期压测”场景把写入频率提到每秒 80,000 条用来观察系统在极端情况下的稳定性。压测时重点盯三个指标生产线程写一条日志的平均耗时这直接决定游戏主循环受不受影响。P99 延迟延迟方差比平均值更能反映卡顿风险。压缩线程队列积压长度积压太长说明压缩速度跟不上产生速度最终会导致内存膨胀。4.2 优化前后的直观对比结果如下指标优化前压缩路径优化后压缩路径优化后普通路径平均写入耗时35 微秒6 微秒5 微秒P99 延迟280 微秒14 微秒12 微秒生产线程最长阻塞1.2ms0未发现阻塞0压缩率3.2:13.5:1不压缩压缩线程 CPU 占用不在路径内约 8% 单核0看到这张表的感受是压缩路径终于不是那个拉垮的“差生”了。平均耗时从 35 微秒降到 6 微秒P99 更是从 280 微秒降到 14 微秒——压缩路径和普通路径的差距已经从“数量级差异”变成了“几乎无感知”。代价是后台多跑一个压缩线程占用单核 8% 的 CPU这在移动端是完全可以接受的。毕竟你省下来的存储和回传成本远大于这点功耗。4.3 高峰期压测下的缓冲水位变化80,000 条/秒的极端压测下生产线程写入耗时反而有些有趣的变化。因为我们的活动块在原位写入单条日志的耗时主要是格式化耗时而格式化本身和日志条数无关所以平均耗时没有上升。压缩线程此时成为瓶颈队列积压量从稳态时的 4 块涨到了 18 块左右但因为有背压机制超过阈值后压缩线程会主动把优先级拉高积压很快回落到正常水位。内存峰值我们控制在 8MB 以内——这是固定块池的总量加上队列指针的极小开销。因为块池是预分配的队列积压只是“块被占用的数量变多”而不会触发新的内存申请。所以在内存表现上压缩路径和普通路径几乎是一样的没有动态内存波动。4.4 为了速度我们到底牺牲了什么任何优化都有代价压缩路径我们牺牲了三样东西压缩率没有拉满zstd 快档比慢档压缩率低约 8%但换来了数倍的压缩速度。在客户端日志这个场景下这 8% 的压缩率不值得用 CPU 去买。代码复杂度上升三级流水线、固定块池、无锁队列、变长块索引这批代码的理解和维护成本远高于普通日志路径。团队新人要看一段时间才能完全消化。多一个后台线程的功耗压缩线程即便在空闲周期也会周期性检查队列存在极小功耗开销。因为游戏本身就是一个持续的 CPU 负载场景这点功耗几乎可以忽略。牺牲换来的收益是日志生产路径完全不受压缩影响P99 延迟和普通路径几乎持平压缩率依然能到 3.5:1。这个交换我认为是划算的。5. 压缩路径优化的踩坑记录与边界5.1 小日志压缩反而膨胀的问题压缩路上第一脚坑是小日志压缩膨胀。一开始我们约定每攒满 64KB 就压缩但在低峰期比如玩家在加载界面时日志产生的频率很低可能一秒钟才几十条64KB 要攒很久。这时候如果一直不压缩日志写入路径是正常了可压缩块迟迟不出IO 线程没活干最终本次会话的日志可能丢在内存里。有人会想那攒不够 64KB 就压缩不就行了问题是你压一个 2KB 的块压缩器头部开销占的比重大压缩后体积可能比明文还大。实测下来小于 1KB 的数据块用 zstd 压缩平均膨胀率达到 110%~120%。这显然不是我们想要的。解决方式是双阈值策略块大小超过 64KB 立即压缩或者距离第一块写入时间超过 500ms 也立即压缩。前者保证高峰期压缩率后者保证低峰期日志不长期滞留内存。另外对极小数据块小于 256 字节做了一个特判不压缩直接按明文存储并在索引里标记。反正这种小块数据量太小不压缩也占不了多少存量反而省了压缩 CPU。5.2 压缩后随机访问日志的痛点明文日志可以用 grep 搜索、用 tail 跟踪可一旦压缩整个文件就是一堆不可读的二进制。某次线上排查运营同学想快速看某个玩家某段对局的日志行为发现日志全是压缩块根本没法直接捞出一条来看。我们在压缩块索引里记录了每个块的时间范围、原始长度、压缩长度、起始偏移。查询时先二分定位时间范围再只解压这一块而不是全量解压整个日志文件。为了实现这个“按时间片解压”压缩块时间范围必须严格单调递增不能出现一个块内横跨两个会话的情况。后来我们加了“会话边界强制切块”检测到会话切换例如玩家掉线重连立即把手头块封口开启新块。这样定位异常日志时最多只解压几百 KB速度很快运营同学也很满意。另一个细节是校验压缩块头引入了 CRC32 校验。原因是压缩数据对损坏极敏感一点点位翻转就可能导致解压失败。日志是我们排查问题的重要依据如果解压不出来整个日志链路相当于白做。CRC32 单块开销大约只有几百纳秒是值得买的保险。5.3 崩溃现场的最后一条日志去哪了压缩线程把日志压出来、但还没来得及刷盘时如果进程崩溃最后一批日志会丢。这在普通路径下也存在但在压缩路径下被放大了——因为后台压缩线程和 IO 线程的节奏是滞后于生产线程的生产线程写完日志到真正落盘间隔通常有几毫秒。我们把压缩块刷盘时机和“会话心跳”绑在一起任何 IO 操作结束或每条日志都有对应的时间戳我们定期对已完成块做一个异步 fsync。正常情况下崩溃最多丢失最后几毫秒的日志而这个损失日志量级在游戏客户端雷同问题定位时基本可接受。如果你对日志完整性有更高要求可以用双缓冲加日志序号的方式确保刷盘序号连续但代价是更大开销这个要在需求阶段就确定好别上线后再补。5.4 什么时候不该走压缩路径最后说一个经验性判断不是所有日志都该压缩。我们保留了按模块开关压缩的能力以下这些场景我建议直接走明文路径调试期日志开发环境日志量小你还需要随手 grep明文效率更高。极高频且极短的单条日志频率超过每秒 10 万条、单条小于 32 字节的时候压缩开销的性价比很低直接明文批量刷盘更快。启动早期日志系统刚起步时线程还没建好压缩线程还没起来这个窗口期走明文。还有一类更大的判断压缩日志的价值在不同产品形态里权重不同。服务端日志和客户端日志取舍逻辑就不一样——服务端带宽充裕、CPU 有预算可以追求高压缩率客户端 CPU 紧张、功耗敏感压缩率要让位于速度。BqLog 的设计没有把压缩逻辑物理耦合进主链路而是通过插件方式挂进去就是为了让不同项目能按自己的资源账单做选择。论文式总结没有意义我更愿意把这些取舍留在实操里。如果你也在做类似的日志压缩链路我的建议是先别急着优化压缩算法本身先把线程模型理清楚把生产线程从压缩路径上摘出去这一步带来的收益比任何压缩器调参都大。等生产线程零阻塞了再回头看缓冲布局、压缩器选型你会发现自己做的是加法而不是拆雷。这套思路我们已经在 BqLog 的压缩路径上验证过数据就是最诚实的答案。
返回列表