2023-07-27 10:55:52

by Damien Le Moal

[permalink] [raw]
Subject: Re: Scsi_bus_resume+0x0/0x90 returns -5 when resuming from s3 sleep

On 7/27/23 19:22, TW wrote:
> I managed to fix the patch file, guess the formatting messed up a bit. So will
> try with those patches installed.

Just in case, patch fil attached to avoid formatting issues.


--
Damien Le Moal
Western Digital Research


Attachments:
0001-ata-scsi-do-not-issue-START-STOP-UNIT-on-resume.patch (2.40 kB)

2023-07-27 13:12:13

by TW

[permalink] [raw]
Subject: Re: Scsi_bus_resume+0x0/0x90 returns -5 when resuming from s3 sleep

It was all 1 patch but the first change had a formatting issue from the
email format I guess. So I fixed that and the patch went through and
looks like the drive error message has stopped. Still a little slow
coming back but that error is gone at least.

Jul 27 05:05:05 rageworks systemd[1]: Starting System Suspend...
Jul 27 05:05:05 rageworks systemd-sleep[1624]: Entering sleep state
'suspend'...
Jul 27 05:05:05 rageworks kernel: PM: suspend entry (deep)
Jul 27 05:05:05 rageworks kernel: Filesystems sync: 0.246 seconds
Jul 27 05:05:26 rageworks kernel: Freezing user space processes
Jul 27 05:05:26 rageworks kernel: Freezing user space processes
completed (elapsed 0.001 seconds)
Jul 27 05:05:26 rageworks kernel: OOM killer disabled.
Jul 27 05:05:26 rageworks kernel: Freezing remaining freezable tasks
Jul 27 05:05:26 rageworks kernel: Freezing remaining freezable tasks
completed (elapsed 0.000 seconds)
Jul 27 05:05:26 rageworks kernel: printk: Suspending console(s) (use
no_console_suspend to debug)
Jul 27 05:05:26 rageworks kernel: serial 00:05: disabled
Jul 27 05:05:26 rageworks kernel: sd 9:0:0:0: [sdc] Synchronizing SCSI cache
Jul 27 05:05:26 rageworks kernel: sd 1:0:0:0: [sdb] Synchronizing SCSI cache
Jul 27 05:05:26 rageworks kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache
Jul 27 05:05:26 rageworks kernel: sd 9:0:0:0: [sdc] Stopping disk
Jul 27 05:05:26 rageworks kernel: sd 1:0:0:0: [sdb] Stopping disk
Jul 27 05:05:26 rageworks kernel: sd 0:0:0:0: [sda] Stopping disk
Jul 27 05:05:26 rageworks kernel: ACPI: PM: Preparing to enter system
sleep state S3
Jul 27 05:05:26 rageworks kernel: ACPI: PM: Saving platform NVS memory
Jul 27 05:05:26 rageworks kernel: Disabling non-boot CPUs ...
Jul 27 05:05:26 rageworks kernel: smpboot: CPU 1 is now offline
Jul 27 05:05:26 rageworks kernel: smpboot: CPU 2 is now offline
Jul 27 05:05:26 rageworks kernel: smpboot: CPU 3 is now offline
Jul 27 05:05:26 rageworks kernel: ACPI: PM: Low-level resume complete
Jul 27 05:05:26 rageworks kernel: ACPI: PM: Restoring platform NVS memory
Jul 27 05:05:26 rageworks kernel: Enabling non-boot CPUs ...
Jul 27 05:05:26 rageworks kernel: smpboot: Booting Node 0 Processor 1
APIC 0x1
Jul 27 05:05:26 rageworks kernel: CPU1 is up
Jul 27 05:05:26 rageworks kernel: smpboot: Booting Node 0 Processor 2
APIC 0x2
Jul 27 05:05:26 rageworks kernel: CPU2 is up
Jul 27 05:05:26 rageworks kernel: smpboot: Booting Node 0 Processor 3
APIC 0x3
Jul 27 05:05:26 rageworks kernel: CPU3 is up
Jul 27 05:05:26 rageworks kernel: ACPI: PM: Waking up from system sleep
state S3
Jul 27 05:05:26 rageworks kernel: xhci_hcd 0000:02:00.0: xHC error in
resume, USBSTS 0x401, Reinit
Jul 27 05:05:26 rageworks kernel: usb usb1: root hub lost power or was reset
Jul 27 05:05:26 rageworks kernel: usb usb2: root hub lost power or was reset
Jul 27 05:05:26 rageworks kernel: sd 0:0:0:0: [sda] Starting disk
Jul 27 05:05:26 rageworks kernel: sd 1:0:0:0: [sdb] Starting disk
Jul 27 05:05:26 rageworks kernel: sd 9:0:0:0: [sdc] Starting disk
Jul 27 05:05:26 rageworks kernel: serial 00:05: activated
Jul 27 05:05:26 rageworks kernel: ata6: SATA link down (SStatus 0
SControl 330)
Jul 27 05:05:26 rageworks kernel: ata5: SATA link down (SStatus 0
SControl 330)
Jul 27 05:05:26 rageworks kernel: ata9: SATA link down (SStatus 0
SControl 300)
Jul 27 05:05:26 rageworks kernel: usb 1-10: reset full-speed USB device
number 4 using xhci_hcd
Jul 27 05:05:26 rageworks kernel: usb 1-8: reset full-speed USB device
number 3 using xhci_hcd
Jul 27 05:05:26 rageworks kernel: usb 1-7: reset full-speed USB device
number 2 using xhci_hcd
Jul 27 05:05:26 rageworks kernel: OOM killer enabled.
Jul 27 05:05:26 rageworks kernel: Restarting tasks ... done.
Jul 27 05:05:26 rageworks kernel: random: crng reseeded on system resumption
Jul 27 05:05:26 rageworks kernel: PM: suspend exit


