[PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Joel Colledge]

When CONFIG_PRINTK_CALLER is set, struct printk_log contains an
additional member caller_id. As a result, the offset of the log text is
different.

This fixes the following error:

  (gdb) lx-dmesg
  Python Exception <class 'ValueError'> embedded null character:
  Error occurred in Python command: embedded null character

Signed-off-by: Joel Colledge <joel.colledge@linbit.com>
---
 scripts/gdb/linux/constants.py.in | 1 +
 scripts/gdb/linux/dmesg.py        | 4 +++-
 2 files changed, 4 insertions(+), 1 deletion(-)

diff --git a/scripts/gdb/linux/constants.py.in b/scripts/gdb/linux/constants.py.in
index 2efbec6b6b8d..3c9794a0bf55 100644
--- a/scripts/gdb/linux/constants.py.in
+++ b/scripts/gdb/linux/constants.py.in
@@ -74,4 +74,5 @@ LX_CONFIG(CONFIG_GENERIC_CLOCKEVENTS_BROADCAST)
 LX_CONFIG(CONFIG_HIGH_RES_TIMERS)
 LX_CONFIG(CONFIG_NR_CPUS)
 LX_CONFIG(CONFIG_OF)
+LX_CONFIG(CONFIG_PRINTK_CALLER)
 LX_CONFIG(CONFIG_TICK_ONESHOT)
diff --git a/scripts/gdb/linux/dmesg.py b/scripts/gdb/linux/dmesg.py
index 6d2e09a2ad2f..1352680ef731 100644
--- a/scripts/gdb/linux/dmesg.py
+++ b/scripts/gdb/linux/dmesg.py
@@ -14,6 +14,7 @@
 import gdb
 import sys
 
+from linux import constants
 from linux import utils
 
 
@@ -53,7 +54,8 @@ class LxDmesg(gdb.Command):
                 continue
 
             text_len = utils.read_u16(log_buf[pos + 10:pos + 12])
