[TOC]

内核版本:Linux5.4.0
本文首先通过介绍用于配置和收集日志信息的应用程序接口(API)来说明了内核的日志(见图 1 关于总结框架和组件的示意图)。然后,本文介绍了日志数据从内核到用户空间的移动过程。最后,本文还介绍了基于内核的日志数据的目标:用户空间中使用 rsyslog 进行日志管理。
内核日志生态系统

内核API

内核的日志是通过 printk 函数实现的,它与用户空间对应函数 printf(按格式打印)具有相似的作用。printf 命令在编程语言中已存在很长时间,最近出现是在 C 语言中,但是最早出现可以追溯到 50 年代和 60 年代的 Fortran(PRINT 和 FORMAT 语句)、BCPL(writf 函数;BCPL 是 C 的前身)和 ALGOL 68 语言(printf 和 putf)。
在内核中,printk(打印内核)可以使用与 printf 函数几乎一样的格式将将格式化消息写入到缓冲区。您可以在 ./linux/include/linux/kernel.h(及其实现 ./linux/kernel/printk.c)中看到 printk 的格式:

int printk( const char * fmt, ... );

这个格式表示的是一个用于定义文本和格式的字符串(类似于 printf),它同时带有一组可变个数参数(由省略号表示 [...])。

内核配置与错误
通过 printk 实现的日志是通过内核配置选项 CONFIG_PRINTK 激活的。虽然 CONFIG_PRINTK 一般都是激活的,但是不包含这个选项的系统对内核的调用会返回一个 ENOSYS 错误返回值。

在使用 printk 时,您首先会发现的不同点更多是关于协议,而不是功能的。这个特性使用了 C 语言的一种模糊方面来简化消息级别和优先级的规范。内核允许每一个消息根据日志级别(定义不同消息重要必的八种级别之一)来分类。这些级别可以用来判断系统是否不可用(紧急消息)、是否发现严重状况(严重消息)或者是否为简单报告消息。 这个内核代码直接将日志级别定义消息的第一个参数,下面这个例子说明的就是严重消息的定义:

printk( KERN_CRIT "Error code %08x.\n", val );

注意,第一个参数并不一个真正的参数,因为其中没有用于分隔级别(KERN_CRIT)和格式字符的逗号(,)。KERN_CRIT 本身只是一个普通的字符串(事实上,它表示的是字符串 "2";表 1 列出了完整的日志级别清单)。作为预处理程序的一部分,C 会自动地使用一个名为 字符串串联 的功能将这两个字符串组合在一起。组合的结果是将日志级别和用户指定的格式字符串包含在一个字符串中。注意,如果调用者未将日志级别提供给 printk,那么系统就会使用默认值 KERN_WARNING(表示只有 KERN_WARNING 级别以上的日志消息会被记录。)
在头文件include/linux/kernel_levels.h里面,定义了日志级别和使用方法:

// 位置:include/linux/kernel_levels.h
#define KERN_SOH    "\001"        /* ASCII Start Of Header */
#define KERN_SOH_ASCII    '\001'

#define KERN_EMERG    KERN_SOH "0"    /* system is unusable */
#define KERN_ALERT    KERN_SOH "1"    /* action must be taken immediately */
#define KERN_CRIT    KERN_SOH "2"    /* critical conditions */
#define KERN_ERR    KERN_SOH "3"    /* error conditions */
#define KERN_WARNING    KERN_SOH "4"    /* warning conditions */
#define KERN_NOTICE    KERN_SOH "5"    /* normal but significant condition */
#define KERN_INFO    KERN_SOH "6"    /* informational */
#define KERN_DEBUG    KERN_SOH "7"    /* debug-level messages */

#define KERN_DEFAULT    KERN_SOH "d"    /* the default kernel loglevel */

printk可以在内核的任意上下文中调用。这个调用从 ./linux/kernel/printk.c 中的 printk 函数开始,它会在使用 va_start 解析可变长度参数之后调用 vprintk(在同一个源文件)。printk函数的实现如下:

