diff --git a/articles/20220606-linux-printk.md b/articles/20220606-linux-printk.md new file mode 100644 index 0000000000000000000000000000000000000000..2c5eb24e6916c8f53efb782fc4395daac17cd2a1 --- /dev/null +++ b/articles/20220606-linux-printk.md @@ -0,0 +1,796 @@ +> Author: iosdevlog
+> Date: 2022/06/06
+> Project: [RISC-V Linux 内核剖析](https://gitee.com/tinylab/riscv-linux) + +# printk 剖析 + +## printk 相关函数 + +![ObjectReferences-printk](./images/printk/ObjectReferences-printk.png) + +## printk 与 printf 对比 + +printk 是一个 Linux 内核接口 C 函数，它将消息输出到内核日志，而 printf 命令用于在终端窗口中显示字符串，数字或任何其他格式说明符。 + +最著名的 Linux 内核函数之一是 `printk()`。 + +它是用于打印消息的默认工具，也是跟踪和调试的最基本方法。`printf()` 方法将参数打印到 stdout 流中，这些参数写在双引号中。 + +`printk()` | printf() +---|--- +`printk()` 是一个内核级函数，可以打印到各种日志级别 | printf() 将始终打印到 STD OUT 文件描述符 +不是标准库函数 | 是 C 标准库函数 +内核层 | 应用程序层 +`printk()` 方法可以随时从内核中的几乎任何地方调用 | printf() 方法不是那么健壮 +在内核启动过程中的特定点之前，在控制台初始化之前，无法使用 | 系统处于就绪状态 +printk(KERN_INFO "This is LinuxLab\n"); | printf("This is LinuxLab\n"); +`printk()` 是行驱动的，只有换行符接收的数据才会写入终端 | 不是行驱动。 + +## printk 历史 + +Linux 0.01 (1991-09) kernel/printk.c + +```c +// https://elixir.bootlin.com/linux/0.01/source/kernel/printk.c +/* + * When in kernel-mode, we cannot use printf, as fs is liable to + * point to 'interesting' things. Make a printf with fs-saving, and + * all is well. + */ +#include +#include + +#include + +static char buf[1024]; + +int printk(const char *fmt, ...) +{ + va_list args; + int i; + + va_start(args, fmt); + i=vsprintf(buf,fmt,args); + va_end(args); + __asm__("push %%fs\n\t" + "push %%ds\n\t" + "pop %%fs\n\t" + "pushl %0\n\t" + "pushl $_buf\n\t" + "pushl $0\n\t" + "call _tty_write\n\t" + "addl $8,%%esp\n\t" + "popl %0\n\t" + "pop %%fs" + ::"r" (i):"ax","cx","dx"); + return i; +} +``` + +版本 | 变更 +|---|---| +0.01/1991-09 | direct synchronous printing to terminal +0.96a/1992-05 | ringbuffer (4K), syslog, variable "log_wait" +0.99.7A/1993-03 | variable "log_buf" (4K), console registration, upon registration console prints existing ringbuffer +0.99.13k/1993-09 | loglevels (encoded as "" in messages) +0.99.14/1993-11 | interrupts disabled for ringbuffer store and console printing +2.1.31/1997-03 | multiple console support, console write() callback +2.1.80/1998-01 | spinlock "console_lock", ringbuffer store and console printing under spinlock +2.4.0/2000-10 | bust_spinlocks(), re-init console_lock on crash/lockup +2.4.10/2001-08 | printk now non-synchronous +2.5.51/2002-12 | /dev/kmsg to printk from userspace +2.5.53/2002-12 | do not console print if printk-CPU is not online +2.6.0/2003-10 | variable "log_buf_len", kernel boot argument "log_bug_len" +2.6.11/2005-01 | BKL changed to semaphore +2.6.12/2005-03 | add timing information to messages +2.6.25/2008-01 | do not allow printk to recurse (unless oops_in_progress) +2.6.26/2008-05 | hide console printing latency from irq latency tracer +2.6.27/2008-08 | add printk tick to wake syslog +2.6.32/2009-10 | kmsg_dump interface +2.6.35/2010-05 | support for dmesg from kdb +2.6.36/2010-06 | trigger console printing when a CPU comes online +2.6.39/2011-03 | add exclusive_console "feature" to avoid multiple messages +3.3/2012-02 | for scheduler context store in a per-cpu (single message) buffer +3.4/2012-05 | re-implement ringbuffer with variable record structures +3.6/2012-07 | change loglevel markers to SOH (start of header) character +3.7/2012-10 | remove printk tick, use irq_work to trigger syslog waking +3.15/2014-06 | report number of dropped messages +3.18/2014-06 | add per-cpu printk function pointer for per-cpu diversion +4.5/2016-01 | allow scheduler to run between lines when console printing +4.7/2016-05 | flush NMI buffers to ringbuffer on panic +4.10/2016-12 | safe buffers, per-cpu function replaced with per-cpu context variable +4.12/2017-04 | store to ringbuffer from any context (if possible) +4.15/2018-01 | add console owner/waiter logic to hand-off console printing +5.0/2019-02 | finally clean LOG_CONT ordering based on caller identifier + +内核的 `printk()` 函数在普通人想象中应该是个非常简单的函数，只要处理好字符串格式化然后输出到 kernel log 里就好。 + +其实这里隐藏着非常多的复杂问题。 + +这里的核心问题是 kernel 代码必须要能在任何上下文 （context） 都可以调用 `printk()`。 + +在 atomic context 调用的话需要确保 `printk()` 不能导致阻塞，而在 non-maskable interrupts (NMIs) 上下文调用的话甚至连spinlock也不能用了。 + +同时，系统出错时 `printk()` 的输出内容非常重要，开发者不愿意丢掉任何一行信息，哪怕系统就要 crash 或者 hang 住了。 + +这些信息要在 console 设备上打印出来，通常是一个串口，或者是经过显卡显示在屏幕上，或者通过网络连接送出来。此外，`printk()` 不应该干扰系统的正常执行过程。 + +`printk()` 看起来简单并且到处都在用，而它的底层实现其实跟系统的方方面面都搅在一起。 + +内核 0.99.7a 版本里就增加了 console registration（注册机制）。 + +在 0.99.13k 版本里增加了 “log level” 设置。 + +在 2.4.0 里面增加了 `bust_spinlocks()` 机制，用来避免系统 crash 以至于无法正常工作的时候还要进行不必要的等待 spinlock 操作。 + +从 2.4.10 开始，`printk()` 也支持异步（asynchronous）工作模式了。 + +2.6.24 版本之前，`printk()`时不时会导致偶发的特别高的延迟，在这个版本里面大家会在latency tracer里面忽略`printk()`，避免干扰人们的分析。 + +3.4 版本里增加了 structured logging，sequence numbers，以及 `/dev/kmsg` 接口。 + +4.10 里面增加了"safe buffers"机制，用来在 NMI context上 下文来做输出。在 4.15 版本里，修复了一个 bug 可能导致 CPU 不停地输出信息。 + +在 5.0 版本里，加入了 caller identifier （调用者标记）功能。 + +也就是说这么多年来 `printk()` 一直在持续改进，不过仍然有很多遗留问题。 + +其中之一就是关于用来保护 ring buffer 的 raw spinlock，它没法在NMI上下文调用，因此 `printk()` 必须要先输出到不依赖 lock 的 safe buffer 里。 + +这样会导致 message 最终被 copy 到真正的 ring buffer 的时候更新的 timestamp 不精确，也可能会导致 message 丢失，或者导致 CPU 异常 offline 的时候 buffer 没有被刷出去。 + +此外 console 驱动这边也有麻烦，因为它不仅很慢，并且还是在关中断模式下调用的。 + +大多数 console device 设计时都没有考虑过 kernel panic 的场景，在这种最需要它的场景下表现得不够可靠。 + +## printk 代码剖析 + +**先介绍一下 RingBuffer** + +```c +// https://elixir.bootlin.com/linux/v5.18/source/init/Kconfig#L716 +config LOG_BUF_SHIFT + int "Kernel log buffer size (16 => 64KB, 17 => 128KB)" + range 12 25 if !H8300 + range 12 19 if H8300 + default 17 + depends on PRINTK + help + Select the minimal kernel log buffer size as a power of 2. + The final size is affected by LOG_CPU_MAX_BUF_SHIFT config + parameter, see below. Any higher size also might be forced + by "log_buf_len" boot parameter. + + Examples: + 17 => 128 KB + 16 => 64 KB + 15 => 32 KB + 14 => 16 KB + 13 => 8 KB + 12 => 4 KB +``` + +`.config` 中 `CONFIG_LOG_BUF_SHIFT=17`。 + +生成 `autoconf.h`。 + +```c +#define CONFIG_LOG_BUF_SHIFT 17 +``` + +```c +// https://elixir.bootlin.com/linux/v5.18/source/kernel/printk/printk.c#L414 +/* the maximum size of a formatted record (i.e. with prefix added per line) */ +#define CONSOLE_LOG_MAX 1024 + +/* the maximum size allowed to be reserved for a record */ +#define PREFIX_MAX 32 +#define LOG_LINE_MAX (CONSOLE_LOG_MAX - PREFIX_MAX) +/* 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; +``` + +**分析 `printk` 宏** + +```c +// https://elixir.bootlin.com/linux/v5.18/source/kernel/printk/printk.h#L392 +#define __printk_index_emit(...) do {} while (0) +// :415 +#define printk_index_wrap(_p_func, _fmt, ...) \ + ({ \ + __printk_index_emit(_fmt, NULL, NULL); \ + _p_func(_fmt, ##__VA_ARGS__); \ + }) +// :422 +/** + * printk - print a kernel message + * @fmt: format string + * + * This is printk(). It can be called from any context. We want it to work. + * + * If printk indexing is enabled, _printk() is called from printk_index_wrap. + * Otherwise, printk is simply #defined to _printk. + * + * We try to grab the console_lock. If we succeed, it's easy - we log the + * output and call the console drivers. If we fail to get the semaphore, we + * place the output into the log buffer and return. The current holder of + * the console_sem will notice the new output in console_unlock(); and will + * send it to the consoles before releasing the lock. + * + * One effect of this deferred printing is that code which calls printk() and + * then changes console_loglevel may break. This is because console_loglevel + * is inspected when the actual printing occurs. + * + * See also: + * printf(3) + * + * See the vsnprintf() documentation for format string extensions over C99. + */ +#define printk(fmt, ...) printk_index_wrap(_printk, fmt, ##__VA_ARGS__) +``` + +分析代码得知，最终是调用 `_printk`。 + +```c +// https://elixir.bootlin.com/linux/v5.18/source/kernel/printk/printk.c#L2287 +asmlinkage __visible int _printk(const char *fmt, ...) +{ + va_list args; + int r; + + va_start(args, fmt); + r = vprintk(fmt, args); + va_end(args); + + return r; +} +EXPORT_SYMBOL(_printk); +``` + +`_printk` 参数为可变参数。通过 `man 3 stdarg` 查看可变参数说明。 + +``` +NAME + stdarg, va_start, va_arg, va_end, va_copy - variable argument lists + +SYNOPSIS + #include + + void va_start(va_list ap, last); + type va_arg(va_list ap, type); + void va_end(va_list ap); + void va_copy(va_list dest, va_list src); + +DESCRIPTION + A function may be called with a varying number of arguments of varying types. The include file declares a type va_list and defines three macros for stepping through a list of + arguments whose number and types are not known to the called function. + + The called function must declare an object of type va_list which is used by the macros va_start(), va_arg(), and va_end(). +``` + +`_printk` 内部调用 `vprintk`，接下来分析 `vprintk`。 + +```c +// https://elixir.bootlin.com/linux/v5.18/source/kernel/printk/printk_safe.c#L29 +asmlinkage int vprintk(const char *fmt, va_list args) +{ +#ifdef CONFIG_KGDB_KDB + /* Allow to pass printk() to kdb but avoid a recursion. */ + if (unlikely(kdb_trap_printk && kdb_printf_cpu < 0)) + return vkdb_printf(KDB_MSGSRC_PRINTK, fmt, args); +#endif + + /* + * Use the main logbuf even in NMI. But avoid calling console + * drivers that might have their own locks. + */ + if (this_cpu_read(printk_context) || in_nmi()) { + int len; + + len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, fmt, args); + defer_console_output(); + return len; + } + + /* No obstacles. */ + return vprintk_default(fmt, args); +} +EXPORT_SYMBOL(vprintk); +``` + +`vprintk 会调用 `vprintk_store` 和 `vprintk_default`。 + +1. `vprintk_store` 格式化字符串到 log_buf。 +2. `vprintk_default` 打印到 console。 + +**我们先分析如何格式化字符串** + +```c +// https://elixir.bootlin.com/linux/v5.18/source/kernel/printk/printk.c#L2122 +int vprintk_store(int facility, int level, + const struct dev_printk_info *dev_info, + const char *fmt, va_list args) +{ + // ... + /* + * The sprintf needs to come first since the syslog prefix might be + * passed in as a parameter. An extra byte must be reserved so that + * later the vscnprintf() into the reserved buffer has room for the + * terminating '\0', which is not counted by vsnprintf(). + */ + va_copy(args2, args); + reserve_size = vsnprintf(&prefix_buf[0], sizeof(prefix_buf), fmt, args2) + 1; + va_end(args2); + + if (reserve_size > LOG_LINE_MAX) + reserve_size = LOG_LINE_MAX; + // ... + /* fill message */ + text_len = printk_sprint(&r.text_buf[0], reserve_size, facility, &flags, fmt, args); + // ... +} +``` + +`vprintk_store 会调用 `printk_sprint`。 + +![Calls-printk_sprint](./images/printk/Calls-printk_sprint.png) + +```c +// https://elixir.bootlin.com/linux/v5.18/source/kernel/printk/printk.c#L2093 +static u16 printk_sprint(char *text, u16 size, int facility, + enum printk_info_flags *flags, const char *fmt, + va_list args) +{ + u16 text_len; + + text_len = vscnprintf(text, size, fmt, args); + + /* Mark and strip a trailing newline. */ + if (text_len && text[text_len - 1] == '\n') { + text_len--; + *flags |= LOG_NEWLINE; + } + + /* Strip log level and control flags. */ + if (facility == 0) { + u16 prefix_len; + + prefix_len = printk_parse_prefix(text, NULL, NULL); + if (prefix_len) { + text_len -= prefix_len; + memmove(text, text + prefix_len, text_len); + } + } + + return text_len; +} +``` + +`printk_sprint` 会调用 `vsnprintf`。代码注释中有说明。 + +```c +/** + * vscnprintf - Format a string and place it in a buffer + * @buf: The buffer to place the result into + * @size: The size of the buffer, including the trailing null space + * @fmt: The format string to use + * @args: Arguments for the format string + * + * The return value is the number of characters which have been written into + * the @buf not including the trailing '\0'. If @size is == 0 the function + * returns 0. + * + * If you're not already dealing with a va_list consider using scnprintf(). + * + * See the vsnprintf() documentation for format string extensions over C99. + */ +int vscnprintf(char *buf, size_t size, const char *fmt, va_list args) +{ + int i; + + if (unlikely(!size)) + return 0; + + i = vsnprintf(buf, size, fmt, args); + + if (likely(i < size)) + return i; + + return size - 1; +} +EXPORT_SYMBOL(vscnprintf); +``` + +`vprintk_store` 和 `vscnprintf` 都会调用 `vsnprintf`。 + +> The functions vprintf(), vfprintf(), vdprintf(), vsprintf(), vsnprintf() are equivalent to the functions printf(), fprintf(), dprintf(), sprintf(), snprintf(), respectively, except that +> they are called with a va_list instead of a variable number of arguments. These functions do not call the va_end macro. Because they invoke the va_arg macro, the value of ap is undefined +> after the call. See stdarg(3). + +```c +// https://elixir.bootlin.com/linux/v5.18/source/kernel/printk/printk.c#L2708 +/** + * vsnprintf - Format a string and place it in a buffer + * @buf: The buffer to place the result into + * @size: The size of the buffer, including the trailing null space + * @fmt: The format string to use + * @args: Arguments for the format string + * + * This function generally follows C99 vsnprintf, but has some + * extensions and a few limitations: + * + * - ``%n`` is unsupported + * - ``%p*`` is handled by pointer() + * + * See pointer() or Documentation/core-api/printk-formats.rst for more + * extensive description. + * + * **Please update the documentation in both places when making changes** + * + * The return value is the number of characters which would + * be generated for the given input, excluding the trailing + * '\0', as per ISO C99. If you want to have the exact + * number of characters written into @buf as return value + * (not including the trailing '\0'), use vscnprintf(). If the + * return is greater than or equal to @size, the resulting + * string is truncated. + * + * If you're not already dealing with a va_list consider using snprintf(). + */ +int vsnprintf(char *buf, size_t size, const char *fmt, va_list args) +{ + unsigned long long num; + char *str, *end; + struct printf_spec spec = {0}; + + /* Reject out-of-range values early. Large positive sizes are + used for unknown buffer sizes. */ + if (WARN_ON_ONCE(size > INT_MAX)) + return 0; + + str = buf; + end = buf + size; + + /* Make sure end is always >= buf */ + if (end < buf) { + end = ((void *)-1); + size = end - buf; + } + + while (*fmt) { + const char *old_fmt = fmt; + int read = format_decode(fmt, &spec); + + fmt += read; + + switch (spec.type) { + case FORMAT_TYPE_NONE: { + int copy = read; + if (str < end) { + if (copy > end - str) + copy = end - str; + memcpy(str, old_fmt, copy); + } + str += read; + break; + } + + case FORMAT_TYPE_WIDTH: + set_field_width(&spec, va_arg(args, int)); + break; + + case FORMAT_TYPE_PRECISION: + set_precision(&spec, va_arg(args, int)); + break; + + case FORMAT_TYPE_CHAR: { + char c; + + if (!(spec.flags & LEFT)) { + while (--spec.field_width > 0) { + if (str < end) + *str = ' '; + ++str; + + } + } + c = (unsigned char) va_arg(args, int); + if (str < end) + *str = c; + ++str; + while (--spec.field_width > 0) { + if (str < end) + *str = ' '; + ++str; + } + break; + } + + case FORMAT_TYPE_STR: + str = string(str, end, va_arg(args, char *), spec); + break; + + case FORMAT_TYPE_PTR: + str = pointer(fmt, str, end, va_arg(args, void *), + spec); + while (isalnum(*fmt)) + fmt++; + break; + + case FORMAT_TYPE_PERCENT_CHAR: + if (str < end) + *str = '%'; + ++str; + break; + + case FORMAT_TYPE_INVALID: + /* + * Presumably the arguments passed gcc's type + * checking, but there is no safe or sane way + * for us to continue parsing the format and + * fetching from the va_list; the remaining + * specifiers and arguments would be out of + * sync. + */ + goto out; + + default: + switch (spec.type) { + case FORMAT_TYPE_LONG_LONG: + num = va_arg(args, long long); + break; + case FORMAT_TYPE_ULONG: + num = va_arg(args, unsigned long); + break; + case FORMAT_TYPE_LONG: + num = va_arg(args, long); + break; + case FORMAT_TYPE_SIZE_T: + if (spec.flags & SIGN) + num = va_arg(args, ssize_t); + else + num = va_arg(args, size_t); + break; + case FORMAT_TYPE_PTRDIFF: + num = va_arg(args, ptrdiff_t); + break; + case FORMAT_TYPE_UBYTE: + num = (unsigned char) va_arg(args, int); + break; + case FORMAT_TYPE_BYTE: + num = (signed char) va_arg(args, int); + break; + case FORMAT_TYPE_USHORT: + num = (unsigned short) va_arg(args, int); + break; + case FORMAT_TYPE_SHORT: + num = (short) va_arg(args, int); + break; + case FORMAT_TYPE_INT: + num = (int) va_arg(args, int); + break; + default: + num = va_arg(args, unsigned int); + } + + str = number(str, end, num, spec); + } + } + +out: + if (size > 0) { + if (str < end) + *str = '\0'; + else + end[-1] = '\0'; + } + + /* the trailing null byte doesn't count towards the total */ + return str-buf; + +} +EXPORT_SYMBOL(vsnprintf); +``` + +**接下来再分析如何输出字符串** + +`vprintk_default` 打印到 console。 + +`vprintk_default` 直接调用 `vprintk_emit`。 + +``` +// https://elixir.bootlin.com/linux/v5.18/source/kernel/printk/printk.c#L2233 +asmlinkage int vprintk_emit(int facility, int level, + const struct dev_printk_info *dev_info, + const char *fmt, va_list args) +{ + int printed_len; + bool in_sched = false; + + /* Suppress unimportant messages after panic happens */ + if (unlikely(suppress_printk)) + return 0; + + if (unlikely(suppress_panic_printk) && + atomic_read(&panic_cpu) != raw_smp_processor_id()) + return 0; + + if (level == LOGLEVEL_SCHED) { + level = LOGLEVEL_DEFAULT; + in_sched = true; + } + + boot_delay_msec(level); + printk_delay(); + + printed_len = vprintk_store(facility, level, dev_info, fmt, args); + + /* If called from the scheduler, we can not call up(). */ + if (!in_sched) { + /* + * Disable preemption to avoid being preempted while holding + * console_sem which would prevent anyone from printing to + * console + */ + preempt_disable(); + /* + * Try to acquire and then immediately release the console + * semaphore. The release will print out buffers and wake up + * /dev/kmsg and syslog() users. + */ + if (console_trylock_spinning()) + console_unlock(); + preempt_enable(); + } + + wake_up_klogd(); + return printed_len; +} +EXPORT_SYMBOL(vprintk_emit); + +int vprintk_default(const char *fmt, va_list args) +{ + return vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, fmt, args); +} +EXPORT_SYMBOL_GPL(vprintk_default); +``` + +最后调用 `console_unlock()`。 + +首先根据 con_start 和 log_end 来检查是否有需要在终端上打印的消息。 + +如果有则开始使用 call_console_drivers 调用 console 关联的底层驱动程序进行最终的消息打印操作。 + +```c +// https://elixir.bootlin.com/linux/v5.18/source/kernel/printk/printk.c#L2646 +/** + * console_unlock - unlock the console system + * + * Releases the console_lock which the caller holds on the console system + * and the console driver list. + * + * While the console_lock was held, console output may have been buffered + * by printk(). If this is the case, console_unlock(); emits + * the output prior to releasing the lock. + * + * If there is output waiting, we wake /dev/kmsg and syslog() users. + * + * console_unlock(); may be called from any context. + */ +void console_unlock(void) +{ + // ... + for (;;) { + stop_critical_timings(); /* don't trace print latency */ + call_console_drivers(ext_text, ext_len, text, len); + start_critical_timings(); + } + // ... +} +``` + +`call_console_drivers` 最终调用不同 console 关联的写操作 `con->write` 实现打印操作。 + +```c +// https://elixir.bootlin.com/linux/v5.18/source/kernel/printk/printk.c#L1913 +/* + * Call the console drivers, asking them to write out + * log_buf[start] to log_buf[end - 1]. + * The console_lock must be held. + */ +static void call_console_drivers(const char *ext_text, size_t ext_len, + const char *text, size_t len) +{ + static char dropped_text[64]; + size_t dropped_len = 0; + struct console *con; + + trace_console_rcuidle(text, len); + + if (!console_drivers) + return; + + if (console_dropped) { + dropped_len = snprintf(dropped_text, sizeof(dropped_text), + "** %lu printk messages dropped **\n", + console_dropped); + console_dropped = 0; + } + + for_each_console(con) { + if (exclusive_console && con != exclusive_console) + continue; + if (!(con->flags & CON_ENABLED)) + continue; + if (!con->write) + continue; + if (!cpu_online(smp_processor_id()) && + !(con->flags & CON_ANYTIME)) + continue; + if (con->flags & CON_EXTENDED) + con->write(con, ext_text, ext_len); + else { + if (dropped_len) + con->write(con, dropped_text, dropped_len); + con->write(con, text, len); + } + } +} +``` + +`for_each_console` 是一个宏，用来遍历 console_drivers。 + +```c +// https://elixir.bootlin.com/linux/v5.18/source/include/linux/console.h#L140 +struct console { + char name[16]; + void (*write)(struct console *, const char *, unsigned); + int (*read)(struct console *, char *, unsigned); + struct tty_driver *(*device)(struct console *, int *); + void (*unblank)(void); + int (*setup)(struct console *, char *); + int (*exit)(struct console *); + int (*match)(struct console *, char *name, int idx, char *options); + short flags; + short index; + int cflag; + uint ispeed; + uint ospeed; + void *data; + struct console *next; +}; + +/* + * for_each_console() allows you to iterate on each console + */ +#define for_each_console(con) \ + for (con = console_drivers; con != NULL; con = con->next) + +// https://elixir.bootlin.com/linux/v5.18/source/kernel/printk/printk.c#L1913 +struct console *console_drivers; +``` + +## 总结 + +![printk](./images/printk/Calls-_printk.png) + +* `printk` 函数第一步是解析参数列表，然后对带有参数的字符串进行格式化，并放入到 log_buf 中。 +* 当 log_buf 中有需要打印的信息时，则调用 console 所关联的驱动程序完成最终的打印操作。 +* 在 `call_console_drivers` 中调用 console 所关联的驱动时会先判断 `con->write` 是否存在。 +* 如果 `con->write` 不存在，则不会在终端中有信息输出，即直接忽略这次打印。 +* 然而在 `linux` 内核启动初期就已经开始调用 `printk` 函数了，而此时还并没注册 `console` 设备，就更不可能存在 `con->write` 了。 +* 那这个阶段调用 printk 输出的信息岂不是都丢了？ +* 然而事实并不是这样子的，这就是 early console 相关的内容，有时间再介绍。 + +## 参考 + +1. [Difference between `printk()` and Printf() in Linux](https://www.geeksforgeeks.org/difference-between-printk-and-printf-in-linux/) +2. [Message logging with printk](https://www.kernel.org/doc/html/latest/core-api/printk-basics.html) +3. [Why `printk()` is so complicated (and how to fix it)](https://lwn.net/Articles/800946/) +4. [printk流程分析](https://zhuanlan.zhihu.com/p/266542404) +5. [printk() - The most useful tool](https://elinux.org/images/7/7c/Elce-printk-v1.pdf) diff --git a/articles/images/printk/Calls-_printk.png b/articles/images/printk/Calls-_printk.png new file mode 100644 index 0000000000000000000000000000000000000000..b0e05e1ccb5fa27b40b49d1eeebe411dfc8ea917 Binary files /dev/null and b/articles/images/printk/Calls-_printk.png differ diff --git a/articles/images/printk/Calls-printk_sprint.png b/articles/images/printk/Calls-printk_sprint.png new file mode 100644 index 0000000000000000000000000000000000000000..e5a8af302ebbd162dc3628ea0daad5272c72935d Binary files /dev/null and b/articles/images/printk/Calls-printk_sprint.png differ diff --git a/articles/images/printk/ObjectReferences-printk.png b/articles/images/printk/ObjectReferences-printk.png new file mode 100644 index 0000000000000000000000000000000000000000..9bc4c7a7addbe2cbb4ed73470c937d37be7d4607 Binary files /dev/null and b/articles/images/printk/ObjectReferences-printk.png differ