diff --git a/.git-hooks/pre-push b/.git-hooks/pre-push index 5b35a131a4..be0b250b79 100755 --- a/.git-hooks/pre-push +++ b/.git-hooks/pre-push @@ -5,6 +5,11 @@ # $ git config core.hooksPath .git-hooks # (in dir) to add hooks # $ git config --unset core.hooksPath # (in dir) to remove hooks +# nixos: skip modified screenshots.py +git checkout upstream/master -- py3status/screenshots.py +git add py3status/screenshots.py +git commit --amend --no-edit + if command -v hatch &>/dev/null; then hatch run all else diff --git a/docs/dev-guide/writing-modules.md b/docs/dev-guide/writing-modules.md index 53591b3376..2dc2654f2c 100644 --- a/docs/dev-guide/writing-modules.md +++ b/docs/dev-guide/writing-modules.md @@ -811,6 +811,49 @@ Loadavg 1.41 1.61 1.82 Loadavg 1.41 1.61 1.82 ^C ``` + +## Logging + +Modules are encouraged to use Python's standard +[`logging`](https://docs.python.org/3/library/logging.config.html?highlight=logging#logging-config-dictschema) +module for debugging. By default, logs will be written to +[`syslog`](https://docs.python.org/3/library/logging.config.html?highlight=logging#logging-config-dictschema) +with a minimum level of `INFO`. + +Several existing modules will write to logs, with varying levels of details. +Therefore, when debugging a specific module, it may be useful to show only the +one you're interested in. This can be done by using the `--log-config` flag to +pass a JSON file that configures logging. This file must be in the format +specified in +[`logging`'s configuration schema](https://docs.python.org/3/library/logging.config.html?highlight=logging#logging-config-dictschema). +For example, to show only logs from your module in a `DEBUG` level, while +keeping all others at `WARNING`, you can use: + +```json +{ + "version": 1, + "handlers": { + "file": { + "class": "logging.handlers.RotatingFileHandler", + "filename": "/tmp/py3status_log.log", + "maxBytes": 2048, + "formatter": "default" + } + }, + "formatters": { + "default": { + "validate": true, + "format":"%(asctime)s %(levelname)s %(module)s %(message)s", + "datefmt":"%Y-%m-%d %H:%M:%S" + } + }, + "loggers": { + "root": {"handlers": ["file"], "level": "WARNING"}, + "": {"level": "DEBUG"} + } +} +``` + ## Publishing custom modules on PyPI You can share your custom modules and make them available for py3status diff --git a/py3status/argparsers.py b/py3status/argparsers.py index 1b332460d2..dde4d7d523 100644 --- a/py3status/argparsers.py +++ b/py3status/argparsers.py @@ -82,12 +82,6 @@ def _format_action_invocation(self, action): metavar="FILE", type=Path, ) - parser.add_argument( - "-d", - "--debug", - action="store_true", - help="enable debug logging in syslog or log file if --log-file option is passed", - ) parser.add_argument( "-i", "--include", @@ -97,15 +91,6 @@ def _format_action_invocation(self, action): metavar="PATH", type=Path, ) - parser.add_argument( - "-l", - "--log-file", - action="store", - dest="log_file", - help="enable logging to FILE (this option is not set by default)", - metavar="FILE", - type=Path, - ) parser.add_argument( "-s", "--standalone", @@ -157,6 +142,36 @@ def _format_action_invocation(self, action): help="specify window manager i3 or sway", ) + logging_args = parser.add_argument_group() + logging_args.add_argument( + "-d", + "--debug", + action="store_true", + help="enable debug logging in syslog or log file if --log-file option is passed", + ) + logging_args.add_argument( + "-l", + "--log-file", + action="store", + dest="log_file", + help="enable logging to FILE (this option is not set by default)", + metavar="FILE", + type=Path, + ) + logging_args.add_argument( + "--log-config", + action="store", + dest="log_config", + help="path to a file that fully configures the 'logging' module. This " + "must contain a JSON dictionary in the format expected by " + "logging.config.dictConfig.", + metavar="FILE", + type=Path, + ) + + # deprecations + parser.add_argument("-n", "--interval", help=argparse.SUPPRESS) + # parse options, command, etc options = parser.parse_args() diff --git a/py3status/core.py b/py3status/core.py index befd7d7af7..6f83c201c7 100644 --- a/py3status/core.py +++ b/py3status/core.py @@ -1,11 +1,12 @@ +import logging +import logging.handlers import sys import time from collections import deque +from json import JSONDecodeError, load from pathlib import Path -from pprint import pformat from signal import SIGCONT, SIGTERM, SIGTSTP, SIGUSR1, Signals, signal from subprocess import Popen -from syslog import LOG_ERR, LOG_INFO, LOG_WARNING, syslog from threading import Event, Thread from traceback import extract_tb, format_stack, format_tb @@ -22,7 +23,11 @@ from py3status.profiling import profile from py3status.udev_monitor import UdevMonitor -LOG_LEVELS = {"error": LOG_ERR, "warning": LOG_WARNING, "info": LOG_INFO} +LOGGING_LEVELS = { + "error": logging.ERROR, + "warning": logging.WARNING, + "info": logging.INFO, +} DBUS_LEVELS = {"error": "critical", "warning": "normal", "info": "low"} @@ -40,6 +45,8 @@ ENTRY_POINT_NAME = "py3status" ENTRY_POINT_KEY = "entry_point" +_logger = logging.getLogger("core") + class Runner(Thread): """ @@ -515,13 +522,34 @@ def load_modules(self, modules_list, user_modules): # only handle modules with available methods if my_m.methods: self.modules[module] = my_m - elif self.config["debug"]: - self.log(f'ignoring module "{module}" (no methods found)') + _logger.debug('ignoring module "%s" (no methods found)', module) except Exception: err = sys.exc_info()[1] msg = f'Loading module "{module}" failed ({err}).' self.report_exception(msg, level="warning") + def _setup_logging(self): + """Set up the global logger.""" + root = logging.getLogger(name=None) + if self.config.get("debug"): + root.setLevel(logging.DEBUG) + else: + root.setLevel(logging.INFO) + + log_file = self.config.get("log_file") + if log_file: + handler = logging.FileHandler(log_file, encoding="utf8") + else: + handler = logging.handlers.SysLogHandler() + handler.setFormatter( + logging.Formatter( + fmt="%(asctime)s %(levelname)s %(module)s %(message)s", + datefmt="%Y-%m-%d %H:%M:%S", + style="%", + ) + ) + root.addHandler(handler) + def _log_gitversion(self): # A git repo is detected looking for the .git directory @@ -565,10 +593,52 @@ def _log_gitversion(self): self.log(f"git commit: {commit.hexsha[:7]} {commit.summary}") self.log(f"git clean: {not repo.is_dirty()!s}") + def _setup_logging(self): + """Set up the global logger.""" + log_config = self.config.get("log_config") + if log_config: + if self.config.get("debug"): + self.report_exception("--debug is invalid when --log-config is passed") + if self.config.get("log_file"): + self.report_exception("--log-file is invalid when --log-config is passed") + + with log_config.open() as f: + try: + config_dict = load(f, strict=False) + config_dict.setdefault("disable_existing_loggers", False) + logging.config.dictConfig(config_dict) + except JSONDecodeError as e: + self.report_exception(str(e)) + # Nothing else to do. All logging config is provided by the config + # dictionary. + return + + root = logging.getLogger(name=None) + if self.config.get("debug"): + root.setLevel(logging.DEBUG) + else: + root.setLevel(logging.INFO) + + log_file = self.config.get("log_file") + if log_file: + handler = logging.FileHandler(log_file, encoding="utf8") + else: + # https://stackoverflow.com/a/3969772/340862 + handler = logging.handlers.SysLogHandler(address="/dev/log") + handler.setFormatter( + logging.Formatter( + fmt="%(asctime)s %(levelname)s %(module)s %(message)s", + datefmt="%Y-%m-%d %H:%M:%S", + style="%", + ) + ) + root.addHandler(handler) + def setup(self): """ Setup py3status and spawn i3status/events/modules threads. """ + self._setup_logging() # log py3status and python versions self.log("=" * 8) @@ -580,8 +650,7 @@ def setup(self): self.log("window manager: {}".format(self.config["wm_name"])) - if self.config["debug"]: - self.log(f"py3status started with config {self.config}") + _logger.debug("py3status started with config %s", self.config) # read i3status.conf config_path = self.config["i3status_config_path"] @@ -631,10 +700,7 @@ def setup(self): i3s_mode = "mocked" break time.sleep(0.1) - if self.config["debug"]: - self.log( - "i3status thread {} with config {}".format(i3s_mode, self.config["py3_config"]) - ) + _logger.debug("i3status thread %s with config %s", i3s_mode, self.config["py3_config"]) # add i3status thread monitoring task if i3s_mode == "started": @@ -645,15 +711,13 @@ def setup(self): self.events_thread = Events(self) self.events_thread.daemon = True self.events_thread.start() - if self.config["debug"]: - self.log("events thread started") + _logger.debug("events thread started") # initialise the command server self.commands_thread = CommandServer(self) self.commands_thread.daemon = True self.commands_thread.start() - if self.config["debug"]: - self.log("commands thread started") + _logger.debug("commands thread started") # initialize the udev monitor (lazy) self.udev_monitor = UdevMonitor(self) @@ -696,8 +760,7 @@ def setup(self): # get a dict of all user provided modules self.log("modules include paths: {}".format(self.config["include_paths"])) user_modules = self.get_user_configured_modules() - if self.config["debug"]: - self.log(f"user_modules={user_modules}") + _logger.debug("user_modules=%s", user_modules) if self.py3_modules: # load and spawn i3status.conf configured modules threads @@ -807,8 +870,7 @@ def stop(self): try: self.lock.set() - if self.config["debug"]: - self.log("lock set, exiting") + _logger.debug("lock set, exiting") # run kill() method on all py3status modules for module in self.modules.values(): module.kill() @@ -839,12 +901,10 @@ def refresh_modules(self, module_string=None, exact=True): or (not exact and name.startswith(module_string)) ): if module["type"] == "py3status": - if self.config["debug"]: - self.log(f"refresh py3status module {name}") + _logger.debug("refresh py3status module %s", name) module["module"].force_update() else: - if self.config["debug"]: - self.log(f"refresh i3status module {name}") + _logger.debug("refresh i3status module %s", name) update_i3status = True if update_i3status: self.i3status_thread.refresh_i3status() @@ -918,29 +978,11 @@ def notify_update(self, update, urgent=False): def log(self, msg, level="info"): """ log this information to syslog or user provided logfile. + + This is soft-deprecated; prefer using the 'logging' module directly in + new code. """ - if not self.config.get("log_file"): - # If level was given as a str then convert to actual level - level = LOG_LEVELS.get(level, level) - syslog(level, f"{msg}") - else: - # Binary mode so fs encoding setting is not an issue - with self.config["log_file"].open("ab") as f: - log_time = time.strftime("%Y-%m-%d %H:%M:%S") - # nice formatting of data structures using pretty print - if isinstance(msg, (dict, list, set, tuple)): - msg = pformat(msg) - # if multiline then start the data output on a fresh line - # to aid readability. - if "\n" in msg: - msg = "\n" + msg - out = f"{log_time} {level.upper()} {msg}\n" - try: - # Encode unicode strings to bytes - f.write(out.encode("utf-8")) - except (AttributeError, UnicodeDecodeError): - # Write any byte strings straight to log - f.write(out) + _logger.log(LOGGING_LEVELS.get(level, logging.DEBUG), msg) def create_output_modules(self): """ diff --git a/py3status/modules/xrandr.py b/py3status/modules/xrandr.py index 7ba38a03b1..73065ce634 100644 --- a/py3status/modules/xrandr.py +++ b/py3status/modules/xrandr.py @@ -140,10 +140,13 @@ {'full_text': 'DP1'} """ +import logging from collections import OrderedDict, deque from itertools import combinations from time import sleep +_logger = logging.getLogger("xrandr") + class Py3status: """""" @@ -223,7 +226,7 @@ def _get_layout(self): else: continue except Exception as err: - self.py3.log(f'xrandr error="{err}"') + _logger.exception("xrandr error", err) else: layout[state][output] = {"infos": infos, "mode": mode, "state": state} @@ -307,7 +310,7 @@ def _choose_what_to_display(self, force_refresh=False): if force_refresh: self.displayed = self.available_combinations[0] else: - self.py3.log('xrandr error="displayed combination is not available"') + _logger.warning('xrandr error="displayed combination is not available"') def _center(self, s): """ @@ -343,7 +346,7 @@ def _apply(self, force=False): resolution = f"--mode {resolution}" if resolution else "--auto" rotation = getattr(self, f"{output}_rotate", "normal") if rotation not in ["inverted", "left", "normal", "right"]: - self.py3.log(f"configured rotation {rotation} is not valid") + _logger.warning("configured rotation %s is not valid", rotation) rotation = "normal" # if primary is True and not primary_added: @@ -365,7 +368,7 @@ def _apply(self, force=False): self.active_comb = combination self.active_layout = self.displayed self.active_mode = mode - self.py3.log(f'command "{cmd}" exit code {code}') + _logger.info('command "%s" exit code %s', cmd, code) if self.command: self.py3.command_run(self.command) @@ -395,7 +398,7 @@ def _apply_workspaces(self, combination, mode): cmd = '{} move workspace to output "{}"'.format(self.py3.get_wm_msg(), output) self.py3.command_run(cmd) # log this - self.py3.log(f"moved workspace {workspace} to output {output}") + _logger.info("moved workspace %s to output %s", workspace, output) def _fallback_to_available_output(self): """ @@ -494,7 +497,7 @@ def xrandr(self): # follow on change if not self._no_force_on_change and self.force_on_change and self._layout_changed(): - self.py3.log("detected change of monitor setup") + _logger.info("detected change of monitor setup") self._force_on_change() # this was a click event triggered update diff --git a/pyproject.toml b/pyproject.toml index 24da108b77..0ef9bab1e4 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -112,4 +112,4 @@ dependencies = [ "mkdocs-material>=9.4.5", "Pillow>=3.4.2", "fonttools==4.24.4", -] \ No newline at end of file +]