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

[Bartlomiej Zolnierkiewicz <b.zolnierkie@samsung.com>]

On 6/24/20 5:15 PM, Tony Asleson wrote:
> 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).

BTW:

Similar dev_printk() conversion for ata_dev_printk() has been tried
recently as a part of changes to add dynamic debugging support to
libata (as it also requires dev_printk() to be used) and had to be
dropped:

https://lore.kernel.org/linux-ide/alpine.DEB.2.21.2003241414490.21582@ramsan.of.borg/

Thus I worry that the proposed ata_dev_printk() conversion is not only
causing duplicated information to be printed but it may also confuse
users.

>> 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.

Please note that with libata transport naming scheme fixed we can use
dev_printk() in libata with unchanged log messages.

> 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.

Well, I'm against changing the libata log messages but durable name
functionality still should be achievable in libata.

How's about:

* adding:

	ata_dev->tdev.durable_name = ata_scsi_durable_name;

  near the end of ata_scsi_slave_config()

and

* implementing ata_scsi_durable_name() which does

	struct ata_device *ata_dev = container_of(dev, struct ata_device, tdev);
	
	return scsi_durable_name(ata_dev->sdev, buf, len);

?

> 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.

Of course I agree that having a persistent identifier associated to
storage related log messages is useful and my previous mail was exactly
a part of discussion on the best way to achieving it. :-)

I agree with James that dev_printk() usage is preferred over legacy
printk_emit() and I've described a way to do it correctly for libata.

Unfortunately it means additional work for getting the new feature 
merged so if you don't agree with doing it you need to convince:

- Jens (libata Maintainer) to accept libata patch as it is

or

- James (& other higher level Maintainers) to use printk_emit() instead

Ultimately they will be the ones merging/long-term supporting proposed
patches and not me..

Best regards,
--
Bartlomiej Zolnierkiewicz
Samsung R&D Institute Poland
Samsung Electronics

> 
> Thanks,
> Tony