内核调试利器printk的使用心得

 

 

[导读] 刚刚开始做Linux相关开发工作时，深感Linux内核代码庞大，要加些自己的驱动进内核代码树，常常深陷bug的泥沼难以自拔，今天来分享一下内核调试利器printk的使用心得。

前面一段时间很忙，后期更文频率会渐渐回归正常频率，尽量会保证每周一到两更。感谢各位朋友的关注而没有弃我而去，我定不负厚爱，会持续输出些日常技术工作中的心得体会，如对朋友们有些许帮助，也烦请帮忙点个赞或者在看(这并不会对各位有何不利的影响哈～～～)，这也是对我坚持持续输出的大大激励！

printk初接触

Linux内核启动之后常会看见很多信息打印出来，这在底层是printk子系统实现的，其实现代码在./kernel/printk/中实现的。

 

一个小小的打印，对于内核而言也需要考虑很多方面，需要考虑到多核、中断、缓冲以及用户空间接口。对于用户空间接口很多朋友或许会很疑惑。

 

其中/dev/kmsg字符设备就是printk子系统实现的内核打印字符设备。如果利用文件操作写这个设备就最终会以printk形式输出，如果读这个设备最终就会返回printk历史，你如不信不妨用这个命令试试:

cat /dev/kmsg

 

看到这里或许有朋友会问，为啥有的文章提到用/proc/kmsg去读取内核打印缓冲区的日志用以调试。来分析一下：

/proc/kmsg

/proc/kmsg仅为root用户提供内核日志缓冲区的只读操作。等效于通过SYSLOG_ACTION_READ操作调用[syslog(2)]。

一个进程必须具有超级用户特权才能读取此文件，并且只有一个进程应读取该文件。如果正在运行使用syslog(2)系统调用记录内核消息的syslog进程，则不应读取该文件。

这里补充说一点是，/proc文件系统本质上是伪文件系统，它提供了内核数据结构的接口。它一般挂载在/proc上。通常情况下，它是由系统自动挂载的的，但是也可以使用以下命令手动安装：

 mount -t proc proc /proc

大部分位于/proc下的文件属于只读特性，但也有少部分是可写的。但是对于/proc/kmsg而言则是只读的。

/dev/kmsg

/dev/kmsg提供对同一内核日志缓冲区的访问，但以一种更易于使用的方式。每次打开都会对读取进行跟踪，因此可以并行读取多个进程，并且在读取条目时不会将其从缓冲区中删除。/dev/kmsg还提供对日志缓冲区的写访问权，因此可用于将条目添加到日志缓冲区。

那么为什么两者都存在，以及为什么一个存在于/proc中和而另一个存在于/dev中，/proc/kmsg是历史设计，而/dev/kmsg是较新引入的，被设计为日志缓冲区的可用接口。该接口也实现了用户空间添加记录进内核日志系统的可能。

其代码实现也可以简单

 

printk使用

printk怎么打印的呢？想必做嵌入式开发的一定熟悉printf函数，那么从范式上printk也比较类似，但也有很多不同。且看：

内核打印，界定了日志级别，其语法范式：

