一、故障现象

内核panic，打印如下：

点击(此处)折叠或打开

Unable to handle kernel NULL pointer dereference at 0000000000000039 RIP:

[] handle_IRQ_event+0x44/0xa6

PGD 61df63067 PUD 61ea5a067 PMD 0

Oops: 0000 [1] SMP

last sysfs file: /devices/system/cpu/cpu0/cpufreq/scaling_max_freq

CPU 8

Modules linked in: ossmod(U) tipc(U) bsp_smbus_ctrl(U) bonding autofs4 hidp rfcomm l2cap bluetooth lockd sunrpc ipv6 xfrm_nalgo crypto_api cpufreq_ondemand acpi_cpufreq freq_table dm_mirror d

m_multipath scsi_dh video hwmon backlight sbs i2c_ec button battery asus_acpi acpi_memhotplug ac lp floppy esh(U) snd_hda_intel snd_seq_dummy snd_seq_oss snd_seq_midi_event snd_seq snd_seq_de

vice sg snd_pcm_oss snd_mixer_oss snd_pcm snd_timer snd_page_alloc snd_hwdep snd igb i2c_i801 i2c_core soundcore 8021q serio_raw parport_pc parport e1000(U) pcspkr dm_raid45 dm_message dm_reg

ion_hash dm_log dm_mod dm_mem_cache ata_piix libata shpchp mptsas mptscsih mptbase scsi_transport_sas sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd

Pid: 0, comm: swapper Tainted: G 2.6.18-164.el5 #1

RIP: 0010:[] [] handle_IRQ_event+0x44/0xa6

RSP: 0018:ffff81032fca7f28 EFLAGS: 00010202

RAX: 0000000000000001 RBX: 0000000000000000 RCX: 00000000000000b2

RDX: ffff810009028520 RSI: ffff81032fc98000 RDI: ffff81032b1c7180

RBP: 0000000000000001 R08: ffff81032fca0000 R09: ffffffff800967c5

R10: ffff81032fca7f30 R11: ffff81032fca1ee8 R12: 00000000000000b2

R13: 0000000000000001 R14: ffff81032fca1df8 R15: ffff81032fca1df8

FS: 0000000000000000(0000) GS:ffff81010b373b40(0000) knlGS:0000000000000000

CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b

CR2: 0000000000000039 CR3: 000000061f37c000 CR4: 00000000000006e0

Process swapper (pid: 0, threadinfo ffff81032fca0000, task ffff81033ab0f7e0)

Stack: ffffffff803e3580 000000000000b200 00000000000000b2 ffff81032acdee40

ffffffff803e35bc ffffffff800b9808 ffffffff8001235a 00000000000000b2

ffff81032fca1df8 00000000009c1418 ffff81062dc4d000 0000000000000800

Call Trace:

[] __do_IRQ+0xa4/0x103

[] __do_softirq+0x89/0x133

[] do_IRQ+0xe7/0xf5

[] ret_from_intr+0x0/0xa

[] acpi_processor_idle+0x274/0x463

[] acpi_processor_idle+0x26a/0x463

[] acpi_processor_idle+0x0/0x463

[] acpi_processor_idle+0x0/0x463

[] cpu_idle+0x95/0xb8

[] start_secondary+0x45a/0x469

从打印看，是在handle_IRQ_event函数中遇到了空指针

二、Vmcore分析

1、反汇编handle_IRQ_event，获取RIP所在的指令

点击(此处)折叠或打开

crash> dis -l handle_IRQ_event

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 134

0xffffffff80010b30 : push %r14

include/trace/irq.h: 7

0xffffffff80010b32 : cmpl $0x0,3859215(%rip) # 0xffffffff803bee48 <__tracepoint_irq_entry.10785>

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 134

0xffffffff80010b39 : mov %rsi,%r14

0xffffffff80010b3c : push %r13

0xffffffff80010b3e : push %r12

0xffffffff80010b40 : mov %edi,%r12d

0xffffffff80010b43 : push %rbp

0xffffffff80010b44 : mov %rdx,%rbp

