]> git.proxmox.com Git - mirror_ubuntu-jammy-kernel.git/commitdiff
scripts/gdb: update for lockless printk ringbuffer
authorJohn Ogness <john.ogness@linutronix.de>
Fri, 14 Aug 2020 21:25:25 +0000 (23:31 +0206)
committerPetr Mladek <pmladek@suse.com>
Tue, 8 Sep 2020 07:33:15 +0000 (09:33 +0200)
With the introduction of the lockless printk ringbuffer, the data
structure for the kernel log buffer was changed. Update the gdb
scripts to be able to parse/print the new log buffer structure.

Fixes: 896fbe20b4e2333fb55 ("printk: use the lockless ringbuffer")
Signed-off-by: John Ogness <john.ogness@linutronix.de>
Reported-by: Nick Desaulniers <ndesaulniers@google.com>
Tested-by: Nick Desaulniers <ndesaulniers@google.com>
Tested-by: Petr Mladek <pmladek@suse.com>
[akpm@linux-foundation.org: A typo fix.]
Signed-off-by: Petr Mladek <pmladek@suse.com>
Link: https://lore.kernel.org/r/20200814212525.6118-3-john.ogness@linutronix.de
Documentation/admin-guide/kdump/gdbmacros.txt
scripts/gdb/linux/dmesg.py

index 220d0a80ca2c9f45ce7f0705be1952c34df4f1dd..7adece30237efe00217e5d8af33e4d20bbe6214b 100644 (file)
@@ -170,57 +170,111 @@ document trapinfo
        address the kernel panicked.
 end
 
-define dump_log_idx
-       set $idx = $arg0
+define dump_record
+       set var $desc = $arg0
        if ($argc > 1)
-               set $prev_flags = $arg1
+               set var $prev_flags = $arg1
        else
-               set $prev_flags = 0
+               set var $prev_flags = 0
        end
-       set $msg = ((struct printk_log *) (log_buf + $idx))
-       set $prefix = 1
-       set $newline = 1
-       set $log = log_buf + $idx + sizeof(*$msg)
-
-       # prev & LOG_CONT && !(msg->flags & LOG_PREIX)
-       if (($prev_flags & 8) && !($msg->flags & 4))
-               set $prefix = 0
+
+       set var $info = &$desc->info
+       set var $prefix = 1
+       set var $newline = 1
+
+       set var $begin = $desc->text_blk_lpos.begin % (1U << prb->text_data_ring.size_bits)
+       set var $next = $desc->text_blk_lpos.next % (1U << prb->text_data_ring.size_bits)
+
+       # handle data-less record
+       if ($begin & 1)
+               set var $text_len = 0
+               set var $log = ""
+       else
+               # handle wrapping data block
+               if ($begin > $next)
+                       set var $begin = 0
+               end
+
+               # skip over descriptor id
+               set var $begin = $begin + sizeof(long)
+
+               # handle truncated message
+               if ($next - $begin < $info->text_len)
+                       set var $text_len = $next - $begin
+               else
+                       set var $text_len = $info->text_len
+               end
+
+               set var $log = &prb->text_data_ring.data[$begin]
+       end
+
+       # prev & LOG_CONT && !(info->flags & LOG_PREIX)
+       if (($prev_flags & 8) && !($info->flags & 4))
+               set var $prefix = 0
        end
 
-       # msg->flags & LOG_CONT
-       if ($msg->flags & 8)
+       # info->flags & LOG_CONT
+       if ($info->flags & 8)
                # (prev & LOG_CONT && !(prev & LOG_NEWLINE))
                if (($prev_flags & 8) && !($prev_flags & 2))
-                       set $prefix = 0
+                       set var $prefix = 0
                end
-               # (!(msg->flags & LOG_NEWLINE))
-               if (!($msg->flags & 2))
-                       set $newline = 0
+               # (!(info->flags & LOG_NEWLINE))
+               if (!($info->flags & 2))
+                       set var $newline = 0
                end
        end
 
        if ($prefix)
-               printf "[%5lu.%06lu] ", $msg->ts_nsec / 1000000000, $msg->ts_nsec % 1000000000
+               printf "[%5lu.%06lu] ", $info->ts_nsec / 1000000000, $info->ts_nsec % 1000000000
        end
-       if ($msg->text_len != 0)
-               eval "printf \"%%%d.%ds\", $log", $msg->text_len, $msg->text_len
+       if ($text_len)
+               eval "printf \"%%%d.%ds\", $log", $text_len, $text_len
        end
        if ($newline)
                printf "\n"
        end
