Re: [RFC PATCH 1/5] printk: implement pr_cont_t

[Petr Mladek]

On Thu 2020-08-20 01:32:28, John Ogness wrote:
> Implement a new buffering mechanism for pr_cont messages.
> 
> Old mechanism syntax:
> 
>     printk(KERN_INFO "text");
>     printk(KERN_CONT " continued");
>     printk(KERN_CONT "\n");
> 
> New mechanism syntax:
> 
>     pr_cont_t c;
> 
>     pr_cont_begin(&c, KERN_INFO "text");
>     pr_cont_append(&c, " continued");
>     pr_cont_end(&c);
> 
> Signed-off-by: John Ogness <john.ogness@xxxxxxxxxxxxx>
> ---
>  include/linux/printk.h |  19 ++++++
>  kernel/printk/printk.c | 137 +++++++++++++++++++++++++++++++++++++++++
>  2 files changed, 156 insertions(+)
> 
> diff --git a/include/linux/printk.h b/include/linux/printk.h
> index 34c1a7be3e01..4d9ce18e4afa 100644
> --- a/include/linux/printk.h
> +++ b/include/linux/printk.h
> @@ -380,6 +380,25 @@ extern int kptr_restrict;
>  #define pr_cont(fmt, ...) \
>  	printk(KERN_CONT fmt, ##__VA_ARGS__)
>  
> +/* opaque handle for continuous printk messages */
> +typedef struct {
> +	u8	index;
> +	u8	loglevel;
> +	u16	text_len;
> +} pr_cont_t;
> +
> +/* initialize handle, provide loglevel and initial message text */
> +int pr_cont_begin(pr_cont_t *c, const char *fmt, ...);
> +
> +/* append message text */
> +int pr_cont_append(pr_cont_t *c, const char *fmt, ...);
> +
> +/* flush message to kernel buffer */
> +void pr_cont_flush(pr_cont_t *c);
> +
> +/* flush message to kernel buffer, cleanup handle */
> +void pr_cont_end(pr_cont_t *c);
> +
>  /**
>   * pr_devel - Print a debug-level message conditionally
>   * @fmt: format string
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index ad8d1dfe5fbe..10113e7ea350 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3495,3 +3495,140 @@ void kmsg_dump_rewind(struct kmsg_dumper *dumper)
>  EXPORT_SYMBOL_GPL(kmsg_dump_rewind);
>  
>  #endif
> +
> +#define CONT_LINE_MAX LOG_LINE_MAX
> +#define CONT_BUF_COUNT 10
> +static char cont_buf[CONT_BUF_COUNT][CONT_LINE_MAX];
> +static DECLARE_BITMAP(cont_buf_map, CONT_BUF_COUNT);
> +
> +static int get_cont_buf(void)
> +{
> +	int bit;
> +
> +	do {
> +		bit = find_first_zero_bit(cont_buf_map, CONT_BUF_COUNT);
> +		if (bit == CONT_BUF_COUNT)
> +			break;
> +	} while (test_and_set_bit(bit, cont_buf_map));
> +
> +	return bit;
> +}

My big problem with this solution is a forgotten pr_cont_end(). It
will cause:

   + the message will never get printed

   + several calls into such a broken code will exhaust the pool of
     cont buffers and it will stop working for the entire system

The above might be solved with some fallback mechanism (timer,
watchdog) but then it needs some synchronization.

Why is it so bad?

   + it will happen like other bugs

   + it is hard to notice; it is easier to notice hard-lockup than
     a missing message


Now that I think about it. This is the biggest problem with any temporary buffer
for pr_cont() lines. I am more and more convinced that we should just
_keep the current behavior_. It is not ideal. But sometimes mixed
messages are always better than lost ones.


That said, some printk() API using local buffer would be still
valuable for pieces of code where people really want to avoid
mixed lines. But it should be optional and people should be
aware of the risks.

Best Regards,
Petr