Log SimulateUserActivity once per burst

Steam calls it thousands of times per hour during controller play, which made up
~98% of the journal. Log the first call and a summary with the count after 5
minutes of quiet, when the client leaves, or on shutdown.

PKGBUILD

@@ -3,7 +3,7 @@
 # Maintainer: Daniele Fucini <dfucini [at] gmail [dot] com>
 
 pkgname=xautolock-inhibit
-pkgver=0.1.1
+pkgver=0.1.2
 pkgrel=1
 pkgdesc='Honor org.freedesktop.ScreenSaver inhibit requests by disabling xautolock'
 arch=('any')

README.md

@@ -85,7 +85,7 @@ journalctl --user -u xautolock-inhibit
 ## Limitations
 
 - Restarting the daemon loses the requests it holds; apps don't send them again. Avoid restarting it while a video or game is running.
-- `SimulateUserActivity` is accepted and logged, but does nothing.
+- `SimulateUserActivity` is accepted but does nothing. Calls are logged once when a client starts sending them and once, with a count, after 5 minutes without any.
 - `GetActive` always returns `false`.
 
 ## License

xautolock-inhibit

@@ -10,6 +10,9 @@ import itertools
 import signal
 import subprocess
 import sys
+import time
+from dataclasses import dataclass
+from datetime import timedelta
 
 from gi.repository import Gio, GLib
 
@@ -22,6 +25,7 @@ except ImportError:
 BUS_NAME = "org.freedesktop.ScreenSaver"
 OBJECT_PATHS = ("/org/freedesktop/ScreenSaver", "/ScreenSaver")  # Vivaldi uses the first, Zen the second
 EXIT_NAME_TAKEN = 2
+ACTIVITY_QUIET = 300  # seconds without SimulateUserActivity that end a logged burst
 
 INTROSPECTION = """
 <node>
@@ -105,6 +109,14 @@ class XBlanking:
             log(f"X blanking {'paused' if on else 'resumed'}")
 
 
+@dataclass
+class ActivityBurst:
+    first: float
+    last: float
+    calls: int = 0
+    timer: int = 0
+
+
 class Inhibitor:
     def __init__(self, ignored_reasons, release_delay, blanking):
         self.ignored_reasons = ignored_reasons
@@ -113,6 +125,7 @@ class Inhibitor:
         self.cookies = {}  # cookie -> (sender, application_name, reason, counts)
         self.next_cookie = itertools.count(1)
         self.proc_names = {}  # sender -> "comm[pid]", for logging only
+        self.activity: dict[str, ActivityBurst] = {}  # sender -> SimulateUserActivity burst
         self.disabled = False
         self.release_timer = 0
         self.conn = None
@@ -150,7 +163,9 @@ class Inhibitor:
         self.blanking.suspend(False)
         self.disabled = False
 
-    def shutdown(self):
+    def shutdown(self) -> None:
+        for sender in list(self.activity):
+            self.end_activity(sender)
         if self.release_timer:
             GLib.source_remove(self.release_timer)
             self.release_timer = 0
@@ -192,11 +207,41 @@ class Inhibitor:
         log(f"UnInhibit {cookie}: '{app}' '{reason}'")
         self.update()
 
-    def release_sender(self, sender):
+    def simulate_activity(self, sender: str) -> None:
+        """Log a sender's calls once per burst: Steam sends thousands per hour."""
+        now = time.monotonic()
+        burst = self.activity.get(sender)
+        if burst is None:
+            log(f"SimulateUserActivity from {self.proc_name(sender)} (not implemented)")
+            burst = self.activity[sender] = ActivityBurst(first=now, last=now)
+        else:
+            GLib.source_remove(burst.timer)
+        burst.calls += 1
+        burst.last = now
+        burst.timer = GLib.timeout_add_seconds(ACTIVITY_QUIET, self.on_activity_quiet, sender)
+
+    def on_activity_quiet(self, sender: str) -> bool:
+        self.activity[sender].timer = 0
+        self.end_activity(sender)
+        return GLib.SOURCE_REMOVE
+
+    def end_activity(self, sender: str) -> None:
+        burst = self.activity.pop(sender, None)
+        if burst is None:
+            return
+        if burst.timer:
+            GLib.source_remove(burst.timer)
+        if burst.calls == 1:
+            return
+        span = timedelta(seconds=round(burst.last - burst.first))
+        log(f"SimulateUserActivity from {self.proc_name(sender)}: {burst.calls} calls over {span}")
+
+    def release_sender(self, sender: str) -> None:
         gone = [c for c, (s, *_) in self.cookies.items() if s == sender]
         for c in gone:
             _, app, reason, _ = self.cookies.pop(c)
             log(f"Released {c}: '{app}' '{reason}' ({sender} left the bus)")
+        self.end_activity(sender)
         self.proc_names.pop(sender, None)
         if gone:
             self.update()
@@ -209,7 +254,7 @@ class Inhibitor:
             self.uninhibit(sender, params.unpack()[0])
             invocation.return_value(None)
         elif method == "SimulateUserActivity":
-            log(f"SimulateUserActivity from {self.proc_name(sender)} (not implemented)")
+            self.simulate_activity(sender)
             invocation.return_value(None)
         elif method == "Lock":
             log(f"Lock from {self.proc_name(sender)}")