logo, poster, cover

一次查找分子级Bug的经历,过程太酸爽了

李亚飞
2023.05.11
实战编程 / 技术招聘 / 实时Debug

Debugging is like trying to find a needle in a haystack, except the needle is also made of hay.

Debug调试就像是在大片的干草堆中找针一样,只不过针也是由干草制成的。

在软件开发的世界里,偶尔会出现一些非常隐蔽的 Bug,这时候工程师们像探险家一样,需要深入代码的丛林,寻找隐藏在其中的“幽灵宝藏”。前段时间,我和我的团队也踏上了这样一段刺激、有趣的探险之旅。

最近繁忙的工作告一段落,我总算轻松下来了,想趁这个机会,跟大家分享我们的这次“旅途”。

01 引子

我是 ShowMeBug 的 CEO 李亚飞,是一个古老的 Ruby 工程师。由于 2019 年招聘工程师的噩梦经历,我立志打造一个真实模拟工作场景的 IDE,用来终结八股文、算法横行的技术招聘时代。

这个云上的 IDE 引擎,我称之为轻协同 IDE 引擎——因为它不是为了繁杂重度的工作场景准备的,而是适应于大部分人的习惯、能快速上手熟悉、加载速度快、能协同(面试用)、低延迟感,让用户感受非常友好。

为了达成秒级启动环境的性能要求,我们设计了一套精巧的分布式文件系统架构,其核心是一个可以瞬间复制大量小文件的写时复制 (COW) 技术。IO 吞吐能达到几万人同时在线,性能绝对是它的一大优势。

我们对此信心满满,然而没想到,很快就翻车了。

02 探险启程

2023 年 1 月,北方已经白雪皑皑,而深圳却仍难以感受到冬天的寒意。

我和我的团队在几次打开文件树的某个文件时,会显得有点慢——当时没有人在意,按照常规思路,“网速”背了这个锅。事后我们复盘才发现,这个看似微不足道的小问题,其实正是我们开始这次探险之旅的起点。

1 月底,南方的寒意缓缓侵入。这时候我们的轻协同 IDE 引擎已经开始陆续支持了 Vue2、Vue3、React、Django、Rails 等框架环境,一开始表现都很棒,加载和启动速度都很快。但是,跑了一段时间,我们开始察觉,线上环境就出现个别环境(Rails 环境)启动要 20-30s 才能完成。

虽然其他环境仍然保持了极快的加载和启动速度,但敏锐的第六感告诉我,不行,这一定有什么猫腻,如果不立即行动,势必会对用户体验带来很不好的影响。于是,我开始安排团队排查眼前这个不起眼的问题,我们的探险之旅正式开始。

03 初露希望

湿冷的冬季,夜已深,我和我们的团队依旧坐在电脑前苦苦探索,瑟瑟发抖。

探险之旅的第一站,就是老大难的问题:定位Bug。目前只有某一个环境启动很慢,其他的环境都表现不错。大家想了很多办法都没有想明白为什么,甚至怀疑这个环境的模板是不是有问题——但把代码放在本地启动,最多就2秒。

哎,太诡异了。我们在这里卡了至少一周时间,不断追踪代码,分析日志文件,尝试各种方案,都没有弄清楚一个正常的程序启动为什么会慢。我们一度陷入了疲惫和焦虑的情绪中。

Debug 是种信仰,只有坚信自己能找到 Bug,才有可能找到 Bug。

软件开发界一直有一个低级 Bug 定律:所有诡异的问题都来自一个低级原因。在这“山重水复疑无路”之际,我们决定重新审视我们的探险路径:为什么只有 Rails 更慢,其他并不慢?会不会只是一个非常微小的原因而导致?

这时候,恰好有一个架构师朋友来访,向我们建议,可以用 perf 火焰图分析看看 Rails 的启动过程。

perf火焰图实例

当我们用 perf 来分析时,惊讶地发现:原来 Rails 的启动要加载更多的文件!紧接着,我们又重新用了一个文件读写监控的工具:fatrace,通过它,我们看到 Rails 每次启动需要读写至少 5000 个文件,但其他框架并不需要。

这才让我们突然意识到,会不会是文件系统读写速度不及预期,导致了启动变慢。

04 Bug现身

为了搞清楚是不是文件系统读写速度的问题,我急需一个测试 IO 抖动的脚本。我们初步估算一下,写好这个脚本需要好几个小时的时间。

夜已深,研发同学都陆续下班了。时间紧迫!我想起了火爆全球的 ChatGPT,心想,不如让它写一个试试。

测试 IO 抖动的脚本

Cool,几乎不需要改动就能用,把代码扔在服务器开跑,一测,果然发现问题:每一次文件读写都需要 10-20ms 才能完成 。实际上,一个优秀的磁盘 IO 读写时延应该在亚毫级,但这里至少慢了 50 倍。

