Re: [RFC PATCH v1 2/2] printk: external log buffer (CONFIG_LOGBUFFER)

[Petr Mladek]

On Wed 2016-10-12 03:12:56, Sean Hudson wrote:
> On 10/5/2016 2:48 PM, Petr Mladek wrote:
> > On Tue 2016-10-04 12:55:35, Sean Hudson wrote:
> >> On 10/4/2016 6:27 AM, Petr Mladek wrote:
> >>> IMHO, the only way is to revisit all locations when the log buffer
> >>> is accessed and add all the needed consistency checks. We must make
> >>> sure that we do not access outside of the buffer. Also the log_*_seq
> >>> numbers are supposed to grow linearly...
> >>
> >> Adding an explicit walk of the external log entries should be trivial.
> >> That will only validate that the passed in log entries are consistent
> >> internally.  I will be submitting a v2 patch shortly that fixes an error
> >> that kernel-ci caught. (if CONFIG_PRINTK is disabled, compilation fails)
> >> I'll see about adding that check at the same time.
> > 
> > The question is if a one time walk might find all potential problems.
> > We might want to add checks into the existing code. For example,
> > log_from_idx() is rather sensitive but it does not check if
> > all the values are sane.
> 
> Checking for every possible problem isn't practical and would adversely
> impact the performance of the logging code.  In the case of the function
> you point out, the patch series doesn't change the logic, rather it
> replaces the structure being used.

I do not have strong opinion about it. In each case, printk() is not
a hot path. The question is if even the current code would not
profit from some consistency checks. I have sometimes broken
the consistency of the buffer when working on the printk() code.
And such checks might help to debug such mistakes.


> > In each case, we need to make sure that the address of the
> > shared buffer is not readable in the booloaded config file
> > for a normal user.
> 
> I do not agree with that last point.  If you cannot trust the bootloader
> then the ability of a userspace program to read log contents seems to be
> the least of your problems.

I see. As I said, I am neither security nor bootloader expert. I just
shared my paranoid uncertainties.


> >>> BTW: You did not answered the question about how the bootloader would
> >>> know the right version of the log format. I am afraid that we do not
> >>> want to maintain backward compatibility on the kernel side. The printk
> >>> code already is too complex.
> >>
> >> This is a matter of magic numbers.  Uboot has two preexisting log
> >> structure versions. Since the kernel did not have a version, I used
> >> LOGBUFF_LOG_VERSION = 3, if CONFIG_LOGBUFFER is enabled.  So, if the
> >> boot loader passes the command line parameter 'lcb_phys_addr' and the
> >> contents of that address pass the validation checks found in
> >> is_valid_external_cb(), then the external buffer is used.  Those checks
> >> include matching the version number, structure sizes match, etc.
> >> Otherwise, the external buffer is ignored.  This should allow for the
> >> kernel to change in the future, e.g. v4, and continue to run correctly
> >> even if an older boot loader passes a v3 version of the log entries.
> > 
> > There might be a problem how to bootstrap this. Someone has to define
> > the initial log control block. If it is done by bootloader and it uses
> > a wrong version, the kernel will not know the size of the external
> > buffer and will ignore and never use it.
> 
> This is already defined in the code.  Using the wrong structure/version
> will behave as expected, and be ignored.  That simply means that the
> bootloader can't 'accidentally' use the wrong version and seems sane to
> me.

I see the oposite in the code. The check makes sure that kernel will
ignore wrong version of the buffer. It suggests that kernel will never
use the buffer until bootloader initializes it to the right version.

It might make sense that kernel reinitialize the buffer to its own
version, so that the bootloader will use the right version next time.
But for this, the kernel must know the size of the buffer. So, it
might be a bad idea after all.


> > I have discussed this with colleagues. All this looked to complicated
> > to them.
> 
> It seems like the complexity comes from the problem itself and I'm
> adding very little in the solution that I'm presenting.  How would they
> suggest reducing that complexity?

They suggest to do not mix bootloaded and kernel messages.


> > This patch set actually implements two features:
> > 
> > 1. Possibility to preserve the kernel log buffer between boots.
> > 
> >    But this is already supported by pstore/ramoops.
> 
> I have not looked into either feature extensively.  However, I believe
> that both work slightly differently.  For instance, this feature affords
> more flexibility about the buffer location and size to the kernel in
> that it doesn't require the kernel to reserve a chunk of RAM ahead of
> time.  However, it might be possible to integrate these features
> together in some manner in the future.

It seems that pstore has many capabilities. It allows to store
various types of messages, e.g. only oops/panic messages,
or all messages, or ftrace logs.

The intergration with printk() is transparent. One way is to
register itself as a console and get messages via console
flush. Another way is to flush all messages via the
kmsg API. It means copying messages but it does not
need to touch the printk() code.


> > 2. Possibility to store bootloader messages in the kernel
> >    log buffer.
> 
> Additionally, this feature allows for multiple boot cycles to co-exist.

It might be useful but it also could cause confusion. One might
get easily lost in all the logs.


> It also allows the _bootloader_ to understand/display _kernel_ log entries.

I do not have much experience with debugging these early boot
problems. So, I am not sure how the would be useful and what
are the other possibilities. 

Note that the early kernel messages do not appear in
the shared buffer until setup_ext_logbuff() is called.
The early serial console provides a better job here.


> >    The question is who wants it and if it is worth the effort.
> 
> This feature existed before I picked it up in Wolfgang Denk's kernels.
> It was broken by the changes to the internal log structures that came in
> with 3.10.

Well, this is not much encouraging. It took 3 years to update it
for a new kernel API.

> > 
> >    The bootloader will need to implement log storing in the
> >    non-trivial format. It will need to maintain compatibility
> >    of this format in the future.
> 
> yes, in order to match what the kernel uses, the bootloader will have to
> use the same format.  FWIW, the kernel structure has been very stable
> over time, with the last major change occurring in the 3.10 time frame.
> Of course, any bootloader that wants to pass information to the kernel
> in a common format will have to keep up to date.

Well, the API is hard to touch because 3rd party tools depend on it.
Adding yet another dependecy will make cleaning/fixing printk() code
even more complicated.


> >    I guess that the bootloader is running on a single CPU
> >    and is basically one process. Therefore it does not need
> >    to solve any races. Therefore it does not need such a complex
> >    format.
> 
> The log structures do not provide protection for multiple CPUs.
> Additional fields in the log structure are only there to provide
> compatibility with the kernel.

I wanted to say that a plain text would be enough for
the bootloader log.

kernel stored plain text into the logbuffer before 3.10 and
many things were much easier. The commit
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/?id=7ff9554bb578ba02166071d2d487b7fc7d860d62
converted it to the variable-length record buffer. This change
caused many problems and complications. Many of them are not
solved until today.

I am not sure that you really want to repeat the "mistake"
and add such complexity to the bootloader.

> >    It might be more effective to write just a simple
> >    text into the persistent memory and provide a userspace tool
> >    to dump it.
> 
> That would not provide any benefit if the kernel doesn't successfully
> start up user space.

IMHO, people mostly use serial console to debug these things.
Your feature will help only if the kernel reaches
setup_ext_logbuff() and the shared buffer is initialized
the right way.

In each case, I do not feel having enough experience to decide
about this feature. It would be great to hear from others.

Best Regards,
Petr