pr_debug、dev_dbg等动态调试二

内核版本：Linux-3.14

作者：彭东林

邮箱：pengdonglin137@163.com

下面我们简要分析

[code] echo -n "file demo.c +p" > /sys/kernel/debug/dynamic_debug/control

[/code]

的实现。

首先看一下dynamic_dedbg/control是如何生成的？

代码位置 lib/dynamic_debug.c

[code] static int __init dynamic_debug_init_debugfs(void)

{

struct dentry *dir, *file;

 if (!ddebug_init_success)

 return -ENODEV;

 dir = debugfs_create_dir("dynamic_debug", NULL);

 if (!dir)

 return -ENOMEM;

 file = debugfs_create_file("control", 0644, dir, NULL,

 &ddebug_proc_fops);

 if (!file){

 debugfs_remove(dir);

 return -ENOMEM;

}

 return 0;

}

fs_initcall(dynamic_debug_init_debugfs);

[/code]

这个函数会在kernel启动的时候执行，在/sys/kernel/debug下创建目录dynamic_debug，然后在dynamic_debug下面创建control节点，并将这个节点的操作函数集设置为ddebug_proc_fops。

[code] static const struct file_operations ddebug_proc_fops ={

 .owner = THIS_MODULE,

 .open = ddebug_proc_open,

 .read = seq_read,

 .llseek = seq_lseek,

 .release = seq_release_private,

 .write = ddebug_proc_write

};

[/code]

这里涉及到了顺序文件seq_file，关于这部分知识可以参考：

序列文件(seq_file)接口

这里我们需要看一下ddebug_proc_open：

[code] /*

* File_ops->open method for <debugfs>/dynamic_debug/control.Does

* the seq_file setup dance, and also creates an iterator to walk the

* _ddebugs.Note that we create a seq_file always, even for O_WRONLY

* files where it's not needed, as doing so simplifies the ->release

* method.

*/

static int ddebug_proc_open(struct inode *inode, struct file *file)

{

 struct ddebug_iter *iter;

 int err;

 vpr_info("called\n");

 iter = kzalloc(sizeof(*iter), GFP_KERNEL);

 if (iter == NULL)

 return -ENOMEM;

 err = seq_open(file, &ddebug_proc_seqops);

 if (err){

 kfree(iter);

 return err;

}

 ((struct seq_file *)file->private_data)->private = iter;

 return 0;

}

[/code]

其中：

[code] static const struct seq_operations ddebug_proc_seqops ={

 .start = ddebug_proc_start,

 .next = ddebug_proc_next,

 .show = ddebug_proc_show,

 .stop = ddebug_proc_stop

};

[/code]

从上面的代码可以看出，我们需要分析的函数主要是ddebug_proc_seqops中的以及ddebug_proc_write。

其中，对于 echo –n “file demo.c +p”> /sys/kernel/debug/dynamic_debug/control来说，函数调用：ddebug_proc_open ---> ddebug_proc_write

下面我们一个一个看。

ddebug_proc_write:

[code] /*

* File_ops->write method for <debugfs>/dynamic_debug/conrol.Gathers the

* command text from userspace, parses and executes it.

*/

#define USER_BUF_PAGE 4096

static ssize_t ddebug_proc_write(struct file *file, const char __user *ubuf,

 size_t len, loff_t *offp)

{

 char *tmpbuf;

 int ret;

 if (len == 0)

 return 0;

 if (len > USER_BUF_PAGE - 1){

 pr_warn("expected <%d bytes into control\n", USER_BUF_PAGE);

 return -E2BIG;

}

 tmpbuf = kmalloc(len + 1, GFP_KERNEL);

 if (!tmpbuf)

 return -ENOMEM;

 if (copy_from_user(tmpbuf, ubuf, len)){

 kfree(tmpbuf);

 return -EFAULT;

}

 tmpbuf[len] = '\0';

 vpr_info("read %d bytes from userspace\n", (int)len);

 ret = ddebug_exec_queries(tmpbuf, NULL);

 kfree(tmpbuf);

 if (ret < 0)

 return ret;

 *offp += len;

 return len;

}

[/code]

