steam-for-linux icon indicating copy to clipboard operation
steam-for-linux copied to clipboard

Steam sets a persistent Screensaver inhibit

Open ortango opened this issue 1 year ago • 0 comments

Your system information

  • Steam client version (build number or date): 1729015347
  • Distribution (e.g. Ubuntu): archlinux
  • Opted into Steam client beta?: Yes
  • Have you checked for system updates?: Yes
  • Steam Logs: NA see below.
  • GPU: AMD

Please describe your issue in as much detail as possible:

Same issue as described in this issue: https://github.com/ValveSoftware/steam-for-linux/issues/5607#issuecomment-2391391457

We have not been able to reproduce situations where the Steam client is permanently preventing the screen saver to activate as described above. But if you run into such a problem, you may want to use these two new command line options: "-verbose-screensaver-inhibit" and "-verbose-computer-activity" to understand why the Steam client thinks there is activity on your system. If you still believe there is an issue with the Steam client after that please open a separate issue and provide logs.

Steam will inhibit the screensaver for the entire duration of its run.

  • This is on X
  • This happens if the dbus screensaver service is not present
  • This happens if the dbus service is present, but the suspend_cookie begins at 0 (which is a valid uint32, but sdl treats specially in its code)
  • This happens after the first steam activity is generated (mouse or gamepad, not keyboard)
  • The first inhibit event that steam logs is always ignored, by both dbus service and Xss. which isn't part of the issue, just an observation.

Steps for reproducing this issue:

  1. Start steam with either a dbus screensaver suspend service running that starts with cookie=0, or without the dbus service. On X.
  2. wait for the first allow after the initial computer-activity (?)
  3. move the mouse or use the gamepad
  4. observe the X screen saver lock state is now persistent.

Logs:

