feat: Add logging and --debug flag

Fixes #122 and #133

keymap_drawer/__init__.py

@@ -0,0 +1,6 @@
+"""Parent module containing all keymap-drawer functionality."""
+
+import logging
+
+logger = logging.getLogger(__name__)
+logging.basicConfig(format="{name}: [{levelname}] {message}", style="{")

keymap_drawer/__main__.py

@@ -4,13 +4,15 @@
 ortho layout), print an SVG representing the keymap to standard output.
 """
 
+import logging
 import sys
 from argparse import ArgumentParser, FileType, Namespace
 from importlib.metadata import version
 from pathlib import Path
 
 import yaml
 
+from keymap_drawer import logger
 from keymap_drawer.config import Config
 from keymap_drawer.draw import KeymapDrawer
 from keymap_drawer.keymap import KeymapData
@@ -101,6 +103,7 @@ def main() -> None:
     """Parse the configuration and print SVG using KeymapDrawer."""
     parser = ArgumentParser(description=__doc__)
     parser.add_argument("-v", "--version", action="version", version=version("keymap-drawer"))
+    parser.add_argument("-d", "--debug", action="store_true")
     parser.add_argument(
         "-c",
         "--config",
@@ -227,6 +230,9 @@ def main() -> None:
 
     args = parser.parse_args()
 
+    if args.debug:
+        logger.setLevel(logging.DEBUG)
+
     config = Config.parse_obj(yaml.safe_load(args.config)) if args.config else Config()
 
     match args.command:

keymap_drawer/draw/glyph.py

@@ -3,6 +3,7 @@
 and drawing SVG glyphs.
 """
 
+import logging
 import re
 from concurrent.futures import ThreadPoolExecutor
 from functools import lru_cache, partial
@@ -18,6 +19,8 @@
 from keymap_drawer.config import DrawConfig
 from keymap_drawer.keymap import KeymapData, LayoutKey
 
+logger = logging.getLogger(__name__)
+
 FETCH_WORKERS = 8
 FETCH_TIMEOUT = 10
 N_RETRY = 5
@@ -54,6 +57,7 @@ def find_key_glyph_names(key: LayoutKey) -> set[str]:
 
         # get the ones defined in draw_config.glyphs
         self.name_to_svg = {name: glyph for name in names if (glyph := self.cfg.glyphs.get(name))}
+        logger.debug("found glyphs %s in draw_config.glyphs", list(self.name_to_svg))
         rest = names - set(self.name_to_svg)
 
         # try to fetch the rest using draw_config.glyph_urls
@@ -146,9 +150,11 @@ def _fetch_svg_url(name: str, url: str, use_local_cache: bool = False) -> str:
     """Get an SVG glyph definition from url, using the local cache for reading and writing if enabled."""
     cache_path = CACHE_GLYPHS_PATH / f"{name.replace('/', '@')}.svg"
     if use_local_cache and cache_path.is_file():
+        logger.debug('found glyph "%s" in local cache', name)
         with open(cache_path, "r", encoding="utf-8") as f:
             return f.read()
 
+    logger.debug('fetching glyph "%s" from %s', name, url)
     try:
         for _ in range(N_RETRY):
             try:
@@ -157,7 +163,7 @@ def _fetch_svg_url(name: str, url: str, use_local_cache: bool = False) -> str:
                     content = f.read().decode("utf-8")
                 break
             except TimeoutError:
-                pass
+                logger.warning("request timed out while trying to fetch SVG from %s", url)
         else:
             raise RuntimeError(f"Failed to fetch SVG in {N_RETRY} tries")
         if use_local_cache:

keymap_drawer/dts.py

