Dev in Linux kernel_ info,dev_dbg,dev_err and dynamic debugging

Posted by mikster on Thu, 20 Jan 2022 12:37:34 +0100

summary

At present, in the kernel driver code, it is no longer recommended to use printk directly to add print information, but to use dev_info,dev_dbg,dev_err and other functions, although these dev_ The essence of XXX function is printed with printk, but compared with printk:

  • Support printing module information and dev information
  • Support dynamic debug mode

Let's briefly describe these devs_ The basic usage rules of XXX function and the usage mode of dynamic debugging.

  • dev_info(): information of "notification class" such as startup process or module loading process. Generally, it will be notified only once, such as probe function;
  • dev_dbg(): it is generally used where common errors such as - EINVAL, - ENOMEM and other errno occur for debugging;
  • dev_err(): generally used for serious errors, especially where users cannot get errno, or where programmers are not easy to guess what is wrong with the system;

Usage of dynamic debugging

Turn on the kernel dynamic debugging switch, make menuconfig, and select CONFIG_DYNAMIC_DEBUG and CONFIG_DEBUG_FS
After Linux starts, use the command line to mount dbgfs

mkdir /mnt/dbg 
mount -t debugfs none /mnt/dbg 
Use the following methods to control the output you want dev_dbg()information
1.Control all of a file dev_dbg(),echo -n "file xxx.c +p" > /mnt/dbg/dynamic_debug/control
2.Control all of a function dev_dbg(),echo -n "func xxx +p" > /mnt/dbg/dynamic_debug/control
 Running programs, using dmesg You can see the corresponding dev_dbg()Output information of
 When debugging is over, you no longer want to output dev_dbg()If the information is, use the following command to close it
1.echo -n "file xxx.c -p" > /mnt/dbg/dynamic_debug/control
2.echo -n "func xxx -p" > /mnt/dbg/dynamic_debug/control

example

echo -n "file ca_dsc_core.c +p" > /mnt/dbg/dynamic_debug/control Then print ca_dsc_core.c be-all dev_dbg()information 
echo -n "func ca_dsc_read +p" > /mnt/dbg/dynamic_debug/control Then print ca_dsc_read()Function all dev_dbg()information 

Basic principle of dynamic printing debugging

When compiling option config_ DYNAMIC_ When debug is turned on, the kernel will use dev for all applications during the compilation phase_ The information of DBG () is recorded in a table, which can be obtained from / mnt/dbg/dynamic_debug/control resolves:

# 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" 

Take one of them as an example:

drivers/alidrivers/modules/alidsc/ca_dsc_core.c:800 [alidsc]ca_dsc_probe_dt =_ "get dev-index error12" Will not print 
drivers/alidrivers/modules/alidsc/ca_dsc_core.c:800 [alidsc]ca_dsc_probe_dt =p "get dev-index error12" Will print 

Therefore, in the application layer, users can control dynamic by using echo_ Debug / control file to control whether to print a dev_dbg() information!

dev_dbg()It is also very meaningful to analyze some kernel subsystems or driver processes, for example, enable net/ipv4/ping.c The commissioning switch can be observed ping Operation principle of.

code analysis

From a code perspective, it's also easy to see dev_dbg() design:

 include/linux/device.h include/linux/dynamic_debug.h lib/dynamic_debug.c 

    //Enable config_ DYNAMIC_ After debug, it will be dynamically printed according to the control information 
    #if defined(CONFIG_DYNAMIC_DEBUG) 
     #define dev_dbg(dev, format, ...)        
     do {            
      dynamic_dev_dbg(dev, format, ##__VA_ARGS__);  
     } while (0) 
    //If DEBUG is enabled, the dev of the entire kernel is printed_ DBG information 
    #elif defined(DEBUG) 
     #define dev_dbg(dev, format, arg...)   
      dev_printk(KERN_DEBUG, dev, format, ##arg) 
    //Not even enabled, dev_dbg does not print anything 
    #else 
     #define dev_dbg(dev, format, arg...)     
     ({         
      if (0)        
       dev_printk(KERN_DEBUG, dev, format, ##arg);  
      0;        
     }) 
    #endif 

The following dynamic_ dev_ The DBG () implementation clearly shows that printing is based on the flag bit of the descriptor_ DPRINTK_FLAGS_PRINT is used for printing, and the flag bit can be controlled through 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) 

benefit

  • Development version, open CONFIG_DYNAMIC_DEBUG and CONFIG_DEBUG_FS, cooperate with dbgfs to dynamically observe and debug kernel code;
  • Official version, close CONFIG_DYNAMIC_DEBUG and CONFIG_DEBUG_FS, all dbgfs and dev_dbg information is automatically removed from the compilation phase;

Topics: Linux