性能文章>精致全景图 | linux内核输出的日志去哪里了>

精致全景图 | linux内核输出的日志去哪里了原创

1年前
7589112

 

因为图片比较大,微信公众号上压缩的比较厉害,所以很多细节都看不清了,我单独传了一份到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级别,甚至更高级别的日志需要我们关注,通过这些日志,我们可以及时的发现系统的异常情况,必要时可以人工介入进行干预。

 

总之,对系统了解的越深,内核日志对我们的帮助就越大。

 

就这些,希望你喜欢。

点赞收藏
分类:标签:
KINGYT

公众号 卯时卯刻,也可搜 ytcode

请先登录,查看1条精彩评论吧
快去登录吧,你将获得
  • 浏览更多精彩评论
  • 和开发者讨论交流,共同进步

为你推荐

【全网首发】内核是如何给容器中的进程分配CPU资源的?

【全网首发】内核是如何给容器中的进程分配CPU资源的?

【全网首发】细节拉满,80 张图带你一步一步推演 slab 内存池的设计与实现

【全网首发】细节拉满,80 张图带你一步一步推演 slab 内存池的设计与实现

【全网首发】从内核源码看 slab 内存池的创建初始化流程

【全网首发】从内核源码看 slab 内存池的创建初始化流程

多图详解Linux内存分配器slub

多图详解Linux内存分配器slub

【全网首发】深入理解 slab cache 内存分配全链路实现

【全网首发】深入理解 slab cache 内存分配全链路实现

图文详解 Linux 分段机制!

图文详解 Linux 分段机制!

12
1