@@ -8,6 +8,7 @@
 Node overrides via node references are supported in a limited capacity.
 """
 
+import logging
 import re
 from io import StringIO
 from itertools import chain
@@ -16,6 +17,8 @@
 from pcpp.preprocessor import Action, OutputDirective, Preprocessor  # type: ignore
 from tree_sitter import Language, Node, Parser, Tree
 
+logger = logging.getLogger(__name__)
+
 TS_LANG = Language(ts.language())
 
 
@@ -197,12 +200,19 @@ def _find_chosen_ts_nodes(tree: Tree) -> list[Node]:
 
     @staticmethod
     def _preprocess(in_str: str, file_name: str | None = None, additional_includes: list[str] | None = None) -> str:
+        # ignore__has_include(...) in preprocessor ifs because pcpp can't handle them
+        in_str = re.sub(r"__has_include\(.*?\)", "0", in_str)
+
         def include_handler(*args):  # type: ignore
             raise OutputDirective(Action.IgnoreAndPassThrough)
 
+        def on_error_handler(file, line, msg):  # type: ignore
+            logger.warning("preprocessor: %s:%d error: %s", file, line, msg)
+
         preprocessor = Preprocessor()
         preprocessor.line_directive = None
         preprocessor.on_include_not_found = include_handler
+        preprocessor.on_error = on_error_handler
         preprocessor.assume_encoding = "utf-8"
         for path in additional_includes or []:
             preprocessor.add_path(path)

keymap_drawer/parse/parse.py

@@ -3,6 +3,7 @@
 Do not use directly, use QmkJsonParser or ZmkKeymapParser instead.
 """
 
+import logging
 import re
 from abc import ABC
 from io import TextIOWrapper
@@ -11,6 +12,8 @@
 from keymap_drawer.config import ParseConfig
 from keymap_drawer.keymap import KeymapData, LayoutKey
 
+logger = logging.getLogger(__name__)
+
 
 class ParseError(Exception):
     """Error type for exceptions that happen during keymap parsing."""
