Linux内核中dev_info、dev_dbg、dev_err及动态调试

朱雀 2023-01-17 08:00 223阅读 0赞

目前在kernel驱动代码中，都不再建议直接使用printk直接添加打印信息，而是使用dev\_info，dev\_dbg，dev\_err之类的函数代替，虽然这些dev\_xxx函数的本质还是使用printk打印的，但是相比起printk：

*  支持打印模块信息、dev信息
 *  支持动态调试(dynamic debug)方式

下面简述下这几个dev\_xxx函数的基本使用规则，以及动态调试使用方式。

*  dev\_info()：启动过程、或者模块加载过程等“通知类的”信息等，一般只会通知一次，例如probe函数；
 *  dev\_dbg()：一般使用在普通错误，如-EINVAL、-ENOMEM等errno发生处，用于调试；
 *  dev\_err()：一般使用在严重错误，尤其是用户无法得到errno的地方，或者程序员不容易猜测系统哪里出了问题的地方；

## 动态调试使用方法 ##

*  打开内核动态调试开关，make menuconfig选中CONFIG\_DYNAMIC\_DEBUG以及CONFIG\_DEBUG\_FS
 *  Linux启动后，使用命令行挂载上dbgfs

mkdir /mnt/dbg
    mount -t debugfs none /mnt/dbg

*  使用下面方式控制你想输出dev\_dbg()信息
 *  1.控制某个文件所有dev\_dbg()，echo -n "file xxx.c +p" > /mnt/dbg/dynamic\_debug/control
 *  2.控制某个函数所有dev\_dbg()，echo -n "func xxx +p" > /mnt/dbg/dynamic\_debug/control
 *  运行程序，使用dmesg则可以看到相应dev\_dbg()的输出信息
 *  当调试结束，不再想输出dev\_dbg()信息了，使用下面命令关闭即可
 *  1.echo -n "file xxx.c -p" > /mnt/dbg/dynamic\_debug/control
 *  2.echo -n "func xxx -p" > /mnt/dbg/dynamic\_debug/control

## 例子 ##

echo -n "file ca_dsc_core.c +p" > /mnt/dbg/dynamic_debug/control 则打印ca_dsc_core.c所有的dev_dbg()信息
    echo -n "func ca_dsc_read +p" > /mnt/dbg/dynamic_debug/control 则打印ca_dsc_read()函数所有dev_dbg()信息

## 动态打印调试的基本原理 ##

当编译选项CONFIG\_DYNAMIC\_DEBUG打开的时候，在编译阶段，kernel会把所有使用dev\_dbg()的信息记录在一个table中，这些信息我们可以从/mnt/dbg/dynamic\_debug/control解析出来：

# cat /mnt/dbg/dynamic_debug/control
    ... ...
    ... ...
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:800 [alidsc]ca_dsc_probe_dt =_ "get dev-index error12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:789 [alidsc]ca_dsc_probe_dt =_ "get clk error12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:292 [alidsc]ca_dsc_read =p "read: session#%d read returned %d bytes12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:234 [alidsc]ca_dsc_read =p "read: session#%d read request: %zd bytes12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:435 [alidsc]ca_dsc_vm_fault =_ "dsc_vm_fault: buffer#%d release %d bytes for session#%d12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:112 [alidsc]ca_dsc_open =_ "dsc_se: failed register se12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:755 [alidsc]ca_dsc_splice_write =_ "splice_write: session#%d dsc_from_pipe %d bytes12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:729 [alidsc]ca_dsc_splice_write =_ "splice_write: session#%d count %zd bytes12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:619 [alidsc]ca_dsc_splice_read =_ "splice_read: session#%d ret %zd bytes12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:532 [alidsc]ca_dsc_splice_read =_ "splice_read: session#%d request %zd bytes12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:871 [alidsc]ca_dsc_probe =_ "Get DSC handler error!12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:820 [alidsc]ca_dsc_probe =_ "Failed to parse DT12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:923 [alidsc]ca_dsc_remove =_ "get clk error12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:396 [alidsc]ca_dsc_write =_ "write: session#%d ret %zd12"
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:325 [alidsc]ca_dsc_write =_ "write: session#%d count %zd12"
    ... ...
    ... ...
    net/ipv4/ping.c:965 [ping]ping_rcv =_ "no socket, dropping12"
    net/ipv4/ping.c:960 [ping]ping_rcv =_ "rcv on socket %p12"
    net/ipv4/ping.c:953 [ping]ping_rcv =_ "ping_rcv(skb=%p,id=%04x,seq=%04x)12"
    net/ipv4/ping.c:932 [ping]ping_queue_rcv_skb =_ "ping_queue_rcv_skb -> failed12"
    net/ipv4/ping.c:929 [ping]ping_queue_rcv_skb =_ "ping_queue_rcv_skb(sk=%p,sk->num=%d,skb=%p)12"
    net/ipv4/ping.c:921 [ping]ping_recvmsg =_ "ping_recvmsg -> %d12"
    net/ipv4/ping.c:840 [ping]ping_recvmsg =_ "ping_recvmsg(sk=%p,sk->num=%u)12"
    net/ipv4/ping.c:693 [ping]ping_v4_sendmsg =_ "ping_v4_sendmsg(sk=%p,sk->num=%u)12"
    net/ipv4/ping.c:197 [ping]ping_lookup =_ "found: %p: num=%d, daddr=%pI4, dif=%d12"
    net/ipv4/ping.c:189 [ping]ping_lookup =_ "iterate12"
    net/ipv4/ping.c:176 [ping]ping_lookup =_ "try to find: num = %d, daddr = %pI4, dif = %d12"
    net/ipv4/ping.c:505 [ping]ping_err =_ "err on socket %p12"
    net/ipv4/ping.c:502 [ping]ping_err =_ "no socket, dropping12"
    net/ipv4/ping.c:498 [ping]ping_err =_ "ping_err(proto=0x%x,type=%d,code=%d,id=%04x,seq=%04x)12"
    net/ipv4/ping.c:304 [ping]ping_check_bind_addr =_ "ping_check_bind_addr(sk=%p,addr=%pI4,port=%d)12"
    net/ipv4/ping.c:445 [ping]ping_bind =_ "ping_v4_bind -> %d12"
    net/ipv4/ping.c:423 [ping]ping_bind =_ "after bind(): num = %d, dif = %d12"
    net/ipv4/ping.c:286 [ping]ping_close =_ "isk->refcnt = %d12"
    net/ipv4/ping.c:285 [ping]ping_close =_ "ping_close(sk=%p,sk->num=%u)12"
    net/ipv4/ping.c:153 [ping]ping_unhash =_ "ping_unhash(isk=%p,isk->num=%u)12"
    net/ipv4/ping.c:146 [ping]ping_hash =_ "ping_hash(sk->port=%u)12"
    net/ipv4/ping.c:67 [ping]ping_hashfn =_ "hash(%d) = %d12"
    net/ipv4/ping.c:130 [ping]ping_get_port =_ "was not hashed12"
    net/ipv4/ping.c:127 [ping]ping_get_port =_ "found port/ident = %d12"

