android 看门狗引起crash分析

最新推荐文章于 2024-06-12 09:29:58 发布

checode

最新推荐文章于 2024-06-12 09:29:58 发布

阅读量1.5k

点赞数 1

分类专栏： arm android 文章标签： crash

本文链接：https://blog.csdn.net/qq_28637193/article/details/103713811

版权

android 同时被 2 个专栏收录

19 篇文章 1 订阅

订阅专栏

arm

13 篇文章 5 订阅

订阅专栏

文章参考：https://blog.csdn.net/juS3Ve/article/details/79428049

在进入橙屏ramdump 后在高通平台高通有专门的脚本配合crash 工具去解析dump 出来的bin 文件。在解析bin 文件之前必须先转被好vmlinux 文件，也就是内核的符号表。解析完成后会在out 文件夹里生成一些信息。这些信息会在一个html 网页中被统计进来。

高通的脚本将一些信息已经从ramdump 中解析出来在out 文件夹中生成了txt 文件。然后高通在生成了一个如上图的一个网页。

分析橙屏问题，首先需要看一下panic 错误。

panic log 的第一条信息如下：

可以看到内核踩到了全是0 的地址，看这条log 基本已经猜到是android 的看门狗触发了的。一般主动触发内核异常是往00地址写入数据。接着看下面的log 果然看到watch dog 相关的log

看门狗线程的pid 是2075 运行在cpu 1上。也就是这个任务往0地址写入数据导致系统crash。

在crash 工具中也可以执行log 命令来查看内核的log 查找panic。下图是将log 保存到了logfile.log 文件中

android watchdog 机制会不断去检测各个任务中mm的mmap_sem 读写信号量，一旦长时间没有拿到就会主动触发crash。一般设置是一分钟还没有拿到这个信号量系统就判断出现了卡死，然后进行crash。

在crash 工具中搜索watchdog

可以看到2074 这个线程现在处于UN状态，UN 即是UNINTERRUPTIBLE 目前已经处于一种不可打断的休眠。此线程就是在等读写信号量失败的线程。

执行bt 命令查看当前线程的调用栈

调度栈的#4可以看到调用了down_read_killable 函数，此函数是以读者的身份去获得锁，但是在#3 rwsem_down_read_failed_killable 看到获取锁失败了，触发了调度。也就是说这个锁被另外的线程持有了，现在要找到持有线程的锁。

在__access_remote_vm 代码中能够看到down_read_killable(&mm->mmap_sem)

int __access_remote_vm(struct task_struct *tsk, struct mm_struct *mm,
		unsigned long addr, void *buf, int len, unsigned int gup_flags)
{
	struct vm_area_struct *vma;
	void *old_buf = buf;
	int write = gup_flags & FOLL_WRITE;

	if (down_read_killable(&mm->mmap_sem))
		return 0;

   .....
}

在arm 体系结构中如果参数少于6个，会直接使用寄存器x0到x6 来保存参数，不使用压栈传递。也就是sem 是通过x0 寄存器传递给down_read_killable 的。也就是说在跳转到down_read_killable 函数前，x0 已经保存好了当前的sem 的地址。

在crash 工具中执行 dis __access_remote_vm 查看其汇编代码。

