diff --git a/.gitignore b/.gitignore index f9b17c714..4c1ba2c22 100644 --- a/.gitignore +++ b/.gitignore @@ -21,6 +21,7 @@ locales/ .DS_Store # 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 '''