Linux日志管理-printk和demsg

1 printk#

printk函数主要做两件事情：第一件就是将信息记录到log中，而第二件事就是调用控制台驱动来将信息输出。printk的相关函数定义在linux/printk.h。

1.1 日志级别#

printk需要设置日志级别，用来控制printk打印的这条信息是否在终端上显示的，当printk设置的日志级别高于控制台级别时，printk要打印的信息才会在控制台打印出来。

内核日志一共有8种级别:

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

1.2 控制台级别#

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
#define MINIMUM_CONSOLE_LOGLEVEL 1 /*可以使用的最小日志级别*/
#define DEFAULT_CONSOLE_LOGLEVEL 7 /*默认的控制台级别*/
#define DEFAULT_MESSAGE_LOGLEVEL 4 /* 默认的日志级别 */

int console_printk[4] = {
    DEFAULT_CONSOLE_LOGLEVEL,/*控制台日志级别：优先级高于该值的消息将被打印至控制台*/
    DEFAULT_MESSAGE_LOGLEVEL,/*缺省的消息日志级别：将用该优先级来打印没有优先级的消息*/
    MINIMUM_CONSOLE_LOGLEVEL,/*最低的控制台日志级别：控制台日志级别可被设置的最小值（最高优先级）*/
    DEFAULT_CONSOLE_LOGLEVEL,/*缺省的控制台日志级别：控制台日志级别的缺省值*/
};

#define console_loglevel (console_printk[0])
#define default_message_loglevel (console_printk[1])
#define minimum_console_loglevel (console_printk[2])
#define default_console_loglevel (console_printk[3])

使用命令 cat /proc/sys/kernel/printk 来查看这四个值:

img

结果显示了 current, default, minimum 和 boot-time-default 日志级别。

其中的 4 4 1 7，分别对应与：console_loglevel、default_message_loglevel、minimum_console_loglevel、default_console_loglevel

default_message_loglevel：

缺省时的消息日志级别，因此当printk未指定优先级时，将以该默认级别输出，也就是DEFAULT_MESSAGE_LOGLEVEL =4， 对应KERN_WARNING。

也就是说printk("hello world\n");就表示printk(KERN_WARNING "hello world\n");

那如果我们将控制台级别设成<4，如：

echo 3 > /proc/sys/kernel/printk

那么printk("hello world\n");就无法输出到控制台。

名称 字符串 别名函数
KERN_EMERG “0” pr_emerg()
KERN_ALERT “1” pr_alert()
KERN_CRIT “2” pr_crit()
KERN_ERR “3” pr_err()
KERN_WARNING “4” pr_warn()
KERN_NOTICE “5” pr_notice()
KERN_INFO “6” pr_info()
KERN_DEBUG “7” pr_debug() and pr_devel() 若定义了DEBUG
KERN_DEFAULT “” KERN_WARNING
KERN_CONT “c” pr_cont()

1.3 修改控制台级别#

1
2
3
echo "n" > /proc/sys/kernel/printk
#Eg:
echo 8 > /proc/sys/kernel/printk

img

另一种方式，使用 dmesg：

1
dmesg -n 8

此时所有的printk日志级别都会被输出到控制台，如下图所示:

1
2
3
4
5
6
7
8
printk ( KERN_EMERG "Hello, EMERG.\n" ) ;
printk ( KERN_ALERT "Hello, ALERT.\n" ) ;
printk ( KERN_CRIT "Hello, CRIT.\n" ) ;
printk ( KERN_ERR "Hello, ERR.\n" ) ;
printk ( KERN_WARNING "Hello, WARNING.\n" ) ;
printk ( KERN_NOTICE "Hello, NOTICE.\n" ) ;
printk ( KERN_INFO "Hello, INFO.\n" ) ;
printk ( KERN_DEBUG "Hello, DEBUG.\n" ) ;

img

再来一种方法，修改bootargs：

Uboot中修改console=ttyS0,115200改为loglevel=7 console=ttyS0,115200,表示设置内核的console_loglevel 值=7，开机cat /proc/sys/kernel/printk，可以看到控制台级别被设置成了7:

img

1.4 printk带时间戳讯息#

make menuconfig开启如下:

img

1.5 printk底层实现#

源码位于kernel\printk\printk.c。

img

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
printk
    // linux 4.9: kernel/printk/internal.h
    // linux 5.4: kernel/printk/printk_safe.c
    vprintk_func 
        vprintk_default(fmt, args);
            vprintk_emit
                vprintk_store // 把要打印的信息保存在log_buf中
                    log_output
                preempt_disable();
                if (console_trylock_spinning())
                    console_unlock();
                preempt_enable();
