You are not logged in.

#1 2022-02-11 14:52:42

threedope
Member
Registered: 2022-01-22
Posts: 5

[SOLVED] nvidia-suspend failing on Wayland Gnome

Hello everyone,

Problem(s):
Using standard suspend/resume services on Gnome-Wayland can cause random rebooting on suspend/resume and varying degrees of graphical mayhem upon successful resume.

Typical solution:
Write

options nvidia NVreg_PreserveVideoMemoryAllocations=1 NVreg_TemporaryFilePath=/var/tmp

to

/etc/modprobe.d/nvidia-power-management.conf

then

systemctl enable nvidia-suspend && systemctl enable nvidia-hibernate

and reboot.

Solution's problem:
Screen turns black for ~1 minute, suspend eventually fails, the machine resumes to Gnome lock screen.


Here's the journalctl output following a suspend attempt.

Feb 11 08:18:50 olga dhcpcd[577]: enp4s0: no IPv6 Routers available
Feb 11 08:18:47 olga dleyna-renderer-service[2264]: dLeyna: Exit
Feb 11 08:18:47 olga kernel: audit: type=1131 audit(1644589127.511:113): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=succes>
Feb 11 08:18:47 olga 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'
Feb 11 08:18:47 olga systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Feb 11 08:18:46 olga gnome-shell[701]: Ignored exception from dbus method: Gio.DBusError: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name com.system76.Scheduler was not provided by any .service files
Feb 11 08:18:46 olga gnome-shell[701]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Feb 11 08:18:46 olga gnome-shell[701]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Feb 11 08:18:46 olga gnome-shell[701]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Feb 11 08:18:46 olga systemd[657]: Started VTE child process 2292 launched by gnome-terminal-server process 2193.
Feb 11 08:18:46 olga systemd[657]: Started Application launched by gnome-shell.
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Client :1.142 lost
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Calling GetRenderers method
Feb 11 08:18:46 olga dbus-daemon[674]: [session uid=1000 pid=674] Successfully activated service 'com.intel.dleyna-renderer'
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Entries: (null)
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Enabled : F
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: [Network filtering settings]
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Log Level: 0x13
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Log Type : 0
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: [Logging settings]
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Push host port: 0
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Port: 0
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Connector Name: dbus
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Never Quit: F
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: [General settings]
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Load file [/home/patrick/.config/dleyna-renderer-service.conf]
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: Type[0] Level[0x13] Mask[0x4C] Flags[0x4F]
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: dleyna-renderer-service version 0.7.2
Feb 11 08:18:46 olga dleyna-renderer-service[2264]: dLeyna core version 0.7.0
Feb 11 08:18:46 olga dbus-daemon[2264]: writing oom_score_adj error: Permission denied
Feb 11 08:18:46 olga dbus-daemon[674]: [session uid=1000 pid=674] Activating service name='com.intel.dleyna-renderer' requested by ':1.142' (uid=1000 pid=2190 comm="/usr/bin/gnome-photos --gapplication-service ")
Feb 11 08:18:46 olga gnome-shell[701]: Timelines with detached actors are not supported
Feb 11 08:18:45 olga systemd[657]: Started GNOME Terminal Server.
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Successfully activated service 'org.gnome.Terminal'
Feb 11 08:18:45 olga dbus-daemon[571]: [system] Activation via systemd failed for unit 'dbus-org.bluez.service': Unit dbus-org.bluez.service not found.
Feb 11 08:18:45 olga dbus-daemon[571]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.82' (uid=1000 pid=2180 comm="/usr/lib/gnome-contacts-search-provider ")
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Successfully activated service 'org.gnome.Contacts.SearchProvider'
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Successfully activated service 'org.gnome.Calculator.SearchProvider'
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Successfully activated service 'org.gnome.Photos'
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Successfully activated service 'org.gnome.Characters.BackgroundService'
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Successfully activated service 'org.gnome.clocks'
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Successfully activated service 'org.gnome.ControlCenter.SearchProvider'
Feb 11 08:18:45 olga systemd[657]: Starting GNOME Terminal Server...
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Successfully activated service 'org.gnome.Boxes.SearchProvider'
Feb 11 08:18:45 olga dbus-daemon[2190]: writing oom_score_adj error: Permission denied
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Activating via systemd: service name='org.gnome.Terminal' unit='gnome-terminal-server.service' requested by ':1.11' (uid=1000 pid=701 comm="/usr/bin/gnome-shell ")
Feb 11 08:18:45 olga dbus-daemon[2188]: writing oom_score_adj error: Permission denied
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Activating service name='org.gnome.Photos' requested by ':1.11' (uid=1000 pid=701 comm="/usr/bin/gnome-shell ")
Feb 11 08:18:45 olga dbus-daemon[2186]: writing oom_score_adj error: Permission denied
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Activating service name='org.gnome.clocks' requested by ':1.11' (uid=1000 pid=701 comm="/usr/bin/gnome-shell ")
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Activating service name='org.gnome.Characters.BackgroundService' requested by ':1.11' (uid=1000 pid=701 comm="/usr/bin/gnome-shell ")
Feb 11 08:18:45 olga dbus-daemon[2184]: writing oom_score_adj error: Permission denied
Feb 11 08:18:45 olga dbus-daemon[2182]: writing oom_score_adj error: Permission denied
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Activating service name='org.gnome.Calculator.SearchProvider' requested by ':1.11' (uid=1000 pid=701 comm="/usr/bin/gnome-shell ")
Feb 11 08:18:45 olga dbus-daemon[2180]: writing oom_score_adj error: Permission denied
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Activating service name='org.gnome.Boxes.SearchProvider' requested by ':1.11' (uid=1000 pid=701 comm="/usr/bin/gnome-shell ")
Feb 11 08:18:45 olga dbus-daemon[2178]: writing oom_score_adj error: Permission denied
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Activating service name='org.gnome.Contacts.SearchProvider' requested by ':1.11' (uid=1000 pid=701 comm="/usr/bin/gnome-shell ")
Feb 11 08:18:45 olga dbus-daemon[674]: [session uid=1000 pid=674] Activating service name='org.gnome.ControlCenter.SearchProvider' requested by ':1.11' (uid=1000 pid=701 comm="/usr/bin/gnome-shell ")
Feb 11 08:18:44 olga systemd[657]: gnome-terminal-server.service: Consumed 7.305s CPU time.
Feb 11 08:18:44 olga gnome-shell[701]: Ignored exception from dbus method: Gio.DBusError: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name com.system76.Scheduler was not provided by any .service files
Feb 11 08:18:44 olga dhcpcd[577]: enp4s0: adding default route via 192.168.86.1
Feb 11 08:18:44 olga dhcpcd[577]: enp4s0: adding route to 192.168.86.0/24
Feb 11 08:18:44 olga dhcpcd[577]: enp4s0: leased 192.168.86.81 for 86400 seconds
Feb 11 08:18:42 olga gnome-shell[701]: Unable to mount volume rem0: Gio.IOErrorEnum: Error mounting /dev/sde1 at /run/media/patrick/rem0: unknown filesystem type 'ntfs3,ntfs'
Feb 11 08:18:42 olga gnome-shell[701]: Unable to mount volume bkp: Gio.IOErrorEnum: Error mounting /dev/sdd1 at /run/media/patrick/bkp: unknown filesystem type 'ntfs3,ntfs'
Feb 11 08:18:42 olga kernel: ntfs3: Unknown parameter 'windows_names'
Feb 11 08:18:42 olga kernel: ntfs3: Unknown parameter 'windows_names'
Feb 11 08:18:42 olga NetworkManager[572]: <info>  [1644589122.1328] agent-manager: agent[f7902e9ebb6df6a3,:1.17/org.gnome.Shell.NetworkAgent/1000]: agent registered
Feb 11 08:18:42 olga kernel: audit: type=1110 audit(1644589121.998:112): pid=2137 uid=0 auid=1000 ses=1 msg='op=PAM:setcred grantors=pam_shells,pam_faillock,pam_permit,pam_faillock,pam_gnome_keyring acct="patrick" exe="/usr/lib/gdm-sessi>
Feb 11 08:18:42 olga kernel: audit: type=1101 audit(1644589121.998:111): pid=2137 uid=0 auid=1000 ses=1 msg='op=PAM:accounting grantors=pam_access,pam_unix,pam_permit,pam_time acct="patrick" exe="/usr/lib/gdm-session-worker" hostname=olg>
Feb 11 08:18:41 olga audit[2137]: CRED_REFR pid=2137 uid=0 auid=1000 ses=1 msg='op=PAM:setcred grantors=pam_shells,pam_faillock,pam_permit,pam_faillock,pam_gnome_keyring acct="patrick" exe="/usr/lib/gdm-session-worker" hostname=olga addr>
Feb 11 08:18:41 olga audit[2137]: USER_ACCT pid=2137 uid=0 auid=1000 ses=1 msg='op=PAM:accounting grantors=pam_access,pam_unix,pam_permit,pam_time acct="patrick" exe="/usr/lib/gdm-session-worker" hostname=olga addr=? terminal=/dev/tty1 r>
Feb 11 08:18:41 olga kernel: audit: type=1100 audit(1644589121.994:110): pid=2137 uid=0 auid=1000 ses=1 msg='op=PAM:authentication grantors=pam_shells,pam_faillock,pam_permit,pam_faillock,pam_gnome_keyring acct="patrick" exe="/usr/lib/gd>
Feb 11 08:18:41 olga audit[2137]: USER_AUTH pid=2137 uid=0 auid=1000 ses=1 msg='op=PAM:authentication grantors=pam_shells,pam_faillock,pam_permit,pam_faillock,pam_gnome_keyring acct="patrick" exe="/usr/lib/gdm-session-worker" hostname=ol>
Feb 11 08:18:41 olga gdm-password][2137]: gkr-pam: unlocked login keyring
Feb 11 08:18:39 olga gdm-password][2137]: pam_systemd_home(gdm-password:auth): systemd-homed is not available: Unit dbus-org.freedesktop.home1.service not found.
Feb 11 08:18:39 olga dbus-daemon[571]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.home1.service': Unit dbus-org.freedesktop.home1.service not found.
Feb 11 08:18:39 olga dbus-daemon[571]: [system] Activating via systemd: service name='org.freedesktop.home1' unit='dbus-org.freedesktop.home1.service' requested by ':1.81' (uid=0 pid=2137 comm="gdm-session-worker [pam/gdm-password] ")
Feb 11 08:18:39 olga dhcpcd[577]: enp4s0: probing address 192.168.86.81/24
Feb 11 08:18:39 olga dhcpcd[577]: enp4s0: rebinding lease of 192.168.86.81
Feb 11 08:18:39 olga kernel: [drm:nv_drm_atomic_commit [nvidia_drm]] *ERROR* [nvidia-drm] [GPU ID 0x00000600] Flip event timeout on head 2
Feb 11 08:18:38 olga dhcpcd[577]: enp4s0: soliciting an IPv6 router
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.7901] manager: NetworkManager state is now CONNECTED_GLOBAL
Feb 11 08:18:37 olga kernel: audit: type=1130 audit(1644589117.497:109): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=succes>
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.5010] device (enp4s0): Activation: successful, device activated.
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.5009] manager: NetworkManager state is now CONNECTED_SITE
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.5007] device (enp4s0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.5007] device (enp4s0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Feb 11 08:18:37 olga audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 11 08:18:37 olga systemd[1]: Started Network Manager Script Dispatcher Service.
Feb 11 08:18:37 olga dbus-daemon[571]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Feb 11 08:18:37 olga systemd[1]: Starting Network Manager Script Dispatcher Service...
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4954] policy: set 'Wired connection 1' (enp4s0) as default for IPv4 routing and DNS
Feb 11 08:18:37 olga dbus-daemon[571]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.3' (uid=0 pid=572 comm="/usr/bin/NetworkManager --no->
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4948] device (enp4s0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4943] dhcp4 (enp4s0): state changed unknown -> bound, address=192.168.86.84
Feb 11 08:18:37 olga dhcpcd[577]: enp4s0: adding address fe80::43f3:8237:1387:26e
Feb 11 08:18:37 olga dhcpcd[577]: enp4s0: IAID 99:ca:1b:be
Feb 11 08:18:37 olga kernel: r8169 0000:04:00.0 enp4s0: Link is Up - 1Gbps/Full - flow control rx/tx
Feb 11 08:18:37 olga kernel: IPv6: ADDRCONF(NETDEV_CHANGE): enp4s0: link becomes ready
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4810] dhcp4 (enp4s0): activation: beginning transaction (timeout in 45 seconds)
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4809] device (enp4s0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4806] device (enp4s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4805] manager: NetworkManager state is now CONNECTING
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4803] device (enp4s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4802] device (enp4s0): Activation: starting connection 'Wired connection 1' (29a55ee0-122d-3800-9912-f505ba1c6fbb)
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4797] policy: auto-activating connection 'Wired connection 1' (29a55ee0-122d-3800-9912-f505ba1c6fbb)
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4789] device (enp4s0): state change: unavailable -> disconnected (reason 'carrier-changed', sys-iface-state: 'managed')
Feb 11 08:18:37 olga NetworkManager[572]: <info>  [1644589117.4787] device (enp4s0): carrier: link connected
Feb 11 08:18:37 olga dhcpcd[577]: enp4s0: carrier acquired
Feb 11 08:18:35 olga kernel: r8169 0000:04:00.0 enp4s0: Link is Down
Feb 11 08:18:35 olga NetworkManager[572]: <info>  [1644589115.0060] manager: NetworkManager state is now DISCONNECTED
Feb 11 08:18:34 olga kernel: Generic FE-GE Realtek PHY r8169-0-400:00: attached PHY driver (mii_bus:phy_addr=r8169-0-400:00, irq=MAC)
Feb 11 08:18:34 olga kernel: rfkill: input handler disabled
Feb 11 08:18:34 olga NetworkManager[572]: <info>  [1644589114.7900] device (enp4s0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Feb 11 08:18:34 olga NetworkManager[572]: <info>  [1644589114.7899] manager: sleep: wake requested (sleeping: yes  enabled: yes)
Feb 11 08:18:34 olga systemd-logind[574]: Operation 'sleep' finished.
Feb 11 08:18:34 olga kernel: audit: type=1130 audit(1644589114.784:108): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Feb 11 08:18:34 olga systemd[1]: Stopped target Sleep.
Feb 11 08:18:34 olga 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=failed'
Feb 11 08:18:34 olga systemd[1]: systemd-suspend.service: Consumed 1.464s CPU time.
Feb 11 08:18:34 olga systemd[1]: suspend.target: Job suspend.target/start failed with result 'dependency'.
Feb 11 08:18:34 olga systemd[1]: Dependency failed for Suspend.
Feb 11 08:18:34 olga systemd[1]: Failed to start System Suspend.
Feb 11 08:18:34 olga systemd[1]: systemd-suspend.service: Failed with result 'exit-code'.
Feb 11 08:18:34 olga systemd[1]: systemd-suspend.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 08:18:34 olga gdm[617]: GLib: Source ID 59 was not found when attempting to remove it
Feb 11 08:18:33 olga systemd-sleep[2087]: Failed to put system to sleep. System resumed again: Device or resource busy
Feb 11 08:18:33 olga kernel: PM: suspend exit
Feb 11 08:18:33 olga kernel: Restarting tasks ... done.
Feb 11 08:18:33 olga kernel: OOM killer enabled.
Feb 11 08:18:33 olga kernel: 
Feb 11 08:18:33 olga kernel:  </TASK>
Feb 11 08:18:33 olga kernel:  ? entry_SYSCALL_64_after_hwframe+0x44/0xae
Feb 11 08:18:33 olga kernel:  ? exc_page_fault+0x72/0x170
Feb 11 08:18:33 olga kernel:  ? do_syscall_64+0x69/0x80
Feb 11 08:18:33 olga kernel:  ? syscall_exit_to_user_mode+0x23/0x40
Feb 11 08:18:33 olga kernel:  ? exit_to_user_mode_prepare+0x77/0x170
Feb 11 08:18:33 olga kernel:  ? switch_fpu_return+0x49/0xd0
Feb 11 08:18:33 olga kernel:  ? __x64_sys_futex+0x8e/0x1e0
Feb 11 08:18:33 olga kernel:  ? do_futex+0x14b/0x1f0
Feb 11 08:18:33 olga kernel:  ? do_syscall_64+0x69/0x80
Feb 11 08:18:33 olga kernel:  ? syscall_exit_to_user_mode+0x23/0x40
Feb 11 08:18:33 olga kernel:  ? do_syscall_64+0x5c/0x80
Feb 11 08:18:33 olga kernel:  ? __x64_sys_ioctl+0x82/0xb0
Feb 11 08:18:33 olga kernel:  ? drm_mode_rmfb+0x210/0x210
Feb 11 08:18:33 olga kernel:  ? drm_ioctl+0x22a/0x3d0
Feb 11 08:18:33 olga kernel:  ? futex_wait+0x18d/0x270
Feb 11 08:18:33 olga kernel:  ? drm_ioctl_kernel+0xb8/0x140
Feb 11 08:18:33 olga kernel:  ? drm_mode_rmfb+0x210/0x210
Feb 11 08:18:33 olga kernel:  ? drm_mode_rmfb+0x1d2/0x210
Feb 11 08:18:33 olga kernel:  ? nv_drm_framebuffer_destroy+0x3b/0x50 [nvidia_drm 83449b98ef70c584f13b04629c5c9c139f48021f]
Feb 11 08:18:33 olga kernel:  _nv000092kms+0x42/0x50 [nvidia_modeset 6533287d4736593a1d42db4207924d5dae07c92e]
Feb 11 08:18:33 olga kernel:  nvkms_ioctl_from_kapi+0x27/0x90 [nvidia_modeset 6533287d4736593a1d42db4207924d5dae07c92e]
Feb 11 08:18:33 olga kernel:  ? __switch_to_asm+0x42/0x70
Feb 11 08:18:33 olga kernel:  rwsem_down_read_slowpath+0x365/0x3c0
Feb 11 08:18:33 olga kernel:  schedule+0x4b/0xc0
Feb 11 08:18:33 olga kernel:  __schedule+0x307/0x10b0
Feb 11 08:18:33 olga kernel:  <TASK>
Feb 11 08:18:33 olga kernel: Call Trace:
Feb 11 08:18:33 olga kernel: task:gnome-shell     state:D stack:    0 pid:  701 ppid:   657 flags:0x00000004
Feb 11 08:18:33 olga kernel: Freezing of tasks failed after 20.005 seconds (1 tasks refusing to freeze, wq_busy=0):
Feb 11 08:18:33 olga kernel: Freezing user space processes ... 
Feb 11 08:18:33 olga kernel: Filesystems sync: 0.004 seconds
Feb 11 08:18:13 olga kernel: audit: type=1131 audit(1644589093.774:107): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=succes>
Feb 11 08:18:13 olga 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'
Feb 11 08:18:13 olga systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Feb 11 08:18:13 olga rtkit-daemon[760]: Demoted 6 threads.
Feb 11 08:18:13 olga rtkit-daemon[760]: Successfully demoted thread 755 of process 755.
Feb 11 08:18:13 olga rtkit-daemon[760]: Successfully demoted thread 770 of process 755.
Feb 11 08:18:13 olga rtkit-daemon[760]: Successfully demoted thread 757 of process 757.
Feb 11 08:18:13 olga rtkit-daemon[760]: Successfully demoted thread 771 of process 757.
Feb 11 08:18:13 olga rtkit-daemon[760]: Successfully demoted thread 756 of process 756.
Feb 11 08:18:13 olga rtkit-daemon[760]: Successfully demoted thread 768 of process 756.
Feb 11 08:18:13 olga rtkit-daemon[760]: Demoting known real-time threads.
Feb 11 08:18:13 olga rtkit-daemon[760]: The canary thread is apparently starving. Taking action.
Feb 11 08:18:13 olga kernel: PM: suspend entry (s2idle)
Feb 11 08:18:13 olga kernel: PM: suspend exit
Feb 11 08:18:13 olga kernel: Restarting tasks ... done.
Feb 11 08:18:13 olga kernel: OOM killer enabled.
Feb 11 08:18:13 olga kernel: 
Feb 11 08:18:13 olga kernel:  </TASK>
Feb 11 08:18:13 olga kernel:  ? entry_SYSCALL_64_after_hwframe+0x44/0xae
Feb 11 08:18:13 olga kernel:  ? exc_page_fault+0x72/0x170
Feb 11 08:18:13 olga kernel:  ? do_syscall_64+0x69/0x80
Feb 11 08:18:13 olga kernel:  ? syscall_exit_to_user_mode+0x23/0x40
Feb 11 08:18:13 olga kernel:  ? exit_to_user_mode_prepare+0x77/0x170
Feb 11 08:18:13 olga kernel:  ? switch_fpu_return+0x49/0xd0
Feb 11 08:18:13 olga kernel:  ? __x64_sys_futex+0x8e/0x1e0
Feb 11 08:18:13 olga kernel:  ? do_futex+0x14b/0x1f0
Feb 11 08:18:13 olga kernel:  ? do_syscall_64+0x69/0x80
Feb 11 08:18:13 olga kernel:  ? syscall_exit_to_user_mode+0x23/0x40
Feb 11 08:18:13 olga kernel:  ? do_syscall_64+0x5c/0x80
Feb 11 08:18:13 olga kernel:  ? __x64_sys_ioctl+0x82/0xb0
Feb 11 08:18:13 olga kernel:  ? drm_mode_rmfb+0x210/0x210
Feb 11 08:18:13 olga kernel:  ? drm_ioctl+0x22a/0x3d0
Feb 11 08:18:13 olga kernel:  ? futex_wait+0x18d/0x270
Feb 11 08:18:13 olga kernel:  ? drm_ioctl_kernel+0xb8/0x140
Feb 11 08:18:13 olga kernel:  ? drm_mode_rmfb+0x210/0x210
Feb 11 08:18:13 olga kernel:  ? drm_mode_rmfb+0x1d2/0x210
Feb 11 08:18:13 olga kernel:  ? nv_drm_framebuffer_destroy+0x3b/0x50 [nvidia_drm 83449b98ef70c584f13b04629c5c9c139f48021f]
Feb 11 08:18:13 olga kernel:  _nv000092kms+0x42/0x50 [nvidia_modeset 6533287d4736593a1d42db4207924d5dae07c92e]
Feb 11 08:18:13 olga kernel:  nvkms_ioctl_from_kapi+0x27/0x90 [nvidia_modeset 6533287d4736593a1d42db4207924d5dae07c92e]
Feb 11 08:18:13 olga kernel:  ? __switch_to_asm+0x42/0x70
Feb 11 08:18:13 olga kernel:  rwsem_down_read_slowpath+0x365/0x3c0
Feb 11 08:18:13 olga kernel:  schedule+0x4b/0xc0
Feb 11 08:18:13 olga kernel:  __schedule+0x307/0x10b0
Feb 11 08:18:13 olga kernel:  <TASK>
Feb 11 08:18:13 olga kernel: Call Trace:
Feb 11 08:18:13 olga kernel: task:gnome-shell     state:D stack:    0 pid:  701 ppid:   657 flags:0x00000004
Feb 11 08:18:13 olga kernel: Freezing of tasks failed after 20.007 seconds (1 tasks refusing to freeze, wq_busy=0):
Feb 11 08:18:13 olga kernel: Freezing user space processes ... 
Feb 11 08:18:13 olga kernel: Filesystems sync: 2.028 seconds
Feb 11 08:17:51 olga kernel: PM: suspend entry (deep)
Feb 11 08:17:51 olga systemd-sleep[2087]: Entering sleep state 'suspend'...
Feb 11 08:17:51 olga systemd[1]: Starting System Suspend...
Feb 11 08:17:51 olga kernel: audit: type=1131 audit(1644589071.726:106): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=nvidia-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 11 08:17:51 olga kernel: audit: type=1130 audit(1644589071.726:105): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=nvidia-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 11 08:17:51 olga systemd[1]: nvidia-suspend.service: Consumed 1.024s CPU time.
Feb 11 08:17:51 olga audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=nvidia-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 11 08:17:51 olga audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=nvidia-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 11 08:17:51 olga systemd[1]: Finished NVIDIA system suspend actions.
Feb 11 08:17:51 olga systemd[1]: nvidia-suspend.service: Deactivated successfully.
Feb 11 08:17:50 olga wireplumber[756]: [string "policy-bluetooth.lua"]:121: bad argument #1 to 'find' (string expected, got nil)
                                       stack traceback:
                                               [C]: in function 'string.find'
                                               [string "policy-bluetooth.lua"]:121: in upvalue 'isBluez5AudioSink'
                                               [string "policy-bluetooth.lua"]:389: in function <[string "policy-bluetooth.lua"]:387>
Feb 11 08:17:50 olga gsd-media-keys[888]: Unable to get default sink
Feb 11 08:17:50 olga gsd-media-keys[888]: Unable to get default source
Feb 11 08:17:50 olga kernel: rfkill: input handler enabled
Feb 11 08:17:50 olga wireplumber[756]: [string "alsa.lua"]:339: attempt to index a nil value (local 'device')
                                       stack traceback:
                                               [string "alsa.lua"]:339: in function <[string "alsa.lua"]:337>
Feb 11 08:17:50 olga kernel: snd_hda_codec_hdmi hdaudioC0D0: HDMI: invalid ELD data byte 19
Feb 11 08:17:50 olga logger[2079]: <13>Feb 11 08:17:50 suspend: nvidia-suspend.service
Feb 11 08:17:50 olga suspend[2079]: nvidia-suspend.service
Feb 11 08:17:50 olga systemd[1]: Starting NVIDIA system suspend actions...
Feb 11 08:17:50 olga systemd[1]: Reached target Sleep.
Feb 11 08:17:49 olga dhcpcd[577]: enp4s0: carrier lost
Feb 11 08:17:49 olga kernel: r8169 0000:04:00.0 enp4s0: Link is Down
Feb 11 08:17:49 olga dhcpcd[577]: enp4s0: rebinding lease of 192.168.86.81
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4428] device (enp4s0): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Feb 11 08:17:49 olga dhcpcd[577]: enp4s0: pid 572 deleted IP address 192.168.86.81/24
Feb 11 08:17:49 olga dhcpcd[577]: enp4s0: pid 572 deleted default route via 192.168.86.1
Feb 11 08:17:49 olga dhcpcd[577]: enp4s0: pid 572 deleted route to 192.168.86.0/24
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4385] dhcp4 (enp4s0): state changed bound -> terminated
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4385] dhcp4 (enp4s0): canceled DHCP transaction
Feb 11 08:17:49 olga gnome-shell[701]: Timelines with detached actors are not supported
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4184] device (enp4s0): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
Feb 11 08:17:49 olga kernel: audit: type=1130 audit(1644589069.413:104): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=succes>
Feb 11 08:17:49 olga audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 11 08:17:49 olga systemd[1]: Started Network Manager Script Dispatcher Service.
Feb 11 08:17:49 olga dbus-daemon[571]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Feb 11 08:17:49 olga systemd[1]: Starting Network Manager Script Dispatcher Service...
Feb 11 08:17:49 olga dbus-daemon[571]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.3' (uid=0 pid=572 comm="/usr/bin/NetworkManager --no->
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4111] device (enp4s0): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed')
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4109] manager: NetworkManager state is now ASLEEP
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4108] manager: sleep: sleep requested (sleeping: no  enabled: yes)
Feb 11 08:17:22 olga gnome-shell[701]: libinput error: client bug: timer event15 debounce short: scheduled expiry is in the past (-20ms), your system is too slow
Feb 11 08:17:22 olga gnome-shell[701]: libinput error: client bug: timer event15 debounce: scheduled expiry is in the past (-7ms), your system is too slow
Feb 11 08:17:12 olga gnome-shell[701]: libinput error: client bug: timer event15 debounce short: scheduled expiry is in the past (-13ms), your system is too slow
Feb 11 08:17:12 olga gnome-shell[701]: libinput error: client bug: timer event15 debounce: scheduled expiry is in the past (-0ms), your system is too slow
Feb 11 08:16:10 olga gnome-shell[701]: libinput error: client bug: timer event15 debounce short: scheduled expiry is in the past (-19ms), your system is too slow
Feb 11 08:16:10 olga gnome-shell[701]: libinput error: client bug: timer event15 debounce: scheduled expiry is in the past (-6ms), your system is too slow
Feb 11 08:14:51 olga gnome-shell[701]: libinput error: client bug: timer event15 debounce short: scheduled expiry is in the past (-0ms), your system is too slow
Feb 11 08:14:44 olga gnome-shell[701]: libinput error: event15 - Logitech G703 LS: WARNING: log rate limit exceeded (5 msgs per 60min). Discarding future messages.
Feb 11 08:14:44 olga gnome-shell[701]: libinput error: event15 - Logitech G703 LS: client bug: event processing lagging behind by 14ms, your system is too slow
Feb 11 08:14:32 olga gnome-shell[701]: libinput error: event15 - Logitech G703 LS: client bug: event processing lagging behind by 15ms, your system is too slow
                                       stack traceback:
                                               [C]: in function 'string.find'
                                               [string "policy-bluetooth.lua"]:121: in upvalue 'isBluez5AudioSink'
                                               [string "policy-bluetooth.lua"]:389: in function <[string "policy-bluetooth.lua"]:387>
