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,那么我可以这样来:

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

                                DEBUG_HASH2=$(shell ./scripts/basic/hash r5 $(@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。

posted @ 2015-07-05 00:47  摩斯电码  阅读(10728)  评论(0编辑  收藏  举报