Re: [PATCH next v3 3/3] printk: remove logbuf_lock protection for ringbuffer
On (20/12/07 23:26), John Ogness wrote: > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c > index e1f068677a74..f3c0fcc3163f 100644 > --- a/kernel/printk/printk.c > +++ b/kernel/printk/printk.c > @@ -1068,7 +1068,6 @@ void __init setup_log_buf(int early) > struct printk_record r; > size_t new_descs_size; > size_t new_infos_size; > - unsigned long flags; > char *new_log_buf; > unsigned int free; > u64 seq; > @@ -1126,8 +1125,6 @@ void __init setup_log_buf(int early) >new_descs, ilog2(new_descs_count), >new_infos); > > - logbuf_lock_irqsave(flags); > - > log_buf_len = new_log_buf_len; > log_buf = new_log_buf; > new_log_buf_len = 0; > @@ -1143,8 +1140,6 @@ void __init setup_log_buf(int early) >*/ > prb = _rb_dynamic; > > - logbuf_unlock_irqrestore(flags); logbuf_lock_irqsave() does two things - it locks the logbuf lock and enables the printk_safe gating. While we can drop the former, the latter one must stay until we have a complete replacement. Looking more: > --- > logbuf_lock_irqsave(flags); > > log_buf_len = new_log_buf_len; > log_buf = new_log_buf; > new_log_buf_len = 0; > > free = __LOG_BUF_LEN; > prb_for_each_record(0, _rb_static, seq, ) > free -= add_to_rb(_rb_dynamic, ); > > /* >* This is early enough that everything is still running on the >* boot CPU and interrupts are disabled. So no new messages will >* appear during the transition to the dynamic buffer. >*/ > prb = _rb_dynamic; > > logbuf_unlock_irqrestore(flags); --- I'd say that I'd prefer to keep logbuf initialisation under printk_safe(), per-CPU buffer can be already initialised at this point. Strictly speaking we can have new message during transition to the dynamic buffer - there are functions there that can pr_err/warn while we prb_for_each_record/add_to_rb. > -ss
Re: [PATCH next v3 3/3] printk: remove logbuf_lock protection for ringbuffer
On Mon 2020-12-07 23:26:20, John Ogness wrote:
> Since the ringbuffer is lockless, there is no need for it to be
> protected by @logbuf_lock. Remove @logbuf_lock protection of the
> ringbuffer.
This patch removes the protection only on the write part. Please,
make it clear here and also in the subject.
> This means that printk_nmi_direct and printk_safe_flush_on_panic()
> no longer need to acquire any lock to run.
>
> Without @logbuf_lock it is no longer possible to use the single
> static buffer for temporarily sprint'ing the message. Instead,
> use vsnprintf() to determine the length and perform the real
> vscnprintf() using the area reserved from the ringbuffer. This
> leads to suboptimal packing of the message data, but will
> result in less wasted storage than multiple per-cpu buffers to
> support lockless temporary sprint'ing.
>
> Signed-off-by: John Ogness
> ---
> kernel/printk/printk.c | 131 +---
> kernel/printk/printk_safe.c | 18 +
> 2 files changed, 95 insertions(+), 54 deletions(-)
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index e1f068677a74..f3c0fcc3163f 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1861,19 +1856,91 @@ static inline u32 printk_caller_id(void)
> 0x8000 + raw_smp_processor_id();
> }
>
> -/* Must be called under logbuf_lock. */
> +/**
> + * parse_prefix - Parse level and control flags.
> + *
> + * @text: The text message.
> + * @text_len: A pointer to a value of strlen(@text), will be updated.
> + * @level:A pointer to the current level value, will be updated.
> + * @lflags: A pointer to the current log flags, will be updated.
> + *
> + * The variable pointed to by @text_len is updated to the message length
> + * when subtracting the parsed level and control flag length.
> + *
> + * @level may be NULL if the caller is not interested in the parsed value.
> + * Otherwise the variable pointed to by @level must be set to
> + * LOGLEVEL_DEFAULT in order to be updated with the parsed value.
> + *
> + * @lflags may be NULL if the caller is not interested in the parsed value.
> + * Otherwise the variable pointed to by @lflags will be OR'd with the parsed
> + * value.
> + *
> + * Return: The text message with the parsed level and control flags skipped.
> + */
> +static char *parse_prefix(char *text, u16 *text_len, int *level, enum
> log_flags *lflags)
> +{
> + int kern_level;
> +
> + while (*text_len >= 2) {
> + kern_level = printk_get_level(text);
> + if (!kern_level)
> + break;
> +
> + switch (kern_level) {
> + case '0' ... '7':
> + if (level && *level == LOGLEVEL_DEFAULT)
> + *level = kern_level - '0';
> + break;
> + case 'c': /* KERN_CONT */
> + if (lflags)
> + *lflags |= LOG_CONT;
> + }
> +
> + *text_len -= 2;
> + text += 2;
> + }
> +
> + return text;
> +}
> +
> +static u16 printk_sprint(char *text, u16 size, int facility, enum log_flags
> *lflags,
> + const char *fmt, va_list args)
> +{
> + char *orig_text = text;
> + u16 text_len;
> +
> + text_len = vscnprintf(text, size, fmt, args);
> +
> + /* Mark and strip a trailing newline. */
> + if (text_len && text[text_len - 1] == '\n') {
> + text_len--;
> + *lflags |= LOG_NEWLINE;
> + }
> +
> + /* Strip log level and control flags. */
> + if (facility == 0) {
> + text = parse_prefix(text, _len, NULL, NULL);
> + if (text != orig_text)
> + memmove(orig_text, text, text_len);
> + }
> +
> + return text_len;
> +}
> +
> +__printf(4, 0)
> int vprintk_store(int facility, int level,
> const struct dev_printk_info *dev_info,
> const char *fmt, va_list args)
> {
> const u32 caller_id = printk_caller_id();
> - static char textbuf[LOG_LINE_MAX];
> struct prb_reserved_entry e;
> enum log_flags lflags = 0;
> struct printk_record r;
> u16 trunc_msg_len = 0;
> - char *text = textbuf;
> + char prefix_buf[8];
> + va_list args2;
> u16 text_len;
> + int ret = 0;
> u64 ts_nsec;
>
> /*
> @@ -1884,35 +1951,21 @@ int vprintk_store(int facility, int level,
>*/
> ts_nsec = local_clock();
>
> + va_copy(args2, args);
> +
> /*
>* The printf needs to come first; we need the syslog
>* prefix which might be passed-in as a parameter.
>*/
> - text_len = vscnprintf(text, sizeof(textbuf), fmt, args);
> + text_len = vsnprintf(_buf[0], sizeof(prefix_buf), fmt, args) + 1;
The "+ 1" confused me a lot.
I guess that you added "+ 1" because we need to reserve the space also
for the trailing "\0". Otherwise,
Re: [PATCH next v3 3/3] printk: remove logbuf_lock protection for ringbuffer
On 2020-12-07, John Ogness wrote:
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index e1f068677a74..f3c0fcc3163f 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
[...]
> int vprintk_store(int facility, int level,
> const struct dev_printk_info *dev_info,
> const char *fmt, va_list args)
> {
> const u32 caller_id = printk_caller_id();
> - static char textbuf[LOG_LINE_MAX];
> struct prb_reserved_entry e;
> enum log_flags lflags = 0;
> struct printk_record r;
> u16 trunc_msg_len = 0;
> - char *text = textbuf;
> + char prefix_buf[8];
> + va_list args2;
> u16 text_len;
> + int ret = 0;
> u64 ts_nsec;
>
> /*
> @@ -1884,35 +1951,21 @@ int vprintk_store(int facility, int level,
>*/
> ts_nsec = local_clock();
>
> + va_copy(args2, args);
> +
> /*
>* The printf needs to come first; we need the syslog
>* prefix which might be passed-in as a parameter.
>*/
> - text_len = vscnprintf(text, sizeof(textbuf), fmt, args);
> + text_len = vsnprintf(_buf[0], sizeof(prefix_buf), fmt, args) + 1;
> + if (text_len > CONSOLE_LOG_MAX)
> + text_len = CONSOLE_LOG_MAX;
LOG_LINE_MAX should be the limit. That was the size of the static
@textbuf.
John Ogness
[PATCH next v3 3/3] printk: remove logbuf_lock protection for ringbuffer
Since the ringbuffer is lockless, there is no need for it to be
protected by @logbuf_lock. Remove @logbuf_lock protection of the
ringbuffer.
This means that printk_nmi_direct and printk_safe_flush_on_panic()
no longer need to acquire any lock to run.
Without @logbuf_lock it is no longer possible to use the single
static buffer for temporarily sprint'ing the message. Instead,
use vsnprintf() to determine the length and perform the real
vscnprintf() using the area reserved from the ringbuffer. This
leads to suboptimal packing of the message data, but will
result in less wasted storage than multiple per-cpu buffers to
support lockless temporary sprint'ing.
Signed-off-by: John Ogness
---
kernel/printk/printk.c | 131 +---
kernel/printk/printk_safe.c | 18 +
2 files changed, 95 insertions(+), 54 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index e1f068677a74..f3c0fcc3163f 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1068,7 +1068,6 @@ void __init setup_log_buf(int early)
struct printk_record r;
size_t new_descs_size;
size_t new_infos_size;
- unsigned long flags;
char *new_log_buf;
unsigned int free;
u64 seq;
@@ -1126,8 +1125,6 @@ void __init setup_log_buf(int early)
new_descs, ilog2(new_descs_count),
new_infos);
- logbuf_lock_irqsave(flags);
-
log_buf_len = new_log_buf_len;
log_buf = new_log_buf;
new_log_buf_len = 0;
@@ -1143,8 +1140,6 @@ void __init setup_log_buf(int early)
*/
prb = _rb_dynamic;
- logbuf_unlock_irqrestore(flags);
-
if (seq != prb_next_seq(_rb_static)) {
pr_err("dropped %llu messages\n",
prb_next_seq(_rb_static) - seq);
@@ -1861,19 +1856,91 @@ static inline u32 printk_caller_id(void)
0x8000 + raw_smp_processor_id();
}
-/* Must be called under logbuf_lock. */
+/**
+ * parse_prefix - Parse level and control flags.
+ *
+ * @text: The text message.
+ * @text_len: A pointer to a value of strlen(@text), will be updated.
+ * @level:A pointer to the current level value, will be updated.
+ * @lflags: A pointer to the current log flags, will be updated.
+ *
+ * The variable pointed to by @text_len is updated to the message length
+ * when subtracting the parsed level and control flag length.
+ *
+ * @level may be NULL if the caller is not interested in the parsed value.
+ * Otherwise the variable pointed to by @level must be set to
+ * LOGLEVEL_DEFAULT in order to be updated with the parsed value.
+ *
+ * @lflags may be NULL if the caller is not interested in the parsed value.
+ * Otherwise the variable pointed to by @lflags will be OR'd with the parsed
+ * value.
+ *
+ * Return: The text message with the parsed level and control flags skipped.
+ */
+static char *parse_prefix(char *text, u16 *text_len, int *level, enum
log_flags *lflags)
+{
+ int kern_level;
+
+ while (*text_len >= 2) {
+ kern_level = printk_get_level(text);
+ if (!kern_level)
+ break;
+
+ switch (kern_level) {
+ case '0' ... '7':
+ if (level && *level == LOGLEVEL_DEFAULT)
+ *level = kern_level - '0';
+ break;
+ case 'c': /* KERN_CONT */
+ if (lflags)
+ *lflags |= LOG_CONT;
+ }
+
+ *text_len -= 2;
+ text += 2;
+ }
+
+ return text;
+}
+
+static u16 printk_sprint(char *text, u16 size, int facility, enum log_flags
*lflags,
+const char *fmt, va_list args)
+{
+ char *orig_text = text;
+ u16 text_len;
+
+ text_len = vscnprintf(text, size, fmt, args);
+
+ /* Mark and strip a trailing newline. */
+ if (text_len && text[text_len - 1] == '\n') {
+ text_len--;
+ *lflags |= LOG_NEWLINE;
+ }
+
+ /* Strip log level and control flags. */
+ if (facility == 0) {
+ text = parse_prefix(text, _len, NULL, NULL);
+ if (text != orig_text)
+ memmove(orig_text, text, text_len);
+ }
+
+ return text_len;
+}
+
+__printf(4, 0)
int vprintk_store(int facility, int level,
const struct dev_printk_info *dev_info,
const char *fmt, va_list args)
{
const u32 caller_id = printk_caller_id();
- static char textbuf[LOG_LINE_MAX];
struct prb_reserved_entry e;
enum log_flags lflags = 0;
struct printk_record r;
u16 trunc_msg_len = 0;
- char *text = textbuf;
+ char prefix_buf[8];
+ va_list args2;
u16 text_len;
+ int ret = 0;
u64 ts_nsec;
/*
@@ -1884,35 +1951,21 @@ int vprintk_store(int