如果以 echo –n “file demo.c +p” > /sys/kernel/debug/dynamic_debug/control 为例：

上面的代码第28行传给ddebug_exec_queries的参数tembuf中存放的就是 “file demo.c +p”，函数ddebug_exec_queries的分析在上一篇博客中已经分析过了。

此外，如何查看某个文件中pr_debug或者dev_dbg的设置情况呢？

[code] [root@TQ2440 /]# cat /sys/kernel/debug/dynamic_debug/control

# filename:lineno [module]function flags format

 init/main.c:679 [main]do_one_initcall_debug =p "calling%pF @ %i\012"

init/main.c:686 [main]do_one_initcall_debug =p "initcall %pF returned %d after %lld usecs\012"

arch/arm/kernel/unwind.c:162 [unwind]unwind_find_origin =_ "%s(%p, %p)\012"

arch/arm/kernel/unwind.c:173 [unwind]unwind_find_origin =_ "%s -> %p\012"

arch/arm/kernel/unwind.c:461 [unwind]unwind_table_add =_ "%s(%08lx, %08lx, %08lx, %08lx)\012"

arch/arm/kernel/unwind.c:117 [unwind]search_index =_ "%s(%08lx, %p, %p, %p)\012"

arch/arm/kernel/unwind.c:341 [unwind]unwind_frame =_ "%s(pc = %08lx lr = %08lx sp = %08lx)\012"

arch/arm/kernel/unwind.c:182 [unwind]unwind_find_idx =_ "%s(%08lx)\012"

......

[/code]

上面每一行对应的就是一个pr_debug或者dev_dbg，以第5行为例

[code]arch/arm/kernel/unwind.c:162 [unwind]unwind_find_origin =_ "%s(%p, %p)\012"

[/code]

表示在文件unwind.c的第162行，modname是unwind，function是unwind_find_origin，”=_”表示不打印， 最后一个表示的是pr_debug要打印的内容。

如果执行

[code]echo -n "file unwind.c +pfmlt" > /sys/kernel/debug/dynamic_debug/control

[/code]

然后再次执行

[code]cat /sys/kernel/debug/dynamic_debug/control | grep “unwind.c:162”

[/code]

得到的结果就是：

[code]arch/arm/kernel/unwind.c:162 [unwind]unwind_find_origin =pmflt "%s(%p, %p)\012"

[/code]

然后我们分析一下 cat /sys/kernel/debug/dynamic_debug/control 的函数调用：

ddebug_proc_open ---> seq_read，在seq_read中又依次调用了ddebug_proc_seqops中的：

ddebug_proc_start/ddebug_proc_next/ddebug_proc_show/ddebug_proc_stop函数。

ddebug_proc_start：

[code] /*

* Seq_ops start method.Called at the start of every

* read() call from userspace.Takes the ddebug_lock and

* seeks the seq_file's iterator to the given position.

*/

static void *ddebug_proc_start(struct seq_file *m, loff_t *pos)

{

 struct ddebug_iter *iter = m->private;

 struct _ddebug *dp;

 int n = *pos;

 vpr_info("called m=%p *pos=%lld\n", m, (unsigned long long)*pos);

 mutex_lock(&ddebug_lock);

 if (!n)

 return SEQ_START_TOKEN;

 if (n < 0)

 return NULL;

 dp = ddebug_iter_first(iter);

 while (dp != NULL && --n > 0)

 dp = ddebug_iter_next(iter);

 return dp;

}

[/code]

第8行中的iter指向的内存是在ddebug_proc_open中调用kzalloc分配的。

第20行函数的目的是获取ddebug_tables中的第一项

ddebug_iter_first:

[code] /*

* Set the iterator to point to the first _ddebug object

* and return a pointer to that first object.Returns

* NULL if there are no _ddebugs at all.

*/

static struct _ddebug *ddebug_iter_first(struct ddebug_iter *iter)

{

 if (list_empty(&ddebug_tables)){

 iter->table = NULL;

 iter->idx = 0;

 return NULL;

}

 iter->table = list_entry(ddebug_tables.next,

struct ddebug_table, link);

 iter->idx = 0;

 return &iter->table->ddebugs[iter->idx];

}