asmlinkage __visible int printk(const char *fmt, ...)
{
    va_list args;                // 可变参数
    int r;

    va_start(args, fmt);
    r = vprintk_func(fmt, args);
    va_end(args);

    return r;
}
EXPORT_SYMBOL(printk);

其中vprintk_func()函数定以如下:

__printf(1, 0) int vprintk_func(const char *fmt, va_list args)
{
    /*
     * Try to use the main logbuf even in NMI. But avoid calling console
     * drivers that might have their own locks.
     */
    if ((this_cpu_read(printk_context) & PRINTK_NMI_DIRECT_CONTEXT_MASK) &&
        raw_spin_trylock(&logbuf_lock)) {
        int len;

        len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args);
        raw_spin_unlock(&logbuf_lock);
        defer_console_output();
        return len;
    }

    /* Use extra buffer in NMI when logbuf_lock is taken or in safe mode. */
    if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK)
        return vprintk_nmi(fmt, args);

    /* Use extra buffer to prevent a recursion deadlock in safe mode. */
    if (this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK)
        return vprintk_safe(fmt, args);

    /* No obstacles. */
    return vprintk_default(fmt, args);
}

vprintk 函数执行了许多管理级检查(递归检查),然后获取日志缓冲区的锁(__log_buf)。接下来,它会对输入的字符串进行日志级别检查; 如果发现日志级别信息,那么对应的日志级别就会被设置。最后,vprintk 会获取当前时间(使用函数 cpu_clock)并使用 sprintf(不是标准库版本,而是在 ./linux/lib/vsprintf.c 中实现的内部内核版本)将它转换成一个字符串。这个字符串会被传递给 printk,然后它会被一个管理缓冲边界(emit_log_char)的特殊函数复制到内核日志缓冲区中。这个函数最后将获取和释放执行控制台信号,并将下一条日志消息发送到控制台(在 release_console_sem 中执行)。内核缓冲缓冲区的大小初始值为 4KB,但是最新的内核大小已经升级到 16KB(在不同的体系架构上,这个值最高可以达到 1MB)。

日志辅助函数
内核也提供了一些日志辅助函数,它们可以简化日志函数的使用。每一个日志级别都有一个对应的函数,它会扩展为 printk 函数的一个宏。例如,如果要使用 printk 处理 KERN_EMERG 日志级别时,您可以直接使用 pr_emerg。所有宏都已列在 ./linux/include/linux/kernel.h 文件中。

至此,您已经了解用于将日志消息插入到内核环缓冲区的 API。现在,让我们讨论一下用于将数据从内核移动到用户空间的方法。

内核日志与接口

多用途的 syslog 系统调用提供了内核的日志缓冲区访问方法。这个调用执行了很多个操作,所有操作都可以在用户空间执行,但是只有一个操作可以被非 root 用户执行。syslog 系统调用的原型定义位于 ./linux/include/linux/syslog.h;而它的实现位于 ./linux/kernel/printk.c。

syslog 调用是作为内核日志消息环缓冲区的输入/输出(I/O)和控制接口。通过 syslog 调用,应用程序可以读取日志消息(部分、整体或者只读取新消息), 以及控制环缓冲区的行为(清除内容、设置日志的消息级别、启用或禁用控制台等等)。图 2 用图形说明了使用所讨论的主要组件进行日志记录的过程。
标示主要组件的内核日志
syslog 调用(在内核中调用 ./linux/kernel/printk.c 的 do_syslog)是一个相对较小的函数,它能够读取和控制内核环缓冲区。注意在 glibc 2.0 中,由于词汇 syslog 使用过于广泛,这个函数的名称被修改成 klogctl,它指的是各种调用和应用程序。syslog 和 klogctl(在用户空间中)的原型函数定义为:

int syslog( int type, char *bufp, int len );
int klogctl( int type, char *bufp, int len );

