★ FEATURED ARTICLE 1. 从一次压测数据异常说起BqLog 压缩路径到底慢在哪第一次注意到压缩日志执行路径的问题是在一次极限压测里。当时我们模拟了单机每秒 80 万条日志写入的场景BqLog 在关闭压缩时吞吐稳定在 72 万条/秒左右CPU 占用约 38%。但一旦打开压缩开关吞吐直接掉到 19 万条/秒CPU 飙到 91%而且 P99 延迟从 0.8ms 涨到 14ms。这个数据非常反直觉——压缩本身是 CPU 密集型操作没错但掉到只剩四分之一说明瓶颈不在压缩算法本身而在压缩前后的执行路径上。我把火焰图拉出来看发现真正吃 CPU 的不是压缩函数而是三个地方一是日志条目在进入压缩队列前的序列化与拷贝二是压缩块边界判定时反复做的CRC 校验三是压缩完成后写盘前的哈希表查找与去重。这三块加起来占了压缩路径总耗时的 67%而真正的压缩算法我们用的是 LZ4只占 21%。也就是说压缩日志慢慢在“压缩之外”。这个发现促使我重新审视整条压缩日志执行路径。BqLog 的设计目标是在高吞吐场景下保持低延迟压缩只是其中一个可选环节但如果压缩路径本身设计得不够紧凑它就会成为整个日志系统的短板。后面几节我会把这条路径拆开逐段讲清楚每个环节为什么慢、怎么改、改完效果如何。如果你也在做高吞吐日志组件或者正在被压缩日志的性能问题困扰这些内容应该能直接拿去用。提示本文讨论的压缩日志执行路径优化前提是日志已经进入内存缓冲区之后的环节。采集端和格式化端的优化不在本文范围内那是另一个话题。2. 压缩日志执行路径的完整拆解从日志条目到落盘块2.1 一条日志从产生到压缩落盘要经过几道手先把这个路径完整走一遍不然后面讲优化会没有参照。BqLog 里一条日志从业务线程调用写接口开始到最终压缩落盘大致经过这么几个阶段业务线程写入调用BqLog::Write()日志内容先进入线程本地缓冲区Thread Local Buffer这一步是无锁的速度极快。缓冲区交换当本地缓冲区写满或达到刷新阈值会跟全局的待处理队列做一次交换把数据交给后台压缩线程。条目序列化后台线程拿到原始条目后需要把变长的日志内容序列化成连续的二进制块方便后续压缩。压缩块组装把多条序列化后的日志拼成一个压缩块块大小通常设为 64KB 或 128KB。CRC 校验计算对每个压缩块计算 CRC32用于落盘后的完整性校验。压缩执行调用 LZ4 对压缩块做压缩。哈希去重对压缩后的块做哈希查表判断是否重复重复则只记录引用。落盘写入把压缩块写入文件同时更新索引。这八步里第 3、5、7 步是优化前的主要瓶颈。第 3 步的序列化涉及多次内存拷贝第 5 步的 CRC 计算在块边界判定时被重复调用第 7 步的哈希表在高并发下锁竞争严重。下面逐个说。2.2 为什么序列化阶段会成为第一个瓶颈优化前的序列化逻辑是这样的每条日志先写到一个临时std::string然后再memcpy到压缩块的缓冲区。这个设计在日志量小的时候没问题但在 80 万条/秒的场景下每条日志平均 200 字节每秒就是 160MB 的数据要经过两次拷贝。第一次是写入临时 string第二次是拷贝到压缩块。两次拷贝加起来光内存带宽就吃掉了大量 CPU 周期。更麻烦的是临时std::string的构造和析构本身有开销。每条日志都要构造一个 string 对象虽然短字符串有 SSOSmall String Optimization优化但超过 15 字节的日志就会触发堆分配。80 万条/秒的堆分配和释放对内存分配器是巨大压力。我实测过光这一块的malloc/free就占了序列化阶段 40% 的时间。优化方案是改成直接写入压缩块缓冲区。具体做法是压缩块缓冲区预分配一块固定大小的内存序列化时直接把日志内容按格式写入这块内存的当前偏移位置写完后更新偏移量。这样一次拷贝就完成了而且完全避免了临时 string 的构造析构。改完之后序列化阶段耗时从原来的 11ms/万条降到 3.2ms/万条降幅 71%。2.3 CRC 校验在压缩路径里的真实开销CRC32 校验本身不慢现代 CPU 都有 CRC32 硬件指令算 64KB 数据大概只要几微秒。但问题在于优化前的代码在压缩路径里对同一个块算了三次 CRC一次是在块组装完成时一次是在压缩前做边界确认时一次是在落盘前做最终校验时。三次计算的数据完全一样纯属重复劳动。为什么会出现这种情况因为代码是分阶段演进的。最早只有落盘前一次校验后来为了在压缩前确认块完整性加了一次再后来块组装阶段为了调试又加了一次调试完忘了删。这种“历史遗留的重复计算”在日志组件里非常常见因为日志组件往往经过多轮迭代每轮加一点东西很少有人回头清理。优化很直接CRC 只在块组装完成时算一次结果缓存在块头里后续阶段直接读缓存值。改完之后CRC 相关耗时从压缩路径总耗时的 18% 降到 4%。这里有个细节要注意缓存 CRC 值的时候要确保块内容在缓存之后不再被修改。我们的做法是在块结构体里加一个crc_valid标志位任何修改块内容的操作都会把这个标志位置为 false下次读 CRC 时如果发现标志位是 false 就重新计算。这样既避免了重复计算又保证了正确性。2.4 哈希去重环节的锁竞争问题哈希去重是为了避免重复日志占用多份存储空间。优化前用的是全局哈希表所有压缩线程共享一把读写锁。在 8 个压缩线程并发的情况下这把锁成了严重的竞争点。火焰图上pthread_rwlock_rdlock的等待时间占了哈希环节的 60% 以上。改成分片哈希表之后问题基本解决。具体做法是把哈希表分成 64 个分片每个分片独立加锁线程根据日志内容的哈希值高位决定去哪个分片。这样锁竞争概率降到原来的 1/64实测哈希环节耗时从 8ms/万条降到 1.1ms/万条。分片数选 64 是因为我们的压缩线程数是 864 分片能保证每个线程大概率落在不同分片上同时分片本身的内存开销也可以接受每个分片就是一个小的哈希桶数组。3. 压缩块边界判定一个被忽视的性能陷阱3.1 块边界判定为什么会影响压缩效率压缩块的大小直接决定压缩率和压缩速度。块太小压缩率上不去因为 LZ4 需要足够的上下文才能找到重复模式块太大单次压缩耗时长延迟抖动大。我们最初设的是 64KB后来发现这个值在高吞吐场景下偏小改成 128KB 后压缩率提升了 12%但延迟 P99 涨了 3ms。最终折中在 96KB压缩率和延迟都比较平衡。但真正的问题不在块大小本身而在边界判定的时机。优化前的逻辑是每写入一条日志就检查当前块是否超过阈值超过就触发压缩。这个检查本身很轻量但它导致了一个问题——块边界往往落在一条日志的中间。也就是说一条日志可能被拆到两个压缩块里。这本身不是错误但会让解压后的日志重组变复杂而且跨块的日志无法被 LZ4 有效压缩因为压缩上下文断了。优化方案是按日志条目对齐块边界。具体做法是在写入日志前先判断“如果写入这条日志会超过块阈值且当前块已经至少有 80% 满就先封口当前块把这条日志放到下一个块”。这样保证每条日志完整地落在一个块里。代价是块的实际大小会在 80% 到 100% 阈值之间浮动但换来的是压缩率提升 8% 左右而且解压逻辑简化了很多。3.2 边界判定中的 CRC 重复计算怎么消掉前面提到 CRC 被算了三次其中一次就发生在边界判定时。优化前的代码在每次判断块是否满的时候都会顺手算一次当前块的 CRC用来做“块完整性预检”。这个预检在调试阶段有用但生产环境完全没必要因为块内容在封口前本来就可能变预检的 CRC 下一秒就失效了。删掉这个预检之后CRC 计算次数从三次降到一次。但删的时候要注意预检的 CRC 值在日志里有记录如果直接删掉日志格式会变旧日志的解析工具可能不兼容。我们的做法是保留日志格式里的 CRC 字段但只在封口时写入预检阶段写 0。解析工具看到 0 就跳过校验看到非 0 才校验。这样既优化了性能又保持了格式兼容。3.3 块封口时的内存屏障与可见性块封口这个操作在多线程环境下有个容易踩的坑封口线程把块标记为“已完成”之后压缩线程可能还没看到块内容的最新写入。这是因为 CPU 的写缓冲区可能导致内存写入乱序。优化前我们用的是std::atomic加默认的内存序理论上没问题但实测在高负载下偶尔会出现压缩线程读到不完整的块。后来改成在封口时显式加一个std::atomic_thread_fence(std::memory_order_release)压缩线程读取块状态前加std::atomic_thread_fence(std::memory_order_acquire)。这样保证封口线程的所有写入对压缩线程可见。改完之后再没出现过不完整块的问题。这个坑很隐蔽因为出问题的概率低压测时可能跑几小时才复现一次但一旦出问题就是数据损坏必须重视。4. 哈希与 CRC 在压缩路径中的分工与取舍4.1 哈希去重和 CRC 校验各自解决什么问题这两个东西经常被混为一谈但它们在压缩路径里的职责完全不同。CRC 校验解决的是“数据有没有坏”它是对块内容的完整性检查防止落盘或传输过程中出现比特翻转。哈希去重解决的是“数据有没有重复”它是对块内容的身份标识用来判断两个块是否内容相同相同则只存一份。因为职责不同它们对算法特性的要求也不同。CRC 要求能检出尽可能多的错误模式尤其是突发错误哈希要求碰撞率低、计算快。优化前我们用的是同一个 CRC32 值同时做校验和去重这其实是有问题的——CRC32 只有 32 位碰撞概率在大量块的情况下不可忽略。我们实测过在 1000 万个块的规模下CRC32 碰撞导致了约 200 次误去重也就是有 200 个不同的块被误判为重复导致数据丢失。后来改成CRC32 做校验、xxHash64 做去重两个值分开存。xxHash64 有 64 位碰撞概率降到可忽略而且计算速度比 CRC32 还快xxHash 是专门为速度设计的非加密哈希。改完之后误去重问题消失哈希环节耗时还降了 15%。4.2 为什么 CRC 不能保证检出全部奇数个比特错误这个问题在热词里被提到值得展开说。CRC 的检错能力取决于生成多项式。一个 n 位的 CRC 能检出所有长度不超过 n 的突发错误能检出所有奇数个比特错误的前提是生成多项式包含因子 (x1)。如果生成多项式不含 (x1)那么某些奇数个比特错误就检不出来。常见的 CRC32 多项式如 IEEE 802.3 用的那个是包含 (x1) 因子的所以能检出所有奇数个比特错误。但如果你自己选了一个不含 (x1) 的多项式那就不能保证。这也是为什么热词里说“不能作为 CRC 生成多项式”——选多项式是有讲究的不是随便一个就行。在实际工程里直接用标准多项式就行不要自己发明。我们用的是 CRC32CCastagnoli 多项式它有硬件指令支持速度比软件实现快一个数量级而且检错能力足够。选 CRC32C 而不是 IEEE CRC32 的原因是前者有 SSE4.2 的crc32指令后者没有硬件加速。4.3 哈希表分片数与压缩线程数的匹配关系分片哈希表的分片数不是随便定的。分片太少锁竞争还是严重分片太多内存开销大而且缓存局部性变差。我们的经验是分片数取压缩线程数的 8 倍左右。比如 8 个压缩线程分片数取 64。这样每个线程在任意时刻大概率操作不同的分片锁竞争概率低同时 64 个分片的总内存开销也就几百 KB可以接受。分片函数也有讲究。优化前用的是hash % shard_count这要求 shard_count 是质数才能分布均匀。后来改成hash (shard_count - 1)要求 shard_count 是 2 的幂。后者更快位运算比取模快而且分布均匀性在 xxHash64 的输出下完全没问题。我们把分片数从 61质数改成 642 的幂分片耗时又降了 8%。5. 执行路径优化的实测数据与调参经验5.1 优化前后的关键指标对比把上面所有优化都落地之后我们做了一轮完整的对比测试。测试环境是 16 核 32 线程的服务器日志写入速率 80 万条/秒平均日志长度 200 字节压缩算法 LZ4压缩块 96KB。指标优化前优化后变化吞吐万条/秒1958205%CPU 占用91%52%-43%P99 延迟ms143.2-77%压缩率3.8:14.3:113%序列化耗时ms/万条113.2-71%CRC 耗时占比18%4%-78%哈希耗时ms/万条81.1-86%吞吐从 19 万涨到 58 万虽然还没到不压缩时的 72 万但已经能接受。CPU 占用降了将近一半说明优化确实消掉了大量无效计算。压缩率提升是因为块边界对齐和块大小调整这个算是意外收获。5.2 调参时容易踩的几个坑第一个坑是压缩块大小设得太大。我试过 256KB 的块压缩率确实上去了但 P99 延迟飙到 20ms 以上因为单次压缩耗时太长压缩线程被长时间占用后续块排队。后来回到 96KB延迟和压缩率平衡得比较好。经验值是块大小不要超过 L2 缓存的一半这样压缩时数据还在缓存里速度最快。第二个坑是分片数设成压缩线程数的整数倍。我一开始把分片数设成 8等于线程数结果发现锁竞争还是很严重因为线程和分片的映射不均匀某些分片被多个线程同时访问。改成 64 之后才解决。分片数最好是线程数的 8 倍以上而且要是 2 的幂。第三个坑是CRC 缓存标志位的更新遗漏。我们有个分支逻辑是“如果块内容没变就复用上次的 CRC”但有一次代码改动中某个修改块内容的路径忘了把crc_valid置为 false导致用了过期的 CRC落盘后校验失败。这个 bug 很难查因为只在特定路径下触发。后来加了个断言在 debug 模式下每次读 CRC 缓存都重新算一遍对比确保标志位逻辑正确。5.3 什么场景下不值得开压缩不是所有场景都适合开压缩。如果你的日志写入速率低于 5 万条/秒压缩带来的 CPU 开销可能比节省的存储空间更不划算。我们内部的经验阈值是当日志写入速率超过 10 万条/秒或者存储成本敏感时才开压缩。低于这个速率直接写原始日志更简单也更容易排查问题。另外如果日志本身已经是高度结构化的二进制格式压缩率可能很低因为二进制数据熵高这时候压缩的收益就更小。我们有个业务线的日志是 protobuf 序列化后的二进制压缩率只有 1.2:1后来干脆关了压缩直接存原始数据。6. 从压缩路径优化延伸出的几个通用原则6.1 热路径上不要做“顺手”的事压缩路径是日志系统的热路径每秒要执行几十万次。在这种路径上任何“顺手”做的事都会被放大。优化前那些重复的 CRC 计算、临时的 string 构造、全局锁都是当初写代码时“顺手”加的单次开销看起来微不足道但在热路径上累积起来就是灾难。我的经验是热路径上的每一行代码都要有明确的理由。如果一个操作不是当前阶段必须的就把它挪到冷路径上或者用条件编译隔离。比如调试用的完整性预检就应该放在#ifdef DEBUG里而不是生产代码里。6.2 缓存友好性比算法复杂度更重要LZ4 的算法复杂度是 O(n)已经很快了但实测中压缩路径的瓶颈往往不在算法本身而在内存访问模式。优化前的序列化逻辑涉及多次内存跳转临时 string 在堆上压缩块在另一块内存缓存命中率低。改成直接写入压缩块缓冲区后内存访问变成顺序的缓存命中率大幅提升这才是性能提升的主因。这个原则在日志组件里特别重要因为日志数据量大缓存未命中的代价很高。写代码时要尽量让数据访问是顺序的、局部的避免指针追逐和随机访问。6.3 多线程下的“无锁”往往比“有锁”更慢我们试过把哈希表改成完全无锁的用 CAS 操作结果发现比加锁还慢。原因是无锁哈希表在冲突时需要重试高并发下重试次数很多而且 CAS 操作本身有开销。分片加锁的方案虽然理论上会有锁竞争但实际竞争概率低而且锁的开销在低竞争下很小。所以不要迷信无锁。低竞争场景下分片加锁通常比无锁更快也更简单。只有在竞争非常激烈、且临界区极短的情况下无锁才有优势。判断标准很简单先做分片加锁如果压测发现锁竞争还是瓶颈再考虑无锁。6.4 日志组件的优化要盯着端到端延迟压缩路径的优化不能只看吞吐还要看延迟分布。我们优化过程中有一次吞吐上去了但 P99 延迟反而变差原因是压缩块变大导致单次压缩耗时波动大。后来把块大小调回来吞吐略降但延迟稳定了。日志组件的用户往往更在意延迟稳定性因为日志写入是在业务线程里同步调用的或者至少是业务线程触发的延迟抖动会直接影响业务。所以优化时要同时看吞吐和 P99/P999 延迟不能偏废。7. 几个实际排查中遇到的典型问题7.1 压缩线程 CPU 占用高但吞吐上不去有一次线上反馈压缩线程 CPU 跑到 100%但日志吞吐只有 15 万条/秒。拉火焰图发现大量时间花在memcpy上。查代码发现是序列化阶段的一个 bug压缩块缓冲区的偏移量更新逻辑有问题导致每次写入都从缓冲区头部重新开始把已经写过的数据又覆盖了一遍。这个 bug 导致实际有效数据只有预期的一半但拷贝量翻倍。修复方法是把偏移量更新改成原子操作并且加了断言检查偏移量单调递增。这个问题的教训是热路径上的状态变量要用原子操作保护并且加断言。偏移量这种变量在单线程下没问题但一旦涉及多线程交换缓冲区就必须小心。7.2 哈希去重导致日志丢失前面提到过 CRC32 碰撞导致误去重这里补充一下排查过程。当时的现象是日志文件里偶尔少几条记录但 CRC 校验都通过。排查了很久才发现是去重逻辑的问题——两个不同的块 CRC32 相同被误判为重复第二个块只存了引用但引用指向的第一个块内容其实不同。排查方法是在去重逻辑里加日志记录每次去重时的块哈希和块大小。跑了一段时间后发现有几对块的 CRC32 相同但 xxHash64 不同这才定位到问题。修复就是前面说的CRC 和哈希分开去重用 xxHash64。7.3 块边界不对齐导致的解压错误块边界不对齐本身不会导致解压错误但如果解压逻辑假设“每个块以完整日志开头”就会出问题。我们有个下游工具就是这么假设的结果遇到跨块日志时解析失败。后来统一改成按日志条目对齐块边界下游工具就不用改。这个问题的教训是压缩块的边界约定要在整个链路里保持一致。如果压缩端按字节对齐解压端也要按字节对齐如果压缩端按条目对齐解压端也要按条目对齐。不要一边按字节一边按条目否则迟早出问题。8. 后续还能怎么继续压榨压缩路径压缩路径优化到目前这个程度吞吐从 19 万涨到 58 万已经能满足大部分场景。但如果要继续压榨还有几个方向可以试。第一个方向是用 SIMD 加速序列化。目前的序列化是逐字段写入如果用 SIMD 指令批量处理理论上还能再快一些。不过 SIMD 序列化的代码复杂度高维护成本大需要权衡。第二个方向是压缩算法换成 Zstd 的低级别模式。Zstd 在低压缩级别下速度接近 LZ4但压缩率更高。我们试过 Zstd level 1压缩率比 LZ4 高 15%速度只慢 8%。如果存储成本敏感这个替换是值得的。第三个方向是把 CRC 计算卸载到独立的硬件队列。有些平台有专门的 CRC 加速硬件可以把 CRC 计算从 CPU 主核卸载出去。不过这个依赖具体硬件通用性差适合特定场景。第四个方向是压缩块预分配池化。目前压缩块是每次压缩时分配的如果改成从内存池里取能省掉分配开销。这个优化在小块场景下收益明显大块场景下收益有限。这些方向我还在陆续尝试有新的数据再分享。压缩日志执行路径的优化是个持续过程没有终点只有不断逼近理论上限。关键是每次优化都要有数据支撑不要凭感觉改代码。
阅读完成 · 觉得有帮助？
