dmesg 初步分析
[??423.400073]?Unable?to?handle?kernel?NULL?pointer?dereference?at?virtual?address?00000008
[??423.400075]?[silead?finger_interrupt_handler?505]:S?IRQ?19?,?GPIO?12?state?is?0
[??423.400083]?[silead?finger_interrupt_handler?506]:state?is?0
[??423.400096]?pgd?=?ffffffc0017eb000
[??423.400103]?[00000008]?*pgd=000000008ea0a003,?*pud=000000008ea0a003,?*pmd=000000008ea0b003,?*pte=006000000b000707
[??423.400124]?Internal?error:?Oops:?96000046?[#1]?PREEMPT?SMP
[??423.400132]?Modules?linked?in:?wlan(O)
[??423.400148]?CPU:?4?PID:?0?Comm:?swapper/4?Tainted:?G????????W??O???3.18.31-perf?#1
[??423.400155]?Hardware?name:?Qualcomm?Technologies,?Inc.?MSM8940-PMI8950?MTP?(DT)
[??423.400164]?task:?ffffffc04eae4980?ti:?ffffffc0b28bc000?task.ti:?ffffffc0b28bc000
[??423.400182]?PC?is?at?run_timer_softirq+0x4ac/0x5ec
[??423.400192]?LR?is?at?run_timer_softirq+0x324/0x5ec
[??423.400199]?pc?:?[]?lr?:?[]?pstate:?600001c5
[??423.400204]?sp?:?ffffffc0b28bfb60
...
[??423.401490]?Process?swapper/4?(pid:?0,?stack?limit?=?0xffffffc0b28bc058)
[??423.401496]?Call?trace:
[??423.401510]?[]?run_timer_softirq+0x4ac/0x5ec
[??423.401523]?[]?__do_softirq+0x178/0x350
[??423.401532]?[]?irq_exit+0x74/0xb0
[??423.401543]?[]?__handle_domain_irq+0xb4/0xec
[??423.401553]?[]?gic_handle_irq+0x54/0x84
[??423.401560]?Exception?stack(0xffffffc0b28bfd40?to?0xffffffc0b28bfe60)
...
[??423.401671]?[]?el1_irq+0x68/0xd4
[??423.401685]?[]?cpuidle_enter_state+0xd0/0x224
[??423.401695]?[]?cpuidle_enter+0x18/0x20
[??423.401706]?[]?cpu_startup_entry+0x288/0x384
[??423.401717]?[]?secondary_start_kernel+0x108/0x114
[??423.401728]?Code:?b90052a0?34000840?f9400321?f9400720?(f9000420)?
[??423.401736]?---[?end?trace?d0daa1892c14378b?]---
[??423.401753]?Kernel?panic?-?not?syncing:?Fatal?exception?in?interrupt
[??423.401774]?CPU7:?stopping
连上trace32,load vmlinux后通过list source看下汇编源码混合显示,如下:
- FFFFFFC0000FE968: 当前汇编指令的虚拟地址
- F9000760: 汇编机器码,ARM/ARM64的指令机器码都是32位固定长度
- str x0,[x27, #0x8]: 汇编指令,;后的是注释
根据AAPCS(ARM二进制过程调用标准)参数传递规则,ARM64的 v0 - v7 参数直接由 x0 - x7 传递,其他参数由压栈传递,子程序返回结果保存到x0。
那么这里可推导如下:
x0 == prev, x1 == next
指令:str x0 ,[x1,#0x8]
x1+0x8 其实就是next+8个字节的偏移,看下:
struct?list_head?{
????struct?list_head?*next,?*prev;
};
ARM体系结构中,ARM64一个指针占8个字节内存,也就是: [x1+0x8] == prev
所以这个str指令就是对应上面的next->prev = prev
我们根据异常栈的寄存器值来看下:
[??423.400182]?PC?is?at?run_timer_softirq+0x4ac/0x5ec
[??423.400192]?LR?is?at?run_timer_softirq+0x324/0x5ec
[??423.400199]?pc?:?[]?lr?:?[]?pstate:?600001c5
[??423.400204]?sp?:?ffffffc0b28bfb60
[??423.400210]?x29:?ffffffc0b28bfb60?x28:?ffffffc0b2619038?
[??423.400219]?x27:?ffffffc000c9a000?x26:?0000000000000000?
[??423.400228]?x25:?ffffffc001741120?x24:?ffffffc0006e277c?
[??423.400237]?x23:?ffffffc0b2619000?x22:?ffffffc0b28bfbf8?
[??423.400246]?x21:?ffffffc0b28bc000?x20:?ffffffc0013d2000?
[??423.400254]?x19:?ffffffc0b2618000?x18:?0000007f9588e080?
[??423.400263]?x17:?0000007f9a36d4b4?x16:?ffffffc0001e4f6c?
[??423.400272]?x15:?003b9aca00000000?x14:?0000000000000001?
[??423.400280]?x13:?0000000000000000?x12:?0000000000000001?
[??423.400289]?x11:?000000000000000f?x10:?ffffffc000c9c3f4?
[??423.400297]?x9?:?0000000000000000?x8?:?0000000000000005?
[??423.400305]?x7?:?0000000000000000?x6?:?000000000001451c?
[??423.400314]?x5?:?ffffffc0b2ae8000?x4?:?00135f1aa15bb200?
[??423.400323]?x3?:?0000000000000018?x2?:?0000000000000000?
[??423.400331]?x1?:?0000000000000000?x0?:?ffffffc0b28bfbf8
上面可以看到,x1+0x8 ==0x0000000000000000+0x8==0x0000000000000008,这个和出错时候报的地址一致“Unable to handle kernel NULL pointer dereference at virtual address 00000008”
因为ARM64内核的虚拟地址空间范围是0xFFFF_0000_0000_0000 =>0xFFFF_FFFF_FFFF_FFFF,很明显这个值0x0000000000000008不在范围内,它属于用户空间的虚拟地址空间,肯定会被MMU拦截掉上报data abort异常,所以此题的真正原因是程序跑飞访问非法地址所致。
目前看来从kernel log上的信息无法直接分析出导致问题的具体源代码,从dmesg的这些信息我们已经知道出问题的是这个prev指针,但是比较难直接抓到导致异常的真凶源码位置。
Trace32 分析
利用dmesg我们分析了产生问题时候的来龙去脉,但是想要彻底解决还需要trace32进一步分析。
输入v.f,调出当前的调用栈关系:
可以看到,异常时候的各种参数都显示出来了,这样就非常有利于我们debug了,这也是单纯从dmesg无法得到的重要信息!注意inline类型的函数会被编译器默认优化掉,所以inline类型的函数的参数不可见,需要通过读汇编代码,分析寄存器传参推导。
输入d.list 查看PC停止的位置,如下高亮:
分析Call Stack:
为方便查看,把调用栈信息复制出来,如下:
?1.?...
-007|die(
????|???,
????|????regs?=?0xFFFFFFC0B28BFA40?->?(
????|??????user_regs?=?(regs?=?(0xFFFFFFC0B28BFBF8,?0x0,?0x0,?0x18,?0x00135F1AA15BB200,?0xFFFFFFC0B2AE800
????|??????regs?=?(0xFFFFFFC0B28BFBF8,?0x0,?0x0,?0x18,?0x00135F1AA15BB200,?0xFFFFFFC0B2AE8000,?0x0001451C
????|??????sp?=?0xFFFFFFC0B28BFB60,
????|??????pc?=?0xFFFFFFC0000FEB98,
????|??????pstate?=?0x600001C5,
????|??????orig_x0?=?0xFFFFFFC0B2618000,
????|??????syscallno?=?0xFFFFFFC0000FE7D0),
????|????err?=?0x96000046)
????|??flags?=?0x01C0
????|??ret?=?0x1
????|??tsk?=?0xFFFFFFC04EAE4980
????|??die_counter?=?0x1
-008|__do_kernel_fault.part.5(
????|????mm?=?0x0,
????|????addr?=?0x8,
????|????esr?=?0x96000046,
????|????regs?=?0xFFFFFFC0B28BFA40)
-009|do_page_fault(
????|????addr?=?0x8,
????|????esr?=?0x96000046,
????|????regs?=?0xFFFFFFC0B28BFA40)
????|??tsk?=?0xFFFFFFC04EAE4980
????|??mm?=?0x0
????|??vm_flags?=?0xFFFFFFC000C9A000
????|??vma?=?0xFFFFFFC0B28BFA40
-010|do_translation_fault(
????|????addr?=?0x0A44,
????|????esr?=?0x0124F800,
????|???)
-011|do_mem_abort(
????|????addr?=?0x8,
????|????esr?=?0x96000046,
????|????regs?=?0xFFFFFFC0B28BFA40)
????|??inf?=?0xFFFFFFC0013DC790?->?(
????|????fn?=?0xFFFFFFC000099A74,
????|????sig?=?0x0B,
????|????code?=?0x00030001,
????|????name?=?0xFFFFFFC0010DF250?->?0x6C)
????|??info?=?(
????|????si_signo?=?0x0032D110,
????|????si_errno?=?0xFFFFFFC0,
????|????si_code?=?0x01C0,
????|????_sifields?=?(_pad?=?(0x7,?0x0,?0xB28BF9E0,?0xFFFFFFC0,?0x000A6D78,?0xFFFFFFC0,?0xB28BF9F0,?0xFFF
-012|el1_da(asm)
?-->|exception
-013|__list_del(inline)
-013|detach_timer(inline)
-013|detach_expired_timer(inline)
-013|__run_timers(inline)
-013|run_timer_softirq(
????|???)
????|??base?=?0xFFFFFFC0B2618000?->?(
????|????lock?=?(rlock?=?(raw_lock?=?(owner?=?0x6FCD,?next?=?0x6FCE))),
????|????running_timer?=?0xFFFFFFC001741120?->?(
????|??????entry?=?(next?=?0xFFFFFFC0B27BC9B8,?prev?=?0xFFFFFFC0B27BC9B8),
????|??????expires?=?0x0000000100003098,
????|??????base?=?0xFFFFFFC0B27BC000,
????|??????function?=?0xFFFFFFC0006E277C?->?,
????|??????data?=?0x0,
????|??????slack?=?0xFFFFFFFF,
????|??????start_pid?=?0xFFFFFFFF,
????|??????start_site?=?0x0,
????|??????start_comm?=?(0x0,?0x0,?0x0,?0x0,?0x0,?0x0,?0x0,?0x0,?0x0,?0x0,?0x0,?0x0,?0x0,?0x0,?0x0,?0x0))
????|????timer_jiffies?=?0x0000000100003035,
????|????next_timer?=?0x0000000100003034,
????|????active_timers?=?0x7,
????|????all_timers?=?0x7,
????|????cpu_=_0x4,
????|????tv1?=?(vec?=?((next?=?0xFFFFFFC0B2618038,?prev?=?0xFFFFFFC0B2618038),?(next?=?0xFFFFFFC0B2618048
????|????tv2?=?(vec?=?((next?=?0xFFFFFFC0B2619038,?prev?=?0xFFFFFFC0B2619038),?(next?=?0xFFFFFFC0B2619048
????|????tv3?=?(vec?=?((next?=?0xFFFFFFC0B2619438,?prev?=?0xFFFFFFC0B2619438),?(next?=?0xFFFFFFC0B2619448
????|????tv4?=?(vec?=?((next?=?0xFFFFFFC0B2619838,?prev?=?0xFFFFFFC0B2619838),?(next?=?0xFFFFFFC0B2619848
????|????tv5?=?(vec?=?((next?=?0xFFFFFFC0B2619C38,?prev?=?0xFFFFFFC0B2619C38),?(next?=?0xFFFFFFC0B2619C48
????|??fn?=?0xFFFFFFC0006E277C?->
????|??data?=?0x0
????|??it_func_ptr?=?0x0
...
看到这里,我们可以猜想是不是run_timer_softirq的参数出现了问题导致后面发生的一系列异常?可以从这个方向开始思考,我们先来看下这个函数的实现:
static?void?run_timer_softirq(struct?softirq_action?*h)
{
????struct?tvec_base?*base?=?__this_cpu_read(tvec_bases);
????hrtimer_run_pending();
????__run_deferrable_timers();
????if?(time_after_eq(jiffies,?base->timer_jiffies))
????????__run_timers(base);
}
我们看到这个函数最重要的参数变量就是这个base,传入的h没有使用,继续来看下base的结构tvec_base :
struct?tvec_base?{
????spinlock_t?lock;
????struct?timer_list?*running_timer;
????unsigned?long?timer_jiffies;
????unsigned?long?next_timer;
????unsigned?long?active_timers;
????unsigned?long?all_timers;
????int?cpu;??//?跟踪所在的CPU是哪个核,这里是CPU?4
????struct?tvec_root?tv1;
????struct?tvec?tv2;
????struct?tvec?tv3;
????struct?tvec?tv4;
????struct?tvec?tv5;
}?____cacheline_aligned;
这里就看到 tvec_base 的结构里面有个 struct timer_list * 的结构,我们继续看它的结构是怎么样的:
struct?timer_list?{
????/*
?????*?All?fields?that?change?during?normal?runtime?grouped?to?the
?????*?same?cacheline
?????*/
????struct?list_head?entry;
????unsigned?long?expires;
????struct?tvec_base?*base;
????void?(*function)(unsigned?long);
????unsigned?long?data;
????int?slack;
...
首先我们查看 running_timer 的数据内容,
工具栏调出:view -> Watch,输入:(struct timer_list *)0xffffffc001741120
这个就是发生异常的那个timer的数据结构实例,我们最希望的就是希望可以通过这里的数据信息找到它在源码的位置,然后进一步分析它,使用Trace32的 dump 分析功能就可以做到这点。
菜单栏调出:view -> dump
输入地址 0xffffffc001741120 然后点OK
右击高亮,选择view info:
同理,还可以看function的位置(0xFFFFFFC0006E277C):
上面所示,出异常的timer实例就是:fp_drv/m_timer, callback = timer_out_handle,源码位置也给出来了,那么就可以着手修复问题了。