rebase after electron remove

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()
+# Configure logging:
-ini.read(SCRIPTDIR / "DEBUG.ini")  # read DEBUG.ini file if exists
+# 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
+# log startup info
-#   - see warnings.warn()
+debug_logging.startup_info(logger, SCRIPTDIR, running_as_frozen, running_from_inkscape, debug_active, debug_type, profiler_type)
-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 ----
 
 # 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)

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}")

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

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):

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
@@ -249,9 +248,6 @@ class PrintPreviewServer(Thread):
             debug.log(f"exception in watcher {sys.exc_info()}")
             pass
 
-    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):
@@ -260,8 +256,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