linux panic 问题定位

1     概述

详细描述出现kernel panic时的处理过程。

 

2     定位方法

2.1   调用栈

最直接、简单的方法，查看panic时的调用栈，根据打印的出错函数及文件行数，找到panic的位置，再详细处理。

2.2   出错地址

有时候会出现错误的调用栈，此时必须查看出错的指令地址，对于x86架构来说，就是EIP，同时关注调用栈的地址。在调用栈错误时，可以手工将地址转换成出错函数及行数，以下分两个部分介绍：

2.2.1  内核模块

大部分kernel panic都是由于可加载卸载的内核模块导致，此时可以通过如下步骤将地址翻译成具体代码位置。

1.     获取内核模块基地址

查看/proc/modules，找到关注的内核模块的基地址，如下是一个示例

root@miner:~#cat /proc/modules | grep mm

mm           643877 0 - Live 0xd27cf000 (O)

mm_if       1526      1mm, Live 0xd27b8000 (O)

绝大部分情况下，系统在重启后，模块的基地址不会改变。如上图所示，mm模块的地址空间从基地址0xd27cf000开始，大小为643877，如果某个地址落在这个区间，则确定为此模块的地址。

2.     计算地址偏移

将出错的内核地址减去模块基地址，即得到偏移地址。

3.     生成模块可调试文件

确保编译内核时EXTRA_CFLAGS参数添加-g，如此编译后会生成内核模块对应的.o文件(假设为hello.o)，使用编译工具链ld(交叉编译时需要使用交叉编译工具链)，命令如下：

 ld -r -d -o hello.ko.debug hello.o

4.     gdb调试

gdbhello.ko.debug

假设偏移地址为0xa7d0，则info line*0xa7d0便得到panic时的位置信息。

2.2.2  内核

如果出错地址为内核，则不需要计算偏移地址，直接使用出错地址即可。，使用gdb 调试vmlinux，注意不是vmlinuz，方法基本与内核模块类似

 

3     panic 实例

3.1    代码段卸载

l  现象

insmod 模块报“operation not permitted”，很快出现panic 信息。此问题为与客户联调时现场出现。

l  定位

此问题最终原因是模块初始化时接口返回值混乱导致，实际上此模块已经成功插入到内核，但是因为返回值混乱，导致判断是插入模块失败，因此当前内核模块退出，此内核模块的代码段卸载，但此内核模块注册到内核报文处理过程没有被正确卸载，故在报文收发时因为没有可用的代码段导致panic。

 

3.2    死锁

l  现象

设备在报文有流量的情况下下发配置到内核，会小概率性的出现panic，panic时串口显示“rcu_preempt self-detected stall on CPU”

l  定位

此问题最终原因是内核死锁。有两个过程需要同步，一个是报文收发软中断，另一个是命令下发过程(进程上下文)，代码中使用spin_lock 同步。

在命令下发过程中，锁已经获取，但恰好此时有一个软中断到来，打断了命令下发过程，而且在软中断过程中需要获取相同的锁，此锁已经被命令下属过程占住，因此导致死锁。解决方法很简单，在命令下发过程中禁止软中断，即使用spin_lock_bh 同步。

 

3.3    代码段替换

l  现象

短时间内，内核模块卸载再加载后，会随机小概率的出现panic

l  定位

内核模块会在流结构中存储若干内容，包括分配的结点指针等。当内核模块卸载之后，这条流一直存在没有结束；当内核模块两次加载后，这条流又被处理，使用了前一次无效的结点指针，导致panic。

此问题通过“模块引用”计数方案解决，当内核模块卸载再加载后，之前已经处理过的流直接bypass。

 

3.4    使用释放的内存

l  现象

网口down再up之后，小概率的出现panic，出错信息如下：

