Unable to suspend TU116M (GF 1660 Ti) - regression in 5.7.6+ (nouveau 0000:01:00.0: acr: init failed, -110)
In kernel 5.7.6+ (tested up to 5.7.10 and 5.8.0-0.rc6.20200723gitd15be546031c - in 5.7.5 it worked fine) it is no longer possible to suspend Hyperbook NH5/Clevo NH55RCQ with GeForce GTX 1660 Mobile (TU116M):
kernel: Freezing remaining freezable tasks ... (elapsed 0.000 seconds) done.
kernel: printk: Suspending console(s) (use no_console_suspend to debug)
↓ related errrors ↓
kernel: xhci_hcd 0000:01:00.2: WARN: xHC CMD_RUN timeout
kernel: PM: suspend_common(): xhci_pci_suspend+0x0/0x100 returns -110
kernel: PM: pci_pm_suspend(): hcd_pci_suspend+0x0/0x30 returns -110
kernel: PM: dpm_run_callback(): pci_pm_suspend+0x0/0x160 returns -110
kernel: PM: Device 0000:01:00.2 failed to suspend async: error -110
↑ related errrors ↑
kernel: sd 4:0:0:0: [sda] Synchronizing SCSI cache
kernel: sd 4:0:0:0: [sda] Stopping disk
kernel: PM: Some devices failed to suspend, or early wake event detected
kernel: sd 4:0:0:0: [sda] Starting disk
kernel: PM: resume devices took 2.184 seconds
kernel: OOM killer enabled.
kernel: Restarting tasks ... done.
kernel: PM: suspend exit
...
systemd[1]: systemd-suspend.service: Main process exited, code=exited, status=1/FAILURE
systemd[1]: systemd-suspend.service: Failed with result 'exit-code'.
systemd[1]: Failed to start Suspend.
systemd[1]: Dependency failed for Suspend.
systemd[1]: suspend.target: Job suspend.target/start failed with result 'dependency'.
systemd[1]: Stopped target Sleep.
The suspend process is aborted and the system stays as is (still can be used, once the screen is unlocked).
01:00.2
is the NVidia's USB host:
$ lspci | grep -i nvidia 15:38
01:00.0 VGA compatible controller: NVIDIA Corporation TU116M [GeForce GTX 1660 Ti Mobile] (rev a1)
01:00.1 Audio device: NVIDIA Corporation TU116 High Definition Audio Controller (rev a1)
01:00.2 USB controller: NVIDIA Corporation TU116 USB 3.1 Host Controller (rev a1)
01:00.3 Serial bus controller [0c80]: NVIDIA Corporation TU116 USB Type-C UCSI Controller (rev a1)
The change is most likely not in the nouveau driver itself, but definitely impacts it. During the system boot the following error and stack trace is visible in the system log (new in 5.7.6):
Jul 29 15:11:13 hszpak kernel: fb0: switching to inteldrmfb from EFI VGA
Jul 29 15:11:13 hszpak kernel: i915 0000:00:02.0: vgaarb: deactivate vga console
Jul 29 15:11:13 hszpak kernel: [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
Jul 29 15:11:13 hszpak kernel: i915 0000:00:02.0: vgaarb: changed VGA decodes: olddecodes=io+mem,decodes=none:owns=io+mem
Jul 29 15:11:13 hszpak kernel: i915 0000:00:02.0: [drm] Finished loading DMC firmware i915/kbl_dmc_ver1_04.bin (v1.4)
Jul 29 15:11:13 hszpak kernel: MXM: GUID detected in BIOS
Jul 29 15:11:13 hszpak kernel: ACPI Warning: \_SB.PCI0.GFX0._DSM: Argument #4 type mismatch - Found [Buffer], ACPI requires [Package] (20200326/nsarguments-59)
Jul 29 15:11:13 hszpak kernel: ACPI Warning: \_SB.PCI0.PEG0.PEGP._DSM: Argument #4 type mismatch - Found [Buffer], ACPI requires [Package] (20200326/nsarguments-59)
Jul 29 15:11:13 hszpak kernel: pci 0000:01:00.0: optimus capabilities: enabled, status dynamic power, hda bios codec supported
Jul 29 15:11:13 hszpak kernel: VGA switcheroo: detected Optimus DSM method \_SB_.PCI0.PEG0.PEGP handle
Jul 29 15:11:13 hszpak kernel: nouveau: detected PR support, will not use DSM
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: enabling device (0106 -> 0107)
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: NVIDIA TU116 (168000a1)
Jul 29 15:11:13 hszpak kernel: [drm] Initialized i915 1.6.0 20200313 for 0000:00:02.0 on minor 0
Jul 29 15:11:13 hszpak kernel: ACPI: Video Device [PEGP] (multi-head: no rom: yes post: no)
Jul 29 15:11:13 hszpak kernel: input: Video Bus as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/device:00/LNXVIDEO:00/input/input25
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: bios: version 90.16.26.00.11
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: fb: 6144 MiB GDDR6
Jul 29 15:11:13 hszpak kernel: input: Logitech Wireless Mouse PID:101f Consumer Control as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1:1.1/0003:046D:C52F.0002/0003:046D:101F.0006/input/input21
Jul 29 15:11:13 hszpak kernel: hid-generic 0003:046D:101F.0006: input,hidraw3: USB HID v1.11 Mouse [Logitech Wireless Mouse PID:101f] on usb-0000:00:14.0-1/input1:1
Jul 29 15:11:13 hszpak kernel: ACPI: Video Device [GFX0] (multi-head: yes rom: no post: no)
Jul 29 15:11:13 hszpak kernel: input: Video Bus as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/LNXVIDEO:01/input/input26
Jul 29 15:11:13 hszpak kernel: input: SYNA1202:00 06CB:CD65 Mouse as /devices/pci0000:00/0000:00:15.0/i2c_designware.0/i2c-0/i2c-SYNA1202:00/0018:06CB:CD65.0005/input/input27
Jul 29 15:11:13 hszpak kernel: input: SYNA1202:00 06CB:CD65 Touchpad as /devices/pci0000:00/0000:00:15.0/i2c_designware.0/i2c-0/i2c-SYNA1202:00/0018:06CB:CD65.0005/input/input28
Jul 29 15:11:13 hszpak kernel: vga_switcheroo: enabled
Jul 29 15:11:13 hszpak kernel: [TTM] Zone kernel: Available graphics memory: 8046730 KiB
Jul 29 15:11:13 hszpak kernel: [TTM] Zone dma32: Available graphics memory: 2097152 KiB
Jul 29 15:11:13 hszpak kernel: [TTM] Initializing pool allocator
Jul 29 15:11:13 hszpak kernel: [TTM] Initializing DMA pool allocator
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: VRAM: 6144 MiB
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: GART: 536870912 MiB
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: BIT table 'A' not found
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: BIT table 'L' not found
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: TMDS table version 2.0
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: DCB version 4.1
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: DCB outp 00: 02002f52 00020010
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: DCB outp 01: 04814f76 04600010
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: DCB outp 02: 04814f72 00020010
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: DCB conn 02: 00010261
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: DCB conn 04: 01000446
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: MM: using COPY for buffer copies
Jul 29 15:11:13 hszpak kernel: [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: [drm] Cannot find any crtc or sizes
Jul 29 15:11:13 hszpak kernel: [drm] Initialized nouveau 1.3.1 20120801 for 0000:01:00.0 on minor 1
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: DRM: Disabling PCI power management to avoid bug
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: [drm] Cannot find any crtc or sizes
Jul 29 15:11:13 hszpak kernel: nouveau 0000:01:00.0: [drm] Cannot find any crtc or sizes
Jul 29 15:11:13 hszpak kernel: hid-multitouch 0018:06CB:CD65.0005: input,hidraw3: I2C HID v1.00 Mouse [SYNA1202:00 06CB:CD65] on i2c-SYNA1202:00
Jul 29 15:11:13 hszpak kernel: psmouse serio2: synaptics: device claims to have extended capability 0x0c, but I'm not able to read it.
Jul 29 15:11:13 hszpak kernel: fbcon: i915drmfb (fb0) is primary device
Jul 29 15:11:13 hszpak kernel: fbcon: Deferring console take-over
Jul 29 15:11:13 hszpak kernel: i915 0000:00:02.0: fb0: i915drmfb frame buffer device
Jul 29 15:11:13 hszpak kernel: i915 0000:00:02.0: fb0: i915drmfb frame buffer device
Jul 29 15:11:13 hszpak kernel: psmouse serio2: synaptics: Unable to initialize device.
Jul 29 15:11:18 hszpak kernel: input: Logitech Wireless Mouse PID:101f as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1:1.1/0003:046D:C52F.0002/0003:046D:101F.0006/input/input30
Jul 29 15:11:18 hszpak kernel: logitech-hidpp-device 0003:046D:101F.0006: input,hidraw5: USB HID v1.11 Mouse [Logitech Wireless Mouse PID:101f] on usb-0000:00:14.0-1/input1:1
Jul 29 15:11:18 hszpak kernel: input: PS/2 Synaptics TouchPad as /devices/platform/i8042/serio2/input/input14
Jul 29 15:11:19 hszpak kernel: psmouse serio2: Failed to enable mouse on isa0060/serio2
↓ new in 5.7.6 ↓
Jul 29 15:11:21 hszpak kernel: nouveau 0000:01:00.0: fifo: fault 09 [PHYS_WRITE] at 000000017fef0000 engine c0 [BAR2] client 08 [HUB/HOST_CPU_NB] reason 0d [REGION_VIOLATION] on channel -1 [0000000000 unknown]
Jul 29 15:11:21 hszpak kernel: nouveau 0000:01:00.0: fifo: fault 09 [PHYS_WRITE] at 000000017fef0000 engine c0 [BAR2] client 08 [HUB/HOST_CPU_NB] reason 0d [REGION_VIOLATION] on channel -1 [0000000000 unknown]
Jul 29 15:11:21 hszpak kernel: ------------[ cut here ]------------
Jul 29 15:11:21 hszpak kernel: nouveau 0000:01:00.0: timeout
Jul 29 15:11:21 hszpak kernel: WARNING: CPU: 4 PID: 428 at drivers/gpu/drm/nouveau/nvkm/falcon/v1.c:247 nvkm_falcon_v1_wait_for_halt+0x96/0xa0 [nouveau]
Jul 29 15:11:21 hszpak kernel: Modules linked in: hid_logitech_hidpp i915 nouveau hid_multitouch ttm cec rtsx_pci_sdmmc i2c_algo_bit drm_kms_helper mmc_core mxm_wmi crct10dif_pclmul crc32_pclmul crc32c_intel nvme drm nvme_core ghash_clmu>
Jul 29 15:11:21 hszpak kernel: CPU: 4 PID: 428 Comm: plymouthd Not tainted 5.7.6-201.fc32.x86_64 #1
Jul 29 15:11:21 hszpak kernel: Hardware name: Blue Technology Sp. z o.o. NH5_NH7/NH5_NH7, BIOS 1.07.03TBT 11/16/2018
Jul 29 15:11:21 hszpak kernel: RIP: 0010:nvkm_falcon_v1_wait_for_halt+0x96/0xa0 [nouveau]
Jul 29 15:11:21 hszpak kernel: Code: 8b 40 10 48 8b 78 10 4c 8b 67 50 4d 85 e4 75 03 4c 8b 27 e8 1c aa 03 d6 4c 89 e2 48 c7 c7 8c d2 86 c0 48 89 c6 e8 31 56 a3 d5 <0f> 0b eb ba 66 0f 1f 44 00 00 0f 1f 44 00 00 41 54 be 80 96 98 00
Jul 29 15:11:21 hszpak kernel: RSP: 0018:ffffb44840707838 EFLAGS: 00010292
Jul 29 15:11:21 hszpak kernel: RAX: 000000000000001d RBX: ffffffffffffff92 RCX: 0000000000000007
Jul 29 15:11:21 hszpak kernel: RDX: 00000000fffffff8 RSI: 0000000000000092 RDI: ffff8f0b60519cc0
Jul 29 15:11:21 hszpak kernel: RBP: ffff8f0b518cb658 R08: 0000000000000385 R09: 0000000000000003
Jul 29 15:11:21 hszpak kernel: R10: 0000000000000000 R11: 0000000000000001 R12: ffff8f0b5d738020
Jul 29 15:11:21 hszpak kernel: R13: 0000000000000000 R14: 0000000000000000 R15: ffff8f0b5441a000
Jul 29 15:11:21 hszpak kernel: FS: 00007ff013b2cf00(0000) GS:ffff8f0b60500000(0000) knlGS:0000000000000000
Jul 29 15:11:21 hszpak kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jul 29 15:11:21 hszpak kernel: CR2: 000055b4f79f9198 CR3: 000000045471c006 CR4: 00000000003606e0
Jul 29 15:11:21 hszpak kernel: Call Trace:
Jul 29 15:11:21 hszpak kernel: gm200_acr_hsfw_boot+0xc3/0x160 [nouveau]
Jul 29 15:11:21 hszpak kernel: ? mutex_lock+0xe/0x30
Jul 29 15:11:21 hszpak kernel: nvkm_acr_hsf_boot+0x85/0xe0 [nouveau]
Jul 29 15:11:21 hszpak kernel: tu102_acr_init+0x15/0x30 [nouveau]
Jul 29 15:11:21 hszpak kernel: nvkm_acr_load+0x2b/0xd0 [nouveau]
Jul 29 15:11:21 hszpak kernel: ? ktime_get+0x38/0x90
Jul 29 15:11:21 hszpak kernel: nvkm_subdev_init+0x92/0xd0 [nouveau]
Jul 29 15:11:21 hszpak kernel: ? ktime_get+0x38/0x90
Jul 29 15:11:21 hszpak kernel: nvkm_device_init+0x10b/0x190 [nouveau]
Jul 29 15:11:21 hszpak kernel: nvkm_udevice_init+0x41/0x60 [nouveau]
Jul 29 15:11:21 hszpak kernel: nvkm_object_init+0x3e/0x100 [nouveau]
Jul 29 15:11:21 hszpak kernel: nvkm_object_init+0x6f/0x100 [nouveau]
Jul 29 15:11:21 hszpak kernel: nvkm_object_init+0x6f/0x100 [nouveau]
Jul 29 15:11:21 hszpak kernel: nouveau_do_resume+0x2a/0xc0 [nouveau]
Jul 29 15:11:21 hszpak kernel: nouveau_pmops_runtime_resume+0x7a/0x170 [nouveau]
Jul 29 15:11:21 hszpak kernel: pci_pm_runtime_resume+0xaa/0xc0
Jul 29 15:11:21 hszpak kernel: ? pci_pm_freeze_noirq+0x110/0x110
Jul 29 15:11:21 hszpak kernel: __rpm_callback+0x81/0x140
Jul 29 15:11:21 hszpak kernel: ? pci_pm_freeze_noirq+0x110/0x110
Jul 29 15:11:21 hszpak kernel: rpm_callback+0x1f/0x70
Jul 29 15:11:21 hszpak kernel: ? pci_pm_freeze_noirq+0x110/0x110
Jul 29 15:11:21 hszpak kernel: rpm_resume+0x575/0x7c0
Jul 29 15:11:21 hszpak kernel: ? __mod_lruvec_state+0x44/0xf0
Jul 29 15:11:21 hszpak kernel: __pm_runtime_resume+0x4a/0x80
Jul 29 15:11:21 hszpak kernel: nouveau_drm_open+0x3b/0x1a0 [nouveau]
Jul 29 15:11:21 hszpak kernel: ? security_capable+0x36/0x50
Jul 29 15:11:21 hszpak kernel: drm_file_alloc+0x194/0x250 [drm]
Jul 29 15:11:21 hszpak kernel: drm_open+0xce/0x250 [drm]
Jul 29 15:11:21 hszpak kernel: drm_stub_open+0xad/0x140 [drm]
Jul 29 15:11:21 hszpak kernel: chrdev_open+0xdd/0x210
Jul 29 15:11:21 hszpak kernel: ? cdev_device_add+0xc0/0xc0
Jul 29 15:11:21 hszpak kernel: do_dentry_open+0x13a/0x380
Jul 29 15:11:21 hszpak kernel: path_openat+0xa9a/0xfe0
Jul 29 15:11:21 hszpak kernel: ? current_time+0x1b/0xd0
Jul 29 15:11:21 hszpak kernel: ? atime_needs_update+0x73/0xd0
Jul 29 15:11:21 hszpak kernel: do_filp_open+0x75/0x100
Jul 29 15:11:21 hszpak kernel: ? __check_object_size+0x12e/0x13c
Jul 29 15:11:21 hszpak kernel: ? __alloc_fd+0x44/0x150
Jul 29 15:11:21 hszpak kernel: do_sys_openat2+0x8a/0x130
Jul 29 15:11:21 hszpak kernel: __x64_sys_openat+0x46/0x70
Jul 29 15:11:21 hszpak kernel: do_syscall_64+0x5b/0xf0
Jul 29 15:11:21 hszpak kernel: entry_SYSCALL_64_after_hwframe+0x44/0xa9
Jul 29 15:11:21 hszpak kernel: RIP: 0033:0x7ff013de414b
Jul 29 15:11:21 hszpak kernel: Code: 25 00 00 41 00 3d 00 00 41 00 74 4b 64 8b 04 25 18 00 00 00 85 c0 75 67 44 89 e2 48 89 ee bf 9c ff ff ff b8 01 01 00 00 0f 05 <48> 3d 00 f0 ff ff 0f 87 91 00 00 00 48 8b 4c 24 28 64 48 33 0c 25
Jul 29 15:11:21 hszpak kernel: RSP: 002b:00007ffd4536a520 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
Jul 29 15:11:21 hszpak kernel: RAX: ffffffffffffffda RBX: 00007ff013b2ce80 RCX: 00007ff013de414b
Jul 29 15:11:21 hszpak kernel: RDX: 0000000000000002 RSI: 000055b4f79e54c0 RDI: 00000000ffffff9c
Jul 29 15:11:21 hszpak kernel: RBP: 000055b4f79e54c0 R08: 000055b4f79e5400 R09: 00007ff013efc380
Jul 29 15:11:21 hszpak kernel: R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
Jul 29 15:11:21 hszpak kernel: R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
Jul 29 15:11:21 hszpak kernel: ---[ end trace 71e1c4626a3ab07b ]---
Jul 29 15:11:21 hszpak kernel: nouveau 0000:01:00.0: acr: AHESASC binary failed
Jul 29 15:11:21 hszpak kernel: nouveau 0000:01:00.0: acr: init failed, -110
Jul 29 15:11:21 hszpak kernel: nouveau 0000:01:00.0: init failed with -110
Jul 29 15:11:21 hszpak kernel: nouveau: systemd-udevd[445]:00000000:00000080: init failed with -110
Jul 29 15:11:21 hszpak kernel: nouveau: DRM-master:00000000:00000000: init failed with -110
Jul 29 15:11:21 hszpak kernel: nouveau: DRM-master:00000000:00000000: init failed with -110
Jul 29 15:11:21 hszpak kernel: nouveau 0000:01:00.0: DRM: Client resume failed with error: -110
Jul 29 15:11:21 hszpak kernel: nouveau 0000:01:00.0: DRM: resume failed with: -110
↑ new in 5.7.6 ↑
As it was introduced between the minor kernel version, number of commits is smaller than between the major ones. Maybe someone with bigger nouveau/drm experience could suggest what could be the culprit to consult it with the commit author?
https://lwn.net/Articles/824499/
https://cdn.kernel.org/pub/linux/kernel/v5.x/ChangeLog-5.7.6
Btw, there was a similar in effects regression in 5.3, but it was fixed in 5.5.0-rc2+.