printk([KERN_LOG_LEVEL] "Message: %s
", arg);

比如：

printk(KERN_DEBUG “Here is: %s:%i
”, __FILE__, __LINE__);

那么有哪些日志级别，又各有何区别呢？

日志级别

级别	宏名	描述
0	KERN_EMERG	最高级别，系统遇到紧急状况，严重时可能挂机了
1	KERN_ALERT	告警级别，需要立即关注或处置
2	KERN_CRIT	critical 情况，比较紧急
3	KERN_ERR	当系统检测到某个错误
4	KERN_WARNING	warning中文也会翻译成警告，但是紧急程度级别比Alert低，
5	KERN_NOTICE	正常操作但或许需要注意的一些操作
6	KERN_INFO	信息提示级别，比如驱动指示一下做了什么操作
7	KERN_DEBUG	调试信息

对于这个表，或许刚使用时会不知所措，这么多级别到底该传入什么级别呢？我的理解如果是自己定义的驱动按照字面意思理解，灵活使用即可。唯一需要注意的时候，不同的级别打印或许在控制台会有不同的体现，这取决于控制台打印的配置。

格式化

下面内容来源于./Documentation/printk-formats.txt,整理于此方便使用：

• 基本变量

类型	格式化
int	%d 或 %x
unsigned int	%u 或 %x
long	%ld 或 %lx
unsigned long	%lu 或 %lx
long long	%lld 或 %llx
unsigned long long	%llu 或 %llx
size_t	%zu 或 %zx
ssize_t	%zd 或 %zx
s32	%d 或 %x
u32	%u 或 %x
s64	%lld 或 %llx
u64	%llu 或 %llx

注意：内核打印不支持浮点，%n也不支持，%e, %f, %g, %a也不支持，如使用了会导致WARN。

• 指针

类型	格式化
%p	打印基本指针
%pF	versatile_init+0x0/0x110
%pf	versatile_init
%pS	versatile_init+0x0/0x110
%pSR	versatile_init+0x9/0x110
%ps	versatile_init
%pB	prev_fn_of_versatile_init+0x88/0x88

除上面描述的这些格式化，printk还支持格式化打印块设备名、IPv4、IPv6地址、网络设备属性、MAC/FDDI地址、UUID/GUID地址等等。如需要用到可查阅该文档获取更为详细的信息。

修改控制台打印级别

运行时修改

在调试过程中，或许会发现有的printk信息没有打印出来，那么肯定是默认运行中内核控制台printk打印级别低于代码中使用的级别，那么如果不想重新编译内核，有没有办法动态修改呢？来看看怎么修改：

在/proc/sys/kernel/printk文件中，有4个属性分别对应：

• 当前控制台日志级别
• 默认日志级别
• 最小日志级别
• 启动阶段默认日志级别

使用下面命令可以当前控制台printk日志级别：

echo 6 > /proc/sys/kernel/printk

这里传入6，表示小于6级别的打印都将会被打印出来。这里可以根据需要传入不同的值。取值参见前表<日志级别>。如想将所有的信息都打印出来，传入8即可，如：

echo 8 > /proc/sys/kernel/printk

如果你想将这些打印记录进一个文件，则可以使用klogd进行重定向，比如：

klogd -o -f ./kernel.msg

编译修改

如果你想将某一模块的内核打印在编译时使能，这样做的好处是在模块加载过程中的所有的信息在控制台都可以看到，你还可以增加你感兴趣的代码添加打印信息，用以辅助调试。这怎么实现呢？

这里需要去看看你的内核模块代码是以何种方式去调用printk的，比如有的代码这样调用：

static int tea5764_i2c_probe(struct i2c_client *client,
        const struct i2c_device_id *id)
{
 struct tea5764_device *radio;
 struct v4l2_device *v4l2_dev;
 struct v4l2_ctrl_handler *hdl;
 struct tea5764_regs *r;
 int ret;

 PDEBUG("probe");
 .....

这里的PDEBUG其实就是printk的一种宏重包装：

#define PINFO(format, ...)
 printk(KERN_INFO KBUILD_MODNAME ": "
  DRIVER_VERSION ": " format "
", ## __VA_ARGS__)
#define PWARN(format, ...)
 printk(KERN_WARNING KBUILD_MODNAME ": "
  DRIVER_VERSION ": " format "
", ## __VA_ARGS__)
# define PDEBUG(format, ...)
 printk(KERN_DEBUG KBUILD_MODNAME ": "
  DRIVER_VERSION ": " format "
", ## __VA_ARGS__)

还有的是这样：

static int ad9467_spi_read(struct spi_device *spi, unsigned reg)
{
 unsigned char buf[3];
 int ret;

 if (spi) {
  buf[0] = 0x80 | (reg >> 8);
  buf[1] = reg & 0xFF;

  ret = spi_write_then_read(spi, &buf[0], 2, &buf[2], 1);

  dev_dbg(&spi->dev, "%s: REG: 0x%X VAL: 0x%X (%d)
",
   __func__, reg, buf[2], ret);

  if (ret < 0)
  {
   dev_dbg(&spi->dev, "spi_write_then_read failed %s: REG: 0x%X VAL: 0x%X (%d)
",
   __func__, reg, buf[2], ret);   
   return ret;
  }
   

  return buf[2];
 }
 return -ENODEV;
}

dev_dbg其本质上也是调用的printk,来看看,在./include/linux/device.h中

#if defined(CONFIG_DYNAMIC_DEBUG)
#define dev_dbg(dev, fmt, ...)      
 dynamic_dev_dbg(dev, dev_fmt(fmt), ##__VA_ARGS__)
#elif defined(DEBUG)
#define dev_dbg(dev, fmt, ...)      
 dev_printk(KERN_DEBUG, dev, dev_fmt(fmt), ##__VA_ARGS__)
#else
#define dev_dbg(dev, fmt, ...)      
({         
 if (0)        
  dev_printk(KERN_DEBUG, dev, dev_fmt(fmt), ##__VA_ARGS__); 
})
#endif

要把这些调试信息从控制台给打印出来，可以这样做：

• 修改一下默认打印机别，在./inlcude/linux/printk.h中，直接修改其默认值，8表示全放出来。

#define CONSOLE_LOGLEVEL_DEFAULT 8//CONFIG_CONSOLE_LOGLEVEL_DEFAULT
#define CONSOLE_LOGLEVEL_QUIET  CONFIG_CONSOLE_LOGLEVEL_QUIET

• 在模块顶端添加宏定义

/*添加宏定义DEBUG开关*/
#define DEBUG
#include 
#include 
#include 

当然，你也可以通过makefile来定义这个宏，找到你模块所在的模块，添加如下语句：

DEBUG = y

推荐使用device.h中的定义的一系列宏，对应了不同日志级别。

#define dev_emerg(dev, fmt, ...)     
 _dev_emerg(dev, dev_fmt(fmt), ##__VA_ARGS__)
#define dev_crit(dev, fmt, ...)      
 _dev_crit(dev, dev_fmt(fmt), ##__VA_ARGS__)
#define dev_alert(dev, fmt, ...)     
 _dev_alert(dev, dev_fmt(fmt), ##__VA_ARGS__)
#define dev_err(dev, fmt, ...)      
 _dev_err(dev, dev_fmt(fmt), ##__VA_ARGS__)
#define dev_warn(dev, fmt, ...)      
 _dev_warn(dev, dev_fmt(fmt), ##__VA_ARGS__)
#define dev_notice(dev, fmt, ...)     
 _dev_notice(dev, dev_fmt(fmt), ##__VA_ARGS__)
#define dev_info(dev, fmt, ...)      
 _dev_info(dev, dev_fmt(fmt), ##__VA_ARGS__)

这有什么好处呢，因为这样可以将模块的设备名给打印出来。比如我在调试一个IIO设备时，其关联的SPI控制接口到底发了些什么控制命令，通过这种方式就可以非常清楚的看到驱动调用了什么设备，写了哪些寄存器，写的什么值。

ad9467 spi1.0: ad9467_spi_write: REG: 0x5 VAL: 0x1 (0)
ad9467 spi1.0: ad9467_spi_write: REG: 0xD VAL: 0x0 (0)
ad9467 spi1.0: ad9467_spi_write: REG: 0x5 VAL: 0x3 (0)
ad9467 spi1.0: ad9467_spi_write: REG: 0xFF VAL: 0x1 (0)
ad9467 spi1.0: ad9467_spi_write: REG: 0xFF VAL: 0x0 (0)
ad9467 spi1.0: ad9467_spi_write: REG: 0x5 VAL: 0x2 (0)
ad9467 spi1.0: ad9467_spi_write: REG: 0xD VAL: 0x0 (0)
ad9467 spi1.0: ad9467_spi_write: REG: 0x5 VAL: 0x3 (0)
ad9467 spi1.0: ad9467_spi_write: REG: 0xFF VAL: 0x1 (0)

仍然没有看到？

如果你配了这些，甚至编译了，可是你还是没有看到打印信息，那么可能printk没有使能，在哪里使能呢？

CONFIG_PRINTK宏是内核打印的编译开关，大概率是这个配置没有使能。

总结一下

内核模块的调试还有很多其他的手段，printk则是一个非常高效的调试手段，所有如何比较好的利用printk进行打印调试，是做内核模块调试一个必要掌握的手段，至于printk的内部实现其实也较为复杂，这块代码则没有必要深究，当然如果从学习的角度去分析分析其代码如何实现的，也是不错的。好了，本期就分享到这里，咱们下期见～

 

责任编辑：haq