<1>[592005.836736]BUG: unable to handle kernel NULL pointer dereference at 00000001
<1>[592005.845688]IP: [<f89a6075>] 0xf89a6074
<4>[592005.846675]*pde = 00000000
<4>[592005.846675]Oops: 0000 [#1]
<4>[592005.846675]Modules linked in: algapi [last unloaded: maxnet_dpi_if]
<4>[592005.846675]
<4>[592005.846675]Pid: 0, comm: swapper Tainted: G          O 3.3.8 #38 HOLL Technologies        /       
<4>[592005.846675]EIP: 0060:[<f89a6075>] EFLAGS: 00010246 CPU: 0
<4>[592005.846675]EIP is at 0xf89a6075
<4>[592005.846675]EAX: c19b6c08 EBX: 00000000 ECX: 00000000 EDX: f59be000
<4>[592005.846675]ESI: f59be000 EDI: 00000001 EBP: c19b6c10 ESP: f600bbac
<4>[592005.846675]  DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
<0>[592005.846675]Process swapper (pid: 0, ti=f600a000 task=c14264c0 task.ti=c141e000)
<0>[592005.846675]Stack:
<4>[592005.846675]  00000000 fffffffe 00000000 c19b7600 c12b775dc1a9fb30 b554c74e 00000869
<4>[592005.846675]  c1a9fc30 c1a9f8c0 c1a9f800 00000000 0386df19c1a9f800 00000001 c1a9fb30
<4>[592005.846675]  c1a9fa30 b90e8051 00000869 c19b7600 c1a9fb30c1a9fa30 c1a9f910 c1a9f800
<0>[592005.846675]Call Trace:
<4>[592005.846675]  [<c12b775d>] ? htb_dequeue+0x3ad/0x7a0
<4>[592005.846675]  [<c12b0635>] ? __qdisc_run+0x75/0xf0

 

l  定位

粗看发现htb_dequeue函数，后来仔细查看是在我们自己的内核模块sch_per，是通过EIP地址转换得到，不清楚此版本的linux kernel显示调用栈为什么不完整。

具体原因是在网口down时，会释放当前所有的IP结点，但是其活跃链表的链表头没有初始化，仍然指向了已经释放的IP结点，导致网口再次up时，出现panic。

 

3. 现象

<1>[3872.496538] BUG: unable to handle kernel NULL pointer dereference at   (null)
<1>[3872.504815] IP: [<  (null)>]   (null)
<4>[3872.506445] *pde = 00000000
<4>[3872.506445] Oops: 0000 [#1]
<4>[3872.506445] Modules linked in: maxnet_dpi(O) sch_per(O)
<4>[3872.506445]
<4>[3872.506445] Pid: 0, comm: swapper Tainted: G           O 3.3.8 #44 MICRO-STAR INTERNATIONALCO., LTD MS-9641/MS-9641
<4>[3872.506445] EIP: 0060:[<00000000>] EFLAGS: 00010286 CPU: 0
<4>[3872.506445] EIP is at 0x0
<4>[3872.506445] EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: c1a3d96d
<4>[3872.506445] ESI: 00000000 EDI: 00000000 EBP: 00000000 ESP: f680bce8
<4>[3872.506445]  DS: 007b ES: 007b FS: 0000GS: 0000 SS: 0068
<0>[3872.506445] Process swapper (pid: 0, ti=f680a000 task=c14264c0task.ti=c141e000)
<0>[3872.506445] Stack:
<4>[3872.506445]  00000000 00000000 00000000f680bd08 f89237d0 f680bd40 f88fb0a2 c1a3d840
<4>[3872.506445]  00000000 00000000 0000000000000000 00000000 00000000 00000000 00000000
<4>[3872.506445]  00000000 00000000 0000000000000000 00000006 00000000 f88fb41c c12c9500
<0>[3872.506445] Call Trace:
<4>[3872.506445]  [<f89237d0>] ?miner_qos_fini+0x240/0x600 [maxnet_dpi]

某一台设备，经常性的panic(每天平均一次以上)，但EIP记录为0，无法获得panic时的地址，通过翻译调用栈地址，仅能得到在内核模块的forward函数和local_in函数位置，详细的panic位置无法获取。

 

粗略查看，panic有两种情况，一种是在0xf89237d0，另一种是在0xf89237bb，目前已知maxnet-dpi.ko 的基地址为0xf8919000，这两种情况如下：

(1) 0xf89237d0

此地址(偏移地址为0xa7d0)定位到函数 app_local_in 的第一行，反汇编后查看，发现指令如下：

0000a7d0 <app_local_in>:

#ifndef MAXNET_CHINA_TELECOM

static int app_local_in(unsigned char*layer2_data, maxnet_tupleinfo_t *tuple, void *data)

{

   a7d0:       57                      push   %edi

仅仅一个入栈动作(push %edi)导致panic，如果其地址可信，怀疑可能是硬件问题。

 

(2) 0xf89237bb

此地址定位到maxnet_dpi_proc函数的最后一行，即maxnet_dpi_forward调用处

 

此问题仅在一台设备上出现，且此设备为很多年前的、不发货仅供测试的设备，也可能是硬件问题

此问题待定，目前尚未解决！！！！！！！

l  现象2

程序在某台网关设备上频繁重启，相关日志如下：

CPU 0 Unable to handle kernel pagingrequest at virtual address 587d7a98, epc == c224ca68, ra == c224cc0c
Oops[#1]:
Cpu 0
$ 0  : 00000000 00000031 ffff0000 00000000
$ 4  : 00000001 00000006 00000000 00000000
$ 8  : 00007740 8bd8791a 00000010 64725049
$12  : 00000000 00000000 00000000 00000000
$16  : 7376694f 43394e4f 64725049 587d7a98
$20  : c228ed60 c2290000 8b9e8100 00000004
$24  : 00000010 c128c3cc                 
$28  : 8d7d4000 8d7d7a38 8d7d7c28 c224cc0c
Hi   : 033e3b62
Lo   : f4806fde
epc  : c224ca68 maxnet_dpi_proc+0xa8/0x374 [m01_b01]
   Tainted: P           O
ra   : c224cc0c maxnet_dpi_proc+0x24c/0x374 [m01_b01]
Status: 10009903    KERNEL EXL IE
Cause : 0000000c
BadVA : 587d7a98
PrId : 0002a080 (Broadcom BMIPS4350)
Call Trace:
[<c224ca68>]maxnet_dpi_proc+0xa8/0x374 [m01_b01]
[<c173420c>]ips_check+0xc0/0x14c [dpi]

查看出错代码位置的反汇编，发现对应的代码段如下：

*layer7_id= 0;
layer3_data =IP_HEADER_FROM_MAC(layer2data);
eh = (struct ethheader*) layer2data;
if ( IP_PROTO_UDP ==tupleinfo->proto ) {
/*4. we check the hostnameby DHCP for osinfo detection */
if ( MAXNET_DPI_ENGINE_ON== g_dpi_engine_conf.osinfo_engine_status ){
if((!tupleinfo->direct)&&
68 ==ntohs(tupleinfo->sport) &&
67 ==ntohs(tupleinfo->dport)){
memcpy(mac_address,eh->h_source, 6);
dpi_osinfo_refresh_hostname(layer3_data,tupleinfo->sipv4, mac_address);
}
}
}
*layer7_id= 0;

出错的指令地址对应红色代码，但上方不远处有相同的代码，故认为是DHCP处理函数(dpi_osinfo_refresh_hostname)导致，详细查看代码，发现其内部的子函数在memcpy 时没有注意长度，会导致栈数组越界。

栈越界时，会将很多信息破坏，包括调用栈、返回指针，所以之前看到的panic，连EIP都是错的，以后如果看到调用栈损坏、EIP非法，就可以考虑是否为栈越界。