From 4c77716be72c193d61b123b38afe04971449bd0e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jo=C3=A3o=20Magalh=C3=A3es?= Date: Fri, 3 Apr 2026 11:56:39 +0100 Subject: [PATCH 01/10] feat: add TRACE log level and patch_logging() Port TRACE log level support from appier (hivesolutions/appier#84) to colony. Adds TRACE constant (logging.DEBUG - 5 = 5) and SILENT constant (logging.CRITICAL + 1 = 51) for fine-grained protocol-level debugging. Co-Authored-By: Claude Opus 4.6 (1M context) --- CHANGELOG.md | 2 +- src/colony/base/__init__.py | 9 ++- src/colony/base/loggers.py | 28 +++++++ src/colony/base/system.py | 22 ++++++ src/colony/base/system.pyi | 1 + src/colony/libs/__init__.py | 2 + src/colony/libs/logging_util.py | 27 +++++++ src/colony/libs/logging_util.pyi | 3 + src/colony/test/base/loggers.py | 127 +++++++++++++++++++++++++++++++ 9 files changed, 219 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 3127953d..8773a6d7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,7 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added -* +* TRACE log level and `patch_logging()` for fine-grained protocol-level debugging ### Changed diff --git a/src/colony/base/__init__.py b/src/colony/base/__init__.py index a3308a86..21c912bf 100644 --- a/src/colony/base/__init__.py +++ b/src/colony/base/__init__.py @@ -89,7 +89,14 @@ DATE_TIME_FORMAT, INFORMATION_PATH, ) -from .loggers import BroadcastHandler, MemoryHandler, LogstashHandler +from .loggers import ( + SILENT, + TRACE, + BroadcastHandler, + MemoryHandler, + LogstashHandler, + patch_logging, +) from .system import ( System, Plugin, diff --git a/src/colony/base/loggers.py b/src/colony/base/loggers.py index 7ad2a94d..d4be9db4 100644 --- a/src/colony/base/loggers.py +++ b/src/colony/base/loggers.py @@ -64,6 +64,17 @@ """ The maximum amount of time in between flush operations in the logstash handler """ +SILENT = logging.CRITICAL + 1 +""" The silent level used to silent all the logging +or an handler, this is used as an utility for debugging +purposes more that a real feature for production systems """ + +TRACE = logging.DEBUG - 5 +""" The trace level used for extremely detailed and verbose +logging of protocol-level operations, this is meant to be +used for fine-grained debugging of low-level operations +like raw byte transfers and frame parsing """ + LEVELS = ("DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL") """ The sequence of levels from the least sever to the most sever this sequence may be used to find all the @@ -386,3 +397,20 @@ def _build_api(self): return None return logstash.API() + + +def patch_logging(): + if hasattr(logging, "_colony_patched"): + return + + # patches the logging infra-structure adding the trace level + # support and the corresponding trace method to the logger + logging.addLevelName(TRACE, "TRACE") + logging.Logger.trace = _trace + + logging._colony_patched = True + + +def _trace(self, message, *args, **kwargs): + if self.isEnabledFor(TRACE): + self._log(TRACE, message, args, **kwargs) diff --git a/src/colony/base/system.py b/src/colony/base/system.py index 9fb44836..e7102418 100644 --- a/src/colony/base/system.py +++ b/src/colony/base/system.py @@ -2223,6 +2223,11 @@ def start_logger(self, log_level=DEFAULT_LOGGING_LEVEL): :param log_level: The log level of the logger. """ + # patches the logging infra-structure so that the TRACE level + # is properly registered and available for usage, this call + # is idempotent and safe to be called multiple times + loggers.patch_logging() + # retrieves the minimal log level between the current # log level and the default one (as specified) minimal_log_level = ( @@ -6570,6 +6575,23 @@ def get_uptime(self): # about the uptime for the current plugin system return uptime + def is_trace(self): + """ + Checks if the current logging level is set to trace, + this check may be used to action conditional code + execution for fine-grained debugging purposes. + + :rtype: bool + :return: Value indicating if the current logging level + is set to trace (for fine-grained debugging). + """ + + if not self.logger: + return False + if not self.logger.level: + return False + return self.logger.level <= loggers.TRACE + def is_development(self): """ Checks if the current run mode in execution is of type diff --git a/src/colony/base/system.pyi b/src/colony/base/system.pyi index f774b75a..621fb244 100644 --- a/src/colony/base/system.pyi +++ b/src/colony/base/system.pyi @@ -428,6 +428,7 @@ class PluginManager: def get_environment(self): ... def get_system_information_map(self): ... def get_uptime(self): ... + def is_trace(self): ... def is_development(self): ... def is_production(self): ... def echo(self, value: str = "echo"): ... diff --git a/src/colony/libs/__init__.py b/src/colony/libs/__init__.py index 85dc4720..81e83ff8 100644 --- a/src/colony/libs/__init__.py +++ b/src/colony/libs/__init__.py @@ -111,6 +111,8 @@ from .lazy_util import LazyClass, LazyIteratorClass, is_lazy, Lazy, LazyIterator from .list_util import list_intersect, list_extend, list_no_duplicates from .logging_util import ( + SILENT, + TRACE, getLogger, getLevelName, getLevelInt, diff --git a/src/colony/libs/logging_util.py b/src/colony/libs/logging_util.py index 35a63b11..94412e38 100644 --- a/src/colony/libs/logging_util.py +++ b/src/colony/libs/logging_util.py @@ -28,6 +28,11 @@ __license__ = "Apache License, Version 2.0" """ The license for the module """ +SILENT = 51 +""" The silent level used to silent all the logging +or an handler, this is used as an utility for debugging +purposes more that a real feature for production systems """ + CRITICAL = 50 """ Critical logging level """ @@ -43,6 +48,12 @@ DEBUG = 10 """ Debug logging level """ +TRACE = 5 +""" The trace level used for extremely detailed and verbose +logging of protocol-level operations, this is meant to be +used for fine-grained debugging of low-level operations +like raw byte transfers and frame parsing """ + NOTSET = 0 """ Not set logging level """ @@ -50,30 +61,36 @@ """ Alias to WARNING log level """ _levelNames = { + SILENT: "SILENT", CRITICAL: "CRITICAL", ERROR: "ERROR", WARNING: "WARNING", INFO: "INFO", DEBUG: "DEBUG", + TRACE: "TRACE", NOTSET: "NOTSET", + "SILENT": SILENT, "CRITICAL": CRITICAL, "ERROR": ERROR, "WARN": WARNING, "WARNING": WARNING, "INFO": INFO, "DEBUG": DEBUG, + "TRACE": TRACE, "NOTSET": NOTSET, } """ The map relating the log levels with the textual representation and vice-versa """ _levelValues = { + "SILENT": SILENT, "CRITICAL": CRITICAL, "ERROR": ERROR, "WARN": WARNING, "WARNING": WARNING, "INFO": INFO, "DEBUG": DEBUG, + "TRACE": TRACE, "NOTSET": NOTSET, } """ Map tha associated the textual representation of the @@ -148,6 +165,16 @@ def setLevel(self, level): pass + def trace(self, msg, *args, **kwargs): + """ + Prints a trace message to the logger. + + :type msg: String + :param msg: The message to print. + """ + + pass + def debug(self, msg, *args, **kwargs): """ Prints a debug message to the logger. diff --git a/src/colony/libs/logging_util.pyi b/src/colony/libs/logging_util.pyi index 08318001..1b2de778 100644 --- a/src/colony/libs/logging_util.pyi +++ b/src/colony/libs/logging_util.pyi @@ -1,11 +1,13 @@ from logging import Handler, Logger, Formatter as BaseFormatter from typing import Mapping +SILENT: int CRITICAL: int ERROR: int WARNING: int INFO: int DEBUG: int +TRACE: int NOTSET: int WARN = ... _levelNames: Mapping[str | int, str | int] @@ -18,6 +20,7 @@ def getLevelInt(levelName: str) -> int: ... class DummyLogger: def __init__(self, name: str, level: int = ...): ... def setLevel(self, level: int): ... + def trace(self, msg: str, *args, **kwargs): ... def debug(self, msg: str, *args, **kwargs): ... def info(self, msg: str, *args, **kwargs): ... def warning(self, msg: str, *args, **kwargs): ... diff --git a/src/colony/test/base/loggers.py b/src/colony/test/base/loggers.py index d8969d33..f6400137 100644 --- a/src/colony/test/base/loggers.py +++ b/src/colony/test/base/loggers.py @@ -32,6 +32,8 @@ import colony +from colony.base import loggers + try: import unittest.mock as mock except ImportError: @@ -44,6 +46,131 @@ class LoggersTest(colony.ColonyTestCase): methods and functions of colony. """ + def test_silent_value(self): + self.assertEqual(colony.SILENT, logging.CRITICAL + 1) + self.assertEqual(type(colony.SILENT), int) + + def test_silent_above_critical(self): + self.assertTrue(colony.SILENT > logging.CRITICAL) + + def test_trace_value(self): + self.assertEqual(colony.TRACE, 5) + self.assertEqual(colony.TRACE, logging.DEBUG - 5) + self.assertEqual(type(colony.TRACE), int) + + def test_trace_below_debug(self): + self.assertTrue(colony.TRACE < logging.DEBUG) + + def test_level_ordering(self): + self.assertTrue(colony.TRACE < logging.DEBUG) + self.assertTrue(logging.DEBUG < logging.INFO) + self.assertTrue(logging.INFO < logging.WARNING) + self.assertTrue(logging.WARNING < logging.ERROR) + self.assertTrue(logging.ERROR < logging.CRITICAL) + self.assertTrue(logging.CRITICAL < colony.SILENT) + + def test_patch_logging(self): + colony.patch_logging() + + result = logging.getLevelName(colony.TRACE) + + self.assertEqual(result, "TRACE") + + def test_patch_logging_reverse(self): + colony.patch_logging() + + result = logging.getLevelName("TRACE") + + self.assertEqual(result, colony.TRACE) + + def test_patch_logging_idempotent(self): + colony.patch_logging() + colony.patch_logging() + + result = logging.getLevelName(colony.TRACE) + + self.assertEqual(result, "TRACE") + + def test_patch_logging_logger_trace(self): + colony.patch_logging() + + logger = logging.getLogger("colony.test.trace") + + self.assertTrue(hasattr(logger, "trace")) + self.assertTrue(callable(logger.trace)) + + def test_patch_logging_logger_trace_call(self): + colony.patch_logging() + + logger = logging.getLogger("colony.test.trace.call") + logger.setLevel(colony.TRACE) + records = [] + handler = logging.Handler() + handler.setLevel(colony.TRACE) + handler.emit = lambda record: records.append(record) + logger.addHandler(handler) + + try: + logger.trace("trace test message") + + self.assertEqual(len(records), 1) + self.assertEqual(records[0].getMessage(), "trace test message") + self.assertEqual(records[0].levelno, colony.TRACE) + self.assertEqual(records[0].levelname, "TRACE") + finally: + logger.removeHandler(handler) + + def test_patch_logging_logger_trace_filtered(self): + colony.patch_logging() + + logger = logging.getLogger("colony.test.trace.filtered") + logger.setLevel(logging.DEBUG) + records = [] + handler = logging.Handler() + handler.setLevel(colony.TRACE) + handler.emit = lambda record: records.append(record) + logger.addHandler(handler) + + try: + # the trace message should be filtered since the logger + # level is set to DEBUG which is above TRACE + logger.trace("this should be filtered") + + self.assertEqual(len(records), 0) + finally: + logger.removeHandler(handler) + + def test_get_level_int_trace(self): + result = colony.getLevelInt("TRACE") + + self.assertEqual(result, colony.TRACE) + self.assertEqual(result, 5) + + def test_get_level_int_silent(self): + result = colony.getLevelInt("SILENT") + + self.assertEqual(result, colony.SILENT) + self.assertEqual(result, 51) + + def test_get_level_name_trace(self): + result = colony.getLevelName("TRACE") + + self.assertEqual(result, loggers.TRACE) + + def test_get_level_name_silent(self): + result = colony.getLevelName("SILENT") + + self.assertEqual(result, loggers.SILENT) + + def test_dummy_logger_trace(self): + logger = colony.DummyLogger("test") + + self.assertTrue(hasattr(logger, "trace")) + self.assertTrue(callable(logger.trace)) + + # should not raise, just a no-op + logger.trace("test message") + def test_memory_handler(self): memory_handler = colony.MemoryHandler() formatter = logging.Formatter("%(message)s") From e64ed5430e91f10be32e438b8031d5554a4dcbde Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jo=C3=A3o=20Magalh=C3=A3es?= Date: Fri, 3 Apr 2026 13:11:32 +0100 Subject: [PATCH 02/10] feat: add trace() method and *args/**kwargs to PluginManager log methods Adds trace() convenience method to PluginManager and makes all log methods (debug, info, warning, error, critical) accept *args and **kwargs for lazy evaluation support. Co-Authored-By: Claude Opus 4.6 (1M context) --- src/colony/base/system.py | 38 ++++++++++++++++++++++++++++---------- src/colony/base/system.pyi | 22 ++++++++++++---------- 2 files changed, 40 insertions(+), 20 deletions(-) diff --git a/src/colony/base/system.py b/src/colony/base/system.py index e7102418..9431d4f6 100644 --- a/src/colony/base/system.py +++ b/src/colony/base/system.py @@ -6009,7 +6009,25 @@ def log_stack_trace(self, level=logging.DEBUG): # prints a log message with the formatted traceback line self.logger.log(level, formatted_traceback_line_stripped) - def debug(self, message): + def trace(self, message, *args, **kwargs): + """ + Adds the given trace message to the logger. + + :type message: String + :param message: The trace message to be added to the logger. + """ + + # in case no logger is defined it's not possible + # to print the message as a trace + if not self.logger: + return + + # formats the logger message and prints it + # as a trace message into the logger + logger_message = self.format_logger_message(message) + self.logger.log(loggers.TRACE, logger_message, *args, **kwargs) + + def debug(self, message, *args, **kwargs): """ Adds the given debug message to the logger. @@ -6025,9 +6043,9 @@ def debug(self, message): # formats the logger message and prints it # as a debug message into the logger logger_message = self.format_logger_message(message) - self.logger.debug(logger_message) + self.logger.debug(logger_message, *args, **kwargs) - def info(self, message): + def info(self, message, *args, **kwargs): """ Adds the given info message to the logger. @@ -6043,9 +6061,9 @@ def info(self, message): # formats the logger message and prints it # as an info message into the logger logger_message = self.format_logger_message(message) - self.logger.info(logger_message) + self.logger.info(logger_message, *args, **kwargs) - def warning(self, message): + def warning(self, message, *args, **kwargs): """ Adds the given warning message to the logger. @@ -6061,12 +6079,12 @@ def warning(self, message): # formats the logger message and prints it # as a warning message into the logger logger_message = self.format_logger_message(message) - self.logger.warning(logger_message) + self.logger.warning(logger_message, *args, **kwargs) # logs the stack trace self.log_stack_trace(level=logging.INFO) - def error(self, message): + def error(self, message, *args, **kwargs): """ Adds the given error message to the logger. @@ -6082,12 +6100,12 @@ def error(self, message): # formats the logger message and prints it # as an error message into the logger logger_message = self.format_logger_message(message) - self.logger.error(logger_message) + self.logger.error(logger_message, *args, **kwargs) # logs the stack trace self.log_stack_trace(level=logging.WARNING) - def critical(self, message): + def critical(self, message, *args, **kwargs): """ Adds the given critical message to the logger. @@ -6099,7 +6117,7 @@ def critical(self, message): logger_message = self.format_logger_message(message) # prints the critical message - self.logger.critical(logger_message) + self.logger.critical(logger_message, *args, **kwargs) # logs the stack trace self.log_stack_trace(level=logging.ERROR) diff --git a/src/colony/base/system.pyi b/src/colony/base/system.pyi index 621fb244..441f28e6 100644 --- a/src/colony/base/system.pyi +++ b/src/colony/base/system.pyi @@ -138,11 +138,12 @@ class Plugin: def get_author_name(self): ... def get_uptime(self): ... def log_stack_trace(self, level=...) -> None: ... - def debug(self, message) -> None: ... - def info(self, message) -> None: ... - def warning(self, message) -> None: ... - def error(self, message) -> None: ... - def critical(self, message) -> None: ... + def trace(self, message, *args, **kwargs) -> None: ... + def debug(self, message, *args, **kwargs) -> None: ... + def info(self, message, *args, **kwargs) -> None: ... + def warning(self, message, *args, **kwargs) -> None: ... + def error(self, message, *args, **kwargs) -> None: ... + def critical(self, message, *args, **kwargs) -> None: ... def format_logger_message(self, message): ... def _get_capabilities_allowed_names(self): ... @@ -388,11 +389,12 @@ class PluginManager: def generate_system_information_map(self) -> None: ... def get_log_handler(self, name): ... def log_stack_trace(self, level=...) -> None: ... - def debug(self, message) -> None: ... - def info(self, message) -> None: ... - def warning(self, message) -> None: ... - def error(self, message) -> None: ... - def critical(self, message) -> None: ... + def trace(self, message, *args, **kwargs) -> None: ... + def debug(self, message, *args, **kwargs) -> None: ... + def info(self, message, *args, **kwargs) -> None: ... + def warning(self, message, *args, **kwargs) -> None: ... + def error(self, message, *args, **kwargs) -> None: ... + def critical(self, message, *args, **kwargs) -> None: ... def format_logger_message(self, message): ... def print_all_plugins(self) -> None: ... def get_prefix_paths(self): ... From fc52df861979671947335b49feccfb8a9b23b9a2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jo=C3=A3o=20Magalh=C3=A3es?= Date: Fri, 3 Apr 2026 14:51:51 +0100 Subject: [PATCH 03/10] feat: add TRACE-aware logging format with pathname and lineno When the log level is set to TRACE, automatically switches to a more detailed format that includes file path and line number for fine-grained debugging of low-level operations. Co-Authored-By: Claude Opus 4.6 (1M context) --- src/colony/base/system.py | 17 +++++++++++++++-- 1 file changed, 15 insertions(+), 2 deletions(-) diff --git a/src/colony/base/system.py b/src/colony/base/system.py index 9431d4f6..a8d01ca0 100644 --- a/src/colony/base/system.py +++ b/src/colony/base/system.py @@ -80,6 +80,13 @@ DEFAULT_LOGGING_FORMAT = "%(asctime)s [%(levelname)s] %(message)s" """ The default logging format """ +DEFAULT_LOGGING_FORMAT_TRACE = ( + "%(asctime)s [%(levelname)s] %(pathname)s:%(lineno)d | %(message)s" +) +""" The format to be used when the logging level is set to TRACE, +includes file path and line number to allow for fine-grained debugging +of low-level protocol operations """ + DEFAULT_LOGGING_FILE_NAME_PREFIX = "colony" """ The default logging file name prefix """ @@ -2317,8 +2324,14 @@ def start_logger(self, log_level=DEFAULT_LOGGING_LEVEL): logstash_handler.setLevel(minimal_log_level) # retrieves the logging format and uses it - # to create the proper logging formatter - logging_format = GLOBAL_CONFIG.get("logging_format", DEFAULT_LOGGING_FORMAT) + # to create the proper logging formatter, in case the + # log level is set to trace uses the trace format that + # includes the file path and line number for debugging + is_trace = log_level <= loggers.TRACE + default_format = ( + DEFAULT_LOGGING_FORMAT_TRACE if is_trace else DEFAULT_LOGGING_FORMAT + ) + logging_format = GLOBAL_CONFIG.get("logging_format", default_format) formatter = logging.Formatter(logging_format) # sets the formatter in the stream and rotating From db2fca214d722d9b51930738a8ddc07068e40708 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jo=C3=A3o=20Magalh=C3=A3es?= Date: Fri, 3 Apr 2026 14:53:21 +0100 Subject: [PATCH 04/10] chore: new module starting --- src/colony/__main__.py | 30 ++++++++++++++++++++++++++++++ src/colony_adm.py | 10 +++++----- 2 files changed, 35 insertions(+), 5 deletions(-) create mode 100644 src/colony/__main__.py diff --git a/src/colony/__main__.py b/src/colony/__main__.py new file mode 100644 index 00000000..c0d7bd35 --- /dev/null +++ b/src/colony/__main__.py @@ -0,0 +1,30 @@ +#!/usr/bin/python +# -*- coding: utf-8 -*- + +# Hive Colony Framework +# Copyright (c) 2008-2024 Hive Solutions Lda. +# +# This file is part of Hive Colony Framework +# +# Hive Colony Framework is free software: you can redistribute it and/or modify +# it under the terms of the Apache License as published by the Apache +# Foundation, either version 2.0 of the License, or (at your option) any +# later version. +# +# Hive Colony Framework is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# Apache License for more details. +# +# You should have received a copy of the Apache License along with +# Hive Colony Framework If not, see . + +__copyright__ = "Copyright (c) 2008-2024 Hive Solutions Lda." +""" The copyright for the module """ + +__license__ = "Apache License, Version 2.0" +""" The license for the module """ + +from colony_start import main + +main() diff --git a/src/colony_adm.py b/src/colony_adm.py index d483ec9b..d66928ca 100644 --- a/src/colony_adm.py +++ b/src/colony_adm.py @@ -590,7 +590,7 @@ def _generate_plugin(path, use_path=True): # filters the resources that have been gathered so that only the ones that # matter are defined in the structure and then creates the sequence of dependency # maps that are going to be defining the dependencies of the plugin - resources = _fitler_resources(resources) + resources = _filter_resources(resources) dependencies = [dependency.get_map() for dependency in plugin.dependencies] # creates the "final" plugin definition structure with the complete set of @@ -653,7 +653,7 @@ def _generate_config(path): output("Generating config descriptor for %s" % name) resources = _gather_config(path) - resources = _fitler_resources(resources) + resources = _filter_resources(resources) structure = dict( type="config", @@ -838,7 +838,7 @@ def _deploy(path, timestamp=None): # dumps the current descriptor object for the item that is going to be # deployed and then writes the contents of it into the info based file - # that is going to be used as a meta information provid3er + # that is going to be used as a meta information provider descriptor_s = json.dumps(descriptor) is_unicode = colony.legacy.is_unicode(descriptor_s) if is_unicode: @@ -1034,7 +1034,7 @@ def _upgrade(): # "calculates" both the path to the plugins directory and to the # meta information directory, both of them will be used to gather - # the information on the current instace's deployment + # the information on the current instance's deployment plugins_path = os.path.join(manager_path, "plugins") meta_path = os.path.join(manager_path, "meta") @@ -1230,7 +1230,7 @@ def _dependencies(info, upgrade=False): _install(id=dependency["id"], version=dependency["version"], upgrade=upgrade) -def _fitler_resources(resources, exclusion=(".pyc", ".temp", ".tmp")): +def _filter_resources(resources, exclusion=(".pyc", ".temp", ".tmp")): filtered = [] for resource in resources: if resource.endswith(exclusion): From 21c6cd314e039dcbdc24ee80d5c513a56f4dbab0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jo=C3=A3o=20Magalh=C3=A3es?= Date: Fri, 3 Apr 2026 14:53:33 +0100 Subject: [PATCH 05/10] fix: handle GLOBAL_CONFIG override for TRACE logging format The GLOBAL_CONFIG always has a hardcoded logging_format value, so the .get() default never triggers. Added explicit check to switch to the trace format when the config value matches the default and the level is TRACE. Co-Authored-By: Claude Opus 4.6 (1M context) --- src/colony/base/system.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/colony/base/system.py b/src/colony/base/system.py index a8d01ca0..714bb9a1 100644 --- a/src/colony/base/system.py +++ b/src/colony/base/system.py @@ -2332,6 +2332,8 @@ def start_logger(self, log_level=DEFAULT_LOGGING_LEVEL): DEFAULT_LOGGING_FORMAT_TRACE if is_trace else DEFAULT_LOGGING_FORMAT ) logging_format = GLOBAL_CONFIG.get("logging_format", default_format) + if logging_format == DEFAULT_LOGGING_FORMAT and is_trace: + logging_format = DEFAULT_LOGGING_FORMAT_TRACE formatter = logging.Formatter(logging_format) # sets the formatter in the stream and rotating From 511a72d17748a7dccb3c44bfa4018f07685e2f87 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jo=C3=A3o=20Magalh=C3=A3es?= Date: Mon, 6 Apr 2026 12:28:50 +0100 Subject: [PATCH 06/10] chore: new logging format for trace --- src/colony/base/system.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/colony/base/system.py b/src/colony/base/system.py index 714bb9a1..3218d8ff 100644 --- a/src/colony/base/system.py +++ b/src/colony/base/system.py @@ -81,7 +81,7 @@ """ The default logging format """ DEFAULT_LOGGING_FORMAT_TRACE = ( - "%(asctime)s [%(levelname)s] %(pathname)s:%(lineno)d | %(message)s" + "%(asctime)s [%(name)s] [%(levelname)s] %(message)s" ) """ The format to be used when the logging level is set to TRACE, includes file path and line number to allow for fine-grained debugging From d40d59d55491e7a83535a012c44383a832e365ff Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jo=C3=A3o=20Magalh=C3=A3es?= Date: Mon, 6 Apr 2026 12:57:21 +0100 Subject: [PATCH 07/10] chore: new black format --- src/colony/base/system.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/src/colony/base/system.py b/src/colony/base/system.py index 3218d8ff..496c8168 100644 --- a/src/colony/base/system.py +++ b/src/colony/base/system.py @@ -80,9 +80,7 @@ DEFAULT_LOGGING_FORMAT = "%(asctime)s [%(levelname)s] %(message)s" """ The default logging format """ -DEFAULT_LOGGING_FORMAT_TRACE = ( - "%(asctime)s [%(name)s] [%(levelname)s] %(message)s" -) +DEFAULT_LOGGING_FORMAT_TRACE = "%(asctime)s [%(name)s] [%(levelname)s] %(message)s" """ The format to be used when the logging level is set to TRACE, includes file path and line number to allow for fine-grained debugging of low-level protocol operations """ From 46f6fccceb4209e7afa5b7aaaf0962b69bcf5ab8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jo=C3=A3o=20Magalh=C3=A3es?= Date: Mon, 6 Apr 2026 13:21:01 +0100 Subject: [PATCH 08/10] chore: new logging format for trace Passes stacklevel=2 in all PluginManager log methods (trace, debug, info, warning, error, critical) so that pathname and lineno in the format string reflect the actual caller, not the internal log method. Guards stacklevel for Python < 3.8 where it is not supported, and makes DEFAULT_LOGGING_FORMAT_TRACE conditional on Python 3.8+. Co-Authored-By: Claude Opus 4.6 (1M context) --- src/colony/base/system.py | 22 +++++++++++++++++++--- 1 file changed, 19 insertions(+), 3 deletions(-) diff --git a/src/colony/base/system.py b/src/colony/base/system.py index 496c8168..a61a9e6d 100644 --- a/src/colony/base/system.py +++ b/src/colony/base/system.py @@ -80,10 +80,14 @@ DEFAULT_LOGGING_FORMAT = "%(asctime)s [%(levelname)s] %(message)s" """ The default logging format """ -DEFAULT_LOGGING_FORMAT_TRACE = "%(asctime)s [%(name)s] [%(levelname)s] %(message)s" +DEFAULT_LOGGING_FORMAT_TRACE = ( + "%(asctime)s [%(levelname)s] %(pathname)s:%(lineno)d | %(message)s" + if sys.version_info >= (3, 8) + else "%(asctime)s [%(levelname)s] %(message)s" +) """ The format to be used when the logging level is set to TRACE, -includes file path and line number to allow for fine-grained debugging -of low-level protocol operations """ +includes file path and line number on Python 3.8+ where stacklevel +is supported for accurate caller information """ DEFAULT_LOGGING_FILE_NAME_PREFIX = "colony" """ The default logging file name prefix """ @@ -6038,6 +6042,8 @@ def trace(self, message, *args, **kwargs): # formats the logger message and prints it # as a trace message into the logger logger_message = self.format_logger_message(message) + if sys.version_info >= (3, 8): + kwargs.setdefault("stacklevel", 2) self.logger.log(loggers.TRACE, logger_message, *args, **kwargs) def debug(self, message, *args, **kwargs): @@ -6056,6 +6062,8 @@ def debug(self, message, *args, **kwargs): # formats the logger message and prints it # as a debug message into the logger logger_message = self.format_logger_message(message) + if sys.version_info >= (3, 8): + kwargs.setdefault("stacklevel", 2) self.logger.debug(logger_message, *args, **kwargs) def info(self, message, *args, **kwargs): @@ -6074,6 +6082,8 @@ def info(self, message, *args, **kwargs): # formats the logger message and prints it # as an info message into the logger logger_message = self.format_logger_message(message) + if sys.version_info >= (3, 8): + kwargs.setdefault("stacklevel", 2) self.logger.info(logger_message, *args, **kwargs) def warning(self, message, *args, **kwargs): @@ -6092,6 +6102,8 @@ def warning(self, message, *args, **kwargs): # formats the logger message and prints it # as a warning message into the logger logger_message = self.format_logger_message(message) + if sys.version_info >= (3, 8): + kwargs.setdefault("stacklevel", 2) self.logger.warning(logger_message, *args, **kwargs) # logs the stack trace @@ -6113,6 +6125,8 @@ def error(self, message, *args, **kwargs): # formats the logger message and prints it # as an error message into the logger logger_message = self.format_logger_message(message) + if sys.version_info >= (3, 8): + kwargs.setdefault("stacklevel", 2) self.logger.error(logger_message, *args, **kwargs) # logs the stack trace @@ -6130,6 +6144,8 @@ def critical(self, message, *args, **kwargs): logger_message = self.format_logger_message(message) # prints the critical message + if sys.version_info >= (3, 8): + kwargs.setdefault("stacklevel", 2) self.logger.critical(logger_message, *args, **kwargs) # logs the stack trace From a200c58daf04c58462671aa7ae68b5da22738ce7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jo=C3=A3o=20Magalh=C3=A3es?= Date: Tue, 7 Apr 2026 11:37:57 +0100 Subject: [PATCH 09/10] fix: trace reference --- src/colony/base/system.py | 18 ++++++++++++++++++ src/colony/base/system.pyi | 1 + src/colony/libs/logging_util.py | 2 +- 3 files changed, 20 insertions(+), 1 deletion(-) diff --git a/src/colony/base/system.py b/src/colony/base/system.py index a61a9e6d..50ea73fc 100644 --- a/src/colony/base/system.py +++ b/src/colony/base/system.py @@ -245,6 +245,11 @@ def get_manager(self): raise exceptions.PluginSystemException("no plugin available") return self.plugin.manager + def trace(self, *args, **kwargs): + if self.plugin == None: + raise exceptions.PluginSystemException("no plugin available") + return self.plugin.trace(*args, **kwargs) + def debug(self, *args, **kwargs): if self.plugin == None: raise exceptions.PluginSystemException("no plugin available") @@ -1389,6 +1394,19 @@ def log_stack_trace(self, level=logging.DEBUG): formatted_traceback_line_stripped = formatted_traceback_line.rstrip() self.logger.log(level, formatted_traceback_line_stripped) + def trace(self, message, *args, **kwargs): + """ + Adds the given trace message to the logger. + + :type message: String + :param message: The trace message to be added to the logger. + """ + + # formats the logger message then prints the + # trace message to the current stream + logger_message = self.format_logger_message(message) + self.logger.trace(logger_message, *args, **kwargs) + def debug(self, message, *args, **kwargs): """ Adds the given debug message to the logger. diff --git a/src/colony/base/system.pyi b/src/colony/base/system.pyi index 441f28e6..c7dbe915 100644 --- a/src/colony/base/system.pyi +++ b/src/colony/base/system.pyi @@ -46,6 +46,7 @@ class System: def __init__(self, plugin) -> None: ... def get_manager(self): ... + def trace(self, *args, **kwargs): ... def debug(self, *args, **kwargs): ... def info(self, *args, **kwargs): ... def warning(self, *args, **kwargs): ... diff --git a/src/colony/libs/logging_util.py b/src/colony/libs/logging_util.py index 94412e38..974ff644 100644 --- a/src/colony/libs/logging_util.py +++ b/src/colony/libs/logging_util.py @@ -93,7 +93,7 @@ "TRACE": TRACE, "NOTSET": NOTSET, } -""" Map tha associated the textual representation of the +""" Map the associated the textual representation of the log level with the integer value """ From d47b3bb1e8d9d0114e5602ae5deeabc5c8e6beef Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jo=C3=A3o=20Magalh=C3=A3es?= Date: Tue, 7 Apr 2026 11:38:28 +0100 Subject: [PATCH 10/10] fix: small spelling error in logging_util.py docstring --- src/colony/libs/logging_util.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/colony/libs/logging_util.py b/src/colony/libs/logging_util.py index 974ff644..6ac61e6d 100644 --- a/src/colony/libs/logging_util.py +++ b/src/colony/libs/logging_util.py @@ -93,7 +93,7 @@ "TRACE": TRACE, "NOTSET": NOTSET, } -""" Map the associated the textual representation of the +""" Map that associates the textual representation of the log level with the integer value """