-
Notifications
You must be signed in to change notification settings - Fork 6
feat: add TRACE log level and patch_logging() #20
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from 2 commits
4c77716
e64ed54
fc52df8
db2fca2
21c6cd3
511a72d
d40d59d
46f6fcc
a200c58
d47b3bb
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -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 | ||
|
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
Adding Useful? React with 👍 / 👎. |
||
| """ 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) | ||
| Original file line number | Diff line number | Diff line change | ||||||||
|---|---|---|---|---|---|---|---|---|---|---|
|
|
@@ -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 = ( | ||||||||||
|
|
@@ -6004,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) | ||||||||||
|
|
||||||||||
|
coderabbitai[bot] marked this conversation as resolved.
|
||||||||||
| def debug(self, message, *args, **kwargs): | ||||||||||
| """ | ||||||||||
| Adds the given debug message to the logger. | ||||||||||
|
|
||||||||||
|
|
@@ -6020,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. | ||||||||||
|
|
||||||||||
|
|
@@ -6038,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. | ||||||||||
|
|
||||||||||
|
|
@@ -6056,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. | ||||||||||
|
|
||||||||||
|
|
@@ -6077,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. | ||||||||||
|
|
||||||||||
|
|
@@ -6094,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) | ||||||||||
|
|
@@ -6570,6 +6593,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 | ||||||||||
|
Comment on lines
+6656
to
+6658
|
||||||||||
| if not self.logger.level: | |
| return False | |
| return self.logger.level <= loggers.TRACE | |
| return self.logger.isEnabledFor(loggers.TRACE) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
🧩 Analysis chain
🏁 Script executed:
#!/bin/bash
python - <<'PY'
import logging
TRACE = logging.DEBUG - 5
parent = logging.getLogger("trace_parent")
child = logging.getLogger("trace_parent.child")
parent.setLevel(TRACE)
child.setLevel(logging.NOTSET)
raw = False if not child.level else child.level <= TRACE
print("raw check:", raw)
print("isEnabledFor:", child.isEnabledFor(TRACE))
child.disabled = True
raw = False if not child.level else child.level <= TRACE
print("raw check after disable:", raw)
print("isEnabledFor after disable:", child.isEnabledFor(TRACE))
PYRepository: hivesolutions/colony
Length of output: 164
🏁 Script executed:
# First, verify the file exists and check the specified lines
if [ -f "src/colony/base/system.py" ]; then
echo "=== File exists, checking lines 6596-6611 ==="
sed -n '6596,6611p' src/colony/base/system.py
else
echo "File not found at src/colony/base/system.py"
git ls-files | grep -i system.py
fiRepository: hivesolutions/colony
Length of output: 648
🏁 Script executed:
# Search for loggers.TRACE definition
echo "=== Searching for TRACE constant definition ==="
rg "TRACE\s*=" --type py -B 2 -A 2 | head -40Repository: hivesolutions/colony
Length of output: 781
🏁 Script executed:
# Check for loggers module and TRACE definition
echo "=== Looking for loggers module ==="
git ls-files | grep -i loggerRepository: hivesolutions/colony
Length of output: 157
🏁 Script executed:
# Check the class context and surrounding code
echo "=== Class context (lines 6580-6620) ==="
sed -n '6580,6620p' src/colony/base/system.pyRepository: hivesolutions/colony
Length of output: 1552
🏁 Script executed:
# Check if there are any logger initializations or type hints
echo "=== Searching for logger attribute initialization ==="
rg "self\.logger\s*=" src/colony/base/system.py -B 2 -A 2 | head -50Repository: hivesolutions/colony
Length of output: 512
🏁 Script executed:
# Verify the file uses CRLF or LF line endings
echo "=== Checking line endings ==="
file src/colony/base/system.pyRepository: hivesolutions/colony
Length of output: 155
🏁 Script executed:
# Check line endings more reliably
echo "=== Checking line endings (first 10 lines) ==="
head -10 src/colony/base/system.py | od -c | head -20Repository: hivesolutions/colony
Length of output: 168
🏁 Script executed:
# Find the class containing is_trace method
echo "=== Finding class definition ==="
grep -n "^class " src/colony/base/system.py | head -5
awk '/^class /{class=$0; line=NR} /def is_trace/{print "Line", line": "class}' src/colony/base/system.pyRepository: hivesolutions/colony
Length of output: 298
🏁 Script executed:
# Check for type annotations in the file
echo "=== Checking for type annotations ==="
rg ":\s*(int|str|bool|List|Dict|Optional|Any)" src/colony/base/system.py | head -10Repository: hivesolutions/colony
Length of output: 350
🏁 Script executed:
# Check the __init__ method to confirm logger initialization
echo "=== Checking PluginManager.__init__ ==="
awk '/^class PluginManager/,/^class [^(]/ {print NR": "$0}' src/colony/base/system.py | grep -A 50 "def __init__" | head -60Repository: hivesolutions/colony
Length of output: 103
🏁 Script executed:
# Verify black compatibility of proposed fix (check if code follows black style)
echo "=== Checking existing code style in nearby methods ==="
sed -n '6620,6650p' src/colony/base/system.pyRepository: hivesolutions/colony
Length of output: 968
🏁 Script executed:
# Test the proposed fix for Python 2.7 compatibility
python - <<'PY'
import logging
TRACE = logging.DEBUG - 5
# Test the proposed fix logic
class MockLogger:
def __init__(self):
self.level = logging.NOTSET
self.disabled = False
def isEnabledFor(self, level):
"""Mock standard logger isEnabledFor"""
if self.disabled:
return False
effective_level = self.level if self.level else logging.WARNING
return level >= effective_level
# Simulate the proposed fix
logger = MockLogger()
is_enabled_for = getattr(logger, "isEnabledFor", None)
if is_enabled_for:
result = is_enabled_for(TRACE)
else:
level = getattr(logger, "level", None)
if level == None:
result = False
else:
result = level <= TRACE
print("Mock logger result (NOTSET):", result)
# Test with actual logging
real_logger = logging.getLogger("test")
parent = logging.getLogger("test_parent")
parent.setLevel(TRACE)
real_logger.setLevel(logging.NOTSET)
is_enabled_for = getattr(real_logger, "isEnabledFor", None)
if is_enabled_for:
result = is_enabled_for(TRACE)
else:
level = getattr(real_logger, "level", None)
if level == None:
result = False
else:
result = level <= TRACE
print("Real logger result (inherited NOTSET):", result)
print("Real logger isEnabledFor(TRACE):", real_logger.isEnabledFor(TRACE))
PYRepository: hivesolutions/colony
Length of output: 182
🏁 Script executed:
# Verify the actual behavior difference more carefully with proper parent-child relationship
python - <<'PY'
import logging
TRACE = logging.DEBUG - 5
# Recreate the exact scenario from initial verification
parent = logging.getLogger("trace_parent")
child = logging.getLogger("trace_parent.child")
parent.setLevel(TRACE)
child.setLevel(logging.NOTSET)
print("=== Current implementation (direct .level check) ===")
# Simulate current is_trace implementation
if not child:
raw_result = False
elif not child.level:
raw_result = False
else:
raw_result = child.level <= TRACE
print(f"child.level = {child.level}")
print(f"child.logger.getEffectiveLevel() = {child.getEffectiveLevel()}")
print(f"Raw check result: {raw_result}")
print(f"isEnabledFor result: {child.isEnabledFor(TRACE)}")
print("\n=== With disabled logger ===")
child.disabled = True
if not child:
raw_result = False
elif not child.level:
raw_result = False
else:
raw_result = child.level <= TRACE
print(f"Raw check result: {raw_result}")
print(f"isEnabledFor result: {child.isEnabledFor(TRACE)}")
PYRepository: hivesolutions/colony
Length of output: 300
🏁 Script executed:
# Check line ending style more directly
echo "=== Checking line ending style ==="
hexdump -C src/colony/base/system.py | head -20Repository: hivesolutions/colony
Length of output: 161
🏁 Script executed:
# Verify the coding guideline: check for any existing "== None" vs "is None" patterns
echo "=== Checking existing None comparison style in the file ==="
rg "\s(==|is)\s+None" src/colony/base/system.py | head -20Repository: hivesolutions/colony
Length of output: 476
🏁 Script executed:
# Verify the proposed fix aligns with black formatter expectations
echo "=== Checking the proposed fix formatting ==="
python - <<'PY'
import logging
# Simulate the proposed fix to ensure it's syntactically valid Python 2.7+
def is_trace(logger, TRACE):
if not logger:
return False
is_enabled_for = getattr(logger, "isEnabledFor", None)
if is_enabled_for:
return is_enabled_for(TRACE)
level = getattr(logger, "level", None)
if level == None:
return False
return level <= TRACE
# Test the proposed fix
test_logger = logging.getLogger("test")
parent = logging.getLogger("test_parent")
parent.setLevel(logging.DEBUG - 5)
test_logger.setLevel(logging.NOTSET)
TRACE = logging.DEBUG - 5
result = is_trace(test_logger, TRACE)
print("Proposed fix result:", result)
print("Correct (should be True):", result == True)
PYRepository: hivesolutions/colony
Length of output: 167
🏁 Script executed:
# Check if there are any type annotations in the method signature
echo "=== Checking method signature (no type annotations required) ==="
sed -n '6596,6600p' src/colony/base/system.pyRepository: hivesolutions/colony
Length of output: 342
🏁 Script executed:
# Verify the proposed fix more carefully with proper logger hierarchy
python - <<'PY'
import logging
TRACE = logging.DEBUG - 5
# Set up the exact same hierarchy as the verification
parent = logging.getLogger("trace_parent")
child = logging.getLogger("trace_parent.child")
parent.setLevel(TRACE)
child.setLevel(logging.NOTSET)
# Simulate the proposed fix
logger = child
if not logger:
result = False
else:
is_enabled_for = getattr(logger, "isEnabledFor", None)
if is_enabled_for:
result = is_enabled_for(TRACE)
else:
level = getattr(logger, "level", None)
if level == None:
result = False
else:
result = level <= TRACE
print("Proposed fix result:", result)
print("Expected (True):", result == True)
print()
print("Verification: isEnabledFor(TRACE) =", child.isEnabledFor(TRACE))
print("Verification: child.level =", child.level)
print("Verification: child.getEffectiveLevel() =", child.getEffectiveLevel())
PYRepository: hivesolutions/colony
Length of output: 227
🏁 Script executed:
# Verify the proposed fix handles disabled loggers correctly
python - <<'PY'
import logging
TRACE = logging.DEBUG - 5
parent = logging.getLogger("trace_parent")
child = logging.getLogger("trace_parent.child")
parent.setLevel(TRACE)
child.setLevel(logging.NOTSET)
child.disabled = True
# Simulate the proposed fix with disabled logger
logger = child
if not logger:
result = False
else:
is_enabled_for = getattr(logger, "isEnabledFor", None)
if is_enabled_for:
result = is_enabled_for(TRACE)
else:
level = getattr(logger, "level", None)
if level == None:
result = False
else:
result = level <= TRACE
print("Proposed fix result (disabled):", result)
print("Expected (False):", result == False)
print("Verification: isEnabledFor(TRACE) =", child.isEnabledFor(TRACE))
PYRepository: hivesolutions/colony
Length of output: 166
Use effective-level semantics for is_trace().
The current implementation reads self.logger.level directly, which returns 0 (NOTSET) for loggers that inherit their effective level from parent loggers. This causes is_trace() to incorrectly return False even when the effective level would enable trace logging. Use isEnabledFor(loggers.TRACE) to respect the standard logging semantics for level inheritance and disabled loggers.
🔧 Prefer the logger API
if not self.logger:
return False
- if not self.logger.level:
- return False
- return self.logger.level <= loggers.TRACE
+ is_enabled_for = getattr(self.logger, "isEnabledFor", None)
+ if is_enabled_for:
+ return is_enabled_for(loggers.TRACE)
+ level = getattr(self.logger, "level", None)
+ if level == None:
+ return False
+ return level <= loggers.TRACE🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.
In `@src/colony/base/system.py` around lines 6596 - 6611, The is_trace() method
incorrectly inspects self.logger.level directly (which may be 0/NOTSET for
inherited levels); change it to use the logger API so it respects
effective-level semantics: verify self.logger is not None and then return
self.logger.isEnabledFor(loggers.TRACE) (or False if no logger) so trace checks
honor parent/inherited levels; update references to is_trace, self.logger and
loggers.TRACE accordingly.
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -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: ... | ||
|
Comment on lines
139
to
+147
|
||
| 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): ... | ||
|
|
@@ -428,6 +430,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"): ... | ||
|
|
||
| Original file line number | Diff line number | Diff line change | ||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
|
|
@@ -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 """ | ||||||||||||||
|
Comment on lines
+32
to
+34
|
||||||||||||||
| """ 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 """ | |
| """ The silent level used to silence all logging | |
| or a handler, this is used as a utility for debugging | |
| purposes more than a real feature for production systems """ |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Docstring grammar typos in the newly added SILENT description (e.g., "silent all the logging", "more that"). Consider correcting to "silence all logging" / "more than".