pr_debug、dev_dbg等动态调试一
内核版本:Linux-3.14
作者:彭东林
邮箱:pengdonglin137@163.com
pr_debug:
#if defined(CONFIG_DYNAMIC_DEBUG)
/* dynamic_pr_debug() uses pr_fmt() internally so we don't need it here */
#define pr_debug(fmt, ...) \
dynamic_pr_debug(fmt, ##__VA_ARGS__)
#elif defined(DEBUG)
#define pr_debug(fmt, ...) \
printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#else
#define pr_debug(fmt, ...) \
no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif
dev_dbg:
#if defined(CONFIG_DYNAMIC_DEBUG)
#define dev_dbg(dev, format, ...) \
do { \
dynamic_dev_dbg(dev, format, ##__VA_ARGS__); \
} while (0)
#elif defined(DEBUG)
#define dev_dbg(dev, format, arg...) \
dev_printk(KERN_DEBUG, dev, format, ##arg)
#else
#define dev_dbg(dev, format, arg...) \
({ \
if (0) \
dev_printk(KERN_DEBUG, dev, format, ##arg); \
0; \
})
#endif
从上面的宏定义可以看出,要使用dynamic_*的话需要配置CONFIG_DYNAMIC_DEBUG。
Kernel hacking --->
Compile-time checks and compiler options --->
[*] Debug Filesystem
printk and dmesg options --->
[*] Enable dynamic printk() support
在[*] Enable dynamic printk() support 上点击h,可以看到帮助信息。
我们以pr_debug为例分析,
1: #define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \
2: static struct _ddebug __aligned(8) \
3: __attribute__((section("__verbose"))) name = { \
4: .modname = KBUILD_MODNAME, \
5: .function = __func__, \
6: .filename = __FILE__, \
7: .format = (fmt), \
8: .lineno = __LINE__, \
9: .flags = _DPRINTK_FLAGS_DEFAULT, \
10: }
11:
12: #define dynamic_pr_debug(fmt, ...) \
13: do { \
14: DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt); \
15: if (unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT)) \
16: __dynamic_pr_debug(&descriptor, pr_fmt(fmt), \
17: ##__VA_ARGS__); \
18: } while (0)
pr_fmt:
1: #ifndef pr_fmt
2: #define pr_fmt(fmt) fmt
3: #endif
所以,如果把pr_debug展开,那么就是:
1: do {
2: static struct _ddebug __aligned(8) \
3: __attribute__((section("__verbose"))) descriptor = { \
4: .modname = KBUILD_MODNAME, \
5: .function = __func__, \
6: .filename = __FILE__, \
7: .format = (fmt), \
8: .lineno = __LINE__, \
9: .flags = _DPRINTK_FLAGS_DEFAULT, \
10: }
11: if (unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT)) \
12: __dynamic_pr_debug(&descriptor, fmt, \
13: ##__VA_ARGS__); \
14: } while (0)
其中flags的赋值_DPRINTK_FLAGS_DEFAULT依赖DEBUG宏,
1: #if defined DEBUG
2: #define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINT
3: #else
4: #define _DPRINTK_FLAGS_DEFAULT 0
5: #endif
即,如果没有定义DEBUG宏,pr_debug默认无法打印出来,需要按照下面介绍的方法。 flags的值对于打印什么和如何打印都非常重要。
此外还定义了static类型的变量descriptor,它在编译链接时会被放到__verbose段,可以看看arch/arm/kernel/vmlinux.lds:
1: OUTPUT_ARCH(arm)
2: ENTRY(stext)
3: jiffies = jiffies_64;
4: SECTIONS
5: {
6: /*
7: * XXX: The linker does not define how output sections are
8: * assigned to input sections when there are multiple statements
9: * matching the same input section name. There is no documented
10: * order of matching.
11: *
12: * unwind exit sections must be discarded before the rest of the
13: * unwind sections get included.
14: */
15: /DISCARD/ : {
16: *(.ARM.exidx.exit.text)
17: *(.ARM.extab.exit.text)
18: *(.ARM.exidx.cpuexit.text)
19: *(.ARM.extab.cpuexit.text)
20:
21:
22: *(.exitcall.exit)
23: *(.alt.smp.init)
24: *(.discard)
25: *(.discard.*)
26: }
27: . = 0xC0000000 + 0x00008000;
28: .head.text : {
29: _text = .;
30: *(.head.text)
31: }
32: .text : { /* Real text segment */
33: _stext = .; /* Text and read-only data */
34: __exception_text_start = .;
35: *(.exception.text)
36: __exception_text_end = .;
37:
38: . = ALIGN(8); *(.text.hot) *(.text) *(.ref.text) *(.text.unlikely)
39: . = ALIGN(8); __sched_text_start = .; *(.sched.text) __sched_text_end = .;
40: . = ALIGN(8); __lock_text_start = .; *(.spinlock.text) __lock_text_end = .;
41: . = ALIGN(8); __kprobes_text_start = .; *(.kprobes.text) __kprobes_text_end = .;
42: . = ALIGN(8); __idmap_text_start = .; *(.idmap.text) __idmap_text_end = .; . = ALIGN(32); __hyp_idmap_text_start = .; *(.hyp.idmap.text) __hyp_idmap_text_end = .;
43: *(.fixup)
44: *(.gnu.warning)
45: *(.glue_7)
46: *(.glue_7t)
47: . = ALIGN(4);
48: *(.got) /* Global offset table */
49:
50: }
51: . = ALIGN(((1 << 12))); .rodata : AT(ADDR(.rodata) - 0) { __start_rodata = .; *(.rodata) *(.rodata.*) *(__vermagic) . = ALIGN(8); __start___tracepoints_ptrs = .; *(__tracepoints_ptrs) __stop___tracepoints_ptrs = .; *(__tracepoints_strings) } .rodata1 : AT(ADDR(.rodata1) - 0) { *(.rodata1) } . = ALIGN(8); __bug_table : AT(ADDR(__bug_table) - 0) { __start___bug_table = .; *(__bug_table) __stop___bug_table = .; } .pci_fixup : AT(ADDR(.pci_fixup) - 0) { __start_pci_fixups_early = .; *(.pci_fixup_early) __end_pci_fixups_early = .; __start_pci_fixups_header = .; *(.pci_fixup_header) __end_pci_fixups_header = .; __start_pci_fixups_final = .; *(.pci_fixup_final) __end_pci_fixups_final = .; __start_pci_fixups_enable = .; *(.pci_fixup_enable) __end_pci_fixups_enable = .; __start_pci_fixups_resume = .; *(.pci_fixup_resume) __end_pci_fixups_resume = .; __start_pci_fixups_resume_early = .; *(.pci_fixup_resume_early) __end_pci_fixups_resume_early = .; __start_pci_fixups_suspend = .; *(.pci_fixup_suspend) __end_pci_fixups_suspend = .; } .builtin_fw : AT(ADDR(.builtin_fw) - 0) { __start_builtin_fw = .; *(.builtin_fw) __end_builtin_fw = .; } __ksymtab : AT(ADDR(__ksymtab) - 0) { __start___ksymtab = .; *(SORT(___ksymtab+*)) __stop___ksymtab = .; } __ksymtab_gpl : AT(ADDR(__ksymtab_gpl) - 0) { __start___ksymtab_gpl = .; *(SORT(___ksymtab_gpl+*)) __stop___ksymtab_gpl = .; } __ksymtab_unused : AT(ADDR(__ksymtab_unused) - 0) { __start___ksymtab_unused = .; *(SORT(___ksymtab_unused+*)) __stop___ksymtab_unused = .; } __ksymtab_unused_gpl : AT(ADDR(__ksymtab_unused_gpl) - 0) { __start___ksymtab_unused_gpl = .; *(SORT(___ksymtab_unused_gpl+*)) __stop___ksymtab_unused_gpl = .; } __ksymtab_gpl_future : AT(ADDR(__ksymtab_gpl_future) - 0) { __start___ksymtab_gpl_future = .; *(SORT(___ksymtab_gpl_future+*)) __stop___ksymtab_gpl_future = .; } __kcrctab : AT(ADDR(__kcrctab) - 0) { __start___kcrctab = .; *(SORT(___kcrctab+*)) __stop___kcrctab = .; } __kcrctab_gpl : AT(ADDR(__kcrctab_gpl) - 0) { __start___kcrctab_gpl = .; *(SORT(___kcrctab_gpl+*)) __stop___kcrctab_gpl = .; } __kcrctab_unused : AT(ADDR(__kcrctab_unused) - 0) { __start___kcrctab_unused = .; *(SORT(___kcrctab_unused+*)) __stop___kcrctab_unused = .; } __kcrctab_unused_gpl : AT(ADDR(__kcrctab_unused_gpl) - 0) { __start___kcrctab_unused_gpl = .; *(SORT(___kcrctab_unused_gpl+*)) __stop___kcrctab_unused_gpl = .; } __kcrctab_gpl_future : AT(ADDR(__kcrctab_gpl_future) - 0) { __start___kcrctab_gpl_future = .; *(SORT(___kcrctab_gpl_future+*)) __stop___kcrctab_gpl_future = .; } __ksymtab_strings : AT(ADDR(__ksymtab_strings) - 0) { *(__ksymtab_strings) } __init_rodata : AT(ADDR(__init_rodata) - 0) { *(.ref.rodata) } __param : AT(ADDR(__param) - 0) { __start___param = .; *(__param) __stop___param = .; } __modver : AT(ADDR(__modver) - 0) { __start___modver = .; *(__modver) __stop___modver = .; . = ALIGN(((1 << 12))); __end_rodata = .; } . = ALIGN(((1 << 12)));
52: . = ALIGN(4);
53: __ex_table : AT(ADDR(__ex_table) - 0) {
54: __start___ex_table = .;
55: *(__ex_table)
56: __stop___ex_table = .;
57: }
58: /*
59: * Stack unwinding tables
60: */
61: . = ALIGN(8);
62: .ARM.unwind_idx : {
63: __start_unwind_idx = .;
64: *(.ARM.exidx*)
65: __stop_unwind_idx = .;
66: }
67: .ARM.unwind_tab : {
68: __start_unwind_tab = .;
69: *(.ARM.extab*)
70: __stop_unwind_tab = .;
71: }
72: .notes : AT(ADDR(.notes) - 0) { __start_notes = .; *(.note.*) __stop_notes = .; }
73: _etext = .; /* End of text and rodata section */
74: . = ALIGN((1 << 12));
75: __init_begin = .;
76: /*
77: * The vectors and stubs are relocatable code, and the
78: * only thing that matters is their relative offsets
79: */
80: __vectors_start = .;
81: .vectors 0 : AT(__vectors_start) {
82: *(.vectors)
83: }
84: . = __vectors_start + SIZEOF(.vectors);
85: __vectors_end = .;
86: __stubs_start = .;
87: .stubs 0x1000 : AT(__stubs_start) {
88: *(.stubs)
89: }
90: . = __stubs_start + SIZEOF(.stubs);
91: __stubs_end = .;
92: . = ALIGN(8); .init.text : AT(ADDR(.init.text) - 0) { _sinittext = .; *(.init.text) *(.meminit.text) _einittext = .; }
93: .exit.text : {
94: *(.exit.text) *(.memexit.text)
95: }
96: .init.proc.info : {
97: . = ALIGN(4); __proc_info_begin = .; *(.proc.info.init) __proc_info_end = .;
98: }
99: .init.arch.info : {
100: __arch_info_begin = .;
101: *(.arch.info.init)
102: __arch_info_end = .;
103: }
104: .init.tagtable : {
105: __tagtable_begin = .;
106: *(.taglist.init)
107: __tagtable_end = .;
108: }
109: .init.pv_table : {
110: __pv_table_begin = .;
111: *(.pv_table)
112: __pv_table_end = .;
113: }
114: .init.data : {
115: *(.init.data) *(.meminit.data) *(.init.rodata) *(.meminit.rodata) . = ALIGN(32); __dtb_start = .; *(.dtb.init.rodata) __dtb_end = .;
116: . = ALIGN(16); __setup_start = .; *(.init.setup) __setup_end = .;
117: __initcall_start = .; *(.initcallearly.init) __initcall0_start = .; *(.initcall0.init) *(.initcall0s.init) __initcall1_start = .; *(.initcall1.init) *(.initcall1s.init) __initcall2_start = .; *(.initcall2.init) *(.initcall2s.init) __initcall3_start = .; *(.initcall3.init) *(.initcall3s.init) __initcall4_start = .; *(.initcall4.init) *(.initcall4s.init) __initcall5_start = .; *(.initcall5.init) *(.initcall5s.init) __initcallrootfs_start = .; *(.initcallrootfs.init) *(.initcallrootfss.init) __initcall6_start = .; *(.initcall6.init) *(.initcall6s.init) __initcall7_start = .; *(.initcall7.init) *(.initcall7s.init) __initcall_end = .;
118: __con_initcall_start = .; *(.con_initcall.init) __con_initcall_end = .;
119: __security_initcall_start = .; *(.security_initcall.init) __security_initcall_end = .;
120: . = ALIGN(4); __initramfs_start = .; *(.init.ramfs) . = ALIGN(8); *(.init.ramfs.info)
121: }
122: .exit.data : {
123: *(.exit.data) *(.memexit.data) *(.memexit.rodata)
124: }
125: __init_end = .;
126: . = ALIGN(8192);
127: __data_loc = .;
128: .data : AT(__data_loc) {
129: _data = .; /* address in memory */
130: _sdata = .;
131: /*
132: * first, the init task union, aligned
133: * to an 8192 byte boundary.
134: */
135: . = ALIGN(8192); *(.data..init_task)
136: . = ALIGN((1 << 12)); __nosave_begin = .; *(.data..nosave) . = ALIGN((1 << 12)); __nosave_end = .;
137: . = ALIGN((1 << 5)); *(.data..cacheline_aligned)
138: . = ALIGN((1 << 5)); *(.data..read_mostly) . = ALIGN((1 << 5));
139: /*
140: * and the usual data section
141: */
142: *(.data) *(.ref.data) *(.data..shared_aligned) *(.data.unlikely) . = ALIGN(32); *(__tracepoints) . = ALIGN(8); __start___jump_table = .; *(__jump_table) __stop___jump_table = .; . = ALIGN(8);__start___verbose = .; *(__verbose) __stop___verbose = .;
143: CONSTRUCTORS
144: _edata = .;
145: }
146: _edata_loc = __data_loc + SIZEOF(.data);
147: . = ALIGN(0); __bss_start = .; . = ALIGN(0); .sbss : AT(ADDR(.sbss) - 0) { *(.sbss) *(.scommon) } . = ALIGN(0); .bss : AT(ADDR(.bss) - 0) { *(.bss..page_aligned) *(.dynbss) *(.bss) *(COMMON) } . = ALIGN(0); __bss_stop = .;
148: _end = .;
149: .stab 0 : { *(.stab) } .stabstr 0 : { *(.stabstr) } .stab.excl 0 : { *(.stab.excl) } .stab.exclstr 0 : { *(.stab.exclstr) } .stab.index 0 : { *(.stab.index) } .stab.indexstr 0 : { *(.stab.indexstr) } .comment 0 : { *(.comment) }
150: .comment 0 : { *(.comment) }
151: }
可以看到,将__verbose段链接到了__start__verbose和__stop__verbose之间,也就是将来可以利用__start_verbose和__stop_verbose这两个符号来找到__verbose段。
一般我们使用debugfs的时候,在系统启动时挂载debugfs文件系统:
1: [root@TQ2440 /]# mount
2: rootfs on / type rootfs (rw)
3: /dev/root on / type yaffs2 (rw,relatime)
4: proc on /proc type proc (rw,relatime)
5: tmpfs on /tmp type tmpfs (rw,relatime)
6: sysfs on /sys type sysfs (rw,relatime)
7: tmpfs on /dev type tmpfs (rw,relatime)
8: debugfs on /sys/kernel/debug type debugfs (rw,relatime)
9: devpts on /dev/pts type devpts (rw,relatime,mode=600)
上面我们将debugfs挂载到了/sys/kernel/debug目录下面。
如果我们想打开某个文件中的pr_debug,如demo.c,可以如下操作:
echo -n "file demo.c +p" > /sys/kernel/debug/dynamic_debug/control
关闭的话:
echo -n "file demo.c -p" > /sys/kernel/debug/dynamic_debug/control
如果想分析一下为什么这样操作就可以实现将某个文件中的pr_debug打开,就需要分析背后的原理,如control节点的创建.
上面pr_debug展开后的descriptor变量被链接到了__verbose段,那么系统一定会有解析这个段的代码。
具体的代码位置是lib/dynamic_debug.c
__verbose的解析:
1: static int __init dynamic_debug_init(void)
2: {
3: struct _ddebug *iter, *iter_start;
4: const char *modname = NULL;
5: char *cmdline;
6: int ret = 0;
7: int n = 0, entries = 0, modct = 0;
8: int verbose_bytes = 0;
9:
10: // __start___verbose 和 __stop___verbose 之间存放的都是struct _ddebug类型的静态变量,
11: // pr_debug展开后的descriptor就在这里。
12: if (__start___verbose == __stop___verbose) {
13: pr_warn("_ddebug table is empty in a CONFIG_DYNAMIC_DEBUG build\n");
14: return 1;
15: }
16:
17: // 下面这段代码完成的任务是解析__verbose段。
18: iter = __start___verbose;
19: modname = iter->modname;
20: iter_start = iter;
21: for (; iter < __stop___verbose; iter++) {
22: entries++;
23: verbose_bytes += strlen(iter->modname) + strlen(iter->function)
24: + strlen(iter->filename) + strlen(iter->format);
25:
26: if (strcmp(modname, iter->modname)) {
27: modct++;
28: // 给每个modname(descriptor和modname是一对一(如demo.c中只有一个pr_debug或者dev_dbg)
29: // 或者多对一(如demo.c中有多个pr_debug或者dev_dbg)的关系,一个文件对应一个modname,
30: // 这些modname相同的descriptor在__verbose中是连续存放的)分配一个struct ddebug_table,
31: // 然后将其存放到全局变量ddebug_tables中,这里的n表示modname相同的descriptor的个数
32: ret = ddebug_add_module(iter_start, n, modname);
33: if (ret)
34: goto out_err;
35: n = 0;
36: modname = iter->modname;
37: iter_start = iter;
38: }
39: n++;
40: }
41: ret = ddebug_add_module(iter_start, n, modname);
42: if (ret)
43: goto out_err;
44:
45: ddebug_init_success = 1;
46: vpr_info("%d modules, %d entries and %d bytes in ddebug tables, %d bytes in (readonly) verbose section\n",
47: modct, entries, (int)(modct * sizeof(struct ddebug_table)),
48: verbose_bytes + (int)(__stop___verbose - __start___verbose));
49:
50: /* apply ddebug_query boot param, dont unload tables on err */
51: // 如在bootargs中设置了ddebug_query="file unwind.c +p",那么ddebug_setup_string数组中存放的就是"file unwind.c +p"
52: // 这个用于处理系统boot过程中的pr_debug或者pr_dev的打印
53: if (ddebug_setup_string[0] != '\0') {
54: pr_warn("ddebug_query param name is deprecated, change it to dyndbg\n");
55: // 处理"file unwind.c +p"
56: ret = ddebug_exec_queries(ddebug_setup_string, NULL);
57: if (ret < 0)
58: pr_warn("Invalid ddebug boot param %s\n",
59: ddebug_setup_string);
60: else
61: pr_info("%d changes by ddebug_query\n", ret);
62: }
63: /* now that ddebug tables are loaded, process all boot args
64: * again to find and activate queries given in dyndbg params.
65: * While this has already been done for known boot params, it
66: * ignored the unknown ones (dyndbg in particular). Reusing
67: * parse_args avoids ad-hoc parsing. This will also attempt
68: * to activate queries for not-yet-loaded modules, which is
69: * slightly noisy if verbose, but harmless.
70: */
71: // 解析bootargs中的参数如有个module的名字是modname是unwind,那么可以是 bootargs 中包含 unwind.dyndbg
72: cmdline = kstrdup(saved_command_line, GFP_KERNEL);
73: parse_args("dyndbg params", cmdline, NULL,
74: 0, 0, 0, &ddebug_dyndbg_boot_param_cb);
75: kfree(cmdline);
76: return 0;
77:
78: out_err:
79: ddebug_remove_all_tables();
80: return 0;
81: }
82: /* Allow early initialization for boot messages via boot param */
83: early_initcall(dynamic_debug_init);
第32行的n的含义也可以理解为demo.c中pr_debug和dev_dbg的个数;
ddebug_add_module:
1: int ddebug_add_module(struct _ddebug *tab, unsigned int n,
2: const char *name)
3: {
4: struct ddebug_table *dt;
5: char *new_name;
6:
7: dt = kzalloc(sizeof(*dt), GFP_KERNEL);
8: if (dt == NULL)
9: return -ENOMEM;
10: new_name = kstrdup(name, GFP_KERNEL);
11: if (new_name == NULL) {
12: kfree(dt);
13: return -ENOMEM;
14: }
15: dt->mod_name = new_name;
16: dt->num_ddebugs = n;
17: dt->ddebugs = tab;
18:
19: mutex_lock(&ddebug_lock);
20: list_add_tail(&dt->link, &ddebug_tables);
21: mutex_unlock(&ddebug_lock);
22:
23: vpr_info("%u debug prints in module %s\n", n, dt->mod_name);
24: return 0;
25: }
第16行的num_ddebugs表示modname相同的descriptor的个数,将来在ddebug_change中会依次索引,这里只需要存放这些descriptor中的第一个;
接下来分析一下数组ddebug_setup_string的赋值:
/lib/dynamic_debug.c
1: #define DDEBUG_STRING_SIZE 1024
2: static __initdata char ddebug_setup_string[DDEBUG_STRING_SIZE];
3:
4: static __init int ddebug_setup_query(char *str)
5: {
6: if (strlen(str) >= DDEBUG_STRING_SIZE) {
7: pr_warn("ddebug boot param string too large\n");
8: return 0;
9: }
10: strlcpy(ddebug_setup_string, str, DDEBUG_STRING_SIZE);
11: return 1;
12: }
13:
14: __setup("ddebug_query=", ddebug_setup_query);
第14行代码表示的意思是如果cmdline(也就是u-boot传给kernel的参数)中如果有ddebug_query=”file demo.c +p”的部分,那么在kernel启动的时候就会调用函数ddebug_setup_query,然后将”file demo.c +p”拷贝到这个ddebug_setup_debug数组中。
ddebug_exec_queries:
1: /* handle multiple queries in query string, continue on error, return
2: last error or number of matching callsites. Module name is either
3: in param (for boot arg) or perhaps in query string.
4: */
5: // 我们以query指向的缓冲区内容是"file demo.c +p"为例, modname是NULL
6: static int ddebug_exec_queries(char *query, const char *modname)
7: {
8: char *split;
9: int i, errs = 0, exitcode = 0, rc, nfound = 0;
10:
11: for (i = 0; query; query = split) {
12: split = strpbrk(query, ";\n"); // NULL
13: if (split)
14: *split++ = '\0';
15:
16: query = skip_spaces(query);
17: if (!query || !*query || *query == '#')
18: continue;
19:
20: vpr_info("query %d: \"%s\"\n", i, query);
21:
22: // query指向"file demo.c +p",modname是NULL, 如果找到匹配项并设置成功返回值大于0
23: rc = ddebug_exec_query(query, modname);
24: if (rc < 0) {
25: errs++;
26: exitcode = rc;
27: } else {
28: nfound += rc;
29: }
30: i++;
31: }
32: vpr_info("processed %d queries, with %d matches, %d errs\n",
33: i, nfound, errs);
34:
35: if (exitcode)
36: return exitcode;
37: return nfound;
38: }
ddebug_exec_query:
1: static int ddebug_exec_query(char *query_string, const char *modname)
2: {
3: unsigned int flags = 0, mask = 0;
4: struct ddebug_query query;
5: #define MAXWORDS 9
6: int nwords, nfound;
7: char *words[MAXWORDS];
8:
9: // 这个函数完成的功能是以空格为分隔符,对query_string进行分割,然后将分割出来的
10: // 每个项的首地址存放到words中,即words每个元素指向分割出来的一项,返回值是项数
11: // 对于我们的例子就是:
12: // words[0] --- "file"
13: // words[1] --- "demo.c"
14: // words[2] --- "+p"
15: // nwords的值是3
16: nwords = ddebug_tokenize(query_string, words, MAXWORDS);
17: if (nwords <= 0) {
18: pr_err("tokenize failed\n");
19: return -EINVAL;
20: }
21: /* check flags 1st (last arg) so query is pairs of spec,val */
22: // 解析"+p",然后据此给flags和mask赋值
23: // +p 对应的是 flags |= _DPRINTK_FLAGS_PRINT, mask是~0U
24: // -p 对应的是 flags = 0 mask = ~_DPRINTK_FLAGS_PRINT
25: if (ddebug_parse_flags(words[nwords-1], &flags, &mask)) {
26: pr_err("flags parse failed\n");
27: return -EINVAL;
28: }
29:
30: // 解析 "file" 和 "demo.c",并给query赋值
31: // query->filename 就是 "demo.c"
32: if (ddebug_parse_query(words, nwords-1, &query, modname)) {
33: pr_err("query parse failed\n");
34: return -EINVAL;
35: }
36:
37: /* actually go and implement the change */
38: // 改变demo.c中的pr_debug或者dev_dbg对应的descriptor的flags的值
39: nfound = ddebug_change(&query, flags, mask);
40: vpr_info_dq(&query, nfound ? "applied" : "no-match");
41:
42: return nfound;
43: }
ddebug_tokenize:
1: /*
2: * Split the buffer `buf' into space-separated words.
3: * Handles simple " and ' quoting, i.e. without nested,
4: * embedded or escaped \". Return the number of words
5: * or <0 on error.
6: */
7: static int ddebug_tokenize(char *buf, char *words[], int maxwords)
8: {
9: int nwords = 0;
10:
11: while (*buf) {
12: char *end;
13:
14: /* Skip leading whitespace */
15: buf = skip_spaces(buf);
16: if (!*buf)
17: break; /* oh, it was trailing whitespace */
18: if (*buf == '#')
19: break; /* token starts comment, skip rest of line */
20:
21: /* find `end' of word, whitespace separated or quoted */
22: if (*buf == '"' || *buf == '\'') {
23: int quote = *buf++;
24: for (end = buf; *end && *end != quote; end++)
25: ;
26: if (!*end) {
27: pr_err("unclosed quote: %s\n", buf);
28: return -EINVAL; /* unclosed quote */
29: }
30: } else {
31: for (end = buf; *end && !isspace(*end); end++)
32: ;
33: BUG_ON(end == buf);
34: }
35:
36: /* `buf' is start of word, `end' is one past its end */
37: if (nwords == maxwords) {
38: pr_err("too many words, legal max <=%d\n", maxwords);
39: return -EINVAL; /* ran out of words[] before bytes */
40: }
41: if (*end)
42: *end++ = '\0'; /* terminate the word */
43: words[nwords++] = buf;
44: buf = end;
45: }
46:
47: if (verbose) {
48: int i;
49: pr_info("split into words:");
50: for (i = 0; i < nwords; i++)
51: pr_cont(" \"%s\"", words[i]);
52: pr_cont("\n");
53: }
54:
55: return nwords;
56: }
ddebug_parse_flags:
1: static struct { unsigned flag:8; char opt_char; } opt_array[] = {
2: { _DPRINTK_FLAGS_PRINT, 'p' },
3: { _DPRINTK_FLAGS_INCL_MODNAME, 'm' },
4: { _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' },
5: { _DPRINTK_FLAGS_INCL_LINENO, 'l' },
6: { _DPRINTK_FLAGS_INCL_TID, 't' },
7: { _DPRINTK_FLAGS_NONE, '_' },
8: };
9:
10:
11: /*
12: * Parse `str' as a flags specification, format [-+=][p]+.
13: * Sets up *maskp and *flagsp to be used when changing the
14: * flags fields of matched _ddebug's. Returns 0 on success
15: * or <0 on error.
16: */
17: static int ddebug_parse_flags(const char *str, unsigned int *flagsp,
18: unsigned int *maskp)
19: {
20: unsigned flags = 0;
21: int op = '=', i;
22:
23: switch (*str) {
24: case '+':
25: case '-':
26: case '=':
27: op = *str++;
28: break;
29: default:
30: pr_err("bad flag-op %c, at start of %s\n", *str, str);
31: return -EINVAL;
32: }
33: vpr_info("op='%c'\n", op);
34:
35: for (; *str ; ++str) {
36: for (i = ARRAY_SIZE(opt_array) - 1; i >= 0; i--) {
37: if (*str == opt_array[i].opt_char) {
38: flags |= opt_array[i].flag;
39: break;
40: }
41: }
42: if (i < 0) {
43: pr_err("unknown flag '%c' in \"%s\"\n", *str, str);
44: return -EINVAL;
45: }
46: }
47: vpr_info("flags=0x%x\n", flags);
48:
49: /* calculate final *flagsp, *maskp according to mask and op */
50: switch (op) {
51: case '=':
52: *maskp = 0;
53: *flagsp = flags;
54: break;
55: case '+':
56: *maskp = ~0U;
57: *flagsp = flags;
58: break;
59: case '-':
60: *maskp = ~flags;
61: *flagsp = 0;
62: break;
63: }
64: vpr_info("*flagsp=0x%x *maskp=0x%x\n", *flagsp, *maskp);
65: return 0;
66: }
这个函数用于解析"+p",他的含义是是否可以打印。此外,这里还可以是"+pmfl",这个参数打印的是最全的。如果要打印"+p"一定是要有的,"fmlt"可以根据需要任选。
其中, m 表示把模块名也打印出来;
f 表示把调用pr_debug的函数名也打印出来;
l 表示把pr_debug的行号也打印出来;
t 表示把进程号打印出来;
如下所示:
ddebug_parse_query:
1: /*
2: * Parse words[] as a ddebug query specification, which is a series
3: * of (keyword, value) pairs chosen from these possibilities:
4: *
5: * func <function-name>
6: * file <full-pathname>
7: * file <base-filename>
8: * module <module-name>
9: * format <escaped-string-to-find-in-format>
10: * line <lineno>
11: * line <first-lineno>-<last-lineno> // where either may be empty
12: *
13: * Only 1 of each type is allowed.
14: * Returns 0 on success, <0 on error.
15: */
16: static int ddebug_parse_query(char *words[], int nwords,
17: struct ddebug_query *query, const char *modname)
18: {
19: unsigned int i;
20: int rc = 0;
21:
22: /* check we have an even number of words */
23: if (nwords % 2 != 0) {
24: pr_err("expecting pairs of match-spec <value>\n");
25: return -EINVAL;
26: }
27: memset(query, 0, sizeof(*query));
28:
29: if (modname)
30: /* support $modname.dyndbg=<multiple queries> */
31: query->module = modname;
32:
33: for (i = 0; i < nwords; i += 2) {
34: if (!strcmp(words[i], "func")) {
35: rc = check_set(&query->function, words[i+1], "func");
36: } else if (!strcmp(words[i], "file")) {
37: rc = check_set(&query->filename, words[i+1], "file");
38: } else if (!strcmp(words[i], "module")) {
39: rc = check_set(&query->module, words[i+1], "module");
40: } else if (!strcmp(words[i], "format")) {
41: string_unescape_inplace(words[i+1], UNESCAPE_SPACE |
42: UNESCAPE_OCTAL |
43: UNESCAPE_SPECIAL);
44: rc = check_set(&query->format, words[i+1], "format");
45: } else if (!strcmp(words[i], "line")) {
46: char *first = words[i+1];
47: char *last = strchr(first, '-');
48: if (query->first_lineno || query->last_lineno) {
49: pr_err("match-spec: line used 2x\n");
50: return -EINVAL;
51: }
52: if (last)
53: *last++ = '\0';
54: if (parse_lineno(first, &query->first_lineno) < 0)
55: return -EINVAL;
56: if (last) {
57: /* range <first>-<last> */
58: if (parse_lineno(last, &query->last_lineno) < 0)
59: return -EINVAL;
60:
61: if (query->last_lineno < query->first_lineno) {
62: pr_err("last-line:%d < 1st-line:%d\n",
63: query->last_lineno,
64: query->first_lineno);
65: return -EINVAL;
66: }
67: } else {
68: query->last_lineno = query->first_lineno;
69: }
70: } else {
71: pr_err("unknown keyword \"%s\"\n", words[i]);
72: return -EINVAL;
73: }
74: if (rc)
75: return rc;
76: }
77: vpr_info_dq(query, "parsed");
78: return 0;
79: }
这个函数用于解析"file" "demo.c",然后构造出一个过滤器query,对于这个例子,将来query->filename会赋值为"demo.c".如果在bootargs中设置了demo.dyndbg="func xxx",表示打印模块demo中函数xxx中的pr_debug或者dev_dbg,此时query->function会被赋值为"xxx".当然也可以使用echo -n 'file demo.c line 1603 +p' > /sys/kernel/debug/dynamic_debug/control,其中:
words[0] --- "file"
words[1] --- "demo.c"
words[2] --- "line"
words[3] --- "1603"
words[4] --- "+p"
表示打印文件demo.c中第1603行的pr_debug或者dev_dbg.
ddebug_change:
1: /*
2: * Search the tables for _ddebug's which match the given `query' and
3: * apply the `flags' and `mask' to them. Returns number of matching
4: * callsites, normally the same as number of changes. If verbose,
5: * logs the changes. Takes ddebug_lock.
6: */
7: static int ddebug_change(const struct ddebug_query *query,
8: unsigned int flags, unsigned int mask)
9: {
10: int i;
11: struct ddebug_table *dt;
12: unsigned int newflags;
13: unsigned int nfound = 0;
14: char flagbuf[10];
15:
16: /* search for matching ddebugs */
17: mutex_lock(&ddebug_lock);
18: list_for_each_entry(dt, &ddebug_tables, link) {
19:
20: /* match against the module name */
21: // match_wildcard 如果匹配成功返回true
22: if (query->module &&
23: !match_wildcard(query->module, dt->mod_name))
24: continue;
25:
26: for (i = 0; i < dt->num_ddebugs; i++) {
27: struct _ddebug *dp = &dt->ddebugs[i]; // modname相同的descriptor是连续存放的
28:
29: /* match against the source filename */
30: if (query->filename &&
31: !match_wildcard(query->filename, dp->filename) &&
32: !match_wildcard(query->filename,
33: kbasename(dp->filename)) &&
34: !match_wildcard(query->filename,
35: trim_prefix(dp->filename)))
36: continue;
37:
38: /* match against the function */
39: if (query->function &&
40: !match_wildcard(query->function, dp->function))
41: continue;
42:
43: /* match against the format */
44: if (query->format &&
45: !strstr(dp->format, query->format))
46: continue;
47:
48: /* match against the line number range */
49: if (query->first_lineno &&
50: dp->lineno < query->first_lineno)
51: continue;
52: if (query->last_lineno &&
53: dp->lineno > query->last_lineno)
54: continue;
55:
56: nfound++; // 找到了匹配项
57:
58: newflags = (dp->flags & mask) | flags; // 赋值
59: if (newflags == dp->flags)
60: continue;
61: dp->flags = newflags; // 将descriptor的flags修改成新的值,在打印是会判断
62: vpr_info("changed %s:%d [%s]%s =%s\n",
63: trim_prefix(dp->filename), dp->lineno,
64: dt->mod_name, dp->function,
65: ddebug_describe_flags(dp, flagbuf,
66: sizeof(flagbuf)));
67: }
68: }
69: mutex_unlock(&ddebug_lock);
70:
71: if (!nfound && verbose)
72: pr_info("no matches for query\n");
73:
74: return nfound;
75: }
函数match_wildcard支持通配符匹配,比如我想打印文件demo_driver.c中的pr_debug,那么我可以这样来:
1 | echo -n "file demo_dri* +p" > /sys/kernel/debug/dynamic_debug/control |
上面query可以认为是过滤器,如果以上面的demo_driver.c为例,那么"file demo_driver.c +p",最后的处理结果是将demo_driver.c中所有的pr_debug和dev_dbg对应的descriptor的flags的值都设置为_DPRINTK_FLAGS_PRINT,那么就可以打印出来了。
match_wildcard:
1: /**
2: * match_wildcard: - parse if a string matches given wildcard pattern
3: * @pattern: wildcard pattern
4: * @str: the string to be parsed
5: *
6: * Description: Parse the string @str to check if matches wildcard
7: * pattern @pattern. The pattern may contain two type wildcardes:
8: * '*' - matches zero or more characters
9: * '?' - matches one character
10: * If it's matched, return true, else return false.
11: */
12: bool match_wildcard(const char *pattern, const char *str)
13: {
14: const char *s = str;
15: const char *p = pattern;
16: bool star = false;
17:
18: while (*s) {
19: switch (*p) {
20: case '?':
21: s++;
22: p++;
23: break;
24: case '*':
25: star = true;
26: str = s;
27: if (!*++p)
28: return true;
29: pattern = p;
30: break;
31: default:
32: if (*s == *p) {
33: s++;
34: p++;
35: } else {
36: if (!star)
37: return false;
38: str++;
39: s = str;
40: p = pattern;
41: }
42: break;
43: }
44: }
45:
46: if (*p == '*')
47: ++p;
48: return !*p;
49: }
下面是如果在bootargs中设置了诸如”demo.dyndbg”或者”demo.dyndbg=+/-p”或者"demo.dyndbg="func xxx_write line 10 +p""那么下面的这个函数就会在执行parse_args的时候被调用
ddebug_dyndbg_param_cb:
1: 如在bootargs中设置了: demo.dyndbg 或者 demo.dyndbg=+p,那么demo.c的pr_debug就会打开
2:
3: /* handle both dyndbg and $module.dyndbg params at boot */
4: static int ddebug_dyndbg_boot_param_cb(char *param, char *val,
5: const char *unused)
6: {
7: vpr_info("%s=\"%s\"\n", param, val);
8: return ddebug_dyndbg_param_cb(param, val, NULL, 0);
9: }
10:
11: /* helper for ddebug_dyndbg_(boot|module)_param_cb */
12: static int ddebug_dyndbg_param_cb(char *param, char *val,
13: const char *modname, int on_err)
14: {
15: char *sep;
16:
17: sep = strchr(param, '.');
18: if (sep) {
19: /* needed only for ddebug_dyndbg_boot_param_cb */
20: *sep = '\0';
21: modname = param;
22: param = sep + 1;
23: }
24: if (strcmp(param, "dyndbg"))
25: return on_err; /* determined by caller */
26: // 如果val是空的话(即只有demo.dyndbg),默认打开pr_debug
27: ddebug_exec_queries((val ? val : "+p"), modname);
28:
29: return 0; /* query failure shouldnt stop module load */
30: }
31:
先分析到这里,接下请看下一篇博客,主要分析一下:
echo –n “file demo.c +p”> /sys/kernel/debug/dynamic_debug/control 的原理。
==========================================================================================
转载:http://blog.csdn.net/pillarbuaa/article/details/7634546
dynamic debug log输出机制
0. 注意该机制只对 dev_dbg -> dynamic_dev_dbg 定义的debug log输出加以控制
1. 如何使用:(kernel/Documentation/dynamic-debug-howto.txt)
mkdir /data/debugfs
mount -t debugfs none /data/debugfs
echo -n 'file ab8500_fg.c +p' > /data/debugfs/dynamic_debug/control //增加该文件dynamic debug的输出
echo -n 'file ab8500_fg.c -p' > /data/debugfs/dynamic_debug/control //去掉该文件dynamic debug的输出
2. 如果想使用debugfs 必须,在kernel的config文件(kernel/arch/arm/configs/semc_lotus_deconfig)中有
CONFIG_DEBUG_FS=y
3. 如果需要使用Dynamic debug机制,需要在kernel的config文件(kernel/arch/arm/configs/semc_lotus_deconfig)中有
CONFIG_DYNAMIC_DEBUG=y
4. dev_dbg@kernel/include/linux/device.h ->dynamic_dev_dbg@kernel/include/linux/dynamic_debug.h
#define dynamic_dev_dbg(dev, fmt, ...) do { \
static struct _ddebug descriptor \
__used \
__attribute__((section("__verbose"), aligned(8))) = \
{ KBUILD_MODNAME, __func__, __FILE__, fmt, DEBUG_HASH, \
DEBUG_HASH2, __LINE__, _DPRINTK_FLAGS_DEFAULT }; \
if (__dynamic_dbg_enabled(descriptor)) \
dev_printk(KERN_DEBUG, dev, fmt, ##__VA_ARGS__); \
} while (0)
a. 该define 最终会展开在被调用dev_dbg函数的c文件中,也就是KBUILD_MODNAME, __func__, __FILE__, __LINE__ 会有对应的字符串
b. _DPRINTK_FLAGS_DEFAULT=0;
c. DEBUG_HASH和DEBUG_HASH2的定义在kernel/scripts/makefile.lib中
DEBUG_HASH=
DEBUG_HASH2=
d. 分析 kernel/scripts/basic/hash.c,会生成out/target/product/lotus/obj/kernel/scripts/basic/hash, shell可执行文件
e. 在编译连接完成后,该 descriptor 值会被保存到 data section的 __verbose区
5. dynamic_debug_init@kernel/lib/dynamic_debug.c
a. dir = debugfs_create_dir("dynamic_debug", NULL);
b. file = debugfs_create_file("control", 0644, dir, NULL, &ddebug_proc_fops); //在debugfs文件系统中创建dynamic_debug/control 文件
c. 通过__start___verbose和__stop___verbose@kernel/include/asm-generic/vmlinux.lds.h中,实际上是获取保存在__verbose区的 struct _ddebug 数据(就是前面编译后添加到data section的__verbose)
d. 如果是不同的modname,就添加到ddebug_tables 中,也就是所有dynamic_dev_dbg的模块(modname),文件(__FILE__),行(__LINE__),函数(__func__),是否输出的flag,对应的hash value都会逐条保存到ddebug_tables中
6. 分析 echo -n 'file ab8500_charger.c +p' > /data/debugfs/dynamic_debug/control 的实际操作
a. 通过system call,debugfs文件系统会调用到ddebug_proc_write,ddebug_parse_query和ddebug_parse_flags@kernel/lib/dynamic_debug.c分析传入的参数字符串
b. 在ddebug_change@kernel/lib/dynamic_debug.c中,会根据modname, __FILE__, __LINE__, __func__信息在ddebug_tables找到对应的item.
c. 然后根据输入的是 +p或-p ,来标志struct _ddebug中flag字段,还有根据struct _ddebug中的primary_hash和secondary_hash,来标志global value dynamic_debug_enabled和dynamic_debug_enabled2 对应的位,会在__dynamic_dbg_enabled@kernel/include/linux/dynamic_debug.h用到
7. 分析 #cat /data/debugfs/dynamic_debug/control的实际操作
a. 先ddebug_proc_open中有err = seq_open(file, &ddebug_proc_seqops);应用了seq file的读写机制
b. 然后seq_read,利用seq file机制逐个读出和显示ddebug_tables中的内容
8. long long dynamic_debug_enabled和dynamic_debug_enabled2@kernel/lib/dynamic_debugc,用于标志某个mod(可包含一个或多个文件,比如ab8500_fg mod,目前只包含ab8500_fg.c file)是否可以输出debug log的模块. 最多可以标志64*64=4096个dev_debug/dynamic_dev_dbg.
9. 是否输出dev_log/dynamic_dev_dbg的log, 关键是如下判断,@kernel/include/linux/dynamic_debug.h
#define __dynamic_dbg_enabled(dd) ({ \
int __ret = 0; \
if (unlikely((dynamic_debug_enabled & (1LL << DEBUG_HASH)) && \
(dynamic_debug_enabled2 & (1LL << DEBUG_HASH2)))) \
if (unlikely(dd.flags)) \
__ret = 1; \
__ret; })
a. dynamic_debug_enabled和dynamic_debug_enabled2就是前面分析的是否输出该modname的两个long long的组合标志位
b. DEBUG_HASH和DEBUG_HASH2 如前面所解释
c. dd.flag 默认为_DPRINTK_FLAGS_DEFAULT,但通过debugfs文件系统,最终操作ddebug_proc_write函数,会设置为_DPRINTK_FLAGS_PRIN或_DPRINTK_FLAGS_DEFAULT
10. debugfs 文件系统中的内容保存在那?????内存中,类似proc
11. 小结:如果你需要用到dynamic debug info, 你需要在你的 .c 文件中查看是否用到了dev_log 输出log。