Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[*] rtsx_usb depends badly on autosuspend #183

Closed
alondrayona opened this issue Jul 4, 2024 · 21 comments
Closed

[*] rtsx_usb depends badly on autosuspend #183

alondrayona opened this issue Jul 4, 2024 · 21 comments

Comments

@alondrayona
Copy link

Entering into S3 is super slow, it takes about 15-20 seconds.

At first I thought it was caused by the iwlwifi module, but even if I remove it before sleep, it still takes a long time.

This happens both on a Fedora 40 live ISO and on an up-to-date installation (Linux 6.9.7-gentoo-dist / linux-firmware 20240610 / firmware 2024.06)

dmesg
[ 5563.904243] elogind-daemon[1740]: Suspending system...
[ 5563.904261] PM: suspend entry (deep)
[ 5563.907497] Filesystems sync: 0.003 seconds
[ 5563.907723] Loading firmware: iwlwifi-so-a0-jf-b0-77.ucode
[ 5563.907756] Loading firmware: regulatory.db
[ 5563.907797] Loading firmware: i915/adlp_dmc.bin
[ 5563.907858] Loading firmware: i915/tgl_guc_70.bin
[ 5563.907993] Loading firmware: i915/tgl_huc.bin
[ 5563.908468] Loading firmware: intel/ibt-0040-2120.sfi
[ 5563.909032] Loading firmware: intel/ibt-0040-2120.ddc
[ 5563.909081] Loading firmware: regulatory.db.p7s
[ 5564.026340] Freezing user space processes
[ 5564.028631] Freezing user space processes completed (elapsed 0.002 seconds)
[ 5564.028638] OOM killer disabled.
[ 5564.028640] Freezing remaining freezable tasks
[ 5580.829045] Freezing remaining freezable tasks completed (elapsed 16.800 seconds)
[ 5580.829088] printk: Suspending console(s) (use no_console_suspend to debug)
[ 5581.066959] iwlwifi 0000:00:14.3: timeout waiting for FW reset ACK (inta_hw=0x0)
[ 5581.067106] iwlwifi 0000:00:14.3: Start IWL Error Log Dump:
[ 5581.067109] iwlwifi 0000:00:14.3: Transport status: 0x0000004A, valid: 6
[ 5581.067115] iwlwifi 0000:00:14.3: Loaded firmware version: 77.f92b5fed.0 so-a0-jf-b0-77.ucode
[ 5581.067120] iwlwifi 0000:00:14.3: 0x00000084 | NMI_INTERRUPT_UNKNOWN       
[ 5581.067125] iwlwifi 0000:00:14.3: 0x000002F0 | trm_hw_status0
[ 5581.067128] iwlwifi 0000:00:14.3: 0x00000000 | trm_hw_status1
[ 5581.067131] iwlwifi 0000:00:14.3: 0x004D2A06 | branchlink2
[ 5581.067134] iwlwifi 0000:00:14.3: 0x004C92BE | interruptlink1
[ 5581.067137] iwlwifi 0000:00:14.3: 0x004C92BE | interruptlink2
[ 5581.067139] iwlwifi 0000:00:14.3: 0x00011B6A | data1
[ 5581.067142] iwlwifi 0000:00:14.3: 0x01000000 | data2
[ 5581.067145] iwlwifi 0000:00:14.3: 0x00000000 | data3
[ 5581.067148] iwlwifi 0000:00:14.3: 0x00000000 | beacon time
[ 5581.067150] iwlwifi 0000:00:14.3: 0x08A496EA | tsf low
[ 5581.067153] iwlwifi 0000:00:14.3: 0x00000000 | tsf hi
[ 5581.067155] iwlwifi 0000:00:14.3: 0x00000000 | time gp1
[ 5581.067158] iwlwifi 0000:00:14.3: 0x08A557AE | time gp2
[ 5581.067160] iwlwifi 0000:00:14.3: 0x00000001 | uCode revision type
[ 5581.067163] iwlwifi 0000:00:14.3: 0x0000004D | uCode version major
[ 5581.067166] iwlwifi 0000:00:14.3: 0xF92B5FED | uCode version minor
[ 5581.067169] iwlwifi 0000:00:14.3: 0x00000370 | hw version
[ 5581.067172] iwlwifi 0000:00:14.3: 0x00480002 | board version
[ 5581.067174] iwlwifi 0000:00:14.3: 0x8025FF00 | hcmd
[ 5581.067177] iwlwifi 0000:00:14.3: 0x00020000 | isr0
[ 5581.067179] iwlwifi 0000:00:14.3: 0x00000000 | isr1
[ 5581.067182] iwlwifi 0000:00:14.3: 0x48F04802 | isr2
[ 5581.067184] iwlwifi 0000:00:14.3: 0x00C3400C | isr3
[ 5581.067187] iwlwifi 0000:00:14.3: 0x00000000 | isr4
[ 5581.067189] iwlwifi 0000:00:14.3: 0x00DB0148 | last cmd Id
[ 5581.067192] iwlwifi 0000:00:14.3: 0x00011B6A | wait_event
[ 5581.067194] iwlwifi 0000:00:14.3: 0x00000000 | l2p_control
[ 5581.067197] iwlwifi 0000:00:14.3: 0x00000000 | l2p_duration
[ 5581.067199] iwlwifi 0000:00:14.3: 0x00000000 | l2p_mhvalid
[ 5581.067202] iwlwifi 0000:00:14.3: 0x00000000 | l2p_addr_match
[ 5581.067204] iwlwifi 0000:00:14.3: 0x00000018 | lmpm_pmg_sel
[ 5581.067207] iwlwifi 0000:00:14.3: 0x00000000 | timestamp
[ 5581.067210] iwlwifi 0000:00:14.3: 0x0000F0EC | flow_handler
[ 5581.067292] iwlwifi 0000:00:14.3: 0x00000000 | ADVANCED_SYSASSERT
[ 5581.067295] iwlwifi 0000:00:14.3: 0x00000000 | umac branchlink1
[ 5581.067298] iwlwifi 0000:00:14.3: 0x00000000 | umac branchlink2
[ 5581.067300] iwlwifi 0000:00:14.3: 0x00000000 | umac interruptlink1
[ 5581.067303] iwlwifi 0000:00:14.3: 0x00000000 | umac interruptlink2
[ 5581.067305] iwlwifi 0000:00:14.3: 0x00000000 | umac data1
[ 5581.067307] iwlwifi 0000:00:14.3: 0x00000000 | umac data2
[ 5581.067310] iwlwifi 0000:00:14.3: 0x00000000 | umac data3
[ 5581.067312] iwlwifi 0000:00:14.3: 0x00000000 | umac major
[ 5581.067314] iwlwifi 0000:00:14.3: 0x00000000 | umac minor
[ 5581.067317] iwlwifi 0000:00:14.3: 0x00000000 | frame pointer
[ 5581.067319] iwlwifi 0000:00:14.3: 0x00000000 | stack pointer
[ 5581.067322] iwlwifi 0000:00:14.3: 0x00000000 | last host cmd
[ 5581.067324] iwlwifi 0000:00:14.3: 0x00000000 | isr status reg
[ 5581.067383] iwlwifi 0000:00:14.3: IML/ROM dump:
[ 5581.067385] iwlwifi 0000:00:14.3: 0x00000B03 | IML/ROM error/state
[ 5581.067443] iwlwifi 0000:00:14.3: 0x000050CE | IML/ROM data1
[ 5581.067504] iwlwifi 0000:00:14.3: 0x00000090 | IML/ROM WFPM_AUTH_KEY_0
[ 5581.067560] iwlwifi 0000:00:14.3: Fseq Registers:
[ 5581.067611] iwlwifi 0000:00:14.3: 0x60000000 | FSEQ_ERROR_CODE
[ 5581.067666] iwlwifi 0000:00:14.3: 0x00330000 | FSEQ_TOP_INIT_VERSION
[ 5581.067718] iwlwifi 0000:00:14.3: 0x00010009 | FSEQ_CNVIO_INIT_VERSION
[ 5581.067770] iwlwifi 0000:00:14.3: 0x0000A384 | FSEQ_OTP_VERSION
[ 5581.067825] iwlwifi 0000:00:14.3: 0xC75441EA | FSEQ_TOP_CONTENT_VERSION
[ 5581.067877] iwlwifi 0000:00:14.3: 0x4552414E | FSEQ_ALIVE_TOKEN
[ 5581.067927] iwlwifi 0000:00:14.3: 0x00080400 | FSEQ_CNVI_ID
[ 5581.067977] iwlwifi 0000:00:14.3: 0x01300202 | FSEQ_CNVR_ID
[ 5581.068031] iwlwifi 0000:00:14.3: 0x00080400 | CNVI_AUX_MISC_CHIP
[ 5581.068084] iwlwifi 0000:00:14.3: 0x01300202 | CNVR_AUX_MISC_CHIP
[ 5581.068134] iwlwifi 0000:00:14.3: 0x0000485B | CNVR_SCU_SD_REGS_SD_REG_DIG_DCDC_VTRIM
[ 5581.068238] iwlwifi 0000:00:14.3: 0x0BADCAFE | CNVR_SCU_SD_REGS_SD_REG_ACTIVE_VDIG_MIRROR
[ 5581.068291] iwlwifi 0000:00:14.3: 0x00000000 | FSEQ_PREV_CNVIO_INIT_VERSION
[ 5581.068343] iwlwifi 0000:00:14.3: 0x00330000 | FSEQ_WIFI_FSEQ_VERSION
[ 5581.068395] iwlwifi 0000:00:14.3: 0x00330000 | FSEQ_BT_FSEQ_VERSION
[ 5581.068447] iwlwifi 0000:00:14.3: 0x00000122 | FSEQ_CLASS_TP_VERSION
[ 5581.068505] iwlwifi 0000:00:14.3: UMAC CURRENT PC: 0x8047e450
[ 5581.068558] iwlwifi 0000:00:14.3: LMAC1 CURRENT PC: 0xd0
[ 5581.068611] iwlwifi 0000:00:14.3: WRT: Collecting data: ini trigger 4 fired (delay=0ms).
[ 5581.550107] PM: suspend devices took 0.724 seconds
[ 5581.600504] ACPI: EC: interrupt blocked
[ 5581.644632] ACPI: PM: Preparing to enter system sleep state S3
[ 5581.690385] ACPI: EC: event blocked
[ 5581.690388] ACPI: EC: EC stopped
[ 5581.690389] ACPI: PM: Saving platform NVS memory
[ 5581.690461] Disabling non-boot CPUs ...
[ 5581.692370] smpboot: CPU 1 is now offline
[ 5581.695551] smpboot: CPU 2 is now offline
[ 5581.698923] smpboot: CPU 3 is now offline
[ 5581.706893] ACPI: PM: Low-level resume complete
[ 5581.706981] ACPI: EC: EC started
[ 5581.706982] ACPI: PM: Restoring platform NVS memory
[ 5581.708256] Enabling non-boot CPUs ...
[ 5581.708287] smpboot: Booting Node 0 Processor 1 APIC 0x2
[ 5581.709336] CPU1 is up
[ 5581.709355] smpboot: Booting Node 0 Processor 2 APIC 0x4
[ 5581.710481] CPU2 is up
[ 5581.710496] smpboot: Booting Node 0 Processor 3 APIC 0x6
[ 5581.711645] CPU3 is up
[ 5581.712018] ACPI: PM: Waking up from system sleep state S3
[ 5581.791701] ACPI: EC: interrupt unblocked
[ 5581.818511] ACPI: EC: event unblocked
[ 5581.822685] i915 0000:00:02.0: [drm] GT0: GuC firmware i915/tgl_guc_70.bin version 70.20.0
[ 5581.822695] i915 0000:00:02.0: [drm] GT0: HuC firmware i915/tgl_huc.bin version 7.9.3
[ 5581.826005] iwlwifi 0000:00:14.3: WRT: Invalid buffer destination
[ 5581.827425] i915 0000:00:02.0: [drm] GT0: HuC: authenticated for all workloads
[ 5581.828366] i915 0000:00:02.0: [drm] GT0: GUC: submission enabled
[ 5581.828368] i915 0000:00:02.0: [drm] GT0: GUC: SLPC enabled
[ 5581.828706] i915 0000:00:02.0: [drm] GT0: GUC: RC enabled
[ 5581.837390] nvme nvme0: 4/0/0 default/read/poll queues
[ 5581.842302] nvme nvme0: Ignoring bogus Namespace Identifiers
[ 5581.928147] iwlwifi 0000:00:14.3: WFPM_UMAC_PD_NOTIFICATION: 0x1f
[ 5581.928207] iwlwifi 0000:00:14.3: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
[ 5581.928269] iwlwifi 0000:00:14.3: WFPM_AUTH_KEY_0: 0x90
[ 5581.928282] iwlwifi 0000:00:14.3: CNVI_SCU_SEQ_DATA_DW9: 0x0
[ 5581.929689] iwlwifi 0000:00:14.3: RFIm is deactivated, reason = 4
[ 5582.077448] usb 1-10: reset full-speed USB device number 3 using xhci_hcd
[ 5582.219855] PM: resume devices took 0.400 seconds
[ 5582.220427] OOM killer enabled.
[ 5582.220430] Restarting tasks ... 
[ 5582.220916] mei_hdcp 0000:00:16.0-b638ab7e-94e2-4ea2-a552-d1c54b627f04: bound 0000:00:02.0 (ops i9xx_always_on_power_well_ops [i915])
[ 5582.221818] mei_pxp 0000:00:16.0-fbf6fcf1-96cf-4e2e-a6a6-1bab8cbe36b1: bound 0000:00:02.0 (ops tfp410_ops [i915])
[ 5582.223501] done.
[ 5582.223515] random: crng reseeded on system resumption
[ 5582.409646] PM: suspend exit
[ 5582.409692] elogind-daemon[1740]: System resumed.
@Sean-StarLabs
Copy link
Contributor

