asm-generic/io: Add _RET_IP_ to MMIO trace for more accurate debug info

Due to compiler optimizations like inlining, there are cases where
MMIO traces using _THIS_IP_ for caller information might not be
sufficient to provide accurate debug traces.

1) With optimizations (Seen with GCC):

In this case, _THIS_IP_ works fine and prints the caller information
since it will be inlined into the caller and we get the debug traces
on who made the MMIO access, for ex:

rwmmio_read: qcom_smmu_tlb_sync+0xe0/0x1b0 width=32 addr=0xffff8000087447f4
rwmmio_post_read: qcom_smmu_tlb_sync+0xe0/0x1b0 width=32 val=0x0 addr=0xffff8000087447f4

2) Without optimizations (Seen with Clang):

_THIS_IP_ will not be sufficient in this case as it will print only
the MMIO accessors itself which is of not much use since it is not
inlined as below for example:

rwmmio_read: readl+0x4/0x80 width=32 addr=0xffff8000087447f4
rwmmio_post_read: readl+0x48/0x80 width=32 val=0x4 addr=0xffff8000087447f4

So in order to handle this second case as well irrespective of the compiler
optimizations, add _RET_IP_ to MMIO trace to make it provide more accurate
debug information in all these scenarios.

Before:

rwmmio_read: readl+0x4/0x80 width=32 addr=0xffff8000087447f4
rwmmio_post_read: readl+0x48/0x80 width=32 val=0x4 addr=0xffff8000087447f4

After:

rwmmio_read: qcom_smmu_tlb_sync+0xe0/0x1b0 -> readl+0x4/0x80 width=32 addr=0xffff8000087447f4
rwmmio_post_read: qcom_smmu_tlb_sync+0xe0/0x1b0 -> readl+0x4/0x80 width=32 val=0x0 addr=0xffff8000087447f4

Fixes: 210031971cdd ("asm-generic/io: Add logging support for MMIO accessors")
Signed-off-by: Sai Prakash Ranjan <[email protected]>
Signed-off-by: Arnd Bergmann <[email protected]>

diff --git a/include/asm-generic/io.h b/include/asm-generic/io.h
index a68f8fbf423bea0e0e8c13c2fc6b2aa1d81a6bf8..4c44a29b5e8ef0e06d4af08e0ea4560e68fce6cf 100644 (file)
--- a/include/asm-generic/io.h
+++ b/include/asm-generic/io.h
@@ -80,24 +80,24 @@ DECLARE_TRACEPOINT(rwmmio_read);
 DECLARE_TRACEPOINT(rwmmio_post_read);
 
 void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr,
-                   unsigned long caller_addr);
+                   unsigned long caller_addr, unsigned long caller_addr0);
 void log_post_write_mmio(u64 val, u8 width, volatile void __iomem *addr,
-                        unsigned long caller_addr);
+                        unsigned long caller_addr, unsigned long caller_addr0);
 void log_read_mmio(u8 width, const volatile void __iomem *addr,
-                  unsigned long caller_addr);
+                  unsigned long caller_addr, unsigned long caller_addr0);
 void log_post_read_mmio(u64 val, u8 width, const volatile void __iomem *addr,
-                       unsigned long caller_addr);
+                       unsigned long caller_addr, unsigned long caller_addr0);
 
 #else
 
 static inline void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr,
-                                 unsigned long caller_addr) {}
+                                 unsigned long caller_addr, unsigned long caller_addr0) {}
 static inline void log_post_write_mmio(u64 val, u8 width, volatile void __iomem *addr,
-                                      unsigned long caller_addr) {}
+                                      unsigned long caller_addr, unsigned long caller_addr0) {}
 static inline void log_read_mmio(u8 width, const volatile void __iomem *addr,
-                                unsigned long caller_addr) {}
+                                unsigned long caller_addr, unsigned long caller_addr0) {}
 static inline void log_post_read_mmio(u64 val, u8 width, const volatile void __iomem *addr,
-                                     unsigned long caller_addr) {}
+                                     unsigned long caller_addr, unsigned long caller_addr0) {}
 
 #endif /* CONFIG_TRACE_MMIO_ACCESS */
 
