内核Panic和soft lockup分析及排错

1、概述

       众所周知，从事linux内核开发的工程师或多或少都会遇到内核panic，亦或者是soft lockup，前者多半是由于内存泄露、内存互踩、访问空地址等错误致使的，然后者能够确定是由于代码的逻辑不当，进而致使内核进入一个死循环。问题可大可小，当问题足够隐蔽又难以复现时一般会让程序猿们十分抓狂，我前些日子有幸体验了一把，足足花费了我一周时间才成功找到问题，为了让本身之后能从容的面对内核panic，也为了能积累更多的经验，仍是用文字记录下来才是最好的形式。

       提到内核panic就不得不提kdump，这是对付内核panic的利器，kdump其实是一个工具集，包括一个带有调试信息的内核镜像(捕获内核)，以及kexec、kdump、crash三个部分，kdump本质上是一个内核崩溃转储工具，即在内核崩溃时捕获尽可能多的信息生成内核core文件。工做原理以下：

       (1) kexec分为内核态的kexec_load和用户态的kexec-tools，系统启动时将原内核加载到内存中，kexec_load将捕获内核也一块儿加载到内存中，加载地址可在grub.conf中配置，默认为auto，kexec-tools则将捕获内核的加载地址传给原内核；

       (2) 原内核系统崩溃的触发点设置在die()、die_nmi()、panic()，前二者最终都会调用panic()，发生崩溃时dump出进程信息、函数栈、寄存器、日志等信息，并使用ELF文件格式编码保存在内存中，调用machine_kexec(addr)启动捕获内核，捕获内核最终转储core文件。捕获内核一般能够采用两种方式访问原内核的内存信息，一种是/dev/oldmem，另外一种则是/proc/vmcore；

       (3) crash工具提供一些调试命令，能够查看函数栈，寄存器，以及内存信息等，这也是分析问题的关键，下面列举几个经常使用命令。

       log：显示日志；

       bt：加参数-a时显示各任务栈信息；

       sym：显示虚拟地址对应的标志符，或相反；

       ps：显示进程信息；

       dis：反汇编函数或者虚拟地址，经过与代码对比，结合寄存器地址找出出错代码中相关变量的地址；

       kmem：显示内存地址对应的内容，或slab节点的信息，若出错地方涉及slab，经过kmem则可看到slab的分配释放状况；

       rd：显示指定内存的内容；

       struct:显示虚拟地址对应的结构体内容，-o参数显示结构体各成员的偏移；

       下面借用一下别人画的内核panic流程框图：

       一般内核soft lockup问题不会致使内核崩溃，只有设置softlockup_panic才会触发panic，因此若未设置可在崩溃前自行查看系统日志查找缘由，若是查找不出缘由，再借助人为panic转储core文件，这时经过crash分析问题。

       linux中借助看门狗来检测soft lockup问题，每一个cpu对应一个看门狗进程，当进程出现死锁或者进入死循环时看门狗进程则得不到调度，系统检测到某进程占用cpu超过20秒时会强制打印soft lockup警告，警告中包含占用时长和进程名及pid。

       linux内核设置不一样错误来触发panic，其触发选项均在/proc/sysy/kernel目录下，包含sysrq、softlockup_panic、panic、panic_on_io_nmi、panic_on_io_nmi、panic_on_oops、panic_on_unrecovered_nmi、unknown_nmi_panic等。

2、panic实例分析

       涉及的代码是处理DNS请求，在DNS请求中须要对重复出现的域名进行压缩，以达到节约带宽的目的，压缩的思想很简单，采用最长匹配算法，偏移量基于DNS头地址。系统中每一个cpu维护一个偏移链表，每次处理一个域名前都会到链表中查询这个域名是否已经处理过，若处理过这时会使用一个偏移值。

       例如：www.baidu.com，链表中会存储www.baidu.com、baidu.com、com三个节点，以后每次查询链表时若查到则使用节点中的偏移，若未查到则将新出现的域名按照这个规律加到链表中。

