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 ?
