基于aarch64分析kernel源码 四：printk 内核打印

一、参考

Message logging with printk — The Linux Kernel documentation

如何获得正确的printk格式占位符 — The Linux Kernel documentation

使用printk记录消息 — The Linux Kernel documentation

printk 内核打印 – 人人都懂物联网 (getiot.tech)

内核printk原理介绍 - 知乎 (zhihu.com)

Linux kernel log与调试_内核log_hui_zh的博客-CSDN博客

linux内核日志的存储与读取 | QZJ (eathanq.github.io)

二、printk概述

printk 函数主要做两件事情：

1. 将信息记录到 log 中；
2. 调用控制台驱动来将信息输出。
   

从上图可看出，其核心是一个叫做log buffer的循环缓冲区，printk作为生产者将消息存入该缓冲区，右边的log服务模块作为消费者可从log buffer中读取消息。这样设计有以下几个优点：

1、控制台和日志模块初始化前，内核的启动日志可以暂存到log buffer中。待它们初始化完成后，再输出相应信息。

2、在printk log输出太快，而log服务的处理速度不足时，防止log信息丢失。

3、将log输入模块和log输出模块解耦，增加设计的灵活性。

三、log buffer

在内核启动初期，系统内存布局和log buffer大小（cpu核心数等因素决定）不确定，导致无法动态分配内存。为了支持printk，内核通过全局变量方式定义一个log buffer（全局变量被定义在数据段中，会在内核镜像映射过程中被映射），其定义如下：

// kernel/printk/printk.c/* record buffer */
#define LOG_ALIGN __alignof__(unsigned long)
#define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT)
#define LOG_BUF_LEN_MAX (u32)(1 << 31)
static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN);
static char *log_buf = __log_buf;
static u32 log_buf_len = __LOG_BUF_LEN;

当必要信息初始化完成后，在 start_kernel 函数中调用 setup_log_buf(0) 函数动态分配 log buffer。

void __init setup_log_buf(int early)
{……log_buf_len = new_log_buf_len;log_buf = new_log_buf;new_log_buf_len = 0;……
}

四、printk_ringbuffer

log buffer通过数据结构printk_ringbuffer维护其状态信息，其主要成员的关系如下图：

// kernel/printk/printk_ringbuffer.h/** Meta information about each stored message.** All fields are set by the printk code except for @seq, which is* set by the ringbuffer code.*/
struct printk_info {u64	seq;		/* sequence number */u64	ts_nsec;	/* timestamp in nanoseconds */u16	text_len;	/* length of text message */u8	facility;	/* syslog facility */u8	flags:5;	/* internal record flags */u8	level:3;	/* syslog level */u32	caller_id;	/* thread id or processor id */struct dev_printk_info	dev_info;
};
/** A structure providing the buffers, used by writers and readers.** Writers:* Using prb_rec_init_wr(), a writer sets @text_buf_size before calling* prb_reserve(). On success, prb_reserve() sets @info and @text_buf to* buffers reserved for that writer.** Readers:* Using prb_rec_init_rd(), a reader sets all fields before calling* prb_read_valid(). Note that the reader provides the @info and @text_buf,* buffers. On success, the struct pointed to by @info will be filled and* the char array pointed to by @text_buf will be filled with text data.*/
struct printk_record {struct printk_info	*info;char			*text_buf;unsigned int		text_buf_size;
};/* Specifies the logical position and span of a data block. */
struct prb_data_blk_lpos {unsigned long	begin;unsigned long	next;
};
/** A descriptor: the complete meta-data for a record.** @state_var: A bitwise combination of descriptor ID and descriptor state.*/
struct prb_desc {atomic_long_t			state_var;struct prb_data_blk_lpos	text_blk_lpos;
};/* A ringbuffer of "ID + data" elements. */
struct prb_data_ring {unsigned int	size_bits;char		*data;atomic_long_t	head_lpos;atomic_long_t	tail_lpos;
};/* A ringbuffer of "struct prb_desc" elements. */
struct prb_desc_ring {unsigned int		count_bits;struct prb_desc		*descs;struct printk_info	*infos;atomic_long_t		head_id;atomic_long_t		tail_id;atomic_long_t		last_finalized_id;
};/** The high level structure representing the printk ringbuffer.** @fail: Count of failed prb_reserve() calls where not even a data-less*        record was created.*/
struct printk_ringbuffer {struct prb_desc_ring	desc_ring;struct prb_data_ring	text_data_ring;atomic_long_t		fail;
};

五、日志等级

日志级别的设置，用来控制 printk 打印的这条信息是否在终端上显示的，当日志级别的数值小于控制台级别时，printk 要打印的信息才会在控制台打印出来，否则不会显示在控制台！

在我们内核中一共有8种级别，他们分别为：

// include/linux/kern_levels.h#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 */

六、控制台级别

// .config#
# printk and dmesg options
#
CONFIG_PRINTK_TIME=y
# CONFIG_PRINTK_CALLER is not set
# CONFIG_STACKTRACE_BUILD_ID is not set
CONFIG_CONSOLE_LOGLEVEL_DEFAULT=7
CONFIG_CONSOLE_LOGLEVEL_QUIET=4
CONFIG_MESSAGE_LOGLEVEL_DEFAULT=4

// include/linux/printk.h/* printk's without a loglevel use this.. */
#define MESSAGE_LOGLEVEL_DEFAULT CONFIG_MESSAGE_LOGLEVEL_DEFAULT/* We show everything that is MORE important than this.. */
#define CONSOLE_LOGLEVEL_SILENT  0 /* Mum's the word */
#define CONSOLE_LOGLEVEL_MIN	 1 /* Minimum loglevel we let people use */
#define CONSOLE_LOGLEVEL_DEBUG	10 /* issue debug messages */
#define CONSOLE_LOGLEVEL_MOTORMOUTH 15	/* You can't shut this one up *//** Default used to be hard-coded at 7, quiet used to be hardcoded at 4,* we're now allowing both to be set from kernel config.*/
#define CONSOLE_LOGLEVEL_DEFAULT CONFIG_CONSOLE_LOGLEVEL_DEFAULT
#define CONSOLE_LOGLEVEL_QUIET	 CONFIG_CONSOLE_LOGLEVEL_QUIET

// kernel/printk/printk.cint console_printk[4] = {CONSOLE_LOGLEVEL_DEFAULT,	/* console_loglevel */MESSAGE_LOGLEVEL_DEFAULT,	/* default_message_loglevel */CONSOLE_LOGLEVEL_MIN,		/* minimum_console_loglevel */CONSOLE_LOGLEVEL_DEFAULT,	/* default_console_loglevel */
};
EXPORT_SYMBOL_GPL(console_printk);

七、常用的日志函数