0xffffffff80010b47 : push %rbx

include/trace/irq.h: 7

0xffffffff80010b48 : je 0xffffffff80010b68

0xffffffff80010b4a : mov 3859199(%rip),%rbx # 0xffffffff803bee50 <__tracepoint_irq_entry.10785>

0xffffffff80010b51 : test %rbx,%rbx

0xffffffff80010b54 : je 0xffffffff80010b68

0xffffffff80010b56 : mov %r14,%rsi

0xffffffff80010b59 : mov %r12d,%edi

0xffffffff80010b5c : callq *(%rbx)

0xffffffff80010b5e : add $0x8,%rbx

0xffffffff80010b62 : cmpq $0x0,(%rbx)

0xffffffff80010b66 : jmp 0xffffffff80010b54

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 142

0xffffffff80010b68 : testb $0x20,0x8(%rbp)

0xffffffff80010b6c : jne 0xffffffff80010b6f

include/asm/irqflags.h: 80

0xffffffff80010b6e : sti

0xffffffff80010b6f : xor %r13d,%r13d

0xffffffff80010b72 : xor %ebx,%ebx

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 146

0xffffffff80010b74 : mov 0x38(%rbp),%rsi

0xffffffff80010b78 : mov %r14,%rdx

从之前的堆栈可以看出RIP为：handle_IRQ_event+0x44/0xa6

0x44折算成十进制为68，所以需要关注handle_IRQ_event+68行：

0xffffffff80010b74 :       mov    0x38(%rbp),%rsi

从之前的汇编分析，rsi的值应该是上级函数传入，不太可能在其中出现空指针，问题应该出在0x38(%rbp)上，也就是rbp上。

2、结合handle_IRQ_event源代码分析

handle_IRQ_event代码如下：

点击(此处)折叠或打开

132 irqreturn_t handle_IRQ_event(unsigned int irq, struct pt_regs *regs,

133 struct irqaction *action)

134 {

135 irqreturn_t ret, retval = IRQ_NONE;

136 unsigned int status = 0;

137

138 trace_irq_entry(irq, regs);

139

140 handle_dynamic_tick(action);

141

142 if (!(action->flags & IRQF_DISABLED))

143 local_irq_enable_in_hardirq();

144

145 do {

146 ret = action->handler(irq, action->dev_id, regs);

147 if (ret == IRQ_HANDLED)

148 status |= action->flags;

149 retval |= ret;

150 action = action->next;

151 } while (action);

152

153 if (status & IRQF_SAMPLE_RANDOM)

154 add_interrupt_randomness(irq);

155 local_irq_disable();

156

157 trace_irq_exit(irq, retval);

158

159 return retval;

160 }

之前反汇编中有代码行提示：

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 146

可以看出问题出在146行：

146         ret = action->handler(irq, action->dev_id, regs);

可以看出0x38(%rbp)应该对应action->dev_id(因为通过偏移访问，结构体访问基本如此)，如此可见rbp中存放的即action变量的的值，

分析源代码，action是通过入参传入的，但是在146-151行的循环中，150行，对action重新赋值了。

150         action = action->next;

如此，可以推测action->next出问题了，也就是通过入参传入的action的next成员出问题了，of course，也可能是一开始的传入的如此就有问题了。

继续分析action入参的值。

3、入参(action)分析

action被放入了rbp寄存器，看如下汇编行：

0xffffffff80010b44 :       mov    %rdx,%rbp

可以看出，action入参是通过rdx寄存器传入的，并不是我们通常认为的通过堆栈。需要进一步分析上级行数中的rdx寄存器的值。

4、上级函数__do_IRQ分析

点击(此处)折叠或打开

crash> bt

PID: 0 TASK: ffff81033ab0f7e0 CPU: 8 COMMAND: "swapper"

#0 [ffff81032fca7c80] crash_kexec at ffffffff800ac5b9

#1 [ffff81032fca7d40] __die at ffffffff80065127

#2 [ffff81032fca7d80] do_page_fault at ffffffff80066da7

#3 [ffff81032fca7e70] error_exit at ffffffff8005dde9

