在Linux调试中,加printk等打印可以解决大部分问题。在Linux默认代码中,常会看到封装了printk() 的更高级的宏,比如dev_info(), dev_dbg(), pr_info(), pr_debug()等。但是有些信息并没有输出到控制台(串口)。本文以i.MX8MP EVK, L6.1.36 Linux版本为例,列出了一些Linux利用printk常用的调试手段:
• printk的级别定义,如何调节日志等级
• 动态调试 (dynamic debug):即在运行Linux时将指定驱动文件的dev_dbg, pr_debug等输出到控制台(串口)
• 静态调试 (debug):即在编译内核时将指定驱动文件的dev_dbg, pr_debug等输出到控制台(串口)
• 修改kernel顶层Makefile, 将所有驱动文件的dev_dbg, pr_debug等输出到控制台(串口)
• 利用initcall_debug跟踪initcall
• 其他模块的debug: 如drm debug
• 手动WARN_ON(1), BUG_ON(1)查看栈回溯
1. 预定开发板
在动手实践本应用案例前先预定开发板:(以i.MX8MP为例,i.MX93等同样适用)
2. printk的级别定义,如何调节日志等级:
内核打印语句printk()会将内核信息输出到内核信息缓冲区中,它是一个环形缓冲区,塞入消息过多会把之前的消息冲掉。Linux内核可通过调节CONFIG_LOG_BUF_SHIFT宏来扩大缓冲区大小。
Printk()定义了8个消息级别,分别为0~7。数值越大,级别越低,消息越不重要。第0级是紧急事件,第7级是调试级。
vi include/linux/kern_levels.h
#definKERN_EMERG KERN_SOH "0" /* system is unusable */
#define KERN_ALERT KERN_SOH "1" /* action must be taken immediately */
#define KERN_CRIT KERN_SOH "2" /* critical conditions */
#define KERN_ERR KERN_SOH "3" /* error conditions */
#define KERN_WARNING KERN_SOH "4" /* warning conditions */
#define KERN_NOTICE KERN_SOH "5" /* normal but significant condition */
#define KERN_INFO KERN_SOH "6" /* informational */
#define KERN_DEBUG KERN_SOH "7" /* debug-level messages */e
其中,KERN_EMERG(等级0)为紧急事件,一般是系统崩溃前的信息。KERN_ERR(等级1)用于报告错误状态,设备驱动程序常采用此等级的打印报告自身硬件问题。KERN_INFO(等级6)是内核提示性信息,驱动程序在启动的时候常用此等级的打印报告硬件信息。KERN_DEBUG(等级7)是调试信息。
用户可以直接用不带flag的printk打印,默认的优先级是4,即直接printk(“XXX“);。也可以选择添加打印等级,比如用printk(KERN_DEBUG “XXX“);或者printk(KERN_INFO “XXX“)。
在打印时,可以使用__func__输出printk所在的函数名,使用__LINE__输出所在代码的行号,使用__FILE__输出源代码的文件名。
例如,按照“编译内核镜像并在云实验室开发板运行.docx“编译内核源码,其中对源码添加如下打印:
git diff
diff --git a/drivers/gpu/drm/bridge/sec-dsim.c b/drivers/gpu/drm/bridge/sec-dsim.c
index fc9ca98f6ef7..ea5fbec61209 100644
--- a/drivers/gpu/drm/bridge/sec-dsim.c
+++ b/drivers/gpu/drm/bridge/sec-dsim.c
@@ -1146,6 +1146,9 @@ struct dsim_pll_pms *sec_mipi_dsim_calc_pmsk(struct sec_mipi_dsim *dsim)
struct sec_mipi_dsim_range pr_new = *prange;
struct sec_mipi_dsim_range sr_new = *srange;
+ printk(KERN_INFO "sec_mipi_dsim_calc_pmsk start, function name is %s,\
+ line is %d, file name is %s\n ", __func__, __LINE__, __FILE__ );
+
pll_pms = devm_kzalloc(dev, sizeof(*pll_pms), GFP_KERNEL);
if (!pll_pms) {
dev_err(dev, "Unable to allocate 'pll_pms'\n");
编好的kernel Image通过以下方式上传至8MPLUSLPD4-PEVK-3开发板的TFTP目录。
再点击PowerReset EVK按钮,重启开发板。之后可以看到以下打印出现。可以作为调试的一种手段。
通过以下命令可查看printk()的输出等级:
cat /proc/sys/kernel/printk
该文件有4个值,依次为:
(1) 控制台(一般是串口)的日志级别, console_loglevel:当前的打印级别,优先级高于该值的将被打印至控制台。
(2) 默认的消息级别, default_message_loglevel:打印没有优先级前缀的消息,即直接printk(“XXX“);的信息。由内核的宏CONFIG_MESSAGE_LOGLEVEL_DEFAULT控制默认值,默认为4,取值1~7。
(3) 最低的控制台日志级别, minimum_console_loglevel:控制台日志级别可设置的最小值(一般为1)。
(4) 默认的控制台日志级别, default_console_loglevel:控制台日志级别的默认值。由内核的宏CONFIG_CONSOLE_LOGLEVEL_DEFAULT控制默认值,默认为7,取值1~15。
通过以下命令可修改控制台的日志级别,以下命令修改为8:
echo 8 4 1 7> /proc/sys/kernel/printk
或者以下命令:
dmesg -n 8
在Linux默认代码中,常会看到封装了printk的更高级的宏,比如dev_info, dev_dbg, pr_info, pr_debug等。但是有些信息并没有输出到控制台(串口)。
以i.MX8MP EVK, L6.1.36 Linux版本为例,若采用默认的Linux kernel, 在启动过程中及利用dmesg查看开机信息时,可以看到pr_debug(),dev_dbg(),和printk(KERN _DEBUG “XXX“);等信息并未没有输出到控制台(串口)。即KERN_DEBUG(等级7)的调试信息没有输出到串口。除此之外,消息级别为0~6的调试信息均可输出到串口。
有时在调试Linux kernel时,我们希望某些文件的pr_debug(),dev_dbg(),和printk(KERN DEBUG “XXX“);等信息也输出到控制台(串口)。如何操作呢?这时候我们需要借助动态调试 (dynamic debug)或者静态调试 (debug)。
3. 动态调试 (dynamic debug):
Dynamic debug(dyndbg) 功能,就是允许用户空间通过 debugfs 导出的文件节点 /sys/kernel/debug/dynamic_debug/control,动态的、在运行时控制 Linux 内核 KERN_DEBUG 类型日志的开启和关闭。
在没开启动态调试时,直到下次重新编译内核做出改变之前,内核 KERN_DEBUG 类型日志要么一直关闭,要么一直开启,无法在运行时做出调整。
在开启动态调试后,指定驱动文件的KERN_DEBUG 等级的打印信息,即利用pr_debug(), dev_dbg(), print_hex_dump_debug(), print_hex_dump_bytes(), printk(KERN_DEBUG “XXX“);的信息均可打印至控制台。
默认Linux kernel没有使能动态调试,若使能,需要在imx_v8_defconfig或者menuconfig中设置CONFIG_DYNAMIC_DEBUG=Y(默认为N) 和 CONFIG_DEBUG_FS=Y(默认为Y)。设置成功后,编译成新的kernel Image,同样方式上传至板子的TFTP目录。
3.1 若用户想要在kernel运行时查看某个驱动文件的KERN_DEBUG等级的打印信息,可以通过以下命令查看drivers/gpu/drm/bridge/sec-dsim.c的KERN_DEBUG信息,其中“pfl”是flags, p代表打印log信息,f代表打印函数名,l代表打印代码行数:
echo -n "file drivers/gpu/drm/bridge/sec-dsim.c +pfl " >
/sys/kernel/debug/dynamic_debug/control
dmesg |grep sec
结合Linux drivers/gpu/drm/bridge/sec-dsim.c驱动的源码,可以看到dev_dbg的信息已经被打印。
3.2 若用户想要在kernel启动时查看某个驱动文件的KERN_DEBUG等级的打印信息,且线下有开发板,可以通过以下方法修改bootargs。以下代码修改drivers/gpu/drm/bridge/sec-dsim.c,需要修改dtb并外接MIPI DSI屏幕:
edit: setenv bootargs ${jh_clk} ${mcore_clk} console=${console} root=${mmcroot} "dyndbg=\"file drivers/gpu/drm/bridge/sec-dsim.c +pfl"\"
u-boot=> saveenv
Saving Environment to MMC... Writing to MMC(1)... OK
u-boot=>
启动kernel后输入dmesg, 可以看到如下log:
结合Linux drivers/gpu/drm/bridge/sec-dsim.c驱动的源码,可以看到dev_dbg的信息已经被打印。
4. 静态调试 (debug):
如果用户不需要像动态调试那样,在运行时控制 Linux 内核 KERN_DEBUG 类型日志的开启和关闭,可以采用静态调试。该调试方法需要重新编译内核才能做出改变。具体需要在想打印的驱动文件头部,加入#define DEBUG。
仍以驱动文件drivers/gpu/drm/bridge/sec-dsim.c为例,按照以下方式修改kernel并重新做出编译后。上传至云实验室开发板的TFTP目录,
diff --git a/drivers/gpu/drm/bridge/sec-dsim.c b/drivers/gpu/drm/bridge/sec-dsim.c
index fc9ca98f6ef7..a042be9c713c 100644
--- a/drivers/gpu/drm/bridge/sec-dsim.c
+++ b/drivers/gpu/drm/bridge/sec-dsim.c
@@ -14,6 +14,7 @@
* GNU General Public License for more details.
*/
+#define DEBUG
#include <asm/unaligned.h>
#include <linux/clk.h>
#include <linux/completion.h>
即使不设置CONFIG_DYNAMIC_DEBUG=Y, 也可以将KERN_DEBUG等级的打印信息输出到控制台,达到动态调试一样的效果:
5. 修改kernel顶层Makefile, 将所有驱动文件的dev_dbg, pr_debug等输出到控制台(串口):以上动态调试和静态调试的方法,需要明确的知道要调试的驱动文件。如果是启动时出现问题(如启动时候hang死),或者要调试的文件很多,或者在调试初期无法定位问题出现在哪个文件时,我们希望把build-in的所有文件的KERN_DEBUG 类型日志均输出到控制台,这种情况下如何调试呢?
我们可以在Linux kernel顶层的Makefile中KBUILD_CFLAGS后添加-DDEBUG。它会将DEBUG宏设置为已定义状态, 其作用相当于在所有函数头都添加#define DEBUG。具体修改如下:
diff --git a/Makefile b/Makefile
index cffb83d7a0fb..1837d6f43a0e 100644
--- a/Makefile
+++ b/Makefile
@@ -570,7 +570,7 @@ KBUILD_CFLAGS := -Wall -Wundef -Werror=strict-prototypes -Wno-trigraphs \
-fno-strict-aliasing -fno-common -fshort-wchar -fno-PIE \
-Werror=implicit-function-declaration -Werror=implicit-int \
-Werror=return-type -Wno-format-security \
- -std=gnu11
+ -std=gnu11 -DDEBUG
KBUILD_CPPFLAGS := -D__KERNEL__
KBUILD_RUSTFLAGS := $(rust_common_flags) \
--target=$(objtree)/rust/target.json \
做以上修改后,编译可能需要较长时间, 尤其是”make -j$(nproc)”。可以用“make Image”命令只编译kernel Image, 不编译内核模块。
替换kernel Image后,启动到文件系统需要较长时间,大概230s。中间会出现大量无关的、重复的日志,可能会影响启动时序,甚至导致无法login。不过利用这些日志仍然能解决一些启动过程中的问题。
结合Linux drivers/gpu/drm/imx/imx8mp-hdmi-pavi.c驱动的源码,可以看到dev_dbg的信息已经被打印。
6. 利用initcall_debug跟踪initcall:
在Linux kernel启动过程中,会通过initcall机制调用初始化函数。initcall_debug是一个内核参数,可以跟踪initcall,用来定位内核初始化的问题。
若用户线下有开发板,可以用以下命令修改bootargs使能initcall_debug:
setenv mmcargs "${mmcargs} initcall_debug loglevel=8"
saveenv
可以看到各函数的initcall信息在启动时被打印至控制台。这些信息有助于帮助我们定位内核启动和初始化时的一些问题,获得更多信息。
因为云实验室安全的限制,开发板在U-boot阶段均不能修改bootargs,且均为网络启动。用户可以按照以下步骤通过修改imx_v8_defconfig的方式,固定command line:
第一次启动板子时,在dmesg中找到kernel cmdline
console=ttymxc1,115200 root=/dev/nfs ip=dhcp
nfsroot=192.168.100.250:/opt/REAL/NFS/IMX8MPEVK-3-root,v3,tcp
修改defconfig文件使能initcall_debug:
diff --git a/arch/arm64/configs/imx_v8_defconfig b/arch/arm64/configs/imx_v8_defconfig
index 85762b37006f..16d8a67b5bd3 100644
--- a/arch/arm64/configs/imx_v8_defconfig
+++ b/arch/arm64/configs/imx_v8_defconfig
@@ -1105,3 +1105,5 @@ CONFIG_CORESIGHT_STM=m
CONFIG_CORESIGHT_CPU_DEBUG=m
CONFIG_CORESIGHT_CTI=m
CONFIG_MEMTEST=y
+CONFIG_CMDLINE_FORCE=y
+CONFIG_CMDLINE="ttymxc1,115200 root=/dev/nfs ip=dhcp
nfsroot=192.168.100.250:/opt/REAL/NFS/IMX8MPEVK-3-root,v3,tcp initcall_debug loglevel=8
同样可以看到各函数的initcall信息在启动时被打印至控制台。
7. 其他模块的debug: 如drm debug:
除了printk, dev_xxx, pr_xx系列的打印,有些模块还有自己专属的打印。比如Linux DRM子系统,其驱动中会有DRM_DEBUG,DRM_DEBUG_DRIVER,DRM_DEBUG_ATOMIC,DRM_DEBUG_KMS等打印。这些函数的定义是在include/drm/drm_print.h路径下,其本质也是调用了printk函数。
DRM也规定了几个打印机别,例如:
* drm.debug=0x1 will enable CORE messages
* drm.debug=0x2 will enable DRIVER messages
* drm.debug=0x3 will enable CORE and DRIVER messages
* ...
* drm.debug=0x3f will enable all messages
在Linux启动后,通过
echo 0x1ff > /sys/module/drm/parameters/debug
或者在kernel编译时,修改defconfig文件使能drm debug,可将所以DRM相关的打印输出到控制台,便于调试显示相关的问题:
diff --git a/arch/arm64/configs/imx_v8_defconfig b/arch/arm64/configs/imx_v8_defconfig
index 85762b37006f..16d8a67b5bd3 100644
--- a/arch/arm64/configs/imx_v8_defconfig
+++ b/arch/arm64/configs/imx_v8_defconfig
@@ -1105,3 +1105,5 @@ CONFIG_CORESIGHT_STM=m
CONFIG_CORESIGHT_CPU_DEBUG=m
CONFIG_CORESIGHT_CTI=m
CONFIG_MEMTEST=y
+CONFIG_CMDLINE_FORCE=y
+CONFIG_CMDLINE="ttymxc1,115200 root=/dev/nfs ip=dhcp
nfsroot=192.168.100.250:/opt/REAL/NFS/IMX8MPEVK-3-root,v3,tcp drm.debug=0x1FF loglevel=8"
启动后可见DRM debug相关的信息。
8. 手动WARN_ON(1), BUG_ON(1)查看栈回溯:
内核中有BUG_ON()和WARN_ON()的语句,在括号中的条件成立时,便会抛出oops信息。我们可以将其作为一个调试技巧。如果我们想知道内核的某个函数是怎样被调用的,可以在该函数中加一个WARN_ON(1), 观察其调用关系:
diff --git a/drivers/gpu/drm/bridge/sec-dsim.c b/drivers/gpu/drm/bridge/sec-dsim.c
index fc9ca98f6ef7..42f647c14e2e 100644
--- a/drivers/gpu/drm/bridge/sec-dsim.c
+++ b/drivers/gpu/drm/bridge/sec-dsim.c
@@ -1146,6 +1146,7 @@ struct dsim_pll_pms *sec_mipi_dsim_calc_pmsk(struct sec_mipi_dsim *dsim)
struct sec_mipi_dsim_range pr_new = *prange;
struct sec_mipi_dsim_range sr_new = *srange;
+ WARN_ON(1);
pll_pms = devm_kzalloc(dev, sizeof(*pll_pms), GFP_KERNEL);
if (!pll_pms) {
dev_err(dev, "Unable to allocate 'pll_pms'\n");