Kernel trace tools（一）：中断和软中断关闭时间过长问题追踪，android系统工程师面试

• local_bh_enable()

• ksoftirqd 进程

当中断返回时会检查 softirq pending，这是大部分执行 softirq 的场景，由于中断的特殊性，在 timer handle 里面记录当前 CPU 的栈是有效的。local_bh_enable()的情况上面已经讨论，可以抓住元凶。但是第 3 种情况下，却不能。这是为什么呢？我们是在 timer handle 里面记录堆栈信息，如果 irq_exit 时 softirq 执行时间过长，会被安排到 ksoftirqd 进程执行。那我们记录的栈信息是什么？仅仅是 ksoftirqd 进程的栈，ksoftirq 并不是元凶。记录是没有用的。所以针对 ksoftirqd 执行的场景，我们需要特殊的处理。我们借助 hrtimer handle。hrtimer 除了测量两次 hardirq 间隔外，还测量 softirq 多长时间没有执行，在合适的时候记录栈。hrtimer 执行的时候，顺便会检测 softirqirq 多长时间没有更新时间戳，如果操作阈值我们也会记录栈信息，这是因为后续如果 softirq 被推迟到 ksoftirqd 进程执行的话，由 softirq 的 timer 记录的栈就没有价值了。

7. 如何安装

========

安装 trace-irqoff 工具很简单，git clone 代码后执行如下命令即可安装。

make -j8

make install

8. 如何使用

========

安装 trace-irqoff 工具成功后。会创建如下 /proc/trace_irqoff 目录。

root@n18-061-206:/proc/trace_irqoff# ls

distribute enable sampling_period trace_latency

/proc/trace_irqoff 目录下存在 4 个文件，分别：distribute, enable, sampling_period 和 trace_latency。工具安装后，默认是关闭状态，我们需要手动打开 trace。

8.1 打开 trace

echo 1 > /proc/trace_irqoff/enable

8.2 关闭 trace

echo 0 > /proc/trace_irqoff/enable

8.3 设置 trace 阈值

trace-irqoff 工具只会针对关闭中断或者软中断时间超过阈值的情况下记录堆栈信息。因此我们可以通过如下命令查看当前 trace 的阈值：

root@n18-061-206:/proc/trace_irqoff# cat /proc/trace_irqoff/trace_latency

trace_irqoff_latency: 50ms

hardirq:

softirq:

默认阈值是 50ms，如第 2 行所示。第 4 行输出 hardirq: 代表下面的栈是可能关闭中断超过阈值的栈。同理，第 6 行是软中断关闭时间超过阈值的栈。如果需要修改阈值至 100ms 可通过如下命令（写入值单位是 ms）：

echo 100 > /proc/trace_irqoff/trace_latency

8.4 清除栈信息

当然如果需要清除 /proc/trace_irqoff 记录的栈信息。可以执行如下命令（不会修改阈值为 0）：

echo 0 > /proc/trace_irqoff/trace_latency

8.5 查看中断关闭次数的统计信息

如果我们需要知道中断被关闭一定的时间的次数，可以通过如下命令获取统计信息：

root@n18-061-206:/proc/trace_irqoff# cat distribute

hardirq-off:

msecs : count distribution

20 -> 39 : 1 |********** |

40 -> 79 : 0 | |

80 -> 159 : 4 |****************************************|

160 -> 319 : 2 |******************** |

320 -> 639 : 1 |********** |

softirq-off:

msecs : count distribution

20 -> 39 : 0 | |

40 -> 79 : 0 | |

80 -> 159 : 0 | |

160 -> 319 : 1 |****************************************|

在这个例子中，我们看到 hardirq 被关闭时间 x ∈ [80, 159] ms，次数 4 次。softirq 被关闭时间 x ∈ [160, 319] ms，次数 1 次 如果没有任何信息输出，这说明没有任何地方关闭中断时间超过 20ms。

8.6 修改采样周期

从上面一节我们可以看到，中断关闭时间分布图最小粒度是 20ms。这是因为采样周期是 10ms。根据采样定理，大于等于 2 倍采样周期时间才能反映真实情况。如果需要提高统计粒度，可修改采样周期时间。例如修改采样周期为 1ms，可执行如下命令（必须在 tracer 关闭的情况下操作有效）：

