Re: kernel/printk/printk.c: Invalid access when buffer wraps around?

[Ivan Delalande]

Hi,

On Mon, Jul 25, 2016 at 11:22:24AM +0200, Vincent Brillault wrote:
> While working on a kernel module that basically forks
> kernel/printk/printk.c to create its own buffer, I believe I have found
> a bug in how printk wraps around its buffer: In a very specific case, a
> reader, trying to read what was supposed to be a zeroed header
> indicating that the buffer wrapped, might read random data from another
> message that has overridden it. The root of the problems seems to be
> that the zeroed header placed at the end of the buffer is not protected
> by the sequence number checks.
> 
> [...]
> 
> Due to scheduling/reader choice, the reader now stops.
> A 20 character-long message arrives. The buffers removes messages from before
> and wraps arround:
> 88888888888888888883333333444444444555555555556666666677770...........
> 
> And we now have:
> log_first_seq = 3, log_next_seq = 9
> log_first_idx = 20, log_next_idx = 20
> 
> Let's continue filling the buffer, without wrapping:
> 88888888888888888889999999999999999999aaaaaaaaaaaaabbbbbbbbbbbbbb.....
> 
> We now have:
> log_first_seq = 8, log_next_seq = 0xc
> log_first_idx = 0, log_next_idx = 65
> 
> And now the reader restarts, it still have the same sequence number, '8'
> As `seq < log_first_seq` is false, it will consider that this message is valid
> and continue. Unfortunately, it's first action will be `log_from_idx(idx)`,
> which will first try to read the header of the message at the offset `idx`.
> This header, which was supposed to be zeroed due to the wrap-around, has now
> been overritten and thus contain random junk, which might ultimately lead
> to a kernel panic (wrong memory access from the reader).
> 
> As I understand it, the underlying problem is that the zeroed-header is
> not properly protected by the sequence number cheks.

Thanks for your very detailled write-up but I believe you are mistaken
on the value of log_first_idx between these two last steps you describe.
To detail even more:

- we want to store bbbâ and we have first_seq=7, first_idx=57,
- first loop in log_make_free_space(), not enough space, so we move the
  next one, first_seq=8, first_idx= *59* (log_next check of msg->len is
  for record 7),
- second loop in log_make_free_space(), logbuf_has_space uses
  first_idx=59 and will still return false, so we go to the next record
  once again and end up with first_seq=9, first_idx=23.

So I think the situation you describe cannot happen, first_seq will
always be incremented when we find the 0-filled record and wrap around,
and so all the later checks of "*_seq < log_first_seq" will reset all
the readers indexes.

Did I miss anything?

-- 
Ivan "Colona" Delalande
Arista Networks