[Crash-utility] [PATCH] printk: add support for lockless ringbuffer
lijiang
lijiang at redhat.com
Sat Nov 28 05:16:59 UTC 2020
在 2020年11月20日 13:56, HAGIO KAZUHITO(萩尾 一仁) 写道:
> From: John Ogness <john.ogness at linutronix.de>
>
> 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.
>
> Signed-off-by: John Ogness <john.ogness at linutronix.de>
> Signed-off-by: Kazuhito Hagio <k-hagio-ab at nec.com>
> ---
> I've updated John's RFC crash patch to match 5.10-rc4 kernel.
> Changes from the RFC patch:
> - followed the following kernel commits
> cfe2790b163a ("printk: move printk_info into separate array")
> 74caba7f2a06 ("printk: move dictionary keys to dev_printk_info")
> f35efc78add6 ("printk: remove dict ring")
> - moved the added members in offset_table and size_table to the end
> of them
> - print offsets and sizes with "help -o" option
> - support "log -T" option
>
Thanks for the patch, Kazu and John.
This patch looks good. Acked-by: Lianbo Jiang <lijiang at redhat.com>
> Makefile | 5 ++
> defs.h | 30 ++++++++
> kernel.c | 7 +-
> printk.c | 255 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
> symbols.c | 27 +++++++
> 5 files changed, 323 insertions(+), 1 deletion(-)
> create mode 100644 printk.c
>
> diff --git a/Makefile b/Makefile
> index d1857190c2fb..f66eba7418d1 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 95949507cae4..e1a18e9d0b4d 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 {
> @@ -6697,6 +6722,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 98716372c8be..e722ff941527 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 000000000000..7be721853cf9
> --- /dev/null
> +++ b/printk.c
> @@ -0,0 +1,255 @@
> +#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: %u\n", seq, caller_id);
> +
> + 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 b2f4eb5402d1..a51078d58e6b 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");
>
>
More information about the Crash-utility
mailing list