-            text = log_buf[pos + 16:pos + 16 + text_len].decode(
+            text_start = pos + (20 if constants.LX_CONFIG_PRINTK_CALLER else 16)
+            text = log_buf[text_start:text_start + text_len].decode(
                 encoding='utf8', errors='replace')
             time_stamp = utils.read_u64(log_buf[pos:pos + 8])
 
-- 
2.17.1

Re: [PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Joel Colledge]

Hi Jan and Kieran, maintainers of scripts/gdb/,
CC: Leonard, most recent contributor to scripts/gdb/linux/dmesg.py

Could someone look at this fix please? Is there anything I should
improve in the code or the format of the contribution? Thanks.

Re: [PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Jan Kiszka]

On 25.09.19 17:03, Joel Colledge wrote:
> When CONFIG_PRINTK_CALLER is set, struct printk_log contains an
> additional member caller_id. As a result, the offset of the log text is
> different.
> 
> This fixes the following error:
> 
>   (gdb) lx-dmesg
>   Python Exception <class 'ValueError'> embedded null character:
>   Error occurred in Python command: embedded null character
> 
> Signed-off-by: Joel Colledge <joel.colledge@linbit.com>
> ---
>  scripts/gdb/linux/constants.py.in | 1 +
>  scripts/gdb/linux/dmesg.py        | 4 +++-
>  2 files changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/scripts/gdb/linux/constants.py.in b/scripts/gdb/linux/constants.py.in
> index 2efbec6b6b8d..3c9794a0bf55 100644
> --- a/scripts/gdb/linux/constants.py.in
> +++ b/scripts/gdb/linux/constants.py.in
> @@ -74,4 +74,5 @@ LX_CONFIG(CONFIG_GENERIC_CLOCKEVENTS_BROADCAST)
>  LX_CONFIG(CONFIG_HIGH_RES_TIMERS)
>  LX_CONFIG(CONFIG_NR_CPUS)
>  LX_CONFIG(CONFIG_OF)
> +LX_CONFIG(CONFIG_PRINTK_CALLER)
>  LX_CONFIG(CONFIG_TICK_ONESHOT)
> diff --git a/scripts/gdb/linux/dmesg.py b/scripts/gdb/linux/dmesg.py
> index 6d2e09a2ad2f..1352680ef731 100644
> --- a/scripts/gdb/linux/dmesg.py
> +++ b/scripts/gdb/linux/dmesg.py
> @@ -14,6 +14,7 @@
>  import gdb
>  import sys
>  
> +from linux import constants
>  from linux import utils
>  
>  
> @@ -53,7 +54,8 @@ class LxDmesg(gdb.Command):
>                  continue
>  
>              text_len = utils.read_u16(log_buf[pos + 10:pos + 12])
> -            text = log_buf[pos + 16:pos + 16 + text_len].decode(
> +            text_start = pos + (20 if constants.LX_CONFIG_PRINTK_CALLER else 16)
> +            text = log_buf[text_start:text_start + text_len].decode(
>                  encoding='utf8', errors='replace')
>              time_stamp = utils.read_u64(log_buf[pos:pos + 8])
>  
> 

Sorry for the delay:

Reviewed-by: Jan Kiszka <jan.kiszka@siemens.com>

I suspect we will see more in nearer future with upcoming printk rework...

Jan

-- 
Siemens AG, Corporate Technology, CT RDA IOT SES-DE
Corporate Competence Center Embedded Linux

Re: [PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Leonard Crestez]

On 10.10.2019 18:14, Jan Kiszka wrote:
> On 25.09.19 17:03, Joel Colledge wrote:
>> When CONFIG_PRINTK_CALLER is set, struct printk_log contains an
>> additional member caller_id. As a result, the offset of the log text is
>> different.
>>
>> This fixes the following error:
>>
>>    (gdb) lx-dmesg
>>    Python Exception <class 'ValueError'> embedded null character:
>>    Error occurred in Python command: embedded null character
>>
>> Signed-off-by: Joel Colledge <joel.colledge@linbit.com>
>> ---
>>   scripts/gdb/linux/constants.py.in | 1 +
>>   scripts/gdb/linux/dmesg.py        | 4 +++-
>>   2 files changed, 4 insertions(+), 1 deletion(-)
>>
>> diff --git a/scripts/gdb/linux/constants.py.in b/scripts/gdb/linux/constants.py.in
>> index 2efbec6b6b8d..3c9794a0bf55 100644
>> --- a/scripts/gdb/linux/constants.py.in
>> +++ b/scripts/gdb/linux/constants.py.in
>> @@ -74,4 +74,5 @@ LX_CONFIG(CONFIG_GENERIC_CLOCKEVENTS_BROADCAST)
>>   LX_CONFIG(CONFIG_HIGH_RES_TIMERS)
>>   LX_CONFIG(CONFIG_NR_CPUS)
>>   LX_CONFIG(CONFIG_OF)
>> +LX_CONFIG(CONFIG_PRINTK_CALLER)
>>   LX_CONFIG(CONFIG_TICK_ONESHOT)
>> diff --git a/scripts/gdb/linux/dmesg.py b/scripts/gdb/linux/dmesg.py
>> index 6d2e09a2ad2f..1352680ef731 100644
>> --- a/scripts/gdb/linux/dmesg.py
>> +++ b/scripts/gdb/linux/dmesg.py
>> @@ -14,6 +14,7 @@
>>   import gdb
>>   import sys
>>   
>> +from linux import constants
>>   from linux import utils
>>   
>>   
>> @@ -53,7 +54,8 @@ class LxDmesg(gdb.Command):
>>                   continue
>>   
>>               text_len = utils.read_u16(log_buf[pos + 10:pos + 12])
>> -            text = log_buf[pos + 16:pos + 16 + text_len].decode(
>> +            text_start = pos + (20 if constants.LX_CONFIG_PRINTK_CALLER else 16)
>> +            text = log_buf[text_start:text_start + text_len].decode(
>>                   encoding='utf8', errors='replace')
>>               time_stamp = utils.read_u64(log_buf[pos:pos + 8])
> 
> Sorry for the delay:
> 
> Reviewed-by: Jan Kiszka <jan.kiszka@siemens.com>
> 
> I suspect we will see more in nearer future with upcoming printk rework...

The patch looks correct but I'm curious: is there a reason this code 
doesn't use struct printk_log?

GDB already knows about struct offsets so there should be no need to 
handle ifdefs with arithmetic.

Is it realistic to use gdb without struct layout info?

--
Regards,
Leonard

[PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Joel Colledge]

When CONFIG_PRINTK_CALLER is set, struct printk_log contains an
additional member caller_id. This affects the offset of the log text.
Account for this by using the type information from gdb to determine all
the offsets instead of using hardcoded values.

This fixes following error:

  (gdb) lx-dmesg
  Python Exception <class 'ValueError'> embedded null character:
  Error occurred in Python command: embedded null character

Signed-off-by: Joel Colledge <joel.colledge@linbit.com>
---
Changes in v2:
- use type information from gdb instead of hardcoded offsets

Thanks for the idea about using the struct layout info from gdb, Leonard. I can't see any reason we shouldn't use that here, since most of the other commands use it. LxDmesg has used hardcoded offsets since scripts/gdb was introduced, so I assume it just ended up like that during the initial development of the tool. Here is a version of the fix using offsets from gdb.

 scripts/gdb/linux/dmesg.py | 16 ++++++++++++----
 1 file changed, 12 insertions(+), 4 deletions(-)

diff --git a/scripts/gdb/linux/dmesg.py b/scripts/gdb/linux/dmesg.py
index 6d2e09a2ad2f..8f5d899029b7 100644
--- a/scripts/gdb/linux/dmesg.py
+++ b/scripts/gdb/linux/dmesg.py
@@ -16,6 +16,8 @@ import sys
 
 from linux import utils
 
+printk_log_type = utils.CachedType("struct printk_log")
+
 
 class LxDmesg(gdb.Command):
     """Print Linux kernel log buffer."""
@@ -42,9 +44,14 @@ class LxDmesg(gdb.Command):
             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 + 8:pos + 10])
+            length = utils.read_u16(log_buf[pos + length_offset:pos + length_offset + 2])
             if length == 0:
                 if log_buf_2nd_half == -1:
                     gdb.write("Corrupted log buffer!\n")
@@ -52,10 +59,11 @@ class LxDmesg(gdb.Command):
                 pos = log_buf_2nd_half
                 continue
 
-            text_len = utils.read_u16(log_buf[pos + 10:pos + 12])
-            text = log_buf[pos + 16:pos + 16 + text_len].decode(
+            text_len = utils.read_u16(log_buf[pos + text_len_offset:pos + text_len_offset + 2])
+            text = log_buf[pos + text_offset:pos + text_offset + text_len].decode(
                 encoding='utf8', errors='replace')
-            time_stamp = utils.read_u64(log_buf[pos:pos + 8])
+            time_stamp = utils.read_u64(
+                log_buf[pos + time_stamp_offset:pos + time_stamp_offset + 8])
 
             for line in text.splitlines():
                 msg = u"[{time:12.6f}] {line}\n".format(
-- 
2.17.1

Re: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Jan Kiszka]

On 11.10.19 14:24, Joel Colledge wrote:
> When CONFIG_PRINTK_CALLER is set, struct printk_log contains an
> additional member caller_id. This affects the offset of the log text.
> Account for this by using the type information from gdb to determine all
> the offsets instead of using hardcoded values.
> 
> This fixes following error:
> 
>    (gdb) lx-dmesg
>    Python Exception <class 'ValueError'> embedded null character:
>    Error occurred in Python command: embedded null character
> 
> Signed-off-by: Joel Colledge <joel.colledge@linbit.com>
> ---
> Changes in v2:
> - use type information from gdb instead of hardcoded offsets
> 
> Thanks for the idea about using the struct layout info from gdb, Leonard. I can't see any reason we shouldn't use that here, since most of the other commands use it. LxDmesg has used hardcoded offsets since scripts/gdb was introduced, so I assume it just ended up like that during the initial development of the tool. Here is a version of the fix using offsets from gdb.

That's not unlikely, indeed. lx-dmesg was one of the very first features 
I've implemented back then, and it definitely predated things like 
CachedType.

> 
>   scripts/gdb/linux/dmesg.py | 16 ++++++++++++----
>   1 file changed, 12 insertions(+), 4 deletions(-)
> 
> diff --git a/scripts/gdb/linux/dmesg.py b/scripts/gdb/linux/dmesg.py
> index 6d2e09a2ad2f..8f5d899029b7 100644
> --- a/scripts/gdb/linux/dmesg.py
> +++ b/scripts/gdb/linux/dmesg.py
> @@ -16,6 +16,8 @@ import sys
>   
>   from linux import utils
>   
> +printk_log_type = utils.CachedType("struct printk_log")
> +
>   
>   class LxDmesg(gdb.Command):
>       """Print Linux kernel log buffer."""
> @@ -42,9 +44,14 @@ class LxDmesg(gdb.Command):
>               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

Does bitpos really use a non-int type? Otherwise, plain '/' suffices.

> +        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 + 8:pos + 10])
> +            length = utils.read_u16(log_buf[pos + length_offset:pos + length_offset + 2])

