观察Linux内核中的变量(内存地址)变化,更改时打印堆栈跟踪? [英] Watch a variable (memory address) change in Linux kernel, and print stack trace when it changes?

查看:1162
本文介绍了观察Linux内核中的变量(内存地址)变化,更改时打印堆栈跟踪?的处理方法,对大家解决问题具有一定的参考价值,需要的朋友们下面随着小编来一起学习吧!

问题描述

我想以某种方式在Linux内核(一个内核模块/驱动程序中)看一个变量(或内存地址),确切地说)并找出改变了什么 - 基本上,当变量改变时打印出一个堆栈跟踪。



例如,在 testjiffy-hr.c ://stackoverflow.com/questions/16920238/reliability-of-linux-kernel-add-timer-at-resolution-of-one-jiffy/17055867#17055867>这个答案,我想打印每次 runco​​unt 变量更改时,输出堆栈跟踪;希望堆栈跟踪会包含一个提到 testjiffy_timer_function ,这实际上是改变该变量的函数。



现在,我知道我可以使用 kgdb 连接到一个虚拟机上运行的调试Linux内核,甚至设置断点(所以希望也是观察点),但问题是我实际上想调试一个ALSA驱动程序,特别是播放 dma_area buffer(where I '得到一些意想不到的数据) - 这对时间非常敏感;并且本身运行调试内核会弄乱时序(更不用说在虚拟机中运行它)。



这里的一个更大的问题是播放 dma_area 指针只存在于播放操作(或换句话说,$ _start _stop 处理程序之间) - 所以我必须记录 dma_area 地址在每个 _start 回调,然后以某种方式调度它在播放操作期间观看。



所以我希望有一种方法可以直接在驱动程序代码中做这样的事情,如在这个 _start 回调,它记录 dma_area 指针,并将其用作启动观察更改的命令的参数;堆栈跟踪从相应的回调函数打印出来。 (我知道这也会影响到时间,但我希望这样轻就不会影响现场驾驶员的操作。



所以我的问题是:这样一种在Linux内核中调试的技术是否存在?



如果没有:是否可以设置硬件(或软件)中断,对特定内存地址的更改做出反应?那么我可以设置这样一个中断处理程序,可以打印出一个堆栈跟踪吗? (尽管如此,我认为,当IRQ处理程序运行时,整个环境都会发生变化,所以也许得到堆栈跟踪会出现错误)?



如果没有:还有其他的技术,这将允许我打印一个进程的堆栈跟踪,改变存储在内核中给定内存位置的值(希望在一个实时的,非调试内核中)的值?

解决方案

非常感谢 @CosminRatiu Eugene ;感谢那些,我发现:





...我可以用它来开发我在这里发布的示例, testhrarr.c 内核模块/驱动程序和 Makefile (下)。它表明硬件观察点跟踪可以通过两种方式实现:使用 perf 程序,可以不改变驱动程序;或通过向驱动程序添加一些硬件断点代码(在示例中,由 HWDEBUG_STACK 定义变量包围)。



本质上,调试标准原子变量类型(如int)(如 runco​​unt 变量)的内容很简单,因为它们被定义为内核模块中的全局变量,所以它们最终在全局显示为内核符号。因此,下面的代码将$ code> testhrarr _ 作为前缀添加到变量中(以避免命名冲突)。但是,由于需要取消引用,调试数组的内容可能会更棘手,所以这个帖子演示的是调试 testhrarr_arr 数组的第一个字节。这是在:

  $ echo`cat / etc / lsb-release` 
DISTRIB_ID = Ubuntu DISTRIB_RELEASE = 11.04 DISTRIB_CODENAME = natty DISTRIB_DESCRIPTION =Ubuntu 11.04
$ uname -a
Linux mypc 2.6.38-16-generic#67-Ubuntu SMP Thu Sep 6 18:00:43 UTC 2012 i686 i686 i386 GNU / Linux
$ cat / proc / cpuinfo | grep型号名称
型号名称:Intel(R)Atom(TM)CPU N450 @ 1.66GHz
型号名称:Intel(R)Atom(TM)CPU N450 @ 1.66GHz

模块初始化时, testhrarr 模块基本上为小数组分配内存,设置一个定时器函数,并公开一个 / proc / testhrarr_proc 文件(使用较新的 proc_create 接口)。然后,尝试从 / proc / testhrarr_proc 文件中读取(例如使用 cat )将触发定时器功能,这将修改 testhrarr_arr 数组值,并将消息转储到 / var / log / syslog 。我们期望在操作过程中, testhrarr_arr [0] 会改变三次;一次在 testhrarr_startup 中,两次在 testhrarr_timer_function (由于包装)。



使用 perf



make ,可以加载:

  sudo insmod ./testhrarr在这一点上, / var / log / syslog 将包含:

 内核:[40277.199913] Init testhrarr:0; HZ:250; 1 / HZ(ms):4; hrres:0.000000001 
kernel:[40277.199930]地址:_runco​​unt 0xf84be22c; _arr 0xf84be2a0; _arr [0] 0xed182a80(0xed182a80); _timer_function 0xf84bc1c3; my_hrtimer 0xf84be260; my_hrt.f 0xf84be27c
内核:[40277.220329]安装testhrarr_arr写入硬件断点(0xf84be2a0)

请注意,刚刚通过 testhrarr_arr 作为硬件观察点的符号扫描该变量的地址( 0xf84be2a0 ),而不是地址的数组的第一个元素( 0xed182a80 )!因此,硬件断点不会触发 - 所以行为就好像硬件断点代码根本不存在(可以通过定义 HWDEBUG_STACK来实现) )!



所以,即使没有通过内核模块代码设置硬件断点,我们仍然可以使用 perf 观察更改内存地址 - 在 perf 中,我们同时指定要观看的地址(这里是第一个元素的地址 testhrarr_arr 0xed182a80 )以及应该运行的进程:这里我们运行 bash ,所以我们可以执行一个 cat / proc / testhrarr_proc ,这将触发内核模块计时器,其次是一个 sleep 0.5 这将允许定时器完成。还需要 -a 参数,否则可能会丢失一些事件:

  $ sudo perf record -a --call-graph --event = mem:0xed182a80:w bash -c'cat / proc / testhrarr_proc;睡眠0.5'
testhrarr proc:startup
[perf记录:唤醒1次写入数据]
[perf记录:捕获并写入0.485 MB perf.data(〜21172个样本)]

此时, / var / log / syslog 还将包含以下内容:

  
[40822.114964] testhrarr_timer_function:testhrarr_runco​​unt 0
[40822.114980] testhrarr jiffies 10130528; ret:1; ktnsec:40822114975062
[40822.118956] testhrarr_timer_function:testhrarr_runco​​unt 1
[40822.118977] testhrarr jiffies 10130529; ret:1; ktnsec:40822118973195
[40822.122940] testhrarr_timer_function:testhrarr_runco​​unt 2
[40822.122956] testhrarr jiffies 10130530; ret:1; ktnsec:40822122951143
[40822.126962] testhrarr_timer_function:testhrarr_runco​​unt 3
[40822.126978] testhrarr jiffies 10130531; ret:1; ktnsec:40822126973583
[40822.130941] testhrarr_timer_function:testhrarr_runco​​unt 4
[40822.130961] testhrarr jiffies 10130532; ret:1; ktnsec:40822130955167
[40822.134940] testhrarr_timer_function:testhrarr_runco​​unt 5
[40822.134962] testhrarr jiffies 10130533; ret:1; ktnsec:40822134958888
[40822.138936] testhrarr_timer_function:testhrarr_runco​​unt 6
[40822.138958] testhrarr jiffies 10130534; ret:1; ktnsec:40822138955693
[40822.142940] testhrarr_timer_function:testhrarr_runco​​unt 7
[40822.142962] testhrarr jiffies 10130535; ret:1; ktnsec:40822142959345
[40822.146936] testhrarr_timer_function:testhrarr_runco​​unt 8
[40822.146957] testhrarr jiffies 10130536; ret:1; ktnsec:40822146954479
[40822.150949] testhrarr_timer_function:testhrarr_runco​​unt 9
[40822.150970] testhrarr jiffies 10130537; ret:1; ktnsec:40822150963438
[40822.154974] testhrarr_timer_function:testhrarr_runco​​unt 10
[40822.154988] testhrarr [5,7,9,11,13,]

要阅读 perf (一个名为 perf.data 的文件)的捕获,我们可以使用:

 $ sudo perf report --call-graph flat --stdio 
没有kallsyms或vmlinux与build-id 5031df4d8668bcc45a7bdb4023909c6f8e2d3d34被发现
[testhrarr]与构建代码5031df4d8668bcc45a7bdb4023909c6f8e2d3d34未找到,继续没有符号
无法打开/ bin / cat,继续没有符号
无法打开/ usr / lib / libpixman-1 .so.0.20.2,无符号继续
无法打开/usr/lib/xorg/modules/drivers/intel_drv.so,无符号继续
无法打开/ usr / bin / Xorg,继续没有符号
#事件:5未知

#开销命令共享对象符号
#........ ....... .... ......... ................ ....................

87.50%Xorg [testhrarr] [k] testhrarr_timer_function
87.50%
testhrarr_timer_function
__run_hrtimer
hrtimer_interrupt
smp_apic_timer_interrupt
apic_timer_interrupt
0x30185d
0x2ed701
0x2ed8cc
0x2edba0
0x9d0386
0x8126fc8
0x81217a1
0x811bdd3
0x8070aa7
0x806281c
__libc_start_main
0x8062411

6.25%cat [testhrarr] [k] testhrarr_timer_function
6.25%
testhrarr_timer_function
testhrarr_proc_show
seq_read
proc_reg_read
vfs_read
sys_read
syscall_call
0xaa2416
0x8049f4d
__libc_start_main
0x8049081

3.12%swapper [testhrarr] [k] testhrarr_timer_function
3.12%
testhrarr_timer_function
__run_hrtimer
hrtimer_interrupt
smp_apic_timer_interrupt
apic_timer_interrupt
cpuidle_idle_call
cpu_idle
start_secondary

3.12% cat [testhrarr] [k] 0x356
3.12%
0xf84bc356
0xf84bc3a7
seq_read
proc_reg_read
vfs_read
sys_read
syscall_call
0xaa2416
0x8049f4d
__libc_start_ma在
0x8049081




#(对于更高级别的概述,请尝试:perf report --sort comm,dso)

所以,因为我们正在使用调试来构建内核模块( -g Makefile 中),对于 perf 找不到此模块的符号不是问题,即使实时内核不是调试内核。所以它大部分时间正确地将 testhrarr_timer_function 解释为设置器,尽管它不报告 testhrarr_startup (但它是报告 testhrarr_proc_show 调用它)。还有对 0xf84bc3a7 0xf84bc356 的引用,它无法解决;但是,请注意,模块加载到 0xf84bc000

  $ sudo cat / proc / modules | grep testhr 
testhrarr 13433 0 - Live 0xf84bc000

...该条目也从 ... [k] 0x356 ;如果我们查看内核模块的 objdump

 $ objdump -S testhrarr.ko |少
...
00000323:

static void testhrarr_startup(void)
{
...
testhrarr_arr [0 ] = 0; //只是第一个元素
34b:a1 80 00 00 00 mov 0x80,%eax
350:c7 00 00 00 00 00 movl $ 0x0,(%eax)
hrtimer_start(&my_hrtimer, ktime_period_ns,HRTIMER_MODE_REL);
356:c7 04 24 01 00 00 00 movl $ 0x1,(%esp)**********
35d:8b 15 1c 00 00 00 mov 0x1c,%edx
...
00000375:


static int testhrarr_proc_show(struct seq_file * m,void * v){
...
seq_printf m,testhrarr proc:startup\\\
);
38f:c7 44 24 04 79 00 00 movl $ 0x79,0x4(%esp)
396:00
397:8b 45 fc mov -0x4(%ebp),%eax
39a:89 04 24 mov%eax,(%esp)
39d:e8 fc ff ff ff call 39e
testhrarr_startup();
3a2:e8 7c ff ff ff call 323
3a7:eb 1c jmp 3c5 **********
} else {
seq_printf(m,testhrarr proc:(正在运行,%d)\\\
,testhrarr_runco​​unt);
3a9:a1 0c 00 00 00 mov 0xc,%eax
...

。 ..所以 0xf84bc356 显然是指 hrtimer_start ;和 0xf84bc3a7 - > 3a7 指的是调用 testhrarr_proc_show 函数;感谢这是有道理的。 (请注意,我经历了不同版本的驱动程序, _start 可以显示,而$ code> timer_function 用绝对的地址表达;不知道这是什么原因)。



尽管如此, perf 的一个问题是,它给出了这些功能发生的统计开销不知道这是什么 - 可能是在函数的进入和退出之间花费的时间?) - 但是我想要的是一个堆栈跟踪的日志,它是顺序的。不知道如果 perf 可以设置为 - 但是它绝对是用于硬件断点的内核模块代码。



使用内核模块HW断点



HWDEBUG_STACK 实现HW断点的设置和处理。如上所述,为 ksym_name (如果未指定)设置的默认值为 testhrarr_arr ,不触发硬件断点。可以在 insmod 中的命令行中指定 ksym_name 参数;这里我们可以注意到:

  $ sudo rmmod testhrarr#remove module if still loaded 
$ sudo insmod ./testhrarr .ko ksym = testhrarr_arr [0]

...结果与 HW / var / log / syslog 中的testhrarr_arr [0]写入断点(0x(null)); - 这意味着我们不能使用带有符号的符号进行数组访问;幸运的是,这里的一个空指针只是意味着HW断点再次不会触发;它完全不会使操作系统崩溃:)



