Re: [PATCH 2/8] sg: introduce sg_log macro
Hello Doug, > Examples please, preferably from the SCSI subsystem. If not, I'll do what > most other drivers do, drop all debug statements. $ git grep trace drivers/scsi/scsi* and $ less include/trace/events/scsi.h We currently only have trace points for command dispatch, completion, and a few error scenarios. As of yet there is no explicit tracing in the ULDs. Mostly because so far it hasn't been needed since the ML tracing will parse CDBs and dump most useful fields. And the ULDs generally have no state of their own above what's in the scsi_cmnd. But if you have a specific set of things that would be useful to inspect in the sg state, by all means introduce trace points for them. -- Martin K. Petersen Oracle Linux Engineering
Re: [PATCH 2/8] sg: introduce sg_log macro
On 2018-10-24 3:58 a.m., Martin K. Petersen wrote: Hi Doug, I'll follow what the scsi mid-level and the other ULDs do. IOW, no change. The debug messages they produce are quite helpful (to me, I use them a lot, and Tony B. has asked for more precision) and well-tuned to the SCSI subsystem (e.g. telling us what sdp represents in useful terms). And they can be compiled out (but not my pr_info above, probably should be a pr_warn). I agree with Johannes. SCSI logging is in sustaining mode. We're trying to remove it, not to add to it. The kernel has much more capable and flexible methods of getting information out to the user these days. No need to resort to arcane logging masks and the like. Examples please, preferably from the SCSI subsystem. If not, I'll do what most other drivers do, drop all debug statements. Doug Gilbert
Re: [PATCH 2/8] sg: introduce sg_log macro
Hi Doug, > I'll follow what the scsi mid-level and the other ULDs do. IOW, no > change. The debug messages they produce are quite helpful (to me, I > use them a lot, and Tony B. has asked for more precision) and > well-tuned to the SCSI subsystem (e.g. telling us what sdp represents > in useful terms). > > And they can be compiled out (but not my pr_info above, probably > should be a pr_warn). I agree with Johannes. SCSI logging is in sustaining mode. We're trying to remove it, not to add to it. The kernel has much more capable and flexible methods of getting information out to the user these days. No need to resort to arcane logging masks and the like. -- Martin K. Petersen Oracle Linux Engineering
Re: [PATCH 2/8] sg: introduce sg_log macro
On 2018-10-19 3:45 a.m., Johannes Thumshirn wrote:
On 19/10/18 08:24, Douglas Gilbert wrote:
[..]
+/*
+ * Kernel needs to be built with CONFIG_SCSI_LOGGING to see log messages.
+ * 'depth' is a number between 1 (most severe) and 7 (most noisy, most
+ * information). All messages are logged as informational (KERN_INFO). In
+ * the unexpected situation where sdp is NULL the macro reverts to a pr_info
+ * and ignores CONFIG_SCSI_LOGGING and always prints to the log.
+ */
+#define SG_LOG(depth, sdp, fmt, a...) \
+ do {\
+ if (IS_ERR_OR_NULL(sdp)) { \
+ pr_info("sg: sdp=NULL_or_ERR, " fmt, ##a);\
+ } else {\
+ SCSI_LOG_TIMEOUT(depth, sdev_prefix_printk( \
+KERN_INFO, (sdp)->device, \
+(sdp)->disk->disk_name, fmt, \
+##a)); \
+ } \
+ } while (0)
Hi Doug,
have you considered using the kernel's dynamic debug infrastructure instead?
Hi,
I'll follow what the scsi mid-level and the other ULDs do. IOW, no
change. The debug messages they produce are quite helpful (to me, I
use them a lot, and Tony B. has asked for more precision) and well-tuned
to the SCSI subsystem (e.g. telling us what sdp represents in useful
terms).
And they can be compiled out (but not my pr_info above, probably
should be a pr_warn).
Doug Gilbert
Re: [PATCH 2/8] sg: introduce sg_log macro
On 19/10/18 08:24, Douglas Gilbert wrote:
[..]
> +/*
> + * Kernel needs to be built with CONFIG_SCSI_LOGGING to see log messages.
> + * 'depth' is a number between 1 (most severe) and 7 (most noisy, most
> + * information). All messages are logged as informational (KERN_INFO). In
> + * the unexpected situation where sdp is NULL the macro reverts to a pr_info
> + * and ignores CONFIG_SCSI_LOGGING and always prints to the log.
> + */
> +#define SG_LOG(depth, sdp, fmt, a...)\
> + do {\
> + if (IS_ERR_OR_NULL(sdp)) { \
> + pr_info("sg: sdp=NULL_or_ERR, " fmt, ##a); \
> + } else {\
> + SCSI_LOG_TIMEOUT(depth, sdev_prefix_printk( \
> + KERN_INFO, (sdp)->device, \
> + (sdp)->disk->disk_name, fmt, \
> + ##a)); \
> + } \
> + } while (0)
Hi Doug,
have you considered using the kernel's dynamic debug infrastructure instead?
--
Johannes ThumshirnSUSE Labs
jthumsh...@suse.de+49 911 74053 689
SUSE LINUX GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: Felix Imendörffer, Jane Smithard, Graham Norton
HRB 21284 (AG Nürnberg)
Key fingerprint = EC38 9CAB C2C4 F25D 8600 D0D0 0393 969D 2D76 0850
[PATCH 2/8] sg: introduce sg_log macro
Introduce the SG_LOG macro to replace long-winded
'SCSI_LOG_TIMEOUT(3, sg_printk ...' debug messages. Use __func__
wherever appropriate to make the debug messages more portable.
Signed-off-by: Douglas Gilbert
---
drivers/scsi/sg.c | 162 +-
1 file changed, 72 insertions(+), 90 deletions(-)
diff --git a/drivers/scsi/sg.c b/drivers/scsi/sg.c
index 7e723f37a269..71623685abfe 100644
--- a/drivers/scsi/sg.c
+++ b/drivers/scsi/sg.c
@@ -216,9 +216,24 @@ static void sg_device_destroy(struct kref *kref);
/* #define SZ_SG_IOVEC sizeof(struct sg_iovec) synonym for 'struct iovec' */
#define SZ_SG_REQ_INFO sizeof(struct sg_req_info)
-#define sg_printk(prefix, sdp, fmt, a...) \
- sdev_prefix_printk(prefix, (sdp)->device, \
- (sdp)->disk->disk_name, fmt, ##a)
+/*
+ * Kernel needs to be built with CONFIG_SCSI_LOGGING to see log messages.
+ * 'depth' is a number between 1 (most severe) and 7 (most noisy, most
+ * information). All messages are logged as informational (KERN_INFO). In
+ * the unexpected situation where sdp is NULL the macro reverts to a pr_info
+ * and ignores CONFIG_SCSI_LOGGING and always prints to the log.
+ */
+#define SG_LOG(depth, sdp, fmt, a...) \
+ do {\
+ if (IS_ERR_OR_NULL(sdp)) { \
+ pr_info("sg: sdp=NULL_or_ERR, " fmt, ##a); \
+ } else {\
+ SCSI_LOG_TIMEOUT(depth, sdev_prefix_printk( \
+KERN_INFO, (sdp)->device, \
+(sdp)->disk->disk_name, fmt, \
+##a)); \
+ } \
+ } while (0)
/*
* The SCSI interfaces that use read() and write() as an asynchronous variant
of
@@ -316,9 +331,8 @@ sg_open(struct inode *inode, struct file *filp)
sdp = sg_get_dev(min_dev);
if (IS_ERR(sdp))
return PTR_ERR(sdp);
-
- SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sdp,
- "sg_open: flags=0x%x\n", flags));
+ SG_LOG(3, sdp, "%s: flags=0x%x; device open count prior=%d\n",
+ __func__, flags, sdp->open_cnt);
/* This driver's module count bumped by fops_get in */
/* Prevent the device driver from vanishing while we sleep */
@@ -414,9 +428,10 @@ sg_release(struct inode *inode, struct file *filp)
return IS_ERR(sfp) ? PTR_ERR(sfp) : -ENXIO;
}
sdp = sfp->parentdp;
- SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sdp, "sg_release\n"));
if (IS_ERR_OR_NULL(sdp))
return IS_ERR(sdp) ? PTR_ERR(sdp) : -ENXIO;
+ SG_LOG(3, sdp, "%s: device open count prior=%d\n", __func__,
+ sdp->open_cnt);
mutex_lock(>open_rel_lock);
scsi_autopm_put_device(sdp->device);
@@ -462,8 +477,7 @@ sg_read(struct file *filp, char __user *buf, size_t count,
loff_t * ppos)
sdp = sfp->parentdp;
if (IS_ERR_OR_NULL(sdp))
return IS_ERR(sdp) ? PTR_ERR(sdp) : -ENXIO;
- SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sdp, "%s: count=%d\n",
-__func__, (int)count));
+ SG_LOG(3, sdp, "%s: read() count=%d\n", __func__, (int)count);
if (!access_ok(VERIFY_WRITE, buf, count))
return -EFAULT;
@@ -663,10 +677,9 @@ sg_write(struct file *filp, const char __user *buf, size_t
count, loff_t * ppos)
return IS_ERR(sfp) ? PTR_ERR(sfp) : -ENXIO;
}
sdp = sfp->parentdp;
+ SG_LOG(3, sdp, "%s: write(3rd arg) count=%d\n", __func__, (int)count);
if (IS_ERR_OR_NULL(sdp))
return IS_ERR(sdp) ? PTR_ERR(sdp) : -ENXIO;
- SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sdp, "%s: count=%d\n",
-__func__, (int)count));
if (atomic_read(>detaching))
return -ENODEV;
if (!((filp->f_flags & O_NONBLOCK) ||
@@ -687,8 +700,7 @@ sg_write(struct file *filp, const char __user *buf, size_t
count, loff_t * ppos)
return -EIO;/* minimum scsi command length is 6 bytes */
if (!(srp = sg_add_request(sfp))) {
- SCSI_LOG_TIMEOUT(1, sg_printk(KERN_INFO, sdp,
- "sg_write: queue full\n"));
+ SG_LOG(1, sdp, "%s: queue full\n", __func__);
return -EDOM;
}
buf += SZ_SG_HEADER;
@@ -703,9 +715,8 @@ sg_write(struct file *filp, const char __user *buf, size_t
count, loff_t * ppos)
cmd_size = 12;
}
mutex_unlock(>f_mutex);
- SCSI_LOG_TIMEOUT(4, sg_printk(KERN_INFO, sdp,
- "%s: scsi
