线上内核panic分析总结

猪小花1号2018-09-07 16:08
作者:刘长伟

线上有台机器跪了,还好之前部署了kdump,通过分析dump文件,找到了宕机原因,记录一下分析过程。
1 准备工作 
 先将内核dump文件拷到另一台机器上,并安装panic内核版本的调试包
 工具用crash,安装crash工具包。
 crash介绍:
 The Red Hat crash analysis utility is loosely based on the SVR4 UNIX crash command, but has been significantly enhanced by completely merging it with the GNU gdb debugger. The marriage of the two effectively combines the kernel-specific nature of the traditional UNIX crash utility with the source code level debugging capabilities of gdb. 
 crash常用指令:
    bt 命令用于查看系统崩溃前的堆栈等信息,这是系统调试中非常常用和好用的一个命令。
    log 命令可以打印系统消息缓冲区
    ps 命令用于显示进程的状态
    dis 命令用于对给定地址的内容进行反汇编
  其余指令可以通过help查看了。
2 执行crash指令:
 crash  3.10.45-openstack-amd64/vmlinux  dump_115.201503071607 进入crash命令行。
3 打印内核堆栈
 crash> bt
 PID: 11180  TASK: ffff883fbf6fe790  CPU: 4   COMMAND: "vhost-11175"
 #0 [ffff88207fa43880] machine_kexec at ffffffff8102c0b8
 #1 [ffff88207fa438e0] crash_kexec at ffffffff8108a3b8
 #2 [ffff88207fa439a0] oops_end at ffffffff8139a49b
 #3 [ffff88207fa439c0] do_divide_error at ffffffff8100d911
 #4 [ffff88207fa43a60] divide_error at ffffffff8139fb8e
    [exception RIP: tun_net_xmit+242]
    RIP: ffffffffa054e6ae  RSP: ffff88207fa43b18  RFLAGS: 00010246
    RAX: 00000000000001f4  RBX: ffff881ece4398c0  RCX: 0000000000000000
    RDX: 0000000000000000  RSI: 00000000000001f4  RDI: ffff88346ba7f400
    RBP: ffff8831fa0b0000   R8: 0000000000000000   R9: ffff881fe1789a80
    R10: 0000000000000000  R11: 0000000000000000  R12: ffff88346ba7f400
    R13: 0000000000000046  R14: ffff881ece4398c0  R15: 0000000000000000
    ORIG_RAX: ffffffffffffffff  CS: 0010  SS: 0018
 #5 [ffff88207fa43b30] dev_hard_start_xmit at ffffffff812d7766
