[Crash-utility] [PATCH] log: output logs of printk safe buffers

[lijiang]

Hi, shogo
Thank you for the patch.

On Thu, Dec 16, 2021 at 4:01 PM <crash-utility-request at redhat.com> wrote:
> Date: Thu, 16 Dec 2021 07:39:42 +0000
> From: "shogo.matsumoto at fujitsu.com" <shogo.matsumoto at fujitsu.com>
> To: "'crash-utility at redhat.com'" <crash-utility at redhat.com>
> Subject: [Crash-utility] [PATCH] log: output logs of printk safe
>         buffers
> Message-ID:
>         <TYAPR01MB62191B03B637D36487695277E2779 at TYAPR01MB6219.jpnprd01.prod.outlook.com>
>
> Content-Type: text/plain; charset="iso-2022-jp"
>
> We sometimes overlook logs written to printk safe buffers
> (safe_print_seq/nmi_print_seq) which have not been flushed yet.
>
> This patch will output unflushed logs of the safe buffers
> at the bottom of log command output as follows:
>
> [nmi_print_seq] CPU: 0  BUFFER: ffff888063c18ac0  LEN: 28
> nmi print seq test message
> [safe_print_seq] CPU: 1  BUFFER: ffff888063d19ae0  LEN: 30
> safe print seq test message
>
> Note that the safe buffer (struct printk_safe_seq_buf) was introduced
> in kernel-4.11 and removed in kernel-5.15.
>

Although the safe buffer has been deprecated from the latest kernel
with the printk ringbuffer feature, it seems to be still helpful for
the old kernel.

> Signed-off-by: Shogo Matsumoto <shogo.matsumoto at fujitsu.com>
> ---
>  defs.h   |  3 +++
>  kernel.c | 58 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++
>  2 files changed, 61 insertions(+)
>
> diff --git a/defs.h b/defs.h
> index 7e2a16e..3ee51e0 100644
> --- a/defs.h
> +++ b/defs.h
> @@ -2146,6 +2146,8 @@ struct offset_table {                    /* stash of commonly-used offsets */
>         long wait_queue_entry_private;
>         long wait_queue_head_head;
>         long wait_queue_entry_entry;
> +       long printk_safe_seq_buf_len;
> +       long printk_safe_seq_buf_buffer;
>  };
>
>  struct size_table {         /* stash of commonly-used sizes */
> @@ -2310,6 +2312,7 @@ struct size_table {         /* stash of commonly-used sizes */
>         long prb_desc;
>         long wait_queue_entry;
>         long task_struct_state;
> +       long printk_safe_seq_buf_buffer;
>  };
>

Can you help to add all new variables mentioned above to the dump table?

>  struct array_table {
> diff --git a/kernel.c b/kernel.c
> index f4598ea..cc97176 100644
> --- a/kernel.c
> +++ b/kernel.c
> @@ -93,6 +93,7 @@ static void source_tree_init(void);
>  static ulong dump_audit_skb_queue(ulong);
>  static ulong __dump_audit(char *);
>  static void dump_audit(void);
> +static void dump_printk_safe_seq_buf(void);
>  static char *vmcoreinfo_read_string(const char *);
>  static void check_vmcoreinfo(void);
>  static int is_pvops_xen(void);
> @@ -5048,6 +5049,7 @@ cmd_log(void)
>         }
>
>         dump_log(msg_flags);
> +       dump_printk_safe_seq_buf();
>  }
>

This does not support dumping with the crash --log  command, right?

Thanks.
Lianbo

>
> @@ -11534,6 +11536,62 @@ dump_audit(void)
>                 error(INFO, "kernel audit log is empty\n");
>  }
>
> +static void
> +__dump_printk_safe_seq_buf(char *buf_name)
> +{
> +       int cpu, buffer_size;
> +       char *buffer;
> +
> +       if (!symbol_exists(buf_name)) {
> +               return;
> +       }
> +
> +       buffer_size = SIZE(printk_safe_seq_buf_buffer);
> +       buffer = GETBUF(buffer_size);
> +       for (cpu = 0; cpu < kt->cpus; cpu++) {
> +               ulong len_addr, buffer_addr;
> +               int len;
> +
> +               len_addr = symbol_value(buf_name) + kt->__per_cpu_offset[cpu] + OFFSET(printk_safe_seq_buf_len);
> +               buffer_addr = symbol_value(buf_name) + kt->__per_cpu_offset[cpu] + OFFSET(printk_safe_seq_buf_buffer);
> +               readmem(len_addr, KVADDR, &len, STRUCT_SIZE("atomic_t"), "printk_safe_seq_buf len", FAULT_ON_ERROR);
> +               readmem(buffer_addr, KVADDR, buffer, buffer_size, "printk_safe_seq_buf buffer", FAULT_ON_ERROR);
> +
> +               if (len > 0) {
> +                       int i, n;
> +                       char *p;
> +                       fprintf(fp, "[%s] CPU: %d  BUFFER: %lx  LEN: %d\n", buf_name, cpu, buffer_addr, len);
> +                       n = (len <= buffer_size) ? len : buffer_size;
> +                       for (i = 0, p = buffer; i < n; i++, p++) {
> +                               if (*p == 0x1) { //SOH
> +                                       i++; p++;
> +                                       continue;
> +                               } else {
> +                                       fputc(ascii(*p) ? *p : '.', fp);
> +                               }
> +                       }
> +                       fputc('\n', fp);
> +               }
> +       }
> +       FREEBUF(buffer);
> +}
> +
> +static void
> +dump_printk_safe_seq_buf(void)
> +{
> +       if (!STRUCT_EXISTS("printk_safe_seq_buf"))
> +               return;
> +
> +       if (INVALID_SIZE(printk_safe_seq_buf_buffer)) {
> +               MEMBER_OFFSET_INIT(printk_safe_seq_buf_len, "printk_safe_seq_buf", "len");
> +               MEMBER_OFFSET_INIT(printk_safe_seq_buf_buffer, "printk_safe_seq_buf", "buffer");
> +               MEMBER_SIZE_INIT(printk_safe_seq_buf_buffer, "printk_safe_seq_buf", "buffer");
> +       }
> +
> +       __dump_printk_safe_seq_buf("nmi_print_seq");
> +       __dump_printk_safe_seq_buf("safe_print_seq");
> +}
> +
>  /*
>   * Reads a string value from the VMCOREINFO data stored in (live) memory.
>   *
> --
> 2.29.2