type 参数是用于传递所执行的命令,它指定了可选的缓冲区长度。
有一些命令(如清除环缓冲)是忽略 bufp 和 len 这两个参数的。虽然前面两个命令类型不会对内核进行任何操作,但是其余命令则是用于读取日志消息或控制日志。其中有三个命令是用于读取日志消息的。SYSLOG_ACTION_READ 用于阻塞操作,直至日志消息到达后才释放该操作,然后将它们返回到所提供的缓冲区。这个命令会处理这些消息(旧的消息将不会出现在这个命令的后续调用中。)
SYSLOG_ACTION_READ_ALL 命令会从日志读取最后 n 个字符(而 n 是在传递给 klogctl 的参数 'len' 中定义的)。SYSLOG_ACTION_READ_CLEAR 命令会先执行 SYSLOG_ACTION_READ_ALL 操作,然后执行 SYSLOG_ACTION_CLEAR 命令(清除环缓冲区)。SYSLOG_ACTION_CONSOLE ON 和 OFF 可以将日志级别设置为激活或禁用日志消息输出到控制台,而 SYSLOG_CONSOLE_LEVEL 则允许调用者定义控制台所接受的日志消息级别。最后,SYSLOG_ACTION_SIZE_BUFFER 是用于返回内核环缓冲区大小,而 SYSLOG_ACTION_SIZE_UNREAD 则返回当前内核环缓冲区可读取的字符数。表 2 显示了 SYSLOG 命令的完整清单。

使用 syslog/klogctl 系统调用实现的命令:

#ifndef _LINUX_SYSLOG_H
#define _LINUX_SYSLOG_H

/* Close the log.  Currently a NOP. */
#define SYSLOG_ACTION_CLOSE          0
/* Open the log. Currently a NOP. */
#define SYSLOG_ACTION_OPEN           1
/* Read from the log. */
#define SYSLOG_ACTION_READ           2
/* Read all messages remaining in the ring buffer. */
#define SYSLOG_ACTION_READ_ALL       3
/* Read and clear all messages remaining in the ring buffer */
#define SYSLOG_ACTION_READ_CLEAR     4
/* Clear ring buffer. */
#define SYSLOG_ACTION_CLEAR          5
/* Disable printk's to console */
#define SYSLOG_ACTION_CONSOLE_OFF    6
/* Enable printk's to console */
#define SYSLOG_ACTION_CONSOLE_ON     7
/* Set level of messages printed to console */
#define SYSLOG_ACTION_CONSOLE_LEVEL  8
/* Return number of unread characters in the log buffer */
#define SYSLOG_ACTION_SIZE_UNREAD    9
/* Return size of the log buffer */
#define SYSLOG_ACTION_SIZE_BUFFER   10

#define SYSLOG_FROM_READER           0
#define SYSLOG_FROM_PROC             1

int do_syslog(int type, char __user *buf, int count, int source);

#endif /* _LINUX_SYSLOG_H */

在实现上面的 syslog/klogctl 层之后,kmsg proc 文件系统成为一个 I/O 通道(在 ./linux/fs/proc/kmsg.c 中实现的),它提供了从内核缓冲区读取日志消息的二进制接口。这个读取操作通常是由一个守护程序(klogd 或 rsyslogd)实现的,它会处理这些消息,然后将它们传递给 rsyslog,以便(基于它的配置)转发到正确的日志文件中。
文件 /proc/kmsg 实现了少数等同于内部 do_syslog 的文件操作。在内部,open 调用与 SYSLOG_ACTION_OPEN 有关,而 SYSLOG_ACTION_CLOSE 则与 release 有关(每一个调用都实现为一个 No Operation Performed [NOP])。这个轮循操作会等待文件活动的完成,然后才调用 SYSLOG_ACTION_SIZE_UNREAD 确定可以读取的字符数。最后,read 操作会被映射到 SYSLOG_ACTION_READ,以处理可用的日志消息。注意,用户是不会用到 /proc/kmsg 文件的:守护程序用它来获取日志消息,并将它们转发到 /var 空间内必要的日志文件中。

用户空间应用程序

