| From a5531b24750e7949c35640d996ea14c0587938bc Mon Sep 17 00:00:00 2001 |
| From: John Ogness <john.ogness@linutronix.de> |
| Date: Fri, 20 Nov 2020 05:56:59 +0000 |
| Subject: [PATCH 1/2] printk: add support for lockless ringbuffer |
| |
| Linux 5.10 introduces a new lockless ringbuffer. The new ringbuffer |
| is structured completely different to the previous iterations. |
| Add support for dumping the ringbuffer with the "log" command. |
| The new ringbuffer is detected based on the availability of |
| the "prb" symbol. |
| |
| Upstream-Status: Backport [https://github.com/crash-utility/crash/commit/a5531b24750e7949c35640d996ea14c0587938bc] |
| |
| Signed-off-by: John Ogness <john.ogness@linutronix.de> |
| Signed-off-by: Kazuhito Hagio <k-hagio-ab@nec.com> |
| Signed-off-by: Mingli Yu <mingli.yu@windriver.com> |
| --- |
| Makefile | 5 ++ |
| defs.h | 30 +++++++ |
| kernel.c | 7 +- |
| printk.c | 256 ++++++++++++++++++++++++++++++++++++++++++++++++++++++ |
| symbols.c | 27 ++++++ |
| 5 files changed, 324 insertions(+), 1 deletion(-) |
| create mode 100644 printk.c |
| |
| diff --git a/Makefile b/Makefile |
| index d185719..f66eba7 100644 |
| --- a/Makefile |
| +++ b/Makefile |
| @@ -61,6 +61,7 @@ VMWARE_HFILES=vmware_vmss.h |
| |
| CFILES=main.c tools.c global_data.c memory.c filesys.c help.c task.c \ |
| kernel.c test.c gdb_interface.c configure.c net.c dev.c bpf.c \ |
| + printk.c \ |
| alpha.c x86.c ppc.c ia64.c s390.c s390x.c s390dbf.c ppc64.c x86_64.c \ |
| arm.c arm64.c mips.c sparc64.c \ |
| extensions.c remote.c va_server.c va_server_v1.c symbols.c cmdline.c \ |
| @@ -80,6 +81,7 @@ SOURCE_FILES=${CFILES} ${GENERIC_HFILES} ${MCORE_HFILES} \ |
| |
| OBJECT_FILES=main.o tools.o global_data.o memory.o filesys.o help.o task.o \ |
| build_data.o kernel.o test.o gdb_interface.o net.o dev.o bpf.o \ |
| + printk.o \ |
| alpha.o x86.o ppc.o ia64.o s390.o s390x.o s390dbf.o ppc64.o x86_64.o \ |
| arm.o arm64.o mips.o sparc64.o \ |
| extensions.o remote.o va_server.o va_server_v1.o symbols.o cmdline.o \ |
| @@ -363,6 +365,9 @@ task.o: ${GENERIC_HFILES} task.c |
| kernel.o: ${GENERIC_HFILES} kernel.c |
| ${CC} -c ${CRASH_CFLAGS} kernel.c ${WARNING_OPTIONS} ${WARNING_ERROR} |
| |
| +printk.o: ${GENERIC_HFILES} printk.c |
| + ${CC} -c ${CRASH_CFLAGS} printk.c ${WARNING_OPTIONS} ${WARNING_ERROR} |
| + |
| gdb_interface.o: ${GENERIC_HFILES} gdb_interface.c |
| ${CC} -c ${CRASH_CFLAGS} gdb_interface.c ${WARNING_OPTIONS} ${WARNING_ERROR} |
| |
| diff --git a/defs.h b/defs.h |
| index 9594950..e1a18e9 100644 |
| --- a/defs.h |
| +++ b/defs.h |
| @@ -2106,6 +2106,28 @@ struct offset_table { /* stash of commonly-used offsets */ |
| long irq_common_data_affinity; |
| long irq_desc_irq_common_data; |
| long uts_namespace_name; |
| + long printk_info_seq; |
| + long printk_info_ts_nsec; |
| + long printk_info_text_len; |
| + long printk_info_level; |
| + long printk_info_caller_id; |
| + long printk_info_dev_info; |
| + long dev_printk_info_subsystem; |
| + long dev_printk_info_device; |
| + long prb_desc_ring; |
| + long prb_text_data_ring; |
| + long prb_desc_ring_count_bits; |
| + long prb_desc_ring_descs; |
| + long prb_desc_ring_infos; |
| + long prb_desc_ring_head_id; |
| + long prb_desc_ring_tail_id; |
| + long prb_desc_state_var; |
| + long prb_desc_text_blk_lpos; |
| + long prb_data_blk_lpos_begin; |
| + long prb_data_blk_lpos_next; |
| + long prb_data_ring_size_bits; |
| + long prb_data_ring_data; |
| + long atomic_long_t_counter; |
| }; |
| |
| struct size_table { /* stash of commonly-used sizes */ |
| @@ -2265,6 +2287,9 @@ struct size_table { /* stash of commonly-used sizes */ |
| long xa_node; |
| long zram_table_entry; |
| long irq_common_data; |
| + long printk_info; |
| + long printk_ringbuffer; |
| + long prb_desc; |
| }; |
| |
| struct array_table { |
| @@ -6696,6 +6721,11 @@ int vmware_guestdump_memory_dump(FILE *); |
| */ |
| int calc_kaslr_offset(ulong *, ulong *); |
| |
| +/* |
| + * printk.c |
| + */ |
| +void dump_lockless_record_log(int); |
| + |
| /* |
| * gnu_binutils.c |
| */ |
| diff --git a/kernel.c b/kernel.c |
| index 9871637..e722ff9 100644 |
| --- a/kernel.c |
| +++ b/kernel.c |
| @@ -5042,6 +5042,11 @@ dump_log(int msg_flags) |
| struct syment *nsp; |
| int log_wrap, loglevel, log_buf_len; |
| |
| + if (kernel_symbol_exists("prb")) { |
| + dump_lockless_record_log(msg_flags); |
| + return; |
| + } |
| + |
| if (kernel_symbol_exists("log_first_idx") && |
| kernel_symbol_exists("log_next_idx")) { |
| dump_variable_length_record_log(msg_flags); |
| @@ -5289,7 +5294,7 @@ dump_log_entry(char *logptr, int msg_flags) |
| } |
| |
| /* |
| - * Handle the new variable-length-record log_buf. |
| + * Handle the variable-length-record log_buf. |
| */ |
| static void |
| dump_variable_length_record_log(int msg_flags) |
| diff --git a/printk.c b/printk.c |
| new file mode 100644 |
| index 0000000..f6d54ce |
| --- /dev/null |
| +++ b/printk.c |
| @@ -0,0 +1,256 @@ |
| +#include "defs.h" |
| +#include <ctype.h> |
| + |
| +#define DESC_SV_BITS (sizeof(unsigned long) * 8) |
| +#define DESC_COMMITTED_MASK (1UL << (DESC_SV_BITS - 1)) |
| +#define DESC_REUSE_MASK (1UL << (DESC_SV_BITS - 2)) |
| +#define DESC_FLAGS_MASK (DESC_COMMITTED_MASK | DESC_REUSE_MASK) |
| +#define DESC_ID_MASK (~DESC_FLAGS_MASK) |
| + |
| +/* convenience struct for passing many values to helper functions */ |
| +struct prb_map { |
| + char *prb; |
| + |
| + char *desc_ring; |
| + unsigned long desc_ring_count; |
| + char *descs; |
| + char *infos; |
| + |
| + char *text_data_ring; |
| + unsigned long text_data_ring_size; |
| + char *text_data; |
| +}; |
| + |
| +static void |
| +init_offsets(void) |
| +{ |
| + char *n; |
| + |
| + n = "printk_info"; |
| + STRUCT_SIZE_INIT(printk_info, n); |
| + MEMBER_OFFSET_INIT(printk_info_seq, n, "seq"); |
| + MEMBER_OFFSET_INIT(printk_info_ts_nsec, n, "ts_nsec"); |
| + MEMBER_OFFSET_INIT(printk_info_text_len, n, "text_len"); |
| + MEMBER_OFFSET_INIT(printk_info_level, n, "level"); |
| + MEMBER_OFFSET_INIT(printk_info_caller_id, n, "caller_id"); |
| + MEMBER_OFFSET_INIT(printk_info_dev_info, n, "dev_info"); |
| + |
| + n = "dev_printk_info"; |
| + MEMBER_OFFSET_INIT(dev_printk_info_subsystem, n, "subsystem"); |
| + MEMBER_OFFSET_INIT(dev_printk_info_device, n, "device"); |
| + |
| + n = "printk_ringbuffer"; |
| + STRUCT_SIZE_INIT(printk_ringbuffer, n); |
| + MEMBER_OFFSET_INIT(prb_desc_ring, n, "desc_ring"); |
| + MEMBER_OFFSET_INIT(prb_text_data_ring, n, "text_data_ring"); |
| + |
| + n = "prb_desc_ring"; |
| + MEMBER_OFFSET_INIT(prb_desc_ring_count_bits, n, "count_bits"); |
| + MEMBER_OFFSET_INIT(prb_desc_ring_descs, n, "descs"); |
| + MEMBER_OFFSET_INIT(prb_desc_ring_infos, n, "infos"); |
| + MEMBER_OFFSET_INIT(prb_desc_ring_head_id, n, "head_id"); |
| + MEMBER_OFFSET_INIT(prb_desc_ring_tail_id, n, "tail_id"); |
| + |
| + n = "prb_desc"; |
| + STRUCT_SIZE_INIT(prb_desc, n); |
| + MEMBER_OFFSET_INIT(prb_desc_state_var, n, "state_var"); |
| + MEMBER_OFFSET_INIT(prb_desc_text_blk_lpos, n, "text_blk_lpos"); |
| + |
| + n = "prb_data_blk_lpos"; |
| + MEMBER_OFFSET_INIT(prb_data_blk_lpos_begin, n, "begin"); |
| + MEMBER_OFFSET_INIT(prb_data_blk_lpos_next, n, "next"); |
| + |
| + n = "prb_data_ring"; |
| + MEMBER_OFFSET_INIT(prb_data_ring_size_bits, n, "size_bits"); |
| + MEMBER_OFFSET_INIT(prb_data_ring_data, n, "data"); |
| + |
| + n = "atomic_long_t"; |
| + MEMBER_OFFSET_INIT(atomic_long_t_counter, n, "counter"); |
| +} |
| + |
| +static void |
| +dump_record(struct prb_map *m, unsigned long id, int msg_flags) |
| +{ |
| + unsigned short text_len; |
| + unsigned long state_var; |
| + unsigned int caller_id; |
| + unsigned char level; |
| + unsigned long begin; |
| + unsigned long next; |
| + char buf[BUFSIZE]; |
| + uint64_t ts_nsec; |
| + ulonglong nanos; |
| + ulonglong seq; |
| + int ilen = 0, i; |
| + char *desc, *info, *text, *p; |
| + ulong rem; |
| + |
| + desc = m->descs + ((id % m->desc_ring_count) * SIZE(prb_desc)); |
| + |
| + /* skip non-committed record */ |
| + state_var = ULONG(desc + OFFSET(prb_desc_state_var) + |
| + OFFSET(atomic_long_t_counter)); |
| + if ((state_var & DESC_FLAGS_MASK) != DESC_COMMITTED_MASK) |
| + return; |
| + |
| + info = m->infos + ((id % m->desc_ring_count) * SIZE(printk_info)); |
| + |
| + seq = ULONGLONG(info + OFFSET(printk_info_seq)); |
| + caller_id = UINT(info + OFFSET(printk_info_caller_id)); |
| + if (CRASHDEBUG(1)) |
| + fprintf(fp, "seq: %llu caller_id: %x (%s: %u)\n", seq, caller_id, |
| + caller_id & 0x80000000 ? "cpu" : "pid", caller_id & ~0x80000000); |
| + |
| + text_len = USHORT(info + OFFSET(printk_info_text_len)); |
| + |
| + begin = ULONG(desc + OFFSET(prb_desc_text_blk_lpos) + |
| + OFFSET(prb_data_blk_lpos_begin)) % |
| + m->text_data_ring_size; |
| + next = ULONG(desc + OFFSET(prb_desc_text_blk_lpos) + |
| + OFFSET(prb_data_blk_lpos_next)) % |
| + m->text_data_ring_size; |
| + |
| + /* skip data-less text blocks */ |
| + if (begin == next) |
| + goto out; |
| + |
| + if ((msg_flags & SHOW_LOG_TEXT) == 0) { |
| + ts_nsec = ULONGLONG(info + OFFSET(printk_info_ts_nsec)); |
| + nanos = (ulonglong)ts_nsec / (ulonglong)1000000000; |
| + rem = (ulonglong)ts_nsec % (ulonglong)1000000000; |
| + if (msg_flags & SHOW_LOG_CTIME) { |
| + time_t t = kt->boot_date.tv_sec + nanos; |
| + sprintf(buf, "[%s] ", ctime_tz(&t)); |
| + } else |
| + sprintf(buf, "[%5lld.%06ld] ", nanos, rem/1000); |
| + |
| + ilen += strlen(buf); |
| + fprintf(fp, "%s", buf); |
| + } |
| + |
| + if (msg_flags & SHOW_LOG_LEVEL) { |
| + level = UCHAR(info + OFFSET(printk_info_level)) >> 5; |
| + sprintf(buf, "<%x>", level); |
| + ilen += strlen(buf); |
| + fprintf(fp, "%s", buf); |
| + } |
| + |
| + /* handle wrapping data block */ |
| + if (begin > next) |
| + begin = 0; |
| + |
| + /* skip over descriptor ID */ |
| + begin += sizeof(unsigned long); |
| + |
| + /* handle truncated messages */ |
| + if (next - begin < text_len) |
| + text_len = next - begin; |
| + |
| + text = m->text_data + begin; |
| + |
| + for (i = 0, p = text; i < text_len; i++, p++) { |
| + if (*p == '\n') |
| + fprintf(fp, "\n%s", space(ilen)); |
| + else if (isprint(*p) || isspace(*p)) |
| + fputc(*p, fp); |
| + else |
| + fputc('.', fp); |
| + } |
| + |
| + if (msg_flags & SHOW_LOG_DICT) { |
| + text = info + OFFSET(printk_info_dev_info) + |
| + OFFSET(dev_printk_info_subsystem); |
| + if (strlen(text)) |
| + fprintf(fp, "\n%sSUBSYSTEM=%s", space(ilen), text); |
| + |
| + text = info + OFFSET(printk_info_dev_info) + |
| + OFFSET(dev_printk_info_device); |
| + if (strlen(text)) |
| + fprintf(fp, "\n%sDEVICE=%s", space(ilen), text); |
| + } |
| +out: |
| + fprintf(fp, "\n"); |
| +} |
| + |
| +/* |
| + * Handle the lockless printk_ringbuffer. |
| + */ |
| +void |
| +dump_lockless_record_log(int msg_flags) |
| +{ |
| + unsigned long head_id; |
| + unsigned long tail_id; |
| + unsigned long kaddr; |
| + unsigned long id; |
| + struct prb_map m; |
| + |
| + if (INVALID_SIZE(printk_info)) |
| + init_offsets(); |
| + |
| + /* setup printk_ringbuffer */ |
| + get_symbol_data("prb", sizeof(char *), &kaddr); |
| + m.prb = GETBUF(SIZE(printk_ringbuffer)); |
| + if (!readmem(kaddr, KVADDR, m.prb, SIZE(printk_ringbuffer), |
| + "printk_ringbuffer contents", RETURN_ON_ERROR|QUIET)) { |
| + error(WARNING, "\ncannot read printk_ringbuffer contents\n"); |
| + goto out_prb; |
| + } |
| + |
| + /* setup descriptor ring */ |
| + m.desc_ring = m.prb + OFFSET(prb_desc_ring); |
| + m.desc_ring_count = 1 << UINT(m.desc_ring + OFFSET(prb_desc_ring_count_bits)); |
| + |
| + kaddr = ULONG(m.desc_ring + OFFSET(prb_desc_ring_descs)); |
| + m.descs = GETBUF(SIZE(prb_desc) * m.desc_ring_count); |
| + if (!readmem(kaddr, KVADDR, m.descs, SIZE(prb_desc) * m.desc_ring_count, |
| + "prb_desc_ring contents", RETURN_ON_ERROR|QUIET)) { |
| + error(WARNING, "\ncannot read prb_desc_ring contents\n"); |
| + goto out_descs; |
| + } |
| + |
| + kaddr = ULONG(m.desc_ring + OFFSET(prb_desc_ring_infos)); |
| + m.infos = GETBUF(SIZE(printk_info) * m.desc_ring_count); |
| + if (!readmem(kaddr, KVADDR, m.infos, SIZE(printk_info) * m.desc_ring_count, |
| + "prb_info_ring contents", RETURN_ON_ERROR|QUIET)) { |
| + error(WARNING, "\ncannot read prb_info_ring contents\n"); |
| + goto out_infos; |
| + } |
| + |
| + /* setup text data ring */ |
| + m.text_data_ring = m.prb + OFFSET(prb_text_data_ring); |
| + m.text_data_ring_size = 1 << UINT(m.text_data_ring + OFFSET(prb_data_ring_size_bits)); |
| + |
| + kaddr = ULONG(m.text_data_ring + OFFSET(prb_data_ring_data)); |
| + m.text_data = GETBUF(m.text_data_ring_size); |
| + if (!readmem(kaddr, KVADDR, m.text_data, m.text_data_ring_size, |
| + "prb_text_data_ring contents", RETURN_ON_ERROR|QUIET)) { |
| + error(WARNING, "\ncannot read prb_text_data_ring contents\n"); |
| + goto out_text_data; |
| + } |
| + |
| + /* ready to go */ |
| + |
| + tail_id = ULONG(m.desc_ring + OFFSET(prb_desc_ring_tail_id) + |
| + OFFSET(atomic_long_t_counter)); |
| + head_id = ULONG(m.desc_ring + OFFSET(prb_desc_ring_head_id) + |
| + OFFSET(atomic_long_t_counter)); |
| + |
| + hq_open(); |
| + |
| + for (id = tail_id; id != head_id; id = (id + 1) & DESC_ID_MASK) |
| + dump_record(&m, id, msg_flags); |
| + |
| + /* dump head record */ |
| + dump_record(&m, id, msg_flags); |
| + |
| + hq_close(); |
| + |
| +out_text_data: |
| + FREEBUF(m.text_data); |
| +out_infos: |
| + FREEBUF(m.infos); |
| +out_descs: |
| + FREEBUF(m.descs); |
| +out_prb: |
| + FREEBUF(m.prb); |
| +} |
| diff --git a/symbols.c b/symbols.c |
| index b2f4eb5..a51078d 100644 |
| --- a/symbols.c |
| +++ b/symbols.c |
| @@ -10426,6 +10426,30 @@ dump_offset_table(char *spec, ulong makestruct) |
| OFFSET(log_level)); |
| fprintf(fp, " log_flags_level: %ld\n", |
| OFFSET(log_flags_level)); |
| + |
| + fprintf(fp, " printk_info_seq: %ld\n", OFFSET(printk_info_seq)); |
| + fprintf(fp, " printk_info_ts_nseq: %ld\n", OFFSET(printk_info_ts_nsec)); |
| + fprintf(fp, " printk_info_text_len: %ld\n", OFFSET(printk_info_text_len)); |
| + fprintf(fp, " printk_info_level: %ld\n", OFFSET(printk_info_level)); |
| + fprintf(fp, " printk_info_caller_id: %ld\n", OFFSET(printk_info_caller_id)); |
| + fprintf(fp, " printk_info_dev_info: %ld\n", OFFSET(printk_info_dev_info)); |
| + fprintf(fp, " dev_printk_info_subsystem: %ld\n", OFFSET(dev_printk_info_subsystem)); |
| + fprintf(fp, " dev_printk_info_device: %ld\n", OFFSET(dev_printk_info_device)); |
| + fprintf(fp, " prb_desc_ring: %ld\n", OFFSET(prb_desc_ring)); |
| + fprintf(fp, " prb_text_data_ring: %ld\n", OFFSET(prb_text_data_ring)); |
| + fprintf(fp, " prb_desc_ring_count_bits: %ld\n", OFFSET(prb_desc_ring_count_bits)); |
| + fprintf(fp, " prb_desc_ring_descs: %ld\n", OFFSET(prb_desc_ring_descs)); |
| + fprintf(fp, " prb_desc_ring_infos: %ld\n", OFFSET(prb_desc_ring_infos)); |
| + fprintf(fp, " prb_desc_ring_head_id: %ld\n", OFFSET(prb_desc_ring_head_id)); |
| + fprintf(fp, " prb_desc_ring_tail_id: %ld\n", OFFSET(prb_desc_ring_tail_id)); |
| + fprintf(fp, " prb_desc_state_var: %ld\n", OFFSET(prb_desc_state_var)); |
| + fprintf(fp, " prb_desc_text_blk_lpos: %ld\n", OFFSET(prb_desc_text_blk_lpos)); |
| + fprintf(fp, " prb_data_blk_lpos_begin: %ld\n", OFFSET(prb_data_blk_lpos_begin)); |
| + fprintf(fp, " prb_data_blk_lpos_next: %ld\n", OFFSET(prb_data_blk_lpos_next)); |
| + fprintf(fp, " prb_data_ring_size_bits: %ld\n", OFFSET(prb_data_ring_size_bits)); |
| + fprintf(fp, " prb_data_ring_data: %ld\n", OFFSET(prb_data_ring_data)); |
| + fprintf(fp, " atomit_long_t_counter: %ld\n", OFFSET(atomic_long_t_counter)); |
| + |
| fprintf(fp, " sched_rt_entity_my_q: %ld\n", |
| OFFSET(sched_rt_entity_my_q)); |
| fprintf(fp, " task_group_parent: %ld\n", |
| @@ -10850,6 +10874,9 @@ dump_offset_table(char *spec, ulong makestruct) |
| SIZE(xarray)); |
| fprintf(fp, " xa_node: %ld\n", |
| SIZE(xa_node)); |
| + fprintf(fp, " printk_info: %ld\n", SIZE(printk_info)); |
| + fprintf(fp, " printk_ringbuffer: %ld\n", SIZE(printk_ringbuffer)); |
| + fprintf(fp, " prb_desc: %ld\n", SIZE(prb_desc)); |
| |
| |
| fprintf(fp, "\n array_table:\n"); |
| -- |
| 2.17.1 |
| |