[exception RIP: handle_IRQ_event+68]

RIP: ffffffff80010b74 RSP: ffff81032fca7f28 RFLAGS: 00010202

RAX: 0000000000000001 RBX: 0000000000000000 RCX: 00000000000000b2

RDX: ffff810009028520 RSI: ffff81032fc98000 RDI: ffff81032b1c7180

RBP: 0000000000000001 R8: ffff81032fca0000 R9: ffffffff800967c5

R10: ffff81032fca7f30 R11: ffff81032fca1ee8 R12: 00000000000000b2

R13: 0000000000000001 R14: ffff81032fca1df8 R15: ffff81032fca1df8

ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018

#4 [ffff81032fca7f20] handle_IRQ_event at ffffffff80010b81

#5 [ffff81032fca7f50] __do_IRQ at ffffffff800b9808

#6 [ffff81032fca7f90] do_IRQ at ffffffff8006c997

--- ---

可见，上级函数为__do_IRQ。

对照__do_IRQ源代码，可以看出调用handle_IRQ_event的地方为240行，所以关注汇编中的相关行附件代码即可

点击(此处)折叠或打开

174 fastcall unsigned int __do_IRQ(unsigned int irq, struct pt_regs *regs)

175 {

176 struct irq_desc *desc = irq_desc + irq;

177 struct irqaction *action;

178 unsigned int status;

...

235 for (;;) {

236 irqreturn_t action_ret;

237

238 spin_unlock(&desc->lock);

239

240 action_ret=handle_IRQ_event(irq,regs,action);

241 if (!noirqdebug)

242 note_interrupt(irq, desc, action_ret, regs);

243

244 spin_lock(&desc->lock);

245 if (likely(!(desc->status & IRQ_PENDING)))

246 break;

247 desc->status &= ~IRQ_PENDING;

248 }

...

260 }

继续反汇编__do_IRQ

点击(此处)折叠或打开

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 222

0xffffffff800b97f1 <__do_irq>: je 0xffffffff800b9845 <__do_irq>

include/asm/spinlock.h: 62

0xffffffff800b97f3 <__do_irq>: movl $0x1,0x3c(%rbx)

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 240

0xffffffff800b97fa <__do_irq>: mov %r13,%rdx

0xffffffff800b97fd <__do_irq>: mov %r15,%rsi

0xffffffff800b9800 <__do_irq>: mov %r12d,%edi

0xffffffff800b9803 <__do_irq>: callq 0xffffffff80010b30

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 241

0xffffffff800b9808 <__do_irq>: cmpl $0x0,3358161(%rip) # 0xffffffff803ed5e0

0xffffffff800b980f <__do_irq>: jne 0xffffffff800b9821 <__do_irq>

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 242

0xffffffff800b9811 <__do_irq>: mov %r15,%rcx

0xffffffff800b9814 <__do_irq>: mov %eax,%edx

0xffffffff800b9816 <__do_irq>: mov %rbx,%rsi

0xffffffff800b9819 <__do_irq>: mov %r12d,%edi

可以看出edx的值来源于r13，再回看handle_IRQ_event函数的反汇编，在该函数的开始对r13寄存器进行了压栈

点击(此处)折叠或打开

0xffffffff80010b30 : push %r14

include/trace/irq.h: 7

0xffffffff80010b32 : cmpl $0x0,3859215(%rip) # 0xffffffff803bee48 <__tracepoint_irq_entry.10785>

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 134

0xffffffff80010b39 : mov %rsi,%r14

0xffffffff80010b3c : push %r13

所以，可以从handle_IRQ_event函数的栈帧中找到action的值。r13应该位于该栈帧中的第3个值，因为第一个必然为函数的返回地址，第二个值为r14(在r13之前压入)。

看看handle_IRQ_event函数的栈

点击(此处)折叠或打开

crash> bt -f

PID: 0 TASK: ffff81033ab0f7e0 CPU: 8 COMMAND: "swapper"

#0 [ffff81032fca7c80] crash_kexec at ffffffff800ac5b9