单位 ms，可设置最小的采样周期是 1ms。

echo 1 > /proc/trace_irqoff/sampling_period

9. 案例分析

========

9.1 hardirq 关闭

我们使用如下示意测试程序，关闭中断 100ms。查看 trace_irqoff 文件内容。

static void disable_hardirq(unsigned long latency)

{

local_irq_disable();

mdelay(latency);

local_irq_enanle();

}

通过模块测试以上代码，然后查看栈信息。

root@n18-061-206:/proc/trace_irqoff# cat trace_latency

trace_irqoff_latency: 50ms

hardirq:

cpu: 17

COMMAND: bash PID: 22840 LATENCY: 107ms

trace_irqoff_hrtimer_handler+0x39/0x99 [trace_irqoff]

__hrtimer_run_queues+0xfa/0x270

hrtimer_interrupt+0x101/0x240

smp_apic_timer_interrupt+0x5e/0x120

apic_timer_interrupt+0xf/0x20

disable_hardirq+0x5b/0x70

proc_reg_write+0x36/0x60

__vfs_write+0x33/0x190

vfs_write+0xb0/0x190

ksys_write+0x52/0xc0

do_syscall_64+0x4f/0xe0

entry_SYSCALL_64_after_hwframe+0x44/0xa9

softirq:

我们可以看到 hardirq 一栏记录 cpu17 执行 bash 命令，关闭中断 107ms（误差 10ms 之内）。其栈信息对应 disable_hardirq() 函数中。第 20 行 softirq 一栏没有信息，说明没有记录 softirq 被关闭的栈。

9.2 softirq 关闭

我们使用如下示意测试程序，关闭 softirq 100ms。查看 trace_irqoff 文件内容。

static void disable_softirq(unsigned long latency)

{

local_bh_disable();

mdelay(latency);

local_bh_enanle();

}

通过模块测试以上代码，然后查看栈信息。

root@n18-061-206:/proc/trace_irqoff# cat trace_latency

trace_irqoff_latency: 50ms

hardirq:

softirq:

cpu: 17

COMMAND: bash PID: 22840 LATENCY: 51+ms

trace_irqoff_hrtimer_handler+0x97/0x99 [trace_irqoff]

__hrtimer_run_queues+0xfa/0x270

hrtimer_interrupt+0x101/0x240

smp_apic_timer_interrupt+0x5e/0x120

apic_timer_interrupt+0xf/0x20

delay_tsc+0x3c/0x50

disable_softirq+0x4b/0x80

proc_reg_write+0x36/0x60

__vfs_write+0x33/0x190

vfs_write+0xb0/0x190

ksys_write+0x52/0xc0

do_syscall_64+0x4f/0xe0

entry_SYSCALL_64_after_hwframe+0x44/0xa9

COMMAND: bash PID: 22840 LATENCY: 106ms

trace_irqoff_timer_handler+0x3a/0x60 [trace_irqoff]

call_timer_fn+0x29/0x120

run_timer_softirq+0x16c/0x400

__do_softirq+0x108/0x2b8

do_softirq_own_stack+0x2a/0x40

do_softirq.part.21+0x56/0x60

__local_bh_enable_ip+0x60/0x70

disable_softirq+0x62/0x80

proc_reg_write+0x36/0x60

__vfs_write+0x33/0x190

vfs_write+0xb0/0x190

ksys_write+0x52/0xc0

do_syscall_64+0x4f/0xe0

entry_SYSCALL_64_after_hwframe+0x44/0xa9

针对 softirq 关闭情况，有 2 个栈与之对应。我们注意到第 9 行的函数名称和第 24 行的函数名称是不一样的。第 9 行的栈是硬件中断 handler 捕捉到软中断关闭，第 24 行是软中断 handler 捕捉到软中断被关闭。正常情况下，我们以 24 行开始的栈为分析目标即可。当 24 行的栈是无效的时候，可以看第 9 行的栈。这里注意：第 9 行的 lantency 提示信息 51+ms 是阈值信息。并非实际 latency（所以我在后面添加一个’+'字符，表示 latency 大于 51ms）。实际的 latency 是第 24 行显示的 106ms。下面就看下为什么 2 个栈是有必要的。

9.3 ksoftirqd 延迟

