系统诊断小技巧（11）：如何解决“问题复现了，但是捕捉数据进程因为CPU打满没有运行”？

引子

曾经搞过一个尴尬的案例。排查过一个CPU打满的问题。因为问题是在凌晨出现，而且非常随机。所以我们就准备了一个脚本，用来捕获占用CPU高的线程。但尴尬的是，问题复现了，我们的脚本偏偏在问题复现时，没有记录。推断是因为CPU打满，脚本没有机会执行导致的。

那么，CPU打满导致捕捉数据的进程没有运行的问题，能够解决吗？我们尝试回答这个问题。

亦步亦趋：了解Linux内核线程watchdog是怎么保证及时运行的

watchdog内核线程是检测Linux内核softlock机制的一部分，必须及时运行，除非是内核死锁了。如果我们把目光聚焦在用户空间，那么watchdog内核线程的运行设定是个合适的模仿对象。

理解watchdog的运行特点，需要稍微了解下Linux的调度策略和

chrt(1)

工具。

Linux支持多个调度策略，在“实时”的调度策略上又有调度优先级的区分。这部分话题，以后有机会我们再细聊。现在只要知道这一点，并且知道我们可以使用

检查和设置即可。

那么，watchdog内核线程有什么特殊呢？比较下

# 1. 检查watchdog的pid
root@pusf:~# ps -ef | egrep watchdog | egrep -v egrep
root        11     2  0 09:15 ?        00:00:00 [watchdog/0]
root        14     2  0 09:15 ?        00:00:00 [watchdog/1]
... ....
# 2. 检测watchdog的调度策略和优先级
root@pusf:~# chrt -p 11
pid 11's current scheduling policy: SCHED_FIFO
pid 11's current scheduling priority: 99
# 3. 检测当前交互shell的调度策略和优先级
root@pusf:~# chrt -p $$
pid 10389's current scheduling policy: SCHED_OTHER
pid 10389's current scheduling priority: 0
root@pusf:~#           

简单比较，让我们了解了两种调度策略(sched-fifo vs. sched-other)和两种优先级(99 vs. 0)。

下面我们用简单例子测试下这两种调度策略的差别。

两种调度策略的比较

测试脚本和压力产生器

我们的测试脚本每隔1秒打印下时间戳，一共取10次。具体内容如下(下文以demo指代这个脚本)：

#!/bin/bash

export LANG=C

for ((i=0;i<10;i++));do
    sleep 1
    date
done           

既然是比较在CPU打满情况下的调度策略，自然也需要一个压力产生器，用来把CPU打满。我们偷偷懒，直接使用

perf(1)

基线数据

我们给出CPU没有打满情况下的测试数据，作为基线数据。测试命令如下

root@pusf:~# ./demo > baseline-data-1 & ./demo > baseline-data-2 &           

让我们看看测试结果

# baseline-data-1
Fri Aug 24 06:17:59 EDT 2018
Fri Aug 24 06:18:00 EDT 2018
Fri Aug 24 06:18:01 EDT 2018
Fri Aug 24 06:18:02 EDT 2018
Fri Aug 24 06:18:04 EDT 2018
Fri Aug 24 06:18:05 EDT 2018
Fri Aug 24 06:18:06 EDT 2018
Fri Aug 24 06:18:07 EDT 2018
Fri Aug 24 06:18:08 EDT 2018
Fri Aug 24 06:18:09 EDT 2018

# baseline-data-2
Fri Aug 24 06:17:59 EDT 2018
Fri Aug 24 06:18:00 EDT 2018
Fri Aug 24 06:18:01 EDT 2018
Fri Aug 24 06:18:02 EDT 2018
Fri Aug 24 06:18:04 EDT 2018
Fri Aug 24 06:18:05 EDT 2018
Fri Aug 24 06:18:06 EDT 2018
Fri Aug 24 06:18:07 EDT 2018
Fri Aug 24 06:18:08 EDT 2018
Fri Aug 24 06:18:09 EDT 2018           

难以置信， 两份数据没有什么差异。好吧，测试机确实是非常的空闲。

CPU打满情况下的测试结果

我们再采样前，先运行压力产生器把CPU打满。具体运行命令如下

root@pusf:~# perf bench sched messaging -l 10000 & \ # 启动压力产生器
sleep 1; \ # 等待压力产生器驱动CPU
./demo > sched-other.log & \ # 以默认/正常的调度策略采样
chrt -f 99 ./demo > sched-fifo.log & # 以watchdog的调度策略和优先级运行采样           

让我们看看结果。

# sched-other.log
Fri Aug 24 06:06:43 EDT 2018
Fri Aug 24 06:06:49 EDT 2018
Fri Aug 24 06:06:55 EDT 2018
Fri Aug 24 06:07:00 EDT 2018
Fri Aug 24 06:07:02 EDT 2018
Fri Aug 24 06:07:04 EDT 2018
Fri Aug 24 06:07:06 EDT 2018
Fri Aug 24 06:07:08 EDT 2018
Fri Aug 24 06:07:09 EDT 2018
Fri Aug 24 06:07:10 EDT 2018

# sched-fifo.log
Fri Aug 24 06:06:39 EDT 2018
Fri Aug 24 06:06:40 EDT 2018
Fri Aug 24 06:06:41 EDT 2018
Fri Aug 24 06:06:42 EDT 2018
Fri Aug 24 06:06:43 EDT 2018
Fri Aug 24 06:06:44 EDT 2018
Fri Aug 24 06:06:45 EDT 2018
Fri Aug 24 06:06:46 EDT 2018
Fri Aug 24 06:06:47 EDT 2018
Fri Aug 24 06:06:48 EDT 2018           

调度策略在CPU打满情况下的差异太明显了。第一份数据前后间隔没有是1秒的情况，而第二份数据估计完美主义者都会树大拇指。

步骤

如何解决我们开头提出的问题，现在已经很明确了。我们不再饶舌。

探索愉快!