以其中一条为例子：

drivers/alidrivers/modules/alidsc/ca_dsc_core.c:800 [alidsc]ca_dsc_probe_dt =_ "get dev-index error12" 则不会打印
    drivers/alidrivers/modules/alidsc/ca_dsc_core.c:800 [alidsc]ca_dsc_probe_dt =p "get dev-index error12" 则会打印

所以在应用层，用户就可以通过使用echo来控制dynamic\_debug/control文件，进而控制是否打印某个dev\_dbg()信息！

> dev\_dbg()对于分析某些内核子系统或者驱动流程也十分有意义，例如，使能net/ipv4/ping.c的调试开关，则可以观测ping的运行原理。

## 代码分析 ##

从代码角度，也很容易看出dev\_dbg()的设计：

include/linux/device.h include/linux/dynamic\_debug.h lib/dynamic\_debug.c

//使能CONFIG_DYNAMIC_DEBUG后则根据control信息动态打印
    #if defined(CONFIG_DYNAMIC_DEBUG)
     #define dev_dbg(dev, format, ...)       
     do {           
      dynamic_dev_dbg(dev, format, ##__VA_ARGS__); 
     } while (0)
    //使能DEBUG，则打印整个kernel的dev_dbg信息
    #elif defined(DEBUG)
     #define dev_dbg(dev, format, arg...)  
      dev_printk(KERN_DEBUG, dev, format, ##arg)
    //都不使能，dev_dbg不打印任何东西
    #else
     #define dev_dbg(dev, format, arg...)    
     ({        
      if (0)       
       dev_printk(KERN_DEBUG, dev, format, ##arg); 
      0;       
     })
    #endif

下面的dynamic\_dev\_dbg()实现显然可以看出，打印是根据descriptor的标志位\_DPRINTK\_FLAGS\_PRINT进行打印的，而标志位是可以通过dbgfs进行控制的。

#define dynamic_dev_dbg(dev, fmt, ...)    
    do {        
     DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt);  
     if (unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT)) 
      __dynamic_dev_dbg(&descriptor, dev, fmt, 
          ##__VA_ARGS__);  
    } while (0)

## 好处 ##

*  开发版本，打开CONFIG\_DYNAMIC\_DEBUG和CONFIG\_DEBUG\_FS，配合dbgfs动态观测和调试内核代码；
 *  正式版本，关闭CONFIG\_DYNAMIC\_DEBUG和CONFIG\_DEBUG\_FS，所有dbgfs以及dev\_dbg信息都从编译阶段自动移除；

![虚线阴影分割线][6af4110eccbc51dfe4e41e6e4a978a3a.png]

![6cf94b4412afdce7fde805d4671cd1f8.png][]

5T技术资源大放送！包括但不限于：C/C++，Arm, Linux，Android，人工智能，单片机，树莓派，等等。在公众号内回复「peter」，即可免费获取！！

![e65f0b4f44817c84e7917aa602b0fc9c.gif][] **记得点击****分享****、****赞****和****在看****，给我**

[6af4110eccbc51dfe4e41e6e4a978a3a.png]: /images/20221021/a66aab17f18c44a79e13de17e8a0fa51.png
[6cf94b4412afdce7fde805d4671cd1f8.png]: /images/20221021/bf3b87e56fca428ab4e64057c1ad4a48.png
[e65f0b4f44817c84e7917aa602b0fc9c.gif]: /images/20221021/8e7d559becce4afa927c6fd41c10ff19.png