You are not logged in.
Hi there,
I'm trying to configure my system to suspend/hibernate, and as far as I can see I've done everything correctly, but the system fails sometimes to resume properly (I get a black screen, but even worse I cannot even ssh to the system, though I can ping it no problem).
I'm using kernel 5.15.31-1-lts, with the following command line:
BOOT_IMAGE=/boot/vmlinuz-linux-lts root=UUID=174c1139-0367-4243-b415-9e4b3b26c1b1 rw loglevel=3 quiet resume=UUID=6719af58-265c-4215-bc70-9f587328d91d xhci_hcd.quirks=270336 initcall_debug no_console_suspend ignore_loglevelRight now I suspended and resumed apparently OK, but upon inspecting the logs I see:
Mar 30 11:36:24 sieladon kernel: ------------[ cut here ]------------
Mar 30 11:36:24 sieladon kernel: WARNING: CPU: 23 PID: 502 at drivers/infiniband/hw/irdma/i40iw_if.c:53 i40iw_close+0x73/0x80 [irdma]
Mar 30 11:36:24 sieladon kernel: Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace sunrpc fscache netfs intel_rapl_msr intel_rapl_common isst_if_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp irdma ice rfkill kvm_intel ib_uverbs ipmi_ssif \
snd_usb_audio kvm irqbypass snd_usbmidi_lib crct10dif_pclmul snd_rawmidi mousedev crc32_pclmul snd_seq_device coretemp ib_core snd_hda_codec_hdmi ghash_clmulni_intel mc snd_hda_intel aesni_intel snd_intel_dspcfg iTCO_wdt snd_intel_sdw_acpi crypto_simd intel_pmc_bxt snd_hda_codec cry\
ptd iTCO_vendor_support snd_hda_core snd_hwdep nls_iso8859_1 rapl snd_pcm joydev intel_cstate snd_timer vfat intel_spi_pci nvidia_drm(POE) snd ast intel_spi nvidia_uvm(POE) nvidia_modeset(POE) drm_vram_helper fat intel_uncore pcspkr soundcore i40e drm_ttm_helper ioatdma spi_nor mei_\
me ttm i2c_i801 acpi_ipmi mei mtd lpc_ich intel_pch_thermal dca i2c_smbus ipmi_si wmi ipmi_devintf ipmi_msghandler hid_logitech_hidpp acpi_pad mac_hid acpi_power_meter
Mar 30 11:36:24 sieladon kernel: nvidia(POE) fuse bpf_preload ip_tables x_tables hid_logitech_dj ext4 crc32c_generic crc16 mbcache jbd2 usbhid xhci_pci crc32c_intel xhci_pci_renesas
Mar 30 11:36:24 sieladon kernel: CPU: 23 PID: 502 Comm: kworker/23:2 Tainted: P OE 5.15.31-1-lts #1 d9b4c4d452da0a959c418544f68e898ce4016136
Mar 30 11:36:24 sieladon kernel: Hardware name: GIGABYTE MD71-HB0-00/MD71-HB0-00, BIOS R09 07/21/2020
Mar 30 11:36:24 sieladon kernel: Workqueue: i40e i40e_service_task [i40e]
Mar 30 11:36:24 sieladon kernel: RIP: 0010:i40iw_close+0x73/0x80 [irdma]
Mar 30 11:36:24 sieladon kernel: Code: 7e ff 66 90 5b 5d 41 5c c3 48 8b 43 18 48 c7 c6 30 e5 d3 c3 5b 48 c7 c7 a8 41 d5 c3 5d 41 5c 8b 50 38 83 e2 07 e9 dd 2d 81 c0 <0f> 0b 5b 5d 41 5c c3 66 0f 1f 44 00 00 0f 1f 44 00 00 48 8b bf 00
Mar 30 11:36:24 sieladon kernel: RSP: 0018:ffffac5989c73dd8 EFLAGS: 00010246
Mar 30 11:36:24 sieladon kernel: RAX: 0000000000000000 RBX: ffff984a86a4cf10 RCX: ffffffffc3d21650
Mar 30 11:36:24 sieladon kernel: RDX: ffff984a8ab6f000 RSI: 0000000000000009 RDI: ffff984a8ab6f000
Mar 30 11:36:24 sieladon kernel: RBP: ffff984a86a4cf10 R08: ffffffffc3d4f0e0 R09: ffff984a919a7bf8
Mar 30 11:36:24 sieladon kernel: R10: 0000000000000180 R11: ffff984a89742400 R12: 0000000000000001
Mar 30 11:36:24 sieladon kernel: R13: ffff984a8909a000 R14: 0000000100060911 R15: ffffcc4d811ddd05
Mar 30 11:36:24 sieladon kernel: FS: 0000000000000000(0000) GS:ffff9855911c0000(0000) knlGS:0000000000000000
Mar 30 11:36:24 sieladon kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Mar 30 11:36:24 sieladon kernel: CR2: 00007f6b87b59000 CR3: 000000070cc10002 CR4: 00000000007706e0
Mar 30 11:36:24 sieladon kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Mar 30 11:36:24 sieladon kernel: DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Mar 30 11:36:24 sieladon kernel: PKRU: 55555554
Mar 30 11:36:24 sieladon kernel: Call Trace:
Mar 30 11:36:24 sieladon kernel: <TASK>
Mar 30 11:36:24 sieladon kernel: i40e_notify_client_of_netdev_close+0x48/0x90 [i40e 2be9a46fb39029d8245beae42d8db2c3649f22e8]
Mar 30 11:36:24 sieladon kernel: i40e_service_task+0x4f1/0xb70 [i40e 2be9a46fb39029d8245beae42d8db2c3649f22e8]
Mar 30 11:36:24 sieladon kernel: ? __switch_to_asm+0x42/0x70
Mar 30 11:36:24 sieladon kernel: ? __switch_to+0x11b/0x420
Mar 30 11:36:24 sieladon kernel: process_one_work+0x1ee/0x390
Mar 30 11:36:24 sieladon kernel: worker_thread+0x53/0x3e0
Mar 30 11:36:24 sieladon kernel: ? process_one_work+0x390/0x390
Mar 30 11:36:24 sieladon kernel: kthread+0x124/0x150
Mar 30 11:36:24 sieladon kernel: ? set_kthread_struct+0x40/0x40
Mar 30 11:36:24 sieladon kernel: ret_from_fork+0x1f/0x30
Mar 30 11:36:24 sieladon kernel: </TASK>
Mar 30 11:36:24 sieladon kernel: ---[ end trace b9a487fab28cac78 ]---Any pointers as to how I could get rid of this upon resuming?
Many thanks,
AdV
Offline
By blacklisting the [irdma] module on booting, I can then do suspend/resume cycles without seeing the errors above, but suspend/resume is not working properly yet (it works sometimes, while others it just hangs when resuming).
I recovered the journal logs from one of these failed resume sessions, but sadly they are not very informative. I get something like the following, where you can see that the first suspend/resume cycle was successful, but the last one, right at the end of the journal is not very informative, since it just says it is entering sleep state 'suspend', but nothing else (AFAIK the problem is not with suspend, but rather with resume, since the screens go into standby mode, the watts usage go down and I can see the workstation increasing the electricity used again when trying to resume it, but then it goes into a 'zombie' state, where the screen is black, power usage is similar to when the machine is idle, I can ping to it, but no ssh).
Any ideas how I could get more log data of what could be causing the problem? Thanks
Mar 30 16:31:47 sieladon NetworkManager[928]: <info> [1648654307.1695] manager: NetworkManager state is now ASLEEP
Mar 30 16:31:47 sieladon systemd[1]: Reached target Sleep.
Mar 30 16:31:47 sieladon systemd[1]: Starting System Suspend...
Mar 30 16:31:47 sieladon systemd-sleep[2626]: Entering sleep state 'suspend'...
Mar 30 16:31:47 sieladon kernel: PM: suspend entry (s2idle)
Mar 30 16:31:47 sieladon kernel: Filesystems sync: 0.018 seconds
Mar 30 16:32:32 sieladon kernel: Freezing user space processes ... (elapsed 0.002 seconds) done.
Mar 30 16:32:32 sieladon kernel: OOM killer disabled.
Mar 30 16:32:32 sieladon kernel: Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
Mar 30 16:32:32 sieladon kernel: leds input30::kana: PM: calling led_suspend+0x0/0x40 @ 2626, parent: input30
Mar 30 16:32:32 sieladon kernel: leds input30::kana: PM: led_suspend+0x0/0x40 returned 0 after 0 usecs
Mar 30 16:32:32 sieladon kernel: leds input30::compose: PM: calling led_suspend+0x0/0x40 @ 2626, parent: input30
Mar 30 16:32:32 sieladon kernel: leds input30::compose: PM: led_suspend+0x0/0x40 returned 0 after 0 usecs
Mar 30 16:32:32 sieladon kernel: leds input30::scrolllock: PM: calling led_suspend+0x0/0x40 @ 2626, parent: input30
Mar 30 16:32:32 sieladon kernel: leds input30::scrolllock: PM: led_suspend+0x0/0x40 returned 0 after 0 usecs
Mar 30 16:32:32 sieladon kernel: leds input30::capslock: PM: calling led_suspend+0x0/0x40 @ 2626, parent: input30
[...]
Mar 30 16:32:32 sieladon kernel: leds input30::compose: PM: calling led_resume+0x0/0x40 @ 2626, parent: input30
Mar 30 16:32:32 sieladon kernel: leds input30::compose: PM: led_resume+0x0/0x40 returned 0 after 0 usecs
Mar 30 16:32:32 sieladon kernel: leds input30::kana: PM: calling led_resume+0x0/0x40 @ 2626, parent: input30
Mar 30 16:32:32 sieladon kernel: leds input30::kana: PM: led_resume+0x0/0x40 returned 0 after 0 usecs
Mar 30 16:32:32 sieladon kernel: nvidia 0000:3b:00.0: PM: pci_pm_resume+0x0/0xe0 returned 0 after 3036688 usecs
Mar 30 16:32:32 sieladon kernel: i40e 0000:1a:00.0 enp26s0f0: NIC Link is Up, 1000 Mbps Full Duplex, Flow Control: None
Mar 30 16:32:32 sieladon kernel: OOM killer enabled.
Mar 30 16:32:32 sieladon kernel: Restarting tasks ... done.
Mar 30 16:32:32 sieladon kernel: PM: suspend exit
Mar 30 16:32:32 sieladon kernel: audit: type=1130 audit(1648654352.580:99): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 30 16:32:32 sieladon kernel: audit: type=1131 audit(1648654352.580:100): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 30 16:32:32 sieladon kernel: audit: type=1334 audit(1648654352.830:101): prog-id=0 op=UNLOAD
Mar 30 16:32:32 sieladon audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 30 16:32:32 sieladon audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 30 16:32:32 sieladon audit: BPF prog-id=0 op=UNLOAD
Mar 30 16:32:32 sieladon rtkit-daemon[1324]: The canary thread is apparently starving. Taking action.
Mar 30 16:32:32 sieladon systemd-sleep[2626]: System returned from sleep state.
Mar 30 16:32:32 sieladon rtkit-daemon[1324]: Demoting known real-time threads.
Mar 30 16:32:32 sieladon systemd[1]: systemd-suspend.service: Deactivated successfully.
Mar 30 16:32:32 sieladon rtkit-daemon[1324]: Demoted 0 threads.
Mar 30 16:32:32 sieladon systemd[1]: Finished System Suspend.
Mar 30 16:32:32 sieladon dbus-daemon[923]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.1' (uid=0 pid=928 comm="/usr/bin/NetworkManager --no-daemon")
Mar 30 16:32:32 sieladon systemd[1]: Stopped target Sleep.
Mar 30 16:32:32 sieladon systemd[1]: Reached target Suspend.
Mar 30 16:32:32 sieladon systemd[1]: Stopped target Suspend.
Mar 30 16:32:32 sieladon systemd-logind[925]: Operation 'sleep' finished.
Mar 30 16:32:32 sieladon NetworkManager[928]: <info> [1648654352.5869] manager: sleep: wake requested (sleeping: yes enabled: yes)
[...]
Mar 30 16:32:40 sieladon ntpd[957]: new interface(s) found: waking up resolver
Mar 30 16:32:42 sieladon systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Mar 30 16:32:42 sieladon audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 30 16:32:42 sieladon kernel: audit: type=1131 audit(1648654362.890:105): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 30 16:33:08 sieladon polkitd[1286]: Registered Authentication Agent for unix-process:2690:43080 (system bus name :1.64 [/usr/bin/pkttyagent --notify-fd 5 --fallback], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_GB.UTF-8)
Mar 30 16:33:08 sieladon NetworkManager[928]: <info> [1648654388.4519] manager: sleep: sleep requested (sleeping: no enabled: yes)
Mar 30 16:33:08 sieladon polkitd[1286]: Unregistered Authentication Agent for unix-process:2690:43080 (system bus name :1.64, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_GB.UTF-8) (disconnected from bus)
Mar 30 16:33:08 sieladon NetworkManager[928]: <info> [1648654388.4530] manager: NetworkManager state is now ASLEEP
Mar 30 16:33:08 sieladon systemd[1]: Reached target Sleep.
Mar 30 16:33:08 sieladon systemd[1]: Starting System Suspend...
Mar 30 16:33:08 sieladon systemd-sleep[2697]: Entering sleep state 'suspend'...
Mar 30 16:33:08 sieladon kernel: PM: suspend entry (s2idle)
Mar 30 16:33:08 sieladon kernel: Filesystems sync: 0.005 secondsOffline