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

From: Sai Prakash Ranjan
Date: Tue Nov 09 2021 - 09:12:49 EST


Hi Steve,

On 11/9/2021 7:24 PM, Steven Rostedt wrote:
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.

Thanks for the informative suggestion, will make the change for the next version.


+ ),
+
+ 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.

Sure, will make the change.


+ ),
+
+ 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

Thanks,

Sai