console_unlock
    for (;;) {
        msg = log_from_idx(console_idx);
        if (suppress_message_printing(msg->level)) {
            /* 如果消息的级别数值大于console_loglevel, 则不打印此信息 */
        }
        printk_safe_enter_irqsave(flags);
        call_console_drivers(ext_text, ext_len, text, len);
        printk_safe_exit_irqrestore(flags);
    }

img

1.5.1 命令行参数console#

1
2
3
/* IMX6ULL */
[root@100ask:~]# cat /proc/cmdline
console=ttymxc0,115200 root=/dev/mmcblk1p2 rootwait rw

命令行信息可以来自设备树或者环境变量:

1
2
3
4
5
/ {
    chosen {
                bootargs = "console=ttymxc1,115200";
        };
};

修改环境变量：

1
2
3
4
5
6
7
/* 进入IMX6ULL的UBOOT */
=> print mmcargs
mmcargs=setenv bootargs console=${console},${baudrate} root=${mmcroot}
=> print console
console=ttymxc0
=> print baudrate
baudrate=115200

1.5.2 console驱动注册过程#

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
struct console {
    char    name[16];  // name为"ttyXXX"，在cmdline中用"console=ttyXXX0"来匹配
    // 输出函数
    void    (*write)(struct console *, const char *, unsigned);
    
    int        (*read)(struct console *, char *, unsigned);
    // APP访问/dev/console时通过这个函数来确定是哪个(index)设备
    // 举例:
    // a. cmdline中"console=ttymxc1"
    // b. 则注册对应的console驱动时：console->index = 1
    // c. APP访问/dev/console时调用"console->device"来返回这个index
    struct  tty_driver *(*device)(struct console *co, int *index);
    void    (*unblank)(void);
    // 设置函数, 可设为NULL
    int        (*setup)(struct console *, char *);
    // 匹配函数, 可设为NULL
    int        (*match)(struct console *, char *name, int idx, char *options); 
    short    flags;
    // 哪个设备用作console: 
    // a. 可以设置为-1, 表示由cmdline确定
    // b. 也可以直接指定
    short    index;
    // 常用: CON_PRINTBUFFER
    int        cflag;
    void    *data;
    struct     console *next;
};

1.5.2.1 处理命令行参数#

1
2
__setup("console=", console_setup);
console=ttymxc0,115200  console=ttyVIRT0

处理u-boot通过dts传给内核的cmdline参数，比如bootparam参数。

对于这两个”console=xxx”就会调用console_setup函数两次，构造得到2个数组项:

1
2
3
4
5
6
7
8
9
10
struct console_cmdline {
    char    name[16];            /* Name of the driver        */
    int    index;                /* Minor dev. to use        */
    char    *options;            /* Options for the driver   */
#ifdef CONFIG_A11Y_BRAILLE_CONSOLE
    char    *brl_options;            /* Options for braille driver */
#endif
};
 
static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];

在cmdline中，最后的”console=xxx”就是”selected_console”(被选中的console，对应/dev/console)：

img

1.5.2.2 register_console#

1
2
3
uart_add_one_port
    uart_configure_port
        register_console(port->cons);

Linux下Uart子系统驱动 - fuzidage - 博客园 (cnblogs.com)