@@ -188,11 +188,11 @@ static inline u8 readb(const volatile void __iomem *addr)
 {
        u8 val;
 
-       log_read_mmio(8, addr, _THIS_IP_);
+       log_read_mmio(8, addr, _THIS_IP_, _RET_IP_);
        __io_br();
        val = __raw_readb(addr);
        __io_ar(val);
-       log_post_read_mmio(val, 8, addr, _THIS_IP_);
+       log_post_read_mmio(val, 8, addr, _THIS_IP_, _RET_IP_);
        return val;
 }
 #endif
@@ -203,11 +203,11 @@ static inline u16 readw(const volatile void __iomem *addr)
 {
        u16 val;
 
-       log_read_mmio(16, addr, _THIS_IP_);
+       log_read_mmio(16, addr, _THIS_IP_, _RET_IP_);
        __io_br();
        val = __le16_to_cpu((__le16 __force)__raw_readw(addr));
        __io_ar(val);
-       log_post_read_mmio(val, 16, addr, _THIS_IP_);
+       log_post_read_mmio(val, 16, addr, _THIS_IP_, _RET_IP_);
        return val;
 }
 #endif
@@ -218,11 +218,11 @@ static inline u32 readl(const volatile void __iomem *addr)
 {
        u32 val;
 
-       log_read_mmio(32, addr, _THIS_IP_);
+       log_read_mmio(32, addr, _THIS_IP_, _RET_IP_);
        __io_br();
        val = __le32_to_cpu((__le32 __force)__raw_readl(addr));
        __io_ar(val);
-       log_post_read_mmio(val, 32, addr, _THIS_IP_);
+       log_post_read_mmio(val, 32, addr, _THIS_IP_, _RET_IP_);
        return val;
 }
 #endif
@@ -234,11 +234,11 @@ static inline u64 readq(const volatile void __iomem *addr)
 {
        u64 val;
 
-       log_read_mmio(64, addr, _THIS_IP_);
+       log_read_mmio(64, addr, _THIS_IP_, _RET_IP_);
        __io_br();
        val = __le64_to_cpu(__raw_readq(addr));
        __io_ar(val);
-       log_post_read_mmio(val, 64, addr, _THIS_IP_);
+       log_post_read_mmio(val, 64, addr, _THIS_IP_, _RET_IP_);
        return val;
 }
 #endif
@@ -248,11 +248,11 @@ static inline u64 readq(const volatile void __iomem *addr)
 #define writeb writeb
 static inline void writeb(u8 value, volatile void __iomem *addr)
 {
-       log_write_mmio(value, 8, addr, _THIS_IP_);
+       log_write_mmio(value, 8, addr, _THIS_IP_, _RET_IP_);
        __io_bw();
        __raw_writeb(value, addr);
        __io_aw();
-       log_post_write_mmio(value, 8, addr, _THIS_IP_);
+       log_post_write_mmio(value, 8, addr, _THIS_IP_, _RET_IP_);
 }
 #endif
 
@@ -260,11 +260,11 @@ static inline void writeb(u8 value, volatile void __iomem *addr)
 #define writew writew
 static inline void writew(u16 value, volatile void __iomem *addr)
 {
-       log_write_mmio(value, 16, addr, _THIS_IP_);
+       log_write_mmio(value, 16, addr, _THIS_IP_, _RET_IP_);
        __io_bw();
        __raw_writew((u16 __force)cpu_to_le16(value), addr);
        __io_aw();
-       log_post_write_mmio(value, 16, addr, _THIS_IP_);
+       log_post_write_mmio(value, 16, addr, _THIS_IP_, _RET_IP_);
 }
 #endif
 
@@ -272,11 +272,11 @@ static inline void writew(u16 value, volatile void __iomem *addr)
 #define writel writel
 static inline void writel(u32 value, volatile void __iomem *addr)
 {
-       log_write_mmio(value, 32, addr, _THIS_IP_);
+       log_write_mmio(value, 32, addr, _THIS_IP_, _RET_IP_);
        __io_bw();
        __raw_writel((u32 __force)__cpu_to_le32(value), addr);
        __io_aw();
-       log_post_write_mmio(value, 32, addr, _THIS_IP_);
+       log_post_write_mmio(value, 32, addr, _THIS_IP_, _RET_IP_);
 }
 #endif
 