i have 4 sets of logs collapsed below.

  1. Xss. no dbus service. A persistant lock is made by steam.
  2. dbus service that has intial suspend_cookie = 0. A persistent lock is made by steam and by dbus (cookie=0 is never removed).
  3. dbus service with cookie = 0, but doesnt actually suspend the screensaver itself at all (never runs XScreenSaverSuspend. In this case steam creates a persistent lock just like case 1 (Xss only).
  4. dbus service that uses 1 for intial suspend_cookie. this works fine. and steam never issues a lock to Xss itself, only through dbus.
Xss only, no dbus.

console_log

[2024-10-16 10:23:08] computer activity: mouse
[2024-10-16 10:23:08] computer activity: controller
[2024-10-16 10:23:08] screen saver inhibit: computer is active
// First inhibit is always skipped by dbus/Xss
[2024-10-16 10:23:08] screen saver inhibit: inhibit
[2024-10-16 10:23:08] screen saver inhibit: computer is active
..
[2024-10-16 10:23:21] screen saver inhibit: computer is active
[2024-10-16 10:23:22] screen saver inhibit: allow
[2024-10-16 10:23:57] computer activity: mouse
[2024-10-16 10:23:57] screen saver inhibit: computer is active
// This suspend lock doesnt go away.
[2024-10-16 10:23:57] screen saver inhibit: inhibit
[2024-10-16 10:23:57] screen saver inhibit: computer is active
..
[2024-10-16 10:24:27] screen saver inhibit: computer is active
[2024-10-16 10:24:27] screen saver inhibit: renew inhibit
[2024-10-16 10:24:28] screen saver inhibit: computer is active
[2024-10-16 10:24:28] screen saver inhibit: allow
[2024-10-16 10:24:35] screen saver inhibit: computer is active
[2024-10-16 10:24:35] screen saver inhibit: inhibit
[2024-10-16 10:24:36] screen saver inhibit: computer is active
..
// Steam is closed at this timestamp.
[2024-10-16 10:24:45] screen saver inhibit: computer is active

Xserver logging

// Timestamp matches second inhibit event
[Wed Oct 16 10:23:57 2024] inhibit event for 0x43e00006
// Timestamp of steam being closed
[Wed Oct 16 10:24:45 2024] uninhibit event for 0x43e00006
Dbus service, initial cookie = 0

console_log.txt

[2024-10-16 11:42:36] computer activity: mouse
[2024-10-16 11:42:36] computer activity: controller
[2024-10-16 11:42:36] screen saver inhibit: computer is active
// First inhibit request ignored by Xss/dbus
[2024-10-16 11:42:36] screen saver inhibit: inhibit
[2024-10-16 11:42:36] screen saver inhibit: computer is active
..
[2024-10-16 11:42:54] screen saver inhibit: computer is active
[2024-10-16 11:42:54] screen saver inhibit: allow
[2024-10-16 11:43:03] computer activity: mouse
[2024-10-16 11:43:04] screen saver inhibit: computer is active
// Timestamp of first lock. Steam sends both dbus lock request and a lock straight to Xss. two locks are placed at this point.
[2024-10-16 11:43:04] screen saver inhibit: inhibit
[2024-10-16 11:43:04] screen saver inhibit: computer is active
..
[2024-10-16 11:43:34] screen saver inhibit: computer is active
// The renew event askes dbus for an additional lock. now there are 2 concurrent dbus lock requests in addition to the straight Xss lock.
[2024-10-16 11:43:34] screen saver inhibit: renew inhibit
[2024-10-16 11:43:34] screen saver inhibit: computer is active
..
[2024-10-16 11:44:04] screen saver inhibit: computer is active
// These renew events will just remove cookie = 1, leaving cookie = 0 at all times.
[2024-10-16 11:44:04] screen saver inhibit: renew inhibit
[2024-10-16 11:44:04] screen saver inhibit: computer is active
..
[2024-10-16 11:44:07] screen saver inhibit: computer is active
[2024-10-16 11:44:08] screen saver inhibit: allow
[2024-10-16 11:44:19] screen saver inhibit: computer is active
[2024-10-16 11:44:19] screen saver inhibit: inhibit
[2024-10-16 11:44:20] screen saver inhibit: computer is active
..
// Steam is exiting. "straight" Xss lock is removed.
[2024-10-16 11:44:22] screen saver inhibit: computer is active

Xserver logging

// Steam's second inhibit request. One dbus lock and one Xss lock are requested. notice the two different XIDs.
// This is the dbus lock.
[Wed Oct 16 11:43:03 2024] inhibit event for 0x41600000
// This is the "straight Xss" lock.
[Wed Oct 16 11:43:03 2024] inhibit event for 0x43c00006
// This is the timestamp of steam closing. and Xss lock is removed.
[Wed Oct 16 11:44:22 2024] uninhibit event for 0x43c00006
// This is the timestamp of steam's dbus client disconnecting. its lock is cleared by client disconnection, and not a request by steam.
[Wed Oct 16 11:44:30 2024] uninhibit event for 0x41600000

Dbus service logging

// Timestamp of second inhibit request steam makes.
[Wed Oct 16 11:43:03 2024] | Suspend screensaver = 'true'
[Wed Oct 16 11:43:03 2024] | ':1.182' now has '1' cookies
[Wed Oct 16 11:43:03 2024] \ Inhibit request app=':1.182' name='Steam' reason='Client interface', cookie='0'
// Timestamp of first renew event. Steam requests a second dbus inhibit, not removing the first.
[Wed Oct 16 11:43:34 2024] | ':1.182' now has '2' cookies
[Wed Oct 16 11:43:34 2024] \ Inhibit request app=':1.182' name='Steam' reason='Client interface', cookie='1'
[Wed Oct 16 11:44:04 2024] | ':1.182' has '1' cookies now
[Wed Oct 16 11:44:04 2024] \ Uninhibit request app=':1.182' cookie='1'
[Wed Oct 16 11:44:04 2024] | ':1.182' now has '2' cookies
[Wed Oct 16 11:44:04 2024] \ Inhibit request app=':1.182' name='Steam' reason='Client interface', cookie='1'
[Wed Oct 16 11:44:08 2024] | ':1.182' has '1' cookies now
[Wed Oct 16 11:44:08 2024] \ Uninhibit request app=':1.182' cookie='1'
[Wed Oct 16 11:44:19 2024] | ':1.182' now has '2' cookies
[Wed Oct 16 11:44:19 2024] \ Inhibit request app=':1.182' name='Steam' reason='Client interface', cookie='1'
// Timestamp of steam closing. Also when the "straight Xss" lock is removed and when the second cookie (1) is removed.
[Wed Oct 16 11:44:22 2024] | ':1.182' has '1' cookies now
[Wed Oct 16 11:44:22 2024] \ Uninhibit request app=':1.182' cookie='1'
// Timestamp of steam's dbus client disconnecting. final dbus lock (0) is removed in cleanup (not by request)
[Wed Oct 16 11:44:30 2024] App disconnect app=':1.182'
[Wed Oct 16 11:44:30 2024] | Suspend screensaver = 'false'
[Wed Oct 16 11:44:38 2024] Terminating
Dbus service, initial cookie = 0, dbus service doesnt actually run XScreenSaverSuspend

console_log.txt

[2024-10-16 10:30:59] computer activity: mouse
[2024-10-16 10:30:59] computer activity: controller
[2024-10-16 10:30:59] screen saver inhibit: computer is active
// First inhibit is does nothing with either dbus or Xss
[2024-10-16 10:30:59] screen saver inhibit: inhibit
[2024-10-16 10:30:59] screen saver inhibit: computer is active
..
[2024-10-16 10:31:17] screen saver inhibit: computer is active
[2024-10-16 10:31:18] screen saver inhibit: allow
[2024-10-16 10:31:33] computer activity: mouse
[2024-10-16 10:31:33] screen saver inhibit: computer is active
// This is the timestamp for the NOOP dbus suspend
// but also the timestamp for the persistant lock that does not go through dbus
[2024-10-16 10:31:33] screen saver inhibit: inhibit
[2024-10-16 10:31:34] screen saver inhibit: computer is active
..
[2024-10-16 10:32:03] screen saver inhibit: computer is active
[2024-10-16 10:32:03] screen saver inhibit: renew inhibit
[2024-10-16 10:32:04] screen saver inhibit: computer is active
..
[2024-10-16 10:32:05] screen saver inhibit: computer is active
[2024-10-16 10:32:06] screen saver inhibit: allow
[2024-10-16 10:32:51] screen saver inhibit: computer is active
[2024-10-16 10:32:51] screen saver inhibit: inhibit
[2024-10-16 10:32:51] screen saver inhibit: computer is active
[2024-10-16 10:32:52] screen saver inhibit: computer is active
// Timestamp for steam closing. Xss inhibit is removed.
[2024-10-16 10:32:52] screen saver inhibit: computer is active

Xserver logging

// Timestamp matches the second inhibit event
[Wed Oct 16 10:31:33 2024] inhibit event for 0x43c00006
// Timestamp of steam closing
[Wed Oct 16 10:32:52 2024] uninhibit event for 0x43c00006

Dbus service logging

// Timestamp of second inhibit event.
[Wed Oct 16 10:31:33 2024] | Suspend screensaver = 'true'
[Wed Oct 16 10:31:33 2024] | dry run. no action taken.
[Wed Oct 16 10:31:33 2024] | ':1.140' now has '1' cookies
[Wed Oct 16 10:31:33 2024] \ Inhibit request app=':1.140' name='Steam' reason='Client interface', cookie='0'
[Wed Oct 16 10:32:03 2024] | ':1.140' now has '2' cookies
[Wed Oct 16 10:32:03 2024] \ Inhibit request app=':1.140' name='Steam' reason='Client interface', cookie='1'
[Wed Oct 16 10:32:06 2024] | ':1.140' has '1' cookies now
[Wed Oct 16 10:32:06 2024] \ Uninhibit request app=':1.140' cookie='1'
// Steam can accumulate lock requests when suspend_cookie == 0. This would be a second problem (but dbus service is not running XScreenSaverSuspend in this run).
[Wed Oct 16 10:32:51 2024] | ':1.140' now has '2' cookies
[Wed Oct 16 10:32:51 2024] \ Inhibit request app=':1.140' name='Steam' reason='Client interface', cookie='1'
// Timestamp of steam exit. Xss lock is removed. (dbus service still thinks a lock exists)
[Wed Oct 16 10:32:52 2024] | ':1.140' has '1' cookies now
[Wed Oct 16 10:32:52 2024] \ Uninhibit request app=':1.140' cookie='1'
// Steam's dbus client disconnects and dbus removes the (NOOP) locks
[Wed Oct 16 10:32:57 2024] App disconnect app=':1.140'
[Wed Oct 16 10:32:57 2024] | Suspend screensaver = 'false'
[Wed Oct 16 10:32:57 2024] | dry run. no action taken.
[Wed Oct 16 10:33:15 2024] Terminating
Dbus service, initial cookie = 1 (this works as expected)

console_log.txt

[2024-10-16 10:35:17] computer activity: mouse
[2024-10-16 10:35:17] computer activity: controller
[2024-10-16 10:35:17] screen saver inhibit: computer is active
// First inhibit is (always) ignored by both Xss/dbus
[2024-10-16 10:35:17] screen saver inhibit: inhibit
[2024-10-16 10:35:17] screen saver inhibit: computer is active
..
[2024-10-16 10:35:35] screen saver inhibit: computer is active
[2024-10-16 10:35:36] screen saver inhibit: allow
[2024-10-16 10:35:42] computer activity: mouse
[2024-10-16 10:35:43] screen saver inhibit: computer is active
// Timestamp of first inhibit request to dbus. First lock added to Xserver.
[2024-10-16 10:35:43] screen saver inhibit: inhibit
[2024-10-16 10:35:43] screen saver inhibit: computer is active
..
[2024-10-16 10:36:12] screen saver inhibit: computer is active
// This all works as I would expect. Though, i do not know why steam doesnt just keep the lock, instead of removing and adding a new one.
[2024-10-16 10:36:13] screen saver inhibit: allow
[2024-10-16 10:36:26] screen saver inhibit: computer is active
[2024-10-16 10:36:26] screen saver inhibit: inhibit
[2024-10-16 10:36:27] screen saver inhibit: computer is active
..
[2024-10-16 10:36:57] screen saver inhibit: computer is active
[2024-10-16 10:36:57] screen saver inhibit: renew inhibit
[2024-10-16 10:36:57] screen saver inhibit: computer is active
..
[2024-10-16 10:37:20] screen saver inhibit: computer is active
[2024-10-16 10:37:21] screen saver inhibit: allow
[2024-10-16 10:37:54] screen saver inhibit: computer is active
[2024-10-16 10:37:54] screen saver inhibit: inhibit
[2024-10-16 10:37:55] screen saver inhibit: computer is active
[2024-10-16 10:37:55] screen saver inhibit: computer is active
// Timestamp of steam closing. Lock is removed.
[2024-10-16 10:37:56] screen saver inhibit: computer is active

Xserver logging

// Timestamp of second inhibit request
[Wed Oct 16 10:35:43 2024] inhibit event for 0x41600000
[Wed Oct 16 10:36:13 2024] uninhibit event for 0x41600000
[Wed Oct 16 10:36:26 2024] inhibit event for 0x41600001
// Timestamp of a "renew" event
[Wed Oct 16 10:36:57 2024] uninhibit event for 0x41600001
[Wed Oct 16 10:36:57 2024] inhibit event for 0x41600002
[Wed Oct 16 10:37:21 2024] uninhibit event for 0x41600002
[Wed Oct 16 10:37:54 2024] inhibit event for 0x41600003
// Steam is closed, lock removed.
[Wed Oct 16 10:37:56 2024] uninhibit event for 0x41600003

Dbus service logging

// Timestamp of second lock request.
[Wed Oct 16 10:35:43 2024] | Suspend screensaver = 'true'
[Wed Oct 16 10:35:43 2024] | ':1.161' now has '1' cookies
[Wed Oct 16 10:35:43 2024] \ Inhibit request app=':1.161' name='Steam' reason='Client interface', cookie='1'
[Wed Oct 16 10:36:13 2024] | ':1.161' has '0' cookies now
[Wed Oct 16 10:36:13 2024] | Suspend screensaver = 'false'
[Wed Oct 16 10:36:13 2024] \ Uninhibit request app=':1.161' cookie='1'
[Wed Oct 16 10:36:26 2024] | Suspend screensaver = 'true'
[Wed Oct 16 10:36:26 2024] | ':1.161' now has '1' cookies
[Wed Oct 16 10:36:26 2024] \ Inhibit request app=':1.161' name='Steam' reason='Client interface', cookie='1'
/ Steam lock "renew" event
[Wed Oct 16 10:36:57 2024] | ':1.161' has '0' cookies now
[Wed Oct 16 10:36:57 2024] | Suspend screensaver = 'false'
[Wed Oct 16 10:36:57 2024] \ Uninhibit request app=':1.161' cookie='1'
[Wed Oct 16 10:36:57 2024] | Suspend screensaver = 'true'
[Wed Oct 16 10:36:57 2024] | ':1.161' now has '1' cookies
[Wed Oct 16 10:36:57 2024] \ Inhibit request app=':1.161' name='Steam' reason='Client interface', cookie='1'
[Wed Oct 16 10:37:21 2024] | ':1.161' has '0' cookies now
[Wed Oct 16 10:37:21 2024] | Suspend screensaver = 'false'
[Wed Oct 16 10:37:21 2024] \ Uninhibit request app=':1.161' cookie='1'
[Wed Oct 16 10:37:54 2024] | Suspend screensaver = 'true'
[Wed Oct 16 10:37:54 2024] | ':1.161' now has '1' cookies
[Wed Oct 16 10:37:54 2024] \ Inhibit request app=':1.161' name='Steam' reason='Client interface', cookie='1'
// Steam removes the final lock (lock doesnt need to be cleaned by app disconnect)
[Wed Oct 16 10:37:56 2024] | ':1.161' has '0' cookies now
[Wed Oct 16 10:37:56 2024] | Suspend screensaver = 'false'
[Wed Oct 16 10:37:56 2024] \ Uninhibit request app=':1.161' cookie='1'
[Wed Oct 16 10:38:01 2024] App disconnect app=':1.161'
[Wed Oct 16 10:38:11 2024] Terminating

ortango avatar Oct 16 '24 16:10 ortango