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

Linux kernel mirror (for testing) git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git

kernel os linux

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 <quic_saipraka@quicinc.com>
Signed-off-by: Arnd Bergmann <arnd@arndb.de>

authored by

Sai Prakash Ranjan and committed by

Arnd Bergmann 3 years ago 5e5ff73c defbab27

+75 -64

3 changed files

expand all

include

asm-generic

io.h

trace

events

rwmmio.h

lib

trace_readwrite.c

+40 -40

include/asm-generic/io.h

··· 80 80 DECLARE_TRACEPOINT(rwmmio_post_read); 81 81 82 82 void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr, 83 - unsigned long caller_addr); 83 + unsigned long caller_addr, unsigned long caller_addr0); 84 84 void log_post_write_mmio(u64 val, u8 width, volatile void __iomem *addr, 85 - unsigned long caller_addr); 85 + unsigned long caller_addr, unsigned long caller_addr0); 86 86 void log_read_mmio(u8 width, const volatile void __iomem *addr, 87 - unsigned long caller_addr); 87 + unsigned long caller_addr, unsigned long caller_addr0); 88 88 void log_post_read_mmio(u64 val, u8 width, const volatile void __iomem *addr, 89 - unsigned long caller_addr); 89 + unsigned long caller_addr, unsigned long caller_addr0); 90 90 91 91 #else 92 92 93 93 static inline void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr, 94 - unsigned long caller_addr) {} 94 + unsigned long caller_addr, unsigned long caller_addr0) {} 95 95 static inline void log_post_write_mmio(u64 val, u8 width, volatile void __iomem *addr, 96 - unsigned long caller_addr) {} 96 + unsigned long caller_addr, unsigned long caller_addr0) {} 97 97 static inline void log_read_mmio(u8 width, const volatile void __iomem *addr, 98 - unsigned long caller_addr) {} 98 + unsigned long caller_addr, unsigned long caller_addr0) {} 99 99 static inline void log_post_read_mmio(u64 val, u8 width, const volatile void __iomem *addr, 100 - unsigned long caller_addr) {} 100 + unsigned long caller_addr, unsigned long caller_addr0) {} 101 101 102 102 #endif /* CONFIG_TRACE_MMIO_ACCESS */ 103 103 ··· 188 188 { 189 189 u8 val; 190 190 191 - log_read_mmio(8, addr, _THIS_IP_); 191 + log_read_mmio(8, addr, _THIS_IP_, _RET_IP_); 192 192 __io_br(); 193 193 val = __raw_readb(addr); 194 194 __io_ar(val); 195 - log_post_read_mmio(val, 8, addr, _THIS_IP_); 195 + log_post_read_mmio(val, 8, addr, _THIS_IP_, _RET_IP_); 196 196 return val; 197 197 } 198 198 #endif ··· 203 203 { 204 204 u16 val; 205 205 206 - log_read_mmio(16, addr, _THIS_IP_); 206 + log_read_mmio(16, addr, _THIS_IP_, _RET_IP_); 207 207 __io_br(); 208 208 val = __le16_to_cpu((__le16 __force)__raw_readw(addr)); 209 209 __io_ar(val); 210 - log_post_read_mmio(val, 16, addr, _THIS_IP_); 210 + log_post_read_mmio(val, 16, addr, _THIS_IP_, _RET_IP_); 211 211 return val; 212 212 } 213 213 #endif ··· 218 218 { 219 219 u32 val; 220 220 221 - log_read_mmio(32, addr, _THIS_IP_); 221 + log_read_mmio(32, addr, _THIS_IP_, _RET_IP_); 222 222 __io_br(); 223 223 val = __le32_to_cpu((__le32 __force)__raw_readl(addr)); 224 224 __io_ar(val); 225 - log_post_read_mmio(val, 32, addr, _THIS_IP_); 225 + log_post_read_mmio(val, 32, addr, _THIS_IP_, _RET_IP_); 226 226 return val; 227 227 } 228 228 #endif ··· 234 234 { 235 235 u64 val; 236 236 237 - log_read_mmio(64, addr, _THIS_IP_); 237 + log_read_mmio(64, addr, _THIS_IP_, _RET_IP_); 238 238 __io_br(); 239 239 val = __le64_to_cpu(__raw_readq(addr)); 240 240 __io_ar(val); 241 - log_post_read_mmio(val, 64, addr, _THIS_IP_); 241 + log_post_read_mmio(val, 64, addr, _THIS_IP_, _RET_IP_); 242 242 return val; 243 243 } 244 244 #endif ··· 248 248 #define writeb writeb 249 249 static inline void writeb(u8 value, volatile void __iomem *addr) 250 250 { 251 - log_write_mmio(value, 8, addr, _THIS_IP_); 251 + log_write_mmio(value, 8, addr, _THIS_IP_, _RET_IP_); 252 252 __io_bw(); 253 253 __raw_writeb(value, addr); 254 254 __io_aw(); 255 - log_post_write_mmio(value, 8, addr, _THIS_IP_); 255 + log_post_write_mmio(value, 8, addr, _THIS_IP_, _RET_IP_); 256 256 } 257 257 #endif 258 258 ··· 260 260 #define writew writew 261 261 static inline void writew(u16 value, volatile void __iomem *addr) 262 262 { 263 - log_write_mmio(value, 16, addr, _THIS_IP_); 263 + log_write_mmio(value, 16, addr, _THIS_IP_, _RET_IP_); 264 264 __io_bw(); 265 265 __raw_writew((u16 __force)cpu_to_le16(value), addr); 266 266 __io_aw(); 267 - log_post_write_mmio(value, 16, addr, _THIS_IP_); 267 + log_post_write_mmio(value, 16, addr, _THIS_IP_, _RET_IP_); 268 268 } 269 269 #endif 270 270 ··· 272 272 #define writel writel 273 273 static inline void writel(u32 value, volatile void __iomem *addr) 274 274 { 275 - log_write_mmio(value, 32, addr, _THIS_IP_); 275 + log_write_mmio(value, 32, addr, _THIS_IP_, _RET_IP_); 276 276 __io_bw(); 277 277 __raw_writel((u32 __force)__cpu_to_le32(value), addr); 278 278 __io_aw(); 279 - log_post_write_mmio(value, 32, addr, _THIS_IP_); 279 + log_post_write_mmio(value, 32, addr, _THIS_IP_, _RET_IP_); 280 280 } 281 281 #endif 282 282 ··· 285 285 #define writeq writeq 286 286 static inline void writeq(u64 value, volatile void __iomem *addr) 287 287 { 288 - log_write_mmio(value, 64, addr, _THIS_IP_); 288 + log_write_mmio(value, 64, addr, _THIS_IP_, _RET_IP_); 289 289 __io_bw(); 290 290 __raw_writeq(__cpu_to_le64(value), addr); 291 291 __io_aw(); 292 - log_post_write_mmio(value, 64, addr, _THIS_IP_); 292 + log_post_write_mmio(value, 64, addr, _THIS_IP_, _RET_IP_); 293 293 } 294 294 #endif 295 295 #endif /* CONFIG_64BIT */ ··· 305 305 { 306 306 u8 val; 307 307 308 - log_read_mmio(8, addr, _THIS_IP_); 308 + log_read_mmio(8, addr, _THIS_IP_, _RET_IP_); 309 309 val = __raw_readb(addr); 310 - log_post_read_mmio(val, 8, addr, _THIS_IP_); 310 + log_post_read_mmio(val, 8, addr, _THIS_IP_, _RET_IP_); 311 311 return val; 312 312 } 313 313 #endif ··· 318 318 { 319 319 u16 val; 320 320 321 - log_read_mmio(16, addr, _THIS_IP_); 321 + log_read_mmio(16, addr, _THIS_IP_, _RET_IP_); 322 322 val = __le16_to_cpu(__raw_readw(addr)); 323 - log_post_read_mmio(val, 16, addr, _THIS_IP_); 323 + log_post_read_mmio(val, 16, addr, _THIS_IP_, _RET_IP_); 324 324 return val; 325 325 } 326 326 #endif ··· 331 331 { 332 332 u32 val; 333 333 334 - log_read_mmio(32, addr, _THIS_IP_); 334 + log_read_mmio(32, addr, _THIS_IP_, _RET_IP_); 335 335 val = __le32_to_cpu(__raw_readl(addr)); 336 - log_post_read_mmio(val, 32, addr, _THIS_IP_); 336 + log_post_read_mmio(val, 32, addr, _THIS_IP_, _RET_IP_); 337 337 return val; 338 338 } 339 339 #endif ··· 344 344 { 345 345 u64 val; 346 346 347 - log_read_mmio(64, addr, _THIS_IP_); 347 + log_read_mmio(64, addr, _THIS_IP_, _RET_IP_); 348 348 val = __le64_to_cpu(__raw_readq(addr)); 349 - log_post_read_mmio(val, 64, addr, _THIS_IP_); 349 + log_post_read_mmio(val, 64, addr, _THIS_IP_, _RET_IP_); 350 350 return val; 351 351 } 352 352 #endif ··· 355 355 #define writeb_relaxed writeb_relaxed 356 356 static inline void writeb_relaxed(u8 value, volatile void __iomem *addr) 357 357 { 358 - log_write_mmio(value, 8, addr, _THIS_IP_); 358 + log_write_mmio(value, 8, addr, _THIS_IP_, _RET_IP_); 359 359 __raw_writeb(value, addr); 360 - log_post_write_mmio(value, 8, addr, _THIS_IP_); 360 + log_post_write_mmio(value, 8, addr, _THIS_IP_, _RET_IP_); 361 361 } 362 362 #endif 363 363 ··· 365 365 #define writew_relaxed writew_relaxed 366 366 static inline void writew_relaxed(u16 value, volatile void __iomem *addr) 367 367 { 368 - log_write_mmio(value, 16, addr, _THIS_IP_); 368 + log_write_mmio(value, 16, addr, _THIS_IP_, _RET_IP_); 369 369 __raw_writew(cpu_to_le16(value), addr); 370 - log_post_write_mmio(value, 16, addr, _THIS_IP_); 370 + log_post_write_mmio(value, 16, addr, _THIS_IP_, _RET_IP_); 371 371 } 372 372 #endif 373 373 ··· 375 375 #define writel_relaxed writel_relaxed 376 376 static inline void writel_relaxed(u32 value, volatile void __iomem *addr) 377 377 { 378 - log_write_mmio(value, 32, addr, _THIS_IP_); 378 + log_write_mmio(value, 32, addr, _THIS_IP_, _RET_IP_); 379 379 __raw_writel(__cpu_to_le32(value), addr); 380 - log_post_write_mmio(value, 32, addr, _THIS_IP_); 380 + log_post_write_mmio(value, 32, addr, _THIS_IP_, _RET_IP_); 381 381 } 382 382 #endif 383 383 ··· 385 385 #define writeq_relaxed writeq_relaxed 386 386 static inline void writeq_relaxed(u64 value, volatile void __iomem *addr) 387 387 { 388 - log_write_mmio(value, 64, addr, _THIS_IP_); 388 + log_write_mmio(value, 64, addr, _THIS_IP_, _RET_IP_); 389 389 __raw_writeq(__cpu_to_le64(value), addr); 390 - log_post_write_mmio(value, 64, addr, _THIS_IP_); 390 + log_post_write_mmio(value, 64, addr, _THIS_IP_, _RET_IP_); 391 391 } 392 392 #endif 393 393