ffff81032fca7c88: ffff81032fca1df8 ffff81032fca1df8

ffff81032fca7c98: 0000000000000001 00000000000000b2

ffff81032fca7ca8: 0000000000000001 0000000000000000

ffff81032fca7cb8: ffff81032fca1ee8 ffff81032fca7f30

ffff81032fca7cc8: ffffffff800967c5 ffff81032fca0000

ffff81032fca7cd8: 0000000000000001 00000000000000b2

ffff81032fca7ce8: ffff810009028520 ffff81032fc98000

ffff81032fca7cf8: ffff81032b1c7180 ffffffffffffffff

ffff81032fca7d08: ffffffff80010b74 0000000000000010

ffff81032fca7d18: 0000000000010202 ffff81032fca7f28

ffff81032fca7d28: 0000000000000018 ffff81032fca7e78

ffff81032fca7d38: ffffffff802a4d0d ffffffff80065127

.......

#4 [ffff81032fca7f20] handle_IRQ_event at ffffffff80010b81

ffff81032fca7f28: ffffffff803e3580 000000000000b200

ffff81032fca7f38: 00000000000000b2 ffff81032acdee40

ffff81032fca7f48: ffffffff803e35bc ffffffff800b9808

#5 [ffff81032fca7f50] __do_IRQ at ffffffff800b9808

ffff81032fca7f58: ffffffff8001235a 00000000000000b2

ffff81032fca7f68: ffff81032fca1df8 00000000009c1418

ffff81032fca7f78: ffff81062dc4d000 0000000000000800

ffff81032fca7f88: ffffffff803ea360 ffffffff8006c997

可以看出action的值应该为ffff81032acdee40，看看其中的内容，顺便验证下。

action为irqaction类型的结构体：

点击(此处)折叠或打开

crash> struct irqaction ffff81032acdee40

struct irqaction {

handler = 0xffffffff8827628b,

flags = 0,

mask = {

bits = {0, 0, 0, 0}

},

name = 0xffff81032b1c7000 "eth0-rx-3",

dev_id = 0xffff81032bef56b8,

next = 0x1,

irq = 178,

dir = 0xffff810328db2180

}

可以看出该irqaction结构体对应于eth0网卡的接收中断，中断号为178，注意其中的next，为0x1，这就是问题所在。

从log信息可以看出空指针具体的值为：0000000000000039 ，正好=0x1+38，所以说明分析是正确的。

分析代码逻辑和irqaction的定义：

点击(此处)折叠或打开

crash> struct irqaction

struct irqaction {

irqreturn_t (*handler)(int, void *, struct pt_regs *);

long unsigned int flags;

cpumask_t mask;

const char *name;

void *dev_id;

struct irqaction *next;

int irq;

struct proc_dir_entry *dir;

}

SIZE: 88

这里的next应该在有中断共享时使用，即同一个irq号对应多个ISR，如果有共享，那么这里的next指向共享该irq的下一个action.

从/proc/interrupts信息，可以看出178号中断并没有共享的情况，所以，这里的next应该为null，为0x1显然有问题了。

从irqaction中的值分析，next前后的数据都是正常的，只有next从0突变成1了，基本可以排除由于内存越界导致内存写坏的情况。

分析设置next指针的所有代码，只有设置地址和删除的代码，并没有发现有直接设置为1的地方。

那为什么如此呢？要继续分析就很困难了。

5、分析irq_desc

没有其它分析思路了，尝试分析action所在的结构体irq_desc，看看其中的内容，该结构体的值需要从上级函数__do_IRQ分析，见其代码176行：

176     struct irq_desc *desc = irq_desc + irq;

其中irq_desc为全局变量(数组)，存放所有的irq_desc，按编号排列。

对照其汇编：

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 176

0xffffffff800b9784 :       lea    0xffffffff803d8380(%rbp),%rbx

lea指令的意思是将0xffffffff803d8380(%rbp)地址(即rbp+0xffffffff803d8380)，赋值给rbx，这里显然0xffffffff803d8380就是irq_desc全局变量的地址。

确认一下：

点击(此处)折叠或打开