@@ -285,11 +285,11 @@ static inline void writel(u32 value, volatile void __iomem *addr)
 #define writeq writeq
 static inline void writeq(u64 value, volatile void __iomem *addr)
 {
-       log_write_mmio(value, 64, addr, _THIS_IP_);
+       log_write_mmio(value, 64, addr, _THIS_IP_, _RET_IP_);
        __io_bw();
        __raw_writeq(__cpu_to_le64(value), addr);
        __io_aw();
-       log_post_write_mmio(value, 64, addr, _THIS_IP_);
+       log_post_write_mmio(value, 64, addr, _THIS_IP_, _RET_IP_);
 }
 #endif
 #endif /* CONFIG_64BIT */
@@ -305,9 +305,9 @@ static inline u8 readb_relaxed(const volatile void __iomem *addr)
 {
        u8 val;
 
-       log_read_mmio(8, addr, _THIS_IP_);
+       log_read_mmio(8, addr, _THIS_IP_, _RET_IP_);
        val = __raw_readb(addr);
-       log_post_read_mmio(val, 8, addr, _THIS_IP_);
+       log_post_read_mmio(val, 8, addr, _THIS_IP_, _RET_IP_);
        return val;
 }
 #endif
@@ -318,9 +318,9 @@ static inline u16 readw_relaxed(const volatile void __iomem *addr)
 {
        u16 val;
 
-       log_read_mmio(16, addr, _THIS_IP_);
+       log_read_mmio(16, addr, _THIS_IP_, _RET_IP_);
        val = __le16_to_cpu(__raw_readw(addr));
-       log_post_read_mmio(val, 16, addr, _THIS_IP_);
+       log_post_read_mmio(val, 16, addr, _THIS_IP_, _RET_IP_);
        return val;
 }
 #endif
@@ -331,9 +331,9 @@ static inline u32 readl_relaxed(const volatile void __iomem *addr)
 {
        u32 val;
 
-       log_read_mmio(32, addr, _THIS_IP_);
+       log_read_mmio(32, addr, _THIS_IP_, _RET_IP_);
        val = __le32_to_cpu(__raw_readl(addr));
-       log_post_read_mmio(val, 32, addr, _THIS_IP_);
+       log_post_read_mmio(val, 32, addr, _THIS_IP_, _RET_IP_);
        return val;
 }
 #endif
@@ -344,9 +344,9 @@ static inline u64 readq_relaxed(const volatile void __iomem *addr)
 {
        u64 val;
 
-       log_read_mmio(64, addr, _THIS_IP_);
+       log_read_mmio(64, addr, _THIS_IP_, _RET_IP_);
        val = __le64_to_cpu(__raw_readq(addr));
-       log_post_read_mmio(val, 64, addr, _THIS_IP_);
+       log_post_read_mmio(val, 64, addr, _THIS_IP_, _RET_IP_);
        return val;
 }
 #endif
@@ -355,9 +355,9 @@ static inline u64 readq_relaxed(const volatile void __iomem *addr)
 #define writeb_relaxed writeb_relaxed
 static inline void writeb_relaxed(u8 value, volatile void __iomem *addr)
 {
-       log_write_mmio(value, 8, addr, _THIS_IP_);
+       log_write_mmio(value, 8, addr, _THIS_IP_, _RET_IP_);
        __raw_writeb(value, addr);
-       log_post_write_mmio(value, 8, addr, _THIS_IP_);
+       log_post_write_mmio(value, 8, addr, _THIS_IP_, _RET_IP_);
 }
 #endif
 
@@ -365,9 +365,9 @@ static inline void writeb_relaxed(u8 value, volatile void __iomem *addr)
 #define writew_relaxed writew_relaxed
 static inline void writew_relaxed(u16 value, volatile void __iomem *addr)
 {
-       log_write_mmio(value, 16, addr, _THIS_IP_);
+       log_write_mmio(value, 16, addr, _THIS_IP_, _RET_IP_);
        __raw_writew(cpu_to_le16(value), addr);
-       log_post_write_mmio(value, 16, addr, _THIS_IP_);
+       log_post_write_mmio(value, 16, addr, _THIS_IP_, _RET_IP_);
 }
 #endif
 
