1 dump_stack函数
打印内核调用堆栈。举个例子:
我们定义四个函数aaa
、bbb
、ccc
、ddd
,然后bbb
中调用aaa
,ccc
中调用bbb
,ddd
函数谁都不调用。在入口函数中,我们调用ccc
与ddd
函数,看看堆栈打印效果如何:
#include <linux/module.h>
#include <linux/kernel.h>
#include <linux/init.h>
#include <linux/delay.h>
void aaa(void) {
printk(KERN_EMERG "aaa\n");
dump_stack();
msleep(100);
}
void bbb(void) {
printk(KERN_EMERG "bbb\n");
aaa();
msleep(100);
}
void ccc(void) {
printk(KERN_EMERG "ccc\n");
bbb();
msleep(100);
}
void ddd(void) {
printk(KERN_EMERG "ddd\n");
msleep(100);
}
static int __init chrdevTest_init(void) {
printk(KERN_EMERG "INIT func\r\n");
ccc();
ddd();
return 0;
}
static void __exit chrdevTest_exit(void) {
printk(KERN_EMERG "EXIT func\r\n");
}
module_init(chrdevTest_init);
module_exit(chrdevTest_exit);
MODULE_LICENSE("GPL");
可以看到当打印完aaa
后开始dump_stack
, 打印出函数调用栈。
2 内核态异常call trace等级
内核态call trace 有三种出错情况,分别是bug
, oops
和panic
。
1、 bug
- bug只是提示警告。
BUG: sleeping function called from invalid context at …
, 比如在原子上下文中休眠,总断服务函数休眠,spin_lock中进行might_sleep等。
我在某个设备驱动的中断处理函数 XXX_ISR()
里加了 msleep(10)
之后:
可以看到跑出了BUG打印,为什么是BUG: scheduling while atomic
呢?而不是BUG: sleeping function called from invalid context at …
那是因为在原子上文中发生了调度,我们调用might_sleep是会时间片到了啊,让出CPU自然就进行了schedule。
BUG: spinlock bad magic on CPU
错误表示自旋锁使用时没有初始化。
2、 Oops
- oops会终止进程,但是不会系统崩溃。
程序在内核态进入一种异常情况,比如引用非法指针导致的数据异常,数组越界导致的取指异常,此时异常处理机制能够捕获此异常,并将系统关键信息打印到串口上,正常情况下Oops消息会被记录到系统日志中去。
3、 Panic
-panic系统崩溃。
当Oops发生在中断上下文中或者在进程0和1中,系统将彻底挂起,因为中断服务程序异常后,将无法恢复,这种情况即称为内核panic。
2.1 WARN_ON函数
我们把上面的实验aaa
函数中dump_stack
改成WARN_ON(1)
函数。可以看到WARN_ON(1)
就是调用了dump_stack
,多了绿色打印部分而已:
注意只有当condition=1
时才会真正调用__warn
:
2.2 BUG_ON函数
BUG_ON
这句,一旦执行就会抛出oops
,导致栈的回溯和错误信息的打印,大部分体系结构把BUG()
和BUG_ON()
定义成某种非法操作,这样自然会产生需要的oops。类似一种断言,让进程终止。我们把上面的实验aaa
函数中dump_stack
改成BUG_ON(1)
函数:
2.3 panic函数
当Oops发生在中断上下文中或者在进程0和1中,系统将彻底挂起,因为中断服务程序异常后,将无法恢复,这种情况即称为内核panic
3 Ftrace工具集
Ftrace
是Function Trace
的简写。它是一个内核函数追踪工具,旨在帮助内核设计和开发人员去追踪系统内部的函数调用流程。
还可以用来调试和分析系统的延迟和性能问题,并发展成为一个追踪类调试工具的框架:
可以看到还包括了用户态的ltrace
和ftrace
。
3.1 Ftrace是如何记录信息的
Ftrace
采用了静态插桩和动态插桩两种方式来实现。
3.1.1 静态插桩
Kernel
中打开了CONFIG_FUNCTION_TRACER
功能后,会增加一个-pg
的一个编译选项,这样每个函数入口处,都会插入bl mcount
跳转指令,使得每个函数运行时都会进入mcount
函数。
既然每个函数都静态插桩,这带来的性能开销是惊人的,有可能导致人们弃用Ftrace
功能。为了解决这个问题,开发者推出了Dynamic ftrace
,以此来优化整体的性能。
3.1.2 动态插桩
既然静态插桩记录这些可追踪的函数,为了减少性能消耗,将跳转函数替换为nop
指令,动态将被调试函数的nop
指令,替换为跳转指令,以实现追踪。
3.2 使能Ftrace
CONFIG_FTRACE=y # 启用了 Ftrace
CONFIG_FUNCTION_TRACER=y # 启用函数级别的追踪器
CONFIG_HAVE_FUNCTION_GRAPH_TRACER=y # 表示内核支持图形显示
CONFIG_FUNCTION_GRAPH_TRACER=y # 以图形的方式显示函数追踪过程
CONFIG_STACK_TRACER=y # 启用堆栈追踪器,用于跟踪内核函数调用的堆栈信息。
CONFIG_DYNAMIC_FTRACE=y # 启用动态 Ftrace,允许在运行时启用和禁用 Ftrace 功能。
CONFIG_HAVE_FTRACE_NMI_ENTER=y # 表示内核支持非屏蔽中断(NMI)时进入 Ftrace 的功能
CONFIG_HAVE_FTRACE_MCOUNT_RECORD=y # 表示内核支持通过 mcount 记录函数调用关系。
CONFIG_FTRACE_NMI_ENTER=y # 表示内核支持通过 mcount 记录函数调用关系。
CONFIG_FTRACE_SYSCALLS=y # 系统调用的追踪
CONFIG_FTRACE_MCOUNT_RECORD=y # 启用 mcount 记录函数调用关系。
CONFIG_SCHED_TRACER=y # 支持调度追踪
CONFIG_CONTEXT_SWITCH_TRACER #使能上下文切换追踪功能,可以用来跟踪进程之间的切换。
CONFIG_NOP_TRACER #使能空操作追踪功能,可以用来在不需要追踪的情况下占位。
CONFIG_FUNCTION_PROFILER=y # 启用函数分析器,主要用于记录函数的执行时间和调用次数
CONFIG_DEBUG_FS=y # 启用 Debug 文件系统支持
上述配置不一定全部打开,勾选自己需要的即可,通常我们选择CONFIG_FUNCTION_TRACER
和CONFIG_HAVE_FUNCTION_GRAPH_TRACER
即可,然后编译烧录到开发板。
通过make menuconfig
的方式写入:
Kernel hacking --->
Tracers ─>
[*] Kernel Function Tracer
[*] Kernel Function Graph Tracer (NEW)
// (下面还有几个追踪器的选项,可以根据自己的需要选择)
Ftrace
通过 debugfs
向用户态提供了访问接口,所以还需要将 debugfs
编译进内核:
Kernel hacking --->
-*- Debug Filesystem
3.2.1 挂载debugfs
#用户态需要挂载debugfs,or通过配置修改etc/fstab文件
mount -t debugfs none /sys/kernel/debug
或者 mount -t tracefs nodev /sys/kernel/tracing
我们能够在/sys/kernel/debug
下看到内核支持的所有的调试信息:
# cd /sys/kernel/debug/
# ls
asoc gpio regmap
bdi ieee80211 sched_debug
block memblock sched_features
clk mmc0 sleep_time
device_component mmc1 suspend_stats
devices_deferred mtd tracing
dma_buf opp ubi
extfrag pinctrl ubifs
fault_around_bytes pm_qos wakeup_sources
3.3 Ftrace 使用
3.3.1 /sys/kernel/tracing介绍
3.3.2 trace和trace_pipe使用
cat trace_pipe
是堵塞读取,有数据就读,没数据就等待。
打开关闭追踪:
echo 1 > tracing_on // 打开跟踪
do_someting
echo 0 > tracing_on // 关闭跟踪
cat trace > /tmp/log //一次性导出log
cat trace_pipe > /tmp/log &//后台导出log
cat current_tracer // 查看当前追踪器
cat available_tracers // 查看当前内核中可用跟踪器
cat available_events // 查看当前内核中可用事件
cat available_filter_functions
// 查看当前内核中可用函数,可以被追踪的函数列表,
// 即可以写到 set_ftrace_filter,set_ftrace_notrace,set_graph_function,
// set_graph_notrace 文件的函数列表
echo function > current_tracer // 选用 function 追踪器,
echo function_graph > current_tracer // 选用 function_graph 追踪器,
echo [func] > set_ftrace_filter // 选择追踪指定 [func] 函数的调用栈
echo [pid] > set_ftrace_pid // 选择追踪指定 [pid] 进程的调用栈
3.3.2.1 选用函数追踪
3.3.2.2 选用图像化函数追踪
3.3.2.3 选用动态过滤追踪
3.3.2.4 追踪特定进程
echo 0 > tracing_on # 关闭追踪器
echo function > current_tracer # 设置当前追踪类别
echo > trace; echo $$ > set_ftrace_pid; echo 1 > tracing_on; your_command; echo 0 > tracing_on
$$
表示当前bash的pid,这样可以追踪任意命令。
如果我们要抓执行a.out
的trace信息,那么先要获取到a.out
程序的pid。
为什么要写成一条语句?
因为ftrace
当打开时,在没有过滤的情况下,瞬间会抓取到内核所有的函数调用,为了更准确的抓取我们执行的命令,所以需要打开trace
,执行完命令后,马上关闭。
3.3.2.5 追踪特定函数
echo 1 > options/func_stack_trace
echo 0 > tracing_on # 关闭追踪器
cat available_filter_functions | grep "xxxxxx" # 搜索函数是否存在
echo xxxxxx > set_ftrace_filter # 设定追踪的函数
echo function > current_tracer # 设置当前追踪类别
echo 1 > options/func_stack_trace # 记录堆栈信息
echo > trace # 清空缓存
echo 1 > tracing_on
查看结果:
# cat trace
# tracer: function
#
# entries-in-buffer/entries-written: 2/2 #P:3
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
kworker/1:1-59 [001] .... 168.954199: mmc_rescan <-process_one_work
kworker/1:1-59 [001] .... 168.954248: <stack trace>
=> mmc_rescan
=> process_one_work
=> worker_thread
=> kthread
=> ret_from_fork
=> 0
3.3.2.6 追踪特定ko模块
编译ko需要加上编译参数-pg
。否则你在available_filter_functions
列表中,查找不到你想要的函数。
# 示例
Format: :mod:<module-name>
example: echo :mod:ext3 > set_ftrace_filter
追踪ext3
模块内的所有函数。
3.3.2.7 重置追踪
echo 0 > tracing_on # 关闭trace
echo > trace # 清空当前trace记录
3.3.2.8 事件追踪
查看事件:
root@100ask:/sys/kernel/debug/tracing/events# ls
alarmtimer exceptions i2c migrate power signal
block ext4 initcall mmc printk skb
enable hyperv mdio percpu
root@100ask:/sys/kernel/debug/tracing/events/sched# ls
enable sched_move_numa sched_process_free sched_stat_runtime sched_switch
filter sched_pi_setprio sched_process_hang sched_stat_sleep
sched_kthread_stop sched_process_exec sched_process_wait sched_stat_wait
追踪一个/若干事件:
# echo 1 > events/sched/sched_wakeup/enable
...(省略追踪过程)
# cat trace | head -10
# tracer: nop
#TASK-PID CPU# TIMESTAMP FUNCTION
# || | |
bash-2613 [001] 425.078164: sched_wakeup: task bash:2613 [120] success=0 [001]
bash-2613 [001] 425.078184: sched_wakeup: task bash:2613 [120] success=0 [001]
追踪所有事件:
# echo 1 > events/enable
...
# cat trace | head -10
# tracer: nop
#TASK-PID CPU# TIMESTAMP FUNCTION
# | | | |
cpid-1470 [001] 794.947181: kfree: call_site=ffffffff810c996d ptr=(null)
acpid-1470 [001] 794.947182: sys_read -> 0x1
3.3.2.n trace_printk函数使用
内核头文件 include/linux/kernel.h
中描述了 ftrace
提供的工具函数的原型,这些函数包括 trace_printk
、tracing_on
/tracing_off
等。