Feb 11 08:17:50 olga gsd-media-keys[888]: Unable to get default sink
Feb 11 08:17:50 olga gsd-media-keys[888]: Unable to get default source
Feb 11 08:17:50 olga kernel: rfkill: input handler enabled
Feb 11 08:17:50 olga wireplumber[756]: [string "alsa.lua"]:339: attempt to index a nil value (local 'device')
                                       stack traceback:
                                               [string "alsa.lua"]:339: in function <[string "alsa.lua"]:337>
Feb 11 08:17:50 olga kernel: snd_hda_codec_hdmi hdaudioC0D0: HDMI: invalid ELD data byte 19
Feb 11 08:17:50 olga logger[2079]: <13>Feb 11 08:17:50 suspend: nvidia-suspend.service
Feb 11 08:17:50 olga suspend[2079]: nvidia-suspend.service
Feb 11 08:17:50 olga systemd[1]: Starting NVIDIA system suspend actions...
Feb 11 08:17:50 olga systemd[1]: Reached target Sleep.
Feb 11 08:17:49 olga dhcpcd[577]: enp4s0: carrier lost
Feb 11 08:17:49 olga kernel: r8169 0000:04:00.0 enp4s0: Link is Down
Feb 11 08:17:49 olga dhcpcd[577]: enp4s0: rebinding lease of 192.168.86.81
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4428] device (enp4s0): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Feb 11 08:17:49 olga dhcpcd[577]: enp4s0: pid 572 deleted IP address 192.168.86.81/24
Feb 11 08:17:49 olga dhcpcd[577]: enp4s0: pid 572 deleted default route via 192.168.86.1
Feb 11 08:17:49 olga dhcpcd[577]: enp4s0: pid 572 deleted route to 192.168.86.0/24
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4385] dhcp4 (enp4s0): state changed bound -> terminated
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4385] dhcp4 (enp4s0): canceled DHCP transaction
Feb 11 08:17:49 olga gnome-shell[701]: Timelines with detached actors are not supported
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4184] device (enp4s0): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
Feb 11 08:17:49 olga kernel: audit: type=1130 audit(1644589069.413:104): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=succes>
Feb 11 08:17:49 olga audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 11 08:17:49 olga systemd[1]: Started Network Manager Script Dispatcher Service.
Feb 11 08:17:49 olga dbus-daemon[571]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Feb 11 08:17:49 olga systemd[1]: Starting Network Manager Script Dispatcher Service...
Feb 11 08:17:49 olga dbus-daemon[571]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.3' (uid=0 pid=572 comm="/usr/bin/NetworkManager --no->
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4111] device (enp4s0): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed')
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4109] manager: NetworkManager state is now ASLEEP
Feb 11 08:17:49 olga NetworkManager[572]: <info>  [1644589069.4108] manager: sleep: sleep requested (sleeping: no  enabled: yes)

08:18:34 is where journalctl reports the system failed to sleep.
There are errors stating that gnome-shell refuses to freeze at 08:18:13 and 08:18:33.
As mentioned, not using nvidia-suspend will put my compter into a sleep state, but standard suspend is very buggy and always requires a relog if it doesn't force my computer to restart.

Any ideas?


Edit:
After making zero changes to my system and reenabling the nvidia-suspend + nvidia-hibernate services in an effort to debug, they now work.
The machine still randomly shuts down on suspend/resume. Marking as solved, but I'll update here if that gets fixed.

Last edited by threedope (2022-02-14 14:22:44)

Offline

Board footer

Powered by FluxBB