+27 -16

include/trace/events/rwmmio.h

··· 12 12 13 13 DECLARE_EVENT_CLASS(rwmmio_rw_template, 14 14 15 - TP_PROTO(unsigned long caller, u64 val, u8 width, volatile void __iomem *addr), 15 + TP_PROTO(unsigned long caller, unsigned long caller0, u64 val, u8 width, 16 + volatile void __iomem *addr), 16 17 17 - TP_ARGS(caller, val, width, addr), 18 + TP_ARGS(caller, caller0, val, width, addr), 18 19 19 20 TP_STRUCT__entry( 20 21 __field(unsigned long, caller) 22 + __field(unsigned long, caller0) 21 23 __field(unsigned long, addr) 22 24 __field(u64, val) 23 25 __field(u8, width) ··· 27 25 28 26 TP_fast_assign( 29 27 __entry->caller = caller; 28 + __entry->caller0 = caller0; 30 29 __entry->val = val; 31 30 __entry->addr = (unsigned long)addr; 32 31 __entry->width = width; 33 32 ), 34 33 35 - TP_printk("%pS width=%d val=%#llx addr=%#lx", 36 - (void *)__entry->caller, __entry->width, 34 + TP_printk("%pS -> %pS width=%d val=%#llx addr=%#lx", 35 + (void *)__entry->caller0, (void *)__entry->caller, __entry->width, 37 36 __entry->val, __entry->addr) 38 37 ); 39 38 40 39 DEFINE_EVENT(rwmmio_rw_template, rwmmio_write, 41 - TP_PROTO(unsigned long caller, u64 val, u8 width, volatile void __iomem *addr), 42 - TP_ARGS(caller, val, width, addr) 40 + TP_PROTO(unsigned long caller, unsigned long caller0, u64 val, u8 width, 41 + volatile void __iomem *addr), 42 + TP_ARGS(caller, caller0, val, width, addr) 43 43 ); 44 44 45 45 DEFINE_EVENT(rwmmio_rw_template, rwmmio_post_write, 46 - TP_PROTO(unsigned long caller, u64 val, u8 width, volatile void __iomem *addr), 47 - TP_ARGS(caller, val, width, addr) 46 + TP_PROTO(unsigned long caller, unsigned long caller0, u64 val, u8 width, 47 + volatile void __iomem *addr), 48 + TP_ARGS(caller, caller0, val, width, addr) 48 49 ); 49 50 50 51 TRACE_EVENT(rwmmio_read, 51 52 52 - TP_PROTO(unsigned long caller, u8 width, const volatile void __iomem *addr), 53 + TP_PROTO(unsigned long caller, unsigned long caller0, u8 width, 54 + const volatile void __iomem *addr), 53 55 54 - TP_ARGS(caller, width, addr), 56 + TP_ARGS(caller, caller0, width, addr), 55 57 56 58 TP_STRUCT__entry( 57 59 __field(unsigned long, caller) 60 + __field(unsigned long, caller0) 58 61 __field(unsigned long, addr) 59 62 __field(u8, width) 60 63 ), 61 64 62 65 TP_fast_assign( 63 66 __entry->caller = caller; 67 + __entry->caller0 = caller0; 64 68 __entry->addr = (unsigned long)addr; 65 69 __entry->width = width; 66 70 ), 67 71 68 - TP_printk("%pS width=%d addr=%#lx", 69 - (void *)__entry->caller, __entry->width, __entry->addr) 72 + TP_printk("%pS -> %pS width=%d addr=%#lx", 73 + (void *)__entry->caller0, (void *)__entry->caller, __entry->width, __entry->addr) 70 74 ); 71 75 72 76 TRACE_EVENT(rwmmio_post_read, 73 77 74 - TP_PROTO(unsigned long caller, u64 val, u8 width, const volatile void __iomem *addr), 78 + TP_PROTO(unsigned long caller, unsigned long caller0, u64 val, u8 width, 79 + const volatile void __iomem *addr), 75 80 76 - TP_ARGS(caller, val, width, addr), 81 + TP_ARGS(caller, caller0, val, width, addr), 77 82 78 83 TP_STRUCT__entry( 79 84 __field(unsigned long, caller) 85 + __field(unsigned long, caller0) 80 86 __field(unsigned long, addr) 81 87 __field(u64, val) 82 88 __field(u8, width) ··· 92 82 93 83 TP_fast_assign( 94 84 __entry->caller = caller; 85 + __entry->caller0 = caller0; 95 86 __entry->val = val; 96 87 __entry->addr = (unsigned long)addr; 97 88 __entry->width = width; 98 89 ), 99 90 100 - TP_printk("%pS width=%d val=%#llx addr=%#lx", 101 - (void *)__entry->caller, __entry->width, 91 + TP_printk("%pS -> %pS width=%d val=%#llx addr=%#lx", 92 + (void *)__entry->caller0, (void *)__entry->caller, __entry->width, 102 93 __entry->val, __entry->addr) 103 94 ); 104 95

+8 -8

lib/trace_readwrite.c

··· 14 14 15 15 #ifdef CONFIG_TRACE_MMIO_ACCESS 16 16 void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr, 17 - unsigned long caller_addr) 17 + unsigned long caller_addr, unsigned long caller_addr0) 18 18 { 19 - trace_rwmmio_write(caller_addr, val, width, addr); 19 + trace_rwmmio_write(caller_addr, caller_addr0, val, width, addr); 20 20 } 21 21 EXPORT_SYMBOL_GPL(log_write_mmio); 22 22 EXPORT_TRACEPOINT_SYMBOL_GPL(rwmmio_write); 23 23 24 24 void log_post_write_mmio(u64 val, u8 width, volatile void __iomem *addr, 25 - unsigned long caller_addr) 25 + unsigned long caller_addr, unsigned long caller_addr0) 26 26 { 27 - trace_rwmmio_post_write(caller_addr, val, width, addr); 27 + trace_rwmmio_post_write(caller_addr, caller_addr0, val, width, addr); 28 28 } 29 29 EXPORT_SYMBOL_GPL(log_post_write_mmio); 30 30 EXPORT_TRACEPOINT_SYMBOL_GPL(rwmmio_post_write); 31 31 32 32 void log_read_mmio(u8 width, const volatile void __iomem *addr, 33 - unsigned long caller_addr) 33 + unsigned long caller_addr, unsigned long caller_addr0) 34 34 { 35 - trace_rwmmio_read(caller_addr, width, addr); 35 + trace_rwmmio_read(caller_addr, caller_addr0, width, addr); 36 36 } 37 37 EXPORT_SYMBOL_GPL(log_read_mmio); 38 38 EXPORT_TRACEPOINT_SYMBOL_GPL(rwmmio_read); 39 39 40 40 void log_post_read_mmio(u64 val, u8 width, const volatile void __iomem *addr, 41 - unsigned long caller_addr) 41 + unsigned long caller_addr, unsigned long caller_addr0) 42 42 { 43 - trace_rwmmio_post_read(caller_addr, val, width, addr); 43 + trace_rwmmio_post_read(caller_addr, caller_addr0, val, width, addr); 44 44 } 45 45 EXPORT_SYMBOL_GPL(log_post_read_mmio); 46 46 EXPORT_TRACEPOINT_SYMBOL_GPL(rwmmio_post_read);