* [PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set @ 2019-09-25 15:03 Joel Colledge 2019-10-10 14:51 ` Joel Colledge 2019-10-10 15:13 ` Jan Kiszka 0 siblings, 2 replies; 12+ messages in thread From: Joel Colledge @ 2019-09-25 15:03 UTC (permalink / raw) To: Jan Kiszka, Kieran Bingham; +Cc: linux-kernel, 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 ^ permalink raw reply related [flat|nested] 12+ messages in thread
* Re: [PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set 2019-09-25 15:03 [PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set Joel Colledge @ 2019-10-10 14:51 ` Joel Colledge 2019-10-10 15:13 ` Jan Kiszka 1 sibling, 0 replies; 12+ messages in thread From: Joel Colledge @ 2019-10-10 14:51 UTC (permalink / raw) To: Jan Kiszka, Kieran Bingham; +Cc: linux-kernel, leonard.crestez 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. ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set 2019-09-25 15:03 [PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set Joel Colledge 2019-10-10 14:51 ` Joel Colledge @ 2019-10-10 15:13 ` Jan Kiszka 2019-10-10 19:36 ` Leonard Crestez 1 sibling, 1 reply; 12+ messages in thread From: Jan Kiszka @ 2019-10-10 15:13 UTC (permalink / raw) To: Joel Colledge, Kieran Bingham, Andrew Morton; +Cc: linux-kernel 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 ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set 2019-10-10 15:13 ` Jan Kiszka @ 2019-10-10 19:36 ` Leonard Crestez 2019-10-11 12:24 ` [PATCH v2] " Joel Colledge 0 siblings, 1 reply; 12+ messages in thread From: Leonard Crestez @ 2019-10-10 19:36 UTC (permalink / raw) To: Jan Kiszka, Joel Colledge; +Cc: Kieran Bingham, Andrew Morton, linux-kernel 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 ^ permalink raw reply [flat|nested] 12+ messages in thread
* [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set 2019-10-10 19:36 ` Leonard Crestez @ 2019-10-11 12:24 ` Joel Colledge 2019-10-11 12:38 ` Jan Kiszka 2019-10-11 12:47 ` [PATCH v2] " Leonard Crestez 0 siblings, 2 replies; 12+ messages in thread From: Joel Colledge @ 2019-10-11 12:24 UTC (permalink / raw) Cc: Leonard Crestez, Joel Colledge, Jan Kiszka, Kieran Bingham, linux-kernel 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 ^ permalink raw reply related [flat|nested] 12+ messages in thread
* Re: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set 2019-10-11 12:24 ` [PATCH v2] " Joel Colledge @ 2019-10-11 12:38 ` Jan Kiszka 2019-10-11 12:56 ` Joel Colledge 2019-10-11 12:47 ` [PATCH v2] " Leonard Crestez 1 sibling, 1 reply; 12+ messages in thread From: Jan Kiszka @ 2019-10-11 12:38 UTC (permalink / raw) To: Joel Colledge; +Cc: Leonard Crestez, Kieran Bingham, linux-kernel 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 ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set 2019-10-11 12:38 ` Jan Kiszka @ 2019-10-11 12:56 ` Joel Colledge 2019-10-11 14:25 ` [PATCH v3] " Joel Colledge 0 siblings, 1 reply; 12+ messages in thread From: Joel Colledge @ 2019-10-11 12:56 UTC (permalink / raw) To: Jan Kiszka; +Cc: Leonard Crestez, Kieran Bingham, linux-kernel 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. ^ permalink raw reply [flat|nested] 12+ messages in thread
* [PATCH v3] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set 2019-10-11 12:56 ` Joel Colledge @ 2019-10-11 14:25 ` Joel Colledge 2019-10-11 15:41 ` Jan Kiszka 0 siblings, 1 reply; 12+ messages in thread From: Joel Colledge @ 2019-10-11 14:25 UTC (permalink / raw) Cc: Jan Kiszka, Kieran Bingham, Leonard Crestez, linux-kernel, 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 ^ permalink raw reply related [flat|nested] 12+ messages in thread
* Re: [PATCH v3] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set 2019-10-11 14:25 ` [PATCH v3] " Joel Colledge @ 2019-10-11 15:41 ` Jan Kiszka 0 siblings, 0 replies; 12+ messages in thread From: Jan Kiszka @ 2019-10-11 15:41 UTC (permalink / raw) To: Joel Colledge, Andrew Morton Cc: Kieran Bingham, Leonard Crestez, linux-kernel 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 ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set 2019-10-11 12:24 ` [PATCH v2] " Joel Colledge 2019-10-11 12:38 ` Jan Kiszka @ 2019-10-11 12:47 ` Leonard Crestez 2019-10-11 13:01 ` Joel Colledge 1 sibling, 1 reply; 12+ messages in thread From: Leonard Crestez @ 2019-10-11 12:47 UTC (permalink / raw) To: Joel Colledge, Jan Kiszka; +Cc: Kieran Bingham, linux-kernel 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( > ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set 2019-10-11 12:47 ` [PATCH v2] " Leonard Crestez @ 2019-10-11 13:01 ` Joel Colledge 2019-10-11 14:20 ` Leonard Crestez 0 siblings, 1 reply; 12+ messages in thread From: Joel Colledge @ 2019-10-11 13:01 UTC (permalink / raw) To: Leonard Crestez; +Cc: Jan Kiszka, Kieran Bingham, linux-kernel 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). ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set 2019-10-11 13:01 ` Joel Colledge @ 2019-10-11 14:20 ` Leonard Crestez 0 siblings, 0 replies; 12+ messages in thread From: Leonard Crestez @ 2019-10-11 14:20 UTC (permalink / raw) To: Joel Colledge; +Cc: Jan Kiszka, Kieran Bingham, linux-kernel 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 ^ permalink raw reply [flat|nested] 12+ messages in thread
end of thread, other threads:[~2019-10-11 15:41 UTC | newest] Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2019-09-25 15:03 [PATCH] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is set Joel Colledge 2019-10-10 14:51 ` Joel Colledge 2019-10-10 15:13 ` Jan Kiszka 2019-10-10 19:36 ` Leonard Crestez 2019-10-11 12:24 ` [PATCH v2] " Joel Colledge 2019-10-11 12:38 ` Jan Kiszka 2019-10-11 12:56 ` Joel Colledge 2019-10-11 14:25 ` [PATCH v3] " Joel Colledge 2019-10-11 15:41 ` Jan Kiszka 2019-10-11 12:47 ` [PATCH v2] " Leonard Crestez 2019-10-11 13:01 ` Joel Colledge 2019-10-11 14:20 ` Leonard Crestez
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.