On 7/27/23 04:27, Damien Le Moal wrote:
> On 7/27/23 19:22, TW wrote:
>> I managed to fix the patch file, guess the formatting messed up a bit. So will
>> try with those patches installed.
> Just in case, patch fil attached to avoid formatting issues.
>
>

2023-07-28 02:51:53

by Damien Le Moal

[permalink] [raw]
Subject: Re: Scsi_bus_resume+0x0/0x90 returns -5 when resuming from s3 sleep

On 7/27/23 21:25, TW wrote:
> It was all 1 patch but the first change had a formatting issue from the
> email format I guess. So I fixed that and the patch went through and
> looks like the drive error message has stopped. Still a little slow
> coming back but that error is gone at least.

"Slow coming back" -> Compared to which version of the kernel ? Do you have
numbers ?

If the devices are HDDs, resume will wait for these to spin up. That takes a
while (about 10s normally).

>
> Jul 27 05:05:05 rageworks systemd[1]: Starting System Suspend...
> Jul 27 05:05:05 rageworks systemd-sleep[1624]: Entering sleep state
> 'suspend'...
> Jul 27 05:05:05 rageworks kernel: PM: suspend entry (deep)
> Jul 27 05:05:05 rageworks kernel: Filesystems sync: 0.246 seconds
> Jul 27 05:05:26 rageworks kernel: Freezing user space processes
> Jul 27 05:05:26 rageworks kernel: Freezing user space processes
> completed (elapsed 0.001 seconds)
> Jul 27 05:05:26 rageworks kernel: OOM killer disabled.
> Jul 27 05:05:26 rageworks kernel: Freezing remaining freezable tasks
> Jul 27 05:05:26 rageworks kernel: Freezing remaining freezable tasks
> completed (elapsed 0.000 seconds)
> Jul 27 05:05:26 rageworks kernel: printk: Suspending console(s) (use
> no_console_suspend to debug)
> Jul 27 05:05:26 rageworks kernel: serial 00:05: disabled
> Jul 27 05:05:26 rageworks kernel: sd 9:0:0:0: [sdc] Synchronizing SCSI cache
> Jul 27 05:05:26 rageworks kernel: sd 1:0:0:0: [sdb] Synchronizing SCSI cache
> Jul 27 05:05:26 rageworks kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache
> Jul 27 05:05:26 rageworks kernel: sd 9:0:0:0: [sdc] Stopping disk
> Jul 27 05:05:26 rageworks kernel: sd 1:0:0:0: [sdb] Stopping disk
> Jul 27 05:05:26 rageworks kernel: sd 0:0:0:0: [sda] Stopping disk
> Jul 27 05:05:26 rageworks kernel: ACPI: PM: Preparing to enter system
> sleep state S3
> Jul 27 05:05:26 rageworks kernel: ACPI: PM: Saving platform NVS memory
> Jul 27 05:05:26 rageworks kernel: Disabling non-boot CPUs ...
> Jul 27 05:05:26 rageworks kernel: smpboot: CPU 1 is now offline
> Jul 27 05:05:26 rageworks kernel: smpboot: CPU 2 is now offline
> Jul 27 05:05:26 rageworks kernel: smpboot: CPU 3 is now offline
> Jul 27 05:05:26 rageworks kernel: ACPI: PM: Low-level resume complete
> Jul 27 05:05:26 rageworks kernel: ACPI: PM: Restoring platform NVS memory
> Jul 27 05:05:26 rageworks kernel: Enabling non-boot CPUs ...
> Jul 27 05:05:26 rageworks kernel: smpboot: Booting Node 0 Processor 1
> APIC 0x1
> Jul 27 05:05:26 rageworks kernel: CPU1 is up
> Jul 27 05:05:26 rageworks kernel: smpboot: Booting Node 0 Processor 2
> APIC 0x2
> Jul 27 05:05:26 rageworks kernel: CPU2 is up
> Jul 27 05:05:26 rageworks kernel: smpboot: Booting Node 0 Processor 3
> APIC 0x3
> Jul 27 05:05:26 rageworks kernel: CPU3 is up
> Jul 27 05:05:26 rageworks kernel: ACPI: PM: Waking up from system sleep
> state S3
> Jul 27 05:05:26 rageworks kernel: xhci_hcd 0000:02:00.0: xHC error in
> resume, USBSTS 0x401, Reinit
> Jul 27 05:05:26 rageworks kernel: usb usb1: root hub lost power or was reset
> Jul 27 05:05:26 rageworks kernel: usb usb2: root hub lost power or was reset
> Jul 27 05:05:26 rageworks kernel: sd 0:0:0:0: [sda] Starting disk
> Jul 27 05:05:26 rageworks kernel: sd 1:0:0:0: [sdb] Starting disk
> Jul 27 05:05:26 rageworks kernel: sd 9:0:0:0: [sdc] Starting disk
> Jul 27 05:05:26 rageworks kernel: serial 00:05: activated
> Jul 27 05:05:26 rageworks kernel: ata6: SATA link down (SStatus 0
> SControl 330)
> Jul 27 05:05:26 rageworks kernel: ata5: SATA link down (SStatus 0
> SControl 330)
> Jul 27 05:05:26 rageworks kernel: ata9: SATA link down (SStatus 0
> SControl 300)
> Jul 27 05:05:26 rageworks kernel: usb 1-10: reset full-speed USB device
> number 4 using xhci_hcd
> Jul 27 05:05:26 rageworks kernel: usb 1-8: reset full-speed USB device
> number 3 using xhci_hcd
> Jul 27 05:05:26 rageworks kernel: usb 1-7: reset full-speed USB device
> number 2 using xhci_hcd
> Jul 27 05:05:26 rageworks kernel: OOM killer enabled.
> Jul 27 05:05:26 rageworks kernel: Restarting tasks ... done.
> Jul 27 05:05:26 rageworks kernel: random: crng reseeded on system resumption
> Jul 27 05:05:26 rageworks kernel: PM: suspend exit
>
>
> On 7/27/23 04:27, Damien Le Moal wrote:
>> On 7/27/23 19:22, TW wrote:
>>> I managed to fix the patch file, guess the formatting messed up a bit. So will
>>> try with those patches installed.
>> Just in case, patch fil attached to avoid formatting issues.
>>
>>

