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

[Sai Prakash Ranjan <quic_saipraka@quicinc.com>]

On 11/19/2021 7:13 PM, Marc Zyngier wrote:
> On Mon, 15 Nov 2021 11:33:29 +0000,
> Sai Prakash Ranjan <quic_saipraka@quicinc.com> wrote:
>> From: Prasad Sodagudi <psodagud@codeaurora.org>
>>
>> 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@codeaurora.org>
>> [saiprakash: Rewrote commit msg and trace event field edits]
>> Signed-off-by: Sai Prakash Ranjan <quic_saipraka@quicinc.com>
>> ---
>>
>> 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