我们看一个曾经处理的一个实际问题：

root@n115-081-045:/proc/trace_irqoff# cat trace_latency

trace_irqoff_latency: 300ms

hardirq:

softirq:

cpu: 4

COMMAND: lxcfs PID: 4058797 LATENCY: 303+ms

trace_irqoff_record+0x12b/0x1b0 [trace_irqoff]

trace_irqoff_hrtimer_handler+0x97/0x99 [trace_irqoff]

__hrtimer_run_queues+0xdc/0x220

hrtimer_interrupt+0xa6/0x1f0

smp_apic_timer_interrupt+0x62/0x120

apic_timer_interrupt+0x7d/0x90

memcg_sum_events.isra.26+0x3f/0x60

memcg_stat_show+0x323/0x460

seq_read+0x11f/0x3f0

__vfs_read+0x33/0x160

vfs_read+0x91/0x130

SyS_read+0x52/0xc0

do_syscall_64+0x68/0x100

entry_SYSCALL_64_after_hwframe+0x3d/0xa2

COMMAND: ksoftirqd/4 PID: 34 LATENCY: 409ms

trace_irqoff_record+0x12b/0x1b0 [trace_irqoff]

trace_irqoff_timer_handler+0x3a/0x60 [trace_irqoff]

call_timer_fn+0x2e/0x130
自我介绍一下，小编13年上海交大毕业，曾经在小公司待过，也去过华为、OPPO等大厂，18年进入阿里一直到现在。

深知大多数初中级Android工程师，想要提升技能，往往是自己摸索成长或者是报班学习，但对于培训机构动则近万的学费，着实压力不小。自己不成体系的自学效果低效又漫长，而且极易碰到天花板技术停滞不前！

因此收集整理了一份《2024年Android移动开发全套学习资料》，初衷也很简单，就是希望能够帮助到想自学提升又不知道该从何学起的朋友，同时减轻大家的负担。

既有适合小白学习的零基础资料，也有适合3年以上经验的小伙伴深入学习提升的进阶课程，基本涵盖了95%以上Android开发知识点，真正体系化！

由于文件比较大，这里只是将部分目录截图出来，每个节点里面都包含大厂面经、学习笔记、源码讲义、实战项目、讲解视频，并且会持续更新！

如果你觉得这些内容对你有帮助，可以扫码获取！！（备注：Android）

最后

那我们该怎么做才能做到年薪60万+呢，对于程序员来说，只有不断学习，不断提升自己的实力。我之前有篇文章提到过，感兴趣的可以看看，到底要学习哪些知识才能达到年薪60万+。

通过职友集数据可以查看，以北京 Android 相关岗位为例，其中 【20k-30k】 薪酬的 Android 工程师，占到了整体从业者的 30.8%！

北京 Android 工程师「工资收入水平 」

今天重点内容是怎么去学，怎么提高自己的技术。

1.合理安排时间

2.找对好的系统的学习资料

3.有老师带，可以随时解决问题

4.有明确的学习路线

当然图中有什么需要补充的或者是需要改善的，可以在评论区写下来，一起交流学习。

《互联网大厂面试真题解析、进阶开发核心学习笔记、全套讲解视频、实战项目源码讲义》点击传送门即可获取！

那我们该怎么做才能做到年薪60万+呢，对于程序员来说，只有不断学习，不断提升自己的实力。我之前有篇文章提到过，感兴趣的可以看看，到底要学习哪些知识才能达到年薪60万+。

通过职友集数据可以查看，以北京 Android 相关岗位为例，其中 【20k-30k】 薪酬的 Android 工程师，占到了整体从业者的 30.8%！

北京 Android 工程师「工资收入水平 」

[外链图片转存中…(img-tGsaIgn1-1712773938033)]

今天重点内容是怎么去学，怎么提高自己的技术。

1.合理安排时间

2.找对好的系统的学习资料

3.有老师带，可以随时解决问题

4.有明确的学习路线

当然图中有什么需要补充的或者是需要改善的，可以在评论区写下来，一起交流学习。

[外链图片转存中…(img-2ecssihu-1712773938033)]

《互联网大厂面试真题解析、进阶开发核心学习笔记、全套讲解视频、实战项目源码讲义》点击传送门即可获取！