Skip to content

Commit

Permalink
Set up standard logging module
Browse files Browse the repository at this point in the history 
This has the advantage of overall less custom code; as well as support
for per-module configuration. This would enable a potential solution for
#1479, since in the future
it can allow per-module configuration of log levels.

I expect this to mainly help module creators, allowing them to enable
logging for only their module, while disabling all other messages. It
also is easier to use, since the `logging` module's interface is
generally simpler than `self.py3`.

Here, I've made the decision to keep the message format as close as
possible to the existing log messages.
  • Loading branch information
@rlerm @lasers
rlerm authored and lasers committed Feb 5, 2024
1 parent df2bac2 commit 318ccce
Show file tree
Hide file tree
Showing 4 changed files with 145 additions and 66 deletions.
43 changes: 43 additions & 0 deletions docs/dev-guide/writing-modules.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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"},
"<my_module>": {"level": "DEBUG"}
}
}
```

## Publishing custom modules on PyPI

You can share your custom modules and make them available for py3status
Expand Down
42 changes: 27 additions & 15 deletions py3status/argparsers.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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",
Expand All @@ -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",
Expand Down Expand Up @@ -157,6 +142,33 @@ 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,
)

# parse options, command, etc
options = parser.parse_args()

Expand Down
111 changes: 66 additions & 45 deletions py3status/core.py
View file
Original file line number Diff line number Diff line change
@@ -1,11 +1,13 @@
import logging
import logging.config
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

Expand All @@ -22,7 +24,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"}

Expand All @@ -40,6 +46,8 @@
ENTRY_POINT_NAME = "py3status"
ENTRY_POINT_KEY = "entry_point"

_logger = logging.getLogger("core")


class Runner(Thread):
"""
Expand Down Expand Up @@ -515,8 +523,7 @@ 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}).'
Expand Down Expand Up @@ -565,10 +572,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)
Expand All @@ -580,8 +629,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"]
Expand Down Expand Up @@ -631,10 +679,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":
Expand All @@ -645,15 +690,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)
Expand Down Expand Up @@ -696,8 +739,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
Expand Down Expand Up @@ -807,8 +849,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()
Expand Down Expand Up @@ -839,12 +880,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()
Expand Down Expand Up @@ -918,29 +957,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):
"""
Expand Down
15 changes: 9 additions & 6 deletions py3status/modules/xrandr.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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:
""""""
Expand Down Expand Up @@ -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}

Expand Down Expand Up @@ -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):
"""
Expand Down Expand Up @@ -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:
Expand All @@ -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)
Expand Down Expand Up @@ -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):
"""
Expand Down Expand Up @@ -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
Expand Down

0 comments on commit 318ccce

Please sign in to comment.