-----Original Message-----
> 在 2020年11月20日 13:56, HAGIO KAZUHITO(萩尾 一仁) 写道:
> > From: John Ogness <john.ogness@xxxxxxxxxxxxx>
> >
> > 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@xxxxxxxxxxxxx>
> > Signed-off-by: Kazuhito Hagio <k-hagio-ab@xxxxxxx>
> > ---
> > 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@xxxxxxxxxx>
OK, thanks.
One thing, I found that caller_id can be raw_smp_processor_id() (see
printk_caller_id()), so will modify a bit as follows when merging.
--- a/printk.c
+++ b/printk.c
@@ -132,7 +132,8 @@ dump_record(struct prb_map *m, unsigned long id, int msg_flags)
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);
+ 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));
Thanks,
Kazu
>
>
> > 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");
> >
> >
--
Crash-utility mailing list
Crash-utility@xxxxxxxxxx
https://www.redhat.com/mailman/listinfo/crash-utility
