精致全景图 | linux内核输出的日志去哪里了
时间：2021-09-26 13:40:15
手机看文章
扫描二维码
随时随地手机看文章
[导读]因为图片比较大，微信公众号上压缩的比较厉害，所以很多细节都看不清了，我单独传了一份到github上，想要原版图片的，可以点击下方的阅读原文，或者直接使用下面的链接，来访问github：https://github.com/wangyuntao/linux-kernel-illus...
因为图片比较大，微信公众号上压缩的比较厉害，所以很多细节都看不清了，我单独传了一份到github上，想要原版图片的，可以点击下方的阅读原文，或者直接使用下面的链接，来访问github：
https://github.com/wangyuntao/linux-kernel-illustrated
另外，精致全景图系列文章，以及之后的linux内核分析文章，我都会整理到这个github仓库里，欢迎大家star收藏。
熟悉linux内核，或者看过linux内核源码的同学就会知道，在内核中，有一个类似于c语言的输出函数，叫做printk，使用它，我们可以打印各种我们想要的信息，比如内核当前的运行状态，又或者是我们自己的调试日志等，非常方便。
那当我们调用printk函数后，这些输出的信息到哪里去了呢？我们又如何在linux下的用户态，查看这些信息呢？
为了解答这些疑问，我画了一张printk全景图，放在了文章开始的部分，这张图既包含了printk在内核态的实现，又包含了其输出的信息在用户态如何查看。
我们可以根据这张图，来理解printk的整体架构。
在内核编码时，如果想要输出一些信息，通常并不会直接使用printk，而是会使用其衍生函数，比如 pr_err / pr_info / pr_debug 等，这些衍生函数附带了日志级别、所属模块等其他信息，比较友好，但其最终还是调用了printk。
printk函数会将每次输出的日志，放到内核为其专门分配的名为ring buffer的一个槽位里。
ring buffer其实就是一个用数组实现的环形队列，不过既然是环形队列，就会有一个问题，即当ring buffer满了的时候，下一条新的日志，会覆盖最开始的旧的日志。
ring buffer的大小，可以通过内核参数来修改。
printk在将日志放到ring buffer后，会再调用系统console的相关方法，将还未输出到系统控制台的消息，继续输出到控制台，这个后面会详细说，这里就暂不赘述。
以上就是printk在内核态的实现。
在用户态，我们有几个方式，可以查看printk输出的内核日志，比如使用dmesg命令，cat /proc/kmsg文件，或者是使用klogctl函数等，这些方式分别对应于全景图中用户态的橙色、绿色、和蓝色的部分。
dmesg命令，在默认情况下，是通过读取/dev/kmsg文件，来实现查看内核日志的。
当该命令运行时，dmesg会先调用open函数，打开/dev/kmsg文件，该打开操作在内核中的逻辑，会为dmesg分配一个file实例，在这个file实例里，会有一个seq变量，该变量记录着下一条要读取的内核日志在ring buffer中的位置。
刚打开/dev/kmsg文件时，这个seq指向的就是ring buffer中最开始的那条日志。
之后，dmesg会以打开的/dev/kmsg文件为媒介，不断的调用read函数，从内核中读取日志消息，每读取出一条，seq的值都会加一，即指向下一条日志的位置，依次往复，直到所有的内核日志读取完毕，dmesg退出。
以上就是dmesg的主体实现。
第二种查看内核日志的方式，是通过 cat /proc/kmsg 命令。
该命令和dmesg命令的实现机制基本类似，都是通过读文件，只不过cat读取的是/proc/kmsg文件，而dmesg读取的是/dev/kmsg文件。
读取这两个文件最大的区别是，/dev/kmsg文件每次打开时，内核都会为其分配一个单独的seq变量，而/proc/kmsg文件每次打开时，用的都是同一个全局的静态seq变量，叫做syslog_seq。
syslog_seq指向的也是下一条要读取的内核日志在ring buffer中的位置，但因为它是一个全局的静态变量，当有多个进程要读取/proc/kmsg文件时，就会有一个比较严重的问题，即内核日志会被这几个进程随机抢占读取，也就是说，每个进程读到的都是整个内核日志的一部分，是不完整的，这也是dmesg命令默认不使用/proc/kmsg文件的原因。
第三种查看内核日志的方式，是通过klogctl函数。
该函数是glibc对syslog系统调用的一个简单封装，其具体使用方式，可以参考全景图中用户态的蓝色部分。
klogctl函数可以指定很多命令，在上图的示例中，我们使用的是SYSLOG_ACTION_READ命令，以此来模拟 cat /proc/kmsg 行为。
其实在内核层面，cat /proc/kmsg命令，使用的就是klogctl对应的syslog系统调用的SYSLOG_ACTION_READ命令的处理逻辑，所以示例中的klogctl函数相关代码，和 cat /proc/kmsg 命令其实是等价的。
也就是说，klogctl函数在内核里使用的也是syslog_seq变量，它也有和/proc/kmsg文件同样的问题。
其实还有一种方式可以查看内核日志，就是通过系统控制台。
但这种方式和前面讲的三种方式都不一样，它是完全被动的，是内核在调用printk函数，将日志信息放到ring buffer后，再去通知系统控制台，告知其可以输出这些日志。
系统控制台也是通过一个console_seq变量，记录下一条要输出内核日志的所在位置。
这里说的系统控制台，是指我们在开机的时候，黑色屏幕输出的那些内容，但当我们进入图形化界面后，我们就看不到系统控制台的输出了，除非我们再用 ctrl alt f1/f2/f3 等方式，切换成系统控制台。
系统控制台输出的内容，是被日志级别过滤过的，内核默认的日志过滤级别是7，即debug级别以上的日志，比如info / err 等，这些都会输出，但debug级别不会输出。
该日志过滤级别，可以通过很多方式改变，比如说，可以通过内核参数 loglevel，所以，如果发现系统控制台没有输出想要的日志信息，先看下其是否被过滤掉了。
以上就是printk生态的完整实现。
了解printk函数的实现，对于内核开发者或研究者来说，意义非常大，但对于普通的应用开发人员来说，又有什么帮助呢？
其实，随着技术的深入，我们不应该再只关心应用层面的行为，而且还要关心系统层面的行为，这样我们才能更好的去定位问题，更好的去保证我们应用的健康运行。
比如，当我们的应用需要内存时，会向操作系统申请，操作系统此时给我们的，其实是虚拟内存，只有当我们的进程真正的在使用这些内存时，比如读/写，操作系统才会为其分配物理内存。
但假设此时物理内存没有了，那操作系统会怎么办？
对于linux内核来说，它会选择一个使用内存最多的进程，然后将其kill掉，以此来释放内存，保证后续的内存分配操作能够成功，这个我在之前文章 为什么我的进程被kill掉了 有详细讲过。
对于内核的这种行为，我们就应该多加关注，而关注的方式，就是查看内核日志。
比如，linux内核在kill掉进程时，会用pr_err记录一行日志：
如果我们发现一个进程跑着跑着就没有了，就可以通过dmesg命令，查看是否有这个日志，如果有，说明该进程因为系统内存不足，被操作系统kill掉了。
类似的，内核里还有很多error级别，甚至更高级别的日志需要我们关注，通过这些日志，我们可以及时的发现系统的异常情况，必要时可以人工介入进行干预。
总之，对系统了解的越深，内核日志对我们的帮助就越大。
就这些，希望你喜欢。
下载文档
