• 内核调试信息printk/pr_debug()/dev_dbg()

    前言

    一 printk的打印等级

            很多内核开发者最喜欢的调试工具之一是printk。printk是内核提供的格式化打印函数，它和C库所提供的printf()函数类似。printk()函数和printf()函数的一个重要区别是前者提供打印等级，内核根据这个等级来判断是否在终端或者串口中打印输出。从我多年的工程实践经验来看，printk是最简单有效的调试方法。

            位于Kern_levels.h (include\linux) 文件。注意KERN_DEBUG展开后值是"\001""1""，中间的空格省略掉也没关系吗，没关系。

    1. #define KERN_SOH	"\001"		/* ASCII Start Of Header */
    2. #define KERN_SOH_ASCII	'\001'
    3.  
    4. #define KERN_EMERG	KERN_SOH "0"	/* system is unusable */
    5. #define KERN_ALERT	KERN_SOH "1"	/* action must be taken immediately */
    6. #define KERN_CRIT	KERN_SOH "2"	/* critical conditions */
    7. #define KERN_ERR	KERN_SOH "3"	/* error conditions */
    8. #define KERN_WARNING	KERN_SOH "4"	/* warning conditions */
    9. #define KERN_NOTICE	KERN_SOH "5"	/* normal but significant condition */
    10. #define KERN_INFO	KERN_SOH "6"	/* informational */
    11. #define KERN_DEBUG	KERN_SOH "7"	/* debug-level messages */
    12.  
    13. #define KERN_DEFAULT	KERN_SOH "d"	/* the default kernel loglevel */

            Linux内核为printk定义了8个打印等级，KERN_EMERG等级最高，KERN_DEBUG等级最低。在内核配置时，有一个宏来设定系统默认的打印等级 CONFIG_MESSAGE_LOGLEVEL_DEFAULT，通常该值设置为4。只有打印等级高于4时才会打印到终端或者串口，即只有KERN_EMERG～KERN_ERR。通常在产品开发阶段，会把系统默认等级设置到最低，以便在开发测试阶段可以暴露更多的问题和调试信息，在产品发布时再把打印等级设置为0或者4。

            此外，还可以通过在启动内核时传递commandline给内核的方法来修改系统默认的打印等级，例如传递“loglevel=8”给内核启动参数。

    二 printk使用

    和printf一样，printk也是可以格式化打印的，打印格式如下：这个格式我基本是记不住，要是警告都我强制转换(#^.^#)。

     可以直接使用printk("hello world");

    也可以使用等级打印printk(KERN_DEBUG"hello world");

    也可以将printk包装为宏定义，这是我最喜欢干的事情

    1. #define DEBUG_CSS(format,...)\
    2. 		printk("\001""1""info:%s:%s:%d: "format"\n",\
    3. 		__FILE__,__func__,__LINE__,\
    4. 		##__VA_ARGS__)
    1. #define DEBUG_CSS_ERR(format,...)\
    2. 		printk("\001""1""error:%s:%s:%d: "format"\n",\
    3. 		__FILE__,__func__,__LINE__,\
    4. 		##__VA_ARGS__)

    三 /proc/sys/kernel/printk*文件

            /proc/sys/kernel/printk

            /proc目录中有很多有用的文件，这些文件真实的表达了内核的动态信息、运行状态、进程状态、中断状态、定时器状态、IO状态、misc驱动信息，网络状态、各种内存的统计信息、系统的启动时长等等。
            读取printk的打印等级。     

    1. root@ATK-IMX6U:/proc/sys/kernel# cat printk
    2. 7       4       1       7
    3. root@ATK-IMX6U:/proc/sys/kernel#

       这四个数字的含义分别是：

    7：表示控制台打印等级、

            printk时，传递给它的KERN_XXX，KERN_XXX如果大于7，在控制台就看不到调试信息。使用dmesg就又可以看到了，

    4：默认消息打印等级

    1：最低打印等级:

    7：默认控制台打印等级。

            调整打印等级为3，

    echo 3 > /proc/sys/kernel/printk
    1. root@ATK-IMX6U:/proc/sys/kernel# cat printk
    2. 3       4       1       7
    3. root@ATK-IMX6U:/proc/sys/kernel#

            测试发现，这个值只能往小了改，不能往大了改。例如现在是3，改成7，就改不成，难道这个和内核版本有关系？那想改回原来的值怎么办，莫慌，重启以后，就会恢复默认值了。

    1. root@ATK-IMX6U:/proc/sys/kernel# cat printk
    2. 7       4       1       7
    3. root@ATK-IMX6U:/proc/sys/kernel# echo 6 > printk
    4. root@ATK-IMX6U:/proc/sys/kernel# cat printk
    5. 6       4       1       7
    6. root@ATK-IMX6U:/proc/sys/kernel# echo 7 printk
    7. 7 printk
    8. root@ATK-IMX6U:/proc/sys/kernel# cat printk
    9. 6       4       1       7
    10. root@ATK-IMX6U:/proc/sys/kernel#

    /proc/sys/kernel/printk_delay

    这个是干什么的呢？

    dmesg命令

    如果调试信息看不到，就使用dmesg命令。

    动态输出pr_debug()/dev_dbg()

            动态输出（Dynamic Printk）是内核子系统开发者最喜欢的输出手段之一。在系统运行时，动态输出可以由系统维护者动态打开那些内核子系统的输出，也可以有选择性地打开某些模块的输出，而printk是全局的，只能设置输出等级。要使用动态输出，必须在内核配置时打开CONFIG_DYNAMIC_DEBUG宏。内核代码里使用了大量的pr_debug()/dev_dbg()函数来输出信息，这些就使用了动态输出技术，另外还需要系统挂载debugfs文件系统。

            动态输出在debugfs文件系统中有一个control文件节点。文件节点记录了系统中所有使用动态输出技术的文件名路径、输出所在的行号、模块名字和要打印的语句。

    我的内核默认没有开启这个功能，DEBUG_FS=n

     DEBUG_FS位置：

     配置如下所示，然后重新编译内核：

    这个Enable dynamic printk() support如何依赖项没有配置，它是隐藏技能，看不到的。

     

     使用新内核后，/sys/kernel目录多了debug文件夹：

    1. root@ATK-IMX6U:/sys/kernel/debug# ls
    2. asoc  bluetooth  ci_hdrc.1  dma_buf  dynamic_debug  fault_around_bytes  hid        iio       mmc0  pinctrl  pwm     regulator   suspend_stats  ubifs  wakeup_sources
    3. bdi   ci_hdrc.0  clk        dri      extfrag        gpio                ieee80211  memblock  mmc1  pm_qos   regmap  sleep_time  ubi            usb
    4. root@ATK-IMX6U:/sys/kernel/debug#
    5.

    dynamic_debug文件夹下有个control文件，该中存有大量的调试信息：

    看看前10行和后10行

    1. root@ATK-IMX6U:/sys/kernel/debug/dynamic_debug# head -n 10 control
    2. # filename:lineno [module]function flags format
    3. init/main.c:712 [main]initcall_blacklist =p "blacklisting initcall %s\012"
    4. init/main.c:736 [main]initcall_blacklisted =p "initcall %s blacklisted\012"
    5. init/initramfs.c:483 [initramfs]unpack_to_rootfs =_ "Detected %s compressed data\012"
    6. arch/arm/vfp/vfpmodule.c:304 [vfp]vfp_emulate_instruction =_ "VFP: emulate: INST=0x%08x SCR=0x%08x\012"
    7. arch/arm/vfp/vfpmodule.c:260 [vfp]vfp_raise_exceptions =_ "VFP: raising exceptions %08x\012"
    8. arch/arm/vfp/vfpmodule.c:456 [vfp]vfp_pm_suspend =_ "%s: saving vfp state\012"
    9. arch/arm/vfp/vfpmodule.c:340 [vfp]VFP_bounce =_ "VFP: bounce: trigger %08x fpexc %08x\012"
    10. arch/arm/vfp/vfpsingle.c:51 [vfp]vfp_single_dump =_ "VFP: %s: sign=%d exponent=%d significand=%08x\012"
    11. arch/arm/vfp/vfpsingle.c:849 [vfp]vfp_single_multiply =_ "VFP: swapping M <-> N\012"
    12. root@ATK-IMX6U:/sys/kernel/debug/dynamic_debug#
    1. root@ATK-IMX6U:/sys/kernel/debug/dynamic_debug# tail -n 10 control
    2. net/bluetooth/hidp/core.c:149 [hidp]hidp_input_event =_ "session %p type %d code %d value %d\012"
    3. net/bluetooth/hidp/core.c:1402 [hidp]hidp_get_connlist =_ "\012"
    4. net/bluetooth/hidp/sock.c:233 [hidp]hidp_sock_create =_ "sock %p\012"
    5. net/bluetooth/hidp/sock.c:60 [hidp]hidp_sock_ioctl =_ "cmd %x arg %lx\012"
    6. net/bluetooth/hidp/sock.c:36 [hidp]hidp_sock_release =_ "sock %p sk %p\012"
    7. net/wireless/reg.c:547 [cfg80211]call_crda =_ "Exceeded CRDA call max attempts. Not calling CRDA\012"
    8. net/wireless/reg.c:553 [cfg80211]call_crda =_ "Calling CRDA for country: %c%c\012"
    9. net/wireless/reg.c:555 [cfg80211]call_crda =_ "Calling CRDA to update world regulatory domain\012"
    10. net/mac80211/mlme.c:1354 [mac80211]ieee80211_handle_pwr_constr =p "%s: Limiting TX power to %d (%d - %d) dBm as advertised by %pM\012"
    11. net/mac80211/mlme.c:1359 [mac80211]ieee80211_handle_pwr_constr =p "%s: Limiting TX power to %d dBm as advertised by %pM\012"
    12. root@ATK-IMX6U:/sys/kernel/debug/dynamic_debug#

    那么如何打开动态输出语句呢？

    直接写一个简单的模块，并在模块中添加如下两个语句

    1. 	pr_debug("css_init init ok");
    2. 	dev_dbg(css_dev->misc.this_device, "css_init init ok");

    加载该模块后，显示control文件后四行的信息：看到我们动态调试信息。

    1. root@ATK-IMX6U:~# tail -n 4 /sys/kernel/debug/dynamic_debug/control
    2. net/mac80211/mlme.c:1359 [mac80211]ieee80211_handle_pwr_constr =p "%s: Limiting TX power to %d dBm as advertised by %pM\012"
    3. /big/csi_driver/css_dma/csi_single.c:161 [csi_single]css_init =_ "css_init init ok"
    4. /big/csi_driver/css_dma/csi_single.c:188 [csi_single]css_init =_ "css_init init ok"
    5. /big/csi_driver/css_dma/csi_single.c:189 [csi_single]css_init =_ "css_init init ok"
    6. root@ATK-IMX6U:~#

    下面的内容，先抄写过来。

    下面举例来说明如何使用动态输出技术。

    // 打开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

            上面是打开动态输出语句的例子，除了能输出 pr_debug()/dev_dbg()函数中定义的输出外，还能输出一些额外信息，例如函数名、行号、模块名字和线程ID等。

    p：打开动态打印语句。

    f：打印函数名。

    l：打印行号。

    m：打印模块名字。

    t：打印线程ID。

            对于调试一些系统启动方面的代码，例如SMP初始化、USB核心初始化等，这些代码在系统进入 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”字符串。

    #qemu-system-arm -M vexpress-a9 -m 1024M -kernel arch/arm/boot/zImage-append "rdinit=/linuxrc console=ttyAMA0 loglevel=8 smp.dyndbg=+plft" -dtbarch/arm/boot/dts/vexpress-v2p-ca9.dtb -nographic -smp 4

    […]

    / # dmesg | grep "Booted" //查询SMP模块的动态输出语句是否打开[0] 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

    / #还可以在各个子系统的Makefile中添加ccflags来打开动态输出。

    […/Makefile]

    ccflags-y := -DDEBU

    Gccflags-y += -DVERBOSE_DEBUG

    扩展函数：

    还有两个函数，在其他文章中介绍

    打印内存的数据函数print_hex_dump()

    打印堆栈函数dump_stack()

    小结

  • 相关阅读:
    【MySQL】日期格式化 yyyy-mm-dd 详解 DATE_FORMAT() 函数
    用Python做一个软件，你想看的视频可以能看 ~ 当然必须是正经的
    Z-Score模型的进阶版：Zeta模型
    ScottPlot入门教程:获取和显示鼠标处的数值
    （附源码）springboot酒店管理平台 毕业设计 201010
    八月回顾 | 炎炎八月，这些“热点”你都知道吗
    Vuex
    openjudge 1.8.15 细菌的繁殖与扩散
    第2-4-6章 springboot整合规则引擎Drools-业务规则管理系统-组件化-中台
    致敬第一个1024（第一次Java代码编程）
  • 原文地址：https://blog.csdn.net/yueni_zhao/article/details/127654005