“土法”排查与修复一个 Linux 内核 Bug

最新推荐文章于 2022-07-19 12:05:38 发布

IT老涵

最新推荐文章于 2022-07-19 12:05:38 发布

阅读量732

点赞数

分类专栏：程序员安全网络文章标签：网络安全信息安全计算机网络

本文链接：https://blog.csdn.net/HBohan/article/details/119910239

版权

本文记录了一次使用'土法'排查与修复一个13年历史的Linux内核bug的过程。在用户环境中，发现产品产生了一个CPU消耗高的僵尸进程，由于现场条件限制，使用了perf工具进行执行流跟踪。分析发现，问题可能出在tracing_read_pipe函数的死循环。通过perf记录和分析，定位到循环块，并通过内存抓取和模拟执行，进一步确定死循环的原因。最终找到了bug的根本原因，并提出了修复方案。此外，还分享了如何复现此bug和系统恢复的方法，以及调试过程中采用的各种技术手段。

摘要由CSDN通过智能技术生成

最近有幸捡了个漏，修了个有13 年历史的 Linux 内核 bug，相关修复已经合并到 Linux 主线版本 5.14-rc3。发现新的 Linux 内核 bug 的机会不总是有，在客户现场进行调试和诊断往往会受到各种限制以致于不得不使用一些“土法”，因此写个博客日志一下，以供备忘与交流。
在这里插入图片描述
我们在一个用户环境中首次发现了这个bug：用户使用我们的产品后，发现我们的产品生成了一个不断消耗 CPU 的僵尸进程，要求我们将他们的业务系统复原，并给出异常的排查结果与修复方案。

在这里插入图片描述

登陆用户宿主机进行调试，发现该僵尸进程的线程组包含两个线程：5543 和 5552。其中 5543 是进程组根线程，目前处于已经退出的 Zombie 状态；而 5552 处于 Running 状态。它们父进程是 1 号进程，显然作为最终的 subreaper 它也无法回收这个进程。尝试使用 kill -9 5552 指令发送 SIGKILL 信号，发现并没有任何效果，因此可以断定 5552 task 在内核态死循环而无法被回收。
在这里插入图片描述
为了获悉当前5552 线程在内核态的执行状态，尝试执行 cat /proc/5552/stack，不料返回Running。幸好用户预装了perf 指令，使用 perf record -a -g 抓取系统全局的 callgrind，发现该进程似乎卡在了 trace_pipe 的读取函数（tracing_read_pipe）中。
【学习资料】
先前已知社区报告过的和tracing_read_pipe 相关的死循环有一个是因为seq_buf_to_user() 函数错误使用可能会溢出的 seq_buf.len导致的，针对该问题的修复已经在Linux 主线版本 4.5 合并了。而出现问题的主机通过 uname -r 获取的版本号为 4.6.0-1.el7.elrepo.x86_64，通过反汇编/proc/kcore 中的 load2 节，查看 seq_buf_to_user 的实现发现确实包含了该修复。因此我们怀疑 tracing_read_pipe 中仍然有未修复的 bug，且用户的宿主机成功地触发了这个 bug。

为了创建更易于调试的环境，尝试让测试同事在内部测试环境安装部署该内核版本的发行版，并安装我们的产品，但无法复现该bug，说明该 bug 的复现条件可能比较复杂或者需要长时间运行才会复现，不适合当前情景下的问题排查。而在用户宿主机上该 bug 比较稳定且没有自动恢复的迹象，因此经过沟通后用户表示可以在用户宿主机上直接排查，但这台机器上虽然存在该 bug 但其部分业务仍然运行着，因此希望能在不能重启该机器的前提下进行排查，并尽可能给出不重启计算机就恢复系统的方案。

【学习资料】

“土法”之使用perf跟踪执行流

我们知道调试linux 内核的一种有效的方式是使用 kgdb。而我们一般通过 kgdboc 来使用 kgdb：首先配置虚拟机的串口配置，使得另一台主机或者当前虚拟化平台可以通过串口与该宿主机通信，并设置 gdboc 的参数为被开放的串口；然后获取待调试宿主机的解压映像 vmlinux，为了方便调试还会获取当前内核的源码和调试信息；最后在待调试宿主机上通过 echo g > /proc/sysrq-trigger 发起内核态调试中断，然后远程主机启动 gdb 并连接到待调试宿主机的串口上进行调试。

但是这种调试方法在实际用户环境（特别是ToB 产品中的客户环境）中基本行不通：首先与我们对接提供远程的用户只能提供 SSH 连接访问，并没有权限修改当前宿主机的配置；其次我们也了解到用户的云主机提供商也没有提供串口配置的能力；再然后由于当前我们没有获取到任何信息，需要经常发起调试中断甚至单步调试来获取到有效信息，而每次发生调试中断都会导致宿主机整体被冻结，影响其正在运行的业务的连续性。

我们先前在排查的时候，发现用户在这台机器上安装了perf 指令，它最广为人知的一点是可以抓取用户态和内核态的执行流采样，并通过 perf report 等指令对抓取到的数据进行聚合，输出性能日志等报告用于诊断和优化等用途。而用户进行分析时往往会使用动态的过滤条件，因此 perf 抓取并持久化的是大量的采样数据，通过 perf script 等指令可以将采样数据输出为字符流形式。