[/code]

这里ddebug_tables是在解析__verbose段的时候填充，这里是获取第一项；注意这里每个文件中的pr_debug和dev_dbg的modname都相同，也就是文件名，每个modname在ddebug_tables中只有一项，每个ddebug_table中的ddebugs指向了模块名为modname的descriptor的第一个，因为这些descriptor在内存中是连续存放的，所以通过ddebugs就可索引了，个数是num_ddebugs.

ddebug_iter_next:

[code] /*

* Advance the iterator to point to the next _ddebug

* object from the one the iterator currently points at,

* and returns a pointer to the new _ddebug.Returns

* NULL if the iterator has seen all the _ddebugs.

*/

static struct _ddebug *ddebug_iter_next(struct ddebug_iter *iter)

{

 if (iter->table == NULL)

 return NULL;

 if (++iter->idx == iter->table->num_ddebugs){

 /* iterate to next table */

 iter->idx = 0;

 if (list_is_last(&iter->table->link, &ddebug_tables)){

 iter->table = NULL;

 return NULL;

}

 iter->table = list_entry(iter->table->link.next,

struct ddebug_table, link);

}

 return &iter->table->ddebugs[iter->idx];

}

[/code]

ddebug_proc_next:

[code] /*

* Seq_ops next method.Called several times within a read()

* call from userspace, with ddebug_lock held.Walks to the

* next _ddebug object with a special case for the header line.

*/

static void *ddebug_proc_next(struct seq_file *m, void *p, loff_t *pos)

{

 struct ddebug_iter *iter = m->private;

 struct _ddebug *dp;

 vpr_info("called m=%p p=%p *pos=%lld\n",

m, p, (unsigned long long)*pos);

 if (p == SEQ_START_TOKEN)

 dp = ddebug_iter_first(iter);

 else

 dp = ddebug_iter_next(iter);

 ++*pos;

 return dp;

}

[/code]

下面是我画的一张图，大概表示出了ddebug_tables/ddebug_tables/_ddebug的关系：





上面的函数返回的类型是struct _ddebug，用于遍历所有的_ddebug.

ddebug_proc_show:

[code] /*

* Seq_ops show method.Called several times within a read()

* call from userspace, with ddebug_lock held.Formats the

* current _ddebug as a single human-readable line, with a

* special case for the header line.

*/

static int ddebug_proc_show(struct seq_file *m, void *p)

{

 struct ddebug_iter *iter = m->private;

 struct _ddebug *dp = p;

 char flagsbuf[10];

 vpr_info("called m=%p p=%p\n", m, p);

 if (p == SEQ_START_TOKEN){

 seq_puts(m,

"# filename:lineno [module]function flags format\n");

 return 0;

}

 seq_printf(m, "%s:%u [%s]%s =%s \"",

trim_prefix(dp->filename), dp->lineno,

iter->table->mod_name, dp->function,

ddebug_describe_flags(dp, flagsbuf, sizeof(flagsbuf)));

 seq_escape(m, dp->format, "\t\r\n\"");

 seq_puts(m, "\"\n");

 return 0;

}

[/code]

我们最终看到的结果：

[code] [root@TQ2440 /]# cat /sys/kernel/debug/dynamic_debug/control| head -n 10

# filename:lineno [module]function flags format

 init/main.c:679 [main]do_one_initcall_debug =p "calling%pF @ %i\012"

init/main.c:686 [main]do_one_initcall_debug =p "initcall %pF returned %d after %lld usecs\012"

arch/arm/kernel/unwind.c:162 [unwind]unwind_find_origin =_ "%s(%p, %p)\012"

arch/arm/kernel/unwind.c:173 [unwind]unwind_find_origin =_ "%s -> %p\012"

[/code]

上面的内容就是ddebug_proc_show打印出来的。

trim_prefix:

[code] /* Return the path relative to source root */

static inline const char *trim_prefix(const char *path)

{

 int skip = strlen(__FILE__) - strlen("lib/dynamic_debug.c");

 if (strncmp(path, __FILE__, skip))

 skip = 0; /* prefix mismatch, don't skip */

 return path + skip;

}

[/code]

