Merge tag 'printk-for-6.3' of git://git.kernel.org/pub/scm/linux/kernel/git/printk/linux

Pull printk updates from Petr Mladek: - Refactor printk code for formatting messages that are shown on consoles. This is a preparatory step for introducing atomic consoles which could not share the global buffers - Prevent memory leak when removing printk index in debugfs - Dump also the newest printk message by the sample gdbmacro - Fix a compiler warning * tag 'printk-for-6.3' of git://git.kernel.org/pub/scm/linux/kernel/git/printk/linux: printf: fix errname.c list kernel/printk/index.c: fix memory leak with using debugfs_lookup() printk: Use scnprintf() to print the message about the dropped messages on a console printk: adjust string limit macros printk: use printk_buffers for devkmsg printk: introduce console_prepend_dropped() for dropped messages printk: introduce printk_get_next_message() and printk_message printk: introduce struct printk_buffers console: Document struct console console: Use BIT() macros for @flags values printk: move size limit macros into internal.h docs: gdbmacros: print newest record

Linus Torvalds committed 3 years ago

Commit d8763152 parents cd43b50 392143c7 files · +313 −168Browse files

Showing the changes to kernel (3 of 7 files). Show all

Unified · Split

3 files

kernel/printk/index.c +1 −1
kernel/printk/internal.h +45 −0
kernel/printk/printk.c +179 −129

kernel/printk/index.c+1−1

@@ -145,7 +145,7 @@ static void pi_create_file(struct module *mod) · 144 unmodified lines
145	#ifdef CONFIG_MODULES	145	#ifdef CONFIG_MODULES
146	static void pi_remove_file(struct module *mod)	146	static void pi_remove_file(struct module *mod)
147	{	147	{
148	debugfs_remove(debugfs_lookup(pi_get_module_name(mod), dfs_index));	148	debugfs_lookup_and_remove(pi_get_module_name(mod), dfs_index);
149	}	149	}
150		150
151	static int pi_module_notify(struct notifier_block *nb, unsigned long op,	151	static int pi_module_notify(struct notifier_block *nb, unsigned long op,

kernel/printk/internal.h+45−0

@@ -14,6 +14,21 @@ int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write, · 13 unmodified lines
14		14
15	#ifdef CONFIG_PRINTK	15	#ifdef CONFIG_PRINTK
16		16
		17	#ifdef CONFIG_PRINTK_CALLER
		18	#define PRINTK_PREFIX_MAX 48
		19	#else
		20	#define PRINTK_PREFIX_MAX 32
		21	#endif
		22
		23	/*
		24	* the maximum size of a formatted record (i.e. with prefix added
		25	* per line and dropped messages or in extended message format)
		26	*/
		27	#define PRINTK_MESSAGE_MAX 2048
		28
		29	/* the maximum size allowed to be reserved for a record */
		30	#define PRINTKRB_RECORD_MAX 1024
		31
17	/* Flags for a single printk record. */	32	/* Flags for a single printk record. */
18	enum printk_info_flags {	33	enum printk_info_flags {
19	LOG_NEWLINE = 2, /* text ended with a newline */	34	LOG_NEWLINE = 2, /* text ended with a newline */
@@ -48,6 +63,10 @@ u16 printk_parse_prefix(const char text, int level, · 28 unmodified lines
48	enum printk_info_flags *flags);	63	enum printk_info_flags *flags);
49	#else	64	#else
50		65
		66	#define PRINTK_PREFIX_MAX 0
		67	#define PRINTK_MESSAGE_MAX 0
		68	#define PRINTKRB_RECORD_MAX 0
		69
51	/*	70	/*
52	* In !PRINTK builds we still export console_sem	71	* In !PRINTK builds we still export console_sem
53	* semaphore and some of console functions (console_unlock()/etc.), so	72	* semaphore and some of console functions (console_unlock()/etc.), so
@@ -58,3 +77,29 @@ u16 printk_parse_prefix(const char text, int level, · 4 unmodified lines
58		77
59	static inline bool printk_percpu_data_ready(void) { return false; }	78	static inline bool printk_percpu_data_ready(void) { return false; }
60	#endif /* CONFIG_PRINTK */	79	#endif /* CONFIG_PRINTK */
		80
		81	/**
		82	* struct printk_buffers - Buffers to read/format/output printk messages.
		83	* @outbuf: After formatting, contains text to output.
		84	* @scratchbuf: Used as temporary ringbuffer reading and string-print space.
		85	*/
		86	struct printk_buffers {
		87	char outbuf[PRINTK_MESSAGE_MAX];
		88	char scratchbuf[PRINTKRB_RECORD_MAX];
		89	};
		90
		91	/**
		92	* struct printk_message - Container for a prepared printk message.
		93	* @pbufs: printk buffers used to prepare the message.
		94	* @outbuf_len: The length of prepared text in @pbufs->outbuf to output. This
		95	* does not count the terminator. A value of 0 means there is
		96	* nothing to output and this record should be skipped.
		97	* @seq: The sequence number of the record used for @pbufs->outbuf.
		98	* @dropped: The number of dropped records from reading @seq.
		99	*/
		100	struct printk_message {
		101	struct printk_buffers *pbufs;
		102	unsigned int outbuf_len;
		103	u64 seq;
		104	unsigned long dropped;
		105	};

kernel/printk/printk.c+179−129

 	.val[1]		= 0,
 };
-#ifdef CONFIG_PRINTK_CALLER
-#define PREFIX_MAX		48
-#else
-#define PREFIX_MAX		32
-#endif
-/* the maximum size of a formatted record (i.e. with prefix added per line) */
-#define CONSOLE_LOG_MAX		1024
-/* the maximum size for a dropped text message */
-#define DROPPED_TEXT_MAX	64
-/* the maximum size allowed to be reserved for a record */
-#define LOG_LINE_MAX		(CONSOLE_LOG_MAX - PREFIX_MAX)
 #define LOG_LEVEL(v)		((v) & 0x07)
 #define LOG_FACILITY(v)		((v) >> 3 & 0xff)
 	return len;
 }
+static bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
+				    bool is_extended, bool may_supress);
 /* /dev/kmsg - userspace message inject/listen interface */
 struct devkmsg_user {
 	atomic64_t seq;
 	struct ratelimit_state rs;
 	struct mutex lock;
-	char buf[CONSOLE_EXT_LOG_MAX];
+	struct printk_buffers pbufs;
-	struct printk_info info;
-	char text_buf[CONSOLE_EXT_LOG_MAX];
-	struct printk_record record;
 };
 static __printf(3, 4) __cold
 	size_t len = iov_iter_count(from);
 	ssize_t ret = len;
