Re: [PATCHv4 1/2] tracing: Add register read/write tracing support

[Sai Prakash Ranjan]

On 11/19/2021 7:13 PM, Marc Zyngier wrote:
> On Mon, 15 Nov 2021 11:33:29 +0000,
> 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
> > rwmmio_read: gic_do_wait_for_rwp+0x54/0x90 readl addr=0xffff800010040000
> > rwmmio_write: gic_set_affinity+0x1bc/0x1e8 writeq addr=0xffff800010046130
> >
> > 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>
> > ---
> >
> > Have dropped value parameter for mmio write trace event as that
> > was causing hangs in strange ways, i.e., if we pass any other
> > 64bit value, it works fine but passing value would just hang.
> > Not just using the log apis, even simple trace_printk with value
> > printed would cause hang. It wasn't noticed in early version
> > because dyndbg would filter the logging in my system (I had
> > set it to trace only specific qcom directory) but once this
> > version starts recording all the reads/writes with value passed,
> > it just hangs system when rwmmio write event tracing is enabled.
> Why is that so? Not being able to track the value written out makes
> the feature pretty useless if you're not writing fixed values.
>
> > Reason why we wouldn't need value along with mmio write log is
> > that value can be easily deduced from the caller_name+offset which is
> > printed already by the rwmmio trace events which gives the exact
> > location of mmio writes and the value is easily known from the driver.
> That's a very narrow view of what can be written in an MMIO
> registers. We write dynamic values at all times, and if we are able to
> trace MMIO writes, then the value written out must be part of the trace.
>
> I'd rather you try and get to the bottom of this issue rather than
> paper over it.
>
> Thanks,
>
> 	M.

Sure, idea was to put it out in the open if anyone has any idea as to 
what might be happening
there since the version where directly instrumenting the raw read/write 
accessors in arm64/asm/io.h
was working fine casting doubts if this has to do something with 
inlining as Arnd mentioned before.

Thanks,
Sai