然而,有一个全局变量指向 testhrarr_arr 数组的第一个元素,称为 testhrarr_arr_first - 注意这个全局变量是如何在代码中特别处理的,需要取消引用,以便获得正确的地址。所以我们做:

  $ sudo rmmod testhrarr#remove module if still loaded 
$ sudo insmod ./testhrarr.ko ksym = testhrarr_arr_first

...和syslog通知:

  kernel:[43910.509726] Init testhrarr:0; HZ:250; 1 / HZ(ms):4; hrres:0.000000001 
kernel:[43910.509765]地址:_runco​​unt 0xf84be22c; _arr 0xf84be2a0; _arr [0] 0xedf6c5c0(0xedf6c5c0); _timer_function 0xf84bc1c3; my_hrtimer 0xf84be260; my_hrt.f 0xf84be27c
内核:[43910.538535]安装testhrarr_arr_first写入硬件断点(0xedf6c5c0)

...我们可以看到HW断点设置为 0xedf6c5c0 ,这是 testhrarr_arr [0] 。现在,如果我们通过 / proc 文件触发驱动程序:

  $ cat / proc / testhrarr_proc 
testhrarr proc:startup

...我们以code> syslog

 内核:[44069.735695] testhrarr_arr_first值更改
[44069.735711] Pid:29320,comm:cat没有污点2.6.38-16-generic#67-Ubuntu
[44069.735719] Call Trace:
[44069.735737] []? sample_hbp_handler + 0x2d / 0x3b [testhrarr]
[44069.735755] []? __perf_event_overflow + 0x90 / 0x240
[44069.735768] []? proc_alloc_inode + 0x23 / 0x90
[44069.735778] []? proc_alloc_inode + 0x23 / 0x90
[44069.735790] []? perf_swevent_event + 0x136 / 0x140
[44069.735801] []? perf_bp_event + 0x70 / 0x80
[44069.735812] []? prep_new_page + 0x110 / 0x1a0
[44069.735824] []? get_page_from_freelist + 0x12e / 0x320
[44069.735836] []? seq_open + 0x3d / 0xa0
[44069.735848] []? hw_breakpoint_handler.clone.0 + 0x102 / 0x130
[44069.735861] []? hw_breakpoint_exceptions_notify + 0x22 / 0x30
[44069.735872] []? notifier_call_chain + 0x45 / 0x60
[44069.735883] []? atomic_notifier_call_chain + 0x22 / 0x30
[44069.735894] []? notify_die + 0x2d / 0x30
[44069.735904] []? do_debug + 0x88 / 0x180
[44069.735915] []? debug_stack_correct + 0x30 / 0x38
[44069.735928] []? testhrarr_startup + 0x33 / 0x52 [testhrarr]
[44069.735940] []? testhrarr_proc_show + 0x32 / 0x57 [testhrarr]
[44069.735952] []? seq_read + 0x145 / 0x390
[44069.735963] []? seq_read + 0x0 / 0x390
[44069.735973] []? proc_reg_read + 0x64 / 0xa0
[44069.735985] []? vfs_read + 0x9f / 0x160
[44069.735995] []? proc_reg_read + 0x0 / 0xa0
[44069.736003] []? sys_read + 0x42 / 0x70
[44069.736013] []? syscall_call + 0x7 / 0xb
[44069.736019]从sample_hbp_handler转储栈
[44069.740132] testhrarr_timer_function:testhrarr_runco​​unt 0
[44069.740146] testhrarr jiffies 10942435; ret:1; ktnsec:44069740142485
[44069.740159] testhrarr_arr_first值更改
[44069.740169] Pid:4302,comm:gnome-terminal没有污点2.6.38-16-generic#67-Ubuntu
[44069.740176]通话追踪:
[44069.740195] []? sample_hbp_handler + 0x2d / 0x3b [testhrarr]
[44069.740213] []? __perf_event_overflow + 0x90 / 0x240
[44069.740227] []? perf_swevent_event + 0x136 / 0x140
[44069.740239] []? perf_bp_event + 0x70 / 0x80
[44069.740253] []? sched_clock_local + 0xd3 / 0x1c0
[44069.740267] []? format_decode + 0x323 / 0x380
[44069.740280] []? hw_breakpoint_handler.clone.0 + 0x102 / 0x130
[44069.740292] []? hw_breakpoint_exceptions_notify + 0x22 / 0x30
[44069.740302] []? notifier_call_chain + 0x45 / 0x60
[44069.740313] []? atomic_notifier_call_chain + 0x22 / 0x30
[44069.740324] []? notify_die + 0x2d / 0x30
[44069.740335] []? do_debug + 0x88 / 0x180
[44069.740345] []? debug_stack_correct + 0x30 / 0x38
[44069.740364] []? init_intel_cacheinfo + 0x103 / 0x394
[44069.740379] []? testhrarr_timer_function + 0xed / 0x160 [testhrarr]
[44069.740391] []? __run_hrtimer + 0x6f / 0x190
[44069.740404] []? testhrarr_timer_function + 0x0 / 0x160 [testhrarr]
[44069.740416] []? hrtimer_interrupt + 0x108 / 0x240
[44069.740430] []? smp_apic_timer_interrupt + 0x56 / 0x8a
[44069.740441] []? apic_timer_interrupt + 0x31 / 0x38
[44069.740453] []? _raw_spin_unlock_irqrestore + 0x15 / 0x20
[44069.740465] []? try_to_del_timer_sync + 0x67 / 0xb0
[44069.740476] []? del_timer_sync + 0x29 / 0x50
[44069.740486] []? flush_delayed_work + 0x13 / 0x40
[44069.740500] []? tty_flush_to_ldisc + 0x12 / 0x20
[44069.740510] []? n_tty_poll + 0x4f / 0x190
[44069.740523] []? tty_poll + 0x6d / 0x90
[44069.740531] []? n_tty_poll + 0x0 / 0x190
[44069.740542] []? do_poll.clone.3 + 0xd0 / 0x210
[44069.740553] []? do_sys_poll + 0x134 / 0x1e0
[44069.740563] []? __pollwait + 0x0 / 0xd0
[44069.740572] []? pollwake + 0x0 / 0x60
...
[44069.740742] []? pollwake + 0x0 / 0x60
[44069.740757] []? rw_verify_area + 0x6c / 0x130
[44069.740770] []? ktime_get_ts + 0xf8 / 0x120
[44069.740781] []? poll_select_set_timeout + 0x64 / 0x70
[44069.740793] []? sys_poll + 0x5a / 0xd0
[44069.740804] []? syscall_call + 0x7 / 0xb
[44069.740815] []? init_intel_cacheinfo + 0x23 / 0x394
[44069.740822]从sample_hbp_handler转储栈
[44069.744130] testhrarr_timer_function:testhrarr_runco​​unt 1
[44069.744143] testhrarr jiffies 10942436; ret:1; ktnsec:44069744140055
[44069.748132] testhrarr_timer_function:testhrarr_runco​​unt 2
[44069.748145] testhrarr jiffies 10942437; ret:1; ktnsec:44069748141271
[44069.752131] testhrarr_timer_function:testhrarr_runco​​unt 3
[44069.752145] testhrarr jiffies 10942438; ret:1; ktnsec:44069752141164
[44069.756131] testhrarr_timer_function:testhrarr_runco​​unt 4
[44069.756141] testhrarr jiffies 10942439; ret:1; ktnsec:44069756138318
[44069.760130] testhrarr_timer_function:testhrarr_runco​​unt 5
[44069.760141] testhrarr jiffies 10942440; ret:1; ktnsec:44069760138469
[44069.760154] testhrarr_arr_first值更改
[44069.760164] Pid:4302,comm:gnome-terminal没有污点2.6.38-16-generic#67-Ubuntu
[44069.760170]通话追踪:
[44069.760187] []? sample_hbp_handler + 0x2d / 0x3b [testhrarr]
[44069.760202] []? __perf_event_overflow + 0x90 / 0x240
[44069.760213] []? perf_swevent_event + 0x136 / 0x140
[44069.760224] []? perf_bp_event + 0x70 / 0x80
[44069.760235] []? sched_clock_local + 0xd3 / 0x1c0
[44069.760247] []? format_decode + 0x323 / 0x380
[44069.760258] []? hw_breakpoint_handler.clone.0 + 0x102 / 0x130
[44069.760269] []? hw_breakpoint_exceptions_notify + 0x22 / 0x30
[44069.760279] []? notifier_call_chain + 0x45 / 0x60
[44069.760289] []? atomic_notifier_call_chain + 0x22 / 0x30
[44069.760299] []? notify_die + 0x2d / 0x30
[44069.760308] []? do_debug + 0x88 / 0x180
[44069.760318] []? debug_stack_correct + 0x30 / 0x38
[44069.760334] []? init_intel_cacheinfo + 0x103 / 0x394
[44069.760345] []? testhrarr_timer_function + 0xed / 0x160 [testhrarr]
[44069.760356] []? __run_hrtimer + 0x6f / 0x190
[44069.760366] []? send_to_group.clone.1 + 0xf8 / 0x150
[44069.760376] []? testhrarr_timer_function + 0x0 / 0x160 [testhrarr]
[44069.760387] []? hrtimer_interrupt + 0x108 / 0x240
[44069.760396] []? fsnotify + 0x1a5 / 0x290
[44069.760407] []? smp_apic_timer_interrupt + 0x56 / 0x8a
[44069.760416] []? apic_timer_interrupt + 0x31 / 0x38
[44069.760428] []? mem_cgroup_resize_limit + 0x108 / 0x1c0
[44069.760437] []? fput + 0x0 / 0x30
[44069.760446] []? sys_write + 0x67 / 0x70
[44069.760455] []? syscall_call + 0x7 / 0xb
[44069.760464] []? init_intel_cacheinfo + 0x23 / 0x394
[44069.760470]从sample_hbp_handler转储栈
[44069.764134] testhrarr_timer_function:testhrarr_runco​​unt 6
[44069.764147] testhrarr jiffies 10942441; ret:1; ktnsec:44069764144141
[44069.768133] testhrarr_timer_function:testhrarr_runco​​unt 7
[44069.768146] testhrarr jiffies 10942442; ret:1; ktnsec:44069768142976
[44069.772134] testhrarr_timer_function:testhrarr_runco​​unt 8
[44069.772148] testhrarr jiffies 10942443; ret:1; ktnsec:44069772144121
[44069.776132] testhrarr_timer_function:testhrarr_runco​​unt 9
[44069.776145] testhrarr jiffies 10942444; ret:1; ktnsec:44069776141971
[44069.780133] testhrarr_timer_function:testhrarr_runco​​unt 10
[44069.780141] testhrarr [5,7,9,11,13,]

