Re: [PATCH] spi: spi-mem: Introduce a default ->exec_op() debug log

[Miquel Raynal <miquel.raynal@xxxxxxxxxxx>]

Hello Mark & Tudor,

On 13/03/2025 at 22:27:54 GMT, Mark Brown <broonie@xxxxxxxxxx> wrote:

> On Thu, Mar 06, 2025 at 09:05:39AM +0000, Tudor Ambarus wrote:
>> On 3/5/25 8:11 PM, Miquel Raynal wrote:
>
>> > --- a/drivers/spi/spi-mem.c
>> > +++ b/drivers/spi/spi-mem.c
>> > @@ -377,6 +377,17 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op)
>> >  	/* Make sure the operation frequency is correct before going futher */
>> >  	spi_mem_adjust_op_freq(mem, (struct spi_mem_op *)op);
>> >  
>> > + dev_dbg(&mem->spi->dev, "[cmd: 0x%02x][%dB addr: %#8llx][%dB
>> > dummy][%4dB data %s] %d%c-%d%c-%d%c-%d%c @ %uHz\n",
>
>> Isn't this too "chatty", especially on page program ops? I wouldn't be
>> surprised if the prints introduce timings that change controller's
>> behavior. How about using dev_vdbg?
>
> That, or covert to trace_printk() or even better a trace event - with a
> trace event you get really fine grained control and extremely low
> overhead.

I do not think it is too chatty, this is typically a trace that is used
when writing the basic parts of a spi-mem controller. Myself I already
wrote something like that twice, just because during the initial
writing, performance simply does not matter.

Regarding the fear that the chatty log could have an impact: if it does,
it is likely a bug of the driver or a severe controller limitation
IMO. Anyway, the point of having a _dbg call is to allow
enabling/disabling the log if it is too time consuming.

I'd say that for this particular purpose I do not thing that trace
printks or events would really fit. As a developer, I'd definitely
always change the function calls to some direct printk calls in this
case. The verbose debug alternative seduced me though, so if that's okay
for you, I'll switch to dev_vdgb() as suggested by Tudor, which honestly
feels like a seducing alternative.

Cheers,
Miquèl