Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
From:   Leonard Crestez <leonard.crestez@nxp.com>
To:     Joel Colledge <joel.colledge@linbit.com>,
        Jan Kiszka <jan.kiszka@siemens.com>
CC:     Kieran Bingham <kbingham@kernel.org>,
        "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>
Subject: Re: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER is
 set
Thread-Topic: [PATCH v2] scripts/gdb: fix lx-dmesg when CONFIG_PRINTK_CALLER
 is set
Thread-Index: AQHVgC7oaoKGJTwDR023SeD0lnQ+JA==
Date:   Fri, 11 Oct 2019 12:47:26 +0000
Message-ID: <VI1PR04MB70239DA9EED5F689645071E9EE970@VI1PR04MB7023.eurprd04.prod.outlook.com>
References: <VI1PR04MB70236211F170522DD456553AEE940@VI1PR04MB7023.eurprd04.prod.outlook.com>
 <20191011122409.23868-1-joel.colledge@linbit.com>
Accept-Language: en-US
Content-Language: en-US
received-spf: None (protection.outlook.com: nxp.com does not designate
 permitted sender hosts)
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0
X-MS-Exchange-CrossTenant-Network-Message-Id: a9a37a02-6936-43bc-3e44-08d74e492bd7
X-MS-Exchange-CrossTenant-originalarrivaltime: 11 Oct 2019 12:47:26.9678
 (UTC)
X-MS-Exchange-CrossTenant-fromentityheader: Hosted
X-MS-Exchange-CrossTenant-id: 686ea1d3-bc2b-4c6f-a92c-d99c5c301635
X-MS-Exchange-CrossTenant-mailboxtype: HOSTED
X-MS-Exchange-CrossTenant-userprincipalname: TGSbM57Ge26Vm/qNxGU4eH7ZhPdtcouEh5YQlxN58VL3FQh4s3RCRq9w6KH/DOWzcsgeG/iIkgPkq7fHvr8qDQ==
X-MS-Exchange-Transport-CrossTenantHeadersStamped: VI1PR04MB3183
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

On 11.10.2019 15:25, Joel Colledge wrote:=0A=
> When CONFIG_PRINTK_CALLER is set, struct printk_log contains an=0A=
> additional member caller_id. This affects the offset of the log text.=0A=
> Account for this by using the type information from gdb to determine all=
=0A=
> the offsets instead of using hardcoded values.=0A=
> =0A=
> This fixes following error:=0A=
> =0A=
>    (gdb) lx-dmesg=0A=
>    Python Exception <class 'ValueError'> embedded null character:=0A=
>    Error occurred in Python command: embedded null character=0A=
> =0A=
> Signed-off-by: Joel Colledge <joel.colledge@linbit.com>=0A=
> ---=0A=
> Changes in v2:=0A=
> - use type information from gdb instead of hardcoded offsets=0A=
> =0A=
> 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 devel=
opment of the tool. Here is a version of the fix using offsets from gdb.=0A=
=0A=
This struct printk_log is quite small, I wonder if it's possible to do a =
=0A=
single read for each log entry? This might make lx-dmesg faster because =0A=
of fewer roundtrips to gdbserver and jtag (or whatever backend you're =0A=
using).=0A=
=0A=
> =0A=
>   scripts/gdb/linux/dmesg.py | 16 ++++++++++++----=0A=
>   1 file changed, 12 insertions(+), 4 deletions(-)=0A=
> =0A=
> diff --git a/scripts/gdb/linux/dmesg.py b/scripts/gdb/linux/dmesg.py=0A=
> index 6d2e09a2ad2f..8f5d899029b7 100644=0A=
> --- a/scripts/gdb/linux/dmesg.py=0A=
> +++ b/scripts/gdb/linux/dmesg.py=0A=
> @@ -16,6 +16,8 @@ import sys=0A=
>   =0A=
>   from linux import utils=0A=
>   =0A=
> +printk_log_type =3D utils.CachedType("struct printk_log")=0A=
> +=0A=
>   =0A=
>   class LxDmesg(gdb.Command):=0A=
>       """Print Linux kernel log buffer."""=0A=
> @@ -42,9 +44,14 @@ class LxDmesg(gdb.Command):=0A=
>               b =3D utils.read_memoryview(inf, log_buf_addr, log_next_idx=
)=0A=
>               log_buf =3D a.tobytes() + b.tobytes()=0A=
>   =0A=
> +        length_offset =3D printk_log_type.get_type()['len'].bitpos // 8=
=0A=
> +        text_len_offset =3D printk_log_type.get_type()['text_len'].bitpo=
s // 8=0A=
> +        time_stamp_offset =3D printk_log_type.get_type()['ts_nsec'].bitp=
os // 8=0A=
> +        text_offset =3D printk_log_type.get_type().sizeof=0A=
> +=0A=
>           pos =3D 0=0A=
>           while pos < log_buf.__len__():=0A=
> -            length =3D utils.read_u16(log_buf[pos + 8:pos + 10])=0A=
> +            length =3D utils.read_u16(log_buf[pos + length_offset:pos + =
length_offset + 2])=0A=
>               if length =3D=3D 0:=0A=
>                   if log_buf_2nd_half =3D=3D -1:=0A=
>                       gdb.write("Corrupted log buffer!\n")=0A=
> @@ -52,10 +59,11 @@ class LxDmesg(gdb.Command):=0A=
>                   pos =3D log_buf_2nd_half=0A=
>                   continue=0A=
>   =0A=
> -            text_len =3D utils.read_u16(log_buf[pos + 10:pos + 12])=0A=
> -            text =3D log_buf[pos + 16:pos + 16 + text_len].decode(=0A=
> +            text_len =3D utils.read_u16(log_buf[pos + text_len_offset:po=
s + text_len_offset + 2])=0A=
> +            text =3D log_buf[pos + text_offset:pos + text_offset + text_=
len].decode(=0A=
>                   encoding=3D'utf8', errors=3D'replace')=0A=
> -            time_stamp =3D utils.read_u64(log_buf[pos:pos + 8])=0A=
> +            time_stamp =3D utils.read_u64(=0A=
> +                log_buf[pos + time_stamp_offset:pos + time_stamp_offset =
+ 8])=0A=
>   =0A=
>               for line in text.splitlines():=0A=
>                   msg =3D u"[{time:12.6f}] {line}\n".format(=0A=
> =0A=
=0A=