Re: [RFC PATCH v2 5/7] ata_dev_printk: Use dev_printk

[Tony Asleson <tasleson@redhat.com>]

On 5/14/20 12:53 AM, Hannes Reinecke wrote:
> On 5/13/20 11:36 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 42c8728f6117..16978d615a17 100644
>> --- a/drivers/ata/libata-core.c
>> +++ b/drivers/ata/libata-core.c
>> @@ -7301,6 +7301,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;
>>   @@ -7309,9 +7310,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,
>> +            dev->link->pmp + dev->devno,
>> +            &vaf);
>>         va_end(args);
>>   }
>>
> That is wrong.
> dev_printk() will already prefix the logging message with the device
> name, so we'll end up having the name printed twice.

It certainly could be. Early in boot when &dev->sdev->sdev_gendev ==
NULL and &dev->tdev is used we get

dev1.0: ata1.00: configured for UDMA/100

later when &dev->sdev->sdev_gendev != NULL we get

sd 1:0:0:0: [sdb] 209715200 512-byte logical blocks: (107 GB/100 GiB)

to clarify, your point is dev1.0 is redundant as ata1.00 exists in the
message?


In the block layer print_req_error we get:

block sdb: blk_update_request: I/O error, dev sdb, sector 10000 op
0x0:(READ) flags 0x80700 phys_seg 4 prio class 0

Which seems a bit more redundant.

I've been trying to be careful to not change the human readable portion
of the message, so not to disturb all the log scraping tools that exist
mining errors.  Maybe this is the wrong approach?  In my original patch
series I brought back printk_emit so that I could add the structured
data without introducing changes in the message text output.  James
Bottomley suggested using dev_printk which certainly made things
cleaner, but it does add the prefix.


Thanks,
Tony