--
Damien Le Moal
Western Digital Research


2023-07-28 05:03:25

by TW

[permalink] [raw]
Subject: Re: Scsi_bus_resume+0x0/0x90 returns -5 when resuming from s3 sleep

Comparing to the 5.15 kernel which had almost no delay. They are HDDs
though, it was working flawlessly earlier but didn't want to top post
again. Tried a systemd suspend instead of from the Xfce4 logout menu and
everything works as intended. So I'd say that it's fixed now.

On 7/27/23 20:33, Damien Le Moal wrote:
> "Slow coming back" -> Compared to which version of the kernel ? Do you
> have numbers ? If the devices are HDDs, resume will wait for these to
> spin up. That takes a while (about 10s normally).

2023-07-31 01:20:23

by Damien Le Moal

[permalink] [raw]
Subject: Re: Scsi_bus_resume+0x0/0x90 returns -5 when resuming from s3 sleep

On 7/28/23 11:49, TW wrote:
> Comparing to the 5.15 kernel which had almost no delay. They are HDDs
> though, it was working flawlessly earlier but didn't want to top post
> again. Tried a systemd suspend instead of from the Xfce4 logout menu and
> everything works as intended. So I'd say that it's fixed now.

I posted a proper patch and CC-ed you. A "Tested-by:" tag from you would be much
appreciated (please use your full name in that case, instead of only "TW").
Thanks.

>
> On 7/27/23 20:33, Damien Le Moal wrote:
>> "Slow coming back" -> Compared to which version of the kernel ? Do you
>> have numbers ? If the devices are HDDs, resume will wait for these to
>> spin up. That takes a while (about 10s normally).

--
Damien Le Moal
Western Digital Research


2023-07-31 05:04:53

by TW

[permalink] [raw]
Subject: Re: Scsi_bus_resume+0x0/0x90 returns -5 when resuming from s3 sleep

Oh excellent I'll go do that now.

On 7/30/23 18:41, Damien Le Moal wrote:
> I posted a proper patch and CC-ed you. A "Tested-by:" tag from you
> would be much appreciated (please use your full name in that case,
> instead of only "TW"). Thanks.