4 可以看到 内核在tun_net_xmit+242出现除零错误。
 执行反汇编:
 crash> dis tun_net_xmit+242
 0xffffffffa054e6ae <tun_net_xmit+242>:  div    %rcx
 但这样也是看不出什么的,那就反汇编整个函数 tun_net_xmit
  crash> dis tun_net_xmit
 0xffffffffa054e5bc <tun_net_xmit>:      push   %r12

 …

 0xffffffffa054e5d6 <tun_net_xmit+26>:   mov    0x800(%rsi,%rdx,8),%r12

 0xffffffffa054e5de <tun_net_xmit+34>:   jae    0xffffffffa054e7c9

 0xffffffffa054e5e4 <tun_net_xmit+40>:   test   %r12,%r12

 …

 0xffffffffa054e64f <tun_net_xmit+147>:  jne    0xffffffffa054e620

 0xffffffffa054e651 <tun_net_xmit+149>:  testb  $0x1,(%rsi)

 0xffffffffa054e654 <tun_net_xmit+152>:  je     0xffffffffa054e7c9

 0xffffffffa054e65a <tun_net_xmit+158>:  mov    $0x6,%edx

 …

 0xffffffffa054e67f <tun_net_xmit+195>:  test   %edx,0x86c(%rbp,%rax,4)

 0xffffffffa054e686 <tun_net_xmit+202>:  je     0xffffffffa054e7c9

 0xffffffffa054e68c <tun_net_xmit+208>:  jmpq   0xffffffffa054e5f5

 …

 0xffffffffa054e6a7 <tun_net_xmit+235>:  mov    0x318(%rbp),%rax

 0xffffffffa054e6ae <tun_net_xmit+242>:  div    %rcx

 0xffffffffa054e6b1 <tun_net_xmit+245>:  cmp    %rax,%rsi

 0xffffffffa054e6b4 <tun_net_xmit+248>:  jae    0xffffffffa054e7c9

 0xffffffffa054e6ba <tun_net_xmit+254>:  jmp    0xffffffffa054e6ce

 …

 0xffffffffa054e6f5 <tun_net_xmit+313>:  mov    %rbx,%rdi

 0xffffffffa054e6f8 <tun_net_xmit+316>:  callq  0xffffffff812caf18 <skb_copy_ubufs>

 0xffffffffa054e6fd <tun_net_xmit+321>:  test   %eax,%eax

 0xffffffffa054e6ff <tun_net_xmit+323>:  jne    0xffffffffa054e7c9

 0xffffffffa054e705 <tun_net_xmit+329>:  jmp    0xffffffffa054e6e2

 0xffffffffa054e707 <tun_net_xmit+331>:  mov    %rbx,%rdi

 …

 0xffffffffa054e7c2 <tun_net_xmit+518>:  callq  0xffffffff81061d48 <__wake_up>

 0xffffffffa054e7c7 <tun_net_xmit+523>:  jmp    0xffffffffa054e7e0

 0xffffffffa054e7c9 <tun_net_xmit+525>:  incq   0xf8(%rbp)

 0xffffffffa054e7d0 <tun_net_xmit+532>:  mov    %rbx,%rdi

 …

 0xffffffffa054e7e4 <tun_net_xmit+552>:  pop    %r12

 0xffffffffa054e7e6 <tun_net_xmit+554>:  retq  

 汇编早就还给老师了,但仔细看,不难发现,有很多类似jae 0xffffffffa054e7c9代码,
 这种代码可以给我们一些提示, 0xffffffffa054e7c9 在函数尾部,后面就是retq返回指令了。
 可以推断代码中有5处判断,如果条件不成立就跳到最后返回了。根据这个,可以大体了解出错代码在函数的
 那个段落中。
5 代码分析
 反汇编和代码可以对照一下,大概就能定位出错的地方了:
  708 static netdev_tx_t tun_net_xmit(struct sk_buff *skb, struct net_device *dev)    
  709 {                                                                               
  ...                                                           
  718     if (txq >= tun->numqueues)                                                  
  719         goto drop;                                                              
  ...                  
  728     if (!check_filter(&tun->txflt, skb))                                        
  729         goto drop;                                                              
  ...                                                                              
  731     if (tfile->socket.sk->sk_filter &&                                          
  732         sk_filter(tfile->socket.sk, skb))                                       
  733         goto drop;                                                              
  ...                                            
  738     if (skb_queue_len(&tfile->socket.sk->sk_receive_queue)                      
  739               >= dev->tx_queue_len / tun->numqueues)                            
  740         goto drop;                                                                                         ...                                           
  744     if (unlikely(skb_orphan_frags(skb, GFP_ATOMIC)))                            
  745         goto drop;                                                      
  762 drop:                                                                           
  ...                                                      
  767     return NETDEV_TX_OK;                                                        
  从代码也验证了之前对  jae   0xffffffffa054e7c9的推测。它对应 goto drop。而除零发生在738-739行,
  在第3和第4个goto drop之间,和汇编中分析的一致。
  看来就是这里了。(当然就这个案例,直接看代码也很清晰)
6 知道kernel哪一行有问题,那就先去社区找补丁了。
 这里补丁也很简单,既然在比较时一端除零,那就两边乘分母好了。
  - if (skb_queue_len(&tfile->socket.sk->sk_receive_queue)
- >= dev->tx_queue_len / tun->numqueues)
+ if (skb_queue_len(&tfile->socket.sk->sk_receive_queue) * numqueues
+ >= dev->tx_queue_len)
将补丁打上去,就没出类似错误了。 

网易云大礼包:https://www.163yun.com/gift

本文来自网易实践者社区,经作者刘长伟授权发布