Re: [RFC][PATCH] Escaping the arguments of kernel messages for sane user-space localisation

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hello again,


On Mon, 2007-10-08 at 21:45 +0200, Vegard Nossum wrote:
> These functions make it quite easy to make snprintf() automatically
> escape certain characters in string arguments, for example. I think they
> are also well suited to printing to variable-sized buffers, though the
> last time I looked, there was no krealloc in the kernel, which makes it
> again useless. Perhaps there are other uses, though?

I have now found what I think is another valid use. What I have done is
to make xprintf() emit the output directly to the kernel ring-buffer.

This means two things:
1. We get rid of a (static) 1K temporary buffer in printk().
2. A single log message (as emitted by a single call to printk()) is no
longer limited to 1K bytes, but is limited to the size of the ring
buffer (this was obviously always true).

In particular, I think this output from bloat-o-meter is interesting:

add/remove: 25/3 grow/shrink: 0/2 up/down: 1955/-2585 (-630)
function                                     old     new   delta
vxprintf                                       -    1048   +1048
xprintf_number                                 -     499    +499
vsnprintf_unknown_conversion                   -      44     +44
printk_put                                     -      35     +35
printk_unknown_conversion                      -      34     +34
vsnprintf_end                                  -      33     +33
xprintf                                        -      32     +32
vsnprintf_put_char                             -      24     +24
printk_end_param                               -      22     +22
printk_begin_param                             -      22     +22
vsnprintf_begin                                -      21     +21
vsnprintf_put_param                            -      20     +20
vsnprintf_put_format                           -      20     +20
printk_put_param                               -      16     +16
printk_put_format                              -      16     +16
printk_begin                                   -      15     +15
vsnprintf_size                                 -      13     +13
printk_size                                    -      10     +10
vsnprintf_end_param                            -       5      +5
vsnprintf_begin_param                          -       5      +5
printk_end                                     -       5      +5
static.log_level                               -       4      +4
printed_len                                    -       4      +4
new_line                                       -       4      +4
escape_args                                    -       4      +4
static.log_level_unknown                       4       -      -4
vprintk                                      537     396    -141
number                                       488       -    -488
vsnprintf                                   1052     124    -928
static.printk_buf                           1024       -   -1024


There is only one very small caveat (that I can see) to be mentioned:
You can still use multiple printk() calls to append new text to a
partial message, but you can NOT output several messages in a single
call. I think, however, that no sanely written code would do this
anyway, with perhaps the exception of writes to /proc/kmsg, which may
contain newlines which will NOT be preceded by log-levels (or
timestamps). The solution would be to change this location to output the
user-provided data as an argument to %s (like my first kprint patches
did anyway), and maybe escape any newlines. I don't think it's an issue.

So please consider this patch instead of the first I submitted. New
diffstat looks like this:

 include/linux/xprintf.h |   28 +++++
 kernel/printk.c         |  171 +++++++++++++++++----------
 lib/vsprintf.c          |  296 ++++++++++++++++++++++++++++-------------------
 3 files changed, 314 insertions(+), 181 deletions(-)


Kind regards,
Vegard Nossum



diff --git a/include/linux/xprintf.h b/include/linux/xprintf.h
new file mode 100644
index 0000000..76efc43
--- /dev/null
+++ b/include/linux/xprintf.h
@@ -0,0 +1,28 @@
+#ifndef LINUX_XPRINTF_H
+#define LINUX_XPRINTF_H
+
+#include <stdarg.h>
+#include <linux/kernel.h>
+
+struct xprintf_ops {
+	void (*begin)(void *data);
+	void (*end)(void *data);
+	void (*put_format)(void *data, char c);
+
+	void (*begin_param)(void *data);
+	void (*end_param)(void *data);
+	void (*put_param)(void *data, char c);
+
+	long (*size)(void *data);
+
+	void (*unknown_conversion)(void *data, char c);
+};
+
+extern void xprintf(void *data, const struct xprintf_ops *ops,
+	const char *fmt, ...)
+	__attribute__ ((format (printf, 3, 4)));
+extern void vxprintf(void *data, const struct xprintf_ops *ops,
+	const char *fmt, va_list args)
+	__attribute__ ((format (printf, 3, 0)));
+
+#endif
diff --git a/kernel/printk.c b/kernel/printk.c
index 8451dfc..78a5be1 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -31,6 +31,7 @@
 #include <linux/bootmem.h>
 #include <linux/syscalls.h>
 #include <linux/jiffies.h>
