如果你在MOBA游戏里摸过性能优化,大概率遇到过这种场景:帧时间曲线平时漂漂亮亮,一开团就冒出几根刺眼的毛刺,拉出来看堆栈,元凶往往不是战斗逻辑,而是日志库。日志这玩意在玩家眼里不存在,但在性能剖析中真是个隐形杀手。
上一篇我们聊过BqLog为什么快的第一层:整体分层+批量刷新,日志写入只在内存里做一次追加,格式化、落盘全部丢给后台线程。这套架构把单次日志调用的开销从微秒级压到纳秒级,单线程场景下表现非常亮眼。但王者荣耀这种项目有个特点,日志输出点遍布主线程、渲染线程、战斗逻辑、网络模块,多线程并发写日志是常态,问题就从这里冒出来了——内存追加虽然快,但必须保证并发安全,而保证安全的方式,直接决定性能天花板。
这一篇是“BqLog为什么这么快”系列的第二篇,核心只聊一件事:BqLog的日志写入端,怎么从最朴素的环形队列,一步步演进成带自适应插入策略的轻量数据总线。这个演进过程不是看论文看出来的,是真刀真枪踩坑踩出来的。我们吃过CAS重试的亏,被伪共享坑过,还亲眼看过锁竞争把日志线程CPU吃满的线上事故。下面我会把设计思路、代码层关键点、以及一次完整的线上问题排查过程都整理出来,给同样在做高性能日志组件、或者对无锁数据结构感兴趣的朋友一份可参考的实战笔记。
1. 日志组件到底需要多快
先说结论:日志组件的性能目标不是“跑分好看”,而是“无论什么场景都不许拖垮帧时间”。MOBA游戏一局对战牵涉到的日志量极其恐怖,战斗结算、技能释放、伤害跳字、网络同步、战绩上报,每一个模块都有自己的日志输出节奏。尤其是开团瞬间,几十个单位同时放技能,主线程在调度战斗逻辑,渲染线程在加载特效,网络线程在处理同步包,这几个线程几乎同时往日志里塞数据。
如果日志写入是同步串行的,主线程每次打日志都要等待IO完成,那等于给每一帧都埋了一颗雷。日志调用本身频率太高了,哪怕一次只花20微秒,一个线程一帧里打几十条日志,帧时间直接多出几百微秒,这在60帧游戏里是不可接受的预算超标。所以BqLog的第一条设计准则非常明确:日志写入路径只能做两件事,一是计算目标槽位,二是执行一次内存拷贝。格式化字符串、拼接参数、写文件、刷缓冲,全部挪到后台线程去处理。
1.1 一个极端的线上场景:日志写成了性能黑洞
我曾经接手过一个线上问题,某个版本更新后,部分机型出现对局内掉帧,而且掉帧规律很奇怪:不是全程卡,而是时不时卡一下,间隔很随机。用Android Studio的CPU Profiler抓了一轮,发现一个叫WriteFileLock的线程长时间处于Runnable状态,再往下看,是日志落盘时和后端线程在锁上打架。
当时我们用的还是旧版日志库,所有线程打日志都要经过同一个全局互斥锁,锁内做格式化、拷贝、判断缓冲区是否写满,写满就触发磁盘IO。在高频日志场景下,这个锁几乎成了全局路障。开团瞬间8个线程同时抢锁,持锁线程在锁内做字符串拼接,其他线程全部自旋等待,等锁时间飙到十几毫秒,帧率直接从60掉到40出头。那次排查看下来,我最大的感受是:日志这种基础设施,平时没人注意,出问题就是灾难级,而且症状会被包装成“莫名掉帧”“偶发卡顿”,非常难定位。
1.2 BqLog的第一性原理:日志写入只做内存追加
BqLog所有的性能设计都围绕一句话:让写入端尽可能轻。具体来说,日志线程调用BqLog::write()时,函数内部只经历三个步骤:
- 从线程本地缓冲区或者总线空闲节点中取一块内存;
- 把格式化后的日志内容追加到内存尾部;
- 更新索引或者长度字段,唤醒后台刷新线程。
整个过程不碰文件系统,不碰系统调用,不做字符串拼接以外的任何重操作。好处是写入端的延迟可以压到纳秒级,但代价是架构复杂度上来了——必须有一个既快又安全的内存数据结构来承担“临时存放日志”的角色。这个数据结构,就是我们这一篇的主角。
1.3 为什么单独拿出数据结构来写一篇
很多人觉得日志组件快了,是因为用了异步线程、批量写盘,但其实那只是表象。真正决定写得快不快的,是写入端背后那个数据结构:线程们把日志塞到哪里?怎么避免互相踩踏?容量满了怎么办?这些问题直接决定写入路径是几纳秒还是几十微秒。BqLog的答案从最朴素的环形队列开始,逐步演进出自适应数据总线。接下来两节,我会把两代方案的设计思路、优点和局限都拆开揉碎讲明白。
2. 第一代方案:用环形队列把日志延迟压缩到纳秒级
BqLog最早期的写入端就是一个环形队列,数据结构本身非常简单。如果你上过数据结构课,对这个东西不会陌生:用数组q[m]存放元素,rear记录队尾下标,length记录当前队列中元素个数,满则拒,空则退。之所以用rear + length这套表示而不是经典的front + rear,是因为BqLog在单生产者场景下更看重“写者只写、读者只读”的干净切分。
环形队列的容量之所以必须设计成2的幂,是为了让取模运算退化成按位与& (m - 1)。数组下标回绕时,(rear + 1) & (capacity - 1)比(rear + 1) % capacity快一个数量级。这个优化在单个日志操作里可能只省了几纳秒,但以每秒几十万次的写入频率累积下来,效果非常可观。
2.1 环形队列为什么能做到无锁
单生产者单消费者的经典模型下,环形队列可以实现完全无锁。生产者只修改rear和length,消费者只修改length,两边的写操作不重叠。生产者的写入路径大致是:
// 生产者:写入日志 int32_t slot = (rear + length) & (capacity - 1); // 队尾 data[slot] = msg; // 关键在于下面的 release 语义 length += 1; // 用 release 语义发布本次写入消费者那边只需要用acquire语义读取length,确认有数据后从队头取走。这里有个讲究:如果用front + rear双指针表示,消费者取走元素后要更新front,生产者又依赖front判断队列是否满,两边就得抢同一条共享变量;而rear + length方案下,消费者最多只读长度字段,生产者的更新路径上不依赖消费者的写操作,这就把真正的共享写降到了最低。
2.2 容量设计的核心准则:宁可丢弃,不可阻塞
这也是BqLog和传统队列理念差别最大的地方。普通队列满时让生产者阻塞等待,但在游戏日志场景下,让主线程等队列腾位置是绝对不可接受的。BqLog的环形队列设计成环形缓冲之后,生产者在队列满时有两条路:覆盖最旧数据,或者直接丢弃本次日志。BqLog默认走覆盖旧数据路线,同时用一个丢弃计数记录被覆盖的日志条数,后台线程落盘时补一条类似“日志已丢N条”的标记,方便排查问题。
容量具体开多大,有个经验公式:队列容量 = 单线程峰值日志速率 × 后台线程最大落盘延迟 × 1.5。比如峰值每秒10万条、后台线程偶尔被IO卡住50毫秒,那容量至少开到7500条,取2的幂就是8192条。这样即使后台线程偶尔抽风,队列也不容易触顶,而一旦真的触顶,丢弃的也是相对不重要的“过程日志”,不会把整个库卡死。
2.3 单生产者场景下的实测数据
我在一台骁龙8系测试机上跑过这个方案的基准测试:单线程持续打日志,每秒写入50万条,每条日志平均写入耗时大约在8到12纳秒之间。这个数据在当时已经碾压很多老牌日志库了——那些库动辄几十上百微秒,差了两个数量级。所以第一代方案上线后,单线程场景的表现我们是很满意的,直到多线程并发的问题暴露出来。
3. 多线程环境下,环形队列的临界区开始失控
第一代方案用好好的,为什么还要改?答案是项目需求变了。随着玩法迭代,王者荣耀里打日志的线程从早期的主线程+少量工作线程,变成了主线程、渲染线程、战斗逻辑线程、网络模块线程、音频线程、AI计算线程等一大堆并发源。它们之间没有天然的“单生产者”约束,任何线程都可能在任何时刻往日志队列里塞数据。而原来的环形队列一旦变成多生产者共享,问题接踵而来。
3.1 临界区膨胀:从无锁退回到“加锁排队”
最朴素的改造方式是在环形队列外面加一把互斥锁。但这样做的结果很讽刺:原本无锁的写入路径变成一个串行临界区,所有线程打日志都在抢同一把锁,日志频率越高,锁竞争越激烈。我们做过一次压测,4个线程同时打日志,锁开销占比直接超过60%,等锁造成的线程切换让CPU上下文切换次数翻了一倍。更麻烦的是,日志写入里还包含一次内存拷贝,如果日志内容比较长,持锁时间被拉长,其他线程的等待时间呈线性上涨。
有人可能会说,那用读写锁,读多写少不就优化了吗?问题是日志这种负载全是写操作,读写锁在这里退化得比互斥锁还慢。
3.2 ABA问题:用CAS修修补补的第一课
既然锁不可取,很自然的思路就是换无锁方案——用CAS原子操作来更新队尾指针。这里就遇到了无锁编程最经典的ABA问题。场景是这样的:线程A读到length等于32,打算CAS更新;被调度器切走;线程B连续写入两条日志,length变成34;线程C又把length恰好看成32(比如线程B写入后队列满覆盖了旧数据,长度恰好回落到32);线程A恢复执行,CAS比较后发现“还是32”,更新成功。表面上看CAS成功了,但它基于的队列状态早已不是最初读到的状态,可能把B写入的数据覆盖掉。
解决ABA的标准套路是加版本号或者序列号,每次更新递增一位。BqLog在环形队列上做了这个改动:把长度字段拆成“长度+序号”两部分打包进一个64位整数,CAS时同时校验二者。方案可行,但副作用也很明显——每个队列slot需要额外存储序号信息,节点体积从16字节涨到24字节甚至32字节,缓存命中率下降,反而拖累性能。
3.3 伪共享:多核下真正影响吞吐量的隐形杀手
CAS和锁至少是明面上的竞争,伪共享才是真正阴人的那个。现代CPU缓存行通常是64字节,环形队列的slot数组如果每个槽位是8到16字节,那么连续几个槽位会落在同一条缓存行里。假设线程A往slot 5写日志,线程B同时往slot 6写日志,这两个slot恰好在同一条缓存行上。A写入导致缓存行失效,B再写时被迫重新从内存加载整条行;反过来B写也会让A的缓存行失效。两个线程明明操作的是不同槽位,却在缓存层面“共享”了同一条行,写入互相踢来踢去,性能直接掉一个量级。
排查这个问题的过程也非常痛苦。当时我们用perf观测到一段奇怪的cache-miss飙升,但所有的锁、CAS都已经被排除了,看代码逻辑怎么都不该这么慢。后来是同事把slot数组的每个元素前后都加了填充字节char padding[64],让每个槽位独占一条缓存行,性能立刻回升。这才真正意识到,并发性能的瓶颈不只在算法逻辑层,也在CPU微架构层。
3.4 一次真实的性能回退:8个线程挤一个队列
线上那次“更新后掉帧”的案例分析到最后,根因已经很清楚:新增的联网战绩模块在启动阶段有8个线程同时高频打日志,全部挤在第一代环形队列上,锁竞争、CAS重试、伪共享三者叠加,把写入端延迟从个位数纳秒干到了几十微秒。虽然单次看还是很快,但在开团这种高频时刻,几十微秒的延迟放大到每帧上百次日志调用,帧时间就撑不住了。
从那之后我们明确了一个判断:单队列多生产者这条路,在BqLog的需求模型下已经走到头了。需要换一个更贴合“多线程并发提交”场景的结构。
4. 从单队列到总线:BqLog自适应数据总线的设计与实现
第二代写入端方案,就是我们说的“自适应数据总线”。名字听着很唬人,核心思想其实就是三个字:分流。不再让所有线程挤同一条队列,而是提供多个“总线节点”,每个节点负责一小段日志缓冲,线程根据当前各节点的负载情况选择最空闲的节点写入。这种设计借鉴了数据库里分区表的思路——与其让所有人抢同一个热点,不如把热点拆碎,让流量自然分散。
4.1 总线的设计目标:观测性、并发度、内存布局
设计总线之前,我们先列了几条硬指标:
- 多个线程可以同时提交日志,互相之间只允许极轻微的竞争;
- 单个节点的写入延迟要求保持在几十纳秒量级;
- 节点之间要能快速感知负载,方便新来的线程选择“冷”节点;
- 内存布局要紧凑,避免链表式的随机访问拖垮缓存。
在这些指标下,很自然地排除掉了链表方案。链表虽然增删节点灵活,但每个节点是单独分配的,内存地址不连续,遍历时缓存命中率极低。我们最终选择了“双向链路数组”:一片连续的数组内存,每个数组元素就是一个总线节点,节点之间通过偏移量串起来,形成一条逻辑上的双向链表。数组保证局部性,双向偏移保证索引方便。
4.2 为什么总线节点带锁反而比CAS更划算
这里有个和其他无锁队列反直觉的设计:总线节点内部用了自旋锁,而不是CAS循环。原因是CAS在高竞争场景下的重试开销非常大,而且多个线程同时抢一个节点的CAS,本质上是把所有压力都打在同一条缓存行上。自旋锁在低竞争场景下的开销比CAS还小,而且临界区极短——只有一次内存拷贝加上阈值变量更新,实测持锁时间不到20纳秒。这个粒度下锁竞争带来的开销远小于无锁CAS失败的惩罚。
其实BqLog内部对锁的使用原则可以总结成一句:尽量不锁,不能避免锁的时候就锁得极短,短到锁本身的开销可以忽略不计。
4.3 自适应插入策略到底在“自适应”什么
这是总线方案的关键,也是整个设计里最有意思的部分。每个总线节点都维护两个基础指标:当前积压的日志条数、最近一段时间被写入的次数。新线程要写日志时,不是走固定路由,而是先做一个轻量的“侦察”:从总线头部开始,按2的幂步长跳跃扫描若干节点(比如0、1、2、4、8、16号位置),每扫到一个节点就读取它的负载值。选择负载最小的节点作为本次写入的入口。
这个扫描策略有两个好处。第一,按2的幂跳跃能避免多个线程同时扫到“看似最小”的同一个节点,降低扎堆概率;第二,因为节点在物理内存上是连续的,扫描过程相当于顺序读几段连续内存,一次预取就能覆盖,开销几乎可以忽略。实测下来,10个节点以内的扫描耗时在5纳秒以内。这就是自适应的第一个维度:入口自适应。它根据当前节点的负载情况,动态决定每个日志写入该从哪个节点进入。
自适应的第二个维度是水位均衡。当某个节点因为历史原因积压了大量日志,或者被某几个高频线程持续占据时,它的负载值会持续上升。总线在每次写入后都会检查节点负载是否超过阈值,如果超了,就把“推荐入口”偏移到相邻的下一个节点。这样,即使某个线程习惯性盯着同一块区域打日志,总线也会悄悄把它的流量分散到其他空闲节点上。
4.4 总线节点的数据结构和核心写入路径
下面给一段贴近真实实现的伪代码,方便理解:
struct BusNode { alignas(64) std::atomic<uint32_t> sequence; // 序号,防ABA char* data; // 日志数据指针 uint32_t capacity; // 节点容量 uint32_t length; // 当前积压条数 uint32_t load; // 负载水位 int32_t next_offset; // 逻辑链表下一节点 int32_t prev_offset; // 逻辑链表上一节点 std::mutex lock; // 极短临界区锁 char padding[64]; }; class AdaptiveBus { std::vector<BusNode> nodes_; // 连续内存的节点池 std::atomic<uint32_t> cursor_; // 游标,用来做跳跃扫描的起点 };写入路径的流程大致是这样:
- 读取
cursor_作为扫描起点,按2的幂跳跃遍历8个节点,收集各节点的load; - 挑出
load最小的节点,尝试加锁; - 锁内把日志数据拷贝到该节点的
data缓冲区尾部,更新length和load; - 释放锁,如果
load超过阈值,把cursor_后移一位,让后续写入自动漂移到相邻节点。
从流程上看,每个线程的写入路径只经历一次极短锁,加锁之外全是连续内存访问。这就是BqLog第二代写入端的核心优势:并发度不再取决于单一队列的吞吐上限,而是取决于总线节点总数。节点开得越多,并发提交能力越强,而且不受节点数量的线性拖累。
5. 一次真实的生产问题排查:日志延迟从2ms暴涨到30ms
光说设计可能不够直观,我分享一个实实在在用总线方案解决线上问题的过程。某个版本预发布阶段,我们在监控系统上发现部分机型日志线程的每次批处理延迟中位数突然从2毫秒涨到30毫秒,帧时间P99也从33毫秒跳到40毫秒。日志线程是后台的,延迟高点按理说不影响主线程,但诡异的是,主线程有大量埋点在等待日志写盘后才能上传战斗回放,日志线程一旦卡顿,埋点队列也跟着堆积。
5.1 从现象倒推:延迟毛刺是怎么传导到主线程的
第一反应是磁盘IO变慢了。查了一圈存储状态,没问题,SSD的写入速度正常。第二反应是后台线程优先级被抢占,看schedstat也没发现明显的调度延迟。最后用perf抓线程栈,发现日志线程大量时间停留在加锁等待上,用的是第一代环形队列的全局锁方案。再一看线上版本,正好是新玩法发布后日志量暴涨的那段时间,旧日志库的全局锁已经被高频写入逼到了极限。
5.2 关键定位:perf top里那把锁占掉了20%的CPU
在perf top的输出里,排序靠前的几个符号分别是BqLog::RingQueue::push、pthread_mutex_lock和fwrite,其中锁相关的占比接近20%。一个日志库能把CPU吃到这个程度,问题已经很严重了。我们当时做了个实验:临时把日志级别从INFO调到ERROR,把大部分日志滤掉,帧时间P99立刻回到33毫秒。这就进一步实锤:日志写入路径是瓶颈,而且瓶颈不在磁盘,在并发写入的临界区。
5.3 切总线方案之后的数据对比
切到自适应数据总线方案后,同机型同场景下,日志线程的等锁时间从总耗时的12%降到了2%以内,日志线程CPU占用整体下降了一半左右。更关键的主线程帧时间也稳了,P99回到33毫秒,新玩法引起的毛刺彻底消失。这个对比非常直观地说明了问题:日志组件的性能瓶颈,本质上不是日志内容本身,而是多线程提交时的扇入模型。总线方案不是把写入变快了,而是把集中式竞争变成了分布式分摊,让每个线程都有机会走自己的“快车道”。
6. 常见问题排查实录:CAS失败、极端竞争、总线扩容
最后整理几个我在实际开发和排查中经常遇到的问题,做成一个速查表,给要动手实现类似方案的朋友参考。
| 问题现象 | 可能原因 | 排查思路 | 解决方案 |
|---|---|---|---|
| CAS一直失败,性能骤降 | 多个线程高频更新同一节点 | 用perf看cache-miss命中率,检查是否有缓存行热点 | 扩容总线节点数,或让节点数据按64字节对齐 |
| 极端竞争下总线退化成串行 | 节点负载阈值设置过小,线程频繁漂移 | 打印负载分布,观察节点load是否总是溢满 | 调大漂移阈值,让线程稳定停留在各自节点 |
| 扩容总线时日志丢失 | 扩容期间旧节点被写入 | 检查扩容暂停逻辑是否覆盖所有写入线程 | 扩容期间置全局暂停位,所有写入线程在线等待 |
| 单节点写入慢 | 节点data分配碎片化 | 查看内存分配器,节点data需要连续大块 | 使用内存池或自定义分配器,减少malloc调用 |
6.1 遇到CAS一直失败怎么办
如果自己实现无锁队列时遇到CAS重试率高居不下的情况,先不要急着调参。检查三件事:第一,是不是多个生产者真的在写同一个槽位,如果是,说明你的队列设计里根本没有“分区”概念;第二,看看节点的内存布局,是不是多个原子变量挤在同一条缓存行上,如果是,用alignas(64)做填充;第三,直接放弃CAS,加一个不到20纳秒的短临界区锁,实测在很多场景下反而更快。BqLog总线的实践说明,无锁不是目的,低延迟才是,手段要为目标服务。
6.2 极端竞争下总线会退化吗
会,但退化形态是“所有日志集中到空闲节点”,不会死锁,也不会丢数据。最坏情况下,总线退化成和单队列类似的形态,但因为有负载漂移机制,只要空闲节点存在,流量会在某个周期内被重新拉开。我在调试时见过一次线程数超过节点数3倍以上的极端场景,性能曲线出现了轻微波动,但不至于崩。建议线上节点数至少是峰值线程数的1.5倍,冗余度留够,才能保证漂移时有地方可去。
6.3 用自定义分配器提升缓存命中率
节点内部的data指针指向的是日志内容缓冲区。如果这块内存是用系统malloc分配的,地址往往是随机的,总线上多个节点之间的内存不连续,扫描时缓存命中率会受到拖累。BqLog的做法是专门写了一个内存池,一次性从系统申请几大块连续内存,再按节点粒度切分。这样总线扫描节点时,顺带把相邻节点的数据区也预取到了缓存里,实际的扫描和写入开销又能再降一截。这种做法看着不复杂,但对日志这种高频小对象写入的场景非常有效。
我在实际使用中还发现一个小技巧:总线节点个数一旦确定,就不要频繁调整。动态增删节点会引入全局同步成本,反而损失性能。比较稳妥的做法是按项目生命周期做一次规划,比如预估并发线程数是16,就把节点数设为32,留一倍余量,然后在运行期间只做水位漂移,不动态改节点数。
最后分享一点个人实操体会
日志组件这种基础设施,性能瓶颈从来不在“日志”本身,而在并发模型。第一代环形队列的教训是:当你把并发写入强行塞进一个共享结构时,无论这个结构原本多快,最终都会被锁、CAS、伪共享拖垮。自适应总线的价值,恰恰是承认了“多个线程就是要同时写”这个现实,然后用分层分流的方式,把共享代价从“强制排队”变成“自由分流”。这个思路不只适用于日志,写任何高频并发组件都可以借鉴。
手里有BqLog源码、或者想自己实现一个日志库的朋友,建议从最小版本开始:先找一块连续内存做存储池,用rear + length表示环形队列,再加一个后台批量刷新线程,把单线程流程跑通。然后加上多线程压测,观察锁竞争数据,最后再上一套自适应总线入口。每一步改动都能明确看到性能数据的变化,比我在这写一万字都管用。