Re: [PATCHv3 1/3] tracing: Add register read/write tracing support

[Steven Rostedt]

On Tue, 9 Nov 2021 17:38:19 +0530
Sai Prakash Ranjan <quic_saipraka@xxxxxxxxxxx> wrote:

> From: Prasad Sodagudi <psodagud@xxxxxxxxxxxxxx>
> 
> Generic MMIO read/write i.e., __raw_{read,write}{b,l,w,q} accessors
> are typically used to read/write from/to memory mapped registers
> and can cause hangs or some undefined behaviour in following few
> cases,
> 
> * If the access to the register space is unclocked, for example: if
>   there is an access to multimedia(MM) block registers without MM
>   clocks.
> 
> * If the register space is protected and not set to be accessible from
>   non-secure world, for example: only EL3 (EL: Exception level) access
>   is allowed and any EL2/EL1 access is forbidden.
> 
> * If xPU(memory/register protection units) is controlling access to
>   certain memory/register space for specific clients.
> 
> and more...
> 
> Such cases usually results in instant reboot/SErrors/NOC or interconnect
> hangs and tracing these register accesses can be very helpful to debug
> such issues during initial development stages and also in later stages.
> 
> So use ftrace trace events to log such MMIO register accesses which
> provides rich feature set such as early enablement of trace events,
> filtering capability, dumping ftrace logs on console and many more.
> 
> Sample output:
> 
> rwmmio_read: gic_peek_irq+0xd0/0xd8 readl addr=0xffff800010040104
> rwmmio_write: gic_poke_irq+0xe4/0xf0 writel addr=0xffff800010040184 val=0x40
> rwmmio_read: gic_do_wait_for_rwp+0x54/0x90 readl addr=0xffff800010040000
> rwmmio_write: gic_set_affinity+0x1bc/0x1e8 writeq addr=0xffff800010046130 val=0x500
> 
> Signed-off-by: Prasad Sodagudi <psodagud@xxxxxxxxxxxxxx>
> [saiprakash: Rewrote commit msg and trace event field edits]
> Signed-off-by: Sai Prakash Ranjan <quic_saipraka@xxxxxxxxxxx>
> ---
>  include/trace/events/rwmmio.h  | 61 ++++++++++++++++++++++++++++++++++
>  kernel/trace/Kconfig           |  7 ++++
>  kernel/trace/Makefile          |  1 +
>  kernel/trace/trace_readwrite.c | 28 ++++++++++++++++
>  4 files changed, 97 insertions(+)
>  create mode 100644 include/trace/events/rwmmio.h
>  create mode 100644 kernel/trace/trace_readwrite.c
> 
> diff --git a/include/trace/events/rwmmio.h b/include/trace/events/rwmmio.h
> new file mode 100644
> index 000000000000..cb5261a559f8
> --- /dev/null
> +++ b/include/trace/events/rwmmio.h
> @@ -0,0 +1,61 @@
> +/* SPDX-License-Identifier: GPL-2.0-only */
> +/*
> + * Copyright (c) 2021 Qualcomm Innovation Center, Inc. All rights reserved.
> + */
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM rwmmio
> +
> +#if !defined(_TRACE_MMIO_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_MMIO_H
> +
> +#include <linux/tracepoint.h>
> +
> +TRACE_EVENT(rwmmio_write,
> +
> +	TP_PROTO(unsigned long fn, const char *width, u64 val, volatile void __iomem *addr),
> +
> +	TP_ARGS(fn, width, val, addr),
> +
> +	TP_STRUCT__entry(
> +		__field(u64, fn)
> +		__string(width, width)
> +		__field(u64, val)
> +		__field(u64, addr)

For better space usage, move the __string to the end. Each of the u64
fields will take up 8 bytes, and the __string only takes up 4 (it's a 2
byte offset and 2 byte length, where the actual string lies at the end of
the event). Many archs will leave a 4 byte "hole" between the __string()
field and the u64 val field. If __string is at the end, it will go nicely
with the actual string that will be appended behind it.

> +	),
> +
> +	TP_fast_assign(
> +		__entry->fn = fn;
> +		__assign_str(width, width);
> +		__entry->val = val;
> +		__entry->addr = (u64)addr;
> +	),
> +
> +	TP_printk("%pS %s addr=%#llx val=%#llx",
> +		(void *)__entry->fn, __get_str(width), __entry->addr, __entry->val)
> +);
> +
> +TRACE_EVENT(rwmmio_read,
> +
> +	TP_PROTO(unsigned long fn, const char *width, const volatile void __iomem *addr),
> +
> +	TP_ARGS(fn, width, addr),
> +
> +	TP_STRUCT__entry(
> +		__field(u64, fn)
> +		__string(width, width)
> +		__field(u64, addr)

Same here.

> +	),
> +
> +	TP_fast_assign(
> +		__entry->fn = fn;
> +		__assign_str(width, width);
> +		__entry->addr = (u64)addr;
> +	),
> +
> +	TP_printk("%pS %s addr=%#llx",
> +		 (void *)__entry->fn, __get_str(width), __entry->addr)
> +);
> +

-- Steve