这里贴出基本的数据结构：

       struct data_buf {
           unsigned char* buf;
           u16 buflen;
           u16 pos;
       };

       struct dns_buf {
           struct data_buf databuf;
           struct sk_buff* skb;
           u32 cpuid;
       };

       代码中静态分配了50个节点，每处理一个域名时取一个节点挂入链表中，每次panic都发生在查询节点函数get_offset_map(data_buf *dbuf, char *domain)的list_for_each()中。所以，猜想其多是因为遍历到空指针或非法地址致使的，缘由应该是因为内存溢出致使的内存互踩，每次panic都是发生在晚上，通常会发生几回。

       起初的办法是在函数中加入判断条件来调用BUG_ON()函数来提早触发panic，经过验证发现有时会出现list_head节点地址为空，有时会出现遍历节点数超过50次，用反汇编dis命令打印出错节点的地址，最终也只看出了某个节点为空，不过对第二种状况有了一些猜想，压缩时所指向的域名可能出现了问题，在这个函数中徘徊了好久都没有定论，最终得出结论：单纯从这个函数入手是不可能找到缘由的，只有打印出原始请求信息和响应信息才能进一步分析，但这个函数所传入的信息颇有限，最后只能把全部信息都存储在data_buf这个结构体中，这是我能想到的最直接也是代码改动最小的办法，随着问题的深刻这个结构体已经达到了几十个变量，甚至超过了2k大小，也就是超过了函数栈的大小。问题向上追溯到了pskb_expand_head()函数，在这个函数以前打印原始的skb内容，以后打印当前处理的skb内容，发现两次skb的内容不一样，当时就误认为问题出在pskb_expand_head()函数上，下面贴出当时的分析报告：

       从目前分析是由于收到请求包中的edns选项部分数据不正确，并包含大量垃圾数据，这些请求一般来自巴西(200.13.144.4),当请求累积到必定数量时可能就会致使死机，定位到出错代码位于expand_dnsbuf()中，这个函数中又调用了pskb_expand_head()函数，初步推测问题出在pskb_expand_head()函数中。

       出错现象表现为扩展前的SKB数据正确，而扩展后SKB数据已经改变，如原始数据包长度为500(长度不定，240~500不等，正常请求不该该为这么长)，请求中dnsid为0x7ebf，问题区和附加区计数均为1，请求域名为lbs.moji.com,扩展后dnsid仍为0x7ebf，问题区仍为1，附加区则变为0，请求域名则变为zj.dcys.ksmobile.com，也就是可能另外一个正常请求(不带edns)覆盖了当前(带edns，并包含大师垃圾数据)的dnsbuf，但DNSID却未被覆盖，同时覆盖的域名都比原始域名长，当查询到答案后putwired请求域名，此时原域名的'\0'被覆盖，在压缩请求域名时检测不到'\0'，所以致使offset数组溢出或者地址错误，最终死在get_offset_map()函数中。

       两次skb内容对好比下：

       红框中依次为dnsid，附加区数量，请求域名('\0')，pos为当前要写的位置，很显然'\0'已被覆盖，pos以后为edns选项，00 29正确，表示edns选项，10 00表示负载长度4096，80 00为Z标志，通常为0，以后是edns长度，这里为0，通常为11或者12，因此由此看来edns选项数据不正确，以后还有不少垃圾数据。

       其它问题：在本机进行构造这种数据包时并未致使服务器死机，有时有回应，有时则无回应，但回应的数据包依然存在错误，有时是权威区中域名被更改，有时附加段的edns出如今了应答区或者权威区，以下图：

       根本缘由：由于这是偶然现象，而且当请求量特别大时才可能出现，在不死机的状况下很难打印信息，因此目前并未找到根本缘由。

       解决办法：对这种请求能够校验edns选项的合法性以及检验数据长度，如出现这种数据包直接丢掉；或将请求域名存入数组中，必要时能够在回应响应包时从DNS头部重写数据，但不知此种办法是否会致使其它内存错误。

       当时基本上已经快放弃了，刚开始觉得这是由于内存互踩致使的，因此现象应该很差复现，不事后来经过发送大量带有垃圾数据的请求已经可以复现了，可见这不是偶尔现象，而是必然现象。当时一直认为是内存被修改，而没有考虑地址的指向是否错误，由于响应时数据是部分出错，而dnsid，问题区的域名只有读的操做却没有写的操做，最大的迷惑是未找到内存是在何处被修改的，因此猜想应该是在扩展skb函数中数据拷贝后被修改的，没有办法只能把内核中的pskb_expand_head()函数搬到模块中，在这个函数中排错，结果意外的发现，拷贝一直到退出这个函数后数据都没有改变，接着又迷惑了。再后来无心中打印原始的dnsbuf地址，发现其与扩展前的ip头地址相差很大，这时才发现dnsbuf的地址可能在某处被修改了，通过不断的复现现象，最终定位在skb_linearize()函数中，真是忽然之间柳暗花明，问题的根本缘由是由于skb线性化函数使用后没有更改地址致使的。

        在skb_linearize()函数中

        1）若是是正常请求，通常head到end之间的线性空间就够用，而且大多也不存在分片的状况，线性化后线性化地址和内存空间保护不变；

        2）若是请求中带有大量垃圾数据，那么线性空间一般会不够用，而且存在分片内容，此时在线性化函数中会从新分配线性空间。

       第二种即为异常状况，此时skb中head，data，iph等指针已发生变化，而原代码中一直在使用已经被释放的地址，若被释放的地址没被从新分配，此时返回的多是部分出错的响应包，当收到大量这种请求包时系统一般会死机。

       具体代码以下：

       在代码中加入iph = ip_hdr(skb);这行代码便可解决问题，小小的一行代码害苦了好多人，固然我是受伤最重的，在这里要牢记skb线性化后必定要从新获取ip头。

       总结：排错经验就是crash vmcore镜像+猜想缘由+多加打印信息+想办法重现现象。先从致使内核崩溃的代码入手，由于是线上环境致使的，因此很难测试，所以必定要猜想哪些因素致使的，选择好要打印的信息，并想办法传入最终崩溃的函数中，在崩溃的函数中加入判断崩溃的条件，打印完信息后调用BUG_ON()让系统崩溃生成crash文件。原本已经到了分析的瓶颈了，由于以前一直觉得skb内存地址在某处被修改，并一度觉得是在pskb_expand_head()处致使的，后来还把内核中的函数搬到模块中，以便输出信息，沿着这条路最终发现是一条死路，以后只能从skb中各指针的地址，以及dnsbuf的地址，ip头的地址开始排查，终于发现是ip头的地址发生了改变，最终才找到问题的根本缘由。另外一个最大的感觉就是必定要想办法复现现象，由于线上的环境很复杂，并且这个现象是偶尔现象，天天都是晚上才发生两三次，这也致使问题更加难解决，最终经过构造这种数据包，并大量的发送给服务器才复现了现象。

3、soft lockup实例

       同事最近遇到一个soft lockup问题，他就借助了dis反汇编，并与原代码进行对比

       从汇编中看出出错的节点地址存在r10寄存器中，r10的地址为88085076de40，接着借助struct命令查看结构体中成员的赋值状况

       到这里发现了原来是在遍历链表时遍历到某个节点时它的前驱和后继都指向本身，所以发生了死循环，顺着代码的流程发现，原来是这个节点执行了两次list_add_tail()，问题迎刃而解。

这个案例相对上面那个panic案例的状况要简单一些，出错的问题是围绕着链表的操做，最后发现是代码的逻辑问题，相对来讲问题不那么隐蔽。经过这两个案例我学到了很多排错经验，有一个清晰的排错思路很关键，不然在烦躁中很难定位出问题的所在。