dynamic_debug和pr_debug()打印

一、简介

动态打印一般在userdebug版本上使能,运行用户通过命令行决定是否进行打印。需要使能 CONFIG_DYNAMIC_DEBUG。


二、实现

1. pr_debug()定义

//msm-5.4/include/linux/printk.h

/* If you are writing a driver, please use dev_dbg instead */
#if defined(CONFIG_DYNAMIC_DEBUG) || (defined(CONFIG_DYNAMIC_DEBUG_CORE) && defined(DYNAMIC_DEBUG_MODULE))

#include <linux/dynamic_debug.h>

/* 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

/* 虚拟 printk 用于禁用调试语句,同时维护 gcc 的格式检查 */
#define no_printk(fmt, ...)                \
({                            \
    if (0)                        \
        printk(fmt, ##__VA_ARGS__);        \
    0;                        \
})

autoconf.h 中:

#define CONFIG_DYNAMIC_DEBUG 1
#define CONFIG_DYNAMIC_DEBUG_CORE 1

CONFIG_DYNAMIC_DEBUG userdebug版本默认使能,user版本默认关闭。CONFIG_DYNAMIC_DEBUG_CORE 没有直接在deconfig中使能,userdebug版本中应该是被选中的。DYNAMIC_DEBUG_MODULE userdebug版本中也未使能。因此 pr_debug() 选取的是 dynamic_pr_debug().

2. pr_debug()调用路径

pr_debug //printk.h
    dynamic_pr_debug //dynamic_debug.h
        _dynamic_func_call(fmt,    __dynamic_pr_debug, pr_fmt(fmt), ##__VA_ARGS__)

/* 宏定义如下 */
#define _dynamic_func_call(fmt, func, ...)                \
    __dynamic_func_call(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__) //dynamic_debug.h

#define __dynamic_func_call(id, fmt, func, ...) \
do {    \
    DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt);        \
    if (DYNAMIC_DEBUG_BRANCH(id))            \
        func(&id, ##__VA_ARGS__);        \
} while (0)

#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt)        \
    static struct _ddebug  __aligned(8)            \
    __attribute__((section("__verbose"))) name = {        \
        .modname = KBUILD_MODNAME,            \
        .function = __func__,                \
        .filename = __FILE__,                \
        .format = (fmt),                \
        .lineno = __LINE__,                \
        .flags = _DPRINTK_FLAGS_DEFAULT,        \
        _DPRINTK_KEY_INIT                \
    }

/* 若使能 CONFIG_JUMP_LABEL 且没有在文件顶define DEBUG 就是:*/
#define DYNAMIC_DEBUG_BRANCH(descriptor) static_branch_unlikely(&descriptor.key.dd_key_false)
    
_dynamic_func_call 宏展开后如下:

_dynamic_func_call(fmt,    __dynamic_pr_debug, pr_fmt(fmt), ##__VA_ARGS__)
    //名字如 ddebug_proc_show$1255da8810773fe8dadb2f387c74bb12.cfi_jt
    static struct _ddebug  __aligned(8) __attribute__((section("__verbose"))) __UNIQUE_ID(ddebug) = {
        .modname = KBUILD_MODNAME, //是自己的模块名,因为头文件中定义的
        .function = __func__, //函数名
        .filename = __FILE__, //文件名
        .format = (fmt), //打印格式控制
        .lineno = __LINE__, //行号
        .flags = _DPRINTK_FLAGS_DEFAULT,
        .key.dd_key_false = STATIC_KEY_FALSE_INIT
    }

    if (static_branch_unlikely(&__UNIQUE_ID(ddebug).key.dd_key_false))
        __dynamic_pr_debug(&__UNIQUE_ID(ddebug), pr_fmt(fmt), ##__VA_ARGS__);

其中 __dynamic_pr_debug() 实现如下:

void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...) //dynamic_debug.c
{
    va_list args;
    struct va_format vaf;
    char buf[PREFIX_SIZE];

    BUG_ON(!descriptor);
    BUG_ON(!fmt);

    va_start(args, fmt);

    vaf.fmt = fmt;
    vaf.va = &args;

    printk(KERN_DEBUG "%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf);

    va_end(args);
}
EXPORT_SYMBOL(__dynamic_pr_debug);

注意最终是调用 printk(KERN_DEBUG, ...) 进行打印的,因此需要 dmesg -n 8 才能打印出来。

上面定义了一个 struct _ddebug 已经带来了一部分代码执行量。下面判断 struct _ddebug.key.dd_key_false 为真才进行真正的打印,又叠加了打印的工作量 ######。看来这样的打印也只是对决定是否打印带来方便,对性能并不见得有多友好

3. 相关文件接口

列出内核里面使用 pr_debug() 的所有地方:

# cat /sys/kernel/debug/dynamic_debug/control | head -5
# filename:lineno [module]function flags format
init/initramfs.c:477 [initramfs]unpack_to_rootfs =_ "Detected %s compressed data\012"
mm/cma_debug.c:119 [cma_debug]cma_free_mem =_ "cma: cannot release partial block when order_per_bit != 0\012"
fs/binfmt_misc.c:328 [binfmt_misc]create_entry =_ "register: received %zu bytes\012"
fs/binfmt_misc.c:349 [binfmt_misc]create_entry =_ "register: delim: %#x {%c}\012"

# echo "func xxxx_function +p" > /sys/kernel/debug/dynamic_debug/control

上面是打开动态输出语句的例子,在kernel dmesg里面可以看到这个函数里面pr_debug()的打印。

除了能输出 pr_debug()/dev_dbg() 函数中定义的输出外,还能输出一些额外信息,例如函数名、行号、模块名字和线程ID等。
p:打开动态打印语句。
f:打印函数名。
l:打印行号。
m:打印模块名字。
t:打印线程ID。

文件接口调用路径:

cat /sys/kernel/debug/dynamic_debug/control
    ddebug_proc_fops.show //dynamic_debug.c
        ddebug_proc_seqops.ddebug_proc_show //dynamic_debug.c
            seq_puts(m, "# filename:lineno [module]function flags format\n");
            seq_printf(m, "%s:%u [%s]%s =%s \"", trim_prefix(dp->filename), dp->lineno,
                    iter->table->mod_name, dp->function, ddebug_describe_flags(dp->flags, &flags)); //struct _ddebug *dp = p;
            seq_escape(m, dp->format, "\t\r\n\"");

echo xxx > /sys/kernel/debug/dynamic_debug/control
    ddebug_proc_fops.write
        ddebug_proc_write
            memdup_user_nul
                ddebug_exec_queries

 

三、动态打印使用方法

1. 常用操作

// 打开svcsock.c文件中所有动态输出语句
# echo 'file svcsock.c +p' > /sys/kernel/debug/dynamic_debug/control

// 打开usbcore模块所有动态输出语句
# echo 'module usbcore +p' > /sys/kernel/debug/dynamic_debug/control

// 打开svc_process()函数中所有的动态输出语句
# echo 'func svc_process +p' > /sys/kernel/debug/dynamic_debug/control
// 关闭svc_process()函数中所有的动态输出语句
# echo 'func svc_process -p' > /sys/kernel/debug/dynamic_debug/control

// 打开文件路径中包含usb的文件里所有的动态输出语句
# echo -n '*usb* +p' > /sys/kernel/debug/dynamic_debug/control

// 打开系统所有的动态输出语句
# echo -n '+p' > /sys/kernel/debug/dynamic_debug/control


2. 内核启动时调试

启动代码在进入 shell 时已完成,这时可以传递启动参数给内核,在系统初始化时动态打开它们。例如调试SMP初始化的代码,查询到ARM SMP模块有一些动态输出语句。

# cat /sys/kernel/debug/dynamic_debug/control | grep smp
arch/arm/kernel/smp.c:354 [smp]secondary_start_kernel =pflt "CPU%u: Bootedsecondary processor\012"

//在内核命令行启动参数中添加“smp.dyndbg=+plft”字符串后:

# dmesg | grep "Booted" 
secondary_start_kernel:354: CPU1: Booted secondary processor[0] 
secondary_start_kernel:354: CPU2: Booted secondary processor[0] 
secondary_start_kernel:354: CPU3: Booted secondary processor

 

四、实验

1. 验证cpu-boost.c中的动态打印

# cat /sys/kernel/debug/dynamic_debug/control | grep cpu_boost
filename:lineno                   [module]function              flags format
kernel/sched/walt/cpu-boost.c:220 [cpu_boost]do_input_boost =_ "Setting input boost min for all CPUs\012"
kernel/sched/walt/cpu-boost.c:147 [cpu_boost]boost_adjust_notify =_ "CPU%u policy min before boost: %u kHz\012"
kernel/sched/walt/cpu-boost.c:191 [cpu_boost]do_input_boost_rem =_ "Resetting input boost min for all CPUs\012"

//注:flags表示使能了什么,若是只使能打印log内容的话flags那里只会显示"p ",这里没有使能,就什么也不显示。

# echo 'func do_input_boost_rem +p' > /sys/kernel/debug/dynamic_debug/control //cat看此时只有这个函数flags位置多了个p
# dmesg -n 8  //必须有,因为最终调用的printk(KERN_DEBUG)来打印的 #########
# dmesg -c | grep cpu-boost
[  539.220213] (1)[251:kworker/1:1H]cpu-boost: Resetting input boost min for all CPUs //打印出来了

# echo 'func do_input_boost_rem -p' > /sys/kernel/debug/dynamic_debug/control //关闭打印,cat看此时这个函数flags位置p消失了

# echo 'module cpu_boost +p' > /sys/kernel/debug/dynamic_debug/control //使能此模块内部所有动态打印
[  780.731812] (3)[266:kworker/3:1H]cpu-boost: Setting input boost min for all CPUs
[  780.732080] (3)[266:kworker/3:1H]cpu-boost: CPU0 policy min before boost: 2246400 kHz

# echo 'module cpu_boost +pflmt' > /sys/kernel/debug/dynamic_debug/control
# dmesg -c | grep cpu-boost
[ 1217.478964] (2)[259:kworker/2:1H][259] cpu_boost:do_input_boost:220: cpu-boost: Setting input boost min for all CPUs
[ 1217.479369] (2)[259:kworker/2:1H][259] cpu_boost:boost_adjust_notify:147: cpu-boost: CPU0 policy min before boost: 2246400 kHz
# cat /sys/kernel/debug/dynamic_debug/control | grep cpu_boost
kernel/sched/walt/cpu-boost.c:220 [cpu_boost]do_input_boost =pmflt "Setting input boost min for all CPUs\012" //flags位置多了pmflt
kernel/sched/walt/cpu-boost.c:147 [cpu_boost]boost_adjust_notify =pmflt "CPU%u policy min before boost: %u kHz\012"

 

五、总结

1. 一般只有userdebug版本才使能动态打印。

2. pr_debug()最终是通过printk(KERN_DEBUG)实现的,注意命令行打印等级,可用dmesg -n 8。

 

参考:
内核调试信息printk/pr_debug()/dev_dbg(): https://blog.csdn.net/yueni_zhao/article/details/127654005

 

posted on 2021-05-08 21:02  Hello-World3  阅读(1148)  评论(0编辑  收藏  举报

导航