[PATCH] printk: deduplicate print_prefix() calls

[Tetsuo Handa]

Since /sys/module/printk/parameters/time can change from N to Y between
"msg_print_text() called print_prefix() with buf == NULL" and
"msg_print_text() again calls print_prefix() with buf != NULL", it is not
safe for print_time() to unconditionally return 0 if printk_time == false.

But print_prefix() is called by only msg_print_text(), and print_prefix()
is called once more for calculating output length of prefix, and there is
no need to recalculate it when one log entry contains multiple lines.

Since max output length for syslog marker and timestamp are known to be
small enough, let's close this race by deduplicating print_prefix() calls.

Signed-off-by: Tetsuo Handa <penguin-kernel@xxxxxxxxxxxxxxxxxxx>
---
 kernel/printk/printk.c | 64 +++++++++++++++-----------------------------------
 1 file changed, 19 insertions(+), 45 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1b2a029..eac4c80 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1213,50 +1213,26 @@ static inline void boot_delay_msec(int level)
 static bool printk_time = IS_ENABLED(CONFIG_PRINTK_TIME);
 module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
 
-static size_t print_time(u64 ts, char *buf)
-{
-	unsigned long rem_nsec;
-
-	if (!printk_time)
-		return 0;
-
-	rem_nsec = do_div(ts, 1000000000);
-
-	if (!buf)
-		return snprintf(NULL, 0, "[%5lu.000000] ", (unsigned long)ts);
-
-	return sprintf(buf, "[%5lu.%06lu] ",
-		       (unsigned long)ts, rem_nsec / 1000);
-}
-
-static size_t print_prefix(const struct printk_log *msg, bool syslog, char *buf)
-{
-	size_t len = 0;
-	unsigned int prefix = (msg->facility << 3) | msg->level;
-
-	if (syslog) {
-		if (buf) {
-			len += sprintf(buf, "<%u>", prefix);
-		} else {
-			len += 3;
-			if (prefix > 999)
-				len += 3;
-			else if (prefix > 99)
-				len += 2;
-			else if (prefix > 9)
-				len++;
-		}
-	}
-
-	len += print_time(msg->ts_nsec, buf ? buf + len : NULL);
-	return len;
-}
-
 static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *buf, size_t size)
 {
 	const char *text = log_text(msg);
 	size_t text_size = msg->text_len;
 	size_t len = 0;
+	char prefix[32]; /* "<2047>[18446744073.709551] " */
+	size_t prefix_len = 0;
+
+	if (syslog)
+		prefix_len += snprintf(prefix, sizeof(prefix), "<%u>",
+				       (msg->facility << 3) | msg->level);
+	if (printk_time) {
+		u64 ts = msg->ts_nsec;
+		unsigned long rem_nsec = do_div(ts, 1000000000);
+
+		prefix_len += snprintf(prefix + prefix_len,
+				       sizeof(prefix) - prefix_len,
+				       "[%5lu.%06lu] ", (unsigned long)ts,
+				       rem_nsec / 1000);
+	}
 
 	do {
 		const char *next = memchr(text, '\n', text_size);
@@ -1271,19 +1247,17 @@ static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *bu
 		}
 
 		if (buf) {
-			if (print_prefix(msg, syslog, NULL) +
-			    text_len + 1 >= size - len)
+			if (prefix_len + text_len + 1 >= size - len)
 				break;
 
-			len += print_prefix(msg, syslog, buf + len);
+			memcpy(buf + len, prefix, prefix_len);
+			len += prefix_len;
 			memcpy(buf + len, text, text_len);
 			len += text_len;
 			buf[len++] = '\n';
 		} else {
 			/* SYSLOG_ACTION_* buffer size only calculation */
-			len += print_prefix(msg, syslog, NULL);
-			len += text_len;
-			len++;
+			len += prefix_len + text_len + 1;
 		}
 
 		text = next;
-- 
1.8.3.1