Re: [PATCH v1 1/1] scsi: ufs: Add command logging infrastructure

[Bart Van Assche <bvanassche@acm.org>]

On 2020-01-16 15:03, Asutosh Das (asd) wrote:
> On 10/28/2019 10:46 PM, Bjorn Andersson wrote:
>> On Mon 28 Oct 19:37 PDT 2019, cang@codeaurora.org wrote:
>>
>>> On 2019-10-23 18:33, Avri Altman wrote:
>>>>>
>>>>>> Add the necessary infrastructure to keep timestamp history of
>>>>>> commands, events and other useful info for debugging complex issues.
>>>>>> This helps in diagnosing events leading upto failure.
>>>>>
>>>>> Why not use tracepoints, for that?
>>>> Ack on Tomas's comment.
>>>> Are there any pieces of information that you need not provided by the
>>>> upiu tracer?
>>>>
>>>> Thanks,
>>>> Avri
>>>
>>> In extreme cases, when the UFS runs into bad state, system may crash.
>>> There
>>> may not be a chance to collect trace. If trace is not collected and
>>> failure
>>> is hard to be reproduced, some command logs prints would be very
>>> helpful to
>>> help understand what was going on before we run into failure.
>>>
>>
>> This is a common problem shared among many/all subsystems, so it's
>> better to rely on a generic solution for this; such as using tracepoints
>> dumped into pstore/ramoops.
>>
>> Regards,
>> Bjorn
>>
> 
> Reviving this discussion.
> 
> Another issue with using ftrace is that several subsystems use it.
> Consider a situation in which we store a history of 64 commands,
> responses and some other required info in ftrace.
> 
> Say there's a command that's stuck for seconds until the software times
> out. In this case, the other ftrace events are still enabled and keep
> writing to ftrace buffer thus overwriting some/most of the ufs's command
> history; thus the history is more or less lost. And there's a need to
> reproduce the issue with other tracing disabled.
> 
> So what we need is a client specific logging mechanism, which is
> lightweight as ftrace and can be parsed from ramdumps.
> 
> I'm open to ideas but ftrace in its current form may not be suitable for
> this.

Hi Asutosh,

Are you aware that it is already possible today to figure out which SCSI
commands are pending? Are you familiar with the files under
/sys/kernel/debug/block/? An example:

$ (cd /sys/kernel/debug/block && grep -aH . */*/busy)
nvme0n1/hctx7/busy:0000000006f07009 {.op=READ, .cmd_flags=META|PRIO,
.rq_flags=DONTPREP|IO_STAT, .state=in_flight, .tag=275, .internal_tag=-1}

Bart.