Re: [RFC PATCH v2 1/2] printk-rb: add a new printk ringbuffer implementation

John Ogness
2019-06-25T12:03:54Z

On 2019-06-25, Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> wrote:
>>>> In vprintk_emit(), are we going to always reserve 1024-byte
>>>> records, since we don't know the size in advance, e.g.
>>>>
>>>> printk("%pS %s\n", regs->ip, current->name)
>>>> prb_reserve(&e, &rb, ????);
>>>>
>>>> or are we going to run vscnprintf() on a NULL buffer first,
>>>> then reserve the exactly required number of bytes and afterwards
>>>> vscnprintf(s) -> prb_commit(&e)?
>>>
>>> (As suggested by Petr) I want to use vscnprintf() on a NULL
>>> buffer. However, a NULL buffer is not sufficient because things like the
>>> loglevel are sometimes added via %s (for example, in /dev/kmsg). So
>>> rather than a NULL buffer, I would use a small buffer on the stack
>>> (large enough to store loglevel/cont information). This way we can use
>>> vscnprintf() to get the exact size _and_ printk_get_level() will see
>>> enough of the formatted string to parse what it needs.
>>
>> vscnprintf() with NULL pointer is perfectly fine. Only the formatted
>> string has variable size.
>
> Yeah, that should work. Probably. Can't think of any issues, except
> for increased CPU usage. Some sprintf() format specifiers are heavier
> than the rest (pS/pF on ia64/ppc/hppa).
>
> OK, very theoretically.
>
> There is a difference.
>
> Doing "sz = vscprintf(NULL, msg); vscnprintf(buf, sz, msg)" for
> msg_print_text() and msg_print_ext_header() was safe, because the
> data - msg - would not change under us, we would work with logbuf
> records, IOW with data which is owned by printk() and printk only.
>
> But doing
> sz = vcsprintf(NULL, "xxx", random_pointer);
> if ((buf = prb_reserve(... sz))) {
> vscnprintf(buf, sz, "xxx", random_pointer);
> prb_commit(...);
> }
>
> might have different outcome sometimes. We probably (!!!) can have
> some race conditions. The problem is that, unlike msg_print_text()
> and msg_print_ext_header(), printk() works with pointers which it
> does not own nor control. IOW within single printk() we will access
> some random kernel pointers, then do prb stuff, then access those
> same pointers, expecting that none of them will ever change their
> state. A very simple example
>
> printk("Comm %s\n", current->comm)
>
> Suppose printk on CPU0 and ia64_mca_modify_comm on CPU1
>
> CPU0 CPU1
> printk(...)
> sz = vscprintf(NULL, "Comm %s\n", current->comm);
> ia64_mca_modify_comm()
> snprintf(comm, sizeof(comm), "%s %d", current->comm, previous_current->pid);
> memcpy(current->comm, comm, sizeof(current->comm));
> if ((buf = prb_reserve(... sz))) {
> vscnprintf(buf, "Comm %s\n", current->comm);
> ^^^^^^^^^^^^^^ ->comm has changed.
> Nothing critical, we
> should not corrupt
> anything, but we will
> truncate ->comm if its
> new size is larger than
> what it used to be when
> we did vscprintf(NULL).
> prb_commit(...);
> }
>
> Probably there can be other examples.

This is a very good point, and quite important. It is not acceptable if
some crash output is cut off because of this effect.

In my v1 rfc series, I avoided this issue by having a separate dedicated
ringbuffer (rb_sprintf) that was used to allocate a temporary max-size
(2KB) buffer for sprinting to. Then _that_ was used for the real
ringbuffer input (strlen, prb_reserve, memcpy, prb_commit). That would
still be the approach of my choice.

John Ogness