Overlong line.

>               if length == 0:
>                   if log_buf_2nd_half == -1:
>                       gdb.write("Corrupted log buffer!\n")
> @@ -52,10 +59,11 @@ class LxDmesg(gdb.Command):
>                   pos = log_buf_2nd_half
>                   continue
>   
> -            text_len = utils.read_u16(log_buf[pos + 10:pos + 12])
> -            text = log_buf[pos + 16:pos + 16 + text_len].decode(
> +            text_len = utils.read_u16(log_buf[pos + text_len_offset:pos + text_len_offset + 2])

Here as well. Better use some temp vars to break up the expressions. 
Helps with readability.

> +            text = log_buf[pos + text_offset:pos + text_offset + text_len].decode(
>                   encoding='utf8', errors='replace')
> -            time_stamp = utils.read_u64(log_buf[pos:pos + 8])
> +            time_stamp = utils.read_u64(
> +                log_buf[pos + time_stamp_offset:pos + time_stamp_offset + 8])
>   
>               for line in text.splitlines():
>                   msg = u"[{time:12.6f}] {line}\n".format(
> 

Looks good otherwise.

Jan

-- 
Siemens AG, Corporate Technology, CT RDA IOT SES-DE
Corporate Competence Center Embedded Linux

Re: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Leonard Crestez]

On 11.10.2019 15:25, Joel Colledge wrote:
> When CONFIG_PRINTK_CALLER is set, struct printk_log contains an
> additional member caller_id. This affects the offset of the log text.
> Account for this by using the type information from gdb to determine all
> the offsets instead of using hardcoded values.
> 
> This fixes following error:
> 
>    (gdb) lx-dmesg
>    Python Exception <class 'ValueError'> embedded null character:
>    Error occurred in Python command: embedded null character
> 
> Signed-off-by: Joel Colledge <joel.colledge@linbit.com>
> ---
> Changes in v2:
> - use type information from gdb instead of hardcoded offsets
> 
> Thanks for the idea about using the struct layout info from gdb, Leonard. I can't see any reason we shouldn't use that here, since most of the other commands use it. LxDmesg has used hardcoded offsets since scripts/gdb was introduced, so I assume it just ended up like that during the initial development of the tool. Here is a version of the fix using offsets from gdb.

This struct printk_log is quite small, I wonder if it's possible to do a 
single read for each log entry? This might make lx-dmesg faster because 
of fewer roundtrips to gdbserver and jtag (or whatever backend you're 
using).

> 
>   scripts/gdb/linux/dmesg.py | 16 ++++++++++++----
>   1 file changed, 12 insertions(+), 4 deletions(-)
> 
> diff --git a/scripts/gdb/linux/dmesg.py b/scripts/gdb/linux/dmesg.py
> index 6d2e09a2ad2f..8f5d899029b7 100644
> --- a/scripts/gdb/linux/dmesg.py
> +++ b/scripts/gdb/linux/dmesg.py
> @@ -16,6 +16,8 @@ import sys
>   
>   from linux import utils
>   
> +printk_log_type = utils.CachedType("struct printk_log")
> +
>   
>   class LxDmesg(gdb.Command):
>       """Print Linux kernel log buffer."""
> @@ -42,9 +44,14 @@ class LxDmesg(gdb.Command):
>               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 + 8:pos + 10])
> +            length = utils.read_u16(log_buf[pos + length_offset:pos + length_offset + 2])
>               if length == 0:
>                   if log_buf_2nd_half == -1:
>                       gdb.write("Corrupted log buffer!\n")
> @@ -52,10 +59,11 @@ class LxDmesg(gdb.Command):
>                   pos = log_buf_2nd_half
>                   continue
>   
> -            text_len = utils.read_u16(log_buf[pos + 10:pos + 12])
> -            text = log_buf[pos + 16:pos + 16 + text_len].decode(
> +            text_len = utils.read_u16(log_buf[pos + text_len_offset:pos + text_len_offset + 2])
> +            text = log_buf[pos + text_offset:pos + text_offset + text_len].decode(
>                   encoding='utf8', errors='replace')
> -            time_stamp = utils.read_u64(log_buf[pos:pos + 8])
> +            time_stamp = utils.read_u64(
> +                log_buf[pos + time_stamp_offset:pos + time_stamp_offset + 8])
>   
>               for line in text.splitlines():
>                   msg = u"[{time:12.6f}] {line}\n".format(
> 

Re: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Joel Colledge]

On Fri, Oct 11, 2019 at 2:38 PM Jan Kiszka <jan.kiszka@siemens.com> wrote:
> Does bitpos really use a non-int type? Otherwise, plain '/' suffices.

bitpos uses gdb.Field. When I use '/' I get an error:
Error occurred in Python command: slice indices must be integers or
None or have an __index__ method

I'm guessing gdb.Field has some kind of override which causes it to be
converted to float when using '/'; hence '//'.

> Overlong line.
> ...
> Here as well. Better use some temp vars to break up the expressions.
> Helps with readability.

Will do.

Re: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Joel Colledge]

