tracing: off by one in __trace_array_vprintk()

This check says "goto out;" if we had to truncate the string.

The "tbuffer" buffer has TRACE_BUF_SIZE bytes. The vsnprintf() function returns the number of characters (not counting the NUL char) which would have been printed if there were space. If we we tried to print TRACE_BUF_SIZE characters, the last character would have been truncated to make space for the NUL character so we should "goto out;".

My other concern here was that a few lines later we do:

	entry->buf[len] = '\0';

I worried that maybe we were putting the NUL char past the end of the array but I wasn't smart enough to figure out the size of entry->buf[].

Signed-off-by Dan Carpenter <[email protected]>

kernel/trace/trace.c +1 -1

index 42a822d..22af2ae 100644
@@ -2161,7 +2161,7 @@ __trace_array_vprintk(struct ring_buffer *buffer,
 	}
 
 	len = vsnprintf(tbuffer, TRACE_BUF_SIZE, fmt, args);
-	if (len > TRACE_BUF_SIZE)
+	if (len >= TRACE_BUF_SIZE)
 		goto out;
 
 	local_save_flags(flags);

Quoted 10 lines · On Wed, 26 Nov 2014 17:06:21 +0300 Dan Carpenter <[email protected]>…

This check says "goto out;" if we had to truncate the string.

The "tbuffer" buffer has TRACE_BUF_SIZE bytes. The vsnprintf() function returns the number of characters (not counting the NUL char) which would have been printed if there were space. If we we tried to print TRACE_BUF_SIZE characters, the last character would have been truncated to make space for the NUL character so we should "goto out;".

My other concern here was that a few lines later we do:

Quoted 4 lines

	entry->buf[len] = '\0';

I worried that maybe we were putting the NUL char past the end of the array but I wasn't smart enough to figure out the size of entry->buf[].

entry is of type struct print_entry *, which is defined by macro magic (sorry),

and would look like this:

struct print_entry {
	unsigned long		ip;
	char			buf[];
};

But then it is allocated like so:

	size = sizeof(*entry) + len + 1;
	event = trace_buffer_lock_reserve(buffer, TRACE_PRINT, size,
					  flags, pc);

	entry = ring_buffer_event_data(event);

This check says "goto out;" if we had to truncate the string.

The "tbuffer" buffer has TRACE_BUF_SIZE bytes. The vsnprintf() function returns the number of characters (not counting the NUL char) which would have been printed if there were space. If we we tried to print TRACE_BUF_SIZE characters, the last character would have been truncated to make space for the NUL character so we should "goto out;".

Quoted 8 lines · On Wed, 26 Nov 2014 17:06:21 +0300 Dan Carpenter <[email protected]>…

This check says "goto out;" if we had to truncate the string.

The "tbuffer" buffer has TRACE_BUF_SIZE bytes. The vsnprintf() function returns the number of characters (not counting the NUL char) which would have been printed if there were space. If we we tried to print TRACE_BUF_SIZE characters, the last character would have been truncated to make space for the NUL character so we should "goto out;".

Oh, and the NUL character is never copied. We copy the string into the buffer with:

	memcpy(&entry->buf, tbuffer, len);

Where len does not include NUL, and why we add it ourselves.

Quoted 17 lines · Steven Rostedt

Quoted 8 lines · On Wed, 26 Nov 2014 17:06:21 +0300 Dan Carpenter <[email protected]>…

This check says "goto out;" if we had to truncate the string.

The "tbuffer" buffer has TRACE_BUF_SIZE bytes. The vsnprintf() function returns the number of characters (not counting the NUL char) which would have been printed if there were space. If we we tried to print TRACE_BUF_SIZE characters, the last character would have been truncated to make space for the NUL character so we should "goto out;".

Oh, and the NUL character is never copied. We copy the string into the buffer with:

	memcpy(&entry->buf, tbuffer, len);

Quoted 1 line

Where len does not include NUL, and why we add it ourselves.

Yeah. I noticed that. Probably we should change the memcpy() to:

	memcpy(&entry->buf, tbuffer, len + 1);

and remove separate NUL assignment? It's a speedup! I'll do it in v2.

I highly doubt it's much of a speed up. And we do that by sacrificing that one byte of buffer, which would lose the printk if len does equal TRACE_BUF_SIZE.

I don't see a bug here. What exactly are you trying to fix?

Quoted 4 lines · Steven Rostedt

I highly doubt it's much of a speed up. And we do that by sacrificing that one byte of buffer, which would lose the printk if len does equal TRACE_BUF_SIZE.

Quoted 1 line

I don't see a bug here. What exactly are you trying to fix?

Heh. vsnprintf() is going to put a NUL char at the end of the string even if you don't plan to use it. :P

Another option would be to just print truncated output. We could use vscnprintf() and remove the off by one limit check.

regards,
dan carpenter

kernel/trace/trace.c +2 -5

index 42a822d..ab76b7b 100644
@@ -2160,9 +2160,7 @@ __trace_array_vprintk(struct ring_buffer *buffer,
 		goto out;
 	}
 
-	len = vsnprintf(tbuffer, TRACE_BUF_SIZE, fmt, args);
-	if (len > TRACE_BUF_SIZE)
-		goto out;
+	len = vscnprintf(tbuffer, TRACE_BUF_SIZE, fmt, args);
 
 	local_save_flags(flags);
 	size = sizeof(*entry) + len + 1;

@@ -2173,8 +2171,7 @@ __trace_array_vprintk(struct ring_buffer *buffer,
 	entry = ring_buffer_event_data(event);
 	entry->ip = ip;
 
-	memcpy(&entry->buf, tbuffer, len);
-	entry->buf[len] = '\0';
+	memcpy(&entry->buf, tbuffer, len + 1);
 	if (!call_filter_check_discard(call, entry, buffer, event)) {
 		__buffer_unlock_commit(buffer, event);
 		ftrace_trace_stack(buffer, flags, 6, pc);

Quoted 10 lines · On Wed, 26 Nov 2014 18:05:41 +0300 Dan Carpenter <[email protected]>…

Quoted 5 lines · Steven Rostedt

I highly doubt it's much of a speed up. And we do that by sacrificing that one byte of buffer, which would lose the printk if len does equal TRACE_BUF_SIZE.

I don't see a bug here. What exactly are you trying to fix?

Heh. vsnprintf() is going to put a NUL char at the end of the string even if you don't plan to use it. :P

Quoted 2 lines

Another option would be to just print truncated output. We could use vscnprintf() and remove the off by one limit check.

Yes, that is a better patch. The previous one wasn't really fixing anything. But printing truncated output is better than nothing.

Want to send it officially?