pr_debug、dev_dbg等动态调试一

时间:2022-05-14 03:29:50

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 表示把进程号打印出来;

如下所示:

pr_debug、dev_dbg等动态调试一

 

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= (shell./scripts/basic/hashdjb2 (@D)$(modname))   //利用djb2 hash算法,计算modname的DEBUG_HASH value;

                                DEBUG_HASH2= (shell./scripts/basic/hashr5 (@D)$(modname))         //利用r5 hash算法,计算modname的DEBUG_HASH2 value;

                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。