On Fri, Oct 11, 2019 at 2:47 PM Leonard Crestez <leonard.crestez@nxp.com> wrote:
> This struct printk_log is quite small, I wonder if it's possible to do a
> single read for each log entry? This might make lx-dmesg faster because
> of fewer roundtrips to gdbserver and jtag (or whatever backend you're
> using).

I think this is already covered. utils.read_memoryview uses
inferior.read_memory and I think that reads the entire log buffer at
once (at most 2 reads, one for each half).

Re: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Leonard Crestez]

On 11.10.2019 16:02, Joel Colledge wrote:
> On Fri, Oct 11, 2019 at 2:47 PM Leonard Crestez <leonard.crestez@nxp.com> wrote:
>> This struct printk_log is quite small, I wonder if it's possible to do a
>> single read for each log entry? This might make lx-dmesg faster because
>> of fewer roundtrips to gdbserver and jtag (or whatever backend you're
>> using).
> 
> I think this is already covered. utils.read_memoryview uses
> inferior.read_memory and I think that reads the entire log buffer at
> once (at most 2 reads, one for each half).

You're right, sorry

[PATCH v3] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Joel Colledge]

When CONFIG_PRINTK_CALLER is set, struct printk_log contains an
additional member caller_id. This affects the offset of the log text.
Account for this by using the type information from gdb to determine all
the offsets instead of using hardcoded values.