@@ -375,9 +375,9 @@ static inline void writew_relaxed(u16 value, volatile void __iomem *addr)
 #define writel_relaxed writel_relaxed
 static inline void writel_relaxed(u32 value, volatile void __iomem *addr)
 {
-       log_write_mmio(value, 32, addr, _THIS_IP_);
+       log_write_mmio(value, 32, addr, _THIS_IP_, _RET_IP_);
        __raw_writel(__cpu_to_le32(value), addr);
-       log_post_write_mmio(value, 32, addr, _THIS_IP_);
+       log_post_write_mmio(value, 32, addr, _THIS_IP_, _RET_IP_);
 }
 #endif
 
@@ -385,9 +385,9 @@ static inline void writel_relaxed(u32 value, volatile void __iomem *addr)
 #define writeq_relaxed writeq_relaxed
 static inline void writeq_relaxed(u64 value, volatile void __iomem *addr)
 {
-       log_write_mmio(value, 64, addr, _THIS_IP_);
+       log_write_mmio(value, 64, addr, _THIS_IP_, _RET_IP_);
        __raw_writeq(__cpu_to_le64(value), addr);
-       log_post_write_mmio(value, 64, addr, _THIS_IP_);
+       log_post_write_mmio(value, 64, addr, _THIS_IP_, _RET_IP_);
 }
 #endif
 