用户空间提供了许多读取和管理内核日志的访问方法。我们开始先介绍较底层的接口(如 /proc 文件系统配置元素),然后再介绍更高层的应用程序。
/proc 文件系统不仅提供了一个访问日志消息(kmsg)的二进制接口。它还有许多与上面讨论的 syslog/klogctl 相关或无关的配置元素。清单 1 显示了这些参数。
清单 1. /proc 中的 printk 配置参数

mtj@ubuntu:~$ cat /proc/sys/kernel/printk
4   4   1   7
mtj@ubuntu:~$ cat /proc/sys/kernel/printk_delay
0
mtj@ubuntu:~$ cat /proc/sys/kernel/printk_ratelimit
5
mtj@ubuntu:~$ cat /proc/sys/kernel/printk_ratelimit_burst
10

在清单 1 中,第一项定义了 printk API 当前使用的日志级别。这些日志级别表示了控制台的日志级别、默认消息日志级别、最小控制台日志级别和默认控制台日志级别。printk_delay 值表示的是 printk 消息之间的延迟毫秒数(用于提高某些场景的可读性)。注意,这里它的值为 0,而它是不可以通过 /proc 设置的。printk_ratelimit 定义了消息之间允许的最小时间间隔(当前定义为每 5 秒内的某个内核消息数)。消息数量是由 printk_ratelimit_burst 定义的(当前定义为 10)。如果您拥有一个非正式内核而又使用有带宽限制的控制台设备(如通过串口), 那么这非常有用。注意,在内核中,速度限制是由调用者控制的,而不是在 printk 中实现的。如果一个 printk 用户要求进行速度限制,那么该用户就需要调用 printk_ratelimit 函数。

dmesg 命令也可用于打印和控制内核环缓冲区。这个命令使用 klogctl 系统调用来读取内核环缓冲区,并将它转发到标准输出(stdout)。这个命令也可以用来清除内核环缓冲区(使用 -c 选项),设置控制台日志级别(-n 选项),以及定义用于读取内核日志消息的缓冲区大小(-s 选项)。注意,如果没有指定缓冲区大小,那么 dmesg 会使用 klogctl 的 SYSLOG_ACTION_SIZE_BUFFER 操作确定缓冲区大小。

最后,所有日志应用程序都是基于一个标准化日志框架 syslog,主流操作系统(包括 Linux® 和 Berkeley Software Distribution [BSD])都实现了这个框架。syslog 使用自身的协议实现在不同传输协议的事件通知消息传输(将组件分成发起者、中继者和收集者)。在许多情况中,所有这三种组件都在一个主机上实现。除了 syslog 的许多有意思的特性,它还规定了日志信息是如何收集、过滤和存储的。syslog 已经经过了许多的变化和发展。您可能听过 syslog、klog 或 sysklogd。最新版本的 Ubuntu 使用的是名为 rsyslog(基于原先的 syslog)的新版本 syslog,它指的是可靠的和扩展的 syslogd。

syslogd 守护程序通过它的配置文件 /etc/rsyslog.conf 来理解 /proc 文件系统的 kmsg 接口,并使用这些接口获取内核日志消息。注意,在内部,所有日志级别都是通过 /proc/kmsg 写入的,这样所传输的日志级别就不是由内核决定的,而是由 rsyslog 本身决定的。然后这些内核日志消息会存储在 /var/log/kern.log(及其他配置的文件)。在 /var/log 中有许多的日志文件,包括一般消息和系统相调用(/var/log/messages)、系统启动日志(/var/log/boot.log)、认证日志(/var/log/auth.log)等等。

虽然您可以检查这些日志,但是您也可以使用它们进行自动审计和检查。有许多日志文件分析器可以用于故障修复, 或者满足安全规范要求,以及自动地使用诸如模式识别或相关性分析(甚至是跨系统的)来发现问题。

结束语

本文简单地介绍了内核日志和一些应用程序—包括在内核中创建内核日志消息,在内核的环缓冲区存储消息,使用 syslog/klogctl 或 /proc/kmsg 实现到用户空间的消息传输,通过 rsyslog 日志框架实现转发,以及它在 /var/log 子树的最终测试位置。Linux 提供了(包括内核及外部空间的)丰富且灵活的日志框架。