我们最为熟悉的perf record 指令执行时会设置一个指定频率的计时器，每当计时器超时即会发出一个中断并执行 perf 抓取现场的中断处理函数，这种采样方式具有随机性，执行足够长时间就会形成覆盖主要执行流的“采样点云”，有点蒙特卡洛方法的意味；此外 perf record 还可以指定 -e mem::x，设置某个调试寄存器DRx 的值为使得该地址被“执行访问”时产生调试中断（这一方法又被称为硬件断点）并进行抓取，而由于其抓取行为的确定性，主要用来针对“采样点云”覆盖不到但又对分析十分关键的地方进行采样。

由开头我们通过perf record -a -g 抓取的结果来看，tracing_read_pipe 是第一个调用了多个其他函数的函数，而从 5552 进程的表现来看，不妨大胆猜测由于 5552 进程执行系统调用时 tracing_read_pipe 函数发生了死循环以致该函数一直不返回并消耗大量 CPU。因此我们不妨先从 tracing_read_pipe 函数开始排查。

通过反汇编可以获悉tracing_read_pipe 函数在当前内核线性地址的 ffffffff811520e0~ffffffff811523fa 范围内。执行 perf record -a -I 周期性采样并在每次采样时抓取处理器现场，并执行 perf script –tid=5552 -F comm,pid,ip,iregs | sort | uniq 对采样数据进行去重和展示，筛选落在范围 ffffffff811520e0~ffffffff811523fa 内的数据，如下：

cloudwalker-eng 5552 ffffffff811521c9 ABI:2 AX:0xfffffffffffffff0 BX:0xfff CX:0xffff8804e7fc5098 DX:0x0 SI:0xc0002bc000 DI:0xffff8804e7fc6098 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff811521c9 FLAGS:0x246 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
cloudwalker-eng 5552 ffffffff811521df ABI:2 AX:0x1 BX:0xfff CX:0xff0 DX:0x0 SI:0xffff8804acbcf940 DI:0x286 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff811521df FLAGS:0x246 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
cloudwalker-eng 5552 ffffffff811521e8 ABI:2 AX:0x1 BX:0xfff CX:0xff0 DX:0x0 SI:0xffff8804acbcf940 DI:0x286 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff811521e8 FLAGS:0x202 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
cloudwalker-eng 5552 ffffffff81152204 ABI:2 AX:0xfff BX:0xfff CX:0xff0 DX:0x0 SI:0xffff8804acbcf940 DI:0x286 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff81152204 FLAGS:0x246 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
cloudwalker-eng 5552 ffffffff81152208 ABI:2 AX:0xfff BX:0xfff CX:0xff0 DX:0x0 SI:0xffff8804acbcf940 DI:0xffff8804e7fc5098 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff81152208 FLAGS:0x246 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
cloudwalker-eng 5552 ffffffff81152211 ABI:2 AX:0xfff BX:0xfff CX:0xff0 DX:0x0 SI:0xffff8804acbcf940 DI:0xffff8804e7fc5098 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff81152211 FLAGS:0x246 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
cloudwalker-eng 5552 ffffffff8115221c ABI:2 AX:0xfff BX:0xfff CX:0xff0 DX:0x1060 SI:0xffff8804acbcf940 DI:0xffff8804e7fc5098 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff8115221c FLAGS:0x246 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
cloudwalker-eng 5552 ffffffff81152230 ABI:2 AX:0xfff BX:0xfff CX:0xff0 DX:0x1060 SI:0xffff8804acbcf940 DI:0xffff8804e7fc5098 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff81152230 FLAGS:0x246 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
cloudwalker-eng 5552 ffffffff8115223a ABI:2 AX:0x0 BX:0xfff CX:0x107 DX:0x1060 SI:0xffff8804acbcf940 DI:0xffff8804e7fc58c0 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff8115223a FLAGS:0x10246 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
cloudwalker-eng 5552 ffffffff8115223a ABI:2 AX:0x0 BX:0xfff CX:0x117 DX:0x1060 SI:0xffff8804acbcf940 DI:0xffff8804e7fc5840 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff8115223a FLAGS:0x10246 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
cloudwalker-eng 5552 ffffffff8115223a ABI:2 AX:0x0 BX:0xfff CX:0x127 DX:0x1060 SI:0xffff8804acbcf940 DI:0xffff8804e7fc57c0 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff8115223a FLAGS:0x10246 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
... // 忽略约 20 条产生自 ffffffff8115223a 的记录，此时在进行 memset
cloudwalker-eng 5552 ffffffff8115223d ABI:2 AX:0x0 BX:0xfff CX:0x0 DX:0x1060 SI:0xffff8804acbcf940 DI:0xffff8804e7fc60f8 BP:0xffff8807babdbe18 SP:0xffff8807babdbdb0 IP:0xffffffff8115223d FLAGS:0x246 CS:0x10 SS:0x18 R8:0x3 R9:0x0 R10:0xffff8808189d14e8 R11:0x0 R12:0xffffffffffffffff R13:0xffff8804e7fc60e0 R14:0xffff8804e7fc60c8 R15:0xffff8804e7fc4000
cloudwalker-eng 5552 ffffffff81152258 ABI:2 AX: