Re: [PATCH printk v2 3/4] printk: Skip unfinalized records in panic

[John Ogness <john.ogness@linutronix.de>]

On 2023-10-17, Petr Mladek <pmladek@suse.com> wrote:
>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
>> @@ -2813,8 +2813,19 @@ static bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
>>  	else
>>  		prb_rec_init_rd(&r, &info, outbuf, outbuf_sz);
>>  
>> -	if (!prb_read_valid(prb, seq, &r))
>> -		return false;
>> +	while (!prb_read_valid(prb, seq, &r)) {
>> +		if (this_cpu_in_panic() && seq < prb_next_seq(prb)) {
>> +			/*
>> +			 * The record @seq is not finalized and there may be
>
> "may be" is a bit misleading. If I count it correctly then there
> "are" more records when seq < prb_next_seq().

Ack.

> But wait. Are the messages printed in panic context always finalized?
> What about messages without the trailing newline printed?
>
> Aha, they actually are finalized because prb_next_seq() would return sequence
> number of the record in "desc_committed" state when there is
> a message without newline and we skip only seq < prb_next_seq().
> So I would update the comment, something like:
>
> 			/*
> 			 * Skip non-finalized records when emitting messages
> 			 * from panic CPU. They might never get	finalized.
> 			 *
> 			 * Note that new messages printed on panic CPU are
> 			 * finalized when we are here. The only exception
> 			 * might be the last message without trailing newline.
> 			 * But it would have the sequence number returned
> 			 * by prb_next_seq().
> 			 */
>
> Sigh, it is long. But this is a quite tricky situation.

OK.

>> diff --git a/kernel/printk/printk_ringbuffer.c b/kernel/printk/printk_ringbuffer.c
>> index 2dc4d5a1f1ff..1bbc008109ef 100644
>> --- a/kernel/printk/printk_ringbuffer.c
>> +++ b/kernel/printk/printk_ringbuffer.c
>> @@ -1876,8 +1876,9 @@ static u64 prb_first_seq(struct printk_ringbuffer *rb)
>>  }
>>  
>>  /*
>> - * Non-blocking read of a record. Updates @seq to the last finalized record
>> - * (which may have no data available).
>> + * Non-blocking read of a record. Updates @seq to the record that was read
>> + * (which may have no data available) or was attempted to be read (in case
>> + * it was unfinalized or non-existent).
>
> I am confused. Well, even the original message was confusing.
> I think about describing it the following way.
>
>   * On input, @seq defines the record which should be read. It might
>   * be updated to a higher value when the requested record has already
>   * been overwritten or when the record had empty data.
>   *
>   * On return, @seq value depends on the situation. It is:
>   *
>   *	- sequence number of the read record on success.
>   *     - sequence number of the first found to-be-finalized record
>   *	  when the input seq number was lower or equal to prb_next_seq().
>   *	- the original value when @seq was invalid, bigger then prb_next_seq().
>
> Sigh, the comment is hairy. Maybe you would find a more elegant way
> to describe the variants.

Be careful. prb_next_seq() is only loosely related to
_prb_read_valid(). I would not mention prb_next_seq() when describing
_prb_read_valid(). There are situations where _prb_read_valid() could
successfully read a record with a higher sequence number than
prb_next_seq() would return. This is because prb_next_seq() is only best
effort.

For panic it is sufficient because panic() will commit finalized records
after having stopped all other CPUs, so it will definitely update
@prb->desc_ring.last_finalized_id and allow prb_next_seq() to point to
the end of the panic messages. But for non-panic that is not the case.

I do not have a problem understanding my version of the comments. Note
that it is just a brief internal comment. It also says:

 * See the description of prb_read_valid() and prb_read_valid_info()
 * for details.

And if you look at the kerneldoc of either of those functions you see:

 * On success, the reader must check r->info.seq to see which record was
 * actually read. This allows the reader to detect dropped records.
 *
 * Failure means @seq refers to a not yet finalized or non-existing record.

Also note that @seq is never passed by reference from the external
caller. It is only passed by reference to the helper function
_prb_read_valid().

> BTW: The support for data-less records were added by the commit
>      ("printk: ringbuffer: support dataless records"). It was
>      needed to handle empty lines: printk("\n"). It is strange
>      that we skip them instead of printing the empty line.

We do not skip them. That was the whole point of adding support for
data-less records. ;-)

get_data() returns "" and @data_size=0

copy_data() returns true (but does not copy any data)

prb_read() returns true (we are assuming it is finalized)

_prb_read_valid() returns true

prb_read_valid() return true

record_print_text() creates a string with prefix and adds "\n"

printk_get_next_message() returns something to print

> Also I would update the above prb_next_seq():
>
> --- a/kernel/printk/printk_ringbuffer.c
> +++ b/kernel/printk/printk_ringbuffer.c
> @@ -2012,8 +2012,8 @@ u64 prb_first_valid_seq(struct printk_ringbuffer *rb)
>   * available records should be skipped.
>   *
>   * Context: Any context.
> - * Return: The sequence number of the next newest (not yet available) record
> - *         for readers.
> + * Return: The sequence number of the next newest (not yet finalized or
> + *	   non-existing) record for readers.

Ack.

John Ogness