-       if ($msg->dict_len > 0)
-               set $dict = $log + $msg->text_len
-               set $idx = 0
-               set $line = 1
-               while ($idx < $msg->dict_len)
+
+       # handle dictionary data
+
+       set var $begin = $desc->dict_blk_lpos.begin % (1U << prb->dict_data_ring.size_bits)
+       set var $next = $desc->dict_blk_lpos.next % (1U << prb->dict_data_ring.size_bits)
+
+       # handle data-less record
+       if ($begin & 1)
+               set var $dict_len = 0
+               set var $dict = ""
+       else
+               # handle wrapping data block
+               if ($begin > $next)
+                       set var $begin = 0
+               end
+
+               # skip over descriptor id
+               set var $begin = $begin + sizeof(long)
+
+               # handle truncated message
+               if ($next - $begin < $info->dict_len)
+                       set var $dict_len = $next - $begin
+               else
+                       set var $dict_len = $info->dict_len
+               end
+
+               set var $dict = &prb->dict_data_ring.data[$begin]
+       end
+
+       if ($dict_len > 0)
+               set var $idx = 0
+               set var $line = 1
+               while ($idx < $dict_len)
                        if ($line)
                                printf " "
-                               set $line = 0
+                               set var $line = 0
                        end
-                       set $c = $dict[$idx]
+                       set var $c = $dict[$idx]
                        if ($c == '\0')
                                printf "\n"
-                               set $line = 1
+                               set var $line = 1
                        else
                                if ($c < ' ' || $c >= 127 || $c == '\\')
                                        printf "\\x%02x", $c
@@ -228,33 +282,40 @@ define dump_log_idx
                                        printf "%c", $c
                                end
                        end
-                       set $idx = $idx + 1
+                       set var $idx = $idx + 1
                end
                printf "\n"
        end
 end
-document dump_log_idx
-       Dump a single log given its index in the log buffer.  The first
-       parameter is the index into log_buf, the second is optional and
-       specified the previous log buffer's flags, used for properly
-       formatting continued lines.
+document dump_record
+       Dump a single record. The first parameter is the descriptor
+       sequence number, the second is optional and specifies the
+       previous record's flags, used for properly formatting
+       continued lines.
 end
 
 define dmesg
-       set $i = log_first_idx
-       set $end_idx = log_first_idx
-       set $prev_flags = 0
+       set var $desc_committed = 1UL << ((sizeof(long) * 8) - 1)
+       set var $flags_mask = 3UL << ((sizeof(long) * 8) - 2)
+       set var $id_mask = ~$flags_mask
+
+       set var $desc_count = 1U << prb->desc_ring.count_bits
+       set var $prev_flags = 0
+
+       set var $id = prb->desc_ring.tail_id.counter
+       set var $end_id = prb->desc_ring.head_id.counter
 
        while (1)
-               set $msg = ((struct printk_log *) (log_buf + $i))
-               if ($msg->len == 0)
-                       set $i = 0
-               else
-                       dump_log_idx $i $prev_flags
-                       set $i = $i + $msg->len
-                       set $prev_flags = $msg->flags
+               set var $desc = &prb->desc_ring.descs[$id % $desc_count]
+
+               # skip non-committed record
+               if (($desc->state_var.counter & $flags_mask) == $desc_committed)
+                       dump_record $desc $prev_flags
+                       set var $prev_flags = $desc->info.flags
                end
-               if ($i == $end_idx)
+
+               set var $id = ($id + 1) & $id_mask
+               if ($id == $end_id)
                        loop_break
                end
        end
index 2fa7bb83885f068e05648448267b3f590bfb2ab9..6c6022012ea8497cafbc679717e6c09dca754414 100644 (file)
@@ -16,8 +16,13 @@ import sys
 
 from linux import utils
 
-printk_log_type = utils.CachedType("struct printk_log")
-
+printk_info_type = utils.CachedType("struct printk_info")
+prb_data_blk_lpos_type = utils.CachedType("struct prb_data_blk_lpos")
+prb_desc_type = utils.CachedType("struct prb_desc")
+prb_desc_ring_type = utils.CachedType("struct prb_desc_ring")
+prb_data_ring_type = utils.CachedType("struct prb_data_ring")
+printk_ringbuffer_type = utils.CachedType("struct printk_ringbuffer")
+atomic_long_type = utils.CachedType("atomic_long_t")
 
 class LxDmesg(gdb.Command):
     """Print Linux kernel log buffer."""
@@ -26,44 +31,102 @@ class LxDmesg(gdb.Command):
         super(LxDmesg, self).__init__("lx-dmesg", gdb.COMMAND_DATA)
 
     def invoke(self, arg, from_tty):
-        log_buf_addr = int(str(gdb.parse_and_eval(
-            "(void *)'printk.c'::log_buf")).split()[0], 16)
-        log_first_idx = int(gdb.parse_and_eval("'printk.c'::log_first_idx"))
-        log_next_idx = int(gdb.parse_and_eval("'printk.c'::log_next_idx"))
-        log_buf_len = int(gdb.parse_and_eval("'printk.c'::log_buf_len"))
-
         inf = gdb.inferiors()[0]
