Controller script elapsed time is correct outside UTC (#821)

systemd prints the start timestamp in local time, which was subtracted from
utcnow(), so elapsed_seconds was off by the UTC offset (6 hours in MDT).  Ask
systemd for a Unix timestamp instead.

Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>

controller/lib/scripts.py

@@ -7,7 +7,8 @@ Uses systemd oneshot services for process survival across controller restarts.
 
 import logging
 import subprocess
-from datetime import datetime
+import time
+from datetime import datetime, timezone
 from typing import Optional
 
 from controller.lib.config import is_docker_mode
@@ -172,27 +173,24 @@ def _get_service_timing(service: str) -> tuple[Optional[str], Optional[int]]:
         Tuple of (started_at ISO string, elapsed_seconds)
     """
     try:
-        # Get ExecMainStartTimestamp from systemctl show
+        # A Unix timestamp, because systemd prints dates in the local timezone.
         result = subprocess.run(
-            ["systemctl", "show", service, "--property=ExecMainStartTimestamp"],
+            ["systemctl", "show", service, "--property=ExecMainStartTimestamp", "--timestamp=unix"],
             capture_output=True,
             text=True,
             timeout=5,
         )
         if result.returncode == 0:
-            # Format: ExecMainStartTimestamp=Wed 2025-01-15 10:30:00 UTC
-            line = result.stdout.strip()
-            if "=" in line:
-                timestamp_str = line.split("=", 1)[1].strip()
-                if timestamp_str:
-                    # Parse the timestamp
-                    try:
-                        # Try common systemd timestamp format
-                        dt = datetime.strptime(timestamp_str, "%a %Y-%m-%d %H:%M:%S %Z")
-                        elapsed = int((datetime.utcnow() - dt).total_seconds())
-                        return dt.isoformat(), max(0, elapsed)
-                    except ValueError:
-                        pass
+            # Format: ExecMainStartTimestamp=@1760226500.123456
+            value = result.stdout.strip().partition("=")[2].lstrip("@")
+            if value:
+                try:
+                    started = float(value)
+                except ValueError:
+                    pass
+                else:
+                    elapsed = int(time.time() - started)
+                    return datetime.fromtimestamp(started, timezone.utc).isoformat(), max(0, elapsed)
     except (subprocess.TimeoutExpired, subprocess.SubprocessError, FileNotFoundError):
         pass
 

controller/test/test_scripts.py

@@ -3,9 +3,11 @@ Unit tests for controller.lib.scripts module.
 """
 
 import subprocess
+import time
 from unittest import mock
 
 from controller.lib.scripts import (
+    _get_service_timing,
     AVAILABLE_SCRIPTS,
     get_current_branch,
     get_script_output,
@@ -285,3 +287,22 @@ class TestGetScriptOutput:
                 assert "wrolpi-repair.service" in call_args
                 assert "-n" in call_args
                 assert "50" in call_args
+
+
+class TestGetServiceTiming:
+
+    def test_elapsed_is_independent_of_local_timezone(self):
+        """systemd prints timestamps in local time; elapsed must not be off by the UTC offset."""
+        started = time.time() - 90
+        completed = subprocess.CompletedProcess(
+            args=[], returncode=0, stdout=f"ExecMainStartTimestamp=@{started:.6f}\n")
+        with mock.patch("controller.lib.scripts.subprocess.run", return_value=completed) as run:
+            started_at, elapsed = _get_service_timing("wrolpi-upgrade.service")
+        assert "--timestamp=unix" in run.call_args.args[0]
+        assert 89 <= elapsed <= 91
+        assert started_at.endswith("+00:00")
+
+    def test_not_started(self):
+        completed = subprocess.CompletedProcess(args=[], returncode=0, stdout="ExecMainStartTimestamp=\n")
+        with mock.patch("controller.lib.scripts.subprocess.run", return_value=completed):
+            assert _get_service_timing("wrolpi-upgrade.service") == (None, None)