[PATCH v2 0/2] printk: more log flag simplification

[PATCH v2 0/2] printk: more log flag simplification

[Alex Elder]

This series eliminates the LOG_CONT entirely from the printk/log code.
It builds on another series, posted earlier today:
    http://www.spinics.net/lists/kernel/msg1791665.html
This series was originally longer, but in review I was reminded
that some of the simplifications I had done were not valid.

The first patch exploits the fact that LOG_CONT and LOG_NEWLINE
are inverses, and uses LOG_NEWLINE (or its negation) anywhere
LOG_CONT is used.  As a result, LOG_CONT is no longer needed, so
it's eliminated.

The second patch improves some comments and makes a few small
code cleanups, now that it's gone through this transformation.

					-Alex

This series is available here:
    http://git.linaro.org/landing-teams/working/broadcom/kernel.git
    Branch review/more-printk-flags-v2
It is based on branch review/printk-flags-v6 in that same repository.

Alex Elder (2):
  printk: kill LOG_CONT
  printk: improve some commentary; tidy up

 kernel/printk/printk.c | 99 ++++++++++++++++++++++++++++++--------------------
 1 file changed, 59 insertions(+), 40 deletions(-)

-- 
1.9.1

[PATCH v2 1/2] printk: kill LOG_CONT

[Alex Elder]

The LOG_CONT and LOG_NEWLINE flags are mutually exclusive, i.e.,
the presence of LOG_NEWLINE implies the absense of LOG_CONT, and
vice-versa.  As a result, wherever LOG_CONT is used, we can
equivalently substitute !LOG_NEWLINE; and we can use LOG_NEWLINE
wherever !LOG_CONT is used.

Switch to using LOG_NEWLINE only, and get rid of LOG_CONT.  Make
some refinements on a nearby block of comments.

