On 12/30/21 22:47, Hannes Reinecke wrote:
> On 12/30/21 6:19 AM, Damien Le Moal wrote:
>> On 12/21/21 16:20, Hannes Reinecke wrote:
>>> Hi all,
>>>
>>> after some prodding from individual persons I've resurrected my
>>> patchset to put libata logging on a even keel, and use structured
>>> logging for everything.
>>> So this patch does away with DPRINTK, ATA_DEBUG or ata_msg_XXX()
>>> calls, and moves everything over to structured logging
>>> (ie the dev_XXX() calls).
>>> Additionally I've added tracepoints to trace command flow,
>>> error handling, host state machine etc.
>>>
>>> So everything is looking far saner now.
>>>
>>> As usual, comments and reviews are welcome.
>>>
>>> I know that the device names suck. Blame Tejun.
>>
>> I applied this series, temporarily, to the branch for-5.17-logging, with
>> the fixes I commented about.
>>
>> After some light testing, seems OK, but need to hammer this a little more.
>>
>> My main concern is the change in patch 12: using the dev_xxx() macros
>> directly changes the messages from being all prefixed with "ataX.X" to
>> different flavors (devX.X, linkX.X, portX.X, etc). While I do like the
>> code simplification, this makes reading dmesg to track how a device is
>> behaving very hard.
>>
> And that was exactly what I had been hinting at with my last sentence :-)
>
> Original sin here is to have completely generic names for ata device
> objects (link-X? C'mon).
>
> And trying to twiddle with the devnames will land you in the mess we are
> in now, _and_ you lose the link between device names in sysfs and what's
> printed in the logging message, making debugging ever so much fun.
> (And I'm not even going into the _very_ slim distinction between port,
> link, and dev here ...)
>
>> Defining dev_fmt() everywhere the ata_{port,link,dev}_XXX functions are
>> used would solve this, but that is annoying as almost all drivers would
>> need to define that. Looking at the dev_XXX() macros, I do not see an
>> easy solution. Any idea ?
>>
> I guess the only sane solution would be to have a clean break by
> introducing a new config variable like ATA_NEW_SYSFS_NAMING.
> Then we could have 'sane' sysfs names like 'ata_port', 'ata_link', and
> 'ata_dev', _and_ would avoid the 'sysfs is ABI and cannot be modified'
> trap.
>
> Plan would be to send a prep patch to partially revert patch 12, so as
> to re-introduce the original formatting, but keeping the new accessors.
> And then have an additional patch to introduce the new-style sysfs
> layout, with the new config option. Which clearly would default to 'n'
> for now.
>
> Hmm?
For the ata_xxx_printk() functions, what about something simpler like this:
+#define ata_port_printk(level, ap, fmt, ...) \
+ pr_ ## level ("ata%u: " fmt, (ap)->print_id, ##__VA_ARGS__)
#define ata_port_err(ap, fmt, ...) \
- ata_port_printk(ap, KERN_ERR, fmt, ##__VA_ARGS__)
+ ata_port_printk(err, ap, fmt, ##__VA_ARGS__)
#define ata_port_warn(ap, fmt, ...) \
- ata_port_printk(ap, KERN_WARNING, fmt, ##__VA_ARGS__)
+ ata_port_printk(warn, ap, fmt, ##__VA_ARGS__)
#define ata_port_notice(ap, fmt, ...) \
- ata_port_printk(ap, KERN_NOTICE, fmt, ##__VA_ARGS__)
+ ata_port_printk(notice, ap, fmt, ##__VA_ARGS__)
#define ata_port_info(ap, fmt, ...) \
- ata_port_printk(ap, KERN_INFO, fmt, ##__VA_ARGS__)
+ ata_port_printk(info, ap, fmt, ##__VA_ARGS__)
#define ata_port_dbg(ap, fmt, ...) \
- ata_port_printk(ap, KERN_DEBUG, fmt, ##__VA_ARGS__)
+ ata_port_printk(debug, ap, fmt, ##__VA_ARGS__)
+
+#define ata_link_printk(level, link, fmt, ...) \
+do { \
+ if (sata_pmp_attached((link)->ap) || \
+ (link)->ap->slave_link) \
+ pr_ ## level ("ata%u.%02u: " fmt, \
+ (link)->ap->print_id, \
+ (link)->pmp, \
+ ##__VA_ARGS__); \
+ else \
+ pr_ ## level ("ata%u: " fmt, \
+ (link)->ap->print_id, \
+ ##__VA_ARGS__); \
+} while (0)
#define ata_link_err(link, fmt, ...) \
- ata_link_printk(link, KERN_ERR, fmt, ##__VA_ARGS__)
+ ata_link_printk(err, link, fmt, ##__VA_ARGS__)
#define ata_link_warn(link, fmt, ...) \
- ata_link_printk(link, KERN_WARNING, fmt, ##__VA_ARGS__)
+ ata_link_printk(warn, link, fmt, ##__VA_ARGS__)
#define ata_link_notice(link, fmt, ...) \
- ata_link_printk(link, KERN_NOTICE, fmt, ##__VA_ARGS__)
+ ata_link_printk(notice, link, fmt, ##__VA_ARGS__)
#define ata_link_info(link, fmt, ...) \
- ata_link_printk(link, KERN_INFO, fmt, ##__VA_ARGS__)
+ ata_link_printk(info, link, fmt, ##__VA_ARGS__)
#define ata_link_dbg(link, fmt, ...) \
- ata_link_printk(link, KERN_DEBUG, fmt, ##__VA_ARGS__)
+ ata_link_printk(debug, link, fmt, ##__VA_ARGS__)
+
+#define ata_dev_printk(level, dev, fmt, ...) \
+ pr_ ## level("ata%u.%02u: " fmt, \
+ (dev)->link->ap->print_id, \
+ (dev)->link->pmp + (dev)->devno, \
+ ##__VA_ARGS__)
#define ata_dev_err(dev, fmt, ...) \
- ata_dev_printk(dev, KERN_ERR, fmt, ##__VA_ARGS__)
+ ata_dev_printk(err, dev, fmt, ##__VA_ARGS__)
#define ata_dev_warn(dev, fmt, ...) \
- ata_dev_printk(dev, KERN_WARNING, fmt, ##__VA_ARGS__)
+ ata_dev_printk(warn, dev, fmt, ##__VA_ARGS__)
#define ata_dev_notice(dev, fmt, ...) \
- ata_dev_printk(dev, KERN_NOTICE, fmt, ##__VA_ARGS__)
+ ata_dev_printk(notice, dev, fmt, ##__VA_ARGS__)
#define ata_dev_info(dev, fmt, ...) \
- ata_dev_printk(dev, KERN_INFO, fmt, ##__VA_ARGS__)
+ ata_dev_printk(info, dev, fmt, ##__VA_ARGS__)
#define ata_dev_dbg(dev, fmt, ...) \
- ata_dev_printk(dev, KERN_DEBUG, fmt, ##__VA_ARGS__)
+ ata_dev_printk(debug, dev, fmt, ##__VA_ARGS__)
And the remaining of the patch is the same. Instead of dev_xxx() this
uses pr_xxx() so we have the same dynamic debug feature and we preserve
the messages as they were until now.
Thoughts ?
I updated the for-5.17-logging branch with this, adding the following
fixes too:
* Patch 21: we need to use dev_dbg() as we cannot easily get the struct
ata_device for ata_dev_dbg().
* Build-bot warning fixes in drivers/ata/pata_atp867x.c (patch 47) and
also in sata_mv.c (patch 16). I wonder why these 2 show up now... The
warnings should exist already... Very weird.
Will test more next week after restart.
Happy new year !
Cheers.
--
Damien Le Moal
Western Digital Research
