Re: [RFC PATCH v3 5/8] ata_dev_printk: Use dev_printk

[Tony Asleson <tasleson@redhat.com>]

On 6/24/20 5:35 AM, Bartlomiej Zolnierkiewicz wrote:
> 
> [ added linux-ide ML to Cc: ]
> 
> Hi,

Hello,

> 
> On 6/23/20 9:17 PM, Tony Asleson wrote:
>> Utilize the dev_printk function which will add structured data
>> to the log message.
>>
>> Signed-off-by: Tony Asleson <tasleson@redhat.com>
>> ---
>>  drivers/ata/libata-core.c | 10 +++++++---
>>  1 file changed, 7 insertions(+), 3 deletions(-)
>>
>> diff --git a/drivers/ata/libata-core.c b/drivers/ata/libata-core.c
>> index beca5f91bb4c..44c874367fe3 100644
>> --- a/drivers/ata/libata-core.c
>> +++ b/drivers/ata/libata-core.c
>> @@ -6475,6 +6475,7 @@ EXPORT_SYMBOL(ata_link_printk);
>>  void ata_dev_printk(const struct ata_device *dev, const char *level,
>>  		    const char *fmt, ...)
>>  {
>> +	const struct device *gendev;
>>  	struct va_format vaf;
>>  	va_list args;
>>  
>> @@ -6483,9 +6484,12 @@ void ata_dev_printk(const struct ata_device *dev, const char *level,
>>  	vaf.fmt = fmt;
>>  	vaf.va = &args;
>>  
>> -	printk("%sata%u.%02u: %pV",
>> -	       level, dev->link->ap->print_id, dev->link->pmp + dev->devno,
>> -	       &vaf);
>> +	gendev = (dev->sdev) ? &dev->sdev->sdev_gendev : &dev->tdev;
>> +
>> +	dev_printk(level, gendev, "ata%u.%02u: %pV",
>> +			dev->link->ap->print_id,
> 
> This duplicates the device information and breaks integrity of
> libata logging functionality (ata_{dev,link,port}_printk() should
> be all converted to use dev_printk() at the same time).
> 
> The root source of problem is that libata transport uses different
> naming scheme for ->tdev devices (please see dev_set_name() in
> ata_t{dev,link,port}_add()) than libata core for its logging
> functionality (ata_{dev,link,port}_printk()).
> 
> Since libata transport is part of sysfs ABI we should be careful
> to not break it so one idea for solving the issue is to convert
> ata_t{dev,link,port}_add() to use libata logging naming scheme and
> at the same time add sysfs symlinks for the old libata transport
> naming scheme.
> 
> dev->sdev usage is not required for dev_printk() conversion and
> should be considered as a separate change (since it also breaks
> integrity of libata logging and can be considered as a mild
> "layering violation" I don't think that it should be applied).

The point of this patch series is to attach a device unique identifier
to the storage device log messages as structured data.  Originally I
resurrected and used printk_emit, but it was suggested I leverage
dev_printk.  dev_printk does change the output of the log message to
include duplicate information if the message isn't changed. You are not
the first person to raise that concern.  I listed this as an open
question in the cover letter.  I've wanted to preserve the original log
message, so as to not break user space mining tools and I've been
concerned that dev_printk prefixing with an id may already do that.
Adding structured data is invisible to them, or at the least shouldn't
break them, eg. adding a new key-value pair.

I can understand the desire to make all the ata logging functions
consistent, and use dev_printk if we go this way.  However, for this
change it wasn't really the goal to refactor all the logging everywhere
to use dev_printk, although that may be a good change in general.  This
is especially true that if at the end of the refactor to use dev_printk
we consider it a layering violation to call into the existing
functionality to return the vpd ID for the device and reject that part
of the change.

What I am hoping is that we can all agree that having a persistent
identifier associated to storage related log messages is indeed useful.
If we can agree on that, then I would like to have the discussion on
what's the best way to achieve that.

Thanks,
Tony