[PATCH] scripts/gdb: lx-dmesg: read records individually

[PATCH] scripts/gdb: lx-dmesg: read records individually

[John Ogness]

For the gdb command lx-dmesg, the entire descriptor, info, and text
data regions are read into memory before printing any records. For
large kernel log buffers, this not only causes a huge delay before
seeing any records, but it may also lead to python errors of too
much memory allocation.

Rather than reading in all these regions in advance, read them as
needed and only read the regions for the particular record that is
being printed.

The gdb macro "dmesg" in Documentation/admin-guide/kdump/gdbmacros.txt
already prints out the kernel log buffer like this.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 scripts/gdb/linux/dmesg.py | 35 ++++++++++++++++++-----------------
 1 file changed, 18 insertions(+), 17 deletions(-)

diff --git a/scripts/gdb/linux/dmesg.py b/scripts/gdb/linux/dmesg.py
index a92c55bd8de5..d5983cf3db7d 100644
--- a/scripts/gdb/linux/dmesg.py
+++ b/scripts/gdb/linux/dmesg.py
@@ -44,19 +44,17 @@ class LxDmesg(gdb.Command):
         sz = prb_desc_ring_type.get_type().sizeof
         desc_ring = utils.read_memoryview(inf, addr, sz).tobytes()
 
-        # read in descriptor array
+        # read in descriptor count, size, and address
         off = prb_desc_ring_type.get_type()['count_bits'].bitpos // 8
         desc_ring_count = 1 << utils.read_u32(desc_ring, off)
         desc_sz = prb_desc_type.get_type().sizeof
         off = prb_desc_ring_type.get_type()['descs'].bitpos // 8
-        addr = utils.read_ulong(desc_ring, off)
-        descs = utils.read_memoryview(inf, addr, desc_sz * desc_ring_count).tobytes()
+        desc_addr = utils.read_ulong(desc_ring, off)
 
-        # read in info array
+        # read in info size and address
         info_sz = printk_info_type.get_type().sizeof
         off = prb_desc_ring_type.get_type()['infos'].bitpos // 8
-        addr = utils.read_ulong(desc_ring, off)
-        infos = utils.read_memoryview(inf, addr, info_sz * desc_ring_count).tobytes()
+        info_addr = utils.read_ulong(desc_ring, off)
 
         # read in text data ring structure
         off = printk_ringbuffer_type.get_type()['text_data_ring'].bitpos // 8
@@ -64,12 +62,11 @@ class LxDmesg(gdb.Command):
         sz = prb_data_ring_type.get_type().sizeof
         text_data_ring = utils.read_memoryview(inf, addr, sz).tobytes()
 
-        # read in text data
+        # read in text data size and address
         off = prb_data_ring_type.get_type()['size_bits'].bitpos // 8
         text_data_sz = 1 << utils.read_u32(text_data_ring, off)
         off = prb_data_ring_type.get_type()['data'].bitpos // 8
-        addr = utils.read_ulong(text_data_ring, off)
-        text_data = utils.read_memoryview(inf, addr, text_data_sz).tobytes()
+        text_data_addr = utils.read_ulong(text_data_ring, off)
 
         counter_off = atomic_long_type.get_type()['counter'].bitpos // 8
 
@@ -102,17 +99,20 @@ class LxDmesg(gdb.Command):
             desc_off = desc_sz * ind
             info_off = info_sz * ind
 
+            desc = utils.read_memoryview(inf, desc_addr + desc_off, desc_sz).tobytes()
+
             # skip non-committed record
-            state = 3 & (utils.read_u64(descs, desc_off + sv_off +
-                                        counter_off) >> desc_flags_shift)
+            state = 3 & (utils.read_u64(desc, sv_off + counter_off) >> desc_flags_shift)
             if state != desc_committed and state != desc_finalized:
                 if did == head_id:
                     break
                 did = (did + 1) & desc_id_mask
                 continue
 
-            begin = utils.read_ulong(descs, desc_off + begin_off) % text_data_sz
-            end = utils.read_ulong(descs, desc_off + next_off) % text_data_sz
+            begin = utils.read_ulong(desc, begin_off) % text_data_sz
+            end = utils.read_ulong(desc, next_off) % text_data_sz
+
+            info = utils.read_memoryview(inf, info_addr + info_off, info_sz).tobytes()
 
             # handle data-less record
             if begin & 1 == 1:
@@ -125,16 +125,17 @@ class LxDmesg(gdb.Command):
                 # skip over descriptor id
                 text_start = begin + utils.get_long_type().sizeof
 
-                text_len = utils.read_u16(infos, info_off + len_off)
+                text_len = utils.read_u16(info, len_off)
 
                 # handle truncated message
                 if end - text_start < text_len:
                     text_len = end - text_start
 
-                text = text_data[text_start:text_start + text_len].decode(
-                    encoding='utf8', errors='replace')
+                text_data = utils.read_memoryview(inf, text_data_addr + text_start,
+                                                  text_len).tobytes()
+                text = text_data[0:text_len].decode(encoding='utf8', errors='replace')
 
-            time_stamp = utils.read_u64(infos, info_off + ts_off)
+            time_stamp = utils.read_u64(info, ts_off)
 
             for line in text.splitlines():
                 msg = u"[{time:12.6f}] {line}\n".format(

base-commit: 0bafb8f3ebc84525d0ae0fcea22d12151b99312f
-- 
2.30.2

Re: [PATCH] scripts/gdb: lx-dmesg: read records individually

[Petr Mladek]

On Wed 2021-12-15 16:16:22, John Ogness wrote:
> For the gdb command lx-dmesg, the entire descriptor, info, and text
> data regions are read into memory before printing any records. For
> large kernel log buffers, this not only causes a huge delay before
> seeing any records, but it may also lead to python errors of too
> much memory allocation.
> 
> Rather than reading in all these regions in advance, read them as
> needed and only read the regions for the particular record that is
> being printed.
> 
> The gdb macro "dmesg" in Documentation/admin-guide/kdump/gdbmacros.txt
> already prints out the kernel log buffer like this.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

Looks good to me.

The patch has been committed into printk/linux.git, branch for-5.17.

Best Regards,
Petr