一次system hang的调试经历

调试了3周，终于把问题找到了，今晚不加班:-).

问题描述

在高通的一个项目中，我们在modem侧制造crash，这个crash会通过管道传递到linux这端。Linux这侧收到这个消息后，就会将重启任务放到一个work中，通过schedule_work将这个work加入system_wq. 等待worker线程执行重启任务。但是经过反复的重启测试，发现会有偶现的系统hang无法重启的情况。

问题定位

对于system hang的问题，高通提供了一套工具，名叫linux-ramdump-parser-v2，可以将ramdump出来，然后用这个工具去解析。

Log分析

下面是workqueue的解析情况，当前平台只有一个CPU，对于bind的线程池，每个 CPU有两个，一个是普通优先级的线程池，一个是高优先级的线程池。高优先级线程池中的线程如kwoker/0:0H。下面pool 0是普通线程池，pool 1是高优先级线程池。

CPU 0
pool 0
BUSY Workqueue worker: kworker/0:8 current_work: (None)
BUSY Workqueue worker: kworker/0:9 current_work: (None)
BUSY Workqueue worker: kworker/0:10 current_work: (None)
BUSY Workqueue worker: kworker/0:11 current_work: (None)
BUSY Workqueue worker: kworker/0:12 current_work: (None)
BUSY Workqueue worker: kworker/0:13 current_work: (None)
BUSY Workqueue worker: kworker/0:2 current_work: (None)
BUSY Workqueue worker: kworker/0:14 current_work: (None)
BUSY Workqueue worker: kworker/0:5 current_work: (None)
BUSY Workqueue worker: kworker/0:4 current_work: (None)
BUSY Workqueue worker: kworker/0:3 current_work: (None)
BUSY Workqueue worker: kworker/0:0 current_work: (None)
BUSY Workqueue worker: kworker/0:6 current_work: (None)
BUSY Workqueue worker: kworker/0:7 current_work: (None)
IDLE Workqueue worker: kworker/0:1 current_work: (None)
IDLE Workqueue worker: kworker/0:15 current_work: (None)
Pending entry: device_restart_work_hdlr
Pending entry: ubiblock_do_work
Pending entry: ubiblock_do_work
Pending entry: ubiblock_do_work
Pending entry: ubiblock_do_work
Pending entry: ubiblock_do_work
Pending entry: pm_runtime_work
Pending entry: neigh_periodic_work
Pending entry: do_cache_clean
Pending entry: neigh_periodic_work
Pending entry: push_to_pool
Pending entry: push_to_pool
Pending entry: addrconf_verify_work
Pending entry: check_lifetime
Pending entry: release_one_tty
Pending entry: console_callback
pool 1
IDLE Workqueue worker: kworker/0:0H current_work: (None)

从上面的日志可以看出普通线程池有大量的BUSY线程，同时也有两个IDLE线程。理论上，只要有IDLE线程，我们的重启任务device_restart_work_hdlr就会被IDLE线程执行。从CMWQ(Concurrency Managed Workqueue)的设计上来说，线程池中一个时间点只允许1个线程运行。于是我们可以猜测，线程池中确实有一个线程正在执行，并且这个线程获取了某种锁，导致其他线程无法获取到锁而睡眠。我们需要这些kworker的backtrace，看看他们在干什么。这里只举两个例子，kworker/0:10和kworker/0:14。

===================================================== 
 Process: kworker/0:10, cpu: 0 pid: 292 start: 0xddea3600 
==