-        start = log_buf_addr + log_first_idx
-        if log_first_idx < log_next_idx:
-            log_buf_2nd_half = -1
-            length = log_next_idx - log_first_idx
-            log_buf = utils.read_memoryview(inf, start, length).tobytes()
-        else:
-            log_buf_2nd_half = log_buf_len - log_first_idx
-            a = utils.read_memoryview(inf, start, log_buf_2nd_half)
-            b = utils.read_memoryview(inf, log_buf_addr, log_next_idx)
-            log_buf = a.tobytes() + b.tobytes()
-
-        length_offset = printk_log_type.get_type()['len'].bitpos // 8
-        text_len_offset = printk_log_type.get_type()['text_len'].bitpos // 8
-        time_stamp_offset = printk_log_type.get_type()['ts_nsec'].bitpos // 8
-        text_offset = printk_log_type.get_type().sizeof
-
-        pos = 0
-        while pos < log_buf.__len__():
-            length = utils.read_u16(log_buf, pos + length_offset)
-            if length == 0:
-                if log_buf_2nd_half == -1:
-                    gdb.write("Corrupted log buffer!\n")
+
+        # read in prb structure
+        prb_addr = int(str(gdb.parse_and_eval("(void *)'printk.c'::prb")).split()[0], 16)
+        sz = printk_ringbuffer_type.get_type().sizeof
+        prb = utils.read_memoryview(inf, prb_addr, sz).tobytes()
+
+        # read in descriptor ring structure
+        off = printk_ringbuffer_type.get_type()['desc_ring'].bitpos // 8
+        addr = prb_addr + off
+        sz = prb_desc_ring_type.get_type().sizeof
+        desc_ring = utils.read_memoryview(inf, addr, sz).tobytes()
+
+        # read in descriptor array
+        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()
+
+        # read in text data ring structure
+        off = printk_ringbuffer_type.get_type()['text_data_ring'].bitpos // 8
+        addr = prb_addr + off
+        sz = prb_data_ring_type.get_type().sizeof
+        text_data_ring = utils.read_memoryview(inf, addr, sz).tobytes()
+
+        # read in text data
+        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()
+
+        counter_off = atomic_long_type.get_type()['counter'].bitpos // 8
+
+        sv_off = prb_desc_type.get_type()['state_var'].bitpos // 8
+
+        off = prb_desc_type.get_type()['text_blk_lpos'].bitpos // 8
+        begin_off = off + (prb_data_blk_lpos_type.get_type()['begin'].bitpos // 8)
+        next_off = off + (prb_data_blk_lpos_type.get_type()['next'].bitpos // 8)
+
+        off = prb_desc_type.get_type()['info'].bitpos // 8
+        ts_off = off + printk_info_type.get_type()['ts_nsec'].bitpos // 8
+        len_off = off + printk_info_type.get_type()['text_len'].bitpos // 8
+
+        # definitions from kernel/printk/printk_ringbuffer.h
+        desc_sv_bits = utils.get_long_type().sizeof * 8
+        desc_committed_mask = 1 << (desc_sv_bits - 1)
+        desc_reuse_mask = 1 << (desc_sv_bits - 2)
+        desc_flags_mask = desc_committed_mask | desc_reuse_mask
+        desc_id_mask = ~desc_flags_mask
+
+        # read in tail and head descriptor ids
+        off = prb_desc_ring_type.get_type()['tail_id'].bitpos // 8
+        tail_id = utils.read_u64(desc_ring, off + counter_off)
+        off = prb_desc_ring_type.get_type()['head_id'].bitpos // 8
+        head_id = utils.read_u64(desc_ring, off + counter_off)
+
+        did = tail_id
+        while True:
+            ind = did % desc_ring_count
+            desc_off = desc_sz * ind
+
+            # skip non-committed record
+            state = utils.read_u64(descs, desc_off + sv_off + counter_off) & desc_flags_mask
+            if state != desc_committed_mask:
+                if did == head_id:
                     break
-                pos = log_buf_2nd_half
+                did = (did + 1) & desc_id_mask
                 continue
 
-            text_len = utils.read_u16(log_buf, pos + text_len_offset)
-            text_start = pos + text_offset
-            text = log_buf[text_start:text_start + text_len].decode(
-                encoding='utf8', errors='replace')
-            time_stamp = utils.read_u64(log_buf, pos + time_stamp_offset)
+            begin = utils.read_ulong(descs, desc_off + begin_off) % text_data_sz
+            end = utils.read_ulong(descs, desc_off + next_off) % text_data_sz
+
+            # handle data-less record
+            if begin & 1 == 1:
+                text = ""
+            else:
+                # handle wrapping data block
+                if begin > end:
+                    begin = 0
+
+                # skip over descriptor id
+                text_start = begin + utils.get_long_type().sizeof
+
+                text_len = utils.read_u16(descs, desc_off + 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')
+
+            time_stamp = utils.read_u64(descs, desc_off + ts_off)
 
             for line in text.splitlines():
                 msg = u"[{time:12.6f}] {line}\n".format(
@@ -75,7 +138,9 @@ class LxDmesg(gdb.Command):
                     msg = msg.encode(encoding='utf8', errors='replace')
                 gdb.write(msg)
 
-            pos += length
+            if did == head_id:
+                break
+            did = (did + 1) & desc_id_mask
 
 
 LxDmesg()