diff --git a/include/trace/events/rwmmio.h b/include/trace/events/rwmmio.h
index de41159216c19f9eb3c4e6a4cbbcf00e63b104c3..a43e5dd7436b568366952821eba599a3b4d27864 100644 (file)
--- a/include/trace/events/rwmmio.h
+++ b/include/trace/events/rwmmio.h
@@ -12,12 +12,14 @@
 
 DECLARE_EVENT_CLASS(rwmmio_rw_template,
 
-       TP_PROTO(unsigned long caller, u64 val, u8 width, volatile void __iomem *addr),
+       TP_PROTO(unsigned long caller, unsigned long caller0, u64 val, u8 width,
+                volatile void __iomem *addr),
 
-       TP_ARGS(caller, val, width, addr),
+       TP_ARGS(caller, caller0, val, width, addr),
 
        TP_STRUCT__entry(
                __field(unsigned long, caller)
+               __field(unsigned long, caller0)
                __field(unsigned long, addr)
                __field(u64, val)
                __field(u8, width)
@@ -25,56 +27,64 @@ DECLARE_EVENT_CLASS(rwmmio_rw_template,
 
        TP_fast_assign(
                __entry->caller = caller;
+               __entry->caller0 = caller0;
                __entry->val = val;
                __entry->addr = (unsigned long)addr;
                __entry->width = width;
        ),
 
-       TP_printk("%pS width=%d val=%#llx addr=%#lx",
-               (void *)__entry->caller, __entry->width,
+       TP_printk("%pS -> %pS width=%d val=%#llx addr=%#lx",
+               (void *)__entry->caller0, (void *)__entry->caller, __entry->width,
                __entry->val, __entry->addr)
 );
 
 DEFINE_EVENT(rwmmio_rw_template, rwmmio_write,
-       TP_PROTO(unsigned long caller, u64 val, u8 width, volatile void __iomem *addr),
-       TP_ARGS(caller, val, width, addr)
+       TP_PROTO(unsigned long caller, unsigned long caller0, u64 val, u8 width,
+                volatile void __iomem *addr),
+       TP_ARGS(caller, caller0, val, width, addr)
 );
 
 DEFINE_EVENT(rwmmio_rw_template, rwmmio_post_write,
-       TP_PROTO(unsigned long caller, u64 val, u8 width, volatile void __iomem *addr),
-       TP_ARGS(caller, val, width, addr)
+       TP_PROTO(unsigned long caller, unsigned long caller0, u64 val, u8 width,
+                volatile void __iomem *addr),
+       TP_ARGS(caller, caller0, val, width, addr)
 );
 
 TRACE_EVENT(rwmmio_read,
 
-       TP_PROTO(unsigned long caller, u8 width, const volatile void __iomem *addr),
+       TP_PROTO(unsigned long caller, unsigned long caller0, u8 width,
+                const volatile void __iomem *addr),
 
-       TP_ARGS(caller, width, addr),
+       TP_ARGS(caller, caller0, width, addr),
 
        TP_STRUCT__entry(
                __field(unsigned long, caller)
+               __field(unsigned long, caller0)
                __field(unsigned long, addr)
                __field(u8, width)
        ),
 
        TP_fast_assign(
                __entry->caller = caller;
+               __entry->caller0 = caller0;
                __entry->addr = (unsigned long)addr;
                __entry->width = width;
        ),
 
-       TP_printk("%pS width=%d addr=%#lx",
-                (void *)__entry->caller, __entry->width, __entry->addr)
+       TP_printk("%pS -> %pS width=%d addr=%#lx",
+                (void *)__entry->caller0, (void *)__entry->caller, __entry->width, __entry->addr)
 );
 
 TRACE_EVENT(rwmmio_post_read,
 
-       TP_PROTO(unsigned long caller, u64 val, u8 width, const volatile void __iomem *addr),
+       TP_PROTO(unsigned long caller, unsigned long caller0, u64 val, u8 width,
+                const volatile void __iomem *addr),
 
-       TP_ARGS(caller, val, width, addr),
+       TP_ARGS(caller, caller0, val, width, addr),
 
        TP_STRUCT__entry(
                __field(unsigned long, caller)
+               __field(unsigned long, caller0)
                __field(unsigned long, addr)
                __field(u64, val)
                __field(u8, width)
@@ -82,13 +92,14 @@ TRACE_EVENT(rwmmio_post_read,
 
        TP_fast_assign(
                __entry->caller = caller;
+               __entry->caller0 = caller0;
                __entry->val = val;
                __entry->addr = (unsigned long)addr;
                __entry->width = width;
        ),
 
-       TP_printk("%pS width=%d val=%#llx addr=%#lx",
-                (void *)__entry->caller, __entry->width,
+       TP_printk("%pS -> %pS width=%d val=%#llx addr=%#lx",
+                (void *)__entry->caller0, (void *)__entry->caller, __entry->width,
                 __entry->val, __entry->addr)
 );
 

diff --git a/lib/trace_readwrite.c b/lib/trace_readwrite.c
index 88637038b30c8e211f2ef3a0a0cb8868ee93e4bf..62b4e8b3c733b5240eff77fcc1f392e17c235960 100644 (file)
--- a/lib/trace_readwrite.c
+++ b/lib/trace_readwrite.c
@@ -14,33 +14,33 @@
 
 #ifdef CONFIG_TRACE_MMIO_ACCESS
 void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr,
-                   unsigned long caller_addr)
+                   unsigned long caller_addr, unsigned long caller_addr0)
 {
-       trace_rwmmio_write(caller_addr, val, width, addr);
+       trace_rwmmio_write(caller_addr, caller_addr0, val, width, addr);
 }
 EXPORT_SYMBOL_GPL(log_write_mmio);
 EXPORT_TRACEPOINT_SYMBOL_GPL(rwmmio_write);
 
 void log_post_write_mmio(u64 val, u8 width, volatile void __iomem *addr,
-                        unsigned long caller_addr)
+                        unsigned long caller_addr, unsigned long caller_addr0)
 {
-       trace_rwmmio_post_write(caller_addr, val, width, addr);
+       trace_rwmmio_post_write(caller_addr, caller_addr0, val, width, addr);
 }
 EXPORT_SYMBOL_GPL(log_post_write_mmio);
 EXPORT_TRACEPOINT_SYMBOL_GPL(rwmmio_post_write);
 
 void log_read_mmio(u8 width, const volatile void __iomem *addr,
-                  unsigned long caller_addr)
+                  unsigned long caller_addr, unsigned long caller_addr0)
 {
-       trace_rwmmio_read(caller_addr, width, addr);
+       trace_rwmmio_read(caller_addr, caller_addr0, width, addr);
 }
 EXPORT_SYMBOL_GPL(log_read_mmio);
 EXPORT_TRACEPOINT_SYMBOL_GPL(rwmmio_read);
 
 void log_post_read_mmio(u64 val, u8 width, const volatile void __iomem *addr,
-                       unsigned long caller_addr)
+                       unsigned long caller_addr, unsigned long caller_addr0)
 {
-       trace_rwmmio_post_read(caller_addr, val, width, addr);
+       trace_rwmmio_post_read(caller_addr, caller_addr0, val, width, addr);
 }
 EXPORT_SYMBOL_GPL(log_post_read_mmio);
 EXPORT_TRACEPOINT_SYMBOL_GPL(rwmmio_post_read);