| Message ID | 99ecc64c6da3abb3ea2930082c40f1820655664c.1638275062.git.quic_saipraka@quicinc.com (mailing list archive) |
|---|---|
| State | Superseded, archived |
| Headers | show |
| Series | tracing/rwmmio/arm64: Add support to trace register reads/writes | expand |
On Mon, Dec 6, 2021 at 9:28 AM Sai Prakash Ranjan <quic_saipraka@quicinc.com> wrote: > +#if IS_ENABLED(CONFIG_TRACE_MMIO_ACCESS) && !(defined(__DISABLE_TRACE_MMIO__)) > +#include <linux/tracepoint-defs.h> > + > +DECLARE_TRACEPOINT(rwmmio_write); > +DECLARE_TRACEPOINT(rwmmio_read); > + > +#define rwmmio_tracepoint_active(t) tracepoint_enabled(t) > +void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr); > +void log_read_mmio(u8 width, const volatile void __iomem *addr); > + > +#else > + > +#define rwmmio_tracepoint_active(t) false > +static inline void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr) {} > +static inline void log_read_mmio(u8 width, const volatile void __iomem *addr) {} > + > +#endif /* CONFIG_TRACE_MMIO_ACCESS */ > > /* > * __raw_{read,write}{b,w,l,q}() access memory in native endianness. > @@ -149,6 +166,8 @@ static inline u8 readb(const volatile void __iomem *addr) > { > u8 val; > > + if (rwmmio_tracepoint_active(rwmmio_read)) > + log_read_mmio(8, addr); > __io_br(); > val = __raw_readb(addr); > __io_ar(val); For readability, it may be nicer to fold the two lines you add for each helper into one, such as void __log_write_mmio(u64 val, u8 width, volatile void __iomem *addr); #define log_write_mmio(val, widtg, addr) do { \ if (tracepoint_enabled(rwmmio_read)) \ __log_write_mmio((val), (width), (addr)); \ } while (0) I wonder if it may even be better to not check for tracepoint_active() in the inline function at all but always enter the external function when built-in. This means we do run into the branch, but it also reduces the i-cache footprint. For general functionality, I think it would be better to trace the returned value from the read, but I don't know if that defeats the purpose you are interested in, since it requires the tracing to come after the __raw_read. Arnd
On 12/6/2021 2:39 PM, Arnd Bergmann wrote: > On Mon, Dec 6, 2021 at 9:28 AM Sai Prakash Ranjan > <quic_saipraka@quicinc.com> wrote: >> +#if IS_ENABLED(CONFIG_TRACE_MMIO_ACCESS) && !(defined(__DISABLE_TRACE_MMIO__)) >> +#include <linux/tracepoint-defs.h> >> + >> +DECLARE_TRACEPOINT(rwmmio_write); >> +DECLARE_TRACEPOINT(rwmmio_read); >> + >> +#define rwmmio_tracepoint_active(t) tracepoint_enabled(t) >> +void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr); >> +void log_read_mmio(u8 width, const volatile void __iomem *addr); >> + >> +#else >> + >> +#define rwmmio_tracepoint_active(t) false >> +static inline void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr) {} >> +static inline void log_read_mmio(u8 width, const volatile void __iomem *addr) {} >> + >> +#endif /* CONFIG_TRACE_MMIO_ACCESS */ >> >> /* >> * __raw_{read,write}{b,w,l,q}() access memory in native endianness. >> @@ -149,6 +166,8 @@ static inline u8 readb(const volatile void __iomem *addr) >> { >> u8 val; >> >> + if (rwmmio_tracepoint_active(rwmmio_read)) >> + log_read_mmio(8, addr); >> __io_br(); >> val = __raw_readb(addr); >> __io_ar(val); > For readability, it may be nicer to fold the two lines you add for each > helper into one, such as > > void __log_write_mmio(u64 val, u8 width, volatile void __iomem *addr); > #define log_write_mmio(val, widtg, addr) do { \ > if (tracepoint_enabled(rwmmio_read)) \ > __log_write_mmio((val), (width), (addr)); \ > } while (0) > > I wonder if it may even be better to not check for tracepoint_active() in the > inline function at all but always enter the external function when built-in. > This means we do run into the branch, but it also reduces the i-cache footprint. Right, we don't need the tracepoint active check as we declare the tracepoint only when the config is enabled so I can just call log_{read,write}_mmio directly. > For general functionality, I think it would be better to trace the returned > value from the read, but I don't know if that defeats the purpose you > are interested in, since it requires the tracing to come after the __raw_read. > > Yes just the trace after read/write won't serve our usecase where we expect crashes/hangs on accessing these registers but internally we did have a log_post_read_mmio() as well, if it is useful then I can add it. Thanks, Sai
On Mon, Dec 6, 2021 at 10:52 AM Sai Prakash Ranjan <quic_saipraka@quicinc.com> wrote: > > Yes just the trace after read/write won't serve our usecase where we > expect crashes/hangs on accessing > these registers but internally we did have a log_post_read_mmio() as > well, if it is useful then I can add it. Are there any downsides to tracing both before and after, besides another growth in binary size? Aside from the 'value', that would also allow measuring the time it takes to complete a readl(), which may be valuable for other users as these can be significant. Not sure how to best do that that, we could return a timestamp from the 'before' tracepoint and pass it into the 'after' tracepoint in order to log the difference, or just rely on calculating the differences in user space based on the log. For the 'write' style accessors, the timing data would be less interesting, at least for posted PCI transactions, but it may be helpful to do the same for symmetry reasons. Arnd
On 12/6/2021 3:31 PM, Arnd Bergmann wrote: > On Mon, Dec 6, 2021 at 10:52 AM Sai Prakash Ranjan > <quic_saipraka@quicinc.com> wrote: >> Yes just the trace after read/write won't serve our usecase where we >> expect crashes/hangs on accessing >> these registers but internally we did have a log_post_read_mmio() as >> well, if it is useful then I can add it. > Are there any downsides to tracing both before and after, besides another growth > in binary size? Aside from the 'value', that would also allow > measuring the time it > takes to complete a readl(), which may be valuable for other users as these > can be significant. Ah yes, that would be useful. No downsides as far as I know other than the size but that should be fine given this depends on ftrace. > > Not sure how to best do that that, we could return a timestamp from the 'before' > tracepoint and pass it into the 'after' tracepoint in order to log the > difference, or just > rely on calculating the differences in user space based on the log. For trace events, timing information is already logged by ftrace infrastructure. Most of the users do use these for timing information based on post processing these logs looking at these timestamps, so we should be good using that as well. > For the 'write' style accessors, the timing data would be less interesting, at > least for posted PCI transactions, but it may be helpful to do the same for > symmetry reasons. Ok, I will add these post read/write logging in the next version. Thanks, Sai
diff --git a/arch/arm64/kvm/hyp/nvhe/Makefile b/arch/arm64/kvm/hyp/nvhe/Makefile index c3c11974fa3b..2765ec38a269 100644 --- a/arch/arm64/kvm/hyp/nvhe/Makefile +++ b/arch/arm64/kvm/hyp/nvhe/Makefile @@ -4,7 +4,12 @@ # asflags-y := -D__KVM_NVHE_HYPERVISOR__ -D__DISABLE_EXPORTS -ccflags-y := -D__KVM_NVHE_HYPERVISOR__ -D__DISABLE_EXPORTS + +# Tracepoint and MMIO logging symbols should not be visible at nVHE KVM as +# there is no way to execute them and any such MMIO access from nVHE KVM +# will explode instantly (Words of Marc Zyngier). So introduce a generic flag +# __DISABLE_TRACE_MMIO__ to disable MMIO tracing for nVHE KVM. +ccflags-y := -D__KVM_NVHE_HYPERVISOR__ -D__DISABLE_EXPORTS -D__DISABLE_TRACE_MMIO__ hostprogs := gen-hyprel HOST_EXTRACFLAGS += -I$(objtree)/include diff --git a/include/asm-generic/io.h b/include/asm-generic/io.h index 7ce93aaf69f8..dd5a803c8479 100644 --- a/include/asm-generic/io.h +++ b/include/asm-generic/io.h @@ -61,6 +61,23 @@ #define __io_par(v) __io_ar(v) #endif +#if IS_ENABLED(CONFIG_TRACE_MMIO_ACCESS) && !(defined(__DISABLE_TRACE_MMIO__)) +#include <linux/tracepoint-defs.h> + +DECLARE_TRACEPOINT(rwmmio_write); +DECLARE_TRACEPOINT(rwmmio_read); + +#define rwmmio_tracepoint_active(t) tracepoint_enabled(t) +void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr); +void log_read_mmio(u8 width, const volatile void __iomem *addr); + +#else + +#define rwmmio_tracepoint_active(t) false +static inline void log_write_mmio(u64 val, u8 width, volatile void __iomem *addr) {} +static inline void log_read_mmio(u8 width, const volatile void __iomem *addr) {} + +#endif /* CONFIG_TRACE_MMIO_ACCESS */ /* * __raw_{read,write}{b,w,l,q}() access memory in native endianness. @@ -149,6 +166,8 @@ static inline u8 readb(const volatile void __iomem *addr) { u8 val; + if (rwmmio_tracepoint_active(rwmmio_read)) + log_read_mmio(8, addr); __io_br(); val = __raw_readb(addr); __io_ar(val); @@ -162,6 +181,8 @@ static inline u16 readw(const volatile void __iomem *addr) { u16 val; + if (rwmmio_tracepoint_active(rwmmio_read)) + log_read_mmio(16, addr); __io_br(); val = __le16_to_cpu((__le16 __force)__raw_readw(addr)); __io_ar(val); @@ -175,6 +196,8 @@ static inline u32 readl(const volatile void __iomem *addr) { u32 val; + if (rwmmio_tracepoint_active(rwmmio_read)) + log_read_mmio(32, addr); __io_br(); val = __le32_to_cpu((__le32 __force)__raw_readl(addr)); __io_ar(val); @@ -189,6 +212,8 @@ static inline u64 readq(const volatile void __iomem *addr) { u64 val; + if (rwmmio_tracepoint_active(rwmmio_read)) + log_read_mmio(64, addr); __io_br(); val = __le64_to_cpu(__raw_readq(addr)); __io_ar(val); @@ -201,6 +226,8 @@ static inline u64 readq(const volatile void __iomem *addr) #define writeb writeb static inline void writeb(u8 value, volatile void __iomem *addr) { + if (rwmmio_tracepoint_active(rwmmio_write)) + log_write_mmio(value, 8, addr); __io_bw(); __raw_writeb(value, addr); __io_aw(); @@ -211,6 +238,8 @@ static inline void writeb(u8 value, volatile void __iomem *addr) #define writew writew static inline void writew(u16 value, volatile void __iomem *addr) { + if (rwmmio_tracepoint_active(rwmmio_write)) + log_write_mmio(value, 16, addr); __io_bw(); __raw_writew((u16 __force)cpu_to_le16(value), addr); __io_aw(); @@ -221,6 +250,8 @@ static inline void writew(u16 value, volatile void __iomem *addr) #define writel writel static inline void writel(u32 value, volatile void __iomem *addr) { + if (rwmmio_tracepoint_active(rwmmio_write)) + log_write_mmio(value, 32, addr); __io_bw(); __raw_writel((u32 __force)__cpu_to_le32(value), addr); __io_aw(); @@ -232,6 +263,8 @@ static inline void writel(u32 value, volatile void __iomem *addr) #define writeq writeq static inline void writeq(u64 value, volatile void __iomem *addr) { + if (rwmmio_tracepoint_active(rwmmio_write)) + log_write_mmio(value, 64, addr); __io_bw(); __raw_writeq(__cpu_to_le64(value), addr); __io_aw(); @@ -248,6 +281,8 @@ static inline void writeq(u64 value, volatile void __iomem *addr) #define readb_relaxed readb_relaxed static inline u8 readb_relaxed(const volatile void __iomem *addr) { + if (rwmmio_tracepoint_active(rwmmio_read)) + log_read_mmio(8, addr); return __raw_readb(addr); } #endif @@ -256,6 +291,8 @@ static inline u8 readb_relaxed(const volatile void __iomem *addr) #define readw_relaxed readw_relaxed static inline u16 readw_relaxed(const volatile void __iomem *addr) { + if (rwmmio_tracepoint_active(rwmmio_read)) + log_read_mmio(16, addr); return __le16_to_cpu(__raw_readw(addr)); } #endif @@ -264,6 +301,8 @@ static inline u16 readw_relaxed(const volatile void __iomem *addr) #define readl_relaxed readl_relaxed static inline u32 readl_relaxed(const volatile void __iomem *addr) { + if (rwmmio_tracepoint_active(rwmmio_read)) + log_read_mmio(32, addr); return __le32_to_cpu(__raw_readl(addr)); } #endif @@ -272,6 +311,8 @@ static inline u32 readl_relaxed(const volatile void __iomem *addr) #define readq_relaxed readq_relaxed static inline u64 readq_relaxed(const volatile void __iomem *addr) { + if (rwmmio_tracepoint_active(rwmmio_read)) + log_read_mmio(64, addr); return __le64_to_cpu(__raw_readq(addr)); } #endif @@ -280,6 +321,8 @@ 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) { + if (rwmmio_tracepoint_active(rwmmio_write)) + log_write_mmio(value, 8, addr); __raw_writeb(value, addr); } #endif @@ -288,6 +331,8 @@ 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) { + if (rwmmio_tracepoint_active(rwmmio_write)) + log_write_mmio(value, 16, addr); __raw_writew(cpu_to_le16(value), addr); } #endif @@ -296,6 +341,8 @@ 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) { + if (rwmmio_tracepoint_active(rwmmio_write)) + log_write_mmio(value, 32, addr); __raw_writel(__cpu_to_le32(value), addr); } #endif @@ -304,6 +351,8 @@ 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) { + if (rwmmio_tracepoint_active(rwmmio_write)) + log_write_mmio(value, 64, addr); __raw_writeq(__cpu_to_le64(value), addr); } #endif
Add logging support for MMIO high level accessors such as read{b,w,l,q} and their relaxed versions to aid in debugging unexpected crashes/hangs caused by the corresponding MMIO operation. Also add a generic flag (__DISABLE_TRACE_MMIO__) which is used to disable MMIO tracing in nVHE KVM and if required can be used to disable MMIO tracing for specific drivers. Signed-off-by: Sai Prakash Ranjan <quic_saipraka@quicinc.com> --- arch/arm64/kvm/hyp/nvhe/Makefile | 7 ++++- include/asm-generic/io.h | 49 ++++++++++++++++++++++++++++++++ 2 files changed, 55 insertions(+), 1 deletion(-)