@@ -35,7 +38,7 @@ def __init__(
         self.layer_legends: list[str] | None = None
         self.virtual_layers = virtual_layers if virtual_layers is not None else []
         if layer_names is not None:
-            self.update_layer_legends()
+            self._update_layer_legends()
         self.base_keymap = base_keymap
         self.layer_activated_from: dict[int, set[tuple[int, bool]]] = {}  # layer to key positions + alternate flags
         self.conditional_layers: dict[int, list[int]] = {}  # then-layer to if-layers mapping
@@ -85,12 +88,25 @@ def format_modified_keys(self, key_str: str, modifiers: list[str]) -> str:
                 fns_str = self.cfg.modifier_fn_map.mod_combiner.format(mod_1=fns_str, mod_2=fn_map[mod])
         return self.cfg.modifier_fn_map.keycode_combiner.format(mods=fns_str, key=key_str)
 
-    def update_layer_legends(self) -> None:
+    def update_layer_names(self, names: list[str]) -> None:
+        """Update layer names to given list, then update legends."""
+        assert self.layer_names is None  # make sure they weren't preset
+        self.layer_names = names
+        logger.debug("updated layer names: %s", self.layer_names)
+
+        self._update_layer_legends()
+
+    def _update_layer_legends(self) -> None:
         """Create layer legends from layer_legend_map in parse_config and inferred/provided layer names."""
         assert self.layer_names is not None
+        for name in self.cfg.layer_legend_map:
+            if name not in self.layer_names + self.virtual_layers:
+                logger.warning('layer name "%s" in parse_config.layer_legend_map not found in keymap layers', name)
+
         self.layer_legends = [
             self.cfg.layer_legend_map.get(name, name) for name in self.layer_names + self.virtual_layers
         ]
+        logger.debug("updated layer legends: %s", self.layer_legends)
 
     def update_layer_activated_from(
         self, from_layers: Sequence[int], to_layer: int, key_positions: Sequence[int]
@@ -137,6 +153,8 @@ def add_held_keys(self, layers: dict[str, list[LayoutKey]]) -> dict[str, list[La
         for then_layer, if_layers in sorted(self.conditional_layers.items()):
             self.update_layer_activated_from(if_layers, then_layer, [])
 
+        logger.debug("layers activated from key positions: %s", self.layer_activated_from)
+
         # assign held keys
         for layer_index, activating_keys in self.layer_activated_from.items():
             for key_idx, is_alternate in activating_keys:
@@ -165,6 +183,7 @@ def _parse(self, in_str: str, file_name: str | None = None) -> tuple[dict, Keyma
     def parse(self, in_buf: TextIOWrapper) -> dict:
         """Wrapper to call parser on a file handle and do post-processing after firmware-specific parsing."""
         layout, keymap_data = self._parse(in_buf.read(), in_buf.name)
+        logger.debug("inferred physical layout: %s", layout)
 
         if self.base_keymap is not None:
             keymap_data.rebase(self.base_keymap)

keymap_drawer/parse/qmk.py

@@ -146,8 +146,7 @@ def _parse(self, in_str: str, file_name: str | None = None) -> tuple[dict, Keyma
 
         num_layers = len(raw["layers"])
         if self.layer_names is None:
-            self.layer_names = [f"L{ind}" for ind in range(num_layers)]
-            self.update_layer_legends()
+            self.update_layer_names([f"L{ind}" for ind in range(num_layers)])
         else:  # user-provided layer names
             assert (
                 l_u := len(self.layer_names)
@@ -156,6 +155,7 @@ def _parse(self, in_str: str, file_name: str | None = None) -> tuple[dict, Keyma
             )
 
         layers: dict[str, list[LayoutKey]] = {}
+        assert self.layer_names is not None
         for layer_ind, layer in enumerate(raw["layers"]):
             layer_name = self.layer_names[layer_ind]
             layers[layer_name] = []

keymap_drawer/parse/zmk.py

@@ -1,5 +1,6 @@
 """Module containing class to parse devicetree format ZMK keymaps."""
 
+import logging
 import re
 from functools import cache
 from itertools import chain
@@ -13,6 +14,8 @@
 from keymap_drawer.keymap import ComboSpec, KeymapData, LayoutKey
 from keymap_drawer.parse.parse import KeymapParser, ParseError
 
+logger = logging.getLogger(__name__)
+
 ZMK_LAYOUTS_PATH = Path(__file__).parent.parent.parent / "resources" / "zmk_keyboard_layouts.yaml"
 ZMK_DEFINES_PATH = Path(__file__).parent.parent.parent / "resources" / "zmk_defines.h"
 
@@ -60,6 +63,7 @@ def _update_raw_binding_map(self, dts: DeviceTree) -> None:
             if new != old:
                 self.raw_binding_map[new] = self.raw_binding_map[old]
                 del self.raw_binding_map[old]
+        logger.debug("updated raw_binding_map: %s", self.raw_binding_map)
 
     def _str_to_key(  # pylint: disable=too-many-return-statements,too-many-locals
         self, binding: str, current_layer: int | None, key_positions: Sequence[int], no_shifted: bool = False
@@ -150,8 +154,11 @@ def get_behavior_bindings(compatible_value: str, n_bindings: int) -> dict[str, l
             return out
 
         self.hold_taps |= get_behavior_bindings("zmk,behavior-hold-tap", 2)
+        logger.debug("found hold-tap bindings: %s", self.hold_taps)
         self.mod_morphs |= get_behavior_bindings("zmk,behavior-mod-morph", 2)
+        logger.debug("found mod-morph bindings: %s", self.mod_morphs)
         self.sticky_keys |= get_behavior_bindings("zmk,behavior-sticky-key", 1)
+        logger.debug("found sticky keys bindings: %s", self.sticky_keys)
 
     def _update_conditional_layers(self, dts: DeviceTree) -> None:
         cl_parents = dts.get_compatible_nodes("zmk,conditional-layers")
@@ -162,6 +169,7 @@ def _update_conditional_layers(self, dts: DeviceTree) -> None:
             if not (if_layers := node.get_array("if-layers")):
                 raise ParseError(f'Could not parse `if-layers` for conditional layer node "{node.name}"')
             self.conditional_layers[int(then_layer_val[0])] = [int(val) for val in if_layers]
+        logger.debug("found conditional layers: %s", self.conditional_layers)
 
     def _get_layers(self, dts: DeviceTree) -> dict[str, list[LayoutKey]]:
         if not (layer_parents := dts.get_compatible_nodes("zmk,keymap")):
@@ -171,16 +179,18 @@ def _get_layers(self, dts: DeviceTree) -> dict[str, list[LayoutKey]]:
             node for parent in layer_parents for node in parent.children if node.get_string("status") != "reserved"
         ]
         if self.layer_names is None:
-            self.layer_names = [
-                node.get_string("label|display-name") or node.name.removeprefix("layer_").removesuffix("_layer")
-                for node in layer_nodes
-            ]
-            self.update_layer_legends()
+            self.update_layer_names(
+                [
+                    node.get_string("label|display-name") or node.name.removeprefix("layer_").removesuffix("_layer")
+                    for node in layer_nodes
+                ]
+            )
         else:
             assert (l_u := len(self.layer_names)) == (
                 l_p := len(layer_nodes)
             ), f"Length of provided layer name list ({l_u}) does not match the number of parsed layers ({l_p})"
 
+        assert self.layer_names is not None
         layers: dict[str, list[LayoutKey]] = {}
         for layer_ind, node in enumerate(layer_nodes):
             layer_name = self.layer_names[layer_ind]

keymap_drawer/physical_layout.py

@@ -5,6 +5,7 @@
 """
 
 import json
+import logging
 import re
 from dataclasses import dataclass
 from functools import cache, cached_property, lru_cache
@@ -22,6 +23,8 @@
 from keymap_drawer.config import Config, ParseConfig
 from keymap_drawer.dts import DeviceTree
 
+logger = logging.getLogger(__name__)
+
 QMK_LAYOUTS_PATH = Path(__file__).parent.parent / "resources" / "qmk_layouts"
 QMK_METADATA_URL = "https://keyboards.qmk.fm/v1/keyboards/{keyboard}/info.json"
 QMK_DEFAULT_LAYOUTS_URL = "https://raw.githubusercontent.com/qmk/qmk_firmware/master/layouts/default/{layout}/info.json"
@@ -205,7 +208,8 @@ def layout_factory(
     draw_cfg, parse_cfg = config.draw_config, config.parse_config
 
     if qmk_layout is not None:
-        assert layout_name is None, '"qmk_layout" is deprecated and cannot be used with "layout_name", use the latter'
+        logger.warning('"qmk_layout" is deprecated, please use "layout_name" instead')
+        assert layout_name is None, '"qmk_layout" cannot be used with "layout_name", use the latter'
         layout_name = qmk_layout
 
     if qmk_keyboard or qmk_info_json:
@@ -487,15 +491,18 @@ def _get_qmk_info(qmk_keyboard: str, use_local_cache: bool = False):
             return json.load(f)
 
     if use_local_cache and cache_path.is_file():
+        logger.debug("found keyboard %s in local cache", qmk_keyboard)
         with open(cache_path, "rb") as f:
             return json.load(f)
 
     try:
         if qmk_keyboard.startswith("generic/"):
+            logger.debug("getting generic layout %s from QMK default layouts", qmk_keyboard)
             with urlopen(QMK_DEFAULT_LAYOUTS_URL.format(layout=qmk_keyboard[len("generic/") :])) as f:
                 info = json.load(f)
         else:
             with urlopen(QMK_METADATA_URL.format(keyboard=qmk_keyboard)) as f:
+                logger.debug("getting QMK keyboard layout %s from QMK metadata API", qmk_keyboard)
                 info = json.load(f)["keyboards"][qmk_keyboard]
         if use_local_cache:
             cache_path.parent.mkdir(parents=True, exist_ok=True)
@@ -537,6 +544,7 @@ def parse_binding_params(bindings):
     defined_layouts: dict[str | None, list[str] | None]
     if nodes := dts.get_compatible_nodes("zmk,physical-layout"):
         defined_layouts = {node.label or node.name: node.get_phandle_array("keys") for node in nodes}
+        logger.debug("found these physical layouts in DTS: %s", defined_layouts)
     else:
         raise ValueError('No `compatible = "zmk,physical-layout"` nodes found in DTS layout')