Same as #168 but your title is better

@Sean-StarLabs Sean-StarLabs mentioned this issue Jul 5, 2024
4 tasks
@Sean-StarLabs Sean-StarLabs changed the title [StarLite Mk V] Slow suspend (S3) [StarLite Mk V] mmc_rescan prevents S3 entry and wastes power Jul 12, 2024
@Sean-StarLabs
Copy link
Contributor

SD_CN_N is pulled low with the tray, so Linux constantly tries to scan for an SD Card. It wastes power and prevents S3 entry (it's frozen after around 13 seconds).

@edpenz
Copy link

edpenz commented Jul 17, 2024

SD_CN_N is pulled low with the tray, so Linux constantly tries to scan for an SD Card. It wastes power and prevents S3 entry (it's frozen after around 13 seconds).

For anyone else tracking this issue, I removed my SD tray and now S3 entry only takes a second.

@rbm78bln
Copy link

SD_CN_N is pulled low with the tray

So the tray pulls SD_CD# low constantly, right?
Looking at the realtek datasheets it should actually only be pulled low by an actual sd card, correct?

Isn't this basically a hardware design flaw (i.e. hardware bug)?

@Sean-StarLabs
Copy link
Contributor

According to realtek, no. Tray should pull it low then the driver should timeout after 100ms.

@rbm78bln
Copy link

rbm78bln commented Jul 18, 2024

Okay cool, this is quite relaxing to know... Thank you!

@AndrzejTunkiel
Copy link

Pulling tray out also fixed my unreliable Suspend issue (sometimes it does suspend, sometimes it does not).

I tried disabling the card reader in the coreboot - that did not work.

I then disabled the USB device via echo '1-3.2' |sudo tee /sys/bus/usb/drivers/usb/unbind and now the suspend is fast and reliable for me too.

I am on Fedora Silverblue 6.9.10-200.fc40.x86_64

@meskio
Copy link

meskio commented Sep 12, 2024

I tried removing the sdcard tray and disabling the usb device, but my starlite never gets to sleep. When I tell it sleep it turns the screen black and keep the led on (no blinking just on all time like when the device is on). Whatever I wait doesn't seem to do anything until I force it to power down pressing the power button.

I see a similar behavior sometimes when I leave it on for a while without touching it even though I disabled the auto suspension, it should only lock, but maybe this is a bug in gnome. Same behavior also when I turn off the device, it doesn't turn off completely it stays with the screen off and the led on until I press the power button for few seconds or it drains completely the battery.

I'm using debian Trixie (testing) with kernel 6.10.6 and I just upgraded the firmware to 24.08 but the problem is still there.

In journalctl -b -1 I don't see any more logs after systemd-sleep[3206]: Performing sleep operation 'suspend'.... Any other way to provide debug information to help finding the issue?

Maybe a different issue? Should I open another issue?

@Sean-StarLabs
Copy link
Contributor

disabling the usb device

What did you do?

Definitely different, could just be a Debian bug - are you able to test with a Live USB with Ubuntu?

@meskio
Copy link

meskio commented Sep 13, 2024

disabling the usb device

What did you do?

I run: echo '1-3.2' |sudo tee /sys/bus/usb/drivers/usb/unbind

Definitely different, could just be a Debian bug - are you able to test with a Live USB with Ubuntu?

I just tried with the latest ubuntu 24.04.2 live USB and the same behavior. I waited for the desktop to be fully loaded, removed the sdcard tray and clicked on the menu to 'suspend'. The screen becomes black and the led keeps on (no blinking signaling suspension). I see the keyboard light turns on if I click on any key, but neither the power button or any key brings the starlite back to life.

@Sean-StarLabs
Copy link
Contributor

Ping support - that's something else

@spiritofsands
Copy link

I have the same issue with a long suspend switching. Workaround with unbinding the usb device from AndrzejTunkiel makes suspend instant.
I have Ubuntu 24.10, kernel 6.8.0-39-generic.
Reproduced on both 24.07 and 24.08 firmware.

@mixmastamyk
Copy link

Same, I've been choosing suspend from the menu, waiting 30 secs and then doing it again to get it to sleep. Thanks for the work around with tee.

@Sean-StarLabs Sean-StarLabs changed the title [StarLite Mk V] mmc_rescan prevents S3 entry and wastes power [*] rtsx_usb depends badly on autosuspend Oct 18, 2024
@Sean-StarLabs
Copy link
Contributor

Workaround until upstreamed: https://github.com/StarLabsLtd/rtsx_usb

@adrianh411
Copy link

Noticed 2 things:-

  1. Suspend works perfectly when the external keyboard is attached.
  2. Suspend works perfectly if you have a MicroSD card in the slot.

So, tested last night with a MicroSD card in the slot, charged Starlite up to 75% and put it into Suspend overnight.
Woke up this morning and resumed perfectly and charge had only dropped to 66% over 9 hours (roughly 1% per hour).

These are still workarounds but hopefully will also provide another way to get suspend working until the software upstream is updated.

@Anachron
Copy link

I've got a bit different numbers. The sleep is deep but I receive around 20% battery drain in 10-12 hours time.

For me that is a bit high.

I'm using the echo '1-3.2' |sudo tee /sys/bus/usb/drivers/usb/unbind workaround.

@Sean-StarLabs
Copy link
Contributor

Merged upstream https://git.kernel.org/pub/scm/linux/kernel/git/gregkh/char-misc.git/commit/?h=char-misc-next&id=235b630eda072d7e7b102ab346d6b8a2c028a772

@Anachron
Copy link

Very nice!

My sleep battery drain meanwhile also decreased, so that's fine on my part now too!

@mixmastamyk
Copy link

What kernel # will this land in?

@Sean-StarLabs
Copy link
Contributor

6.13 I believe

@mixmastamyk
Copy link

Today I installed Fedora 41 with kernel 6.13.5, deactivated the unbind command at boot, and restarted....

Sleep is working promptly without the workaround! Thanks.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

10 participants