* [PATCH 1/2][next] scripts/gdb: add utils.read_ulong()
2020-08-14 21:25 [PATCH 0/2][next] update gdb scripts for lockless printk ringbuffer John Ogness
@ 2020-08-14 21:25 ` John Ogness
2020-08-14 22:29 ` Nick Desaulniers
2020-08-14 21:25 ` [PATCH 2/2][next] scripts/gdb: update for lockless printk ringbuffer John Ogness
` (2 subsequent siblings)
3 siblings, 1 reply; 12+ messages in thread
From: John Ogness @ 2020-08-14 21:25 UTC (permalink / raw)
To: Jan Kiszka
Cc: Andrew Morton, Baoquan He, Dave Young, Vivek Goyal,
Jonathan Corbet, Kieran Bingham, Petr Mladek, Sergey Senozhatsky,
Sergey Senozhatsky, Steven Rostedt, Linus Torvalds,
Greg Kroah-Hartman, Nick Desaulniers, linux-kernel
Add a function for reading unsigned long values, which vary in size
depending on the architecture.
Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
based on next-20200814
scripts/gdb/linux/utils.py | 7 +++++++
1 file changed, 7 insertions(+)
diff --git a/scripts/gdb/linux/utils.py b/scripts/gdb/linux/utils.py
index ea94221dbd39..ff7c1799d588 100644
--- a/scripts/gdb/linux/utils.py
+++ b/scripts/gdb/linux/utils.py
@@ -123,6 +123,13 @@ def read_u64(buffer, offset):
return read_u32(buffer, offset + 4) + (read_u32(buffer, offset) << 32)
+def read_ulong(buffer, offset):
+ if get_long_type().sizeof == 8:
+ return read_u64(buffer, offset)
+ else:
+ return read_u32(buffer, offset)
+
+
target_arch = None
--
2.20.1
^ permalink raw reply [flat|nested] 12+ messages in thread* [PATCH 2/2][next] scripts/gdb: update for lockless printk ringbuffer
2020-08-14 21:25 [PATCH 0/2][next] update gdb scripts for lockless printk ringbuffer John Ogness
2020-08-14 21:25 ` [PATCH 1/2][next] scripts/gdb: add utils.read_ulong() John Ogness
@ 2020-08-14 21:25 ` John Ogness
2020-08-14 22:24 ` [PATCH 0/2][next] update gdb scripts " Nick Desaulniers
2020-08-21 8:08 ` Petr Mladek
3 siblings, 0 replies; 12+ messages in thread
From: John Ogness @ 2020-08-14 21:25 UTC (permalink / raw)
To: Jan Kiszka
Cc: Andrew Morton, Baoquan He, Dave Young, Vivek Goyal,
Jonathan Corbet, Kieran Bingham, Petr Mladek, Sergey Senozhatsky,
Sergey Senozhatsky, Steven Rostedt, Linus Torvalds,
Greg Kroah-Hartman, Nick Desaulniers, linux-kernel
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: ("printk: use the lockless ringbuffer")
Signed-off-by: John Ogness <john.ogness@linutronix.de>
Reported-by: Nick Desaulniers <ndesaulniers@google.com>
---
based on next-20200814
Documentation/admin-guide/kdump/gdbmacros.txt | 153 ++++++++++++------
scripts/gdb/linux/dmesg.py | 139 +++++++++++-----
2 files changed, 209 insertions(+), 83 deletions(-)
diff --git a/Documentation/admin-guide/kdump/gdbmacros.txt b/Documentation/admin-guide/kdump/gdbmacros.txt
index 220d0a80ca2c..6025534c6c14 100644
--- a/Documentation/admin-guide/kdump/gdbmacros.txt
+++ b/Documentation/admin-guide/kdump/gdbmacros.txt
@@ -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 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
diff --git a/scripts/gdb/linux/dmesg.py b/scripts/gdb/linux/dmesg.py
index 2fa7bb83885f..6c6022012ea8 100644
--- a/scripts/gdb/linux/dmesg.py
+++ b/scripts/gdb/linux/dmesg.py
@@ -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()
--
2.20.1
^ permalink raw reply [flat|nested] 12+ messages in thread* Re: [PATCH 0/2][next] update gdb scripts for lockless printk ringbuffer
2020-08-14 21:25 [PATCH 0/2][next] update gdb scripts for lockless printk ringbuffer John Ogness
2020-08-14 21:25 ` [PATCH 1/2][next] scripts/gdb: add utils.read_ulong() John Ogness
2020-08-14 21:25 ` [PATCH 2/2][next] scripts/gdb: update for lockless printk ringbuffer John Ogness
@ 2020-08-14 22:24 ` Nick Desaulniers
2020-08-21 8:08 ` Petr Mladek
3 siblings, 0 replies; 12+ messages in thread
From: Nick Desaulniers @ 2020-08-14 22:24 UTC (permalink / raw)
To: John Ogness
Cc: Jan Kiszka, Andrew Morton, Baoquan He, Dave Young, Vivek Goyal,
Jonathan Corbet, Kieran Bingham, Petr Mladek, Sergey Senozhatsky,
Sergey Senozhatsky, Steven Rostedt, Linus Torvalds,
Greg Kroah-Hartman, LKML
On Fri, Aug 14, 2020 at 2:25 PM John Ogness <john.ogness@linutronix.de> wrote:
>
> Hi,
>
> When we brought in the new lockless printk ringbuffer, we overlooked the gdb
> scripts. Here are a set of patches to implement gdb support for the new
> ringbuffer.
>
> John Ogness (2):
> scripts/gdb: add utils.read_ulong()
> scripts/gdb: update for lockless printk ringbuffer
Thanks John! For the series:
Tested-by: Nick Desaulniers <ndesaulniers@google.com>
>
> Documentation/admin-guide/kdump/gdbmacros.txt | 153 ++++++++++++------
> scripts/gdb/linux/dmesg.py | 139 +++++++++++-----
> scripts/gdb/linux/utils.py | 7 +
> 3 files changed, 216 insertions(+), 83 deletions(-)
>
> --
> 2.20.1
>
--
Thanks,
~Nick Desaulniers
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH 0/2][next] update gdb scripts for lockless printk ringbuffer
2020-08-14 21:25 [PATCH 0/2][next] update gdb scripts for lockless printk ringbuffer John Ogness
` (2 preceding siblings ...)
2020-08-14 22:24 ` [PATCH 0/2][next] update gdb scripts " Nick Desaulniers
@ 2020-08-21 8:08 ` Petr Mladek
2020-08-21 8:55 ` Jan Kiszka
3 siblings, 1 reply; 12+ messages in thread
From: Petr Mladek @ 2020-08-21 8:08 UTC (permalink / raw)
To: John Ogness
Cc: Jan Kiszka, Andrew Morton, Baoquan He, Dave Young, Vivek Goyal,
Jonathan Corbet, Kieran Bingham, Sergey Senozhatsky,
Sergey Senozhatsky, Steven Rostedt, Linus Torvalds,
Greg Kroah-Hartman, Nick Desaulniers, linux-kernel
On Fri 2020-08-14 23:31:23, John Ogness wrote:
> Hi,
>
> When we brought in the new lockless printk ringbuffer, we overlooked the gdb
> scripts. Here are a set of patches to implement gdb support for the new
> ringbuffer.
>
> John Ogness (2):
> scripts/gdb: add utils.read_ulong()
> scripts/gdb: update for lockless printk ringbuffer
I am not fluent in the gdb macros and python so I did not try any
deep review. But both patches work for me:
Tested-by: Petr Mladek <pmladek@suse.com>
I am going to give it few more days before pushing just in case there is
another feedback.
Best Regards,
Petr
BTW: Are you aware of https://github.com/crash-python/crash-python project?
The ambition is to implement "crash" features and even more into
gdb using python extensions. It similar approach like
scripts/gdb/
crash-python is being developed sporadically in waves. It is
mostly during a week that is dedicated for such projects
at SUSE. It would be great to get more contributors.
^ permalink raw reply [flat|nested] 12+ messages in thread