crash> dis __access_remote_vm
0xffffffac3ae64c88 <__access_remote_vm>:        sub     sp, sp, #0x80
0xffffffac3ae64c8c <__access_remote_vm+4>:      stp     x28, x27, [sp,#32]
0xffffffac3ae64c90 <__access_remote_vm+8>:      stp     x26, x25, [sp,#48]
0xffffffac3ae64c94 <__access_remote_vm+12>:     stp     x24, x23, [sp,#64]
0xffffffac3ae64c98 <__access_remote_vm+16>:     stp     x22, x21, [sp,#80]
0xffffffac3ae64c9c <__access_remote_vm+20>:     stp     x20, x19, [sp,#96]
0xffffffac3ae64ca0 <__access_remote_vm+24>:     stp     x29, x30, [sp,#112]
0xffffffac3ae64ca4 <__access_remote_vm+28>:     add     x29, sp, #0x70
0xffffffac3ae64ca8 <__access_remote_vm+32>:     adrp    x8, 0xffffffac3d00d000
0xffffffac3ae64cac <__access_remote_vm+36>:     add     x20, x1, #0x68
0xffffffac3ae64cb0 <__access_remote_vm+40>:     mov     x25, x0
0xffffffac3ae64cb4 <__access_remote_vm+44>:     ldr     x8, [x8,#2696]
0xffffffac3ae64cb8 <__access_remote_vm+48>:     mov     x0, x20
0xffffffac3ae64cbc <__access_remote_vm+52>:     mov     w21, w5
0xffffffac3ae64cc0 <__access_remote_vm+56>:     mov     x22, x1
0xffffffac3ae64cc4 <__access_remote_vm+60>:     mov     w23, w4
0xffffffac3ae64cc8 <__access_remote_vm+64>:     mov     x19, x3
0xffffffac3ae64ccc <__access_remote_vm+68>:     str     x8, [sp,#24]
0xffffffac3ae64cd0 <__access_remote_vm+72>:     mov     x24, x2
0xffffffac3ae64cd4 <__access_remote_vm+76>:     bl      0xffffffac3bf52400
0xffffffac3ae64cd8 <__access_remote_vm+80>:     cbz     w0, 0xffffffac3ae64ce4
0xffffffac3ae64cdc <__access_remote_vm+84>:     mov     w0, wzr

...... 省略一部分代码

从c语言代码中可以看到down_read_killable 是其第一个跳转。从当前汇编代码中跳转一般是bl 指令

0xffffffac3ae64cd4 <__access_remote_vm+76>: bl 0xffffffac3bf52400

0xffffffac3bf52400 地址对应的符号查一下是不是down_read_killable ，可以确定猜想了。

crash 中提供了命令sym 实现了这个功能

crash> sym 0xffffffac3bf52400
ffffffac3bf52400 (T) down_read_killable  kernel/locking/rwsem.c: 33

确定了跳转的位置后，开始查找x0 寄存器被赋值的地方，可以看到

0xffffffac3ae64cb8 <__access_remote_vm+48>: mov x0, x20

x0 的值是x20 给赋值的，继续查找x20 寄存器被赋值的地方，继续向上可以看到

0xffffffac3ae64cac <__access_remote_vm+36>: add x20, x1, #0x68

x20 是 x1 加上0x68 的位置。

这里x1 就是mm_struct 结构的地址。执行whatis -o 可以查看结构体的中的内容和偏移

crash> whatis -o mm_struct
struct mm_struct {
        struct {
    [0]     struct vm_area_struct *mmap;
    [8]     struct rb_root mm_rb;
   [16]     u64 vmacache_seqnum;
   [24]     rwlock_t mm_rb_lock;
   [32]     unsigned long (*get_unmapped_area)(struct file *, unsigned long, unsigned long, unsigned long, unsigned long);
   [40]     unsigned long mmap_base;
   [48]     unsigned long mmap_legacy_base;
   [56]     unsigned long task_size;
   [64]     unsigned long highest_vm_end;
   [72]     pgd_t *pgd;
   [80]     atomic_t mm_users;
   [84]     atomic_t mm_count;
   [88]     atomic_long_t pgtables_bytes;
   [96]     int map_count;
  [100]     spinlock_t page_table_lock;
  [104]     struct rw_semaphore mmap_sem;

0x68 对应的就是104 。在看上面函数的反汇编代码

0xffffffac3ae64cc0 <__access_remote_vm+56>: mov x22, x1

x1 会被赋值给x22

所以知道x22，x1 或者x20的值就知道sem 读写信号量的地址了。由于系统在修改寄存器的时候会将寄存器原来的值压栈，在后面的函数中不断的查找有没有使用这个几个寄存器。

crash> dis down_read_killable
0xffffffac3bf52400 <down_read_killable>:        str     x19, [sp,#-32]!
0xffffffac3bf52404 <down_read_killable+4>:      stp     x29, x30, [sp,#16]
0xffffffac3bf52408 <down_read_killable+8>:      add     x29, sp, #0x10
0xffffffac3bf5240c <down_read_killable+12>:     prfm    pstl1strm, [x0]
0xffffffac3bf52410 <down_read_killable+16>:     ldaxr   x8, [x0]
0xffffffac3bf52414 <down_read_killable+20>:     add     x8, x8, #0x1
0xffffffac3bf52418 <down_read_killable+24>:     stxr    w9, x8, [x0]
0xffffffac3bf5241c <down_read_killable+28>:     cbnz    w9, 0xffffffac3bf52410
0xffffffac3bf52420 <down_read_killable+32>:     mov     x19, x0
0xffffffac3bf52424 <down_read_killable+36>:     cmp     x8, #0x0
0xffffffac3bf52428 <down_read_killable+40>:     b.le    0xffffffac3bf52458
0xffffffac3bf5242c <down_read_killable+44>:     ldr     x8, [x19,#32]
0xffffffac3bf52430 <down_read_killable+48>:     cmp     x8, #0x1
0xffffffac3bf52434 <down_read_killable+52>:     b.eq    0xffffffac3bf52448
0xffffffac3bf52438 <down_read_killable+56>:     orr     w8, wzr, #0x1
0xffffffac3bf5243c <down_read_killable+60>:     mov     w0, wzr
0xffffffac3bf52440 <down_read_killable+64>:     str     x8, [x19,#32]
0xffffffac3bf52444 <down_read_killable+68>:     b       0xffffffac3bf5244c
0xffffffac3bf52448 <down_read_killable+72>:     mov     w0, wzr
0xffffffac3bf5244c <down_read_killable+76>:     ldp     x29, x30, [sp,#16]
0xffffffac3bf52450 <down_read_killable+80>:     ldr     x19, [sp],#32
0xffffffac3bf52454 <down_read_killable+84>:     ret
0xffffffac3bf52458 <down_read_killable+88>:     mov     x0, x19
0xffffffac3bf5245c <down_read_killable+92>:     bl      0xffffffac3bf52e68
0xffffffac3bf52460 <down_read_killable+96>:     cmn     x0, #0x1, lsl #12
0xffffffac3bf52464 <down_read_killable+100>:    b.ls    0xffffffac3bf5242c
0xffffffac3bf52468 <down_read_killable+104>:    orr     w0, wzr, #0xfffffffc
0xffffffac3bf5246c <down_read_killable+108>:    b       0xffffffac3bf5244c

down_read_killable 函数中没有使用，接着追rwsem_down_read_failed_killable 函数

crash> dis rwsem_down_read_failed_killable
0xffffffac3bf52e68 <rwsem_down_read_failed_killable>:   sub     sp, sp, #0x90
0xffffffac3bf52e6c <rwsem_down_read_failed_killable+4>: str     x23, [sp,#80]
0xffffffac3bf52e70 <rwsem_down_read_failed_killable+8>: stp     x22, x21, [sp,#96]
0xffffffac3bf52e74 <rwsem_down_read_failed_killable+12>:        stp     x20, x19, [sp,#112]
0xffffffac3bf52e78 <rwsem_down_read_failed_killable+16>:        stp     x29, x30, [sp,#128]
0xffffffac3bf52e7c <rwsem_down_read_failed_killable+20>:        add     x29, sp, #0x80
0xffffffac3bf52e80 <rwsem_down_read_failed_killable+24>:        adrp    x8, 0xffffffac3d00d000
0xffffffac3bf52e84 <rwsem_down_read_failed_killable+28>:        mrs     x21, sp_el0

在rwsem_down_read_failed_killable 函数的开始就看到入栈指令stp 将x22 压入栈中。此时需要看前面的调用栈

ffffff801b833c10 是 rwsem_down_read_failed_killable 函数的fp ， ffffff801b833b80 是 schedule 的fp。

我们要求当前rwsem_down_read_failed_killable 的sp，将schedule 的fp 加上0x10 就是rwsem_down_read_failed_killable 的sp

ffffff801b833b80 + 0x10 = ffffff801b833b90 .为什么是0x10 从代码上看，比如rwsem_down_read_failed_killable 的汇编，进入代码后sp直接减0x90 但是保存fp 的地址是sp +0x80 中间差了0x10

算出堆栈的地址后，rd 命令读取此地址的值

获得地址fffffffaacb16900，使用struct 命令此处结构体

查找其owner, 有两个owner 有一个是mm_struct 的持有者，一个是

0xfffffffaa1d7d700 就是当前mm_struct 的owner . owner =1 这个owner 是mmap_sem 中的owner

等于1 说明当前是个读者持有的锁。

是用stuct 命令在看其任务名称

此时已经知道当前看门狗在等待那个任务的读写信号量

list rwsem_waiter.list -s rwsem_waiter.task,type -h 0xffffff80169d3c18 来获得读写信号量上的wait list

0xffffff80169d3c18 这个地址是在前面获得 struct mm_struct fffffffaacb16900 mm_struct 结构体中打印出来的list 地址

mmap_sem = {
      count = {
        counter = -4294967259
      }, 
      wait_list = {
        next = 0xffffff80169d3c18, 
        prev = 0xffffff801b833bb8
      }, 
      wait_lock = {
        raw_lock = {
          {
            val = {
              counter = 0
            }, 
            {
              locked = 0 '\000', 
              pending = 0 '\000'
            }, 
            {
              locked_pending = 0, 
              tail = 0
            }
          }
        }
      },

从等待链表中可以看到第一个是写线程，后面都是读线程。这中情况一般都是信号释放后，把原本写者前面的读者任务都给唤醒的了.

后面挨个通过任务地址获得pid ，然后使用bt 命令调用其调用栈，查看其是否拿者锁

执行 search -t 0xfffffffaacb1696 从所有内核任务中堆栈中搜索0xfffffffaacb1696

-t 官方解释

-t  Search only the kernel stack pages of every task.  If one or more
              matches are found in a task's kernel stack, precede the output
              with a task-identifying header.

朴英敏的文章能够从任务中直接找到down_read 函数调用，不过有些时候无法获取到相关的信息。

比如用search 搜出的一个任务

PID: 13736  TASK: fffffff9e5118000  CPU: 6   COMMAND: "HwBinder:751_2"
ffffff8017173bc8: fffffffaacb16968 
ffffff8017173c40: fffffffaacb16968 
ffffff8017173c48: fffffffaacb16968 
ffffff8017173cc8: fffffffaacb16968

使用bt 查看这个任务的调用栈

crash> bt 13736
PID: 13736  TASK: fffffff9e5118000  CPU: 6   COMMAND: "HwBinder:751_2"
 #0 [ffffff8017173a40] __switch_to at ffffffac3ac87ae0
 #1 [ffffff8017173ad0] __schedule at ffffffac3bf4f628
 #2 [ffffff8017173af0] preempt_schedule_irq at ffffffac3bf4fc18
 #3 [ffffff8017173c30] el1_preempt at ffffffac3ac82c6c
 #4 [ffffff8017173c50] schedule at ffffffac3bf4fa64
 #5 [ffffff8017173cd0] rwsem_down_read_failed at ffffffac3bf52de4
 #6 [ffffff8017173cf0] down_read at ffffffac3bf523f8
 #7 [ffffff8017173de0] do_page_fault at ffffffac3aca2c6c
 #8 [ffffff8017173eb0] do_mem_abort at ffffffac3ac80c68
 #9 [ffffff8017173ff0] el0_da at ffffffac3ac832a0

可以看到 rwsem_down_read_failed 说明获取读写锁失败了，理论上当失败应该被挂到读写信号量的wait list 中，但是在当前的wait list 并没有这个任务。

在crash 工具中执行runq 查看当前cpu 的runqueue

crash> runq
CPU 0 RUNQUEUE: fffffffabfc32b80
  CURRENT: PID: 0      TASK: ffffffac3d01bfc0  COMMAND: "swapper/0"
  RT PRIO_ARRAY: fffffffabfc32d80
     [no tasks queued]
  CFS RB_ROOT: fffffffabfc32c30
     [no tasks queued]

CPU 1 RUNQUEUE: fffffffabfc4ab80
  CURRENT: PID: 2075   TASK: fffffffa5371c880  COMMAND: "watchdog"
  RT PRIO_ARRAY: fffffffabfc4ad80
     [no tasks queued]
  CFS RB_ROOT: fffffffabfc4ac30
     [120] PID: 23819  TASK: fffffffa51124880  COMMAND: "kworker/1:0"

CPU 2 RUNQUEUE: fffffffabfc62b80
  CURRENT: PID: 0      TASK: fffffffab8534880  COMMAND: "swapper/2"
  RT PRIO_ARRAY: fffffffabfc62d80
     [no tasks queued]
  CFS RB_ROOT: fffffffabfc62c30
     [no tasks queued]

CPU 3 RUNQUEUE: fffffffabfc7ab80
  CURRENT: PID: 23828  TASK: fffffff99b470000  COMMAND: "logcat"
  RT PRIO_ARRAY: fffffffabfc7ad80
     [no tasks queued]
  CFS RB_ROOT: fffffffabfc7ac30
     [no tasks queued]

CPU 4 RUNQUEUE: fffffffabfc92b80
  CURRENT: PID: 0      TASK: fffffffab8531d00  COMMAND: "swapper/4"
  RT PRIO_ARRAY: fffffffabfc92d80
     [no tasks queued]
  CFS RB_ROOT: fffffffabfc92c30
     [no tasks queued]

CPU 5 RUNQUEUE: fffffffabfcaab80
  CURRENT: PID: 0      TASK: fffffffab8532b80  COMMAND: "swapper/5"
  RT PRIO_ARRAY: fffffffabfcaad80
     [no tasks queued]
  CFS RB_ROOT: fffffffabfcaac30
     [no tasks queued]

CPU 6 RUNQUEUE: fffffffabfcc2b80
  CURRENT: PID: 9316   TASK: fffffff9ef0a5700  COMMAND: "HwBinder:751_3"
  RT PRIO_ARRAY: fffffffabfcc2d80
     [ 98] PID: 3214   TASK: fffffffa32e38e80  COMMAND: "HwBinder:751_2"
  CFS RB_ROOT: fffffffabfcc2c30
     [120] PID: 13729  TASK: fffffffab7552b80  COMMAND: "HwBinder:751_2"
     [120] PID: 13712  TASK: fffffff9c9e62b80  COMMAND: "HwBinder:751_2"
     [120] PID: 13736  TASK: fffffff9e5118000  COMMAND: "HwBinder:751_2"
     [120] PID: 13713  TASK: fffffff9c9e61d00  COMMAND: "HwBinder:751_2"
     [119] PID: 3275   TASK: fffffffa88e7ab80  COMMAND: "cds_ol_rx_threa"
     [120] PID: 13714  TASK: fffffffa88e25700  COMMAND: "HwBinder:751_2"
     [120] PID: 13718  TASK: fffffffaa2e09d00  COMMAND: "HwBinder:751_2"
     [120] PID: 8368   TASK: fffffff99d33ba00  COMMAND: "kworker/6:0"
     [120] PID: 13735  TASK: fffffff9e511ab80  COMMAND: "HwBinder:751_2"
     [120] PID: 13732  TASK: fffffffa2a823a00  COMMAND: "HwBinder:751_2"
     [120] PID: 13715  TASK: fffffff9fcc75700  COMMAND: "HwBinder:751_2"
     [120] PID: 13716  TASK: fffffff9fcc72b80  COMMAND: "HwBinder:751_2"
     [120] PID: 13731  TASK: fffffffa2a820e80  COMMAND: "HwBinder:751_2"
     [120] PID: 13730  TASK: fffffffab7551d00  COMMAND: "HwBinder:751_2"
     [120] PID: 13711  TASK: fffffff9c9e66580  COMMAND: "HwBinder:751_2"
     [120] PID: 13724  TASK: fffffffaaa473a00  COMMAND: "HwBinder:751_2"
     [120] PID: 13737  TASK: fffffffa89f3ba00  COMMAND: "HwBinder:751_2"
     [120] PID: 13739  TASK: fffffff9da3ec880  COMMAND: "HwBinder:751_2"
     [120] PID: 13721  TASK: fffffffa8983c880  COMMAND: "HwBinder:751_2"
     [120] PID: 13726  TASK: fffffff9cd185700  COMMAND: "HwBinder:751_2"
     [120] PID: 13707  TASK: fffffff9e7975700  COMMAND: "HwBinder:751_2"
     [120] PID: 13720  TASK: fffffffa8983d700  COMMAND: "HwBinder:751_2"
     [120] PID: 13727  TASK: fffffff9fc656580  COMMAND: "HwBinder:751_2"
     [120] PID: 1535   TASK: fffffffa65c42b80  COMMAND: "provider@2.4-se"
     [120] PID: 13719  TASK: fffffffa8889ab80  COMMAND: "HwBinder:751_2"
     [120] PID: 13717  TASK: fffffff9f0709d00  COMMAND: "HwBinder:751_2"
     [120] PID: 13733  TASK: fffffff9f7294880  COMMAND: "HwBinder:751_2"
     [120] PID: 3203   TASK: fffffffa88ab8e80  COMMAND: "HwBinder:751_1"
     [120] PID: 13734  TASK: fffffff99b754880  COMMAND: "HwBinder:751_2"
     [120] PID: 13740  TASK: fffffff9fa1c8000  COMMAND: "HwBinder:751_2"
     [120] PID: 13725  TASK: fffffff9cd180e80  COMMAND: "HwBinder:751_2"
     [120] PID: 13710  TASK: fffffffa89d90e80  COMMAND: "HwBinder:751_2"
     [120] PID: 13723  TASK: fffffffaaa476580  COMMAND: "HwBinder:751_2"
     [120] PID: 13706  TASK: fffffffaa4194880  COMMAND: "HwBinder:751_2"
     [120] PID: 13738  TASK: fffffffa89f3d700  COMMAND: "HwBinder:751_2"
     [120] PID: 13722  TASK: fffffffa89839d00  COMMAND: "HwBinder:751_2"
     [120] PID: 13709  TASK: fffffff9e5210000  COMMAND: "HwBinder:751_2"
     [120] PID: 13728  TASK: fffffffab7553a00  COMMAND: "HwBinder:751_2"

CPU 7 RUNQUEUE: fffffffabfcdab80
  CURRENT: PID: 0      TASK: fffffffab8535700  COMMAND: "swapper/7"
  RT PRIO_ARRAY: fffffffabfcdad80
     [no tasks queued]
  CFS RB_ROOT: fffffffabfcdac30
     [no tasks queued]

发现包含pid 13736 在内的很多任务在cpu6 上等待运行。 cpu6 的任务负载很重。之前在sem等待队列中没有 13736 ，从这里看他已经被唤醒，到达了cpu6 的等待运行队列。其他cpu 比较空闲，这里cpu6 应该是存在大量的绑定核。许多任务在runqueue中没有得到及时执行。