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

Date: Thu, 16 Dec 2021 07:39:42 +0000 From: &quot;shogo.matsumoto(a)fujitsu.com&quot; <shogo.matsumoto(a)fujitsu.com&gt; To: &quot;&#39;crash-utility(a)redhat.com&#39;&quot; <crash-utility(a)redhat.com&gt; Subject: [Crash-utility] [PATCH] log: output logs of printk safe buffers Message-ID: <TYAPR01MB62191B03B637D36487695277E2779(a)TYAPR01MB6219.jpnprd01.prod.outlook.com&gt; 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.

Signed-off-by: Shogo Matsumoto <shogo.matsumoto(a)fujitsu.com&gt; --- 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; };

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(); }

@@ -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