前几天我们正在运营的一款产品发生了崩溃,我花了两天尝试用 gdb 分析了 coredump ,虽然最后还是没能找到 bug ,但还是觉得应该做一些总结。
产品是基于 skynet 开发的,由于历史原因,它基于的是 skynet 1.0 之前 2015 年中的一个版本,由于这两年一直没出过什么问题,所以维护人员懈怠而没有更新。
崩溃的时候,关于 Lua 部分的代码缺少调试符号信息,这加大了分析难度。现在的 skynet 在编译 lua 时,加入了 -g 选项,这应该可以帮助未来出现类似问题时更好的定位问题。
导致代码崩溃的直接原因是 rip 指向了一个数据段的地址,准确的说,跳转到了当前工作线程拥有的 lua 虚拟机的主线程 L 那里。
发现这条线索很容易,skynet 的其它部分是有调试符号的,可以在崩溃的调用栈上看到,服务的 callback 函数的 ud 和崩溃地址一致,而 lua 服务的 ud 正是 L 。用 gdb 的 p (lua_State
*)地址 查看这个结构,也能观察到这个数据结构的内容正是一个 lua_State
。
由于用 bt 查看的调用栈是不正常的,所以可以断定在函数调用链的过程中应该是发生了某种错误改写了 C 栈的内容。在这种情况下,gdb 多半靠猜测来重建调用链(就是用 bt 看到的那些)。
现代编译器经过优化代码之后, C 栈上已经没有 stack frame 的基地址了,所以现在不能简单的看堆栈的数据内容来推测 stack frame 。也就是经过优化的代码不一定适用 rbp 来保存 stack frame ,它也不一定入栈。对于 gcc ,这个优化策略是通过 -fomit-frame-pointer 开启的,只要用 -O 编译,就一定打开的。在 stack 本身出问题时,gdb 的猜测很可能不准确,人工来猜或手工补全或许更靠谱一些。方法就是先用 x/40xg $rsp 打印出 C stack 的内容,然后观察确定 stack 上的哪些数据落在代码段上。所有有函数调用的地方,一定有处于代码段上的某处返回地址指针。
主程序的代码段一般都地址偏低,动态链入的代码段可以用 info sharedlibrary 来查看。返回地址肯定是落在函数代码的内部,而肯定不会是函数入口,而这些地址除了函数调用外,都不可能用正常的 C 代码生成出来,所以识别性很强,不会有歧义。
如果觉得某个指针是函数返回地址,可以用 x/10i 地址 来反汇编确认。
但是需要注意的是,即使在 C stack 上发现一个函数返回地址,并不说明这个函数调用尚未返回。它只能说明这个函数至少被调用过。这是因为,汇编在 call 一个函数时,会把当前调用处的地址压栈。而调用结束后,ret 指令返回只是修改了 rsp 这个栈指针,而数据本身是残留在栈上的。这也是为什么 gdb 有时候也会猜错。
在这次的案例里,崩溃发生在执行跳转到了数据段,这种情况多半是因为 call 指令调用的是一个间接引用,在 C 层面来看,就是调用了一个函数指针。这种情况下,跳转地址肯定还在寄存器里。用 info registers 可以查看。(注:在 64bit 平台下,查看寄存器内容非常重要,因为 64bit 下,函数调用的前四个参数是通过寄存器 rdi rsi 传递而非堆栈,往往需要结合 disass 反汇编看代码去推算。)
当然,按 lua 自己的正常逻辑,是不可能把 L 作为一个函数指针来调用的。按我的猜测,这里出错比较大的可能是 longjmp 的时候数据出错,恢复了错误的寄存器。btw, setjmp 在生成 jmp_buf
时,对于 rsp rbp 这类很可能用于地址的寄存器,crt 做了变形(mangling)处理,所以很难简单的靠写越界写出一个巧合的错误值。
对于调试崩溃在 lua 内部的情况,比较关键的线索通常是 L 本身的状态。因为业务的主流程其实是用 lua vm 驱动的,L 的 callinfo 也就是 lua 的 stack frame 信息更多。
对于 skynet ,在正常运行的时候通常会有两个活动的 L 。一个是主线程,用来分发消息;但消息本身是在一个独立的 coroutine 中进行的。以上可以确定主线程,而子线程的 L 可以在寄存器和 stack frame 里找。由于没有调试符号,所以可以靠猜来寻找,这并不算太麻烦。要确定一个地址是否是 L ,只需要查看 L->l_G
看是否和前面找到的主线程 L 的对应值是否相同。
在缺少调试符号的情况下,会发现 lua 下的一些内部数据结构 gdb 无法识别。这个时候可以用 add-symbol-file 来导入需要的结构信息。方法是加上 -g 重新编译一下 lua ,把一些包含这些结构的文件,例如 ldo.o 加进来。
我在分析这次的问题时,写了脚本查看两个 L 的 lua 调用栈,这些脚本只要对 lstate.h 里的 callinfo 数据结构熟悉就很容易写出来。lua 的调试信息很丰富,找到源文件名和行号都很容易。另外,L 栈顶的数据是什么也是重要的线索,可以推导出崩溃发生时 Lua 的状态。
这次我们崩溃的程序最后停在主线程的 resume 调用子线程上。子线程调用了 skynet.sleep ,也就是最后把 "SLEEP", session 通过 yield 传给了主线程。这些要传出的量可以在子线程的 L->top
上查到。虽然 lua 本身已经把值 pop 出去了,但 pop 本身是不清空栈的,只是调整了栈顶指针,所以在 gdb 下依然可见。主线程也接收到了传过来的数据,数据栈上可见。
不过这次的吊诡之处在于,lua 线程间拷贝数据这个过程是在 lcorolib.c 中的 auxresume 函数中执行的,在 luaB_coresume
里还需要在结果中插入一个 boolean 。而我在 coredump 数据中发现了拷贝过程已经完成,但是 boolean 却没有压入。那么事故发生点只可能在两者之间。不过在 auxresume 返回到后续 push boolean 之间只有几行汇编代码,绝对不可能出错。
唯一能解释的就是在 lua_resume
期间,子线程运行的流程破坏了 C 的 stackframe ,让 auxresume 没能正确的返回到调用它的 luaB_coresume
中。但怎样才能制造出这种情况,我暂时没有想法。
在 C 层面制造出崩溃的可能性并不是很多,数据越界是一类常见的 bug (这次并不像);另一类是内存管理出错,比如对同一个指针 free 多次,导致内存管理器出错,把同一个地址分配给两个位置,导致两个对象地址重叠。后一类问题能干扰到 C 的 stack frame 可能性比较小,除非有堆上的对象指针指向了栈地址,然后并引用。这次的 bug 中,最打的线索是 L->errorJmp
,也就是 lua 线程中指向恢复点的 jmp_buf
,它是在 C 栈上的。
L 中有一些相关变量可以推测 resume/yield/pcall 等的执行状态:L->nny
L->nCcalls
L->ci->callstatus
等都是。我分析的结果是在 auxresume 返回后,没有继续运行 luaB_coresume
中的 push boolean 过程,却又运行了新的一轮 luaD_pcall
,导致了最终的崩溃。这可以通过 L 的 errorJmp 的 status 得到一定的佐证。不过 C stack 上没有 luaB_coresume
的返回地址比较难解释,只能说是可能被错误的运行流程覆盖掉了。
gc 会是触发 bug 的多发点,因为 gc 是平行于主流程同步进行的。这次崩溃点的子线程的 lua 栈帧停留在 yield 函数上,在此之前也的确调用了 gc step 。但是,我们可以通过查阅 L 的 gcstate 变量查看 gc 处于什么阶段。在这次的事发现场,可以看到 gcstate 为 GCSpropagate 也就是 mark 阶段,所以并不会引发任何 __gc
流程,也没有内存释放。
结论:对于 bug ,暂时没有结论。不过对于调试 lua 编写的程序,还是积累了一些经验:
一定要在编译 lua 时加 -g ,虽然 lua 本身出严重 bug 的可能性极低,但可以方便在出问题时用 gdb 分析。
在 gdb 中查看 lua 的调用栈很有意义,分析 L->ci
很容易拿到调用栈信息。
记得查看一下 lua 的数据栈内容,包括已经 pop 出去,但还残留在内存中的数据,可以帮助分析崩溃时的状态。
记得查看 L 中保留的 gcstate GCdebt 等 gc 相关变量,可以用于推断 lua gc 的工作状态。
L 中的 nny nCcalls errorJmp 可以帮助确定 lua 到 C 的调用层次。注意:一个 yield 状态的 coroutine ,errorJmp 指针应该为 NULL 。
另外,gdb 分析 skynet 可以从下面的线索入手:
context 对象里能找到当前服务的地址、最后一个向外提起的请求的 session 、接收过多少条消息等。结合 log 文件来看会有参考价值。
如果想找到内存中其它的服务对象(非当前线程上活动的),可以试试 p *H 。 H 是个数组,定义在 skynet_handle.c
中,里面有所有服务的地址。
如果想找到内存中待唤醒的 timer ,可以试试 p *TI 。它定义在 skynet_timer.c
中。