1.5.2.3 /dev/console#

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
tty_open
    tty = tty_open_by_driver(device, inode, filp);
        driver = tty_lookup_driver(device, filp, &index);
            case MKDEV(TTYAUX_MAJOR, 1): {
                struct tty_driver *console_driver = console_device(index);
 
/* 从console_drivers链表头开始寻找
 * 如果console->device成功，就返回它对应的tty_driver
 * 这就是/dev/console对应的tty_driver
 */ 
struct tty_driver *console_device(int *index)
{
    struct console *c;
    struct tty_driver *driver = NULL;
 
    console_lock();
    for_each_console(c) {
        if (!c->device)
            continue;
        driver = c->device(c, index);
        if (driver)
            break;
    }
    console_unlock();
    return driver;
}

Linux下Uart子系统驱动 - fuzidage - 博客园 (cnblogs.com)

1.6 内核信息的早期打印#

当我们注册了uart_driver、并调用uart_add_one_port后，它里面才注册console，在这之后才能使用printk。

如果想更早地使用printk函数，比如在安装UART驱动之前就使用printk，这时就需要自己去注册console。

更早地、单独地注册console，有两种方法：

early_printk：自己实现write函数，不涉及设备树，简单明了

earlycon：通过设备树传入硬件信息，跟内核中驱动程序匹配
earlycon是新的、推荐的方法，在内核已经有驱动的前提下，通过设备树或cmdline指定寄存器地址即可。

1.6.1 early_printk#

arch\arm\kernel\early_printk.c，必须实现这几点：

  • 配置内核，选择：CONFIG_EARLY_PRINTK
  • 内核中实现：printch函数
  • cmdline中添加：earlyprintk

img

1.6.2 earlycon#

2 prink.h介绍#

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
#define pr_emerg(fmt, ...) \
        printk(KERN_EMERG pr_fmt(fmt), ##__VA_ARGS__)
#define pr_alert(fmt, ...) \
        printk(KERN_ALERT pr_fmt(fmt), ##__VA_ARGS__)
#define pr_crit(fmt, ...) \
        printk(KERN_CRIT pr_fmt(fmt), ##__VA_ARGS__)
#define pr_err(fmt, ...) \
        printk(KERN_ERR pr_fmt(fmt), ##__VA_ARGS__)
#define pr_warning(fmt, ...) \
        printk(KERN_WARNING pr_fmt(fmt), ##__VA_ARGS__)
#define pr_warn pr_warning
#define pr_notice(fmt, ...) \
        printk(KERN_NOTICE pr_fmt(fmt), ##__VA_ARGS__)
#define pr_info(fmt, ...) \
        printk(KERN_INFO pr_fmt(fmt), ##__VA_ARGS__)
/* If you are writing a driver, please use dev_dbg instead */
#if defined(CONFIG_DYNAMIC_DEBUG)
#include <linux/dynamic_debug.h>

/* dynamic_pr_debug() uses pr_fmt() internally so we don't need it here */
#define pr_debug(fmt, ...) \
        dynamic_pr_debug(fmt, ##__VA_ARGS__)
#elif defined(DEBUG)
#define pr_debug(fmt, ...) \
        printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#else
#define pr_debug(fmt, ...) \
        no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif

img

pr_emerg到pr_info都是一些基本的kernel打印函数，用来设置内核日志打印级别，可以看到它和下面这种打印本质上并无差异。

而pr_debug则有3种输出方式，当开启dynamic_debug后，则走dynamic_pr_debug流程（dynamic_debug见下一节）。当用户开启了DEBUG宏，则走printk流程，否则什么都不打印。

3 dmesg命令#

3.1 /proc/kmsg#

/proc/kmsg 是一个特殊的文件，它提供了内核消息缓冲区的访问，这个缓冲区包含了内核产生的所有消息，包括各种调试和错误信息，如内核的启动打印

dmesg命令就是cat /proc/kmsg。

3.2 修改内核日志缓冲区大小#

img

3.3 dmesg#

img

dmesg命令是从kernel ring buffer中读取内核日志信息。因此可以用dmesg命令查看。

1
2
3
4
5
6
7
8
9
10
-C:  直接清除ring buffer
-c： 当完成打印显示后清除环缓冲内的内容。
-s： 缓冲区大小
　	定义一个大小为"缓冲区大小"的缓冲区用于查询内核环缓冲区。默认大小为 8196，如果你设置了一个大于默认值的环缓冲区，那你就可以用这个选项定义一个相当的缓冲区来查看完整的环缓冲区内容。

-n：级别

dmesg -k：打印内核信息
dmesg -u：打印用户空间信息

其实用dmesg -n也是可以设置控制台打印级别:

img

有时候在调试kernel驱动时内核panic了or死锁了，那么无法敲命令，如何查看日志呢？重启后日志就没了，那么可以敲如下命令：

1
cat /proc/kmsg > /mnt/data/ker.log & 2>&1

用后台进程将日志导入到文件。

  1. dmesg -f：根据系统打印信息:

可用系统有

kern - kernel messages（内核信息）
user - random user-level messages（随机用户信息）
mail - mail system（邮件系统信息）
daemon - system daemons（系统守护进程信息）
auth - security/authorization messages（认证授权安全信息）
syslog - messages generated internally by syslogd（系统日志信息）
lpr - line printer subsystem（打印机信息）
news - network news subsystem（网络系统信息）

img

  1. dmesg -l：根据level来打印信息:

可用的level信息有

   emerg - system is unusable（系统无法使用）
      alert - action must be taken immediately
       crit - critical conditions（临界条件）
        err - error conditions（错误条件）
       warn - warning conditions（警告条件）
     notice - normal but significant condition
       info - informational
      debug - debug-level messages（debug）

img