这个函数的目的是将文件名的绝对路径转换为相对路径，相对于kernel源码的根目录。

ddebug_describe_flags:

[code] static struct{ unsigned flag:8; char opt_char;} opt_array[] ={

{ _DPRINTK_FLAGS_PRINT, 'p'},

{ _DPRINTK_FLAGS_INCL_MODNAME, 'm'},

{ _DPRINTK_FLAGS_INCL_FUNCNAME, 'f'},

{ _DPRINTK_FLAGS_INCL_LINENO, 'l'},

{ _DPRINTK_FLAGS_INCL_TID, 't'},

{ _DPRINTK_FLAGS_NONE, '_'},

};

/* format a string into buf[] which describes the _ddebug's flags */

static char *ddebug_describe_flags(struct _ddebug *dp, char *buf,

 size_t maxlen)

{

 char *p = buf;

 int i;

 BUG_ON(maxlen < 6);

 for (i = 0; i < ARRAY_SIZE(opt_array); ++i)

 if (dp->flags & opt_array[i].flag)

 *p++ = opt_array[i].opt_char;

 if (p == buf)

 *p++ = '_';

 *p = '\0';

 return buf;

}

[/code]

这个函数是将flags的值转换为字符串，存放到buf中，并将buf返回。

ddebug_proc_stop:

[code] /*

* Seq_ops stop method.Called at the end of each read()

* call from userspace.Drops ddebug_lock.

*/

static void ddebug_proc_stop(struct seq_file *m, void *p)

{

 vpr_info("called m=%p p=%p\n", m, p);

 mutex_unlock(&ddebug_lock);

}

[/code]

在上一篇博客中pr_debug展开结果：

[code] do{

 static struct _ddebug__aligned(8)\

 __attribute__((section("__verbose"))) descriptor ={\

 .modname = KBUILD_MODNAME,\

 .function = __func__,\

 .filename = __FILE__,\

 .format = (fmt),\

 .lineno = __LINE__,\

 .flags =_DPRINTK_FLAGS_DEFAULT,\

}

 if (unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT))\

 __dynamic_pr_debug(&descriptor, fmt,\

##__VA_ARGS__);\

} while (0)

[/code]

第11行就是判断descriptor.flags的值，看是否能够打印。

__dynamic_pr_debug:

[code] int __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)

{

 va_list args;

 int res;

 struct va_format vaf;

 char buf[PREFIX_SIZE];

 BUG_ON(!descriptor);

 BUG_ON(!fmt);

 va_start(args, fmt);

 vaf.fmt = fmt;

 vaf.va = &args;

 res = printk(KERN_DEBUG "%s%pV",

dynamic_emit_prefix(descriptor, buf), &vaf);

 va_end(args);

 return res;

}

[/code]

dynamic_emit_prefix:

[code] static char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf)

{

 int pos_after_tid;

 int pos = 0;

 *buf = '\0';

 if (desc->flags & _DPRINTK_FLAGS_INCL_TID){

 if (in_interrupt())

 pos += snprintf(buf + pos, remaining(pos), "<intr> ");

 else

 pos += snprintf(buf + pos, remaining(pos), "[%d] ",

 task_pid_vnr(current));

}

 pos_after_tid = pos;

 if (desc->flags & _DPRINTK_FLAGS_INCL_MODNAME)

 pos += snprintf(buf + pos, remaining(pos), "%s:",

 desc->modname);

 if (desc->flags & _DPRINTK_FLAGS_INCL_FUNCNAME)

 pos += snprintf(buf + pos, remaining(pos), "%s:",

 desc->function);

 if (desc->flags & _DPRINTK_FLAGS_INCL_LINENO)

 pos += snprintf(buf + pos, remaining(pos), "%d:",

 desc->lineno);

 if (pos - pos_after_tid)

 pos += snprintf(buf + pos, remaining(pos), " ");

 if (pos >= PREFIX_SIZE)

 buf[PREFIX_SIZE - 1] = '\0';

 return buf;

}

[/code]

这个函数会根据flags（如fmtl）的值向buf中填充内容，然后将buf返回给printk。

先分析到这里，下一篇总结一些开启pr_debug的一些方法。

完。