# Authors: see git history # # Copyright (c) 2010 Authors # Licensed under the GNU GPL version 3.0 or later. See the file LICENSE for details. import atexit # to save svg file on exit import time # to measure time of code block, use time.monotonic() instead of time.time() from datetime import datetime from contextlib import contextmanager # to measure time of with block from pathlib import Path # to work with paths as objects import inkex from lxml import etree # to create svg file from ..svg import line_strings_to_path from ..svg.tags import INKSCAPE_GROUPMODE, INKSCAPE_LABEL import logging logger = logging.getLogger("inkstitch.debug") # -------------------------------------------------------------------------------------------- # decorator to check if debugging is enabled # - if debug is not enabled then decorated function is not called def check_enabled(func): def decorated(self, *args, **kwargs): if self.enabled: return func(self, *args, **kwargs) return decorated # unwrapping = provision for functions as arguments # - if argument is callable then it is called and return value is used as argument # otherwise argument is returned as is def _unwrap(arg): if callable(arg): return arg() else: return arg # decorator to unwrap arguments if they are callable # eg: if argument is lambda function then it is called and return value is used as argument def unwrap_arguments(func): def decorated(self, *args, **kwargs): unwrapped_args = [_unwrap(arg) for arg in args] unwrapped_kwargs = {name: _unwrap(value) for name, value in kwargs.items()} return func(self, *unwrapped_args, **unwrapped_kwargs) return decorated class Debug(object): """Tools to help debug Ink/Stitch This class contains methods to log strings and SVG elements. Strings are logged to debug.log, and SVG elements are stored in debug.svg to aid in debugging stitch algorithms. All functionality is gated by self.enabled. If debugging is not enabled, then debug calls will consume very few resources. Any method argument can be a callable, in which case it is called and the return value is logged instead. This way one can log potentially expensive expressions by wrapping them in a lambda: debug.log(lambda: some_expensive_function(some_argument)) The lambda is only called if debugging is enabled. """ def __init__(self): self.enabled = False self.last_log_time = None self.current_layer = None self.group_stack = [] def enable(self): # self.log is activated by active logger # - enabled only if logger has any handler, # for "inkstitch.debug" simply comment out handlers in .toml file to disable for logger if len(logger.handlers) > 0: # count of handlers self.enabled = True self.log("Logging enabled") self.init_svg() else: logger.info("No handlers in logger, cannot enable logging and svg file creation") def init_svg(self): self.svg = etree.Element("svg", nsmap=inkex.NSS) atexit.register(self.save_svg) def save_svg(self): # check if there is a file handler and is type of logging.FileHandler if len(logger.handlers) > 0 and isinstance(logger.handlers[0], logging.FileHandler): filename = Path(logger.handlers[0].baseFilename) svg_file = filename.with_suffix(".svg") self.log(f"Writing svg file: {svg_file}") tree = etree.ElementTree(self.svg) tree.write(str(svg_file)) # lxml <5.0.0 does not support Path objects else: self.log("No file handler in logger cannot save svg file") @check_enabled @unwrap_arguments def add_layer(self, name="Debug"): layer = etree.Element("g", { INKSCAPE_GROUPMODE: "layer", INKSCAPE_LABEL: name, "style": "display: none" }) self.svg.append(layer) self.current_layer = layer @check_enabled @unwrap_arguments def open_group(self, name="Group"): group = etree.Element("g", { INKSCAPE_LABEL: name }) self.log_svg_element(group) self.group_stack.append(group) @check_enabled @unwrap_arguments def close_group(self): if self.group_stack: self.group_stack.pop() @check_enabled @unwrap_arguments def log(self, message, *args): if self.last_log_time: message = "(+%s) %s" % (datetime.now() - self.last_log_time, message) self.raw_log(message, *args) def raw_log(self, message, *args): now = datetime.now() self.last_log_time = now msg = message % args logger.info(msg) # decorator to measure time of function def time(self, func): def decorated(*args, **kwargs): if self.enabled: self.raw_log("entering %s()", func.__name__) start = time.monotonic() result = func(*args, **kwargs) if self.enabled: end = time.monotonic() self.raw_log("leaving %s(), duration = %s", func.__name__, round(end - start, 6)) return result return decorated @check_enabled @unwrap_arguments def log_svg_element(self, element): if self.current_layer is None: self.add_layer() if self.group_stack: self.group_stack[-1].append(element) else: self.current_layer.append(element) @check_enabled @unwrap_arguments def log_line_string(self, line_string, name=None, color=None): """Add a Shapely LineString to the SVG log.""" self.log_line_strings([line_string], name, color) @check_enabled @unwrap_arguments def log_line_strings(self, line_strings, name=None, color=None): path = line_strings_to_path(line_strings) path.set('style', str(inkex.Style({"stroke": color or "#000000", "stroke-width": "0.3", "fill": None}))) if name is not None: path.set(INKSCAPE_LABEL, name) self.log_svg_element(path) @check_enabled @unwrap_arguments def log_line(self, start, end, name="line", color=None): self.log_svg_element(etree.Element("path", { "d": "M%s,%s %s,%s" % (start + end), "style": str(inkex.Style({"stroke": color or "#000000", "stroke-width": "0.3", "fill": None})), INKSCAPE_LABEL: name })) @check_enabled @unwrap_arguments def log_point(self, point, name="point", color=None): self.log_svg_element(etree.Element("circle", { "cx": str(point.x), "cy": str(point.y), "r": "1", "style": str(inkex.Style({"fill": "#000000"})), })) @check_enabled @unwrap_arguments def log_graph(self, graph, name="Graph", color=None): d = "" for edge in graph.edges: d += "M%s,%s %s,%s" % (edge[0] + edge[1]) self.log_svg_element(etree.Element("path", { "d": d, "style": str(inkex.Style({"stroke": color or "#000000", "stroke-width": "0.3", "fill": None})), INKSCAPE_LABEL: name })) # decorator to measure time of with block @contextmanager def time_this(self, label="code block"): if self.enabled: start = time.monotonic() self.raw_log("begin %s", label) yield if self.enabled: self.raw_log("completed %s, duration = %s", label, time.monotonic() - start) # global debug object debug = Debug()