Bingo,如同“幽灵宝藏”一般的分子级 Bug 逐渐显现,问题的根因已经确认:过慢的磁盘 IO 读写引发了一系列操作变慢,进而导致启动时间变得非常慢。

更庆幸的是,它还让我们发现了偶尔打开文件树变慢的根本原因,这也是整个系统并发能力下降的罪魁祸首。

05 迷雾追因

看到这里,大家可能会问,这套分布式文件系统莫非一直这么慢,你们为什么在之前没有发现?

非也,早在项目开始的时候,这里的时延是比较良好的,大家没有特别注意这个 IOPS 性能指标,直到我们后面才留意到,系统运行超过一个月时,IO 读写时延很容易就进入到卡顿的状态,表现就是文件系统所在主机 CPU 忽高忽低,重启就会临时恢复。

此时,探险之旅还没结束。毕竟,这个“幽灵宝藏”周围依旧笼罩着一层迷雾。

我们继续用 fatrace(监控谁在读写哪个 IO)监控线上各个候选人答题目录的 IO读写情况,好家伙,我们发现了一个意外的情况:几乎每一秒都有一次全量的文件 stats 操作 (这是一个检测文件是否有属性变化的 IO 操作)!

也就是说,比如有 1000 个候选人正在各自的 IDE 中编码,每个候选人平均有 300 个文件,就会出现每秒 30 万的 IO 操作数!

我们赶紧去查资料,根据研究数据显示,一个普通的 SSD 盘的 IOPS 最高也就到 2-3 万 。于是,我们重新测试了自己分布式文件系统的 IOPS 能力,结果发现也是 2-3 万 。

那这肯定远远达不到我们理想中的能力级别。

这时,问题更加明确:某种未知的原因导致了大量的 IOPS 的需求,引发了 IO 读写时延变长,慢了大约几十倍。

06 接近尾声

我和我的团队继续深究下去,问题已经变得非常明确了:

原来,早在去年 12 月,我们上线一个监听文件增删的变化来通知各端刷新的功能。

最开始我们采用事件监听 (fswatch event),因为跨了主机,所以存在 1-2s 的延迟。研发同学将其改为轮询实现的方案,进而引发了每秒扫描目录的 stats 行为。

当在百人以下访问时,IOPS 没有破万,还足够应对。但一旦访问量上千,便会引发 IO 变慢,进而导致系统出现各种异常:间歇导致某些关键接口 QPS 变低,进而引发系统抖动。

随着“幽灵宝藏”显露真身,这次分子级 Bug 的探险之旅也已经接近尾声。团队大呼:这过程实在太酸爽了!

07 技术无止境

每一个程序员在成长路上,都需要与 Bug 作充足的对抗,要么你勇于探索,深入代码的丛林,快速定位,挖到越来越丰富的“宝藏”,然后尽情汲取到顶级的知识,最终成为高手;或者被它打趴下, 花费大量时间都找不到问题的根源,成为芸芸众生中的一人。

当然,程序员的世界中,不单单是 Debug。

当我毕业 5 年之后,开始意识到技术的真正价值是解决真正的社会问题。前文中我提到,由于我发现技术招聘真是一个极其痛苦的事:特别花面试官的时间,却又无法有效分析出候选人的技术能力,所以创立 ShowMeBug 来解决这个问题:用模拟实战的编程环境,解决科学评估人才的难度。

这个轻协同 IDE 技术从零开发,支持协同文件树、完全自定义的文件编辑器、协同的控制台 (Console) 与终端 (Shell),甚至直接支持 Ctrl+P 的文件树搜索,不仅易于使用,又强大有力。

但是这还不够。要知道,追求技术精进是我们技术人的毕生追求。对于这个轻协同IDE,我们追求三个零:零配置、零启动、零延迟。其中,零启动就是本文所追求的极限:以最快的速度启动环境和切换环境。

因此,探险之旅结束后,我们进一步改进了此文件系统,设定 raid 的多磁盘冗余,采用高性能 SSD,同时重新制定了新磁盘架构参数,优化相关代码,最终大幅提升了分布式文件系统的稳定性与并发能力。

截止本文结尾,我们启动环境的平均速度为 1.3 秒,切换环境速度进入到亚秒级,仅需要 780ms。目前在全球范围的技术能力评估赛道 (TSA) 中,具备 1-2 年的领先性。

08 后记

正当我打算结束本文时,我们内部的产品吐槽群信息闪烁,点开一看:嚯,我们又发现了新 Bug。

立夏已至,我们的探险之旅又即将开始。

技术测评,就用ShowMeBug!

公众号二维码

关注 ShowMeBug 公众号

随时随地发现更多内容

客服二维码

添加 ShowMeBug 官方客服

提升用户体验,解决用户问题

售前顾问

咨询产品方案

扫码立即咨询

技术支持

使用遇到问题

扫码立即咨询