This fixes following error:

  (gdb) lx-dmesg
  Python Exception <class 'ValueError'> embedded null character:
  Error occurred in Python command: embedded null character

The read_u* utility functions now take an offset argument to make them
easier to use.

Signed-off-by: Joel Colledge <joel.colledge@linbit.com>
---
Changes in v3:
- fix some overlong lines and generally make the code more readable by
  pushing the slicing down into the read_u* helper functions

In general, I would consider slicing to be more "pythonic" than passing
around offsets. However, in this case we always want to slice with
(offset, length), rather than (start, end), so the normal slicing syntax
is not very helpful. Rather than writing [a:a+b] everywhere I just
decided to pass the whole buffer and an offset to the read_u* helpers.

 scripts/gdb/linux/dmesg.py | 16 ++++++++++++----
 scripts/gdb/linux/utils.py | 25 +++++++++++++------------
 2 files changed, 25 insertions(+), 16 deletions(-)

diff --git a/scripts/gdb/linux/dmesg.py b/scripts/gdb/linux/dmesg.py
index 6d2e09a2ad2f..2fa7bb83885f 100644
--- a/scripts/gdb/linux/dmesg.py
+++ b/scripts/gdb/linux/dmesg.py
@@ -16,6 +16,8 @@ import sys
 
 from linux import utils
 
+printk_log_type = utils.CachedType("struct printk_log")
+
 
 class LxDmesg(gdb.Command):
     """Print Linux kernel log buffer."""