Signed-off-by: Alex Elder <elder@linaro.org>
---
 kernel/printk/printk.c | 42 +++++++++++++++++++++---------------------
 1 file changed, 21 insertions(+), 21 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 6848e7d..49c9238 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -211,7 +211,6 @@ enum log_flags {
 	LOG_NOCONS	= 1,	/* already flushed, do not print to console */
 	LOG_NEWLINE	= 2,	/* text ended with a newline */
 	LOG_PREFIX	= 4,	/* text started with a prefix */
-	LOG_CONT	= 8,	/* text is a fragment of a continuation line */
 };
 
 struct printk_log {
@@ -613,22 +612,25 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 	do_div(ts_usec, 1000);
 
 	/*
-	 * If we couldn't merge continuation line fragments during the print,
-	 * export the stored flags to allow an optional external merge of the
-	 * records. Merging the records isn't always necessarily correct, like
-	 * when we hit a race during printing. In most cases though, it produces
-	 * better readable output. 'c' in the record flags mark the first
-	 * fragment of a line, '+' the following.
+	 * Sometimes it's necessary to flush an incomplete record to the log.
+	 * When this happens, consecutive records should be merged to produce
+	 * a logically complete message.
+	 *
+	 * Indicate this to user space with a flag character.  A 'c' indicates
+	 * the first of a series of incomplete log records.  A '+' indicates
+	 * a record that should be merged with one or more earlier records.
+	 * And a '-' indicates a "normal" self-contained single record.
 	 */
-	if ((user->prev & LOG_CONT) && !(msg->flags & LOG_PREFIX))
+	if (!(user->prev & LOG_NEWLINE) && !(msg->flags & LOG_PREFIX))
 		cont = '+';
-	else if (msg->flags & LOG_CONT)
+	else if (!(msg->flags & LOG_NEWLINE))
 		cont = 'c';
 	else
 		cont = '-';
 
 	/* Insert a newline if the previous line was not terminated properly */
-	insert_newline = (user->prev & LOG_CONT) && (msg->flags & LOG_PREFIX);
+	insert_newline = !(user->prev & LOG_NEWLINE) &&
+			    (msg->flags & LOG_PREFIX);
 	len = sprintf(user->buf, "%s%u,%llu,%llu,%c;",
 		      insert_newline ? "\n" : "",
 		      (msg->facility << 3) | msg->level,
@@ -1007,13 +1009,13 @@ static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
 	bool newline = true;
 	size_t len = 0;
 
-	if ((prev & LOG_CONT) && !(msg->flags & LOG_PREFIX))
+	if (!(prev & LOG_NEWLINE) && !(msg->flags & LOG_PREFIX))
 		prefix = false;
 
-	if (msg->flags & LOG_CONT)
+	if (!(msg->flags & LOG_NEWLINE))
 		newline = false;
 
-	if ((prev & LOG_CONT) && (msg->flags & LOG_PREFIX) && len < size) {
+	if (!(prev & LOG_NEWLINE) && (msg->flags & LOG_PREFIX) && len < size) {
 		if (buf)
 			buf[len++] = '\n';
 		else
@@ -1081,7 +1083,7 @@ static int syslog_print(char __user *buf, int size)
 			 */
 			syslog_seq = log_first_seq;
 			syslog_idx = log_first_idx;
-			syslog_prev &= LOG_NEWLINE|LOG_CONT;
+			syslog_prev &= LOG_NEWLINE;
 			syslog_partial = 0;
 		}
 		if (syslog_seq == log_next_seq) {
@@ -1210,7 +1212,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 				 */
 				seq = log_first_seq;
 				idx = log_first_idx;
-				prev &= LOG_NEWLINE|LOG_CONT;
+				prev &= LOG_NEWLINE;
 			}
 		}
 	}
@@ -1319,7 +1321,7 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
 			 */
 			syslog_seq = log_first_seq;
 			syslog_idx = log_first_idx;
-			syslog_prev &= LOG_NEWLINE|LOG_CONT;
+			syslog_prev &= LOG_NEWLINE;
 			syslog_partial = 0;
 		}
 		if (from_file) {
@@ -1534,7 +1536,7 @@ static bool cont_add(int facility, int level, const char *text, size_t len)
 
 	if (cont.len + len > sizeof(cont.buf)) {
 		/* the line gets too long, split it up in separate records */
-		cont_flush(LOG_CONT);
+		cont_flush(0);
 		return false;
 	}
 
@@ -1552,7 +1554,7 @@ static bool cont_add(int facility, int level, const char *text, size_t len)
 	cont.len += len;
 
 	if (cont.len > (sizeof(cont.buf) * 80) / 100)
-		cont_flush(LOG_CONT);
+		cont_flush(0);
 
 	return true;
 }