...我们得到一个堆栈跟踪三次 - 一次在 testhrarr_startup 中,两次在 testhrarr_timer_function :一次为 runco​​unt == 0 ,一次为 runco​​unt == 5 ,如预期。



嗯,希望这有助于某人,

干杯!






Makefile

  CONFIG_MODULE_FORCE_UNLOAD = y 

#debug build:
#CFLAGS已更改...修复它使用EXTRA_CFLAGS。
覆盖EXTRA_CFLAGS + = - g -O0

obj-m + = testhrarr.o
#testhrarr-objs:= testhrarr.o

全部:
@echo EXTRA_CFLAGS = $(EXTRA_CFLAGS)
make -C / lib / modules / $(shell uname -r)/ build M = $(PWD)modules

clean:
make -C / lib / modules / $(shell uname -r)/ build M = $(PWD)clean

testhrarr.c

  / * 
* [http://www.tldp.org/LDP/lkmpg/2.6/html/lkmpg.html#AEN189 Linux内核模块编程指南]
* http:/ /stackoverflow.com/questions/16920238/reliability-of-linux-kernel-add-timer-at-resolution-of-one-jiffy/17055867#17055867
* http://stackoverflow.com/questions/8516021 / proc-create-example-for-kernel-module / 18924359#18924359
* http://lxr.free-electrons.com/source/samples/hw_breakpoint/data_breakpoint.c
* /


#include< linux / module.h> / *所有模块都需要* /
#include< linux / kernel.h> / *需要KERN_INFO * /
#include< linux / init.h> / *需要的宏* /
#include< linux / jiffies.h>
#include< linux / time.h>
#include< linux / proc_fs.h> / * / proc entry * /
#include< linux / seq_file.h> / * / proc entry * /
#define ARRSIZE 5
#define MAXRUNS 2 * ARRSIZE

#include< linux / hrtimer.h>

#define HWDEBUG_STACK 1

#if(HWDEBUG_STACK == 1)
#include< linux / perf_event.h>
#include< linux / hw_breakpoint.h>

struct perf_event * __percpu * sample_hbp;
static char ksym_name [KSYM_NAME_LEN] =testhrarr_arr;
module_param_string(ksym,ksym_name,KSYM_NAME_LEN,S_IRUGO);
MODULE_PARM_DESC(ksym,要监视的内核符号;此模块将在内核符号上报告任何
写入操作);
#endif

static volatile int testhrarr_runco​​unt = 0;
static volatile int testhrarr_isRunning = 0;

static unsigned long period_ms;
static unsigned long period_ns;
static ktime_t ktime_period_ns;
static struct hrtimer my_hrtimer;

static int * testhrarr_arr;
static int * testhrarr_arr_first;

static enum hrtimer_restart testhrarr_timer_function(struct hrtimer * timer)
{
unsigned long tjnow;
ktime_t kt_now;
int ret_overrun;

printk(KERN_INFO
%s:testhrarr_runco​​unt%d \\\

__func__,testhrarr_runco​​unt);

if(testhrarr_runco​​unt< MAXRUNS){
tjnow = jiffies;
kt_now = hrtimer_cb_get_time(& my_hrtimer);
ret_overrun = hrtimer_forward(& my_hrtimer,kt_now,ktime_period_ns);
printk(KERN_INFO
testhrarr jiffies%lu; ret:%d; ktnsec:%lld\\\

tjnow,ret_overrun,ktime_to_ns(kt_now));
testhrarr_arr [(testhrarr_runco​​unt%ARRSIZE)] + = testhrarr_runco​​unt;
testhrarr_runco​​unt ++;
返回HRTIMER_RESTART;
}
else {
int i;
testhrarr_isRunning = 0;
//不要使用KERN_DEBUG等,如果printk缓冲直到换行符为止!
printk(testhrarr_arr [); (i = 0; i< ARRSIZE; i ++){
printk(%d,testhrarr_arr [i]);

}
printk(] \\\
);
返回HRTIMER_NORESTART;
}
}

static void testhrarr_startup(void)
{
if(testhrarr_isRunning == 0){
testhrarr_isRunning = 1;
testhrarr_runco​​unt = 0;
testhrarr_arr [0] = 0; //只是第一个元素
hrtimer_start(& my_hrtimer,ktime_period_ns,HRTIMER_MODE_REL);
}
}


static int testhrarr_proc_show(struct seq_file * m,void * v){
if(testhrarr_isRunning == 0){
seq_printf(m,testhrarr proc:startup\\\
);
testhrarr_startup();
} else {
seq_printf(m,testhrarr proc:(正在运行,%d)\\\
,testhrarr_runco​​unt);
}
return 0;
}

static int testhrarr_proc_open(struct inode * inode,struct file * file){
return single_open(file,testhrarr_proc_show,NULL);
}

static const struct file_operations testhrarr_proc_fops = {
.owner = THIS_MODULE,
.open = testhrarr_proc_open,
.read = seq_read,
.llseek = seq_lseek,
.release = single_release,
};


#if(HWDEBUG_STACK == 1)
static void sample_hbp_handler(struct perf_event * bp,
struct perf_sample_data * data,
struct pt_regs * regs )
{
printk(KERN_INFO%s value is changed\\\
,ksym_name);
dump_stack();
printk(KERN_INFO从sample_hbp_handler\\\
转储栈);
}
#endif

static int __init testhrarr_init(void)
{
struct timespec tp_hr_res;
#if(HWDEBUG_STACK == 1)
struct perf_event_attr attr;
#endif

period_ms = 1000 / HZ;
hrtimer_get_res(CLOCK_MONOTONIC,& tp_hr_res);
printk(KERN_INFO
\"Init testhrarr: %d ; HZ: %d ; 1/HZ (ms): %ld ; hrres: %lld.%.9ld\n\",
testhrarr_runcount, HZ, period_ms, (long long)tp_hr_res.tv_sec, tp_hr_res.tv_nsec );

testhrarr_arr = (int*)kcalloc(ARRSIZE, sizeof(int), GFP_ATOMIC);
testhrarr_arr_first = &testhrarr_arr[0];

hrtimer_init(&my_hrtimer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);
my_hrtimer.function = &testhrarr_timer_function;
period_ns = period_ms*( (unsigned long)1E6L );
ktime_period_ns = ktime_set(0,period_ns);

printk(KERN_INFO
\" Addresses: _runcount 0x%p ; _arr 0x%p ; _arr[0] 0x%p (0x%p) ; _timer_function 0x%p ; my_hrtimer 0x%p; my_hrt.f 0x%p\n\",
&testhrarr_runcount, &testhrarr_arr, &(testhrarr_arr[0]), testhrarr_arr_first, &testhrarr_timer_function, &my_hrtimer, &my_hrtimer.function);


proc_create(\"testhrarr_proc\", 0, NULL, &testhrarr_proc_fops);


#if (HWDEBUG_STACK == 1)
hw_breakpoint_init(&attr);
if (strcmp(ksym_name, \"testhrarr_arr_first\") == 0) {
// just for testhrarr_arr_first - interpret the found symbol address
// as int*, and dereference it to get the \"real\" address it points to
attr.bp_addr = *((int*)kallsyms_lookup_name(ksym_name));
} else {
// the usual - address is kallsyms_lookup_name result
attr.bp_addr = kallsyms_lookup_name(ksym_name);
}
attr.bp_len = HW_BREAKPOINT_LEN_1;
attr.bp_type = HW_BREAKPOINT_W ; //| HW_BREAKPOINT_R;

sample_hbp = register_wide_hw_breakpoint(&attr, (perf_overflow_handler_t)sample_hbp_handler);
if (IS_ERR((void __force *)sample_hbp)) {
int ret = PTR_ERR((void __force *)sample_hbp);
printk(KERN_INFO \"Breakpoint registration failed\n\");
return ret;
}

// explicit cast needed to show 64-bit bp_addr as 32-bit address
// http://stackoverflow.com/questions/11796909/how-to-resolve-cast-to-pointer-from-integer-of-different-size-warning-in-c-co/11797103#11797103
printk(KERN_INFO \"HW Breakpoint for %s write installed (0x%p)\n\", ksym_name, (void*)(uintptr_t)attr.bp_addr);
#endif

return 0;
}

static void __exit testhrarr_exit(void)
{
int ret_cancel = 0;
kfree(testhrarr_arr);
while( hrtimer_callback_running(&my_hrtimer) ) {
ret_cancel++;
}
if (ret_cancel != 0) {
printk(KERN_INFO \" testhrarr Waited for hrtimer callback to finish (%d)\n\", ret_cancel);
}
if (hrtimer_active(&my_hrtimer) != 0) {
ret_cancel = hrtimer_cancel(&my_hrtimer);
printk(KERN_INFO \" testhrarr active hrtimer cancelled: %d (%d)\n\", ret_cancel, testhrarr_runcount);
}
if (hrtimer_is_queued(&my_hrtimer) != 0) {
ret_cancel = hrtimer_cancel(&my_hrtimer);
printk(KERN_INFO \" testhrarr queued hrtimer cancelled: %d (%d)\n\", ret_cancel, testhrarr_runcount);
}
remove_proc_entry(\"testhrarr_proc\", NULL);
#if (HWDEBUG_STACK == 1)
unregister_wide_hw_breakpoint(sample_hbp);
printk(KERN_INFO \"HW Breakpoint for %s write uninstalled\n\", ksym_name);
#endif
printk(KERN_INFO \"Exit testhrarr\n\");
}

module_init(testhrarr_init);
module_exit(testhrarr_exit);

MODULE_LICENSE(GPL);


I would like to somehow "watch" a variable (or a memory address, rather) in the Linux kernel (a kernel module/driver, to be exact); and find out what changed it - basically, print out a stack trace when the variable changed.

For instance, in the kernel module testjiffy-hr.c listed at end of this answer, I would like to print out a stack trace each time the runcount variable changes; hopefully the stack trace then would contain a mention of testjiffy_timer_function, which is indeed the function that changes that variable.

Now, I know I can use kgdb to connect to a debug Linux kernel running in say a virtual machine, and even set breakpoints (so hopefully, also watchpoints) like that - but the problem is that I actually want to debug an ALSA driver, in particular the playback dma_area buffer (where I'm getting some unexpected data) - which is highly sensitive to timing; and running the debug kernel in itself would mess up the timings (let alone running it in a virtual machine).

An even bigger problem here is that the playback dma_area pointer exists only during a playback operation (or in other words, between the _start and _stop handlers) - so I'd have to record the dma_area address at each _start callback, and then somehow "schedule" it for "watching" during the playback operation.

So I was hoping there was a way to do something like this directly in the driver code - as in, add some code in this _start callback which records the dma_area pointer, and use it as an argument to a command which initiates the "watch" for a change; with the stack trace printed from a corresponding callback function. (I'm aware that this too would influence the timing, but I was hoping it would be "light" enough not to influence the "live" driver operation too much).

So my question is: does such a technique for debugging in the Linux kernel exist?

If not: is it possible to set up a hardware (or software) interrupt, that reacts on a change of a specific memory address? Then could I set up such an interrupt handler, that could print out a stack trace? (although, I think the whole context changes when IRQ handlers run, so maybe getting a stack trace there would be wrong)?

If not: are there any other techniques left, that would allow me to print a stack trace of the process that changed the value stored in a given memory location in the kernel ( hopefully in a live, non-debug kernel)?

解决方案

Many thanks for the replies by @CosminRatiu and Eugene; thanks to those, I found:

... with which I could develop the example I'm posting here, the testhrarr.c kernel module/driver and the Makefile (below). It demonstrates that the hardware watchpoint tracing can be achieved in two ways: either using the perf program, which can probe the driver unchanged; or by adding some hardware breakpoint code to the driver (in the example, enveloped by the HWDEBUG_STACK define variable).

Essentially, debugging contents of standard atomic variable types like ints (like the runcount variable) are straightforward, as long as they are defined as a global variable in the kernel module, so they end up showing as a kernel symbol globally. Because of that, the code below adds the testhrarr_ as prefix to the variables (so as to avoid naming conflicts). However, debugging contents of arrays may be a bit trickier, due to the need for dereferencing - so that is what this post demonstrates, debug of the first byte of the testhrarr_arr array. It was done on:

$ echo `cat /etc/lsb-release` 
DISTRIB_ID=Ubuntu DISTRIB_RELEASE=11.04 DISTRIB_CODENAME=natty DISTRIB_DESCRIPTION="Ubuntu 11.04"
$ uname -a
Linux mypc 2.6.38-16-generic #67-Ubuntu SMP Thu Sep 6 18:00:43 UTC 2012 i686 i686 i386 GNU/Linux
$ cat /proc/cpuinfo | grep "model name"
model name  : Intel(R) Atom(TM) CPU N450   @ 1.66GHz
model name  : Intel(R) Atom(TM) CPU N450   @ 1.66GHz

The testhrarr module basically allocates memory for a small array upon module initialization, sets up a timer function, and exposes a /proc/testhrarr_proc file (using the newer proc_create interface). Then, attempting to read from the /proc/testhrarr_proc file (say, using cat) will trigger the timer function, which will modify the testhrarr_arr array values, and dump messages to /var/log/syslog. We expect that testhrarr_arr[0] will change three times during the operation; once in testhrarr_startup, and twice in testhrarr_timer_function (due to wrapping).

using perf

After building the module with make, you can load it with:

sudo insmod ./testhrarr.ko

At that point, /var/log/syslog would contain:

kernel: [40277.199913] Init testhrarr: 0 ; HZ: 250 ; 1/HZ (ms): 4 ; hrres: 0.000000001
kernel: [40277.199930]  Addresses: _runcount 0xf84be22c ; _arr 0xf84be2a0 ; _arr[0] 0xed182a80 (0xed182a80) ; _timer_function 0xf84bc1c3 ; my_hrtimer 0xf84be260; my_hrt.f 0xf84be27c
kernel: [40277.220329] HW Breakpoint for testhrarr_arr write installed (0xf84be2a0)

Note that just passing testhrarr_arr as symbol for hardware watchpoint scans the address of that variable (0xf84be2a0), not the address of the first element of the array (0xed182a80)! Because of this, the hardware breakpoint is not going to trigger - so the behavior will be as if the hardware breakpoint code is not present at all (which can be achieved by undefining HWDEBUG_STACK)!

So, even without a hardware breakpoint set through kernel module code, we can still use perf to observe a change of a memory address - in perf, we specify both the address we want to watch (here the address of the first element of testhrarr_arr, 0xed182a80), and the process which should be ran: here we run bash, so we can execute a cat /proc/testhrarr_proc which will trigger the kernel module timer, followed by a sleep 0.5 which will allow the timer to complete. The -a parameter is also needed, otherwise some events may be missed:

$ sudo perf record -a --call-graph --event=mem:0xed182a80:w bash -c 'cat /proc/testhrarr_proc ; sleep 0.5'
testhrarr proc: startup
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.485 MB perf.data (~21172 samples) ]

At this point, /var/log/syslog would also contain something like:


[40822.114964]  testhrarr_timer_function: testhrarr_runcount 0 
[40822.114980]  testhrarr jiffies 10130528 ; ret: 1 ; ktnsec: 40822114975062
[40822.118956]  testhrarr_timer_function: testhrarr_runcount 1 
[40822.118977]  testhrarr jiffies 10130529 ; ret: 1 ; ktnsec: 40822118973195
[40822.122940]  testhrarr_timer_function: testhrarr_runcount 2 
[40822.122956]  testhrarr jiffies 10130530 ; ret: 1 ; ktnsec: 40822122951143
[40822.126962]  testhrarr_timer_function: testhrarr_runcount 3 
[40822.126978]  testhrarr jiffies 10130531 ; ret: 1 ; ktnsec: 40822126973583
[40822.130941]  testhrarr_timer_function: testhrarr_runcount 4 
[40822.130961]  testhrarr jiffies 10130532 ; ret: 1 ; ktnsec: 40822130955167
[40822.134940]  testhrarr_timer_function: testhrarr_runcount 5 
[40822.134962]  testhrarr jiffies 10130533 ; ret: 1 ; ktnsec: 40822134958888
[40822.138936]  testhrarr_timer_function: testhrarr_runcount 6 
[40822.138958]  testhrarr jiffies 10130534 ; ret: 1 ; ktnsec: 40822138955693
[40822.142940]  testhrarr_timer_function: testhrarr_runcount 7 
[40822.142962]  testhrarr jiffies 10130535 ; ret: 1 ; ktnsec: 40822142959345
[40822.146936]  testhrarr_timer_function: testhrarr_runcount 8 
[40822.146957]  testhrarr jiffies 10130536 ; ret: 1 ; ktnsec: 40822146954479
[40822.150949]  testhrarr_timer_function: testhrarr_runcount 9 
[40822.150970]  testhrarr jiffies 10130537 ; ret: 1 ; ktnsec: 40822150963438
[40822.154974]  testhrarr_timer_function: testhrarr_runcount 10 
[40822.154988] testhrarr [ 5, 7, 9, 11, 13, ]

To read the capture of perf (a file called perf.data) we can use:

$ sudo perf report --call-graph flat --stdio
No kallsyms or vmlinux with build-id 5031df4d8668bcc45a7bdb4023909c6f8e2d3d34 was found
[testhrarr] with build id 5031df4d8668bcc45a7bdb4023909c6f8e2d3d34 not found, continuing without symbols
Failed to open /bin/cat, continuing without symbols
Failed to open /usr/lib/libpixman-1.so.0.20.2, continuing without symbols
Failed to open /usr/lib/xorg/modules/drivers/intel_drv.so, continuing without symbols
Failed to open /usr/bin/Xorg, continuing without symbols
# Events: 5  unknown
#
# Overhead  Command  Shared Object                                Symbol
# ........  .......  .............  ....................................
#
    87.50%     Xorg  [testhrarr]    [k] testhrarr_timer_function
            87.50%
                testhrarr_timer_function
                __run_hrtimer
                hrtimer_interrupt
                smp_apic_timer_interrupt
                apic_timer_interrupt
                0x30185d
                0x2ed701
                0x2ed8cc
                0x2edba0
                0x9d0386
                0x8126fc8
                0x81217a1
                0x811bdd3
                0x8070aa7
                0x806281c
                __libc_start_main
                0x8062411

     6.25%      cat  [testhrarr]    [k] testhrarr_timer_function
             6.25%
                testhrarr_timer_function
                testhrarr_proc_show
                seq_read
                proc_reg_read
                vfs_read
                sys_read
                syscall_call
                0xaa2416
                0x8049f4d
                __libc_start_main
                0x8049081

     3.12%  swapper  [testhrarr]    [k] testhrarr_timer_function
             3.12%
                testhrarr_timer_function
                __run_hrtimer
                hrtimer_interrupt
                smp_apic_timer_interrupt
                apic_timer_interrupt
                cpuidle_idle_call
                cpu_idle
                start_secondary

     3.12%      cat  [testhrarr]    [k] 0x356   
             3.12%
                0xf84bc356
                0xf84bc3a7
                seq_read
                proc_reg_read
                vfs_read
                sys_read
                syscall_call
                0xaa2416
                0x8049f4d
                __libc_start_main
                0x8049081



#
# (For a higher level overview, try: perf report --sort comm,dso)
#

So, since we're building the kernel module with debugging on (-g in the Makefile), it is not a problem for perf to find this module's symbols, even if the live kernel is not a debug kernel. So it correctly interprets testhrarr_timer_function as the setter most of the time, although it doesn't report testhrarr_startup (but it does report testhrarr_proc_show which calls it). There are also references to 0xf84bc3a7 and 0xf84bc356 which it couldn't resolve; however, note that the module is loaded at 0xf84bc000:

$ sudo cat /proc/modules | grep testhr
testhrarr 13433 0 - Live 0xf84bc000

... and that entry also starts with ...[k] 0x356; and if we look in the objdump of the kernel module:

$ objdump -S testhrarr.ko | less
...
00000323 :

static void testhrarr_startup(void)
{
...
    testhrarr_arr[0] = 0; //just the first element
 34b:   a1 80 00 00 00          mov    0x80,%eax
 350:   c7 00 00 00 00 00       movl   $0x0,(%eax)
    hrtimer_start(&my_hrtimer, ktime_period_ns, HRTIMER_MODE_REL);
 356:   c7 04 24 01 00 00 00    movl   $0x1,(%esp)                     **********
 35d:   8b 15 1c 00 00 00       mov    0x1c,%edx
...
00000375 :


static int testhrarr_proc_show(struct seq_file *m, void *v) {
...
    seq_printf(m, "testhrarr proc: startup\n");
 38f:   c7 44 24 04 79 00 00    movl   $0x79,0x4(%esp)
 396:   00 
 397:   8b 45 fc                mov    -0x4(%ebp),%eax
 39a:   89 04 24                mov    %eax,(%esp)
 39d:   e8 fc ff ff ff          call   39e 
    testhrarr_startup();
 3a2:   e8 7c ff ff ff          call   323 
 3a7:   eb 1c                   jmp    3c5   **********
  } else {
    seq_printf(m, "testhrarr proc: (is running, %d)\n", testhrarr_runcount);
 3a9:   a1 0c 00 00 00          mov    0xc,%eax
...

... so 0xf84bc356 apparently refers to hrtimer_start; and 0xf84bc3a7 -> 3a7 refers to its calling testhrarr_proc_show function; which thankfully makes sense. (Note that I've experienced with different versions of the driver, that the _start could show, and the timer_function to be expressed by sheer addresses; not sure what this is due).

One problem with perf, though, is that it gives me a statistical "Overhead" of these functions occurring (not sure what that refers to - probably time spent between entry and exit of a function?) - but what I want, really, is a log of stack traces which is sequential. Not sure if perf can be set up for that - but it definitely be done with kernel module code for hardware breakpoints.

using kernel module HW breakpoint

The code which is in the HWDEBUG_STACK implements the HW breakpoint setup and handling. As noted, the default set up for the symbol ksym_name (if unspecified), is testhrarr_arr, which doesn't trigger the hardware breakpoint at all. The ksym_name parameter can be specified on the command line during insmod; here we can note that:

$ sudo rmmod testhrarr    # remove module if still loaded
$ sudo insmod ./testhrarr.ko ksym=testhrarr_arr[0]

... results with a HW Breakpoint for testhrarr_arr[0] write installed (0x (null)) in /var/log/syslog; - which means we cannot use symbols with bracket notation for array access; thankfully a null pointer here simply means that HW breakpoint will again not fire; it doesn't crash the OS completely :)

There is, however, a global variable made to refer to the first element of the testhrarr_arr array, called testhrarr_arr_first - note how this global variable is specially handled in the code, and needs to be dereferenced, so that the correct address is obtained. So we do:

$ sudo rmmod testhrarr    # remove module if still loaded
$ sudo insmod ./testhrarr.ko ksym=testhrarr_arr_first

... and the syslog informs:

kernel: [43910.509726] Init testhrarr: 0 ; HZ: 250 ; 1/HZ (ms): 4 ; hrres: 0.000000001
kernel: [43910.509765]  Addresses: _runcount 0xf84be22c ; _arr 0xf84be2a0 ; _arr[0] 0xedf6c5c0 (0xedf6c5c0) ; _timer_function 0xf84bc1c3 ; my_hrtimer 0xf84be260; my_hrt.f 0xf84be27c
kernel: [43910.538535] HW Breakpoint for testhrarr_arr_first write installed (0xedf6c5c0)

... and we can see that the HW breakpoint is set at 0xedf6c5c0, which is the address of testhrarr_arr[0]. Now if we trigger the driver via the /proc file:

$ cat /proc/testhrarr_proc 
testhrarr proc: startup

... we obtain in syslog:

kernel: [44069.735695] testhrarr_arr_first value is changed
[44069.735711] Pid: 29320, comm: cat Not tainted 2.6.38-16-generic #67-Ubuntu
[44069.735719] Call Trace:
[44069.735737]  [] ? sample_hbp_handler+0x2d/0x3b [testhrarr]
[44069.735755]  [] ? __perf_event_overflow+0x90/0x240
[44069.735768]  [] ? proc_alloc_inode+0x23/0x90
[44069.735778]  [] ? proc_alloc_inode+0x23/0x90
[44069.735790]  [] ? perf_swevent_event+0x136/0x140
[44069.735801]  [] ? perf_bp_event+0x70/0x80
[44069.735812]  [] ? prep_new_page+0x110/0x1a0
[44069.735824]  [] ? get_page_from_freelist+0x12e/0x320
[44069.735836]  [] ? seq_open+0x3d/0xa0
[44069.735848]  [] ? hw_breakpoint_handler.clone.0+0x102/0x130
[44069.735861]  [] ? hw_breakpoint_exceptions_notify+0x22/0x30
[44069.735872]  [] ? notifier_call_chain+0x45/0x60
[44069.735883]  [] ? atomic_notifier_call_chain+0x22/0x30
[44069.735894]  [] ? notify_die+0x2d/0x30
[44069.735904]  [] ? do_debug+0x88/0x180
[44069.735915]  [] ? debug_stack_correct+0x30/0x38
[44069.735928]  [] ? testhrarr_startup+0x33/0x52 [testhrarr]
[44069.735940]  [] ? testhrarr_proc_show+0x32/0x57 [testhrarr]
[44069.735952]  [] ? seq_read+0x145/0x390
[44069.735963]  [] ? seq_read+0x0/0x390
[44069.735973]  [] ? proc_reg_read+0x64/0xa0
[44069.735985]  [] ? vfs_read+0x9f/0x160
[44069.735995]  [] ? proc_reg_read+0x0/0xa0
[44069.736003]  [] ? sys_read+0x42/0x70
[44069.736013]  [] ? syscall_call+0x7/0xb
[44069.736019] Dump stack from sample_hbp_handler
[44069.740132]  testhrarr_timer_function: testhrarr_runcount 0 
[44069.740146]  testhrarr jiffies 10942435 ; ret: 1 ; ktnsec: 44069740142485
[44069.740159] testhrarr_arr_first value is changed
[44069.740169] Pid: 4302, comm: gnome-terminal Not tainted 2.6.38-16-generic #67-Ubuntu
[44069.740176] Call Trace:
[44069.740195]  [] ? sample_hbp_handler+0x2d/0x3b [testhrarr]
[44069.740213]  [] ? __perf_event_overflow+0x90/0x240
[44069.740227]  [] ? perf_swevent_event+0x136/0x140
[44069.740239]  [] ? perf_bp_event+0x70/0x80
[44069.740253]  [] ? sched_clock_local+0xd3/0x1c0
[44069.740267]  [] ? format_decode+0x323/0x380
[44069.740280]  [] ? hw_breakpoint_handler.clone.0+0x102/0x130
[44069.740292]  [] ? hw_breakpoint_exceptions_notify+0x22/0x30
[44069.740302]  [] ? notifier_call_chain+0x45/0x60
[44069.740313]  [] ? atomic_notifier_call_chain+0x22/0x30
[44069.740324]  [] ? notify_die+0x2d/0x30
[44069.740335]  [] ? do_debug+0x88/0x180
[44069.740345]  [] ? debug_stack_correct+0x30/0x38
[44069.740364]  [] ? init_intel_cacheinfo+0x103/0x394
[44069.740379]  [] ? testhrarr_timer_function+0xed/0x160 [testhrarr]
[44069.740391]  [] ? __run_hrtimer+0x6f/0x190
[44069.740404]  [] ? testhrarr_timer_function+0x0/0x160 [testhrarr]
[44069.740416]  [] ? hrtimer_interrupt+0x108/0x240
[44069.740430]  [] ? smp_apic_timer_interrupt+0x56/0x8a
[44069.740441]  [] ? apic_timer_interrupt+0x31/0x38
[44069.740453]  [] ? _raw_spin_unlock_irqrestore+0x15/0x20
[44069.740465]  [] ? try_to_del_timer_sync+0x67/0xb0
[44069.740476]  [] ? del_timer_sync+0x29/0x50
[44069.740486]  [] ? flush_delayed_work+0x13/0x40
[44069.740500]  [] ? tty_flush_to_ldisc+0x12/0x20
[44069.740510]  [] ? n_tty_poll+0x4f/0x190
[44069.740523]  [] ? tty_poll+0x6d/0x90
[44069.740531]  [] ? n_tty_poll+0x0/0x190
[44069.740542]  [] ? do_poll.clone.3+0xd0/0x210
[44069.740553]  [] ? do_sys_poll+0x134/0x1e0
[44069.740563]  [] ? __pollwait+0x0/0xd0
[44069.740572]  [] ? pollwake+0x0/0x60
...
[44069.740742]  [] ? pollwake+0x0/0x60
[44069.740757]  [] ? rw_verify_area+0x6c/0x130
[44069.740770]  [] ? ktime_get_ts+0xf8/0x120
[44069.740781]  [] ? poll_select_set_timeout+0x64/0x70
[44069.740793]  [] ? sys_poll+0x5a/0xd0
[44069.740804]  [] ? syscall_call+0x7/0xb
[44069.740815]  [] ? init_intel_cacheinfo+0x23/0x394
[44069.740822] Dump stack from sample_hbp_handler
[44069.744130]  testhrarr_timer_function: testhrarr_runcount 1 
[44069.744143]  testhrarr jiffies 10942436 ; ret: 1 ; ktnsec: 44069744140055
[44069.748132]  testhrarr_timer_function: testhrarr_runcount 2 
[44069.748145]  testhrarr jiffies 10942437 ; ret: 1 ; ktnsec: 44069748141271
[44069.752131]  testhrarr_timer_function: testhrarr_runcount 3 
[44069.752145]  testhrarr jiffies 10942438 ; ret: 1 ; ktnsec: 44069752141164
[44069.756131]  testhrarr_timer_function: testhrarr_runcount 4 
[44069.756141]  testhrarr jiffies 10942439 ; ret: 1 ; ktnsec: 44069756138318
[44069.760130]  testhrarr_timer_function: testhrarr_runcount 5 
[44069.760141]  testhrarr jiffies 10942440 ; ret: 1 ; ktnsec: 44069760138469
[44069.760154] testhrarr_arr_first value is changed
[44069.760164] Pid: 4302, comm: gnome-terminal Not tainted 2.6.38-16-generic #67-Ubuntu
[44069.760170] Call Trace:
[44069.760187]  [] ? sample_hbp_handler+0x2d/0x3b [testhrarr]
[44069.760202]  [] ? __perf_event_overflow+0x90/0x240
[44069.760213]  [] ? perf_swevent_event+0x136/0x140
[44069.760224]  [] ? perf_bp_event+0x70/0x80
[44069.760235]  [] ? sched_clock_local+0xd3/0x1c0
[44069.760247]  [] ? format_decode+0x323/0x380
[44069.760258]  [] ? hw_breakpoint_handler.clone.0+0x102/0x130
[44069.760269]  [] ? hw_breakpoint_exceptions_notify+0x22/0x30
[44069.760279]  [] ? notifier_call_chain+0x45/0x60
[44069.760289]  [] ? atomic_notifier_call_chain+0x22/0x30
[44069.760299]  [] ? notify_die+0x2d/0x30
[44069.760308]  [] ? do_debug+0x88/0x180
[44069.760318]  [] ? debug_stack_correct+0x30/0x38
[44069.760334]  [] ? init_intel_cacheinfo+0x103/0x394
[44069.760345]  [] ? testhrarr_timer_function+0xed/0x160 [testhrarr]
[44069.760356]  [] ? __run_hrtimer+0x6f/0x190
[44069.760366]  [] ? send_to_group.clone.1+0xf8/0x150
[44069.760376]  [] ? testhrarr_timer_function+0x0/0x160 [testhrarr]
[44069.760387]  [] ? hrtimer_interrupt+0x108/0x240
[44069.760396]  [] ? fsnotify+0x1a5/0x290
[44069.760407]  [] ? smp_apic_timer_interrupt+0x56/0x8a
[44069.760416]  [] ? apic_timer_interrupt+0x31/0x38
[44069.760428]  [] ? mem_cgroup_resize_limit+0x108/0x1c0
[44069.760437]  [] ? fput+0x0/0x30
[44069.760446]  [] ? sys_write+0x67/0x70
[44069.760455]  [] ? syscall_call+0x7/0xb
[44069.760464]  [] ? init_intel_cacheinfo+0x23/0x394
[44069.760470] Dump stack from sample_hbp_handler
[44069.764134]  testhrarr_timer_function: testhrarr_runcount 6 
[44069.764147]  testhrarr jiffies 10942441 ; ret: 1 ; ktnsec: 44069764144141
[44069.768133]  testhrarr_timer_function: testhrarr_runcount 7 
[44069.768146]  testhrarr jiffies 10942442 ; ret: 1 ; ktnsec: 44069768142976
[44069.772134]  testhrarr_timer_function: testhrarr_runcount 8 
[44069.772148]  testhrarr jiffies 10942443 ; ret: 1 ; ktnsec: 44069772144121
[44069.776132]  testhrarr_timer_function: testhrarr_runcount 9 
[44069.776145]  testhrarr jiffies 10942444 ; ret: 1 ; ktnsec: 44069776141971
[44069.780133]  testhrarr_timer_function: testhrarr_runcount 10 
[44069.780141] testhrarr [ 5, 7, 9, 11, 13, ]

... we get a stack trace exactly three times - once during testhrarr_startup, and twice in testhrarr_timer_function: once for runcount==0 and once for runcount==5, as expected.

Well, hope this helps someone,
Cheers!


Makefile

CONFIG_MODULE_FORCE_UNLOAD=y

# debug build:
# "CFLAGS was changed ... Fix it to use EXTRA_CFLAGS."
override EXTRA_CFLAGS+=-g -O0 

obj-m += testhrarr.o
#testhrarr-objs  := testhrarr.o

all:
    @echo EXTRA_CFLAGS = $(EXTRA_CFLAGS)
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) modules

clean:
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) clean

testhrarr.c

/*
 * [http://www.tldp.org/LDP/lkmpg/2.6/html/lkmpg.html#AEN189 The Linux Kernel Module Programming Guide]
 * http://stackoverflow.com/questions/16920238/reliability-of-linux-kernel-add-timer-at-resolution-of-one-jiffy/17055867#17055867
 * http://stackoverflow.com/questions/8516021/proc-create-example-for-kernel-module/18924359#18924359
 * http://lxr.free-electrons.com/source/samples/hw_breakpoint/data_breakpoint.c
 */


#include <linux/module.h>   /* Needed by all modules */
#include <linux/kernel.h>   /* Needed for KERN_INFO */
#include <linux/init.h>     /* Needed for the macros */
#include <linux/jiffies.h>
#include <linux/time.h>
#include <linux/proc_fs.h>  /* /proc entry */
#include <linux/seq_file.h> /* /proc entry */
#define ARRSIZE 5
#define MAXRUNS 2*ARRSIZE

#include <linux/hrtimer.h>

#define HWDEBUG_STACK 1

#if (HWDEBUG_STACK == 1)
#include <linux/perf_event.h>
#include <linux/hw_breakpoint.h>

struct perf_event * __percpu *sample_hbp;
static char ksym_name[KSYM_NAME_LEN] = "testhrarr_arr";
module_param_string(ksym, ksym_name, KSYM_NAME_LEN, S_IRUGO);
MODULE_PARM_DESC(ksym, "Kernel symbol to monitor; this module will report any"
      " write operations on the kernel symbol");
#endif

static volatile int testhrarr_runcount = 0;
static volatile int testhrarr_isRunning = 0;

static unsigned long period_ms;
static unsigned long period_ns;
static ktime_t ktime_period_ns;
static struct hrtimer my_hrtimer;

static int* testhrarr_arr;
static int* testhrarr_arr_first;

static enum hrtimer_restart testhrarr_timer_function(struct hrtimer *timer)
{
  unsigned long tjnow;
  ktime_t kt_now;
  int ret_overrun;

  printk(KERN_INFO
    " %s: testhrarr_runcount %d \n",
    __func__, testhrarr_runcount);

  if (testhrarr_runcount < MAXRUNS) {
    tjnow = jiffies;
    kt_now = hrtimer_cb_get_time(&my_hrtimer);
    ret_overrun = hrtimer_forward(&my_hrtimer, kt_now, ktime_period_ns);
    printk(KERN_INFO
      " testhrarr jiffies %lu ; ret: %d ; ktnsec: %lld\n",
      tjnow, ret_overrun, ktime_to_ns(kt_now));
    testhrarr_arr[(testhrarr_runcount % ARRSIZE)] += testhrarr_runcount;
    testhrarr_runcount++;
    return HRTIMER_RESTART;
  }
  else {
    int i;
    testhrarr_isRunning = 0;
    // do not use KERN_DEBUG etc, if printk buffering until newline is desired!
    printk("testhrarr_arr [ ");
    for(i=0; i<ARRSIZE; i++) {
      printk("%d, ", testhrarr_arr[i]);
    }
    printk("]\n");
    return HRTIMER_NORESTART;
  }
}

static void testhrarr_startup(void)
{
  if (testhrarr_isRunning == 0) {
    testhrarr_isRunning = 1;
    testhrarr_runcount = 0;
    testhrarr_arr[0] = 0; //just the first element
    hrtimer_start(&my_hrtimer, ktime_period_ns, HRTIMER_MODE_REL);
  }
}


static int testhrarr_proc_show(struct seq_file *m, void *v) {
  if (testhrarr_isRunning == 0) {
    seq_printf(m, "testhrarr proc: startup\n");
    testhrarr_startup();
  } else {
    seq_printf(m, "testhrarr proc: (is running, %d)\n", testhrarr_runcount);
  }
  return 0;
}

static int testhrarr_proc_open(struct inode *inode, struct  file *file) {
  return single_open(file, testhrarr_proc_show, NULL);
}

static const struct file_operations testhrarr_proc_fops = {
  .owner = THIS_MODULE,
  .open = testhrarr_proc_open,
  .read = seq_read,
  .llseek = seq_lseek,
  .release = single_release,
};


#if (HWDEBUG_STACK == 1)
static void sample_hbp_handler(struct perf_event *bp,
             struct perf_sample_data *data,
             struct pt_regs *regs)
{
  printk(KERN_INFO "%s value is changed\n", ksym_name);
  dump_stack();
  printk(KERN_INFO "Dump stack from sample_hbp_handler\n");
}
#endif

static int __init testhrarr_init(void)
{
  struct timespec tp_hr_res;
  #if (HWDEBUG_STACK == 1)
  struct perf_event_attr attr;
  #endif

  period_ms = 1000/HZ;
  hrtimer_get_res(CLOCK_MONOTONIC, &tp_hr_res);
  printk(KERN_INFO
    "Init testhrarr: %d ; HZ: %d ; 1/HZ (ms): %ld ; hrres: %lld.%.9ld\n",
               testhrarr_runcount,      HZ,        period_ms, (long long)tp_hr_res.tv_sec, tp_hr_res.tv_nsec );

  testhrarr_arr = (int*)kcalloc(ARRSIZE, sizeof(int), GFP_ATOMIC);
  testhrarr_arr_first = &testhrarr_arr[0];

  hrtimer_init(&my_hrtimer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);
  my_hrtimer.function = &testhrarr_timer_function;
  period_ns = period_ms*( (unsigned long)1E6L );
  ktime_period_ns = ktime_set(0,period_ns);

  printk(KERN_INFO
    " Addresses: _runcount 0x%p ; _arr 0x%p ; _arr[0] 0x%p (0x%p) ; _timer_function 0x%p ; my_hrtimer 0x%p; my_hrt.f 0x%p\n",
    &testhrarr_runcount, &testhrarr_arr, &(testhrarr_arr[0]), testhrarr_arr_first, &testhrarr_timer_function, &my_hrtimer, &my_hrtimer.function);


  proc_create("testhrarr_proc", 0, NULL, &testhrarr_proc_fops);


  #if (HWDEBUG_STACK == 1)
  hw_breakpoint_init(&attr);
  if (strcmp(ksym_name, "testhrarr_arr_first") == 0) {
    // just for testhrarr_arr_first - interpret the found symbol address
    // as int*, and dereference it to get the "real" address it points to
    attr.bp_addr = *((int*)kallsyms_lookup_name(ksym_name));
  } else {
    // the usual - address is kallsyms_lookup_name result
    attr.bp_addr = kallsyms_lookup_name(ksym_name);
  }
  attr.bp_len = HW_BREAKPOINT_LEN_1;
  attr.bp_type = HW_BREAKPOINT_W ; //| HW_BREAKPOINT_R;

  sample_hbp = register_wide_hw_breakpoint(&attr, (perf_overflow_handler_t)sample_hbp_handler);
  if (IS_ERR((void __force *)sample_hbp)) {
    int ret = PTR_ERR((void __force *)sample_hbp);
    printk(KERN_INFO "Breakpoint registration failed\n");
    return ret;
  }

  // explicit cast needed to show 64-bit bp_addr as 32-bit address
  // http://stackoverflow.com/questions/11796909/how-to-resolve-cast-to-pointer-from-integer-of-different-size-warning-in-c-co/11797103#11797103
  printk(KERN_INFO "HW Breakpoint for %s write installed (0x%p)\n", ksym_name, (void*)(uintptr_t)attr.bp_addr);
  #endif

  return 0;
}

static void __exit testhrarr_exit(void)
{
  int ret_cancel = 0;
  kfree(testhrarr_arr);
  while( hrtimer_callback_running(&my_hrtimer) ) {
    ret_cancel++;
  }
  if (ret_cancel != 0) {
    printk(KERN_INFO " testhrarr Waited for hrtimer callback to finish (%d)\n", ret_cancel);
  }
  if (hrtimer_active(&my_hrtimer) != 0) {
    ret_cancel = hrtimer_cancel(&my_hrtimer);
    printk(KERN_INFO " testhrarr active hrtimer cancelled: %d (%d)\n", ret_cancel, testhrarr_runcount);
  }
  if (hrtimer_is_queued(&my_hrtimer) != 0) {
    ret_cancel = hrtimer_cancel(&my_hrtimer);
    printk(KERN_INFO " testhrarr queued hrtimer cancelled: %d (%d)\n", ret_cancel, testhrarr_runcount);
  }
  remove_proc_entry("testhrarr_proc", NULL);
  #if (HWDEBUG_STACK == 1)
  unregister_wide_hw_breakpoint(sample_hbp);
  printk(KERN_INFO "HW Breakpoint for %s write uninstalled\n", ksym_name);
  #endif
  printk(KERN_INFO "Exit testhrarr\n");
}

module_init(testhrarr_init);
module_exit(testhrarr_exit);

MODULE_LICENSE("GPL");

这篇关于观察Linux内核中的变量(内存地址)变化,更改时打印堆栈跟踪?的文章就介绍到这了,希望我们推荐的答案对大家有所帮助,也希望大家多多支持IT屋!

查看全文
登录 关闭
扫码关注1秒登录
发送“验证码”获取 | 15天全站免登陆