@@ -42,9 +44,14 @@ class LxDmesg(gdb.Command):
             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 + 8:pos + 10])
+            length = utils.read_u16(log_buf, pos + length_offset)
             if length == 0:
                 if log_buf_2nd_half == -1:
                     gdb.write("Corrupted log buffer!\n")
@@ -52,10 +59,11 @@ class LxDmesg(gdb.Command):
                 pos = log_buf_2nd_half
                 continue
 
-            text_len = utils.read_u16(log_buf[pos + 10:pos + 12])
-            text = log_buf[pos + 16:pos + 16 + text_len].decode(
+            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:pos + 8])
+            time_stamp = utils.read_u64(log_buf, pos + time_stamp_offset)
 
             for line in text.splitlines():
                 msg = u"[{time:12.6f}] {line}\n".format(
diff --git a/scripts/gdb/linux/utils.py b/scripts/gdb/linux/utils.py
index bc67126118c4..ea94221dbd39 100644
--- a/scripts/gdb/linux/utils.py
+++ b/scripts/gdb/linux/utils.py
@@ -92,15 +92,16 @@ def read_memoryview(inf, start, length):
     return memoryview(inf.read_memory(start, length))
 
 
-def read_u16(buffer):
+def read_u16(buffer, offset):
+    buffer_val = buffer[offset:offset + 2]
     value = [0, 0]
 
-    if type(buffer[0]) is str:
-        value[0] = ord(buffer[0])
-        value[1] = ord(buffer[1])
+    if type(buffer_val[0]) is str:
+        value[0] = ord(buffer_val[0])
+        value[1] = ord(buffer_val[1])
     else:
-        value[0] = buffer[0]
-        value[1] = buffer[1]
+        value[0] = buffer_val[0]
+        value[1] = buffer_val[1]
 
     if get_target_endianness() == LITTLE_ENDIAN:
         return value[0] + (value[1] << 8)
@@ -108,18 +109,18 @@ def read_u16(buffer):
         return value[1] + (value[0] << 8)
 
 
-def read_u32(buffer):
+def read_u32(buffer, offset):
     if get_target_endianness() == LITTLE_ENDIAN:
-        return read_u16(buffer[0:2]) + (read_u16(buffer[2:4]) << 16)
+        return read_u16(buffer, offset) + (read_u16(buffer, offset + 2) << 16)
     else:
-        return read_u16(buffer[2:4]) + (read_u16(buffer[0:2]) << 16)
+        return read_u16(buffer, offset + 2) + (read_u16(buffer, offset) << 16)
 
 
-def read_u64(buffer):
+def read_u64(buffer, offset):
     if get_target_endianness() == LITTLE_ENDIAN:
-        return read_u32(buffer[0:4]) + (read_u32(buffer[4:8]) << 32)
+        return read_u32(buffer, offset) + (read_u32(buffer, offset + 4) << 32)
     else:
-        return read_u32(buffer[4:8]) + (read_u32(buffer[0:4]) << 32)
+        return read_u32(buffer, offset + 4) + (read_u32(buffer, offset) << 32)
 
 
 target_arch = None
-- 
2.17.1

Re: [PATCH v3] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set

[Jan Kiszka]

On 11.10.19 16:25, Joel Colledge wrote:
> When CONFIG_PRINTK_CALLER is set, struct printk_log contains an
> additional member caller_id. This affects the offset of the log text.
> Account for this by using the type information from gdb to determine all
> the offsets instead of using hardcoded values.
> 
> This fixes following error:
> 
>    (gdb) lx-dmesg
>    Python Exception <class 'ValueError'> embedded null character:
>    Error occurred in Python command: embedded null character
> 
> The read_u* utility functions now take an offset argument to make them
> easier to use.
> 
> Signed-off-by: Joel Colledge <joel.colledge@linbit.com>
> ---
> Changes in v3:
> - fix some overlong lines and generally make the code more readable by
>    pushing the slicing down into the read_u* helper functions
> 
> In general, I would consider slicing to be more "pythonic" than passing
> around offsets. However, in this case we always want to slice with
> (offset, length), rather than (start, end), so the normal slicing syntax
> is not very helpful. Rather than writing [a:a+b] everywhere I just
> decided to pass the whole buffer and an offset to the read_u* helpers.

Agreed.

> 
>   scripts/gdb/linux/dmesg.py | 16 ++++++++++++----
>   scripts/gdb/linux/utils.py | 25 +++++++++++++------------
>   2 files changed, 25 insertions(+), 16 deletions(-)
> 
> diff --git a/scripts/gdb/linux/dmesg.py b/scripts/gdb/linux/dmesg.py
> index 6d2e09a2ad2f..2fa7bb83885f 100644
> --- a/scripts/gdb/linux/dmesg.py
> +++ b/scripts/gdb/linux/dmesg.py
> @@ -16,6 +16,8 @@ import sys
>   
>   from linux import utils
>   
> +printk_log_type = utils.CachedType("struct printk_log")
> +
>   
>   class LxDmesg(gdb.Command):
>       """Print Linux kernel log buffer."""
> @@ -42,9 +44,14 @@ class LxDmesg(gdb.Command):
>               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 + 8:pos + 10])
> +            length = utils.read_u16(log_buf, pos + length_offset)
>               if length == 0:
>                   if log_buf_2nd_half == -1:
>                       gdb.write("Corrupted log buffer!\n")
> @@ -52,10 +59,11 @@ class LxDmesg(gdb.Command):
>                   pos = log_buf_2nd_half
>                   continue
>   
> -            text_len = utils.read_u16(log_buf[pos + 10:pos + 12])
> -            text = log_buf[pos + 16:pos + 16 + text_len].decode(
> +            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:pos + 8])
> +            time_stamp = utils.read_u64(log_buf, pos + time_stamp_offset)
>   
>               for line in text.splitlines():
>                   msg = u"[{time:12.6f}] {line}\n".format(
> diff --git a/scripts/gdb/linux/utils.py b/scripts/gdb/linux/utils.py
> index bc67126118c4..ea94221dbd39 100644
> --- a/scripts/gdb/linux/utils.py
> +++ b/scripts/gdb/linux/utils.py
> @@ -92,15 +92,16 @@ def read_memoryview(inf, start, length):
>       return memoryview(inf.read_memory(start, length))
>   
>   
> -def read_u16(buffer):
> +def read_u16(buffer, offset):
> +    buffer_val = buffer[offset:offset + 2]
>       value = [0, 0]
>   
> -    if type(buffer[0]) is str:
> -        value[0] = ord(buffer[0])
> -        value[1] = ord(buffer[1])
> +    if type(buffer_val[0]) is str:
> +        value[0] = ord(buffer_val[0])
> +        value[1] = ord(buffer_val[1])
>       else:
> -        value[0] = buffer[0]
> -        value[1] = buffer[1]
> +        value[0] = buffer_val[0]
> +        value[1] = buffer_val[1]
>   
>       if get_target_endianness() == LITTLE_ENDIAN:
>           return value[0] + (value[1] << 8)
> @@ -108,18 +109,18 @@ def read_u16(buffer):
>           return value[1] + (value[0] << 8)
>   
>   
> -def read_u32(buffer):
> +def read_u32(buffer, offset):
>       if get_target_endianness() == LITTLE_ENDIAN:
> -        return read_u16(buffer[0:2]) + (read_u16(buffer[2:4]) << 16)
> +        return read_u16(buffer, offset) + (read_u16(buffer, offset + 2) << 16)
>       else:
> -        return read_u16(buffer[2:4]) + (read_u16(buffer[0:2]) << 16)
> +        return read_u16(buffer, offset + 2) + (read_u16(buffer, offset) << 16)
>   
>   
> -def read_u64(buffer):
> +def read_u64(buffer, offset):
>       if get_target_endianness() == LITTLE_ENDIAN:
> -        return read_u32(buffer[0:4]) + (read_u32(buffer[4:8]) << 32)
> +        return read_u32(buffer, offset) + (read_u32(buffer, offset + 4) << 32)
>       else:
> -        return read_u32(buffer[4:8]) + (read_u32(buffer[0:4]) << 32)
> +        return read_u32(buffer, offset + 4) + (read_u32(buffer, offset) << 32)
>   
>   
>   target_arch = None
> 

Reviewed-by: Jan Kiszka <jan.kiszka@siemens.com>

Jan

-- 
Siemens AG, Corporate Technology, CT RDA IOT SES-DE
Corporate Competence Center Embedded Linux