| Message ID | 20200408171012.76890-1-dwagner@suse.de (mailing list archive) |
|---|---|
| State | Rejected |
| Headers | show |
| Series | scsi: core: Rate limit "rejecting I/O" messages | expand |
On Wed, 2020-04-08 at 19:10 +0200, Daniel Wagner wrote: > +#define sdev_printk_ratelimited(l, sdev, fmt, a...) > \ > +({ > \ > + static DEFINE_RATELIMIT_STATE(_rs, > \ > + DEFAULT_RATELIMIT_INTERVAL, > \ > + DEFAULT_RATELIMIT_BURST); > \ > + > \ > + if (__ratelimit(&_rs)) > \ > + sdev_prefix_printk(l, sdev, NULL, fmt, ##a); If we do go with a ratelimit architecture for sdev_printk, I would think the limit has to be per sdev, because we wouldn't want a burst of messages on one sdev to suppress messages on another. For this particular issue, I suppose one target can have many sdevs, so you'd prefer to rate limit by target? James
On Wed, 2020-04-08 at 19:10 +0200, Daniel Wagner wrote: > Prevent excessive logging by rate limiting the "rejecting I/O" > messages. For example in setups where remote syslog is used the link > is saturated by those messages when a storage controller/disk > misbehaves. > > Cc: "James E.J. Bottomley" <jejb@linux.ibm.com> > Cc: "Martin K. Petersen" <martin.petersen@oracle.com> > Signed-off-by: Daniel Wagner <dwagner@suse.de> > --- > drivers/scsi/scsi_lib.c | 4 ++-- > include/scsi/scsi_device.h | 10 ++++++++++ > 2 files changed, 12 insertions(+), 2 deletions(-) > > diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c > index 47835c4b4ee0..01c35c58c6f3 100644 > --- a/drivers/scsi/scsi_lib.c > +++ b/drivers/scsi/scsi_lib.c > @@ -1217,7 +1217,7 @@ scsi_prep_state_check(struct scsi_device *sdev, > struct request *req) > */ > if (!sdev->offline_already) { > sdev->offline_already = true; > - sdev_printk(KERN_ERR, sdev, > + sdev_printk_ratelimited(KERN_ERR, sdev, > "rejecting I/O to offline > device\n"); I would really prefer we not do it this way if at all possible. It loses information we may need to debug SAN outage problems. The reason I didn't use ratelimit is that the ratelimit structure is per-instance of the ratelimit call here, not per-device. So this doesn't work right -- it will drop messages for other devices. > } > return BLK_STS_IOERR; > @@ -1226,7 +1226,7 @@ scsi_prep_state_check(struct scsi_device *sdev, > struct request *req) > * If the device is fully deleted, we refuse to > * process any commands as well. > */ > - sdev_printk(KERN_ERR, sdev, > + sdev_printk_ratelimited(KERN_ERR, sdev, > "rejecting I/O to dead device\n"); I practice I hardly see this message, do you actually have a case where this happens? If so perhaps add another flag similar to offline_already? The offline message happens a *lot*, we get a ton of them for each active device when the queues are unblocked when a target goes away. -Ewan > return BLK_STS_IOERR; > case SDEV_BLOCK: > diff --git a/include/scsi/scsi_device.h b/include/scsi/scsi_device.h > index c3cba2aaf934..8be40b0e1b8f 100644 > --- a/include/scsi/scsi_device.h > +++ b/include/scsi/scsi_device.h > @@ -257,6 +257,16 @@ sdev_prefix_printk(const char *, const struct > scsi_device *, const char *, > #define sdev_printk(l, sdev, fmt, a...) > \ > sdev_prefix_printk(l, sdev, NULL, fmt, ##a) > > +#define sdev_printk_ratelimited(l, sdev, fmt, a...) > \ > +({ > \ > + static DEFINE_RATELIMIT_STATE(_rs, > \ > + DEFAULT_RATELIMIT_INTERVAL, \ > + DEFAULT_RATELIMIT_BURST); > \ > + > \ > + if (__ratelimit(&_rs)) > \ > + sdev_prefix_printk(l, sdev, NULL, fmt, ##a); > \ > +}) > + > __printf(3, 4) void > scmd_printk(const char *, const struct scsi_cmnd *, const char *, > ...); >
On Wed, 2020-04-08 at 15:16 -0400, Ewan D. Milne wrote: > On Wed, 2020-04-08 at 19:10 +0200, Daniel Wagner wrote: > > Prevent excessive logging by rate limiting the "rejecting I/O" > > messages. For example in setups where remote syslog is used the link > > is saturated by those messages when a storage controller/disk > > misbehaves. > > > > Cc: "James E.J. Bottomley" <jejb@linux.ibm.com> > > Cc: "Martin K. Petersen" <martin.petersen@oracle.com> > > Signed-off-by: Daniel Wagner <dwagner@suse.de> > > --- > > drivers/scsi/scsi_lib.c | 4 ++-- > > include/scsi/scsi_device.h | 10 ++++++++++ > > 2 files changed, 12 insertions(+), 2 deletions(-) > > > > diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c > > index 47835c4b4ee0..01c35c58c6f3 100644 > > --- a/drivers/scsi/scsi_lib.c > > +++ b/drivers/scsi/scsi_lib.c > > @@ -1217,7 +1217,7 @@ scsi_prep_state_check(struct scsi_device *sdev, > > struct request *req) > > */ > > if (!sdev->offline_already) { > > sdev->offline_already = true; > > - sdev_printk(KERN_ERR, sdev, > > + sdev_printk_ratelimited(KERN_ERR, sdev, > > "rejecting I/O to offline > > device\n"); > > I would really prefer we not do it this way if at all possible. > It loses information we may need to debug SAN outage problems. > > The reason I didn't use ratelimit is that the ratelimit structure is > per-instance of the ratelimit call here, not per-device. So this > doesn't work right -- it will drop messages for other devices. Could add a ratelimit_state to struct scsi_device. Something like: --- drivers/scsi/scsi_scan.c | 2 ++ include/scsi/scsi_device.h | 2 ++ 2 files changed, 4 insertions(+) diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c index f2437a..938c83f 100644 --- a/drivers/scsi/scsi_scan.c +++ b/drivers/scsi/scsi_scan.c @@ -279,6 +279,8 @@ static struct scsi_device *scsi_alloc_sdev(struct scsi_target *starget, scsi_change_queue_depth(sdev, sdev->host->cmd_per_lun ? sdev->host->cmd_per_lun : 1); + ratelimit_state_init(&sdev->rs, DEFAULT_RATELIMIT_INTERVAL, + DEFAULT_RATELIMIT_BURST); scsi_sysfs_device_initialize(sdev); if (shost->hostt->slave_alloc) { diff --git a/include/scsi/scsi_device.h b/include/scsi/scsi_device.h index c3cba2..2600de7 100644 --- a/include/scsi/scsi_device.h +++ b/include/scsi/scsi_device.h @@ -8,6 +8,7 @@ #include <linux/blkdev.h> #include <scsi/scsi.h> #include <linux/atomic.h> +#include <linux/ratelimit.h> struct device; struct request_queue; @@ -233,6 +234,7 @@ struct scsi_device { struct mutex state_mutex; enum scsi_device_state sdev_state; struct task_struct *quiesced_by; + struct ratelimit_state rs; unsigned long sdev_data[]; } __attribute__((aligned(sizeof(unsigned long))));
Hi Ewan, On Wed, Apr 08, 2020 at 03:16:27PM -0400, Ewan D. Milne wrote: > On Wed, 2020-04-08 at 19:10 +0200, Daniel Wagner wrote: > > --- a/drivers/scsi/scsi_lib.c > > +++ b/drivers/scsi/scsi_lib.c > > @@ -1217,7 +1217,7 @@ scsi_prep_state_check(struct scsi_device *sdev, > > struct request *req) > > */ > > if (!sdev->offline_already) { > > sdev->offline_already = true; > > - sdev_printk(KERN_ERR, sdev, > > + sdev_printk_ratelimited(KERN_ERR, sdev, > > "rejecting I/O to offline > > device\n"); > > I would really prefer we not do it this way if at all possible. > It loses information we may need to debug SAN outage problems. Understood. > The reason I didn't use ratelimit is that the ratelimit structure is > per-instance of the ratelimit call here, not per-device. So this > doesn't work right -- it will drop messages for other devices. I didn't really think this through. Sorry. > > - sdev_printk(KERN_ERR, sdev, > > + sdev_printk_ratelimited(KERN_ERR, sdev, > > "rejecting I/O to dead device\n"); > > I practice I hardly see this message, do you actually have a case > where this happens? If so perhaps add another flag similar to > offline_already? > > The offline message happens a *lot*, we get a ton of them for each > active device when the queues are unblocked when a target goes away. I've missed commit b0962c53bde9 ("scsi: core: avoid repetitive logging of device offline messages") which should address the report I got in our enterprise kernel. I was over eager to rate limit the 'dead device' as well. It seem no need for this patch. Let me backport the commit and see what our customer has to say. Thanks for the help! Daniel
On Wed, 2020-04-08 at 12:49 -0700, Joe Perches wrote: > > Could add a ratelimit_state to struct scsi_device. > > Something like: > --- > drivers/scsi/scsi_scan.c | 2 ++ > include/scsi/scsi_device.h | 2 ++ > 2 files changed, 4 insertions(+) > > diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c > index f2437a..938c83f 100644 > --- a/drivers/scsi/scsi_scan.c > +++ b/drivers/scsi/scsi_scan.c > @@ -279,6 +279,8 @@ static struct scsi_device *scsi_alloc_sdev(struct > scsi_target *starget, > scsi_change_queue_depth(sdev, sdev->host->cmd_per_lun ? > sdev->host->cmd_per_lun : 1); > > + ratelimit_state_init(&sdev->rs, DEFAULT_RATELIMIT_INTERVAL, > + DEFAULT_RATELIMIT_BURST); > scsi_sysfs_device_initialize(sdev); > > if (shost->hostt->slave_alloc) { > diff --git a/include/scsi/scsi_device.h b/include/scsi/scsi_device.h > index c3cba2..2600de7 100644 > --- a/include/scsi/scsi_device.h > +++ b/include/scsi/scsi_device.h > @@ -8,6 +8,7 @@ > #include <linux/blkdev.h> > #include <scsi/scsi.h> > #include <linux/atomic.h> > +#include <linux/ratelimit.h> > > struct device; > struct request_queue; > @@ -233,6 +234,7 @@ struct scsi_device { > struct mutex state_mutex; > enum scsi_device_state sdev_state; > struct task_struct *quiesced_by; > + struct ratelimit_state rs; > unsigned long sdev_data[]; > } __attribute__((aligned(sizeof(unsigned long)))); > We could but in our experience this may not work well enough. We do wants to see the message when the device goes offline, so we can look at logs from SAN failures to see when that happened, but logging more than one message per device is worthless. And there can be *LOTS* of LUNs behind targets that go away. Hundreds. Thousands, even. I keep getting crash dumps with nothing useful in the dmesg buffer. And we see a lot of serial console lockups. -Ewan
diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c index 47835c4b4ee0..01c35c58c6f3 100644 --- a/drivers/scsi/scsi_lib.c +++ b/drivers/scsi/scsi_lib.c @@ -1217,7 +1217,7 @@ scsi_prep_state_check(struct scsi_device *sdev, struct request *req) */ if (!sdev->offline_already) { sdev->offline_already = true; - sdev_printk(KERN_ERR, sdev, + sdev_printk_ratelimited(KERN_ERR, sdev, "rejecting I/O to offline device\n"); } return BLK_STS_IOERR; @@ -1226,7 +1226,7 @@ scsi_prep_state_check(struct scsi_device *sdev, struct request *req) * If the device is fully deleted, we refuse to * process any commands as well. */ - sdev_printk(KERN_ERR, sdev, + sdev_printk_ratelimited(KERN_ERR, sdev, "rejecting I/O to dead device\n"); return BLK_STS_IOERR; case SDEV_BLOCK: diff --git a/include/scsi/scsi_device.h b/include/scsi/scsi_device.h index c3cba2aaf934..8be40b0e1b8f 100644 --- a/include/scsi/scsi_device.h +++ b/include/scsi/scsi_device.h @@ -257,6 +257,16 @@ sdev_prefix_printk(const char *, const struct scsi_device *, const char *, #define sdev_printk(l, sdev, fmt, a...) \ sdev_prefix_printk(l, sdev, NULL, fmt, ##a) +#define sdev_printk_ratelimited(l, sdev, fmt, a...) \ +({ \ + static DEFINE_RATELIMIT_STATE(_rs, \ + DEFAULT_RATELIMIT_INTERVAL, \ + DEFAULT_RATELIMIT_BURST); \ + \ + if (__ratelimit(&_rs)) \ + sdev_prefix_printk(l, sdev, NULL, fmt, ##a); \ +}) + __printf(3, 4) void scmd_printk(const char *, const struct scsi_cmnd *, const char *, ...);
Prevent excessive logging by rate limiting the "rejecting I/O" messages. For example in setups where remote syslog is used the link is saturated by those messages when a storage controller/disk misbehaves. Cc: "James E.J. Bottomley" <jejb@linux.ibm.com> Cc: "Martin K. Petersen" <martin.petersen@oracle.com> Signed-off-by: Daniel Wagner <dwagner@suse.de> --- drivers/scsi/scsi_lib.c | 4 ++-- include/scsi/scsi_device.h | 10 ++++++++++ 2 files changed, 12 insertions(+), 2 deletions(-)