@@ -1665,8 +1667,6 @@ asmlinkage int vprintk_emit(int facility, int level,
 	if (text_len && text[text_len-1] == '\n') {
 		text_len--;
 		lflags = LOG_NEWLINE;
-	} else {
-		lflags = LOG_CONT;
 	}
 
 	/* strip kernel syslog prefix and extract log level or control flags */
@@ -2167,7 +2167,7 @@ again:
 		if (console_seq < log_first_seq) {
 			len = sprintf(text,
 				      "%s** %u printk messages dropped **\n",
-				      (console_prev & LOG_CONT) ? "\n" : "",
+				      (console_prev & LOG_NEWLINE) ? "" : "\n",
 				      (unsigned)(log_first_seq - console_seq));
 			/* Messages are gone, move to first one. */
 			console_seq = log_first_seq;
-- 
1.9.1

[PATCH v2 2/2] printk: improve some commentary; tidy up

[Alex Elder]

Add some comments to explain how the log flags are used to control
how records get formatted.  Also add and refine some comments in
vprintk_emit().

Now that we're done fixing up log record flags, simplify how they're
used in computing some local variable values in msg_print_text().

Use a local variable "flush_cont" in vprintk_emit() to factor out a
common expression used later in that function.

Signed-off-by: Alex Elder <elder@linaro.org>
---
 kernel/printk/printk.c | 63 ++++++++++++++++++++++++++++++++------------------
 1 file changed, 41 insertions(+), 22 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 49c9238..cecdc1b 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -141,6 +141,12 @@ EXPORT_SYMBOL(console_set_on_cmdline);
 static int console_may_schedule;
 
 /*
+ * Each call to printk() fills a record in a circular log buffer.
+ * The contents of the log buffer are read by various subsystems
+ * (including the console subsystem), each of which formats the
+ * content of log buffers for human consumption.  Flags in each
+ * log record are used to track formatting-related state.
+ *
  * The printk log buffer consists of a chain of concatenated variable
  * length records. Every record starts with a record header, containing
  * the overall length of the record.
@@ -150,7 +156,7 @@ static int console_may_schedule;
  * are stored..
  *
  * If the heads indicate available messages, the length in the header
- * tells the start next message. A length == 0 for the next message
+ * tells the start of the next message. A length == 0 for the next message
  * indicates a wrap-around to the beginning of the buffer.
  *
  * Every record carries the monotonic timestamp in microseconds, as well as
@@ -192,6 +198,16 @@ static int console_may_schedule;
  *         67                           "g"
  *   0032     00 00 00                  padding to next message header
  *
+ * If a printk() call contains no newline, its content is saved in a
+ * special "cont" buffer rather than being written directly into the
+ * log.  One or more follow-in printk() calls from the same source
+ * can then be combined into a single newline-terminated message (if
+ * possible) before the combined result is saved into a log record.
+ * Occasionally a buffered/partial message needs to be flushed to
+ * the log before the logically next printk() call is seen.  When
+ * this occurs, the incomplete record (with no LOG_NEWLINE) will
+ * be followed by a new record marked LOG_PREFIX.
+ *
  * The 'struct printk_log' buffer header must never be directly exported to
  * userspace, it is a kernel-private implementation detail that might
  * need to be changed in the future, when the requirements change.
@@ -1005,17 +1021,14 @@ static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
 {
 	const char *text = log_text(msg);
 	size_t text_size = msg->text_len;
-	bool prefix = true;
-	bool newline = true;
 	size_t len = 0;
+	bool prefix;
+	bool newline;
 
-	if (!(prev & LOG_NEWLINE) && !(msg->flags & LOG_PREFIX))
-		prefix = false;
-
-	if (!(msg->flags & LOG_NEWLINE))
-		newline = false;
-
-	if (!(prev & LOG_NEWLINE) && (msg->flags & LOG_PREFIX) && len < size) {
+	prefix = (prev & LOG_NEWLINE) || (msg->flags & LOG_PREFIX);
+	newline = !!(msg->flags & LOG_NEWLINE);
+	/* Insert a newline if we're terminating the previous line early */
+	if (prefix && !(prev & LOG_NEWLINE) && len < size) {
 		if (buf)
 			buf[len++] = '\n';
 		else
@@ -1600,6 +1613,7 @@ asmlinkage int vprintk_emit(int facility, int level,
 	int this_cpu;
 	int printed_len = 0;
 	bool in_sched = false;
+	bool flush_cont = false;
 	/* cpu currently holding logbuf_lock in this function */
 	static volatile unsigned int logbuf_cpu = UINT_MAX;
 
@@ -1698,12 +1712,16 @@ asmlinkage int vprintk_emit(int facility, int level,
 	if (dict)
 		lflags = LOG_PREFIX|LOG_NEWLINE;
 
+	/*
+	 * If the previous printk() call had no newline, it will be buffered.
+	 * If the buffered message was produced by someone else, or if this
+	 * call is forcing a new record, we will need to flush the buffer
+	 * rather than merge this message into it.
+	 */
+	flush_cont = (cont.owner != current) || (lflags & LOG_PREFIX);
 	if (!(lflags & LOG_NEWLINE)) {
-		/*
-		 * Flush the conflicting buffer. An earlier newline was missing,
-		 * or another task also prints continuation lines.
-		 */
-		if (cont.len && (lflags & LOG_PREFIX || cont.owner != current))
+		/* If the buffered record conflicts, flush it first. */
+		if (cont.len && flush_cont)
 			cont_flush(LOG_NEWLINE);
 
 		/* buffer line if possible, otherwise store it right away */
@@ -1716,20 +1734,21 @@ asmlinkage int vprintk_emit(int facility, int level,
 		bool stored = false;
 
 		/*
-		 * If an earlier newline was missing and it was the same task,
-		 * either merge it with the current buffer and flush, or if
-		 * there was a race with interrupts (prefix == true) then just
-		 * flush it out and store this line separately.
-		 * If the preceding printk was from a different task and missed
-		 * a newline, flush and append the newline.
+		 * If there's a buffered message, try to merge with
+		 * it, then flush whatever's buffered to the log.
 		 */
 		if (cont.len) {
-			if (cont.owner == current && !(lflags & LOG_PREFIX))
+			if (!flush_cont)
 				stored = cont_add(facility, level, text,
 						  text_len);
 			cont_flush(LOG_NEWLINE);
 		}
 
+		/*
+		 * Record how much we just formatted.  If cont_add() didn't
+		 * combine this message with the buffered one we still have
+		 * to store this one to the log.
+		 */
 		if (stored)
 			printed_len += text_len;
 		else
-- 
1.9.1

Re: [PATCH v2 0/2] printk: more log flag simplification

[Borislav Petkov]

On Tue, Jul 22, 2014 at 09:01:55AM -0500, Alex Elder wrote:
> This series eliminates the LOG_CONT entirely from the printk/log code.
> It builds on another series, posted earlier today:
>     http://www.spinics.net/lists/kernel/msg1791665.html
> This series was originally longer, but in review I was reminded
> that some of the simplifications I had done were not valid.
> 
> The first patch exploits the fact that LOG_CONT and LOG_NEWLINE
> are inverses, and uses LOG_NEWLINE (or its negation) anywhere
> LOG_CONT is used.  As a result, LOG_CONT is no longer needed, so
> it's eliminated.
> 
> The second patch improves some comments and makes a few small
> code cleanups, now that it's gone through this transformation.

This is getting ridiculous - you've been spamming me with printk patches
like crazy every day! I told you to wait a bit with a resend until
people have had a chance to review them, but you don't seem to care.

Would you please remove me from your CC list?

Thank you.

-- 
Regards/Gruss,
    Boris.

Sent from a fat crate under my desk. Formatting is fine.
--

Re: [PATCH v2 0/2] printk: more log flag simplification

[Alex Elder]

On 07/22/2014 09:24 AM, Borislav Petkov wrote:
> On Tue, Jul 22, 2014 at 09:01:55AM -0500, Alex Elder wrote:
>> This series eliminates the LOG_CONT entirely from the printk/log code.
>> It builds on another series, posted earlier today:
>>     http://www.spinics.net/lists/kernel/msg1791665.html
>> This series was originally longer, but in review I was reminded
>> that some of the simplifications I had done were not valid.
>>
>> The first patch exploits the fact that LOG_CONT and LOG_NEWLINE
>> are inverses, and uses LOG_NEWLINE (or its negation) anywhere
>> LOG_CONT is used.  As a result, LOG_CONT is no longer needed, so
>> it's eliminated.
>>
>> The second patch improves some comments and makes a few small
>> code cleanups, now that it's gone through this transformation.
> 
> This is getting ridiculous - you've been spamming me with printk patches
> like crazy every day! I told you to wait a bit with a resend until
> people have had a chance to review them, but you don't seem to care.
> 
> Would you please remove me from your CC list?

Yes.	-Alex

> Thank you.
>