From 8b78fdd151ab7dc8c184749c34a2b88cb3a0b8e0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Erik=20Bj=C3=A4reholt?= Date: Wed, 26 Oct 2022 16:18:07 +0200 Subject: [PATCH] fix: improved error handling to avoid logspam (#73) --- aw_watcher_window/__main__.py | 3 +- aw_watcher_window/exceptions.py | 2 ++ aw_watcher_window/lib.py | 12 +++++-- aw_watcher_window/main.py | 36 ++++++++++++++------ aw_watcher_window/xlib.py | 59 +++++++++++++++++++++++---------- 5 files changed, 81 insertions(+), 31 deletions(-) create mode 100644 aw_watcher_window/exceptions.py diff --git a/aw_watcher_window/__main__.py b/aw_watcher_window/__main__.py index 7e24b3c..6405bfd 100644 --- a/aw_watcher_window/__main__.py +++ b/aw_watcher_window/__main__.py @@ -1,3 +1,4 @@ from aw_watcher_window import main -main() +if __name__ == "__main__": + main() diff --git a/aw_watcher_window/exceptions.py b/aw_watcher_window/exceptions.py new file mode 100644 index 0000000..99bceab --- /dev/null +++ b/aw_watcher_window/exceptions.py @@ -0,0 +1,2 @@ +class FatalError(Exception): + """Exception raised when the program should exit with a fatal error.""" diff --git a/aw_watcher_window/lib.py b/aw_watcher_window/lib.py index 5e02bcc..d79860e 100644 --- a/aw_watcher_window/lib.py +++ b/aw_watcher_window/lib.py @@ -1,6 +1,8 @@ import sys from typing import Optional +from .exceptions import FatalError + def get_current_window_linux() -> Optional[dict]: from . import xlib @@ -30,7 +32,7 @@ def get_current_window_macos(strategy: str) -> Optional[dict]: return macos_applescript.getInfo() else: - raise ValueError(f"invalid strategy '{strategy}'") + raise FatalError(f"invalid strategy '{strategy}'") def get_current_window_windows() -> Optional[dict]: @@ -49,11 +51,17 @@ def get_current_window_windows() -> Optional[dict]: def get_current_window(strategy: str = None) -> Optional[dict]: + """ + :raises FatalError: if a fatal error occurs (e.g. unsupported platform, X server closed) + """ + if sys.platform.startswith("linux"): return get_current_window_linux() elif sys.platform == "darwin": + if strategy is None: + raise FatalError("macOS strategy not specified") return get_current_window_macos(strategy) elif sys.platform in ["win32", "cygwin"]: return get_current_window_windows() else: - raise Exception(f"Unknown platform: {sys.platform}") + raise FatalError(f"Unknown platform: {sys.platform}") diff --git a/aw_watcher_window/main.py b/aw_watcher_window/main.py index a84a4c9..79b23bd 100644 --- a/aw_watcher_window/main.py +++ b/aw_watcher_window/main.py @@ -1,20 +1,20 @@ import logging -import sys import os -import subprocess import signal -from time import sleep +import subprocess +import sys from datetime import datetime, timezone +from time import sleep -from aw_core.models import Event -from aw_core.log import setup_logging from aw_client import ActivityWatchClient +from aw_core.log import setup_logging +from aw_core.models import Event -from .lib import get_current_window from .config import parse_args +from .exceptions import FatalError +from .lib import get_current_window from .macos_permissions import background_ensure_permissions - logger = logging.getLogger(__name__) # run with LOG_LEVEL=DEBUG @@ -102,20 +102,36 @@ def heartbeat_loop(client, bucket_id, poll_time, strategy, exclude_title=False): break current_window = None - try: current_window = get_current_window(strategy) logger.debug(current_window) + except (FatalError, OSError): + # Fatal exceptions should quit the program + try: + logger.exception("Fatal error, stopping") + except OSError: + pass + break except Exception: - logger.exception("Exception thrown while trying to get active window") + # Non-fatal exceptions should be logged + try: + # If stdout has been closed, this exception-print can cause (I think) + # OSError: [Errno 5] Input/output error + # See: https://github.com/ActivityWatch/activitywatch/issues/756#issue-1296352264 + # + # However, I'm unable to reproduce the OSError in a test (where I close stdout before logging), + # so I'm in uncharted waters here... but this solution should work. + logger.exception("Exception thrown while trying to get active window") + except OSError: + break - now = datetime.now(timezone.utc) if current_window is None: logger.debug("Unable to fetch window, trying again on next poll") else: if exclude_title: current_window["title"] = "excluded" + now = datetime.now(timezone.utc) current_window_event = Event(timestamp=now, data=current_window) # Set pulsetime to 1 second more than the poll_time diff --git a/aw_watcher_window/xlib.py b/aw_watcher_window/xlib.py index e208a46..954a92e 100644 --- a/aw_watcher_window/xlib.py +++ b/aw_watcher_window/xlib.py @@ -1,10 +1,12 @@ -from typing import Optional import logging +from typing import Optional import Xlib import Xlib.display +from Xlib import X from Xlib.xobject.drawable import Window -from Xlib import X, Xatom + +from .exceptions import FatalError logger = logging.getLogger(__name__) @@ -30,15 +32,28 @@ def _get_current_window_id() -> Optional[int]: def _get_window(window_id: int) -> Window: - return display.create_resource_object('window', window_id) + return display.create_resource_object("window", window_id) def get_current_window() -> Optional[Window]: - window_id = _get_current_window_id() - if window_id is None: - return None - else: - return _get_window(window_id) + """ + Returns the current window, or None if no window is active. + """ + try: + window_id = _get_current_window_id() + if window_id is None: + return None + else: + return _get_window(window_id) + except Xlib.error.ConnectionClosedError: + # when the X server closes the connection, we should exit + # note that stdio is probably closed at this point, so we can't print anything (causes OSError) + try: + logger.warning("X server closed connection, exiting") + except OSError: + pass + raise FatalError() + # Things that can lead to unknown cls/name: # - (cls+name) Empty desktop in xfce (no window focused) @@ -46,12 +61,14 @@ def get_current_window() -> Optional[Window]: def get_window_name(window: Window) -> str: - """ After some annoying debugging I resorted to pretty much copying selfspy. - Source: https://github.com/gurgeh/selfspy/blob/8a34597f81000b3a1be12f8cde092a40604e49cf/selfspy/sniff_x.py#L165 """ + """After some annoying debugging I resorted to pretty much copying selfspy. + Source: https://github.com/gurgeh/selfspy/blob/8a34597f81000b3a1be12f8cde092a40604e49cf/selfspy/sniff_x.py#L165""" try: d = window.get_full_property(NET_WM_NAME, UTF8_STRING) except Xlib.error.XError as e: - logger.warning(f"Unable to get window property NET_WM_NAME, got a {type(e).__name__} exception from Xlib") + logger.warning( + f"Unable to get window property NET_WM_NAME, got a {type(e).__name__} exception from Xlib" + ) # I strongly suspect window.get_wm_name() will also fail and we should return "unknown" right away. # But I don't know, so I pass the thing on, for now. d = None @@ -61,19 +78,23 @@ def get_window_name(window: Window) -> str: if type(r) == str: return r else: - logger.warning("I don't think this case will ever happen, but not sure so leaving this message here just in case.") - return r.decode('latin1') # WM_NAME with type=STRING. + logger.warning( + "I don't think this case will ever happen, but not sure so leaving this message here just in case." + ) + return r.decode("latin1") # WM_NAME with type=STRING. else: # Fixing utf8 issue on Ubuntu (https://github.com/gurgeh/selfspy/issues/133) # Thanks to https://github.com/gurgeh/selfspy/issues/133#issuecomment-142943681 try: - return d.value.decode('utf8') + return d.value.decode("utf8") except UnicodeError: - logger.warning(f"Failed to decode one or more characters which will be skipped, bytes are: {d.value}") + logger.warning( + f"Failed to decode one or more characters which will be skipped, bytes are: {d.value}" + ) if isinstance(d.value, bytes): - return d.value.decode('utf8', 'ignore') + return d.value.decode("utf8", "ignore") else: - return d.value.encode('utf8').decode('utf8', 'ignore') + return d.value.encode("utf8").decode("utf8", "ignore") def get_window_class(window: Window) -> str: @@ -92,7 +113,9 @@ def get_window_class(window: Window) -> str: try: window = window.query_tree().parent except Xlib.error.XError as e: - logger.warning(f"Unable to get window query_tree().parent, got a {type(e).__name__} exception from Xlib") + logger.warning( + f"Unable to get window query_tree().parent, got a {type(e).__name__} exception from Xlib" + ) return "unknown" if window: return get_window_class(window)