| Message ID | 20240716161101.30692-1-johan+linaro@kernel.org |
|---|---|
| State | New |
| Headers | show |
| Series | Revert "scsi: sd: Do not repeat the starting disk message" | expand |
On 7/17/24 01:11, Johan Hovold wrote: > This reverts commit 7a6bbc2829d4ab592c7e440a6f6f5deb3cd95db4. > > The offending commit tried to suppress a double "Starting disk" message > for some drivers, but instead started spamming the log with bogus > messages every five seconds: > > [ 311.798956] sd 0:0:0:0: [sda] Starting disk > [ 316.919103] sd 0:0:0:0: [sda] Starting disk > [ 322.040775] sd 0:0:0:0: [sda] Starting disk > [ 327.161140] sd 0:0:0:0: [sda] Starting disk > [ 332.281352] sd 0:0:0:0: [sda] Starting disk > [ 337.401878] sd 0:0:0:0: [sda] Starting disk > [ 342.521527] sd 0:0:0:0: [sda] Starting disk > [ 345.850401] sd 0:0:0:0: [sda] Starting disk > [ 350.967132] sd 0:0:0:0: [sda] Starting disk > [ 356.090454] sd 0:0:0:0: [sda] Starting disk > ... > > on machines that do not actually stop the disk on runtime suspend (e.g. > the Qualcomm sc8280xp CRD with UFS). This is odd. If the disk is not being being suspended, why does the platform even enable runtime PM for it ? Are you sure about this ? Or is it simply that the runtime pm timer is set to a very low interval ? It almost sound like what we need to do here is suppress this message for the runtime resume case, so something like: diff --git a/drivers/scsi/sd.c b/drivers/scsi/sd.c index 2e933fd1de70..4261128bf1f3 100644 --- a/drivers/scsi/sd.c +++ b/drivers/scsi/sd.c @@ -4220,7 +4220,8 @@ static int sd_resume_common(struct device *dev, bool runtime) if (!sdkp) /* E.g.: runtime resume at the start of sd_probe() */ return 0; - sd_printk(KERN_NOTICE, sdkp, "Starting disk\n"); + if (!runtime) + sd_printk(KERN_NOTICE, sdkp, "Starting disk\n"); if (!sd_do_start_stop(sdkp->device, runtime)) { sdkp->suspended = false; However, I would like to make sure that this platform is not calling sd_resume_runtime() for nothing every 5s. If that is the case, then there is a more fundamental problem here and reverting this patch is only hiding that. > > Let's just revert for now to address the regression. > > Fixes: 7a6bbc2829d4 ("scsi: sd: Do not repeat the starting disk message") > Cc: stable@vger.kernel.org > Signed-off-by: Johan Hovold <johan+linaro@kernel.org> > --- > drivers/scsi/sd.c | 5 +++-- > 1 file changed, 3 insertions(+), 2 deletions(-) > > > Hi, > > I just noticed this regression that snuck into 6.10-final and tracked it > down to 7a6bbc2829d4 ("scsi: sd: Do not repeat the starting disk > message"). > > I wanted to get this out ASAP to address the immediate regression while > someone who cares enough can work out a proper fix for the double start > message (which seems less annoying). > > Note that the offending commit is marked for stable. > > Johan > > > diff --git a/drivers/scsi/sd.c b/drivers/scsi/sd.c > index 1b7561abe05d..6b64af7d4927 100644 > --- a/drivers/scsi/sd.c > +++ b/drivers/scsi/sd.c > @@ -4119,6 +4119,8 @@ static int sd_resume(struct device *dev) > { > struct scsi_disk *sdkp = dev_get_drvdata(dev); > > + sd_printk(KERN_NOTICE, sdkp, "Starting disk\n"); > + > if (opal_unlock_from_suspend(sdkp->opal_dev)) { > sd_printk(KERN_NOTICE, sdkp, "OPAL unlock failed\n"); > return -EIO; > @@ -4135,13 +4137,12 @@ static int sd_resume_common(struct device *dev, bool runtime) > if (!sdkp) /* E.g.: runtime resume at the start of sd_probe() */ > return 0; > > - sd_printk(KERN_NOTICE, sdkp, "Starting disk\n"); > - > if (!sd_do_start_stop(sdkp->device, runtime)) { > sdkp->suspended = false; > return 0; > } > > + sd_printk(KERN_NOTICE, sdkp, "Starting disk\n"); > ret = sd_start_stop_device(sdkp, 1); > if (!ret) { > sd_resume(dev);
On Wed, Jul 17, 2024 at 07:48:26AM +0900, Damien Le Moal wrote: > On 7/17/24 01:11, Johan Hovold wrote: > > This reverts commit 7a6bbc2829d4ab592c7e440a6f6f5deb3cd95db4. > > > > The offending commit tried to suppress a double "Starting disk" message > > for some drivers, but instead started spamming the log with bogus > > messages every five seconds: > > > > [ 311.798956] sd 0:0:0:0: [sda] Starting disk > > [ 316.919103] sd 0:0:0:0: [sda] Starting disk > > [ 322.040775] sd 0:0:0:0: [sda] Starting disk > > [ 327.161140] sd 0:0:0:0: [sda] Starting disk > > [ 332.281352] sd 0:0:0:0: [sda] Starting disk > > [ 337.401878] sd 0:0:0:0: [sda] Starting disk > > [ 342.521527] sd 0:0:0:0: [sda] Starting disk > > [ 345.850401] sd 0:0:0:0: [sda] Starting disk > > [ 350.967132] sd 0:0:0:0: [sda] Starting disk > > [ 356.090454] sd 0:0:0:0: [sda] Starting disk > > ... > > > > on machines that do not actually stop the disk on runtime suspend (e.g. > > the Qualcomm sc8280xp CRD with UFS). > > This is odd. If the disk is not being being suspended, why does the platform > even enable runtime PM for it ? This is clearly intended to be supported as sd_do_start_stop() returns false and that prevents sd_start_stop_device() from being called on resume (and similarly on suspend which is why there are no matching stopping disk messages above): [ 32.822189] sd 0:0:0:0: sd_resume_common - runtime = 1, sd_do_start_stop = 0, manage_runtime_start_stop = 0 > Are you sure about this ? Or is it simply that > the runtime pm timer is set to a very low interval ? I haven't tried to determine why runtime pm is used this way, but your patch is clearly broken as it prints a message about starting the disk even when sd_do_start_stop() returns false. > It almost sound like what we need to do here is suppress this message for the > runtime resume case, so something like: No, that would only make things worse as I assume you'd have a stopped disk message without a matching start message for driver that do end up stopping the disk here. > However, I would like to make sure that this platform is not calling > sd_resume_runtime() for nothing every 5s. If that is the case, then there is a > more fundamental problem here and reverting this patch is only hiding that. This is with the Qualcomm UFS driver, but it seems it just relies on the generic ufshcd_pltfrm_init() implementation. Also not sure why anyone would want to see these messages on every runtime suspend (for drivers that end up taking this path), but that's a separate discussion. Johan
On Wed, Jul 17, 2024 at 07:46:14PM +0900, Damien Le Moal wrote: > On 7/17/24 18:00, Johan Hovold wrote: > > On Wed, Jul 17, 2024 at 07:48:26AM +0900, Damien Le Moal wrote: > >> On 7/17/24 01:11, Johan Hovold wrote: > >>> This reverts commit 7a6bbc2829d4ab592c7e440a6f6f5deb3cd95db4. > >>> > >>> The offending commit tried to suppress a double "Starting disk" message > >>> for some drivers, but instead started spamming the log with bogus > >>> messages every five seconds: > >>> > >>> [ 311.798956] sd 0:0:0:0: [sda] Starting disk > >>> [ 316.919103] sd 0:0:0:0: [sda] Starting disk > >>> [ 322.040775] sd 0:0:0:0: [sda] Starting disk > >>> [ 327.161140] sd 0:0:0:0: [sda] Starting disk > >>> [ 332.281352] sd 0:0:0:0: [sda] Starting disk > >>> [ 337.401878] sd 0:0:0:0: [sda] Starting disk > >>> [ 342.521527] sd 0:0:0:0: [sda] Starting disk > >>> [ 345.850401] sd 0:0:0:0: [sda] Starting disk > >>> [ 350.967132] sd 0:0:0:0: [sda] Starting disk > >>> [ 356.090454] sd 0:0:0:0: [sda] Starting disk > >>> ... > >>> > >>> on machines that do not actually stop the disk on runtime suspend (e.g. > >>> the Qualcomm sc8280xp CRD with UFS). > >> > >> This is odd. If the disk is not being being suspended, why does the platform > >> even enable runtime PM for it ? > > > > This is clearly intended to be supported as sd_do_start_stop() returns > > false and that prevents sd_start_stop_device() from being called on > > resume (and similarly on suspend which is why there are no matching > > stopping disk messages above): > > > > [ 32.822189] sd 0:0:0:0: sd_resume_common - runtime = 1, sd_do_start_stop = 0, manage_runtime_start_stop = 0 > > Yes, so we can suppress the "Starting disk" message for runtime resume, to match > the runtime suspend not having the message. No, the point is that the stopping disk message is also suppressed when sd_do_start_stop() returns false (i.e. when sd_start_stop_device() is never called). See sd_suspend_common(). > >> Are you sure about this ? Or is it simply that > >> the runtime pm timer is set to a very low interval ? > > > > I haven't tried to determine why runtime pm is used this way, but your > > patch is clearly broken as it prints a message about starting the disk > > even when sd_do_start_stop() returns false. > > The patch is not *that* broken, because sd_do_start_stop() returning false mean > only that the disk will *not* be started using a START STOP UNIT command. But > the underlying LLD must start the drive. So the message is not wrong, even > though it is probably best to suppress it for the runtime case.
On 7/17/24 01:11, Johan Hovold wrote: > This reverts commit 7a6bbc2829d4ab592c7e440a6f6f5deb3cd95db4. > > The offending commit tried to suppress a double "Starting disk" message > for some drivers, but instead started spamming the log with bogus > messages every five seconds: > > [ 311.798956] sd 0:0:0:0: [sda] Starting disk > [ 316.919103] sd 0:0:0:0: [sda] Starting disk > [ 322.040775] sd 0:0:0:0: [sda] Starting disk > [ 327.161140] sd 0:0:0:0: [sda] Starting disk > [ 332.281352] sd 0:0:0:0: [sda] Starting disk > [ 337.401878] sd 0:0:0:0: [sda] Starting disk > [ 342.521527] sd 0:0:0:0: [sda] Starting disk > [ 345.850401] sd 0:0:0:0: [sda] Starting disk > [ 350.967132] sd 0:0:0:0: [sda] Starting disk > [ 356.090454] sd 0:0:0:0: [sda] Starting disk > ... > > on machines that do not actually stop the disk on runtime suspend (e.g. > the Qualcomm sc8280xp CRD with UFS). > > Let's just revert for now to address the regression. > > Fixes: 7a6bbc2829d4 ("scsi: sd: Do not repeat the starting disk message") > Cc: stable@vger.kernel.org > Signed-off-by: Johan Hovold <johan+linaro@kernel.org> Reviewed-by: Damien Le Moal <dlemoal@kernel.org>
Johan,
> This reverts commit 7a6bbc2829d4ab592c7e440a6f6f5deb3cd95db4.
Applied to 6.11/scsi-staging, thanks!
diff --git a/drivers/scsi/sd.c b/drivers/scsi/sd.c index 1b7561abe05d..6b64af7d4927 100644 --- a/drivers/scsi/sd.c +++ b/drivers/scsi/sd.c @@ -4119,6 +4119,8 @@ static int sd_resume(struct device *dev) { struct scsi_disk *sdkp = dev_get_drvdata(dev); + sd_printk(KERN_NOTICE, sdkp, "Starting disk\n"); + if (opal_unlock_from_suspend(sdkp->opal_dev)) { sd_printk(KERN_NOTICE, sdkp, "OPAL unlock failed\n"); return -EIO; @@ -4135,13 +4137,12 @@ static int sd_resume_common(struct device *dev, bool runtime) if (!sdkp) /* E.g.: runtime resume at the start of sd_probe() */ return 0; - sd_printk(KERN_NOTICE, sdkp, "Starting disk\n"); - if (!sd_do_start_stop(sdkp->device, runtime)) { sdkp->suspended = false; return 0; } + sd_printk(KERN_NOTICE, sdkp, "Starting disk\n"); ret = sd_start_stop_device(sdkp, 1); if (!ret) { sd_resume(dev);
This reverts commit 7a6bbc2829d4ab592c7e440a6f6f5deb3cd95db4. The offending commit tried to suppress a double "Starting disk" message for some drivers, but instead started spamming the log with bogus messages every five seconds: [ 311.798956] sd 0:0:0:0: [sda] Starting disk [ 316.919103] sd 0:0:0:0: [sda] Starting disk [ 322.040775] sd 0:0:0:0: [sda] Starting disk [ 327.161140] sd 0:0:0:0: [sda] Starting disk [ 332.281352] sd 0:0:0:0: [sda] Starting disk [ 337.401878] sd 0:0:0:0: [sda] Starting disk [ 342.521527] sd 0:0:0:0: [sda] Starting disk [ 345.850401] sd 0:0:0:0: [sda] Starting disk [ 350.967132] sd 0:0:0:0: [sda] Starting disk [ 356.090454] sd 0:0:0:0: [sda] Starting disk ... on machines that do not actually stop the disk on runtime suspend (e.g. the Qualcomm sc8280xp CRD with UFS). Let's just revert for now to address the regression. Fixes: 7a6bbc2829d4 ("scsi: sd: Do not repeat the starting disk message") Cc: stable@vger.kernel.org Signed-off-by: Johan Hovold <johan+linaro@kernel.org> --- drivers/scsi/sd.c | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) Hi, I just noticed this regression that snuck into 6.10-final and tracked it down to 7a6bbc2829d4 ("scsi: sd: Do not repeat the starting disk message"). I wanted to get this out ASAP to address the immediate regression while someone who cares enough can work out a proper fix for the double start message (which seems less annoying). Note that the offending commit is marked for stable. Johan