-	if (!user || len > LOG_LINE_MAX)
+	if (!user || len > PRINTKRB_RECORD_MAX)
 		return -EINVAL;
 	/* Ignore when user logging is disabled. */
 			    size_t count, loff_t *ppos)
 {
 	struct devkmsg_user *user = file->private_data;
-	struct printk_record *r = &user->record;
+	char *outbuf = &user->pbufs.outbuf[0];
-	size_t len;
+	struct printk_message pmsg = {
+		.pbufs = &user->pbufs,
+	};
 	ssize_t ret;
 	if (!user)
 	if (ret)
 		return ret;
-	if (!prb_read_valid(prb, atomic64_read(&user->seq), r)) {
+	if (!printk_get_next_message(&pmsg, atomic64_read(&user->seq), true, false)) {
 		if (file->f_flags & O_NONBLOCK) {
 			ret = -EAGAIN;
 			goto out;
 		 * This pairs with __wake_up_klogd:A.
 		 */
 		ret = wait_event_interruptible(log_wait,
-				prb_read_valid(prb,
+				printk_get_next_message(&pmsg, atomic64_read(&user->seq), true,
-					atomic64_read(&user->seq), r)); /* LMM(devkmsg_read:A) */
+							false)); /* LMM(devkmsg_read:A) */
 		if (ret)
 			goto out;
 	}
-	if (r->info->seq != atomic64_read(&user->seq)) {
+	if (pmsg.dropped) {
 		/* our last seen message is gone, return error and reset */
-		atomic64_set(&user->seq, r->info->seq);
+		atomic64_set(&user->seq, pmsg.seq);
 		ret = -EPIPE;
 		goto out;
 	}
-	len = info_print_ext_header(user->buf, sizeof(user->buf), r->info);
+	atomic64_set(&user->seq, pmsg.seq + 1);
-	len += msg_print_ext_body(user->buf + len, sizeof(user->buf) - len,
-				  &r->text_buf[0], r->info->text_len,
-				  &r->info->dev_info);
-	atomic64_set(&user->seq, r->info->seq + 1);
-	if (len > count) {
+	if (pmsg.outbuf_len > count) {
 		ret = -EINVAL;
 		goto out;
 	}
-	if (copy_to_user(buf, user->buf, len)) {
+	if (copy_to_user(buf, outbuf, pmsg.outbuf_len)) {
 		ret = -EFAULT;
 		goto out;
 	}
-	ret = len;
+	ret = pmsg.outbuf_len;
 out:
 	mutex_unlock(&user->lock);
 	return ret;
 	mutex_init(&user->lock);
-	prb_rec_init_rd(&user->record, &user->info,
-			&user->text_buf[0], sizeof(user->text_buf));
 	atomic64_set(&user->seq, prb_first_valid_seq(prb));
 	file->private_data = user;
 	return prb_record_text_space(&e);
 }
-static char setup_text_buf[LOG_LINE_MAX] __initdata;
+static char setup_text_buf[PRINTKRB_RECORD_MAX] __initdata;
 void __init setup_log_buf(int early)
 {
 	size_t text_len = r->info->text_len;
 	size_t buf_size = r->text_buf_size;
 	char *text = r->text_buf;
-	char prefix[PREFIX_MAX];
+	char prefix[PRINTK_PREFIX_MAX];
 	bool truncated = false;
 	size_t prefix_len;
 	size_t line_len;
 					 unsigned int line_count,
 					 bool syslog, bool time)
 {
-	char prefix[PREFIX_MAX];
+	char prefix[PRINTK_PREFIX_MAX];
 	size_t prefix_len;
 	prefix_len = info_print_prefix(info, syslog, time, prefix);
 	int len = 0;
 	u64 seq;
-	text = kmalloc(CONSOLE_LOG_MAX, GFP_KERNEL);
+	text = kmalloc(PRINTK_MESSAGE_MAX, GFP_KERNEL);
 	if (!text)
 		return -ENOMEM;
-	prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX);
+	prb_rec_init_rd(&r, &info, text, PRINTK_MESSAGE_MAX);
 	mutex_lock(&syslog_lock);
 	u64 seq;
 	bool time;
-	text = kmalloc(CONSOLE_LOG_MAX, GFP_KERNEL);
+	text = kmalloc(PRINTK_MESSAGE_MAX, GFP_KERNEL);
 	if (!text)
 		return -ENOMEM;
 	seq = find_first_fitting_seq(latched_seq_read_nolock(&clear_seq), -1,
 				     size, true, time);
-	prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX);
+	prb_rec_init_rd(&r, &info, text, PRINTK_MESSAGE_MAX);
 	len = 0;
 	prb_for_each_record(seq, prb, seq, &r) {
 	return 1;
 }
-/*
- * Call the specified console driver, asking it to write out the specified
- * text and length. If @dropped_text is non-NULL and any records have been
- * dropped, a dropped message will be written out first.
- */
-static void call_console_driver(struct console *con, const char *text, size_t len,
-				char *dropped_text)
-{
-	size_t dropped_len;
-	if (con->dropped && dropped_text) {
-		dropped_len = snprintf(dropped_text, DROPPED_TEXT_MAX,
-				       "** %lu printk messages dropped **\n",
-				       con->dropped);
-		con->dropped = 0;
-		con->write(con, dropped_text, dropped_len);
-	}
-	con->write(con, text, len);
-}
 /*
  * Recursion is tracked separately on each CPU. If NMIs are supported, an
  * additional NMI context per CPU is also separately tracked. Until per-CPU
 	reserve_size = vsnprintf(&prefix_buf[0], sizeof(prefix_buf), fmt, args2) + 1;
 	va_end(args2);
-	if (reserve_size > LOG_LINE_MAX)
+	if (reserve_size > PRINTKRB_RECORD_MAX)
-		reserve_size = LOG_LINE_MAX;
+		reserve_size = PRINTKRB_RECORD_MAX;
 	/* Extract log level or control flags. */
 	if (facility == 0)
 	if (flags & LOG_CONT) {
 		prb_rec_init_wr(&r, reserve_size);
-		if (prb_reserve_in_last(&e, prb, &r, caller_id, LOG_LINE_MAX)) {
+		if (prb_reserve_in_last(&e, prb, &r, caller_id, PRINTKRB_RECORD_MAX)) {
 			text_len = printk_sprint(&r.text_buf[r.info->text_len], reserve_size,
 						 facility, &flags, fmt, args);
 			r.info->text_len += text_len;
 #else /* CONFIG_PRINTK */
-#define CONSOLE_LOG_MAX		0
-#define DROPPED_TEXT_MAX	0
 #define printk_time		false
 #define prb_read_valid(rb, seq, r)	false
 				  struct dev_printk_info *dev_info) { return 0; }
 static void console_lock_spinning_enable(void) { }
 static int console_lock_spinning_disable_and_check(int cookie) { return 0; }
-static void call_console_driver(struct console *con, const char *text, size_t len,
-				char *dropped_text)
-{
-}
 static bool suppress_message_printing(int level) { return false; }
 static bool pr_flush(int timeout_ms, bool reset_on_progress) { return true; }
 static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress) { return true; }
 }
 /*
- * Print one record for the given console. The record printed is whatever
+ * Prepend the message in @pmsg->pbufs->outbuf with a "dropped message". This
- * record is the next available record for the given console.
+ * is achieved by shifting the existing message over and inserting the dropped
+ * message.
+ *
+ * @pmsg is the printk message to prepend.
  *
- * @text is a buffer of size CONSOLE_LOG_MAX.
+ * @dropped is the dropped count to report in the dropped message.
  *
- * If extended messages should be printed, @ext_text is a buffer of size
+ * If the message text in @pmsg->pbufs->outbuf does not have enough space for
- * CONSOLE_EXT_LOG_MAX. Otherwise @ext_text must be NULL.
+ * the dropped message, the message text will be sufficiently truncated.
  *
- * If dropped messages should be printed, @dropped_text is a buffer of size
+ * If @pmsg->pbufs->outbuf is modified, @pmsg->outbuf_len is updated.
- * DROPPED_TEXT_MAX. Otherwise @dropped_text must be NULL.
+ */
+#ifdef CONFIG_PRINTK
+static void console_prepend_dropped(struct printk_message *pmsg, unsigned long dropped)
+{
+	struct printk_buffers *pbufs = pmsg->pbufs;
+	const size_t scratchbuf_sz = sizeof(pbufs->scratchbuf);
+	const size_t outbuf_sz = sizeof(pbufs->outbuf);
+	char *scratchbuf = &pbufs->scratchbuf[0];
+	char *outbuf = &pbufs->outbuf[0];
+	size_t len;
+	len = scnprintf(scratchbuf, scratchbuf_sz,
+		       "** %lu printk messages dropped **\n", dropped);
+	/*
+	 * Make sure outbuf is sufficiently large before prepending.
+	 * Keep at least the prefix when the message must be truncated.
+	 * It is a rather theoretical problem when someone tries to
+	 * use a minimalist buffer.
+	 */
+	if (WARN_ON_ONCE(len + PRINTK_PREFIX_MAX >= outbuf_sz))
+		return;
+	if (pmsg->outbuf_len + len >= outbuf_sz) {
+		/* Truncate the message, but keep it terminated. */
+		pmsg->outbuf_len = outbuf_sz - (len + 1);
+		outbuf[pmsg->outbuf_len] = 0;
+	}
+	memmove(outbuf + len, outbuf, pmsg->outbuf_len + 1);
+	memcpy(outbuf, scratchbuf, len);
+	pmsg->outbuf_len += len;
+}
+#else
+#define console_prepend_dropped(pmsg, dropped)
+#endif /* CONFIG_PRINTK */
+/*
+ * Read and format the specified record (or a later record if the specified
+ * record is not available).
+ *
+ * @pmsg will contain the formatted result. @pmsg->pbufs must point to a
+ * struct printk_buffers.
+ *
+ * @seq is the record to read and format. If it is not available, the next
+ * valid record is read.
+ *
+ * @is_extended specifies if the message should be formatted for extended
+ * console output.
+ *
+ * @may_supress specifies if records may be skipped based on loglevel.
+ *
+ * Returns false if no record is available. Otherwise true and all fields
+ * of @pmsg are valid. (See the documentation of struct printk_message
+ * for information about the @pmsg fields.)
+ */
+static bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
+				    bool is_extended, bool may_suppress)
+{
+	static int panic_console_dropped;
+	struct printk_buffers *pbufs = pmsg->pbufs;
+	const size_t scratchbuf_sz = sizeof(pbufs->scratchbuf);
+	const size_t outbuf_sz = sizeof(pbufs->outbuf);
+	char *scratchbuf = &pbufs->scratchbuf[0];
+	char *outbuf = &pbufs->outbuf[0];
+	struct printk_info info;
+	struct printk_record r;
+	size_t len = 0;
+	/*
+	 * Formatting extended messages requires a separate buffer, so use the
+	 * scratch buffer to read in the ringbuffer text.
+	 *
+	 * Formatting normal messages is done in-place, so read the ringbuffer
+	 * text directly into the output buffer.
+	 */
+	if (is_extended)
+		prb_rec_init_rd(&r, &info, scratchbuf, scratchbuf_sz);
+	else
+		prb_rec_init_rd(&r, &info, outbuf, outbuf_sz);
+	if (!prb_read_valid(prb, seq, &r))
+		return false;
+	pmsg->seq = r.info->seq;
+	pmsg->dropped = r.info->seq - seq;
+	/*
+	 * Check for dropped messages in panic here so that printk
+	 * suppression can occur as early as possible if necessary.
+	 */
+	if (pmsg->dropped &&
+	    panic_in_progress() &&
+	    panic_console_dropped++ > 10) {
+		suppress_panic_printk = 1;
+		pr_warn_once("Too many dropped messages. Suppress messages on non-panic CPUs to prevent livelock.\n");
+	}
+	/* Skip record that has level above the console loglevel. */
+	if (may_suppress && suppress_message_printing(r.info->level))
+		goto out;
+	if (is_extended) {
+		len = info_print_ext_header(outbuf, outbuf_sz, r.info);
+		len += msg_print_ext_body(outbuf + len, outbuf_sz - len,
+					  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
+	} else {
+		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
+	}
+out:
+	pmsg->outbuf_len = len;
+	return true;
+}
+/*
+ * Print one record for the given console. The record printed is whatever
+ * record is the next available record for the given console.
  *
  * @handover will be set to true if a printk waiter has taken over the
  * console_lock, in which case the caller is no longer holding both the
  *
  * Requires the console_lock and the SRCU read lock.
  */
-static bool console_emit_next_record(struct console *con, char *text, char *ext_text,
+static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
-				     char *dropped_text, bool *handover, int cookie)
 {
-	static int panic_console_dropped;
+	static struct printk_buffers pbufs;
-	struct printk_info info;
-	struct printk_record r;
-	unsigned long flags;
-	char *write_text;
-	size_t len;
-	prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX);
+	bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
+	char *outbuf = &pbufs.outbuf[0];
+	struct printk_message pmsg = {
+		.pbufs = &pbufs,
+	};
+	unsigned long flags;
 	*handover = false;
-	if (!prb_read_valid(prb, con->seq, &r))
+	if (!printk_get_next_message(&pmsg, con->seq, is_extended, true))
 		return false;
-	if (con->seq != r.info->seq) {
+	con->dropped += pmsg.dropped;
-		con->dropped += r.info->seq - con->seq;
-		con->seq = r.info->seq;
-		if (panic_in_progress() && panic_console_dropped++ > 10) {
-			suppress_panic_printk = 1;
-			pr_warn_once("Too many dropped messages. Suppress messages on non-panic CPUs to prevent livelock.\n");
-		}
-	}
-	/* Skip record that has level above the console loglevel. */
+	/* Skip messages of formatted length 0. */
-	if (suppress_message_printing(r.info->level)) {
+	if (pmsg.outbuf_len == 0) {
-		con->seq++;
+		con->seq = pmsg.seq + 1;
 		goto skip;
 	}
-	if (ext_text) {
+	if (con->dropped && !is_extended) {
-		write_text = ext_text;
+		console_prepend_dropped(&pmsg, con->dropped);
-		len = info_print_ext_header(ext_text, CONSOLE_EXT_LOG_MAX, r.info);
+		con->dropped = 0;
-		len += msg_print_ext_body(ext_text + len, CONSOLE_EXT_LOG_MAX - len,
-					  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
-	} else {
-		write_text = text;
-		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
 	}
 	/*
 	printk_safe_enter_irqsave(flags);
 	console_lock_spinning_enable();
-	stop_critical_timings();	/* don't trace print latency */
+	/* Do not trace print latency. */
-	call_console_driver(con, write_text, len, dropped_text);
+	stop_critical_timings();
+	/* Write everything out to the hardware. */
+	con->write(con, outbuf, pmsg.outbuf_len);
 	start_critical_timings();
-	con->seq++;
+	con->seq = pmsg.seq + 1;
 	*handover = console_lock_spinning_disable_and_check(cookie);
 	printk_safe_exit_irqrestore(flags);
  */
 static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
 {
-	static char dropped_text[DROPPED_TEXT_MAX];
-	static char ext_text[CONSOLE_EXT_LOG_MAX];
-	static char text[CONSOLE_LOG_MAX];
 	bool any_usable = false;
 	struct console *con;
 	bool any_progress;
 				continue;
 			any_usable = true;
-			if (console_srcu_read_flags(con) & CON_EXTENDED) {
+			progress = console_emit_next_record(con, handover, cookie);
-				/* Extended consoles do not print "dropped messages". */
-				progress = console_emit_next_record(con, &text[0],
-								    &ext_text[0], NULL,
-								    handover, cookie);
-			} else {
-				progress = console_emit_next_record(con, &text[0],
-								    NULL, &dropped_text[0],
-								    handover, cookie);
-			}
 			/*
 			 * If a handover has occurred, the SRCU read lock