From 6bf31a67ac0bf46c2c2f5d2ef9ee997da6770a96 Mon Sep 17 00:00:00 2001 From: karnigen Date: Mon, 12 Feb 2024 22:44:46 +0100 Subject: [PATCH 01/12] update config files --- .gitignore | 3 +++ DEBUG_template.ini | 13 +++++++++++++ LOGGING_template.toml | 38 ++++++++++++++++++++++++++++++++++++++ 3 files changed, 54 insertions(+) create mode 100644 LOGGING_template.toml diff --git a/.gitignore b/.gitignore index 7a4657101..616be3269 100644 --- a/.gitignore +++ b/.gitignore @@ -6,6 +6,7 @@ __pycache__ *.zip *.tar.gz *.po +*.log dist/ build/ locales/ @@ -23,6 +24,8 @@ electron/yarn.lock # debug and profile files /DEBUG.ini +/LOGGING.toml +/LOGGING[0-9]*.toml /debug* /.debug* # old debug files diff --git a/DEBUG_template.ini b/DEBUG_template.ini index 41d067966..38871357f 100644 --- a/DEBUG_template.ini +++ b/DEBUG_template.ini @@ -2,7 +2,20 @@ ;;; use the pip installed version of inkex.py, default: True ; prefer_pip_inkex = False +[LOGGING] +;;; logging configuration file, default: none - use implicit DEBUG logging to inkstitch.log +;;; we may have multiple configurations: LOGGING.toml, LOGGING1.toml, LOGGING2.toml, etc. +; log_config_file = LOGGING.toml + +;;; disable globally logging: default: False - using logging.disable() +;;; reenable logging.disable(0) +; disable_logging = True + + [DEBUG] +;;; simulate frozen mode, overwrite running_as_frozen in inkstitch.py, default: False +; force_frozen = True + ;;; select one active debug_type, default: none ; debug_type = vscode ; debug_type = pycharm diff --git a/LOGGING_template.toml b/LOGGING_template.toml new file mode 100644 index 000000000..85eece945 --- /dev/null +++ b/LOGGING_template.toml @@ -0,0 +1,38 @@ +# logging/warning template for inkstitch +# format: toml +# enable config file in DEBUG.ini: log_config_file + +# warnings.simplefilter(action), default: "default" +# - possible values: "error", "ignore", "always", "default", "module", "once" +warnings_action = "default" + +# logging.captureWarnings() default: true +# - possible values: true, false +warnings_capture = true + +# mandatory, must be an integer and 1 +version = 1 + +# false - to keep existing loggers, not specified here +# true - to disable all loggers not specified here +disable_existing_loggers = false + +[filters] + +[formatters.simple] + format = "%(asctime)s [%(levelname)s]: %(filename)s.%(funcName)s: %(message)s" + +[handlers.file] + class = "logging.FileHandler" + formatter = "simple" + filename = "%(SCRIPTDIR)s/inkstitch.log" + mode = "w" + +[loggers.inkstitch] + level = "DEBUG" + handlers = [ "file",] + propagate = false + +[loggers.root] + level = "DEBUG" + handlers = [ "file",] From 42c03aa80f9a7a234f029fa1d800f9f62fac9d17 Mon Sep 17 00:00:00 2001 From: karnigen Date: Mon, 12 Feb 2024 23:17:37 +0100 Subject: [PATCH 02/12] central logging config from file --- inkstitch.py | 89 ++++++++++----- lib/api/server.py | 6 -- lib/debug_logging.py | 197 ++++++++++++++++++++++++++++++++++ lib/debug_utils.py | 4 +- lib/extensions/break_apart.py | 6 -- lib/extensions/print_pdf.py | 6 -- 6 files changed, 259 insertions(+), 49 deletions(-) create mode 100644 lib/debug_logging.py diff --git a/inkstitch.py b/inkstitch.py index dde884d7f..6697e107c 100644 --- a/inkstitch.py +++ b/inkstitch.py @@ -6,15 +6,30 @@ import os import sys from pathlib import Path # to work with paths as objects -import configparser # to read DEBUG.ini from argparse import ArgumentParser # to parse arguments and remove --extension +import configparser # to read DEBUG.ini +import toml # to read logging configuration from toml file +import warnings +import logging +import logging.config + import lib.debug_utils as debug_utils +import lib.debug_logging as debug_logging SCRIPTDIR = Path(__file__).parent.absolute() +logger = logging.getLogger("inkstitch") # create module logger with name 'inkstitch' + +ini = configparser.ConfigParser() +ini.read(SCRIPTDIR / "DEBUG.ini") # read DEBUG.ini file if exists, otherwise use default values in ini object running_as_frozen = getattr(sys, 'frozen', None) is not None # check if running from pyinstaller bundle +if not running_as_frozen: # override running_as_frozen from DEBUG.ini - for testing + if ini.getboolean("DEBUG", "force_frozen", fallback=False): + running_as_frozen = True + + if len(sys.argv) < 2: # no arguments - prevent accidentally running this script msg = "No arguments given, exiting!" # without gettext localization see _() @@ -31,8 +46,46 @@ if len(sys.argv) < 2: print(msg) exit(1) -ini = configparser.ConfigParser() -ini.read(SCRIPTDIR / "DEBUG.ini") # read DEBUG.ini file if exists +# Configure logging: +# in release mode normally we want to ignore all warnings and logging, but we can enable it by setting environment variables +# - INKSTITCH_LOGLEVEL - logging level: +# 'DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL' +# - PYTHONWARNINGS, -W - warnings action controlled by python +# actions: 'error', 'ignore', 'always', 'default', 'module', 'once' +if running_as_frozen: # in release mode + loglevel = os.environ.get('INKSTITCH_LOGLEVEL') # read log level from environment variable or None + docpath = os.environ.get('DOCUMENT_PATH') # read document path from environment variable (set by inkscape) or None + + if docpath is not None and loglevel is not None and loglevel.upper() in ['DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL']: + # enable logging-warning and redirect output to input_svg.inkstitch.log + logfilename = Path(docpath).with_suffix('.inkstitch.log') # log file is created in document path + loglevel = loglevel.upper() + + logging.config.dictConfig(debug_logging.frozen_config) # configure root logger from dict - using loglevel, logfilename + logging.captureWarnings(True) # capture all warnings to log file with level WARNING + logger.info(f"Running as frozen: {running_as_frozen}") + else: + logging.disable() # globally disable all logging of all loggers + warnings.simplefilter('ignore') # ignore all warnings + +else: + # in development mode we want to use configuration from some LOGGING.toml file + logging_config_file = ini.get("LOGGING", "log_config_file", fallback=None) + if logging_config_file is not None: + logging_config_file = Path(logging_config_file) + if logging_config_file.exists(): + with open(logging_config_file, "r") as f: + development_config = toml.load(f) + else: + raise FileNotFoundError(f"{logging_config_file} file not found") + else: # if LOGGING.toml file does not exist, use default logging configuration + loglevel = 'DEBUG' # set log level to DEBUG + logfilename = SCRIPTDIR / "inkstitch.log" # log file is created in current directory + development_config = debug_logging.development_config + + debug_logging.configure_logging(development_config, ini, SCRIPTDIR) # initialize logging configuration + logger.info("Running in development mode") + logger.info(f"Using logging configuration from file: {logging_config_file}") # check if running from inkscape, given by environment variable if os.environ.get('INKSTITCH_OFFLINE_SCRIPT', '').lower() in ['true', '1', 'yes', 'y']: @@ -48,9 +101,9 @@ if not running_as_frozen: # debugging/profiling only in development mode # specify debugger type # but if script was already started from debugger then don't read debug type from ini file or cmd line if not debug_active: - debug_type = debug_utils.resole_debug_type(ini) # read debug type from ini file or cmd line + debug_type = debug_utils.resolve_debug_type(ini) # read debug type from ini file or cmd line - profile_type = debug_utils.resole_profile_type(ini) # read profile type from ini file or cmd line + profile_type = debug_utils.resolve_profile_type(ini) # read profile type from ini file or cmd line if running_from_inkscape: # process creation of the Bash script - should be done before sys.path is modified, see below in prefere_pip_inkex @@ -75,27 +128,8 @@ if debug_type != 'none': # check if debugger is really activated debug_active = bool((gettrace := getattr(sys, 'gettrace')) and gettrace()) -# warnings are used by some modules, we want to ignore them all in release -# - see warnings.warn() -if running_as_frozen or not debug_active: - import warnings - warnings.filterwarnings('ignore') - -# TODO - check if this is still needed for shapely, apparently shapely now uses only exceptions instead of io. -# all logs were removed from version 2.0.0 and above -# ---- plan to remove this in future ---- -# import logging # to set logger for shapely -# from io import StringIO # to store shapely errors -# set logger for shapely - for old versions of shapely -# logger = logging.getLogger('shapely.geos') # attach logger of shapely -# logger.setLevel(logging.DEBUG) -# shapely_errors = StringIO() # in memory file to store shapely errors -# ch = logging.StreamHandler(shapely_errors) -# ch.setLevel(logging.DEBUG) -# formatter = logging.Formatter('%(name)s - %(levelname)s - %(message)s') -# ch.setFormatter(formatter) -# logger.addHandler(ch) -# ---- plan to remove this in future ---- +# log startup info +debug_logging.startup_info(logger, SCRIPTDIR, running_as_frozen, running_from_inkscape, debug_active, debug_type, profiler_type) # pop '--extension' from arguments and generate extension class name from extension name # example: --extension=params will instantiate Params() class from lib.extensions. @@ -151,7 +185,4 @@ else: # if not debug nor profile mode finally: restore_stderr() - # if shapely_errors.tell(): # see above plan to remove this in future for shapely - # errormsg(shapely_errors.getvalue()) - sys.exit(0) diff --git a/lib/api/server.py b/lib/api/server.py index 5625d77de..6428ce694 100644 --- a/lib/api/server.py +++ b/lib/api/server.py @@ -4,7 +4,6 @@ # Licensed under the GNU GPL version 3.0 or later. See the file LICENSE for details. import errno -import logging import socket import sys import time @@ -66,9 +65,6 @@ class APIServer(Thread): self.flask_server.shutdown() self.server_thread.join() - def disable_logging(self): - logging.getLogger('werkzeug').setLevel(logging.ERROR) - # https://github.com/aluo-x/Learning_Neural_Acoustic_Fields/blob/master/train.py # https://github.com/pytorch/pytorch/issues/71029 def find_free_port(self): @@ -77,8 +73,6 @@ class APIServer(Thread): return s.getsockname()[1] def run(self): - self.disable_logging() - self.host = "127.0.0.1" self.port = self.find_free_port() self.flask_server = make_server(self.host, self.port, self.app) diff --git a/lib/debug_logging.py b/lib/debug_logging.py new file mode 100644 index 000000000..f94e753e6 --- /dev/null +++ b/lib/debug_logging.py @@ -0,0 +1,197 @@ +# Authors: see git history +# +# Copyright (c) 2010 Authors +# Licensed under the GNU GPL version 3.0 or later. See the file LICENSE for details. + +# basic info for inkstitch logging: +# --------------------------------- +# some idea can be found in: Modern Python logging - https://www.youtube.com/watch?v=9L77QExPmI0 +# +# logging vs warnings (ChatGPT) +# ----------------------------- +# warnings - a built-in mechanism for alerting developers to potential issues or deprecated features within their code. +# logging - to track events, errors, and other information relevant to the program's operation. +# Developers typically use logging to understand how their program behaves during execution, diagnose issues, +# and monitor performance. +# +# Inkstitch is application for Inkscape, so it is not a library, so we use logging for all messages. +# + +# root logger: +# ------------ +# - The primary logger orchestrates all other loggers through logging.xxx() calls. +# - It should only be utilized at the application's highest level to manage the logging of all loggers. +# - It can easily disable all loggers by invoking logging.disable() and channel all warnings to logging +# by setting logging.captureWarnings(True) with the level WARNING. +# - The configuration of all loggers can be achieved via a file, and logging.config.dictConfig(logging_dict). + + +# module logger: +# -------------- +# - Instantiate the logger by invoking logger=getLogger(name). +# Avoid using __name__ as the name, as it generates numerous loggers per application. +# The logger name persists globally throughout the application. +# - Avoid configuring the module logger within the module itself; +# instead, utilize the top-level application configuration with logging.config. +# This allows users of the application to customize it according to their requirements. + +# example of module logger: +# ------------------------- +# import logging +# logger = logging.getLogger('inkstitch') # create module logger with name 'inkstitch', but configure it at top level of app +# ... +# logger.debug('debug message') # example of using module logger +# ... + +# top level of the application: +# ---------------------------- +# - configure root and other loggers +# - best practice is to configure from a file: eg logging.config.fileConfig('logging.conf') +# - consider toml format for logging configuration (json, yaml, xml, dict are also possible) +# + +# list of loggers in inkstitch (not complete): +# ------------------------------------------- +# - root - main logger that controls all other loggers +# - inkstitch - suggested name for inkstitch +# - inkstitch.xyz - suggested name for inkstitch submodule xyz if needed +# +# third-party loggers: +# -------------------- +# - werkzeug - is used by flask +# - shapely.geos - was used by shapely but currently replaced by exceptions and warnings +# + +# -------------------------------------------------------------------------------------------- + +import logging +import warnings + +logger = logging.getLogger('inkstitch') + +# example of logger configuration for release mode: +# ------------------------------------------------ +# - logger suitable for release mode, where we assume that the directory of the input SVG file allows writing the log file. +# - this config redirect all loggers to file svg_file.inkstitch.log to directory of svg file +# - set loglevel and logfilename in inkstitch.py before calling logging.config.dictConfig(frozen_config) +frozen_config = { + "version": 1, # mandatory key and value (int) is 1 + "disable_existing_loggers": False, # false enable all loggers not defined here, true disable + "filters": {}, # no filters + "formatters": { + "simple": { # formatter name (https://docs.python.org/3/library/logging.html#logging.LogRecord) + "format": '%(asctime)s [%(levelname)s]: %(filename)s.%(funcName)s: %(message)s' # format string + } + }, + "handlers": { + "file": { + "class": "logging.FileHandler", # type - file output + "formatter": "simple", # use formatter 'simple' for handler 'file' + "filename": "ext://__main__.logfilename", # access variable logfilename + "mode": "w" # create new file + } + }, + "loggers": { + "root": { # top level logger + "level": "ext://__main__.loglevel", # access variable loglevel + "handlers": ["file"], # use handler 'file' for logger + } + }, +} + +# example of implicit developer logger configuration: +# --------------------------------------------------- +# - configured two loggers: root and inkstitch loggers +# - output is redirected to file 'logfilename' in the directory of inkstitch.py +# - this configuration uses only one log level 'loglevel for both the root and inkstitch loggers. +# - set loglevel and logfilename in inkstitch.py before calling logging.config.dictConfig(development_config) +development_config = { + "warnings_action": "default", # dafault action for warnings + "warnings_capture": True, # capture warnings to log file with level WARNING + + "version": 1, # mandatory key and value (int) is 1 + "disable_existing_loggers": False, # false enable all loggers not defined here, true disable + "filters": {}, # no filters + "formatters": { + "simple": { # formatter name (https://docs.python.org/3/library/logging.html#logging.LogRecord) + "format": '%(asctime)s [%(levelname)s]: %(filename)s.%(funcName)s: %(message)s' # format string + } + }, + "handlers": { + "file": { + "class": "logging.FileHandler", # type - file output + "formatter": "simple", # use formatter 'simple' for handler 'file' + "filename": "ext://__main__.logfilename", # ext: --> access variable logfilename + "mode": "w" # create new file + }, + }, + "loggers": { # configure loggers + "inkstitch": { # specific logger to inkstitch application + "level": "ext://__main__.loglevel", # ext: --> access variable loglevel + "handlers": ["file"], # use handler 'file' for logger + "propagate": False, # don't propagate to root logger - otherwise all will be logged twice + }, + "root": { # top level logger + "level": "ext://__main__.loglevel", # ext: --> access variable loglevel + "handlers": ["file"], # use handler 'file' for logger + } + }, +} + + +# -------------------------------------------------------------------------------------------- +# configure logging from dictionary: +# - capture all warnings to log file with level WARNING - depends on warnings_capture +# - set action for warnings: 'error', 'ignore', 'always', 'default', 'module', 'once' - depends on warnings_action +def configure_logging(config, ini, SCRIPTDIR): + + # replace %(SCRIPTDIR)s -> script path in filenames + config = evaluate_filenames(config, {'SCRIPTDIR': SCRIPTDIR}) + + logging.config.dictConfig(config) # configure loggers from dict - using loglevel, logfilename + + warnings_capture = config.get('warnings_capture', True) + logging.captureWarnings(warnings_capture) # capture warnings to log file with level WARNING + warnings_action = config.get('warnings_action', 'default').lower() + warnings.simplefilter(warnings_action) # set action for warnings: 'error', 'ignore', 'always', ... + disable_logging = ini.getboolean("LOGGING", "disable_logging", fallback=False) + if disable_logging: + logger.warning("Logging is disabled by configuration in ini file.") + logging.disable() # globally disable all logging of all loggers + + +# Evaluate filenames in logging configuration using myvars dictionary: +# "handlers": { +# "file": { +# "class": "logging.FileHandler", +# "filename": "%(SCRIPTDIR)s/xxx.log", # replace %(SCRIPTDIR)s -> script path +# } +# } +# config - logging configuration +# myvars - dictionary with variables +# returns: logging configuration with evaluated filenames +def evaluate_filenames(config, myvars): + import copy + cfg = copy.deepcopy(config) + for k, v in cfg.get('handlers', {}).items(): + if 'filename' in v: + cfg['handlers'][k]['filename'] = v['filename'] % myvars + return cfg + + +def startup_info(logger, SCRIPTDIR, running_as_frozen, running_from_inkscape, debug_active, debug_type, profiler_type): + logger.info(f"Running as frozen: {running_as_frozen}") + logger.info(f"Running from inkscape: {running_from_inkscape}") + logger.info(f"Debugger active: {debug_active}") + logger.info(f"Debugger type: {debug_type}") + logger.info(f"Profiler type: {profiler_type}") + logger.info(f"Using logging configuration from file: {SCRIPTDIR / 'LOGGING.toml'}") + + # log Python version, platform, command line arguments, sys.path + import sys + import platform + + logger.info(f"Python version: {sys.version}") + logger.info(f"Platform: {platform.platform()}") + logger.info(f"Command line arguments: {sys.argv}") + logger.info(f"sys.path: {sys.path}") diff --git a/lib/debug_utils.py b/lib/debug_utils.py index ef8b364d3..c680e9234 100644 --- a/lib/debug_utils.py +++ b/lib/debug_utils.py @@ -147,7 +147,7 @@ def reorder_sys_path(): # ----------------------------------------------------------------------------- # try to resolve debugger type from ini file or cmd line of bash -def resole_debug_type(ini: configparser.ConfigParser): +def resolve_debug_type(ini: configparser.ConfigParser): # enable/disable debugger from bash: -d if os.environ.get('INKSTITCH_DEBUG_ENABLE', '').lower() in ['true', '1', 'yes', 'y']: debug_enable = True @@ -166,7 +166,7 @@ def resole_debug_type(ini: configparser.ConfigParser): # try to resolve profiler type from ini file or cmd line of bash -def resole_profile_type(ini: configparser.ConfigParser): +def resolve_profile_type(ini: configparser.ConfigParser): # enable/disable profiling from bash: -p if os.environ.get('INKSTITCH_PROFILE_ENABLE', '').lower() in ['true', '1', 'yes', 'y']: profile_enable = True diff --git a/lib/extensions/break_apart.py b/lib/extensions/break_apart.py index 581e49bcb..b5104dc74 100644 --- a/lib/extensions/break_apart.py +++ b/lib/extensions/break_apart.py @@ -3,7 +3,6 @@ # Copyright (c) 2010 Authors # Licensed under the GNU GPL version 3.0 or later. See the file LICENSE for details. -import logging from copy import copy import inkex @@ -92,12 +91,7 @@ class BreakApart(InkstitchExtension): return polygons def geom_is_valid(self, geom): - # Don't complain about invalid shapes, we just want to know - logger = logging.getLogger('shapely.geos') - level = logger.level - logger.setLevel(logging.CRITICAL) valid = geom.is_valid - logger.setLevel(level) return valid def ensure_minimum_size(self, polygons, size): diff --git a/lib/extensions/print_pdf.py b/lib/extensions/print_pdf.py index c3c14e489..9072b2432 100644 --- a/lib/extensions/print_pdf.py +++ b/lib/extensions/print_pdf.py @@ -4,7 +4,6 @@ # Licensed under the GNU GPL version 3.0 or later. See the file LICENSE for details. import json -import logging import os import socket import sys @@ -159,9 +158,6 @@ class PrintPreviewServer(Thread): self.flask_server.shutdown() self.server_thread.join() - def disable_logging(self): - logging.getLogger('werkzeug').setLevel(logging.ERROR) - # https://github.com/aluo-x/Learning_Neural_Acoustic_Fields/blob/master/train.py # https://github.com/pytorch/pytorch/issues/71029 def find_free_port(self): @@ -170,8 +166,6 @@ class PrintPreviewServer(Thread): return s.getsockname()[1] def run(self): - self.disable_logging() - self.host = "127.0.0.1" self.port = self.find_free_port() # exporting the port number for languages to work in electron vuejs part of inkstitch From 306c7c3425e7b07145c523463e7e122d179eefe8 Mon Sep 17 00:00:00 2001 From: karnigen Date: Mon, 12 Feb 2024 23:53:20 +0100 Subject: [PATCH 03/12] added toml to requirements --- requirements.txt | 1 + 1 file changed, 1 insertion(+) diff --git a/requirements.txt b/requirements.txt index 5763d128f..9869ec7d0 100644 --- a/requirements.txt +++ b/requirements.txt @@ -13,6 +13,7 @@ appdirs numpy jinja2>2.9 requests +toml # colormath - last official release: 3.0.0 # we need already submitted fixes - so let's grab them from the github repository From 5f6989886b4083a4c5ca86139230170b7dae49a6 Mon Sep 17 00:00:00 2001 From: karnigen Date: Wed, 14 Feb 2024 14:04:18 +0100 Subject: [PATCH 04/12] logging update --- inkstitch.py | 2 +- lib/debug_logging.py | 7 +------ 2 files changed, 2 insertions(+), 7 deletions(-) diff --git a/inkstitch.py b/inkstitch.py index 6697e107c..7658cfe03 100644 --- a/inkstitch.py +++ b/inkstitch.py @@ -63,7 +63,6 @@ if running_as_frozen: # in release mode logging.config.dictConfig(debug_logging.frozen_config) # configure root logger from dict - using loglevel, logfilename logging.captureWarnings(True) # capture all warnings to log file with level WARNING - logger.info(f"Running as frozen: {running_as_frozen}") else: logging.disable() # globally disable all logging of all loggers warnings.simplefilter('ignore') # ignore all warnings @@ -93,6 +92,7 @@ if os.environ.get('INKSTITCH_OFFLINE_SCRIPT', '').lower() in ['true', '1', 'yes' else: running_from_inkscape = True +# initialize debug and profiler type debug_active = bool((gettrace := getattr(sys, 'gettrace')) and gettrace()) # check if debugger is active on startup debug_type = 'none' profiler_type = 'none' diff --git a/lib/debug_logging.py b/lib/debug_logging.py index f94e753e6..b3763dbbf 100644 --- a/lib/debug_logging.py +++ b/lib/debug_logging.py @@ -144,10 +144,8 @@ development_config = { # - capture all warnings to log file with level WARNING - depends on warnings_capture # - set action for warnings: 'error', 'ignore', 'always', 'default', 'module', 'once' - depends on warnings_action def configure_logging(config, ini, SCRIPTDIR): - # replace %(SCRIPTDIR)s -> script path in filenames config = evaluate_filenames(config, {'SCRIPTDIR': SCRIPTDIR}) - logging.config.dictConfig(config) # configure loggers from dict - using loglevel, logfilename warnings_capture = config.get('warnings_capture', True) @@ -170,9 +168,7 @@ def configure_logging(config, ini, SCRIPTDIR): # config - logging configuration # myvars - dictionary with variables # returns: logging configuration with evaluated filenames -def evaluate_filenames(config, myvars): - import copy - cfg = copy.deepcopy(config) +def evaluate_filenames(cfg, myvars): for k, v in cfg.get('handlers', {}).items(): if 'filename' in v: cfg['handlers'][k]['filename'] = v['filename'] % myvars @@ -185,7 +181,6 @@ def startup_info(logger, SCRIPTDIR, running_as_frozen, running_from_inkscape, de logger.info(f"Debugger active: {debug_active}") logger.info(f"Debugger type: {debug_type}") logger.info(f"Profiler type: {profiler_type}") - logger.info(f"Using logging configuration from file: {SCRIPTDIR / 'LOGGING.toml'}") # log Python version, platform, command line arguments, sys.path import sys From 1080eceb14ff7143248e949679415cfeddf7462e Mon Sep 17 00:00:00 2001 From: karnigen Date: Wed, 20 Mar 2024 14:55:11 +0100 Subject: [PATCH 05/12] Unified use of the TOML format instead of INI [no ci] --- .gitignore | 6 +++-- DEBUG_template.ini | 59 ------------------------------------------- DEBUG_template.toml | 57 +++++++++++++++++++++++++++++++++++++++++ LOGGING_template.toml | 2 +- inkstitch.py | 43 +++++++++++++++++++------------ lib/debug.py | 38 ++++++++++++++-------------- lib/debug_logging.py | 11 +++++--- lib/debug_utils.py | 37 +++++++++++++++++---------- 8 files changed, 140 insertions(+), 113 deletions(-) delete mode 100644 DEBUG_template.ini create mode 100644 DEBUG_template.toml diff --git a/.gitignore b/.gitignore index 616be3269..60e27fe41 100644 --- a/.gitignore +++ b/.gitignore @@ -23,12 +23,14 @@ flaskserverport.json electron/yarn.lock # debug and profile files -/DEBUG.ini +/DEBUG.toml /LOGGING.toml /LOGGING[0-9]*.toml /debug* /.debug* -# old debug files + +# old debug files - to be removed +/DEBUG*.ini /DEBUG /PROFILE /profile* diff --git a/DEBUG_template.ini b/DEBUG_template.ini deleted file mode 100644 index 38871357f..000000000 --- a/DEBUG_template.ini +++ /dev/null @@ -1,59 +0,0 @@ -[LIBRARY] -;;; use the pip installed version of inkex.py, default: True -; prefer_pip_inkex = False - -[LOGGING] -;;; logging configuration file, default: none - use implicit DEBUG logging to inkstitch.log -;;; we may have multiple configurations: LOGGING.toml, LOGGING1.toml, LOGGING2.toml, etc. -; log_config_file = LOGGING.toml - -;;; disable globally logging: default: False - using logging.disable() -;;; reenable logging.disable(0) -; disable_logging = True - - -[DEBUG] -;;; simulate frozen mode, overwrite running_as_frozen in inkstitch.py, default: False -; force_frozen = True - -;;; select one active debug_type, default: none -; debug_type = vscode -; debug_type = pycharm -; debug_type = pydev - -;;; enable debugger, see cmd line arg -d, default: False -; debug_enable = True - -;;; debug log output to file even if debugger is not enabled, default: False -; debug_to_file = True - -;;; disable debugger when calling from inkscape, default: False -; disable_from_inkscape = True - -;;; wait for debugger to attach (vscode), default: True -; wait_attach = False - -;;; debug log file, default: debug.log -; debug_log_file = debug.log - -;;; debug file for graph related things, default: debug.svg -; debug_svg_file = debug.svg - -;;; creation of bash script, default: False -; create_bash_script = True - -;;; base name for bash script, default: debug_inkstitch -; bash_file_base = debug_inkstitch - -[PROFILE] -;;; select one active profiler_type, default: none -; profiler_type = cprofile -; profiler_type = profile -; profiler_type = pyinstrument - -;;; enable profiler, see cmd line arg -p, default: False -; profile_enable = True - -;;; base name for profile output files, default: debug_profile -; profile_file_base = debug_profile - diff --git a/DEBUG_template.toml b/DEBUG_template.toml new file mode 100644 index 000000000..81fb46e98 --- /dev/null +++ b/DEBUG_template.toml @@ -0,0 +1,57 @@ +[LIBRARY] +### use the pip installed version of inkex.py, default: True +# prefer_pip_inkex = false + +[LOGGING] +### logging configuration file, default: none - use implicit DEBUG logging to inkstitch.log +### we may have multiple configurations: LOGGING.toml, LOGGING1.toml, LOGGING2.toml, etc. +# log_config_file = "LOGGING.toml" + +### disable globally logging: default: False - using logging.disable() +### reenable logging.disable(0) +# disable_logging = true + +[DEBUG] +### simulate frozen mode, overwrite running_as_frozen in inkstitch.py, default: False +# force_frozen = true + +### select one active debug_type, default: none +# debug_type = "vscode" +# debug_type = "pycharm" +# debug_type = "pydev" + +### enable debugger, see cmd line arg -d, default: False +# debug_enable = true + +### debug log output to file even if debugger is not enabled, default: False +# debug_to_file = true + +### disable debugger when calling from inkscape, default: False +# disable_from_inkscape = true + +### wait for debugger to attach (vscode), default: True +# wait_attach = false + +### debug log file, default: debug.log +# debug_log_file = "debug.log" + +### debug file for graph related things, default: debug.svg +# debug_svg_file = "debug.svg" + +### creation of bash script, default: False +# create_bash_script = true + +### base name for bash script, default: debug_inkstitch +# bash_file_base = "debug_inkstitch" + +[PROFILE] +### select one active profiler_type, default: none +# profiler_type = "cprofile" +# profiler_type = "profile" +# profiler_type = "pyinstrument" + +### enable profiler, see cmd line arg -p, default: False +# profile_enable = true + +### base name for profile output files, default: debug_profile +# profile_file_base = "debug_profile" diff --git a/LOGGING_template.toml b/LOGGING_template.toml index 85eece945..589aed156 100644 --- a/LOGGING_template.toml +++ b/LOGGING_template.toml @@ -1,6 +1,6 @@ # logging/warning template for inkstitch # format: toml -# enable config file in DEBUG.ini: log_config_file +# enable config file in DEBUG.toml: log_config_file # warnings.simplefilter(action), default: "default" # - possible values: "error", "ignore", "always", "default", "module", "once" diff --git a/inkstitch.py b/inkstitch.py index 7658cfe03..09e3a91de 100644 --- a/inkstitch.py +++ b/inkstitch.py @@ -8,28 +8,39 @@ import sys from pathlib import Path # to work with paths as objects from argparse import ArgumentParser # to parse arguments and remove --extension -import configparser # to read DEBUG.ini -import toml # to read logging configuration from toml file -import warnings -import logging -import logging.config +import toml # to read logging configuration from toml file +import warnings # to control python warnings +import logging # to configure logging +import logging.config # to configure logging from dict import lib.debug_utils as debug_utils import lib.debug_logging as debug_logging +from lib.debug_utils import safe_get # mimic get method of dict with default value SCRIPTDIR = Path(__file__).parent.absolute() logger = logging.getLogger("inkstitch") # create module logger with name 'inkstitch' -ini = configparser.ConfigParser() -ini.read(SCRIPTDIR / "DEBUG.ini") # read DEBUG.ini file if exists, otherwise use default values in ini object +# temporary - catch old DEBUG.ini file and inform user to reformat it to DEBUG.toml +old_debug_ini = SCRIPTDIR / "DEBUG.ini" +if old_debug_ini.exists(): + print("ERROR: old DEBUG.ini exists, please reformat it to DEBUG.toml and remove DEBUG.ini file") + exit(1) + +debug_toml = SCRIPTDIR / "DEBUG.toml" +if debug_toml.exists(): + ini = toml.load(SCRIPTDIR / "DEBUG.toml") # read DEBUG.toml file if exists, otherwise use default values in ini object +else: + ini = {} +print(ini) # TODO remove this line after DEBUG.ini is not used anymore +# -------------------------------------------------------------------------------------------- + running_as_frozen = getattr(sys, 'frozen', None) is not None # check if running from pyinstaller bundle -if not running_as_frozen: # override running_as_frozen from DEBUG.ini - for testing - if ini.getboolean("DEBUG", "force_frozen", fallback=False): +if not running_as_frozen: # override running_as_frozen from DEBUG.toml - for testing + if safe_get(ini, "DEBUG", "force_frozen", default=False): running_as_frozen = True - if len(sys.argv) < 2: # no arguments - prevent accidentally running this script msg = "No arguments given, exiting!" # without gettext localization see _() @@ -57,7 +68,7 @@ if running_as_frozen: # in release mode docpath = os.environ.get('DOCUMENT_PATH') # read document path from environment variable (set by inkscape) or None if docpath is not None and loglevel is not None and loglevel.upper() in ['DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL']: - # enable logging-warning and redirect output to input_svg.inkstitch.log + # end user enabled logging&warnings and redirect output to input_svg.inkstitch.log logfilename = Path(docpath).with_suffix('.inkstitch.log') # log file is created in document path loglevel = loglevel.upper() @@ -69,7 +80,7 @@ if running_as_frozen: # in release mode else: # in development mode we want to use configuration from some LOGGING.toml file - logging_config_file = ini.get("LOGGING", "log_config_file", fallback=None) + logging_config_file = safe_get(ini, "LOGGING", "log_config_file", default=None) if logging_config_file is not None: logging_config_file = Path(logging_config_file) if logging_config_file.exists(): @@ -107,21 +118,21 @@ if not running_as_frozen: # debugging/profiling only in development mode if running_from_inkscape: # process creation of the Bash script - should be done before sys.path is modified, see below in prefere_pip_inkex - if ini.getboolean("DEBUG", "create_bash_script", fallback=False): # create script only if enabled in DEBUG.ini + if safe_get(ini, "DEBUG", "create_bash_script", default=False): # create script only if enabled in DEBUG.toml debug_utils.write_offline_debug_script(SCRIPTDIR, ini) # disable debugger when running from inkscape - disable_from_inkscape = ini.getboolean("DEBUG", "disable_from_inkscape", fallback=False) + disable_from_inkscape = safe_get(ini, "DEBUG", "disable_from_inkscape", default=False) if disable_from_inkscape: debug_type = 'none' # do not start debugger when running from inkscape # prefer pip installed inkex over inkscape bundled inkex, pip version is bundled with Inkstitch # - must be be done before importing inkex - prefere_pip_inkex = ini.getboolean("LIBRARY", "prefer_pip_inkex", fallback=True) + prefere_pip_inkex = safe_get(ini, "LIBRARY", "prefer_pip_inkex", default=True) if prefere_pip_inkex and 'PYTHONPATH' in os.environ: debug_utils.reorder_sys_path() -# enabling of debug depends on value of debug_type in DEBUG.ini file +# enabling of debug depends on value of debug_type in DEBUG.toml file if debug_type != 'none': from lib.debug import debug # import global variable debug - don't import whole module debug.enable(debug_type, SCRIPTDIR, ini) diff --git a/lib/debug.py b/lib/debug.py index e72f64353..190e9d49d 100644 --- a/lib/debug.py +++ b/lib/debug.py @@ -11,8 +11,8 @@ import time # to measure time of code block, use time.monotonic() instead of from datetime import datetime from contextlib import contextmanager # to measure time of with block -import configparser # to read DEBUG.ini from pathlib import Path # to work with paths as objects +from .debug_utils import safe_get # mimic get method of dict with default value import inkex from lxml import etree # to create svg file @@ -79,12 +79,12 @@ class Debug(object): self.current_layer = None self.group_stack = [] - def enable(self, debug_type, debug_dir: Path, ini: configparser.ConfigParser): - # initilize file names and other parameters from DEBUG.ini file + def enable(self, debug_type, debug_dir: Path, ini: dict): + # initilize file names and other parameters from DEBUG.toml file self.debug_dir = debug_dir # directory where debug files are stored - self.debug_log_file = ini.get("DEBUG", "debug_log_file", fallback="debug.log") - self.debug_svg_file = ini.get("DEBUG", "debug_svg_file", fallback="debug.svg") - self.wait_attach = ini.getboolean("DEBUG", "wait_attach", fallback=True) # currently only for vscode + self.debug_log_file = safe_get(ini, "DEBUG", "debug_log_file", default="debug.log") + self.debug_svg_file = safe_get(ini, "DEBUG", "debug_svg_file", default="debug.svg") + self.wait_attach = safe_get(ini, "DEBUG", "wait_attach", default=True) # currently only for vscode if debug_type == 'none': return @@ -107,11 +107,11 @@ class Debug(object): # flake8: noqa: C901 def init_debugger(self): # ### General debugging notes: - # 1. to enable debugging or profiling copy DEBUG_template.ini to DEBUG.ini and edit it + # 1. to enable debugging or profiling copy DEBUG_template.toml to DEBUG.toml and edit it # ### How create bash script for offline debugging from console - # 1. in DEBUG.ini set create_bash_script = True - # 2. call inkstitch.py extension from inkscape to create bash script named by bash_file_base in DEBUG.ini + # 1. in DEBUG.toml set create_bash_script = true + # 2. call inkstitch.py extension from inkscape to create bash script named by bash_file_base in DEBUG.toml # 3. run bash script from console # ### Enable debugging @@ -119,7 +119,7 @@ class Debug(object): # debug_type = vscode - 'debugpy' for vscode editor # debug_type = pycharm - 'pydevd-pycharm' for pycharm editor # debug_type = pydev - 'pydevd' for eclipse editor - # 2. set debug_enable = True in DEBUG.ini + # 2. set debug_enable = true in DEBUG.toml # or use command line argument -d in bash script # or set environment variable INKSTITCH_DEBUG_ENABLE = True or 1 or yes or y @@ -128,16 +128,16 @@ class Debug(object): # profiler_type = cprofile - 'cProfile' profiler # profiler_type = profile - 'profile' profiler # profiler_type = pyinstrument- 'pyinstrument' profiler - # 2. set profile_enable = True in DEBUG.ini + # 2. set profile_enable = true in DEBUG.toml # or use command line argument -p in bash script # or set environment variable INKSTITCH_PROFILE_ENABLE = True or 1 or yes or y # ### Miscelaneous notes: - # - to disable debugger when running from inkscape set disable_from_inkscape = True in DEBUG.ini - # - to write debug output to file set debug_to_file = True in DEBUG.ini - # - to change various output file names see DEBUG.ini - # - to disable waiting for debugger to attach (vscode editor) set wait_attach = False in DEBUG.ini - # - to prefer inkscape version of inkex module over pip version set prefer_pip_inkex = False in DEBUG.ini + # - to disable debugger when running from inkscape set disable_from_inkscape = true in DEBUG.toml + # - to write debug output to file set debug_to_file = true in DEBUG.toml + # - to change various output file names see DEBUG.toml + # - to disable waiting for debugger to attach (vscode editor) set wait_attach = false in DEBUG.toml + # - to prefer inkscape version of inkex module over pip version set prefer_pip_inkex = false in DEBUG.toml # ### @@ -146,7 +146,7 @@ class Debug(object): # 1. Install LiClipse (liclipse.com) -- no need to install Eclipse first # 2. Start debug server as described here: http://www.pydev.org/manual_adv_remote_debugger.html # * follow the "Note:" to enable the debug server menu item - # 3. Copy and edit a file named "DEBUG.ini" from "DEBUG_template.ini" next to inkstitch.py in your git clone + # 3. Copy and edit a file named "DEBUG.toml" from "DEBUG_template.toml" next to inkstitch.py in your git clone # and set debug_type = pydev # 4. Run any extension and PyDev will start debugging. @@ -173,7 +173,7 @@ class Debug(object): # configuration. Set "IDE host name:" to "localhost" and "Port:" to 5678. # You can leave the default settings for all other choices. # - # 3. Touch a file named "DEBUG.ini" at the top of your git repo, as above + # 3. Touch a file named "DEBUG.toml" at the top of your git repo, as above # set debug_type = pycharm # # 4. Create a symbolic link in the Inkscape extensions directory to the @@ -217,7 +217,7 @@ class Debug(object): # } # } # ] - # 3. Touch a file named "DEBUG.ini" at the top of your git repo, as above + # 3. Touch a file named "DEBUG.toml" at the top of your git repo, as above # set debug_type = vscode # 4. Start the debug server in VS Code by clicking on the debug icon in the left pane # select "Python: Attach" from the dropdown menu and click on the green arrow. diff --git a/lib/debug_logging.py b/lib/debug_logging.py index b3763dbbf..85fa404a3 100644 --- a/lib/debug_logging.py +++ b/lib/debug_logging.py @@ -67,6 +67,8 @@ import logging import warnings +from .debug_utils import safe_get # mimic get method of dict with default value + logger = logging.getLogger('inkstitch') # example of logger configuration for release mode: @@ -152,17 +154,20 @@ def configure_logging(config, ini, SCRIPTDIR): logging.captureWarnings(warnings_capture) # capture warnings to log file with level WARNING warnings_action = config.get('warnings_action', 'default').lower() warnings.simplefilter(warnings_action) # set action for warnings: 'error', 'ignore', 'always', ... - disable_logging = ini.getboolean("LOGGING", "disable_logging", fallback=False) + disable_logging = safe_get(ini, "LOGGING", "disable_logging", default=False) if disable_logging: logger.warning("Logging is disabled by configuration in ini file.") logging.disable() # globally disable all logging of all loggers -# Evaluate filenames in logging configuration using myvars dictionary: +# Evaluate filenames in logging configuration using myvars dictionary argument. +# - for external configuration file (eg. LOGGING.toml) we cannot pass parameters such as the current directory. +# - we do that by replacing %(SCRIPTDIR)s -> script path in filenames +# - example of usage: # "handlers": { # "file": { # "class": "logging.FileHandler", -# "filename": "%(SCRIPTDIR)s/xxx.log", # replace %(SCRIPTDIR)s -> script path +# "filename": "%(SCRIPTDIR)s/xxx.log", # <--- replace %(SCRIPTDIR)s -> script path # } # } # config - logging configuration diff --git a/lib/debug_utils.py b/lib/debug_utils.py index c680e9234..b37e72799 100644 --- a/lib/debug_utils.py +++ b/lib/debug_utils.py @@ -6,23 +6,34 @@ import os import sys from pathlib import Path # to work with paths as objects -import configparser # to read DEBUG.ini # this file is without: import inkex # - we need dump argv and sys.path as is on startup from inkscape # - later sys.path may be modified that influences importing inkex (see prefere_pip_inkex) -def write_offline_debug_script(debug_script_dir: Path, ini: configparser.ConfigParser): +# safe_get - get value from nested dictionary, return default if key does not exist +# - to read nested values from dict - mimic get method of dict with default value +# example: safe_get({'a': {'b': 1}}, 'a', 'b') -> 1 +# safe_get({'a': {'b': 1}}, 'a', 'c', default=2) -> 2 +def safe_get(dictionary:dict, *keys, default=None): + for key in keys: + if key not in dictionary: + return default + dictionary = dictionary[key] + return dictionary + + +def write_offline_debug_script(debug_script_dir: Path, ini: dict): ''' prepare Bash script for offline debugging from console arguments: - debug_script_dir - Path object, absolute path to directory of inkstitch.py - - ini - see DEBUG.ini + - ini - see DEBUG.toml ''' # define names of files used by offline Bash script - bash_file_base = ini.get("DEBUG", "bash_file_base", fallback="debug_inkstitch") + bash_file_base = safe_get(ini, "DEBUG", "bash_file_base", default="debug_inkstitch") bash_name = Path(bash_file_base).with_suffix(".sh") # Path object bash_svg = Path(bash_file_base).with_suffix(".svg") # Path object @@ -147,18 +158,18 @@ def reorder_sys_path(): # ----------------------------------------------------------------------------- # try to resolve debugger type from ini file or cmd line of bash -def resolve_debug_type(ini: configparser.ConfigParser): +def resolve_debug_type(ini: dict): # enable/disable debugger from bash: -d if os.environ.get('INKSTITCH_DEBUG_ENABLE', '').lower() in ['true', '1', 'yes', 'y']: debug_enable = True else: - debug_enable = ini.getboolean("DEBUG", "debug_enable", fallback=False) # enable debugger on startup from ini + debug_enable = safe_get(ini, "DEBUG", "debug_enable", default=False) # enable debugger on startup from ini - debug_type = ini.get("DEBUG", "debug_type", fallback="none") # debugger type vscode, pycharm, pydevd + debug_type = safe_get(ini, "DEBUG", "debug_type", default="none") # debugger type vscode, pycharm, pydevd if not debug_enable: debug_type = 'none' - debug_to_file = ini.getboolean("DEBUG", "debug_to_file", fallback=False) # write debug output to file + debug_to_file = safe_get(ini, "DEBUG", "debug_to_file", default=False) # write debug output to file if debug_to_file and debug_type == 'none': debug_type = 'file' @@ -166,15 +177,15 @@ def resolve_debug_type(ini: configparser.ConfigParser): # try to resolve profiler type from ini file or cmd line of bash -def resolve_profile_type(ini: configparser.ConfigParser): +def resolve_profile_type(ini: dict): # enable/disable profiling from bash: -p if os.environ.get('INKSTITCH_PROFILE_ENABLE', '').lower() in ['true', '1', 'yes', 'y']: profile_enable = True else: - profile_enable = ini.getboolean("PROFILE", "profile_enable", fallback=False) # read from ini + profile_enable = safe_get(ini, "PROFILE", "profile_enable", default=False) # read from ini # specify profiler type - profiler_type = ini.get("PROFILE", "profiler_type", fallback="none") # profiler type cprofile, profile, pyinstrument + profiler_type = safe_get(ini, "PROFILE", "profiler_type", default="none") # profiler type cprofile, profile, pyinstrument if not profile_enable: profiler_type = 'none' @@ -189,11 +200,11 @@ def resolve_profile_type(ini: configparser.ConfigParser): # - pyinstrument - profiler with nice html output -def profile(profiler_type, profile_dir: Path, ini: configparser.ConfigParser, extension, remaining_args): +def profile(profiler_type, profile_dir: Path, ini: dict, extension, remaining_args): ''' profile with cProfile, profile or pyinstrument ''' - profile_file_base = ini.get("PROFILE", "profile_file_base", fallback="debug_profile") + profile_file_base = safe_get(ini, "PROFILE", "profile_file_base", default="debug_profile") profile_file_path = profile_dir / profile_file_base # Path object if profiler_type == 'cprofile': From 47fdfa41cf005e9d5ff8192fae72f8dad5ae29c7 Mon Sep 17 00:00:00 2001 From: karnigen Date: Wed, 20 Mar 2024 16:41:25 +0100 Subject: [PATCH 06/12] Unified use of the TOML format instead of INI [no ci] --- .gitignore | 1 + DEBUG_template.toml | 32 ++++++++++++++++---------------- LOGGING_template.toml | 38 +++++++++++++++++++++++--------------- inkstitch.py | 19 +++++++++++++------ lib/debug.py | 2 +- lib/debug_logging.py | 26 +++++++++++++++++--------- lib/debug_utils.py | 12 ++++++++---- 7 files changed, 79 insertions(+), 51 deletions(-) diff --git a/.gitignore b/.gitignore index 60e27fe41..f927923ef 100644 --- a/.gitignore +++ b/.gitignore @@ -23,6 +23,7 @@ flaskserverport.json electron/yarn.lock # debug and profile files +logs/ /DEBUG.toml /LOGGING.toml /LOGGING[0-9]*.toml diff --git a/DEBUG_template.toml b/DEBUG_template.toml index 81fb46e98..9f8758b13 100644 --- a/DEBUG_template.toml +++ b/DEBUG_template.toml @@ -1,5 +1,5 @@ [LIBRARY] -### use the pip installed version of inkex.py, default: True +### use the pip installed version of inkex.py, default: true # prefer_pip_inkex = false [LOGGING] @@ -7,51 +7,51 @@ ### we may have multiple configurations: LOGGING.toml, LOGGING1.toml, LOGGING2.toml, etc. # log_config_file = "LOGGING.toml" -### disable globally logging: default: False - using logging.disable() +### disable globally logging: default: false - using logging.disable() ### reenable logging.disable(0) # disable_logging = true [DEBUG] -### simulate frozen mode, overwrite running_as_frozen in inkstitch.py, default: False +### simulate frozen mode, overwrite running_as_frozen in inkstitch.py, default: false # force_frozen = true -### select one active debug_type, default: none +### select one active debug_type, default: "none" # debug_type = "vscode" # debug_type = "pycharm" # debug_type = "pydev" -### enable debugger, see cmd line arg -d, default: False +### enable debugger, see cmd line arg -d, default: false # debug_enable = true -### debug log output to file even if debugger is not enabled, default: False +### debug log output to file even if debugger is not enabled, default: false # debug_to_file = true -### disable debugger when calling from inkscape, default: False +### disable debugger when calling from inkscape, default: false # disable_from_inkscape = true -### wait for debugger to attach (vscode), default: True +### wait for debugger to attach (vscode), default: true # wait_attach = false -### debug log file, default: debug.log +### debug log file, default: "debug.log" # debug_log_file = "debug.log" -### debug file for graph related things, default: debug.svg +### debug file for graph related things, default: "debug.svg" # debug_svg_file = "debug.svg" -### creation of bash script, default: False +### creation of bash script, default: false # create_bash_script = true -### base name for bash script, default: debug_inkstitch +### base name for bash script, default: "debug_inkstitch" # bash_file_base = "debug_inkstitch" [PROFILE] -### select one active profiler_type, default: none +### select one active profiler_type, default: "none" # profiler_type = "cprofile" # profiler_type = "profile" # profiler_type = "pyinstrument" -### enable profiler, see cmd line arg -p, default: False +### enable profiler, see cmd line arg -p, default: false # profile_enable = true -### base name for profile output files, default: debug_profile -# profile_file_base = "debug_profile" +### base name for profile output files, default: "debug_profile" +# profile_file_base = "logs/debug_profile" diff --git a/LOGGING_template.toml b/LOGGING_template.toml index 589aed156..ed7e34c00 100644 --- a/LOGGING_template.toml +++ b/LOGGING_template.toml @@ -1,20 +1,20 @@ -# logging/warning template for inkstitch -# format: toml -# enable config file in DEBUG.toml: log_config_file - -# warnings.simplefilter(action), default: "default" -# - possible values: "error", "ignore", "always", "default", "module", "once" +### logging/warning template for inkstitch +### format: toml +### enable config file in DEBUG.toml: log_config_file +### +### warnings.simplefilter(action), default: "default" +### - possible values: "error", "ignore", "always", "default", "module", "once" warnings_action = "default" -# logging.captureWarnings() default: true -# - possible values: true, false +### logging.captureWarnings() default: true +### - possible values: true, false warnings_capture = true -# mandatory, must be an integer and 1 +### mandatory, must be an integer and 1 version = 1 -# false - to keep existing loggers, not specified here -# true - to disable all loggers not specified here +### false - to keep existing loggers, not specified here +### true - to disable all loggers not specified here disable_existing_loggers = false [filters] @@ -22,17 +22,25 @@ disable_existing_loggers = false [formatters.simple] format = "%(asctime)s [%(levelname)s]: %(filename)s.%(funcName)s: %(message)s" -[handlers.file] +[handlers.file_inkstitch] class = "logging.FileHandler" formatter = "simple" - filename = "%(SCRIPTDIR)s/inkstitch.log" + filename = "%(SCRIPTDIR)s/logs/inkstitch.log" mode = "w" +[handlers.file_root] + class = "logging.FileHandler" + formatter = "simple" + filename = "%(SCRIPTDIR)s/logs/inkstitch_root.log" + mode = "w" + +### inkstitch logger [loggers.inkstitch] level = "DEBUG" - handlers = [ "file",] + handlers = [ "file_inkstitch",] propagate = false +### loggers not specified here will be managed by the root logger [loggers.root] level = "DEBUG" - handlers = [ "file",] + handlers = [ "file_root",] diff --git a/inkstitch.py b/inkstitch.py index 09e3a91de..b252eb93e 100644 --- a/inkstitch.py +++ b/inkstitch.py @@ -21,18 +21,18 @@ SCRIPTDIR = Path(__file__).parent.absolute() logger = logging.getLogger("inkstitch") # create module logger with name 'inkstitch' -# temporary - catch old DEBUG.ini file and inform user to reformat it to DEBUG.toml +# TODO --- temporary --- catch old DEBUG.ini file and inform user to reformat it to DEBUG.toml old_debug_ini = SCRIPTDIR / "DEBUG.ini" if old_debug_ini.exists(): print("ERROR: old DEBUG.ini exists, please reformat it to DEBUG.toml and remove DEBUG.ini file") exit(1) +# --- end of temporary --- debug_toml = SCRIPTDIR / "DEBUG.toml" if debug_toml.exists(): ini = toml.load(SCRIPTDIR / "DEBUG.toml") # read DEBUG.toml file if exists, otherwise use default values in ini object else: ini = {} -print(ini) # TODO remove this line after DEBUG.ini is not used anymore # -------------------------------------------------------------------------------------------- running_as_frozen = getattr(sys, 'frozen', None) is not None # check if running from pyinstaller bundle @@ -72,7 +72,12 @@ if running_as_frozen: # in release mode logfilename = Path(docpath).with_suffix('.inkstitch.log') # log file is created in document path loglevel = loglevel.upper() - logging.config.dictConfig(debug_logging.frozen_config) # configure root logger from dict - using loglevel, logfilename + # dictConfig has access to top level variables + # in dict config string we use: + # - ext://__main__.logfilename -> access to logfilename: user.svg.inkstitch.log + # - ext://__main__.loglevel -> access to loglevel: user defined log level + # restriction: variable must be last token in string + logging.config.dictConfig(debug_logging.frozen_config) # configure root logger from dict logging.captureWarnings(True) # capture all warnings to log file with level WARNING else: logging.disable() # globally disable all logging of all loggers @@ -85,14 +90,16 @@ else: logging_config_file = Path(logging_config_file) if logging_config_file.exists(): with open(logging_config_file, "r") as f: - development_config = toml.load(f) + development_config = toml.load(f) # -> dict else: raise FileNotFoundError(f"{logging_config_file} file not found") else: # if LOGGING.toml file does not exist, use default logging configuration loglevel = 'DEBUG' # set log level to DEBUG logfilename = SCRIPTDIR / "inkstitch.log" # log file is created in current directory - development_config = debug_logging.development_config + development_config = debug_logging.development_config # get TOML configuration from module + # we cannot use dictConfig() as above due to restrictions in logging current implementation + # - we need replace: filename = "%(SCRIPTDIR)s/inkstitch.log" -> filename = "path/inkstitch.log" debug_logging.configure_logging(development_config, ini, SCRIPTDIR) # initialize logging configuration logger.info("Running in development mode") logger.info(f"Using logging configuration from file: {logging_config_file}") @@ -114,7 +121,7 @@ if not running_as_frozen: # debugging/profiling only in development mode if not debug_active: debug_type = debug_utils.resolve_debug_type(ini) # read debug type from ini file or cmd line - profile_type = debug_utils.resolve_profile_type(ini) # read profile type from ini file or cmd line + profiler_type = debug_utils.resolve_profiler_type(ini) # read profile type from ini file or cmd line if running_from_inkscape: # process creation of the Bash script - should be done before sys.path is modified, see below in prefere_pip_inkex diff --git a/lib/debug.py b/lib/debug.py index 190e9d49d..0b0fa1b7d 100644 --- a/lib/debug.py +++ b/lib/debug.py @@ -79,7 +79,7 @@ class Debug(object): self.current_layer = None self.group_stack = [] - def enable(self, debug_type, debug_dir: Path, ini: dict): + def enable(self, debug_type:str, debug_dir: Path, ini: dict): # initilize file names and other parameters from DEBUG.toml file self.debug_dir = debug_dir # directory where debug files are stored self.debug_log_file = safe_get(ini, "DEBUG", "debug_log_file", default="debug.log") diff --git a/lib/debug_logging.py b/lib/debug_logging.py index 85fa404a3..7d6a655f2 100644 --- a/lib/debug_logging.py +++ b/lib/debug_logging.py @@ -66,6 +66,7 @@ import logging import warnings +from pathlib import Path from .debug_utils import safe_get # mimic get method of dict with default value @@ -74,7 +75,8 @@ logger = logging.getLogger('inkstitch') # example of logger configuration for release mode: # ------------------------------------------------ # - logger suitable for release mode, where we assume that the directory of the input SVG file allows writing the log file. -# - this config redirect all loggers to file svg_file.inkstitch.log to directory of svg file +# - in inkstitch.py we check release mode and environment variable INKSTITCH_LOGLEVEL +# - this config redirect all loggers to file svg_file.inkstitch.log to directory of svg file # - set loglevel and logfilename in inkstitch.py before calling logging.config.dictConfig(frozen_config) frozen_config = { "version": 1, # mandatory key and value (int) is 1 @@ -145,7 +147,7 @@ development_config = { # configure logging from dictionary: # - capture all warnings to log file with level WARNING - depends on warnings_capture # - set action for warnings: 'error', 'ignore', 'always', 'default', 'module', 'once' - depends on warnings_action -def configure_logging(config, ini, SCRIPTDIR): +def configure_logging(config:dict, ini:dict, SCRIPTDIR:Path): # replace %(SCRIPTDIR)s -> script path in filenames config = evaluate_filenames(config, {'SCRIPTDIR': SCRIPTDIR}) logging.config.dictConfig(config) # configure loggers from dict - using loglevel, logfilename @@ -160,9 +162,10 @@ def configure_logging(config, ini, SCRIPTDIR): logging.disable() # globally disable all logging of all loggers -# Evaluate filenames in logging configuration using myvars dictionary argument. +# Evaluate filenames in logging configuration using dictionary argument: myvars. # - for external configuration file (eg. LOGGING.toml) we cannot pass parameters such as the current directory. -# - we do that by replacing %(SCRIPTDIR)s -> script path in filenames +# - we do: filename = "%(SCRIPTDIR)s/inkstitch.log" -> filename = "path/inkstitch.log" +# # - example of usage: # "handlers": { # "file": { @@ -170,17 +173,22 @@ def configure_logging(config, ini, SCRIPTDIR): # "filename": "%(SCRIPTDIR)s/xxx.log", # <--- replace %(SCRIPTDIR)s -> script path # } # } -# config - logging configuration -# myvars - dictionary with variables +# # returns: logging configuration with evaluated filenames -def evaluate_filenames(cfg, myvars): +def evaluate_filenames(cfg: dict, myvars: dict): for k, v in cfg.get('handlers', {}).items(): - if 'filename' in v: + if 'filename' in v: # replace filename in handler cfg['handlers'][k]['filename'] = v['filename'] % myvars + + # create logging directory if not exists + dirname = Path(cfg['handlers'][k]['filename']).parent + if not dirname.exists(): + dirname.mkdir(parents=True, exist_ok=True) return cfg -def startup_info(logger, SCRIPTDIR, running_as_frozen, running_from_inkscape, debug_active, debug_type, profiler_type): +def startup_info(logger:logging.Logger, SCRIPTDIR:Path, running_as_frozen:bool, running_from_inkscape:bool, + debug_active:bool, debug_type:str, profiler_type:str): logger.info(f"Running as frozen: {running_as_frozen}") logger.info(f"Running from inkscape: {running_from_inkscape}") logger.info(f"Debugger active: {debug_active}") diff --git a/lib/debug_utils.py b/lib/debug_utils.py index b37e72799..998e2ad87 100644 --- a/lib/debug_utils.py +++ b/lib/debug_utils.py @@ -177,7 +177,7 @@ def resolve_debug_type(ini: dict): # try to resolve profiler type from ini file or cmd line of bash -def resolve_profile_type(ini: dict): +def resolve_profiler_type(ini: dict): # enable/disable profiling from bash: -p if os.environ.get('INKSTITCH_PROFILE_ENABLE', '').lower() in ['true', '1', 'yes', 'y']: profile_enable = True @@ -207,6 +207,10 @@ def profile(profiler_type, profile_dir: Path, ini: dict, extension, remaining_ar profile_file_base = safe_get(ini, "PROFILE", "profile_file_base", default="debug_profile") profile_file_path = profile_dir / profile_file_base # Path object + # create directory if not exists + dirname = profile_file_path.parent + dirname.mkdir(parents=True, exist_ok=True) + if profiler_type == 'cprofile': with_cprofile(extension, remaining_args, profile_file_path) elif profiler_type == 'profile': @@ -217,7 +221,7 @@ def profile(profiler_type, profile_dir: Path, ini: dict, extension, remaining_ar raise ValueError(f"unknown profiler type: '{profiler_type}'") -def with_cprofile(extension, remaining_args, profile_file_path): +def with_cprofile(extension, remaining_args, profile_file_path:Path): ''' profile with cProfile ''' @@ -238,7 +242,7 @@ def with_cprofile(extension, remaining_args, profile_file_path): file=sys.stderr) -def with_profile(extension, remaining_args, profile_file_path): +def with_profile(extension, remaining_args, profile_file_path:Path): ''' profile with profile ''' @@ -257,7 +261,7 @@ def with_profile(extension, remaining_args, profile_file_path): file=sys.stderr) -def with_pyinstrument(extension, remaining_args, profile_file_path): +def with_pyinstrument(extension, remaining_args, profile_file_path:Path): ''' profile with pyinstrument ''' From 7c2e6d286f3cba46131548d98f24ba5223b4bae9 Mon Sep 17 00:00:00 2001 From: karnigen Date: Fri, 22 Mar 2024 19:52:51 +0100 Subject: [PATCH 07/12] moving debug*.py to debug dir, moving some part for debugger [no ci] --- DEBUG_template.toml | 10 +- LOGGING_template.toml | 30 +- inkstitch.py | 80 ++-- lib/debug.py | 421 --------------------- lib/debug/__init__.py | 11 + lib/debug/debug.py | 240 ++++++++++++ lib/debug/debugger.py | 192 ++++++++++ lib/{debug_logging.py => debug/logging.py} | 230 +++++++---- lib/{debug_utils.py => debug/utils.py} | 28 +- requirements.txt | 5 +- 10 files changed, 670 insertions(+), 577 deletions(-) delete mode 100644 lib/debug.py create mode 100644 lib/debug/__init__.py create mode 100644 lib/debug/debug.py create mode 100644 lib/debug/debugger.py rename lib/{debug_logging.py => debug/logging.py} (57%) rename lib/{debug_utils.py => debug/utils.py} (96%) diff --git a/DEBUG_template.toml b/DEBUG_template.toml index 9f8758b13..747916027 100644 --- a/DEBUG_template.toml +++ b/DEBUG_template.toml @@ -23,21 +23,12 @@ ### enable debugger, see cmd line arg -d, default: false # debug_enable = true -### debug log output to file even if debugger is not enabled, default: false -# debug_to_file = true - ### disable debugger when calling from inkscape, default: false # disable_from_inkscape = true ### wait for debugger to attach (vscode), default: true # wait_attach = false -### debug log file, default: "debug.log" -# debug_log_file = "debug.log" - -### debug file for graph related things, default: "debug.svg" -# debug_svg_file = "debug.svg" - ### creation of bash script, default: false # create_bash_script = true @@ -55,3 +46,4 @@ ### base name for profile output files, default: "debug_profile" # profile_file_base = "logs/debug_profile" + diff --git a/LOGGING_template.toml b/LOGGING_template.toml index ed7e34c00..27aadcb3b 100644 --- a/LOGGING_template.toml +++ b/LOGGING_template.toml @@ -13,34 +13,56 @@ warnings_capture = true ### mandatory, must be an integer and 1 version = 1 -### false - to keep existing loggers, not specified here -### true - to disable all loggers not specified here +### disable loggers not specified here true/false - may be overrided by root logger disable_existing_loggers = false +### define the loggers, handlers, formatters, filters [filters] [formatters.simple] format = "%(asctime)s [%(levelname)s]: %(filename)s.%(funcName)s: %(message)s" +[formatters.debug] + format = "%(asctime)s %(message)s" + + [handlers.file_inkstitch] class = "logging.FileHandler" formatter = "simple" filename = "%(SCRIPTDIR)s/logs/inkstitch.log" mode = "w" +[handlers.file_inkstitch_debug] + class = "logging.FileHandler" + formatter = "debug" + filename = "%(SCRIPTDIR)s/logs/inkstitch_debug.log" + mode = "w" + [handlers.file_root] class = "logging.FileHandler" formatter = "simple" filename = "%(SCRIPTDIR)s/logs/inkstitch_root.log" mode = "w" -### inkstitch logger + +### used for: logger = logging.getLogger("inkstitch") +### logger = logging.getLogger("inkstitch.xxx") where xxx is not specified in this config file +### - highest level logger for all 'inkstitch.*' loggers [loggers.inkstitch] level = "DEBUG" handlers = [ "file_inkstitch",] propagate = false -### loggers not specified here will be managed by the root logger +### used for: logger = logging.getLogger("inkstitch.debug") +### - use quotes for the logger name with dots, otherwise it will be treated as a table subsection +### - [loggers.inkstitch.debug] is not the same as [loggers.'inkstitch.debug'] +### - to disable the logger, comment out handlers +[loggers.'inkstitch.debug'] + level = "DEBUG" + handlers = [ "file_inkstitch_debug",] + propagate = false + +### root - loggers not specified in this config file will be managed by this logger [loggers.root] level = "DEBUG" handlers = [ "file_root",] diff --git a/inkstitch.py b/inkstitch.py index b252eb93e..7d9860105 100644 --- a/inkstitch.py +++ b/inkstitch.py @@ -8,14 +8,18 @@ import sys from pathlib import Path # to work with paths as objects from argparse import ArgumentParser # to parse arguments and remove --extension -import toml # to read logging configuration from toml file -import warnings # to control python warnings -import logging # to configure logging -import logging.config # to configure logging from dict +if sys.version_info >= (3, 11): + import tomllib # built-in in Python 3.11+ +else: + import tomli as tomllib -import lib.debug_utils as debug_utils -import lib.debug_logging as debug_logging -from lib.debug_utils import safe_get # mimic get method of dict with default value +import logging + +import lib.debug.utils as debug_utils +import lib.debug.logging as debug_logging +from lib.debug.utils import safe_get # mimic get method of dict with default value + +# -------------------------------------------------------------------------------------------- SCRIPTDIR = Path(__file__).parent.absolute() @@ -30,7 +34,8 @@ if old_debug_ini.exists(): debug_toml = SCRIPTDIR / "DEBUG.toml" if debug_toml.exists(): - ini = toml.load(SCRIPTDIR / "DEBUG.toml") # read DEBUG.toml file if exists, otherwise use default values in ini object + with debug_toml.open("rb") as f: + ini = tomllib.load(f) # read DEBUG.toml file if exists, otherwise use default values in ini object else: ini = {} # -------------------------------------------------------------------------------------------- @@ -57,52 +62,9 @@ if len(sys.argv) < 2: print(msg) exit(1) -# Configure logging: -# in release mode normally we want to ignore all warnings and logging, but we can enable it by setting environment variables -# - INKSTITCH_LOGLEVEL - logging level: -# 'DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL' -# - PYTHONWARNINGS, -W - warnings action controlled by python -# actions: 'error', 'ignore', 'always', 'default', 'module', 'once' -if running_as_frozen: # in release mode - loglevel = os.environ.get('INKSTITCH_LOGLEVEL') # read log level from environment variable or None - docpath = os.environ.get('DOCUMENT_PATH') # read document path from environment variable (set by inkscape) or None - - if docpath is not None and loglevel is not None and loglevel.upper() in ['DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL']: - # end user enabled logging&warnings and redirect output to input_svg.inkstitch.log - logfilename = Path(docpath).with_suffix('.inkstitch.log') # log file is created in document path - loglevel = loglevel.upper() - - # dictConfig has access to top level variables - # in dict config string we use: - # - ext://__main__.logfilename -> access to logfilename: user.svg.inkstitch.log - # - ext://__main__.loglevel -> access to loglevel: user defined log level - # restriction: variable must be last token in string - logging.config.dictConfig(debug_logging.frozen_config) # configure root logger from dict - logging.captureWarnings(True) # capture all warnings to log file with level WARNING - else: - logging.disable() # globally disable all logging of all loggers - warnings.simplefilter('ignore') # ignore all warnings - -else: - # in development mode we want to use configuration from some LOGGING.toml file - logging_config_file = safe_get(ini, "LOGGING", "log_config_file", default=None) - if logging_config_file is not None: - logging_config_file = Path(logging_config_file) - if logging_config_file.exists(): - with open(logging_config_file, "r") as f: - development_config = toml.load(f) # -> dict - else: - raise FileNotFoundError(f"{logging_config_file} file not found") - else: # if LOGGING.toml file does not exist, use default logging configuration - loglevel = 'DEBUG' # set log level to DEBUG - logfilename = SCRIPTDIR / "inkstitch.log" # log file is created in current directory - development_config = debug_logging.development_config # get TOML configuration from module - - # we cannot use dictConfig() as above due to restrictions in logging current implementation - # - we need replace: filename = "%(SCRIPTDIR)s/inkstitch.log" -> filename = "path/inkstitch.log" - debug_logging.configure_logging(development_config, ini, SCRIPTDIR) # initialize logging configuration - logger.info("Running in development mode") - logger.info(f"Using logging configuration from file: {logging_config_file}") +# activate logging - must be done before any logging is done +debug_logging.activate_logging(running_as_frozen, ini, SCRIPTDIR) +# -------------------------------------------------------------------------------------------- # check if running from inkscape, given by environment variable if os.environ.get('INKSTITCH_OFFLINE_SCRIPT', '').lower() in ['true', '1', 'yes', 'y']: @@ -141,14 +103,20 @@ if not running_as_frozen: # debugging/profiling only in development mode # enabling of debug depends on value of debug_type in DEBUG.toml file if debug_type != 'none': - from lib.debug import debug # import global variable debug - don't import whole module - debug.enable(debug_type, SCRIPTDIR, ini) + from lib.debug.debugger import init_debugger + init_debugger(debug_type, ini) # check if debugger is really activated debug_active = bool((gettrace := getattr(sys, 'gettrace')) and gettrace()) +# activate logging for svg +from lib.debug import debug # noqa: E402 # import global variable debug - don't import whole module +debug.enable() # see source how enable/disable logging + # log startup info debug_logging.startup_info(logger, SCRIPTDIR, running_as_frozen, running_from_inkscape, debug_active, debug_type, profiler_type) +# -------------------------------------------------------------------------------------------- + # pop '--extension' from arguments and generate extension class name from extension name # example: --extension=params will instantiate Params() class from lib.extensions. diff --git a/lib/debug.py b/lib/debug.py deleted file mode 100644 index 0b0fa1b7d..000000000 --- a/lib/debug.py +++ /dev/null @@ -1,421 +0,0 @@ -# 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 os -import sys -import atexit # to save svg file on exit -import socket # to check if debugger is running -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 -from .debug_utils import safe_get # mimic get method of dict with default value - -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 - - -# 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.debugger = None - self.wait_attach = True - self.enabled = False - self.last_log_time = None - self.current_layer = None - self.group_stack = [] - - def enable(self, debug_type:str, debug_dir: Path, ini: dict): - # initilize file names and other parameters from DEBUG.toml file - self.debug_dir = debug_dir # directory where debug files are stored - self.debug_log_file = safe_get(ini, "DEBUG", "debug_log_file", default="debug.log") - self.debug_svg_file = safe_get(ini, "DEBUG", "debug_svg_file", default="debug.svg") - self.wait_attach = safe_get(ini, "DEBUG", "wait_attach", default=True) # currently only for vscode - - if debug_type == 'none': - return - - self.debugger = debug_type - self.enabled = True - self.init_log() - self.init_debugger() - self.init_svg() - - def init_log(self): - self.log_file = self.debug_dir / self.debug_log_file - # delete old content - with self.log_file.open("w"): - pass - self.log("Debug logging enabled.") - - # we intentionally disable flakes C901 - function is too complex, beacuse it is used only for debugging - # currently complexity is set 10 see 'make style', this means that function can have max 10 nested blocks, here we have more - # flake8: noqa: C901 - def init_debugger(self): - # ### General debugging notes: - # 1. to enable debugging or profiling copy DEBUG_template.toml to DEBUG.toml and edit it - - # ### How create bash script for offline debugging from console - # 1. in DEBUG.toml set create_bash_script = true - # 2. call inkstitch.py extension from inkscape to create bash script named by bash_file_base in DEBUG.toml - # 3. run bash script from console - - # ### Enable debugging - # 1. set debug_type to one of - vscode, pycharm, pydev, see below for details - # debug_type = vscode - 'debugpy' for vscode editor - # debug_type = pycharm - 'pydevd-pycharm' for pycharm editor - # debug_type = pydev - 'pydevd' for eclipse editor - # 2. set debug_enable = true in DEBUG.toml - # or use command line argument -d in bash script - # or set environment variable INKSTITCH_DEBUG_ENABLE = True or 1 or yes or y - - # ### Enable profiling - # 1. set profiler_type to one of - cprofile, profile, pyinstrument - # profiler_type = cprofile - 'cProfile' profiler - # profiler_type = profile - 'profile' profiler - # profiler_type = pyinstrument- 'pyinstrument' profiler - # 2. set profile_enable = true in DEBUG.toml - # or use command line argument -p in bash script - # or set environment variable INKSTITCH_PROFILE_ENABLE = True or 1 or yes or y - - # ### Miscelaneous notes: - # - to disable debugger when running from inkscape set disable_from_inkscape = true in DEBUG.toml - # - to write debug output to file set debug_to_file = true in DEBUG.toml - # - to change various output file names see DEBUG.toml - # - to disable waiting for debugger to attach (vscode editor) set wait_attach = false in DEBUG.toml - # - to prefer inkscape version of inkex module over pip version set prefer_pip_inkex = false in DEBUG.toml - - # ### - - # ### How to debug Ink/Stitch with LiClipse: - # - # 1. Install LiClipse (liclipse.com) -- no need to install Eclipse first - # 2. Start debug server as described here: http://www.pydev.org/manual_adv_remote_debugger.html - # * follow the "Note:" to enable the debug server menu item - # 3. Copy and edit a file named "DEBUG.toml" from "DEBUG_template.toml" next to inkstitch.py in your git clone - # and set debug_type = pydev - # 4. Run any extension and PyDev will start debugging. - - # ### - - # ### To debug with PyCharm: - - # You must use the PyCharm Professional Edition and _not_ the Community - # Edition. Jetbrains has chosen to make remote debugging a Pro feature. - # To debug Inkscape python extensions, the extension code and Inkscape run - # independently of PyCharm, and only communicate with the debugger via a - # TCP socket. Thus, debugging is "remote," even if it's on the same machine, - # connected via the loopback interface. - # - # 1. pip install pydev_pycharm - # - # pydev_pycharm is versioned frequently. Jetbrains suggests installing - # a version at least compatible with the current build. For example, if your - # PyCharm build, as found in menu PyCharm -> About Pycharm is 223.8617.48, - # you could do: - # pip install pydevd-pycharm~=223.8617.48 - # - # 2. From the Pycharm "Run" menu, choose "Edit Configurations..." and create a new - # configuration. Set "IDE host name:" to "localhost" and "Port:" to 5678. - # You can leave the default settings for all other choices. - # - # 3. Touch a file named "DEBUG.toml" at the top of your git repo, as above - # set debug_type = pycharm - # - # 4. Create a symbolic link in the Inkscape extensions directory to the - # top-level directory of your git repo. On a mac, for example: - # cd ~/Library/Application\ Support/org.inkscape.Inkscape/config/inkscape/extensions/ - # ln -s - # On other architectures it may be: - # cd ~/.config/inkscape/extensions - # ln -s - # Remove any other Ink/Stitch files or references to Ink/Stitch from the - # extensions directory, or you'll see duplicate entries in the Ink/Stitch - # extensions menu in Inkscape. - # - # 5. In Pycharm, either click on the green "bug" icon if visible in the upper - # right or press Ctrl-D to start debugging.The PyCharm debugger pane will - # display the message "Waiting for process connection..." - # - # 6. Do some action in Inkscape which invokes Ink/Stitch extension code, and the - # debugger will be triggered. If you've left "Suspend after connect" checked - # in the Run configuration, PyCharm will pause in the "self.log("Enabled - # PyDev debugger.)" statement, below. Uncheck the box to have it continue - # automatically to your first set breakpoint. - - # ### - - # ### To debug with VS Code - # see: https://code.visualstudio.com/docs/python/debugging#_command-line-debugging - # https://code.visualstudio.com/docs/python/debugging#_debugging-by-attaching-over-a-network-connection - # - # 1. Install the Python extension for VS Code - # pip install debugpy - # 2. create .vscode/launch.json containing: - # "configurations": [ ... - # { - # "name": "Python: Attach", - # "type": "python", - # "request": "attach", - # "connect": { - # "host": "localhost", - # "port": 5678 - # } - # } - # ] - # 3. Touch a file named "DEBUG.toml" at the top of your git repo, as above - # set debug_type = vscode - # 4. Start the debug server in VS Code by clicking on the debug icon in the left pane - # select "Python: Attach" from the dropdown menu and click on the green arrow. - # The debug server will start and connect to already running python processes, - # but immediately exit if no python processes are running. - # - # Notes: - # to see flask server url routes: - # - comment out the line self.disable_logging() in run() of lib/api/server.py - - try: - if self.debugger == 'vscode': - import debugpy - elif self.debugger == 'pycharm': - import pydevd_pycharm - elif self.debugger == 'pydev': - import pydevd - elif self.debugger == 'file': - pass - else: - raise ValueError(f"unknown debugger: '{self.debugger}'") - - except ImportError: - self.log(f"importing debugger failed (debugger disabled) for {self.debugger}") - - # pydevd likes to shout about errors to stderr whether I want it to or not - with open(os.devnull, 'w') as devnull: - stderr = sys.stderr - sys.stderr = devnull - - try: - if self.debugger == 'vscode': - debugpy.listen(('localhost', 5678)) - if self.wait_attach: - print("Waiting for debugger attach") - debugpy.wait_for_client() # wait for debugger to attach - debugpy.breakpoint() # stop here to start normal debugging - elif self.debugger == 'pycharm': - pydevd_pycharm.settrace('localhost', port=5678, stdoutToServer=True, - stderrToServer=True) - elif self.debugger == 'pydev': - pydevd.settrace() - elif self.debugger == 'file': - pass - else: - raise ValueError(f"unknown debugger: '{self.debugger}'") - - except socket.error as error: - self.log("Debugging: connection to pydevd failed: %s", error) - self.log(f"Be sure to run 'Start debugging server' in {self.debugger} to enable debugging.") - else: - self.log(f"Enabled '{self.debugger}' debugger.") - - sys.stderr = stderr - - def init_svg(self): - self.svg = etree.Element("svg", nsmap=inkex.NSS) - atexit.register(self.save_svg) - - def save_svg(self): - tree = etree.ElementTree(self.svg) - debug_svg = self.debug_dir / self.debug_svg_file - tree.write(str(debug_svg)) # lxml <5.0.0 does not support Path objects - - @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() - timestamp = now.isoformat() - self.last_log_time = now - - with self.log_file.open("a") as logfile: - print(timestamp, message % args, file=logfile) - logfile.flush() - - # 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() diff --git a/lib/debug/__init__.py b/lib/debug/__init__.py new file mode 100644 index 000000000..8093e6a04 --- /dev/null +++ b/lib/debug/__init__.py @@ -0,0 +1,11 @@ +# Authors: see git history +# +# Copyright (c) 2010 Authors +# Licensed under the GNU GPL version 3.0 or later. See the file LICENSE for details. + + +# this enable: +# from .debug import debug +# from ..debug import debug +from .debug import debug + diff --git a/lib/debug/debug.py b/lib/debug/debug.py new file mode 100644 index 000000000..2d9696cfd --- /dev/null +++ b/lib/debug/debug.py @@ -0,0 +1,240 @@ +# 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() diff --git a/lib/debug/debugger.py b/lib/debug/debugger.py new file mode 100644 index 000000000..01f4033db --- /dev/null +++ b/lib/debug/debugger.py @@ -0,0 +1,192 @@ +# Authors: see git history +# +# Copyright (c) 2010 Authors +# Licensed under the GNU GPL version 3.0 or later. See the file LICENSE for details. + + +# ### General debugging notes: +# 1. to enable debugging or profiling copy DEBUG_template.toml to DEBUG.toml and edit it + +# ### How create bash script for offline debugging from console +# 1. in DEBUG.toml set create_bash_script = true +# 2. call inkstitch.py extension from inkscape to create bash script named by bash_file_base in DEBUG.toml +# 3. run bash script from console + +# ### Enable debugging +# 1. set debug_type to one of - vscode, pycharm, pydev, see below for details +# debug_type = vscode - 'debugpy' for vscode editor +# debug_type = pycharm - 'pydevd-pycharm' for pycharm editor +# debug_type = pydev - 'pydevd' for eclipse editor +# 2. set debug_enable = true in DEBUG.toml +# or use command line argument -d in bash script +# or set environment variable INKSTITCH_DEBUG_ENABLE = True or 1 or yes or y + +# ### Enable profiling +# 1. set profiler_type to one of - cprofile, profile, pyinstrument +# profiler_type = cprofile - 'cProfile' profiler +# profiler_type = profile - 'profile' profiler +# profiler_type = pyinstrument- 'pyinstrument' profiler +# 2. set profile_enable = true in DEBUG.toml +# or use command line argument -p in bash script +# or set environment variable INKSTITCH_PROFILE_ENABLE = True or 1 or yes or y + +# ### Miscelaneous notes: +# - to disable debugger when running from inkscape set disable_from_inkscape = true in DEBUG.toml +# - to change various output file names see DEBUG.toml +# - to disable waiting for debugger to attach (vscode editor) set wait_attach = false in DEBUG.toml +# - to prefer inkscape version of inkex module over pip version set prefer_pip_inkex = false in DEBUG.toml + +# ### + +# ### How to debug Ink/Stitch with LiClipse: +# +# 1. Install LiClipse (liclipse.com) -- no need to install Eclipse first +# 2. Start debug server as described here: http://www.pydev.org/manual_adv_remote_debugger.html +# * follow the "Note:" to enable the debug server menu item +# 3. Copy and edit a file named "DEBUG.toml" from "DEBUG_template.toml" next to inkstitch.py in your git clone +# and set debug_type = pydev +# 4. Run any extension and PyDev will start debugging. + +# ### + +# ### To debug with PyCharm: + +# You must use the PyCharm Professional Edition and _not_ the Community +# Edition. Jetbrains has chosen to make remote debugging a Pro feature. +# To debug Inkscape python extensions, the extension code and Inkscape run +# independently of PyCharm, and only communicate with the debugger via a +# TCP socket. Thus, debugging is "remote," even if it's on the same machine, +# connected via the loopback interface. +# +# 1. pip install pydev_pycharm +# +# pydev_pycharm is versioned frequently. Jetbrains suggests installing +# a version at least compatible with the current build. For example, if your +# PyCharm build, as found in menu PyCharm -> About Pycharm is 223.8617.48, +# you could do: +# pip install pydevd-pycharm~=223.8617.48 +# +# 2. From the Pycharm "Run" menu, choose "Edit Configurations..." and create a new +# configuration. Set "IDE host name:" to "localhost" and "Port:" to 5678. +# You can leave the default settings for all other choices. +# +# 3. Touch a file named "DEBUG.toml" at the top of your git repo, as above +# set debug_type = pycharm +# +# 4. Create a symbolic link in the Inkscape extensions directory to the +# top-level directory of your git repo. On a mac, for example: +# cd ~/Library/Application\ Support/org.inkscape.Inkscape/config/inkscape/extensions/ +# ln -s +# On other architectures it may be: +# cd ~/.config/inkscape/extensions +# ln -s +# Remove any other Ink/Stitch files or references to Ink/Stitch from the +# extensions directory, or you'll see duplicate entries in the Ink/Stitch +# extensions menu in Inkscape. +# +# 5. In Pycharm, either click on the green "bug" icon if visible in the upper +# right or press Ctrl-D to start debugging.The PyCharm debugger pane will +# display the message "Waiting for process connection..." +# +# 6. Do some action in Inkscape which invokes Ink/Stitch extension code, and the +# debugger will be triggered. If you've left "Suspend after connect" checked +# in the Run configuration, PyCharm will pause in the "self.log("Enabled +# PyDev debugger.)" statement, below. Uncheck the box to have it continue +# automatically to your first set breakpoint. + +# ### + +# ### To debug with VS Code +# see: https://code.visualstudio.com/docs/python/debugging#_command-line-debugging +# https://code.visualstudio.com/docs/python/debugging#_debugging-by-attaching-over-a-network-connection +# +# 1. Install the Python extension for VS Code +# pip install debugpy +# 2. create .vscode/launch.json containing: +# "configurations": [ ... +# { +# "name": "Python: Attach", +# "type": "python", +# "request": "attach", +# "connect": { +# "host": "localhost", +# "port": 5678 +# } +# } +# ] +# 3. Touch a file named "DEBUG.toml" at the top of your git repo, as above +# set debug_type = vscode +# 4. Start the debug server in VS Code by clicking on the debug icon in the left pane +# select "Python: Attach" from the dropdown menu and click on the green arrow. +# The debug server will start and connect to already running python processes, +# but immediately exit if no python processes are running. +# +# Notes: +# to see flask server url routes: +# - comment out the line self.disable_logging() in run() of lib/api/server.py + +import os +import sys + +import socket # to check if debugger is running + +from .utils import safe_get # mimic get method of dict with default value + +import logging + +logger = logging.getLogger("inkstitch") + +# we intentionally disable flakes C901 - function is too complex, beacuse it is used only for debugging +# currently complexity is set 10 see 'make style', this means that function can have max 10 nested blocks, here we have more +# flake8: noqa: C901 +def init_debugger(debug_type:str, ini: dict): + if debug_type == 'none': + return + + wait_attach = safe_get(ini, "DEBUG", "wait_attach", default=True) # currently only for vscode + debugger = debug_type + + try: + if debugger == 'vscode': + import debugpy + elif debugger == 'pycharm': + import pydevd_pycharm + elif debugger == 'pydev': + import pydevd + elif debugger == 'file': + pass + else: + raise ValueError(f"unknown debugger: '{debugger}'") + + except ImportError: + logger.info(f"importing debugger failed (debugger disabled) for {debugger}") + + # pydevd likes to shout about errors to stderr whether I want it to or not + with open(os.devnull, 'w') as devnull: + stderr = sys.stderr + sys.stderr = devnull + + try: + if debugger == 'vscode': + debugpy.listen(('localhost', 5678)) + if wait_attach: + print("Waiting for debugger attach") + debugpy.wait_for_client() # wait for debugger to attach + debugpy.breakpoint() # stop here to start normal debugging + elif debugger == 'pycharm': + pydevd_pycharm.settrace('localhost', port=5678, stdoutToServer=True, + stderrToServer=True) + elif debugger == 'pydev': + pydevd.settrace() + elif debugger == 'file': + pass + else: + raise ValueError(f"unknown debugger: '{debugger}'") + + except socket.error as error: + logger.info("Debugging: connection to pydevd failed: %s", error) + logger.info(f"Be sure to run 'Start debugging server' in {debugger} to enable debugging.") + else: + logger.info(f"Enabled '{debugger}' debugger.") + + sys.stderr = stderr diff --git a/lib/debug_logging.py b/lib/debug/logging.py similarity index 57% rename from lib/debug_logging.py rename to lib/debug/logging.py index 7d6a655f2..81029ff9b 100644 --- a/lib/debug_logging.py +++ b/lib/debug/logging.py @@ -54,7 +54,7 @@ # ------------------------------------------- # - root - main logger that controls all other loggers # - inkstitch - suggested name for inkstitch -# - inkstitch.xyz - suggested name for inkstitch submodule xyz if needed +# - inkstitch.debug - uses in debug module with svg file saving # # third-party loggers: # -------------------- @@ -63,15 +63,162 @@ # # -------------------------------------------------------------------------------------------- - -import logging -import warnings +import os +import sys from pathlib import Path -from .debug_utils import safe_get # mimic get method of dict with default value +if sys.version_info >= (3, 11): + import tomllib # built-in in Python 3.11+ +else: + import tomli as tomllib + +import warnings # to control python warnings +import logging # to configure logging +import logging.config # to configure logging from dict + +from .utils import safe_get # mimic get method of dict with default value logger = logging.getLogger('inkstitch') + +# -------------------------------------------------------------------------------------------- +# activate_logging - configure logging for inkstitch application +def activate_logging(running_as_frozen: bool, ini: dict, SCRIPTDIR: Path): + if running_as_frozen: # in release mode + activate_for_frozen() + else: # in development + activate_for_development(ini, SCRIPTDIR) + + +# Configure logging in frozen (release) mode of application: +# in release mode normally we want to ignore all warnings and logging, but we can enable it by setting environment variables +# - INKSTITCH_LOGLEVEL - logging level: +# 'DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL' +# - PYTHONWARNINGS, -W - warnings action controlled by python +# actions: 'error', 'ignore', 'always', 'default', 'module', 'once' +def activate_for_frozen(): + loglevel = os.environ.get('INKSTITCH_LOGLEVEL') # read log level from environment variable or None + docpath = os.environ.get('DOCUMENT_PATH') # read document path from environment variable (set by inkscape) or None + + if docpath is not None and loglevel is not None and loglevel.upper() in ['DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL']: + + # end user enabled logging & warnings are redirect output to input_svg.inkstitch.log + + vars = { + 'loglevel': loglevel.upper(), + 'logfilename': Path(docpath).with_suffix('.inkstitch.log') # log file is created in document path + } + config = expand_variables(frozen_config, vars) + + # dictConfig has access to top level variables, dict contains: ext://__main__.var + # - restriction: variable must be last token in string - very limited functionality, avoid using it + + # here is logging activated, so we can use logger + logging.config.dictConfig(config) # configure root logger from dict + + logging.captureWarnings(True) # capture all warnings to log file with level WARNING + else: + logging.disable() # globally disable all logging of all loggers + warnings.simplefilter('ignore') # ignore all warnings + + +# in development mode we want to use configuration from some LOGGING.toml file +def activate_for_development(ini: dict, SCRIPTDIR: Path): + logging_config_file = safe_get(ini, "LOGGING", "log_config_file", default=None) + vars = {'SCRIPTDIR': SCRIPTDIR} # dynamic data for logging configuration + + if logging_config_file is not None: + logging_config_file = Path(logging_config_file) + if logging_config_file.exists(): + with open(logging_config_file, "rb") as f: + devel_config = tomllib.load(f) # -> dict + else: + raise FileNotFoundError(f"{logging_config_file} file not found") + else: # if LOGGING.toml file does not exist, use default logging configuration + vars['loglevel'] = 'DEBUG' # set log level to DEBUG + vars['logfilename'] = SCRIPTDIR / "inkstitch.log" # log file is created in current directory + devel_config = development_config # get TOML configuration from module + + configure_logging(devel_config, ini, vars) # initialize and activate logging configuration + + logger.info("Running in development mode") + logger.info(f"Using logging configuration from file: {logging_config_file}") + logger.debug(f"Logging configuration: {devel_config = }") + + +# -------------------------------------------------------------------------------------------- +# configure logging from dictionary: +# - capture all warnings to log file with level WARNING - depends on warnings_capture +# - set action for warnings: 'error', 'ignore', 'always', 'default', 'module', 'once' - depends on warnings_action +def configure_logging(config: dict, ini: dict, vars: dict): + config = expand_variables(config, vars) + + # here is logging activated, so now we can use logger + logging.config.dictConfig(config) # configure loggers from dict - using loglevel, logfilename + + warnings_capture = config.get('warnings_capture', True) + logging.captureWarnings(warnings_capture) # capture warnings to log file with level WARNING + warnings_action = config.get('warnings_action', 'default').lower() + warnings.simplefilter(warnings_action) # set action for warnings: 'error', 'ignore', 'always', ... + + disable_logging = safe_get(ini, "LOGGING", "disable_logging", default=False) + if disable_logging: + logger.warning("Logging is disabled by configuration in ini file.") + logging.disable() # globally disable all logging of all loggers + + +# Evaluate evaluation of variables in logging configuration: +# "handlers": { +# "file": { +# "filename": "%(SCRIPTDIR)s/xxx.log", # <--- replace %(SCRIPTDIR)s -> script path +# "%(logfilename)s", # <--- replace %(logfilename)s -> log file name +# ... +# "loggers": { +# "inkstitch": { +# "level": "%(loglevel)s", # <--- replace %(loglevel)s -> log level +# ... +# - for external configuration file (eg. LOGGING.toml) we cannot pass parameters such as the current directory. +# - we do: filename = "%(SCRIPTDIR)s/inkstitch.log" -> filename = "path/inkstitch.log" +# - safety: we can use only predefined variables in myvars, otherwise we get KeyError +# - return modified configuration +# - create logging directory if not exists, directory cannot end with ":" to avoid error with ext:// keys +def expand_variables(cfg: dict, vars: dict): + for k, v in cfg.get('loggers', {}).items(): + if 'level' in v: # replace level in logger + cfg['loggers'][k]['level'] = v['level'] % vars + + for k, v in cfg.get('handlers', {}).items(): + if 'filename' in v: # replace filename in handler + orig_filename = v['filename'] # original filename for later comparison + cfg['handlers'][k]['filename'] = v['filename'] % vars + # create logging directory only if substitution was done, we need to avoid ext:// cfg:// keys + if orig_filename != cfg['handlers'][k]['filename']: + dirname = Path(cfg['handlers'][k]['filename']).parent + if not dirname.exists(): + # inform user about creating logging directory, otherwise it is silent, logging is not yet active + print(f"DEBUG: Creating logging directory: {dirname} ", file=sys.stderr) + dirname.mkdir(parents=True, exist_ok=True) + return cfg + + +def startup_info(logger: logging.Logger, SCRIPTDIR: Path, running_as_frozen: bool, running_from_inkscape: bool, + debug_active: bool, debug_type: str, profiler_type: str): + logger.info(f"Running as frozen: {running_as_frozen}") + logger.info(f"Running from inkscape: {running_from_inkscape}") + logger.info(f"Debugger active: {debug_active}") + logger.info(f"Debugger type: {debug_type!r}") + logger.info(f"Profiler type: {profiler_type!r}") + + # log Python version, platform, command line arguments, sys.path + import sys + import platform + + logger.info(f"Python version: {sys.version}") + logger.info(f"Platform: {platform.platform()}") + logger.info(f"Command line arguments: {sys.argv}") + logger.debug(f"sys.path: {sys.path}") + + # example of logger configuration for release mode: # ------------------------------------------------ # - logger suitable for release mode, where we assume that the directory of the input SVG file allows writing the log file. @@ -91,18 +238,19 @@ frozen_config = { "file": { "class": "logging.FileHandler", # type - file output "formatter": "simple", # use formatter 'simple' for handler 'file' - "filename": "ext://__main__.logfilename", # access variable logfilename + "filename": "%(logfilename)s", # access variable logfilename "mode": "w" # create new file } }, "loggers": { "root": { # top level logger - "level": "ext://__main__.loglevel", # access variable loglevel + "level": "%(loglevel)s", # access variable loglevel "handlers": ["file"], # use handler 'file' for logger } }, } +# --------------------------------------------------- # example of implicit developer logger configuration: # --------------------------------------------------- # - configured two loggers: root and inkstitch loggers @@ -125,81 +273,19 @@ development_config = { "file": { "class": "logging.FileHandler", # type - file output "formatter": "simple", # use formatter 'simple' for handler 'file' - "filename": "ext://__main__.logfilename", # ext: --> access variable logfilename + "filename": "%(logfilename)s", # ext: --> access variable logfilename "mode": "w" # create new file }, }, "loggers": { # configure loggers "inkstitch": { # specific logger to inkstitch application - "level": "ext://__main__.loglevel", # ext: --> access variable loglevel + "level": "%(loglevel)s", # ext: --> access variable loglevel "handlers": ["file"], # use handler 'file' for logger "propagate": False, # don't propagate to root logger - otherwise all will be logged twice }, "root": { # top level logger - "level": "ext://__main__.loglevel", # ext: --> access variable loglevel + "level": "%(loglevel)s", # ext: --> access variable loglevel "handlers": ["file"], # use handler 'file' for logger } }, } - - -# -------------------------------------------------------------------------------------------- -# configure logging from dictionary: -# - capture all warnings to log file with level WARNING - depends on warnings_capture -# - set action for warnings: 'error', 'ignore', 'always', 'default', 'module', 'once' - depends on warnings_action -def configure_logging(config:dict, ini:dict, SCRIPTDIR:Path): - # replace %(SCRIPTDIR)s -> script path in filenames - config = evaluate_filenames(config, {'SCRIPTDIR': SCRIPTDIR}) - logging.config.dictConfig(config) # configure loggers from dict - using loglevel, logfilename - - warnings_capture = config.get('warnings_capture', True) - logging.captureWarnings(warnings_capture) # capture warnings to log file with level WARNING - warnings_action = config.get('warnings_action', 'default').lower() - warnings.simplefilter(warnings_action) # set action for warnings: 'error', 'ignore', 'always', ... - disable_logging = safe_get(ini, "LOGGING", "disable_logging", default=False) - if disable_logging: - logger.warning("Logging is disabled by configuration in ini file.") - logging.disable() # globally disable all logging of all loggers - - -# Evaluate filenames in logging configuration using dictionary argument: myvars. -# - for external configuration file (eg. LOGGING.toml) we cannot pass parameters such as the current directory. -# - we do: filename = "%(SCRIPTDIR)s/inkstitch.log" -> filename = "path/inkstitch.log" -# -# - example of usage: -# "handlers": { -# "file": { -# "class": "logging.FileHandler", -# "filename": "%(SCRIPTDIR)s/xxx.log", # <--- replace %(SCRIPTDIR)s -> script path -# } -# } -# -# returns: logging configuration with evaluated filenames -def evaluate_filenames(cfg: dict, myvars: dict): - for k, v in cfg.get('handlers', {}).items(): - if 'filename' in v: # replace filename in handler - cfg['handlers'][k]['filename'] = v['filename'] % myvars - - # create logging directory if not exists - dirname = Path(cfg['handlers'][k]['filename']).parent - if not dirname.exists(): - dirname.mkdir(parents=True, exist_ok=True) - return cfg - - -def startup_info(logger:logging.Logger, SCRIPTDIR:Path, running_as_frozen:bool, running_from_inkscape:bool, - debug_active:bool, debug_type:str, profiler_type:str): - logger.info(f"Running as frozen: {running_as_frozen}") - logger.info(f"Running from inkscape: {running_from_inkscape}") - logger.info(f"Debugger active: {debug_active}") - logger.info(f"Debugger type: {debug_type}") - logger.info(f"Profiler type: {profiler_type}") - - # log Python version, platform, command line arguments, sys.path - import sys - import platform - - logger.info(f"Python version: {sys.version}") - logger.info(f"Platform: {platform.platform()}") - logger.info(f"Command line arguments: {sys.argv}") - logger.info(f"sys.path: {sys.path}") diff --git a/lib/debug_utils.py b/lib/debug/utils.py similarity index 96% rename from lib/debug_utils.py rename to lib/debug/utils.py index 998e2ad87..29daea68b 100644 --- a/lib/debug_utils.py +++ b/lib/debug/utils.py @@ -3,20 +3,23 @@ # Copyright (c) 2010 Authors # Licensed under the GNU GPL version 3.0 or later. See the file LICENSE for details. -import os -import sys -from pathlib import Path # to work with paths as objects - # this file is without: import inkex # - we need dump argv and sys.path as is on startup from inkscape # - later sys.path may be modified that influences importing inkex (see prefere_pip_inkex) +import os +import sys +from pathlib import Path # to work with paths as objects +import logging + +logger = logging.getLogger("inkstitch") + # safe_get - get value from nested dictionary, return default if key does not exist # - to read nested values from dict - mimic get method of dict with default value # example: safe_get({'a': {'b': 1}}, 'a', 'b') -> 1 # safe_get({'a': {'b': 1}}, 'a', 'c', default=2) -> 2 -def safe_get(dictionary:dict, *keys, default=None): +def safe_get(dictionary: dict, *keys, default=None): for key in keys: if key not in dictionary: return default @@ -136,7 +139,6 @@ def reorder_sys_path(): ''' change sys.path to prefer pip installed inkex over inkscape bundled inkex ''' - # see static void set_extensions_env() in inkscape/src/inkscape-main.cpp # what we do: # - move inkscape extensions path to the end of sys.path @@ -169,10 +171,6 @@ def resolve_debug_type(ini: dict): if not debug_enable: debug_type = 'none' - debug_to_file = safe_get(ini, "DEBUG", "debug_to_file", default=False) # write debug output to file - if debug_to_file and debug_type == 'none': - debug_type = 'file' - return debug_type @@ -209,7 +207,9 @@ def profile(profiler_type, profile_dir: Path, ini: dict, extension, remaining_ar # create directory if not exists dirname = profile_file_path.parent - dirname.mkdir(parents=True, exist_ok=True) + if not dirname.exists(): + logger.debug(f"Creating directory for profile output: {dirname}") + dirname.mkdir(parents=True, exist_ok=True) if profiler_type == 'cprofile': with_cprofile(extension, remaining_args, profile_file_path) @@ -221,7 +221,7 @@ def profile(profiler_type, profile_dir: Path, ini: dict, extension, remaining_ar raise ValueError(f"unknown profiler type: '{profiler_type}'") -def with_cprofile(extension, remaining_args, profile_file_path:Path): +def with_cprofile(extension, remaining_args, profile_file_path: Path): ''' profile with cProfile ''' @@ -242,7 +242,7 @@ def with_cprofile(extension, remaining_args, profile_file_path:Path): file=sys.stderr) -def with_profile(extension, remaining_args, profile_file_path:Path): +def with_profile(extension, remaining_args, profile_file_path: Path): ''' profile with profile ''' @@ -261,7 +261,7 @@ def with_profile(extension, remaining_args, profile_file_path:Path): file=sys.stderr) -def with_pyinstrument(extension, remaining_args, profile_file_path:Path): +def with_pyinstrument(extension, remaining_args, profile_file_path: Path): ''' profile with pyinstrument ''' diff --git a/requirements.txt b/requirements.txt index 9869ec7d0..7a25792e9 100644 --- a/requirements.txt +++ b/requirements.txt @@ -13,7 +13,10 @@ appdirs numpy jinja2>2.9 requests -toml + +# toml release 0.10.2 still buggy for heterogenous arrays +# tomli is built as tomllib in python 3.11 and higher +tomli # colormath - last official release: 3.0.0 # we need already submitted fixes - so let's grab them from the github repository From c63086307a1ae378a32f397ee0ee532303a217fa Mon Sep 17 00:00:00 2001 From: karnigen Date: Sat, 23 Mar 2024 12:40:19 +0100 Subject: [PATCH 08/12] use of alternate logging in some cases --- lib/debug/debug.py | 11 ++++++++--- 1 file changed, 8 insertions(+), 3 deletions(-) diff --git a/lib/debug/debug.py b/lib/debug/debug.py index 2d9696cfd..69034c4e6 100644 --- a/lib/debug/debug.py +++ b/lib/debug/debug.py @@ -17,7 +17,10 @@ from ..svg import line_strings_to_path from ..svg.tags import INKSCAPE_GROUPMODE, INKSCAPE_LABEL import logging -logger = logging.getLogger("inkstitch.debug") +logger = logging.getLogger("inkstitch.debug") # create module logger with name 'inkstitch.debug' + +# to log messages if previous debug logger is not enabled +logger_inkstich = logging.getLogger("inkstitch") # create module logger with name 'inkstitch' # -------------------------------------------------------------------------------------------- @@ -86,7 +89,8 @@ class Debug(object): self.log("Logging enabled") self.init_svg() else: - logger.info("No handlers in logger, cannot enable logging and svg file creation") + # use alternative logger to log message if logger has no handlers + logger_inkstich.info("No handlers in logger, cannot enable logging and svg file creation") def init_svg(self): self.svg = etree.Element("svg", nsmap=inkex.NSS) @@ -101,7 +105,8 @@ class Debug(object): 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") + # use alternative logger to log message if logger has no handlers + logger_inkstich.info("No file handler in logger cannot save svg file") @check_enabled @unwrap_arguments From cb1eb506f3fdd73c7efcb8e10e46ab8c97f94961 Mon Sep 17 00:00:00 2001 From: karnigen Date: Sat, 23 Mar 2024 18:43:06 +0100 Subject: [PATCH 09/12] updated debug logger [no ci] --- LOGGING_template.toml | 4 ++-- lib/debug/debug.py | 28 +++++++++++++++++----------- lib/debug/logging.py | 8 ++++---- 3 files changed, 23 insertions(+), 17 deletions(-) diff --git a/LOGGING_template.toml b/LOGGING_template.toml index 27aadcb3b..85e3d2a9b 100644 --- a/LOGGING_template.toml +++ b/LOGGING_template.toml @@ -56,9 +56,9 @@ disable_existing_loggers = false ### used for: logger = logging.getLogger("inkstitch.debug") ### - use quotes for the logger name with dots, otherwise it will be treated as a table subsection ### - [loggers.inkstitch.debug] is not the same as [loggers.'inkstitch.debug'] -### - to disable the logger, comment out handlers [loggers.'inkstitch.debug'] - level = "DEBUG" + level = "DEBUG" # to enable the logger, seems to be the default + # level = "CRITICAL" # to disable the logger handlers = [ "file_inkstitch_debug",] propagate = false diff --git a/lib/debug/debug.py b/lib/debug/debug.py index 69034c4e6..ab5132e4e 100644 --- a/lib/debug/debug.py +++ b/lib/debug/debug.py @@ -79,15 +79,24 @@ class Debug(object): self.last_log_time = None self.current_layer = None self.group_stack = [] + self.svg_filename = None def enable(self): + # determine svg filename from logger + if len(logger.handlers) > 0 and isinstance(logger.handlers[0], logging.FileHandler): + # determine filename of svg file from logger + filename = Path(logger.handlers[0].baseFilename) + self.svg_filename = filename.with_suffix(".svg") + self.svg_filename.unlink(missing_ok=True) # remove existing svg file + # 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 + # - enabled only if logger first handler is FileHandler + # to disable "inkstitch.debug" simply set logging level to CRITICAL + if logger.isEnabledFor(logging.INFO) and self.svg_filename is not None: self.enabled = True - self.log("Logging enabled") + self.log(f"Logging enabled with svg file: {self.svg_filename}") self.init_svg() + else: # use alternative logger to log message if logger has no handlers logger_inkstich.info("No handlers in logger, cannot enable logging and svg file creation") @@ -97,16 +106,13 @@ class Debug(object): 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}") + if self.enabled and self.svg_filename is not None: + self.log(f"Writing svg file: {self.svg_filename}") tree = etree.ElementTree(self.svg) - tree.write(str(svg_file)) # lxml <5.0.0 does not support Path objects + tree.write(str(self.svg_filename)) # lxml <5.0.0 does not support Path objects, requires string else: # use alternative logger to log message if logger has no handlers - logger_inkstich.info("No file handler in logger cannot save svg file") + logger_inkstich.info(f"Saving to svg file is not activated {self.svg_filename=}") @check_enabled @unwrap_arguments diff --git a/lib/debug/logging.py b/lib/debug/logging.py index 81029ff9b..68557975e 100644 --- a/lib/debug/logging.py +++ b/lib/debug/logging.py @@ -102,7 +102,7 @@ def activate_for_frozen(): if docpath is not None and loglevel is not None and loglevel.upper() in ['DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL']: - # end user enabled logging & warnings are redirect output to input_svg.inkstitch.log + # The end user enabled logging and warnings are redirected to the input_svg.inkstitch.log file. vars = { 'loglevel': loglevel.upper(), @@ -113,7 +113,7 @@ def activate_for_frozen(): # dictConfig has access to top level variables, dict contains: ext://__main__.var # - restriction: variable must be last token in string - very limited functionality, avoid using it - # here is logging activated, so we can use logger + # After this operation, logging will be activated, so we can use the logger. logging.config.dictConfig(config) # configure root logger from dict logging.captureWarnings(True) # capture all warnings to log file with level WARNING @@ -153,7 +153,7 @@ def activate_for_development(ini: dict, SCRIPTDIR: Path): def configure_logging(config: dict, ini: dict, vars: dict): config = expand_variables(config, vars) - # here is logging activated, so now we can use logger + # After this operation, logging will be activated, so we can use the logger. logging.config.dictConfig(config) # configure loggers from dict - using loglevel, logfilename warnings_capture = config.get('warnings_capture', True) @@ -163,7 +163,7 @@ def configure_logging(config: dict, ini: dict, vars: dict): disable_logging = safe_get(ini, "LOGGING", "disable_logging", default=False) if disable_logging: - logger.warning("Logging is disabled by configuration in ini file.") + logger.warning(f"Logging is disabled by configuration in ini file. {disable_logging = }") logging.disable() # globally disable all logging of all loggers From b2325f943626428f6cda0799595a6cf2bee695d1 Mon Sep 17 00:00:00 2001 From: karnigen Date: Sun, 24 Mar 2024 14:30:59 +0100 Subject: [PATCH 10/12] logging update --- DEBUG_template.toml | 2 ++ LOGGING_template.toml | 5 +++-- inkstitch.py | 9 +++++---- lib/debug/debugger.py | 4 ++-- lib/debug/logging.py | 2 +- lib/debug/utils.py | 2 +- 6 files changed, 14 insertions(+), 10 deletions(-) diff --git a/DEBUG_template.toml b/DEBUG_template.toml index 747916027..1822902c7 100644 --- a/DEBUG_template.toml +++ b/DEBUG_template.toml @@ -1,3 +1,5 @@ +### customize this file and save as DEBUG.toml + [LIBRARY] ### use the pip installed version of inkex.py, default: true # prefer_pip_inkex = false diff --git a/LOGGING_template.toml b/LOGGING_template.toml index 85e3d2a9b..3c90cf584 100644 --- a/LOGGING_template.toml +++ b/LOGGING_template.toml @@ -1,7 +1,8 @@ +### customize this file and save as LOGGING.toml ### logging/warning template for inkstitch ### format: toml ### enable config file in DEBUG.toml: log_config_file -### + ### warnings.simplefilter(action), default: "default" ### - possible values: "error", "ignore", "always", "default", "module", "once" warnings_action = "default" @@ -13,7 +14,7 @@ warnings_capture = true ### mandatory, must be an integer and 1 version = 1 -### disable loggers not specified here true/false - may be overrided by root logger +### disable loggers activated before the configuration is loaded disable_existing_loggers = false ### define the loggers, handlers, formatters, filters diff --git a/inkstitch.py b/inkstitch.py index 7d9860105..4c086a039 100644 --- a/inkstitch.py +++ b/inkstitch.py @@ -28,7 +28,7 @@ logger = logging.getLogger("inkstitch") # create module logger with name 'inks # TODO --- temporary --- catch old DEBUG.ini file and inform user to reformat it to DEBUG.toml old_debug_ini = SCRIPTDIR / "DEBUG.ini" if old_debug_ini.exists(): - print("ERROR: old DEBUG.ini exists, please reformat it to DEBUG.toml and remove DEBUG.ini file") + print("ERROR: old DEBUG.ini exists, please reformat it to DEBUG.toml and remove DEBUG.ini file", file=sys.stderr) exit(1) # --- end of temporary --- @@ -57,9 +57,9 @@ if len(sys.argv) < 2: dlg.ShowModal() dlg.Destroy() except ImportError: - print(msg) + print(msg, file=sys.stderr) else: - print(msg) + print(msg, file=sys.stderr) exit(1) # activate logging - must be done before any logging is done @@ -109,8 +109,9 @@ if debug_type != 'none': debug_active = bool((gettrace := getattr(sys, 'gettrace')) and gettrace()) # activate logging for svg +# we need to import only after possible modification of sys.path, we disable here flake8 E402 from lib.debug import debug # noqa: E402 # import global variable debug - don't import whole module -debug.enable() # see source how enable/disable logging +debug.enable() # perhaps it would be better to find a more relevant name; in fact, it's about logging and svg creation. # log startup info debug_logging.startup_info(logger, SCRIPTDIR, running_as_frozen, running_from_inkscape, debug_active, debug_type, profiler_type) diff --git a/lib/debug/debugger.py b/lib/debug/debugger.py index 01f4033db..11293c8ac 100644 --- a/lib/debug/debugger.py +++ b/lib/debug/debugger.py @@ -1,6 +1,6 @@ # Authors: see git history # -# Copyright (c) 2010 Authors +# Copyright (c) 2024 Authors # Licensed under the GNU GPL version 3.0 or later. See the file LICENSE for details. @@ -170,7 +170,7 @@ def init_debugger(debug_type:str, ini: dict): if debugger == 'vscode': debugpy.listen(('localhost', 5678)) if wait_attach: - print("Waiting for debugger attach") + print("Waiting for debugger attach", file=sys.stderr) debugpy.wait_for_client() # wait for debugger to attach debugpy.breakpoint() # stop here to start normal debugging elif debugger == 'pycharm': diff --git a/lib/debug/logging.py b/lib/debug/logging.py index 68557975e..c83ed79f1 100644 --- a/lib/debug/logging.py +++ b/lib/debug/logging.py @@ -1,6 +1,6 @@ # Authors: see git history # -# Copyright (c) 2010 Authors +# Copyright (c) 2024 Authors # Licensed under the GNU GPL version 3.0 or later. See the file LICENSE for details. # basic info for inkstitch logging: diff --git a/lib/debug/utils.py b/lib/debug/utils.py index 29daea68b..9618d173b 100644 --- a/lib/debug/utils.py +++ b/lib/debug/utils.py @@ -1,6 +1,6 @@ # Authors: see git history # -# Copyright (c) 2010 Authors +# Copyright (c) 2024 Authors # Licensed under the GNU GPL version 3.0 or later. See the file LICENSE for details. # this file is without: import inkex From c08f4600d45795386a63b485b673555eeb9c03e2 Mon Sep 17 00:00:00 2001 From: karnigen Date: Sun, 24 Mar 2024 16:16:48 +0100 Subject: [PATCH 11/12] updated notes --- requirements.txt | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/requirements.txt b/requirements.txt index 7a25792e9..16826108f 100644 --- a/requirements.txt +++ b/requirements.txt @@ -1,8 +1,14 @@ +# Assuming pyembroidery is installed in parent directory of inkstitch. +# Maybe it would be better to install PyEmbroidery as a submodule and automatically update it, +# but the .gitignore file should be updated to ignore the build directory. ./pyembroidery # get up to date inkex version (Febuary 10, 2024) inkex @ git+https://gitlab.com/inkscape/extensions.git@8d51d7449d73096382c2f39e726eddc4f9bbcfc4 +# for linux user it may be tricky to install wxPython from sources +# prebuilt packages: https://wxpython.org/pages/downloads/index.html +# https://extras.wxpython.org/wxPython4/extras/linux/gtk3/ wxPython>=4.1.1 backports.functools_lru_cache From 5cbe8268a47e191bf643e5577426b52e2f7ab023 Mon Sep 17 00:00:00 2001 From: karnigen Date: Wed, 17 Apr 2024 10:01:37 +0200 Subject: [PATCH 12/12] updated notes about logging --- lib/debug/logging.py | 21 ++++++++++++--------- 1 file changed, 12 insertions(+), 9 deletions(-) diff --git a/lib/debug/logging.py b/lib/debug/logging.py index c83ed79f1..4d3683b6e 100644 --- a/lib/debug/logging.py +++ b/lib/debug/logging.py @@ -7,16 +7,19 @@ # --------------------------------- # some idea can be found in: Modern Python logging - https://www.youtube.com/watch?v=9L77QExPmI0 # -# logging vs warnings (ChatGPT) -# ----------------------------- -# warnings - a built-in mechanism for alerting developers to potential issues or deprecated features within their code. -# logging - to track events, errors, and other information relevant to the program's operation. -# Developers typically use logging to understand how their program behaves during execution, diagnose issues, -# and monitor performance. +# logging vs warnings +# ------------------- +# warnings - see https://docs.python.org/3/library/warnings.html +# logging - see https://docs.python.org/3/library/logging.html +# +# In simplified terms, use "warning" to alert that a specific function is deprecated, and in all other cases, use "logging". +# Warnings are primarily intended for libraries where there's a newer solution available, but for backward compatibility +# reasons, the old functionality is retained. +# +# In complex applications like Inkstitch, it might be sensible to exclusively use one method, namely "logging", +# to unify and simplify the messaging system of such a system. # -# Inkstitch is application for Inkscape, so it is not a library, so we use logging for all messages. # - # root logger: # ------------ # - The primary logger orchestrates all other loggers through logging.xxx() calls. @@ -24,7 +27,7 @@ # - It can easily disable all loggers by invoking logging.disable() and channel all warnings to logging # by setting logging.captureWarnings(True) with the level WARNING. # - The configuration of all loggers can be achieved via a file, and logging.config.dictConfig(logging_dict). - +# # module logger: # --------------