+#include <linux/xprintf.h>
 
 #include <asm/uaccess.h>
 
@@ -481,6 +482,80 @@ static int have_callable_console(void)
 	return 0;
 }
 
+static int printed_len;
+static int new_line = 1;
+
+/* Output a single character to the log buffer, and keep count of how many
+ * we print. Also keep track of whether we are starting a new line or not
+ * the next time we print something. */
+static void printk_put(char c)
+{
+	new_line = (c == '\n');
+
+	emit_log_char(c);
+	printed_len++;
+}
+
+static void printk_begin(void *data)
+{
+	printed_len = 0;
+}
+
+static void printk_end(void *data)
+{
+}
+
+static void printk_put_format(void *data, char c)
+{
+	printk_put(c);
+}
+
+/* If set, we output markers in the log to indicate what parts of a message
+ * are from the format string, and what parts are the arguments. */
+static int escape_args;
+
+static void printk_begin_param(void *data)
+{
+	if(escape_args)
+		printk_put('\x1f');
+}
+
+static void printk_end_param(void *data)
+{
+	if(escape_args)
+		printk_put('\x1f');
+}
+
+static void printk_put_param(void *data, char c)
+{
+	printk_put(c);
+}
+
+static long printk_size(void *data)
+{
+	return printed_len;
+}
+
+static void printk_unknown_conversion(void *data, char c)
+{
+	printk_put('%');
+
+	if (c)
+		printk_put(c);
+}
+
+static const struct xprintf_ops printk_ops = {
+	.begin			= &printk_begin,
+	.end			= &printk_end,
+	.put_format		= &printk_put_format,
+	.begin_param		= &printk_begin_param,
+	.end_param		= &printk_end_param,
+	.put_param		= &printk_put_param,
+	.size			= &printk_size,
+	.unknown_conversion	= &printk_unknown_conversion,
+};
+
+
 /**
  * printk - print a kernel message
  * @fmt: format string
@@ -522,10 +597,7 @@ static volatile unsigned int printk_cpu = UINT_MAX;
 asmlinkage int vprintk(const char *fmt, va_list args)
 {
 	unsigned long flags;
-	int printed_len;
-	char *p;
-	static char printk_buf[1024];
-	static int log_level_unknown = 1;
+	int len;
 
 	preempt_disable();
 	if (unlikely(oops_in_progress) && printk_cpu == smp_processor_id())
@@ -539,66 +611,43 @@ asmlinkage int vprintk(const char *fmt, va_list args)
 	spin_lock(&logbuf_lock);
 	printk_cpu = smp_processor_id();
 
-	/* Emit the output into the temporary buffer */
-	printed_len = vscnprintf(printk_buf, sizeof(printk_buf), fmt, args);
+	if(new_line) {
+		static int log_level;
 
-	/*
-	 * Copy the output into log_buf.  If the caller didn't provide
-	 * appropriate log level tags, we insert them here
-	 */
-	for (p = printk_buf; *p; p++) {
-		if (log_level_unknown) {
-                        /* log_level_unknown signals the start of a new line */
-			if (printk_time) {
-				int loglev_char;
-				char tbuf[50], *tp;
-				unsigned tlen;
-				unsigned long long t;
-				unsigned long nanosec_rem;
-
-				/*
-				 * force the log level token to be
-				 * before the time output.
-				 */
-				if (p[0] == '<' && p[1] >='0' &&
-				   p[1] <= '7' && p[2] == '>') {
-					loglev_char = p[1];
-					p += 3;
-					printed_len -= 3;
-				} else {
-					loglev_char = default_message_loglevel
-						+ '0';
-				}
-				t = printk_clock();
-				nanosec_rem = do_div(t, 1000000000);
-				tlen = sprintf(tbuf,
-						"<%c>[%5lu.%06lu] ",
-						loglev_char,
-						(unsigned long)t,
-						nanosec_rem/1000);
-
-				for (tp = tbuf; tp < tbuf + tlen; tp++)
-					emit_log_char(*tp);
-				printed_len += tlen;
-			} else {
-				if (p[0] != '<' || p[1] < '0' ||
-				   p[1] > '7' || p[2] != '>') {
-					emit_log_char('<');
-					emit_log_char(default_message_loglevel
-						+ '0');
-					emit_log_char('>');
-					printed_len += 3;
-				}
-			}
-			log_level_unknown = 0;
-			if (!*p)
-				break;
+		/* Extract log-level */
+		if (fmt[0] == '<' && fmt[1] >= '0'
+			&& fmt[1] <= '7' && fmt[2] == '>')
+		{
+			log_level = fmt[1] - '0';
+			fmt += 3;
+		} else {
+			log_level = default_message_loglevel;
+		}
+
+		escape_args = 0;
+		xprintf(NULL, &printk_ops, "<%d>", log_level);
+
+		/* Print the current time... */
+		if (printk_time) {
+			unsigned long long t;
+			unsigned long nanosec_rem;
+
+			t = printk_clock();
+			nanosec_rem = do_div(t, 1000000000);
+
+			escape_args = 0;
+			xprintf(NULL, &printk_ops, "[%5lu.%06lu] ",
+				(unsigned long) t, nanosec_rem / 1000);
 		}
-		emit_log_char(*p);
-		if (*p == '\n')
-			log_level_unknown = 1;
 	}
 
+	/* Print the message straight to the log buffer */
+	escape_args = 1;
+	vxprintf(NULL, &printk_ops, fmt, args);
+
+	/* Copy this prevent a race when we return this value. */
+	len = printed_len;
+
 	if (!down_trylock(&console_sem)) {
 		/*
 		 * We own the drivers.  We can drop the spinlock and
@@ -637,7 +686,7 @@ asmlinkage int vprintk(const char *fmt, va_list args)
 	}
 
 	preempt_enable();
-	return printed_len;
+	return len;
 }
 EXPORT_SYMBOL(printk);
 EXPORT_SYMBOL(vprintk);
diff --git a/lib/vsprintf.c b/lib/vsprintf.c
index 7b481ce..60fb5e2 100644
--- a/lib/vsprintf.c
+++ b/lib/vsprintf.c
@@ -22,6 +22,7 @@
 #include <linux/string.h>
 #include <linux/ctype.h>
 #include <linux/kernel.h>
+#include <linux/xprintf.h>
 
 #include <asm/page.h>		/* for PAGE_SIZE */
 #include <asm/div64.h>
@@ -240,7 +241,8 @@ static noinline char* put_dec(char *buf, unsigned long long num)
 #define SPECIAL	32		/* 0x */
 #define LARGE	64		/* use 'ABCDEF' instead of 'abcdef' */
 
-static char *number(char *buf, char *end, unsigned long long num, int base, int size, int precision, int type)
+static void xprintf_number(void *data, const struct xprintf_ops *ops,
+	unsigned long long num, int base, int size, int precision, int type)
 {
 	char sign,tmp[66];
 	const char *digits;
@@ -254,7 +256,7 @@ static char *number(char *buf, char *end, unsigned long long num, int base, int
 	if (type & LEFT)
 		type &= ~ZEROPAD;
 	if (base < 2 || base > 36)
-		return NULL;
+		return;
 	sign = 0;
 	if (type & SIGN) {
 		if ((signed long long) num < 0) {
@@ -302,59 +304,116 @@ static char *number(char *buf, char *end, unsigned long long num, int base, int
 	/* leading space padding */
 	size -= precision;
 	if (!(type & (ZEROPAD+LEFT))) {
-		while(--size >= 0) {
-			if (buf < end)
-				*buf = ' ';
-			++buf;
-		}
+		while (--size >= 0)
+			ops->put_param(data, ' ');
 	}
 	/* sign */
-	if (sign) {
-		if (buf < end)
-			*buf = sign;
-		++buf;
-	}
+	if (sign)
+		ops->put_param(data, sign);
 	/* "0x" / "0" prefix */
 	if (need_pfx) {
-		if (buf < end)
-			*buf = '0';
-		++buf;
+		ops->put_param(data, '0');
 		if (base == 16) {
-			if (buf < end)
-				*buf = digits[16]; /* for arbitrary base: digits[33]; */
-			++buf;
+			ops->put_param(data, digits[16]);
+			/* for arbitrary base: digits[33]; */
 		}
 	}
 	/* zero or space padding */
 	if (!(type & LEFT)) {
 		char c = (type & ZEROPAD) ? '0' : ' ';
-		while (--size >= 0) {
-			if (buf < end)
-				*buf = c;
-			++buf;
-		}
+		while (--size >= 0)
+			ops->put_param(data, c);
 	}
 	/* hmm even more zero padding? */
-	while (i <= --precision) {
-		if (buf < end)
-			*buf = '0';
-		++buf;
-	}
+	while (i <= --precision)
+		ops->put_param(data, '0');
 	/* actual digits of result */
-	while (--i >= 0) {
-		if (buf < end)
-			*buf = tmp[i];
-		++buf;
-	}
+	while (--i >= 0)
+		ops->put_param(data, tmp[i]);
 	/* trailing space padding */
-	while (--size >= 0) {
-		if (buf < end)
-			*buf = ' ';
-		++buf;
+	while (--size >= 0)
+		ops->put_param(data, ' ');
+}
+
+struct vsnprintf_data {
+	char *buf;
+	const size_t size;
+
+	char *str;
+	char *end;
+};
+
+static void vsnprintf_put_char(struct vsnprintf_data *d, char c)
+{
+	if (d->str < d->end)
+		*d->str = c;
+	d->str++;
+}
+
+static void vsnprintf_begin(void *data)
+{
+	struct vsnprintf_data *d = data;
+	d->str = d->buf;
+	d->end = d->buf + d->size;
+}
+
+static void vsnprintf_end(void *data)
+{
+	struct vsnprintf_data *d = data;
+
+	if (d->size > 0) {
+		if (d->str < d->end)
+			d->str[0] = '\0';
+		else
+			d->end[-1] = '\0';
+
+		/* The trailing null byte doesn't count towards the total,
+		 * so we don't increment the buffer pointer. */
 	}
-	return buf;
 }
 
+static void vsnprintf_put_format(void *data, char c)
+{
+	vsnprintf_put_char(data, c);
+}
+
+static void vsnprintf_begin_param(void *data)
+{
+}
+
+static void vsnprintf_end_param(void *data)
+{
+}
+
+static void vsnprintf_put_param(void *data, char c)
+{
+	vsnprintf_put_char(data, c);
+}
+
+static long vsnprintf_size(void *data)
+{
+	struct vsnprintf_data *d = data;
+	return d->str - d->buf;
+}
+
+static void vsnprintf_unknown_conversion(void *data, char c)
+{
+	vsnprintf_put_char(data, '%');
+	if (c)
+		vsnprintf_put_char(data, c);
+}
+
+static const struct xprintf_ops vsnprintf_ops = {
+	.begin			= &vsnprintf_begin,
+	.end			= &vsnprintf_end,
+	.put_format		= &vsnprintf_put_format,
+	.begin_param		= &vsnprintf_begin_param,
+	.end_param		= &vsnprintf_end_param,
+	.put_param		= &vsnprintf_put_param,
+	.size			= &vsnprintf_size,
+	.unknown_conversion	= &vsnprintf_unknown_conversion,
+};
+
 /**
  * vsnprintf - Format a string and place it in a buffer
  * @buf: The buffer to place the result into
@@ -375,10 +434,37 @@ static char *number(char *buf, char *end, unsigned long long num, int base, int
  */
 int vsnprintf(char *buf, size_t size, const char *fmt, va_list args)
 {
+	struct vsnprintf_data data = {
+		.size = size,
+		.buf = buf,
+	};
+
+	/* Reject out-of-range values early.  Large positive sizes are
+	   used for unknown buffer sizes. */
+	if (unlikely((int) size < 0)) {
+		/* There can be only one.. */
+		static char warn = 1;
+		WARN_ON(warn);
+		warn = 0;
+		return 0;
+	}
+
+	vxprintf(&data, &vsnprintf_ops, fmt, args);
+	return data.str - buf;
+}
+
+EXPORT_SYMBOL(vsnprintf);
+
+/* This is similar to printf(), except we output not to a string, but call
+ * the callback functions provided through xprintf_ops. This gives much
+ * flexibility in what and where to output the result of the formatting. */
+void vxprintf(void *data, const struct xprintf_ops *ops,
+	const char *fmt, va_list args)
+{
 	int len;
 	unsigned long long num;
 	int i, base;
-	char *str, *end, c;
+	char c;
 	const char *s;
 
 	int flags;		/* flags to number() */
@@ -391,33 +477,16 @@ int vsnprintf(char *buf, size_t size, const char *fmt, va_list args)
 				/* 'z' changed to 'Z' --davidm 1/25/99 */
 				/* 't' added for ptrdiff_t */
 
-	/* Reject out-of-range values early.  Large positive sizes are
-	   used for unknown buffer sizes. */
-	if (unlikely((int) size < 0)) {
-		/* There can be only one.. */
-		static char warn = 1;
-		WARN_ON(warn);
-		warn = 0;
-		return 0;
-	}
-
-	str = buf;
-	end = buf + size;
-
-	/* Make sure end is always >= buf */
-	if (end < buf) {
-		end = ((void *)-1);
-		size = end - buf;
-	}
+	ops->begin(data);
 
 	for (; *fmt ; ++fmt) {
 		if (*fmt != '%') {
-			if (str < end)
-				*str = *fmt;
-			++str;
+			ops->put_format(data, *fmt);
 			continue;
 		}
 
+		ops->begin_param(data);
+
 		/* process flags */
 		flags = 0;
 		repeat:
@@ -477,21 +546,14 @@ int vsnprintf(char *buf, size_t size, const char *fmt, va_list args)
 		switch (*fmt) {
 			case 'c':
 				if (!(flags & LEFT)) {
-					while (--field_width > 0) {
-						if (str < end)
-							*str = ' ';
-						++str;
-					}
+					while (--field_width > 0)
+						ops->put_param(data, ' ');
 				}
 				c = (unsigned char) va_arg(args, int);
-				if (str < end)
-					*str = c;
-				++str;
-				while (--field_width > 0) {
-					if (str < end)
-						*str = ' ';
-					++str;
-				}
+				ops->put_param(data, c);
+				while (--field_width > 0)
+					ops->put_param(data, ' ');
+				ops->end_param(data);
 				continue;
 
 			case 's':
@@ -502,22 +564,16 @@ int vsnprintf(char *buf, size_t size, const char *fmt, va_list args)
 				len = strnlen(s, precision);
 
 				if (!(flags & LEFT)) {
-					while (len < field_width--) {
-						if (str < end)
-							*str = ' ';
-						++str;
-					}
+					while (len < field_width--)
+						ops->put_param(data, ' ');
 				}
 				for (i = 0; i < len; ++i) {
-					if (str < end)
-						*str = *s;
-					++str; ++s;
-				}
-				while (len < field_width--) {
-					if (str < end)
-						*str = ' ';
-					++str;
+					ops->put_param(data, *s);
+					++s;
 				}
+				while (len < field_width--)
+					ops->put_param(data, ' ');
+				ops->end_param(data);
 				continue;
 
 			case 'p':
@@ -525,31 +581,30 @@ int vsnprintf(char *buf, size_t size, const char *fmt, va_list args)
 					field_width = 2*sizeof(void *);
 					flags |= ZEROPAD;
 				}
-				str = number(str, end,
-						(unsigned long) va_arg(args, void *),
-						16, field_width, precision, flags);
+				xprintf_number(data, ops,
+					(unsigned long) va_arg(args, void *),
+					16, field_width, precision, flags);
+				ops->end_param(data);
 				continue;
 
 
 			case 'n':
-				/* FIXME:
-				* What does C99 say about the overflow case here? */
 				if (qualifier == 'l') {
-					long * ip = va_arg(args, long *);
-					*ip = (str - buf);
+					long *ip = va_arg(args, long *);
+					*ip = ops->size(data);
 				} else if (qualifier == 'Z' || qualifier == 'z') {
-					size_t * ip = va_arg(args, size_t *);
-					*ip = (str - buf);
+					size_t *ip = va_arg(args, size_t *);
+					*ip = ops->size(data);
 				} else {
-					int * ip = va_arg(args, int *);
-					*ip = (str - buf);
+					int *ip = va_arg(args, int *);
+					*ip = ops->size(data);
 				}
+				ops->end_param(data);
 				continue;
 
 			case '%':
-				if (str < end)
-					*str = '%';
-				++str;
+				ops->put_param(data, '%');
+				ops->end_param(data);
 				continue;
 
 				/* integer number formats - set up the flags and "break" */
@@ -570,16 +625,10 @@ int vsnprintf(char *buf, size_t size, const char *fmt, va_list args)
 				break;
 
 			default:
-				if (str < end)
-					*str = '%';
-				++str;
-				if (*fmt) {
-					if (str < end)
-						*str = *fmt;
-					++str;
-				} else {
+				ops->unknown_conversion(data, *fmt);
+				if (!*fmt)
 					--fmt;
-				}
+				ops->end_param(data);
 				continue;
 		}
 		if (qualifier == 'L')
@@ -601,20 +650,15 @@ int vsnprintf(char *buf, size_t size, const char *fmt, va_list args)
 			if (flags & SIGN)
 				num = (signed int) num;
 		}
-		str = number(str, end, num, base,
-				field_width, precision, flags);
-	}
-	if (size > 0) {
-		if (str < end)
-			*str = '\0';
-		else
-			end[-1] = '\0';
+		xprintf_number(data, ops,
+			num, base, field_width, precision, flags);
+		ops->end_param(data);
 	}
-	/* the trailing null byte doesn't count towards the total */
-	return str-buf;
+
+	ops->end(data);
 }
 
-EXPORT_SYMBOL(vsnprintf);
+EXPORT_SYMBOL(vxprintf);
 
 /**
  * vscnprintf - Format a string and place it in a buffer
@@ -665,6 +709,18 @@ int snprintf(char * buf, size_t size, const char *fmt, ...)
 
 EXPORT_SYMBOL(snprintf);
 
+/* See vxprintf(). */
+void xprintf(void *data, const struct xprintf_ops *ops, const char *fmt, ...)
+{
+	va_list ap;
+
+	va_start(ap, fmt);
+	vxprintf(data, ops, fmt, ap);
+	va_end(ap);
+}
+
+EXPORT_SYMBOL(xprintf);
+
 /**
  * scnprintf - Format a string and place it in a buffer
  * @buf: The buffer to place the result into


-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[Index of Archives]     [Kernel Newbies]     [Netfilter]     [Bugtraq]     [Photo]     [Stuff]     [Gimp]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Video 4 Linux]     [Linux for the blind]     [Linux Resources]
  Powered by Linux