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) 编辑 收藏 举报