前言
也许大家都知道,分析KernelDump有个常用的工具叫Crash,在我刚开始学习分析KernelDump的时候,总是花大量的时间折腾这个工具的用法,却总是记不住这个工具的功能。后来有一次在参加某次内部分享的时候,有位大佬说了一句话让我印象非常深刻:这些工具怎么用的大家不用记,等到真正开始用的时候你就会猜到这个工具有什么功能。
这篇文章我想通过分析一个实际的案例,尽量把学习KernelDump需要用到的知识串起来,虽然某些知识也许只会在这个案例中用到,但是我相信所用到的方法是可以应用到各个地方的。
起线上有一台VM宕机了,刚好有抓到dump,拿到一台测试机上就可以开始分析了。首先需要的是kernel版本对应的symbol,如果事先不知道kernel的版本,可以通过`stringscorefile|grep"Linuxversion"'获取到当前corefile的kernel版本,例如3.10.0-862.14.4._64
在获取到内核版本之后,根据相应的发行版以及系统架构到特定的symbol发布页面下载symbol,这里的发行版是Centos,可以到。如果是Ubuntu发行版,可以到。要找到指定kernel版本的symbol很简单,只需要拿着kernel版本3.10.0-862.14.4._64搜一下就能找到了,通常我们需要的symbol的只有下面这三个中的两个,但是我总是记不住是哪两个,所以我会把三个都下载下来并安装:_64.rpm、_64.rpm、kernel-debuginfo-common-x86_64-3.10.0-862.14.4._64.rpm。在安装的时候由于依赖的关系需要先安装common的symbol才能安装其它symbol,另外如果测试机上的kernel版本比corefile的版本新,需要加上--force选项才能安装上。
承在symbol安装完之后,就可以通过crash载入corefile和symbol了。
[root@iZxxx1Zcrash]1SMPWedSep2615:12:11UTC2018MACHINE:x86_64(2500Mhz)MEMORY:16GBPANIC:"kernelBUGatdrivers/virtio/virtio_:278!"PID:278COMMAND:"kworker/2:1H"TASK:ffff917c6d3b3f40[THREAD_INFO:ffff917c64798000]CPU:2STATE:TASK_RUNNING(PANIC)
PANIC:"kernelBUGatdrivers/virtio/virtio_:278!"
这个信息告诉我们,系统触发了位于drivers/virtio/virtio_这个文件的第278行的Bug,这里系统之所以知道是Bug,是因为编写这段代码的大佬在这里埋了一个检测的点,这个待会我们会在源码里看到。
在看完上面的信息后,我的习惯是先看看当时系统在做什么,通过bt命令可以看到当时的调用堆栈:
crashbtPID:278TASK:ffff917c6d3b3f40CPU:2COMMAND:"kworker/2:1H"1[ffff917c6479b8d0]do_trapatffffffff8bf1cea03[ffff917c6479b9d0]invalid_opatffffffff8bf28aee[exceptionRIP:virtqueue_add+1186]RIP:ffffffffc023a382RSP:ffff917c6479ba80RFLAGS:00010097RAX:0000000000000081RBX:ffff917c6c67d000RCX:0000000000000002RDX:0000000000000081RSI:ffff917c6479bc00RDI:ffff917c6c67d000RBP:ffff917c6479bae8R8:0000000000000001R9:ffff917c6b48a380R10:ffff917c6b410000R11:0000000000000002R12:ffff917c6479bc18R13:ffff917c6479bc18R14:ffff917c6479bc00R15:0000000000000001ORIG_RAX:ffffffffffffffffCS:0010SS:00185[ffff917c6479baf0]virtqueue_add_sgsatffffffffc023a437[virtio_ring]7[ffff917c6479bc68]virtio_queue_rqatffffffffc03876f9[virtio_blk]9[ffff917c6479bd50]blk_mq_do_dispatch_schedatffffffff8bb2f76e11[ffff917c6479bde8]__blk_mq_run_hw_queueatffffffff8bb2936213[ffff917c6479be20]process_one_workatffffffff8b8b613f15[ffff917c6479bec8]kthreadatffffffff8b8bdf21
上图打印的信息包含函数调用堆栈和各寄存器的值,这里挑几个比较重要的寄存器讲一下。RIP指向正在执行的指令地址,在发生宕机之前,系统最后执行的函数是virtqueue_add,导致宕机的语句位于virtqueue_add+1186。根据x86_64Linux系统的函数调用约定,RDI,RSI,RDX,RCX,R8,R9为传入函数的前六个参数,如果参数超过六个,第七个以上的参数将通过栈传递。注意在实际函数执行的过程中,寄存器的值可能会改变。
现在来看看ffffffffc023a382+1186这行代码到底是什么,通过dis命令可以查看到对应的汇编。但当我们执行disvirtqueue_add+1186的时候,发现报错了,报错的内容是symbol有重复。
crashdisvirtqueue_add+1186dis:virtqueue_add+1186:duplicatetextsymbolsfound:ffffffffc0239ee0(t)virtqueue_add[virtio_ring]ffffffffc023ab73(t)virtqueue_add[virtio_ring]
我们可以通过RIP的值来计算出当前的virtqueue_add对应的是哪个symbol,计算方法很简单,只要把RIP的值减去偏移量1186即可。
crashp/x0xffffffffc023a382-1186$1=0xffffffffc0239ee0
通过disffffffffc0239ee0可以打印出virtqueue_add的汇编,找到virtqueue_add+1186
0xffffffffc023a378virtqueue_add+1176:mov0x60(%rbx),%eax0xffffffffc023a37bvirtqueue_add+1179:jmpq0xffffffffc023a299virtqueue_add+9530xffffffffc023a380virtqueue_add+1184:ud20xffffffffc023a382virtqueue_add+1186:ud2
该行汇编实际上是ud2,这是一条undefined的语句,也正是因为这条语句让系统宕机了。这个时候通常应该往上找,看看之前执行过的指令是什么。这里上一条指令是jmpq,这是无条件跳转语句,跳转到virtqueue_add+953,也就是说ud2指令的上一条指令一定不是jmpq这条,可以猜到应该是前面有某个跳转直接跳到这里来了,往上找找就可以找到
0xffffffffc0239ef4virtqueue_add+20:mov%rsi,-0x48(%rbp)0xffffffffc0239ef8virtqueue_add+24:mov%edx,-0x2c(%rbp)0xffffffffc0239efbvirtqueue_add+27:mov%ecx,-0x38(%rbp)0xffffffffc0239efevirtqueue_add+30:mov%r8d,-0x58(%rbp)0xffffffffc0239f02virtqueue_add+34:mov%r9,-0x60(%rbp)0xffffffffc0239f06virtqueue_add+38:je0xffffffffc023a384virtqueue_add+11880xffffffffc0239f0cvirtqueue_add+44:cmpb$0x0,0x59(%rdi)0xffffffffc0239f10virtqueue_add+48:mov%rdi,%rbx0xffffffffc0239f13virtqueue_add+51:jne0xffffffffc023a05dvirtqueue_add+3810xffffffffc0239f19virtqueue_add+57:mov-0x2c(%rbp),%eax0xffffffffc0239f1cvirtqueue_add+60:cmp%eax,0x38(%rdi)0xffffffffc0239f1fvirtqueue_add+63:jb0xffffffffc023a382virtqueue_add+1186
可以看到跳转的语句是jb0xffffffffc023a382virtqueue_add+1186,跳转的条件是%eax小于[%rdi+0x38]。那%eax和[%rdi+0x38]里面存的值是什么呢?这个时候就需要对照源码来看了。通过dis-l可以看到函数所在的源文件,但是直接执行dis-lffffffffc0239ee0会发现没有源文件的信息,这种情况通常是对应的debug模块没有导进来。通过mod命令可以看到当前的模块,找到我们需要的模块,通过mod-s找到模块对应的目录,再通过相同的命令导入即可,如:
crashmod-svirtio_ringMODULENAMESIZEOBJECTFILEffffffffc023c0e0virtio_ring22746/usr/lib/debug/usr/lib/modules/3.10.0-862.14.4._64/kernel/drivers/virtio/virtio__ring/usr/lib/debug/usr/lib/modules/3.10.0-862.14.4._64/kernel/drivers/virtio/virtio__ring22746/usr/lib/debug/usr/lib/modules/3.10.0-862.14.4._64/kernel/drivers/virtio/virtio_
把所有缺少的模块导入进来之后,再次执行dis-lffffffffc0239ee0就可以看到对应的源文件了。部分virtqueue_add源代码如下:
241staticinlineintvirtqueue_add(structvirtqueue*_vq,242structscatterlist*sgs[],243unsignedinttotal_sg,244unsignedintout_sgs,245unsignedintin_sgs,246void*data,247gfp_tgfp)248{249structvring_virtqueue*vq=to_vvq(_vq);250structscatterlist*sg;251structvring_desc*desc;252unsignedinti,n,avail,descs_used,uninitialized_var(prev),err_idx;253inthead;254boolindirect;255256START_USE(vq);257258BUG_ON(data==NULL);259260if(unlikely(vq-broken)){261END_USE(vq);262return-EIO;263}264265if277278BUG_ON(total_);279BUG_ON(total_sg==0);280281head=vq-free_head;282283/*Ifthehostsupportsindirectdescriptortables,andwehavemultiple284*buffers,:tunethisthreshold*/285if(vq-indirecttotal__free)286desc=alloc_indirect(_vq,total_sg,gfp);287else288desc=NULL;289290if(desc){291/*Useasinglebufferwhichdoesn'tcontinue*/292indirect=true;293/*Setupresttousethisindirecttable.*/294i=0;295descs_used=1;296}else{297indirect=false;298desc=;299i=head;300descs_used=total_sg;301}
通过dis-lffffffffc0239ee0打印出的信息并结合之前的分析,可以知道:1.virtqueue_add的前五个参数分别是structvirtqueue、structscatterlist、unsignedint、unsignedint、unsignedint类型的,对应的是RDI,RSI,RDX,RCX,R8这五个寄存器的值。2.触发bug的语句是第278行的BUG_ON(total_);
通过structvirtqueueffff917c6c67d000可以解析出第一个参数的结构:
crashstructvirtqueueffff917c6c67d000structvirtqueue{list={next=0xffff917bbefa82c8,prev=0xffff917bbefa82c8},callback=0xffffffffc0387000,name=0xffff917c6c7a1dcc"",vdev=0xffff917bbefa8000,index=0,num_free=1,priv=0xffffadff81b5e010}
回到刚刚我们讨论的%eax和[%rdi+0x38],[%rdi+0x38]实际上就是virtqueue中偏移量为0x38的值,通过struct-ovirtqueue可以打印出virtqueue各成员的偏移:
crashstruct-ovirtqueuestructvirtqueue{[0]structlist_headlist;[16]void(*callback)(structvirtqueue*);[24]constchar*name;[32]structvirtio_device*vdev;[40]unsignedintindex;[44]unsignedintnum_free;[48]void*priv;}SIZE:56
这里又出现了一个问题,0x38是十进制的56,而这个结构体的大小总共只有56个字节,难道是“溢出”了?仔细阅读代码后发现,代码里有一句structvring_virtqueue*vq=to_vvq(_vq);,to_vvq是一个宏,定义如下#defineto_vvq(_vq)container_of(_vq,structvring_virtqueue,vq),实际上这就是对container_of的一个封装,container_of的功能跟字面意思很接近,这里virtqueue类型的_vq变量实际上是vring_virtqueue类型的vq变量的一个成员变量,通过container_of(_vq,structvring_virtqueue,vq)把vq计算出来。我们通过struct-ovring_virtqueue来查看vring_virtqueue的结构:
crashstruct-ovring_virtqueuestructvring_virtqueue{[0]structvirtqueuevq;[56]structvringvring;[88]boolweak_barriers;[89]boolbroken;[90]boolindirect;[91]boolevent;[92]unsignedintfree_head;[96]unsignedintnum_added;[100]u16last_used_idx;[104]bool(*notify)(structvirtqueue*);[112]boolwe_own_ring;[120]size_tqueue_size_in_bytes;[128]dma_addr_tqueue_dma_addr;[136]structvring_desc_statedesc_state[];}SIZE:136
可以看到实际上virtqueue结构就在vring_virtqueue偏移为0的地方,因此可以直接通过structvring_virtqueueffff917c6c67d000来解析
vring_virtqueue结构:
crashstructvring_virtqueueffff917c6c67d000structvring_virtqueue{vq={list={next=0xffff917bbefa82c8,prev=0xffff917bbefa82c8},callback=0xffffffffc0387000,name=0xffff917c6c7a1dcc"",vdev=0xffff917bbefa8000,index=0,num_free=1,priv=0xffffadff81b5e010},vring={num=128,desc=0xffff917c6bf68000,avail=0xffff917c6bf68800,used=0xffff917c6bf69000},weak_barriers=true,broken=false,indirect=true,event=false,free_head=94,num_added=0,last_used_idx=38531,notify=0xffffffffc0249a50,we_own_ring=true,queue_size_in_bytes=5126,queue_dma_addr=,desc_state=0xffff917c6c67d088}
因此[%rdi+0x38]实际上获取的是vring结构里偏移量为0的即第一个成员的值,这里获取到的值就是128。现在我们已经通过这种方法获取到触发bug的语句中BUG_ON(total_);的值了,而total_sg实际上是virtqueue_add的第三个参数,保存在RDX寄存器里,是0x81,即十进制的129。
合至此,我只是分析了这几个数据结构中相关的变量内容,还没有解释这些变量或者函数的含义,现在我们已经验证了触发BUG的条件total_,但是为什么会出现这种情况呢?要分析这几个变量的值需要回溯到调用这个函数的函数,最终可能需要一直回溯到发起IO请求的应用层程序,这显然是一件非常麻烦的事情。换一个角度来想,total_sg是vm需要的scatterlist的总数,scatterlist是一个跟物理内存有关的结构,这里可以简单理解为vm所需要的物理内存,而vring是virtio前后端数据传输的载体,这里可以简单理解前后端数据传输的能力。直观的感觉是total_sg确实不应该比大,但实际上total_sg只比大1,而且这里total_sg的值与我刚开始的想法不一样,由于total_sg是unsignedint类型的,而这里的比较是total_,因此我开始的想法是total_sg下溢出了。分析到这里,我抱着试一试的态度把BUG_ON(total_);丢到Google上搜了一把,发现这行代码已经在某个版本中patch掉了,最新的kernel里把BUG_ON改成了低一级的WARN_ON_ONCE,同时把条件改成了total_!vq-indirect。也就是说,在使用了indirectdescriptors的情况下,是允许total_这中情况出现的,那如何验证vm有没有使用indirectdescriptors呢?实际上在vring_virtqueue中的成员indirect标示了是否使用indirectdescriptors,在上面执行structvring_virtqueueffff917c6c67d000的时候已经把indirect的值打印出来了,vm确实使用了indirectdescriptors,因此这个bug实际上触发得并不合理,仅仅只判断total_就触发宕机的条件太过严格了。
总结这个宕机问题到这里就算分析完了,最后解决的方案是升级内核,考虑到目前Centos官方还未接受该patch,需要手动编译修复或通过第三方repo升级。实际上很多奇奇怪怪的问题都可以通过升级内核来解决,但是最新的内核同样可能遇到奇奇怪怪的问题,谁知道下一个发现内核bug后写了patch最后被社区接受的会不会是自己呢?希望大家通过这篇文章能有所收获。文章写得不好或不对的地方请各位大佬不吝赐教。