一、背景
性能和稳定性是一个计算机工程里的一个永恒的主题。其中尤其稳定性这块的问题发现和问题分析及问题解决就依赖合适的对系统的观测的手段,帮助我们发现问题,识别问题原因最后才能解决问题。稳定性问题里尤其底层问题里,除了panic问题可以借助pstore的堆栈快速定位问题以外,其他有些问题并不触发panic,但是对系统却带来很大的不稳定的因素。比如,因为某些设计上或者设计外的原因长时间关闭了抢占甚至长时间关闭了软中断或者硬中断,这些行为无论是预期内还是预期外的,我们至少要能察觉,或者有办法察觉和观测,可以在需要的时候打开这些观测手段,做这些系统异常行为的记录,方便问题回溯和追查根因。
在 中断上下文及抢占标志位的检查——基于调度及锁举例-CSDN博客 这篇博客里,我们介绍了如何来检查这些标志位状态,以及这些标志位状态的具体的含义和对应的场景,在里面的 2.2.2 一节里也提到了:
这也正是现在这篇博文要讨论的硬中断关闭场景如何观测的事情。
本文的第二章会介绍系统现有的抓取机制hardlockup/softlockup,以及一个开源的项目trace_irqoff来捕获软硬中断关闭事件及事件有关的信息,也会讲到它们的一些美中不足,该第二章里并不会设计很多trace_irqoff的代码细节,有关trace_irqoff的代码实现细节后面会写一篇来详细介绍。在第三章里会介绍当前的“定制”后的方案及对应的逻辑实现细节,以及为什么要这么定制。
二、系统现有的watchdog方案及开源项目trace_irqoff及它们的美中不足
系统的watchdog方案和开源项目的trace_irqoff的方案在检测硬中断关闭的场景的方法部分是类似的,都是借助hrtimer,因为hrtimer是被硬中断触发来响应的,如果hrtimer的回调没有按照设定的时间超时来响应就说明没有及时响应的这段时间内硬中断被关闭了。系统的watchdog还利用了nmi中断去在检测到硬中断关闭的时候通过nmi进行堆栈状态的搜集,当然这个搜集动作做还是不做是受变量控制的。
对于软中断而言,则方案上就有很多种了。trace_irqoff借助的是普通的timer,因为普通的timer的响应是借助着softirq里的TIMER类别的软中断响应来做状态的更新。系统的watchdog里的软中断关闭检测是借助的内嵌于内核调度系统里的代码,跟随调度系统的逻辑进行定期的更新。
2.1 系统现有的watchdog方案及其美中不足
2.1.1 系统现有的watchdog的实现方案介绍
系统现有的watchdog的方案,分为hardlockup和softlockup两种。
2.1.1.1 hardlockup实现介绍
hardlockup是复用的perf的nmi中断的使能和触发逻辑:
上图里的watchdog_nmi_enable里调用了hardlockup_detector_perf_enable函数
在hardlockup_detector_perf_enable函数里先按照watchdog的阈值watchdog_thresh注册了一个perf的counter超时的perf event(关于perf的原理介绍见之前的博客:perf原理介绍-CSDN博客 ):
上图中的watchdog_overflow_callback是触发counter到期后的回调,我们看一下回调里的实现:
可以从上图中看到了该回调里,检查了是否有hardlockup的情况,如果发现有,则打印检测到的信息及根据配置hardlockup是否触发panic的选项来决定是否触发panic(默认是不触发panic的):
回到hardlockup_detector_perf_enable函数里,在hardlockup_detector_perf_enable里完成了perf event的配置和注册回调后,然后使能了perf的event:
上面讲的是hardlockup的注册和周期检查和触发上报的逻辑,那么具体如何检查和具体如何喂狗的呢?
再次回到watchdog_overflow_callback里的is_hardlockup的实现:
我们从下面的逻辑里可以看到is_hardlockup里是比较的hrtimer_interrupts_saved(也就是上一次hardlockup检查时保存的当时的hrtimer_interrupts的值)和当前的hrtimer_interrupts的值,如果一样,说明hrtimer_interrupts这个per-cpu变量长时间没有更新了:
hrtimer_interrupts的更新是在watchdog_timer_fn里的watchdog_interrupt_count里做的:
而这个timer的启动也是在刚才讲到的watchdog_enable函数里进行设置和启动的:
上图中的sample_period是哪里做初始化的呢?是在下图里的set_sample_period里做的初始化:
关于hardlockup的喂狗周期和检测周期如下图,下图左边是喂狗周期,右边是检测周期,关于右边的检测周期设置有关的逻辑里的hw_nmi_get_sample_period函数其实就是把秒转换成perf里要的cycle单位:
cpu_khz是每秒内有多少个k个tsc clocks,所以要乘上1000转换成
可以看到hardlockup的喂狗周期是watchdog_thresh的2/5,检测周期是watchdog_thresh,关于watchdog_thresh的配置以及其他watchdog的配置见 2.1.2 一节里的介绍
事实上,内核源码里也有关于这个hardlockup和softlockup的中文文档介绍,如下,也印证了我们刚才的分析:
2.1.1.2 softlockup实现介绍
softlockup功能的喂狗逻辑与hardlockup功能里的喂狗逻辑差不多,上面讲到hardlockup功能里的喂狗逻辑是刷新到hrtimer_interrupts这个per-cpu变量里,softlockup功能是的喂狗逻辑是刷新到watchdog_touch_ts这个per-cpu变量里:
这个update_touch_ts函数是在上一节里讲到的hardlockup有关的注册的采样周期回调函数watchdog_timer_fn里注册的以stop调度类优先级进行执行的函数softlockup_fn里:
检查是否发生softlockup也是在上面讲过的watchdog_timer_fn函数里:
上图中框出的is_softlockup的判断,用的touch_ts就是刚才说的以stop调度类(最高优先级)调度的一个任务里去更新的,period_ts则是watchdog_timer_fn函数里同步立马去更新的一个时间戳,如下:
为什么这么判断可以判断出softlockup呢,因为同步的时间戳更新肯定能执行到(在hrtimer的硬中断逻辑里),而以stop调度类优先级来调度执行一个时间戳更新则不一定,会受制于系统preempt_count变量的情况,如果softirq有禁用计数或者抢占关闭有计数,上下文切换的调度都是不能够执行的,关于这块细节可以参考之前的博客 中断上下文及抢占标志位的检查——基于调度及锁举例-CSDN博客 里尤其 2.1.2 一节。
2.1.2 系统watchdog方案如何使用?
关于系统watchdog方案的用户配置这块(我们只罗列关键的几个配置):
在/proc/sys/kernel/下有一些开关和阈值设置的控制节点,可做调整:
打开总开关:
echo 1 > /proc/sys/kernel/watchdog
打开softlockup开关:
echo 1 > /proc/sys/kernel/soft_watchdog
打开hardlockup开关:
echo 1 > /proc/sys/kernel/nmi_watchdog
使能hardlockup视为panic(默认是不视为panic):
echo 1 > /proc/sys/kernel/hardlockup_panic
使能softlockup视为panic(默认是不视为panic):
echo 1 > /proc/sys/kernel/softlockup_panic
设置watchdog的阈值(下面设的10表示10秒,是默认的设置):
echo 10 > /proc/sys/kernel/watchdog_thresh
(默认的10秒对应的hardlockup的阈值是10秒,对应的softlockup的阈值是20秒)
剩余的一些开关和设置这里就不展开一一介绍了,网上也有不少资料可以查阅。
2.1.3 系统watchdog方案的美中不足
美中不足的是,虽然系统默认是打开hardlockup和softlockup的功能的,且我们也可以控制hardlockup和softlockup的阈值,且也可以抓到出现问题后的堆栈,但是其阈值最小的颗粒度是秒,而在我们实时性要求比较高的系统上,如果已经发生了秒级别的硬中断关闭或者软中断关闭,那么系统已经长时间地异常运行了很久了,也应该被视为一个问题来看待和分析其根因。秒单位的检测是远远不够的!
2.2 开源项目trace_irqoff的简介及其美中不足
trace_irqoff是字节跳动的系统团队做的一个开源项目,目的和系统的watchdog方案差不多,但是它并不能检测抢占关闭的情况,它只能检测硬中断关闭和软中断关闭的情况。
关于trace_irqoff的详细介绍包括代码实现细节介绍我们放到后面的博文中阐述,这里就先说一下针对硬中断关闭场景,这个工具使用上的美中不足的点。
由于trace_irqoff对于硬中断场景并没有使用利用nmi中断,所以它很显然并不能在别的核主动地去触发硬中断关闭核上去抓取硬中断关闭核上运行堆栈情况。要注意的是,普通的ipi中断也收到硬中断关闭的管辖,也是不能触发另外一个已经关闭硬中断的核上立马去执行任何操作的。
关于普通ipi的操作顺便提及一下,如果使用ipi中断去试图触发一个硬中断关闭的核上去做一些行为的话,无论发送的ipi中断配的是同步操作还是异步操作,发送ipi中断的核也会因为目标核上硬中断关闭的状态导致发送ipi的核也被block住,就算配置成异步也一样会block住,这也是我们在使用普通ipi中断时要注意的事项。
三、“定制”后的方案及实现细节,以及为什么要这么定制
总结一下,上面提到的两个方案上的美中不足:
1)系统watchdog方案单位是秒,无法满足高实时系统上的监控要求
2)trace_irqoff工具虽然是一个模块,也能控制阈值(单位可以是毫秒),但是不能抓取在硬中断发生期间时的堆栈状态
如果要使用系统watchdog就要修改原生的代码,既然要修改内核部分代码,还不如自己去实现一个模块,这样可以灵活地开关来使用,也可以不用替换内核镜像,方便使用和调试。另外,系统watchdog的抓到的堆栈也是默认达到dmesg里的,有时候对我们定制的一些监控要求来说并没有很方便。
另外一方面,trace_irqoff除去监控时间的颗粒度上有了提升以外(从秒到了毫秒),从功能上算是系统watchdog方案的一个阉割版。对于硬中断关闭的场景下,trace_irqoff并不能抓取到发生硬中断期间的堆栈,而硬中断关闭期间的堆栈的情况(比如采样个几次),对我们分析问题还是有不少帮助的。
接下来讲到的这个定制的方案(本文只涉及硬中断关闭的监控这一单项,其他监控会在后面的文章里逐步分享),从功能原理上来说也是和watchdog的hardlockup一样使用了nmi中断,从功能实现上,我们并没有用perf里的现成的api(上面文章里讲到的perf_event_create_kernel_counter),而是用的x86的底层的发送nmi的接口apic接口来做一个技术上的实验和尝试,当然,也是有依据内核里现成的sample代码。
从另外一个角度来说,自己去完整的实现一个工具,可以非常快速的帮助我们理解里面的细节,尤其api使用上的细节,在实现过程中踩坑时获得成长。
3.1 整体设计思路
刚才也提到,本章只提及硬中断关闭场景的抓取,针对硬中断关闭场景的抓取,我们相比于现有的watchdog方案和trace_irqoff方案要有哪些改进点(这里所谓的“改进”也是特指针对我们实时性要求较高的系统上,比较在意短时间关中断的发生的原因及要捕获到每一次系统异常情况并能抓取当时堆栈情况,这么个大前期的需求下):
1)监控和抓取的颗粒度从watchdog实现的秒改小至毫秒颗粒度
2)通过tracepoint注册sched_stat_runtime和sched_switch的回调,刷新per-cpu的进tracepoint的最新的时间(相当于喂狗)
3)由一个业务不敏感的核(也就是不跑业务,可以跑一些系统监控的核)起一个hrtimer,去定期读取各个cpu更新的进tracepoint的最新的时间(相当于检查喂狗状态),如果监测到异常,则发送nmi中断到嫌疑关硬中断的核上(hrtimer是一个硬中断上下文,可以保证这个上下文内不会发生硬中断打断及任务抢占,确保发送nmi中断的行为是“安全”的)
4)nmi中断的响应函数里,要做double-check,判断当前的preempt_count情况,检查是否有因为spin_lock_irqsave这类的函数导致的硬中断关闭的情况
5)由一个业务不敏感的核去定期做异常状态时的记录(目前为了便捷是直接写的文件)
6)因为监控的颗粒度降至毫秒了,所以再去起毫秒的hrtimer对系统的性能影响过大,所以,就放弃使用hrtimer来确定是否硬中断关闭,改由上面4)里描述的方式来判断
3.2 具体实现细节
我们先讲喂狗的逻辑,再讲如何绑定到一个业务不敏感的核去跑一个周期性的work来监控喂狗状态,然后再讲发送nmi的ipi中断的方法及注意事项,最后再讲疑似硬中断关闭的核上如何响应ipi中断并做double-check再进行抓取堆栈的逻辑
3.2.1 注册sched_stat_runtime和sched_switch的回调,进行喂狗
关于在模块里注册tracepoint的方法在之前多篇博客里有提及,见 内核tracepoint的注册回调及添加的方法_tracepoint 自定义回调-CSDN博客 和 内核模块注册调度的tracepoint的回调,逻辑里判断当前线程处于内核态还是用户态的方法-CSDN博客
这里,我们直接看回调逻辑怎么写的:
上图中的tplastenter_timens就是进行喂狗,更新的最新的进入tracepoint函数的mono时间。
osmon_check_update_items_per_cpu的逻辑这里就不展开了,其实如果走进这个stat_runtime的回调函数里,就说明硬中断并没有关闭,或者刚被打开了,所以,要检查是否刚才发生了硬中断的状态,并把硬中断关闭状态下的抓取的堆栈内容和其他信息都flush给事件消费者那里
3.2.2 创建绑核的hrtimer来定期检查喂狗状态
要创建绑核的hrtimer需要使用smp_call_function_single来派发ipi任务:
下图中的HRTIMER_MODE_PINNED表示绑核,nr_cpu_ids - 1表示绑定在最后一个cpu上
派发的ipi任务的执行函数是smp_hrtimer_start:
接下来,我们来看喂狗逻辑:
喂狗逻辑是hrtimer的回调函数里,在初始化hrtimer时指定这个function:
下图中的红色框框是检查是否长时间没有喂狗:
但是要注意排除掉检查的核上并没有任何任务要跑,也就是sched_switch切换到pid是0的swapper线程后的状态:
上图中的currpid是在sched_switch的回调函数里更新:
最后要记得重启hrtimer,实现周期性的检查:
3.2.3 发现嫌疑的关硬中断的核后,发送nmi的ipi,及nmi发送的注意事项
上一节中,我们讲到我们是在hrtimer里进行喂狗检查的,检查完我们可以直接在hrtimer里进行nmi的ipi发送(不会发送本核,是最后一个cpu上做的检查,只检查前面的cpu不检查自己),这样上下文是安全的不会被打断和抢占破坏。发送的逻辑如下:
我们是通过apic的这一层底层的ipi发送的接口进行的nmi的发送,标记成NMI_VECTOR也就是发送的是nmi的ipi
其实上面这个发送的逻辑是参考的nmi_selftest.c里的逻辑:
注册nmi回调的逻辑,用NMI_LOCK标志位,设置NMI_FLAG_FIRST:
设置NMI_FLAG_FIRST是为了让触发的nmi回调可以优先走到我们注册的回调函数里,这样,我们可以先判断是否是自己发送的nmi中断,如果是的话,可以返回NMI_HANDLED来告诉系统,该nmi已经被成功处理了(表示认领了):
否则如果没人认领nmi的话,系统会有错误提示:
另外,我们从逻辑上确保了,发送给同一个核的nmi的ipi是周期性的,不会短时间内发送多次,另外,我们用了一个变量nmi_count来标记是否我们进行了发送,在处理完后进行了标记清除,如下红色框出的逻辑:
另外,发送nmi用到了特殊寄存器,这涉及到了内存屏障的使用细节上,详细可以参考之前的博客 循环内的会被其他核修改的变量需要使用volatile的例子说明,及内存屏障的原理及使用-CSDN博客里的 3.1 一节。我们逻辑上需要写保序,保序内容范围由于包含了特殊寄存器,所以,需要使用wmb这个内存屏障宏,当然,在arm64架构上,我们还可以把wmb优化到更加细颗粒度的影响上(wmb这个内存屏障宏,因为arm64下wmb是dsb(st)保序角色范围是full system,这个场景下保序角色范围是cpu和cpu之间,不需要是full system,所以,可以在arm64上改成dsb(ishst),这一块会在后面的博客中详细介绍)。
回到这边,我们现在实验的平台是x86,所以也只有用wmb()对应的sfence作为内存屏障:
还有一个发送nmi的ipi要注意的事项就是ipi的嵌套发送,或者说比如在kworker线程上下文里发送ipi时,被中断打算,而在中断的逻辑里再次执行ipi发送,也就是发送ipi逻辑上嵌套了,这会导致系统无响应卡死,但是不触发panic。
3.2.4 疑似关硬中断的核上响应该ipi中断,做double-check再抓取堆栈
我们看一下我们注册的nmi的回调函数里的逻辑:
上图中红色框出的内容也就是double-check的第一个部分,检查当前是否核是空闲的,因为,如果核是空闲的,自然就不会调用到sched_stat_runtime和sched_switch的逻辑里。
double-check逻辑里的第二个部分就是下图里的获取当前核心的preempt_count相关状态,并做检查:
关于preempt_count相关状态见之前的博客 中断上下文及抢占标志位的检查——基于调度及锁举例-CSDN博客,里面有非常详细的介绍,还模拟了关硬中断锁的例子。这里,我们复用了这篇博客里的获取标志位的函数get_preempt_count_items_and_hardirqoff。
在上图中的第二函数osmon_check_update_hardirqoff里,有下面的逻辑:
就是判断preempt_count的低位来得知是否进行了如spin_lock_irqsave函数类似的关了硬中断和抢占,如果发现关了抢占,配合上当前sched_stat_runtime和sched_switch两个tracepoint回调函数长时间没有进来的状态以及当前核没有空闲这些综合因素,就能基本确定是关了硬中断的状态了。其实,我们要抓的主要场景也就是调用spin_lock_irqsave等类似锁后执行很长时间的逻辑再unlock,这样的长时间保持关硬中断状态的行为。
抓取堆栈使用下图中的stack_trace_save即可:
3.2.5 创建绑核的work任务来定期记录异常状态及异常状态时的堆栈
目前我是为了图方便,直接在发生问题时做写文件记录,并没有去做上传给用户态处理的逻辑。
要创建一个work的同时还得创建一个workqueue,用来派发这个work,下面是变量定义的逻辑:
下图是workqueue和work的初始化逻辑,分配一个workqueue出来,再把初始化延迟任务设置该work的执行函数:
最后用刚创建出来workqueue派发这个延迟任务,使用queue_delayed_work_on指定要运行的cpu(nr_cpu_ids - 1表示的是要运行在最后一个核心上),下图中框出的3表示3个tick,如果HZ是250的话,也就是12ms,表示该延迟任务的延迟时间是12ms。
下图里work指定的执行函数write_file里,处理完任务后,再次借助workqueue派发该延迟任务,最后一个参数是1,表示延迟的是4ms(HZ是250时),这样来实现周期性的work逻辑。
关于写文件的逻辑也比较基础和琐碎,这里就不展开了。
3.3 实验验证
验证的方式是先insmod该抓硬中断关闭状态的ko,再insmod一个测试的ko,ko里的逻辑就是调用spin_lock_irqsave函数,执行下面的操作,持续10秒后,再unlock:
上图红色框出的部分,是为了模拟spin_lock里的逻辑比较复杂的情况,让抓到的堆栈发生变动。
从下图中可以看到,抓取的时间每2ms一次,能显示出当时的preempt_count状态,下图中preempt_count_low_bits_dec_tp表示的是去除tracepoint回调函数本身上下文环境所有增加的preempt_count计数,但是在这个发送nmi ipi到目标核上进行nmi_handler这个场景下,并不需要扣除tracepoint回调的上下文环境增加的preempt_count计数
从下图中可以看到,抓取到的堆栈是有动的: