printk()函数分析

在内核模块中，常用的输出函数为printk()，为了理解该函数的工作原理以及执行流程，接下来对该函数进行分析。printk()函数原型如下：

//以“printk("num is: %d!\n", num)”语句为例，开始分析。
//在分析之前，先来了解两个宏定义，分别是：

#define va_start(v, l) __builtin_va_start(v, l)	//参数v将指向(addr + sizeof(l))，addr为参数的首地址
#define va_end(v) __builtin_va_end(v)	//参数v将指向参数的尾地址

asmlinkage __visible int printk(const char *fmt, ...)
{
	va_list args;
	int r;
	
	va_start(args, fmt);
	//args指向传入的（addr + sizeof(fmt)），addr为参数的首地址
	r = vprintk_func(fmt, args);
	//调用实际printk()函数，里面仍会有多层嵌套
	va_end(args);

	return r;
}

通过上述代码，可以看出，调用printk()函数时，首先获取到要被打印的参数的首地址，随后调用vprintk_func()函数。

//关于vprintk_func()函数，首先来看如下的宏定义：
#define __printf(a, b) __attribute__((__format__(printf, a, b)))
//该宏定义主要通过__format__属性，来让编译器按照printf()函数的参数格式来对函数的参数进行检查。

__printf(1, 0) int vprintk_func(const char *fmt, va_list args)
{
	if ((this_cpu_read(printk_context) & PRINTK_NMI_DIRECT_CONTEXT_MASK) && raw_spin_trylok(&logbuf_lock)) {
	//this_cpu_read函数将根据printk_context的值，来选择执行this_cpu_read1/2/4/8这四个函数中的一个。
	//关于printk_context，被定义为int类型。即int printk_context的全局变量。
	//假设当前printk_context为0。则this_cpu_read函数的执行结果全为0，三种条件都不成立，则执行默认的printk。 
		int len;
		len = vprintk_store();
		raw_spin_unlock();
		defer_console_output();
		return len;		
	}

	if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK)
		return vprintk_nmi(fmt, args);

	if (this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK)
		return vprintk_safe(fmt, args);

	return vprintk_default(fmt, args);
}

假设当前选择为默认形式的输出。即vprintk_default()函数，其原型如下：

int vprintk_default(const char *fmt, va_list args)
{
	int r;
//假设配置中，未开启KGDB，则直接执行vprintk_emit函数。
#ifdef CONFIG_KGDB_KDB
	if (unlikely(kdb_trap_printk && kdb_print_cpu < 0)) {
		r = vkdb_printf(KDB_MSGRC_PRINTK, fmt, args);
	}
#endif
	r = vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args);
	//这里，默认日志等级为-1,即#define LOGLEVEL_DEFAULT -1。
	return r;
}

asmlinkage int vprintk_emit(int facility, int level, const char *dict, size_t ditclen, const char *fmt, va_list args)
{
	int printed_len;
	bool in_sched = false, pending_output;
	unsigned long flags;
	u64 curr_log_seq;

	if (unlikely(suppress_printk))
	//suppress_printk为全局只读变量，假设该值当前为0。
		return 0;
		
	if (level == LOGLEVEL_SCHED) {
	//在当前情况下，level并不为LOGLEVEL_SCHED，因此条件不成立
		level = LOGLEVEL_DEFAULT;
		in_sched = true;
	}
	//延时
	boot_delay_msce(level);
	prinkt_delay();
	
	logbuf_lock_irqsave(flags);
	curr_log_seq = log_next_seq;
	printed_len = vprintk_store(facility, level, dict, dictlen, fmt, args);
	//将所要输出的内容进行寄存
	pending_output = (curr_log_seq != log_next_seq)
	...
	if (!in_sched && pending_output) {
	//in_sched为false，且pending_output为true。因此，该条件成立
		...
		preempt_disable();
		if (console_trylock_spinning())
			console_unlock();
			//将日志缓冲中的内容进行打印
		premmpt_enable();
	} 
	...
}

//寄存所要输出的内容
int vprintk_store(int facility, int level, const char *dict, size_t dictlen, const char *fmt, va_list args)
{
	static char textbuf[LOG_LINE_MAX];
	char *text = textbuf;
	size_t text_len;
	enum log_flags lflags = 0;

	text_len = vscnprintf(text, sizeof(textbuf), fmt, args);
	//该函数最终通过调用vsprintf()函数，vsprintf函数通过对fmt进行解析，将参数按照fmt格式填入，并将最终字符串写入text中。text_len表示写入的字节数。
	if (text_len && text[text_len - 1] == '\n') {
		text_len--;
		lflags |= LOG_NEWLINE;
	}

	if (facility == 0) {
		int kern_level;
		while ((kern_level = printk_get_level(text)) != 0) {
		//如果text的首字符为‘\001’，且第二字符为0～7或c,则返回第二字符。否则，返回0。假设当前返回值为0。
			switch (kern_level) {
				case '0' ... '7':
					if (level == LOGLEVEL_DEFAULT)
						level = kern_level - '0';
					break;
				case 'c':
					lflags |= LOG_CONT; 
			}
			text_len -= 2;
			text += 2;
		}
	}

	if (level == LOGLEVEL_DEFAULT)
	//如果等级为默认的，则将其值更改为dafault_message_loglevel。
		level = default_message_loglevel;

	if (dict)
		lflags |= LOG_NEWLINE;
	//开始调用日志输出函数。
	return log_output(facility, level, lflags, dict, dictlen, text, text_len);
}

static size_t log_output(int facility, int level, enum log_flags lflags, const char *dict, size_t dictlen, char *text, size_t text_len)
{
	const u32 caller_id = printk_caller_id();
	//首先获取一个caller_id，即当前的进程号。
	
	if (cont.len) {
	//cont为类型为struct cont的全局变量，启动阶段cont.len为0。跳过该执行条件
		if (cont.caller_id == caller_id && (lflags & LOG_CONT)) {
			if (cont_add(caller_id, facility, level, lflags, text, text_len))
				return text_len;
		}
		cont_flush();
	}
	
	if (!text_len && (lflags & LOG_CONT))
		return 0;
	if (!(lflags & LOG_NEWLINE)) {
	//假设当前输出的内容为完整的一行内容，也会跳过该执行条件
		if (cont_add(caller_id, facility, level, lflags, text, text_len))
			return text_len;
	}
	//开始寄存所要输出的内容
	return log_store(caller_id, facility, level, lflags, 0, dict, dictlen, text, text_len);
}

static int log_store(u32 caller_id, int facility, int level, enum log_flags flags, u64 ts_nsec, const char *dict, u16 dict_len, const char *text, u16 text_len)
{
	...
	msg = (struct printk_log *)(log_buf + log_next_idx);
	//申请struct printk_log结构体对象
	memcpy(log_text(msg), text, text_len);
	//将所要输出的内容复制到申请的struct printk_log结构体对象中
	msg->text_len = text_len;
	...

	return msg->text_len;
	//结束整个操作
}

在上述代码中出现了两个结构体，这里对它们进行简单的说明：

struct printk_log {
	u64 ts_nsec;
	u16 len;
	u16 text_len;
	u16 dict_len;
	u8 facility;
	u8 flags:5;
	u8 level:3;
#iddef CONFIG_PRINTK_CALLER
	u32 caller_id
#endif
}
#ifdef CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS
__packed __aligned(4)
#endif
;

static struct cont {
	char buf[LOG_LINE_MAX];
	size_t len;
	u32 caller_id;
	u64 ts_nesc;
	u8 level;
	u8 facility;
	enum log_flags flags;
} cont;

综上，可以知道printk()函数将所要输出的内容全部存储到一段空间中。随后该段空间被使用，从而打印出内容。打印日志信息由上述解析过程中的console_unlock()函数来完成。

void console_unlock(void)
{
	static char ext_text[CONSOLE_EXT_LOG_MAX];
	static char text[LOG_LINE_MAX + PREFIX_MAX];
	...
	for (;;) {
		...
		call_console_drivers(ext_text, ext_len, text, len);
		//调用控制台驱动
		...
	}
	...
}

static void call_console_drivers(const char *ext_text, size_t ext_len, const_char *text, size_t len)
{
	struct console *con;
	trace_console_rcuidle(text, len);
	for_each_console(con) {
	//遍历以console_drivers为表头的链表，访问每一个已经注册的console，并调用该console中定义的write方法来打印日志信息
		...
		if (con->flags & CON_EXTENDED)
			con->write(con, ext_text, ext_len);
		else
			con->write(con, text, len);
			//通用模式下的打印日志信息方法
	}
}

关于上述代码中打印日志信息的方法，主要在注册console时来进行指定。比如：在启动阶段的早期，如果内核中配置了CONFIG_EARLY_PRINTK选项，则会注册early_console终端。如下：

static void early_console_write(struct console *con, const char *s, unsigned n)
{
	while (n-- && *s) {
		if (*s == '\n')
			prom_putchar('\r');
		prom_putchar(*s);
		s++;
	}
}

struct console early_console_prom = {
	.name = "early",
	.write = early_console_write,
	.flags = CON_PRINTBUFFER | CON_BOOT,
	.index = -1
};

void __init setup_early_printk(void)
{
	if (early_console)
		return;
	early_console = &early_console_prom;
	register_console(&early_console_prom);
}

void register_console(struct console *newcon)
{
	...
	struct console *bcon = NULL;
	...
	for_each_console(bcon) {
	//遍历console链表，链表头为全局变量console_drivers，此时改变量为空，因此该条件并不成立
		if (WARN(bcon == newcon, "console '%s%d' already registered\n", bcon->name, bcon->index))
			return;
	}
	...
	if ((newcon->flags & CON_CONSDEV) || console_drivers == NULL) {
	//该条件此时成立，因此执行该条件操作
		newcon->next = console_drivers;
		console_drivers = newcon;
	//上述两步操作，将新的console添加到console_driver链表中，且以其为表头
		if (newcon->next)
			newcon->next->flags &= ~CON_CONSDEV;
	} else {
		newcon->next = console_drivers->next;
		console_drivers->next = newcon;
	}
	...
}

综上分析，可知当执行printk()函数时，首先会将所要输出的信息寄存到日志缓冲区，随后遍历所有的控制台，检查其是否满足当前要求，如果满足，则调用该控制台所指定的write()函数，从而打印信息。

所以，关于内核启动时的日志打印，也需要在注册某个console之后，再次调用printk()函数来进行日志的输出。因此，内核在启动阶段首先注册了用于启动阶段的console，即early_console。随后，又初始化了内核启动之后的console，即tty0_console。与此同时，将前边注册的early_console进行了注销。

综上，便是关于内核日志打印的分析。