crash> struct irq_desc 0xffffffff803d8380

struct irq_desc {

handle_irq = 0,

chip = 0xffffffff803ec7e0,

handler_data = 0x0,

chip_data = 0x0,

action = 0xffffffff803018a0,

status = 0,

depth = 0,

wake_depth = 0,

irq_count = 22386,

irqs_unhandled = 0,

lock = {

raw_lock = {

slock = 1

}

},

affinity = {

bits = {1, 0, 0, 0}

},

cpu = 0,

pending_mask = {

bits = {0, 0, 0, 0}

},

move_irq = 0,

dir = 0xffff81062ddbd180

}

crash> struct irqaction 0xffffffff803018a0

struct irqaction {

handler = 0xffffffff8006e9da ,

flags = 32,

mask = {

bits = {0, 0, 0, 0}

},

name = 0xffffffff802b3dfa "timer",

dev_id = 0x0,

next = 0x0,

irq = 0,

dir = 0x0

}

可以看出位于该全局变量的第一个元素为时钟中断对应的描述符，说明分析正确。但我们这里需要分析的是178号中断(irq好前面已经分析得到了)，应该怎么查找呢。

继续看汇编代码，可以看出178号中断对应的描述符在irq_desc数组中的偏移量存放在rbp中了，查看rbp后续的汇编代码，并没有对进行压栈处理，且当前函数不是最顶级的堆栈函数，所以无法直接从vmcore中获取rbp的值，只能想其它办法了。

继续看汇编代码：

/usr/src/debug/kernel-2.6.18/linux-2.6.18.x86_64/kernel/irq/handle.c: 176

0xffffffff800b977c :       mov    %rcx,%rbp

0xffffffff800b977f :       shl    $0x8,%rbp

这里的rcx应该存放的是irq的编号，也就是178，将rcx左移8位后即得到rbp(shl    $0x8,%rbp)，即178*256=rbp=0xb200

0xffffffff803d8380+0xb200=0xffffffff803e3580，该地址即为178号中断对应的描述符的地址了：

点击(此处)折叠或打开

crash> struct irq_desc FFFFFFFF803E3580

struct irq_desc {

handle_irq = 0,

chip = 0xffffffff80323c40,

handler_data = 0x0,

chip_data = 0x0,

action = 0xffff81032acdee40,

status = 65536,

depth = 0,

wake_depth = 0,

irq_count = 78785,

irqs_unhandled = 0,

lock = {

raw_lock = {

slock = 1

}

},

affinity = {

bits = {256, 0, 0, 0}

},

cpu = 0,

pending_mask = {

bits = {32768, 0, 0, 0}

},

move_irq = 1,

dir = 0xffff810328db2380

}

crash> struct irqaction 0xffff81032acdee40

struct irqaction {

handler = 0xffffffff8827628b,

flags = 0,

mask = {

bits = {0, 0, 0, 0}

},

name = 0xffff81032b1c7000 "eth0-rx-3",

dev_id = 0xffff81032bef56b8,

next = 0x1,

irq = 178,

dir = 0xffff810328db2180

exactly，正是我们需要的，于是找到了描述符，看看其内容，其中

irq_count = 78785,

irq_count用于监测中断是否挂起的计数，不为0表明之前已处理过该中断，说明该中断之前正在被正常处理，突然直接出了问题。

至此，确实无法继续分析了，从故障现象看，内核问题可能性不大，更像是是内存的1bit跳变导致的问题，但是通常的服务器环境中，内存(控制器)硬件应该有ECC校验功能，可以自动纠正1bit跳变的情况才对。

核对了一下出现问题的硬件环境，dmicode命令中可以看到内存硬件确实有ECC校验功能，但是发现CPU cache硬件中没有包含ECC校验功能：

Error Correction Type: None

看了看其它类型的服务器，一些服务器有ECC校验功能：

Error Correction Type: Single-bit ECC

因此，没有其它疑点，只能怀疑是内存(或者说是cache)的1bit跳变硬件故障导致。

但没有进一步证据了，有其它想法欢迎讨论。