Update logging with console output format changes

"console_format_type" with "normal", "condensed", "minimal" options
This sets the format of the console output, controlling the amount of detail shown.
normal show log title, file, function and line number
condensed show file and line number only
minimal shows only timestamp, log level and message
Default is normal

"console_iso_precision" with "seconds", "milliseconds", "microseconds" options
This sets the precision of the ISO timestamp in console logs.
Default is milliseconds

The timestamp output is now ISO8601 formatatted with time zone.
This commit is contained in:
Clemens Schwaighofer
2025-11-18 15:31:16 +09:00
parent 6a1724695e
commit 592652cff1
10 changed files with 290 additions and 7 deletions

View File

@@ -28,6 +28,8 @@ class LogSettings(TypedDict):
per_run_log: bool
console_enabled: bool
console_color_output_enabled: bool
console_format_type: str
console_iso_precision: str
add_start_info: bool
add_end_info: bool
log_queue: 'Queue[str] | None'
@@ -39,6 +41,18 @@ class LoggerInit(TypedDict):
log_queue: 'Queue[str] | None'
# show log title, file, function and line number types
CONSOLE_FORMAT_TYPE_NORMAL = 'normal'
# show file and line number only
CONSOLE_FORMAT_TYPE_CONDENSED = 'condensed'
# only show timestamp, log level and message
CONSOLE_FORMAT_TYPE_MINIMAL = 'minimal'
# for console ISO time format
CONSOLE_ISO_TIME_SECONDS = 'seconds'
CONSOLE_ISO_TIME_MILLISECONDS = 'milliseconds'
CONSOLE_ISO_TIME_MICROSECONDS = 'microseconds'
# MARK: Custom color filter
class CustomConsoleFormatter(logging.Formatter):
"""
@@ -56,6 +70,21 @@ class CustomConsoleFormatter(logging.Formatter):
LoggingLevel.EXCEPTION.name: Colors.magenta_bright, # will never be written to console
}
# def formatTime(self, record: logging.LogRecord, datefmt: str | None = None):
# """
# Set timestamp in ISO8601 format
# Arguments:
# record {logging.LogRecord} -- _description_
# Keyword Arguments:
# datefmt {str | None} -- _description_ (default: {None})
# Returns:
# _type_ -- _description_
# """
# return datetime.fromtimestamp(record.created).astimezone().isoformat(sep=' ', timespec='milliseconds')
def format(self, record: logging.LogRecord) -> str:
"""
set the color highlight
@@ -409,6 +438,9 @@ class Log(LogParent):
"per_run_log": False,
"console_enabled": True,
"console_color_output_enabled": True,
# do not print log title, file, function and line number
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": True,
"add_end_info": False,
"log_queue": None,
@@ -461,8 +493,11 @@ class Log(LogParent):
if self.log_settings['console_enabled']:
# console
self.add_handler('stream_handler', self.__create_console_handler(
'stream_handler', self.log_settings['log_level_console'])
)
'stream_handler',
self.log_settings['log_level_console'],
console_format_type=self.log_settings['console_format_type'],
console_iso_precision=self.log_settings['console_iso_precision']
))
# add other handlers,
if other_handlers is not None:
for handler_key, handler in other_handlers.items():
@@ -518,6 +553,27 @@ class Log(LogParent):
if not isinstance(__setting := log_settings.get(__log_entry, ''), bool):
__setting = self.DEFAULT_LOG_SETTINGS.get(__log_entry, True)
default_log_settings[__log_entry] = __setting
# check console log type
default_log_settings['console_format_type'] = cast('str', log_settings.get(
'console_format_type', self.DEFAULT_LOG_SETTINGS['console_format_type']
))
# if not valid
if default_log_settings['console_format_type'] not in [
CONSOLE_FORMAT_TYPE_NORMAL,
CONSOLE_FORMAT_TYPE_CONDENSED,
CONSOLE_FORMAT_TYPE_MINIMAL,
]:
default_log_settings['console_format_type'] = self.DEFAULT_LOG_SETTINGS['console_format_type']
# check console iso time precision
default_log_settings['console_iso_precision'] = cast('str', log_settings.get(
'console_iso_precision', self.DEFAULT_LOG_SETTINGS['console_iso_precision']
))
if default_log_settings['console_iso_precision'] not in [
CONSOLE_ISO_TIME_SECONDS,
CONSOLE_ISO_TIME_MILLISECONDS,
CONSOLE_ISO_TIME_MICROSECONDS,
]:
default_log_settings['console_iso_precision'] = self.DEFAULT_LOG_SETTINGS['console_iso_precision']
# check log queue
__setting = log_settings.get('log_queue', self.DEFAULT_LOG_SETTINGS['log_queue'])
if __setting is not None:
@@ -554,7 +610,10 @@ class Log(LogParent):
# MARK: console handler
def __create_console_handler(
self, handler_name: str,
log_level_console: LoggingLevel = LoggingLevel.WARNING, filter_exceptions: bool = True
log_level_console: LoggingLevel = LoggingLevel.WARNING,
filter_exceptions: bool = True,
console_format_type: str = CONSOLE_FORMAT_TYPE_NORMAL,
console_iso_precision: str = CONSOLE_ISO_TIME_MILLISECONDS
) -> logging.StreamHandler[TextIO]:
# console logger
if not self.validate_log_level(log_level_console):
@@ -562,18 +621,42 @@ class Log(LogParent):
console_handler = logging.StreamHandler()
# format layouts
format_string = (
'[%(asctime)s.%(msecs)03d] '
# '[%(asctime)s.%(msecs)03d] '
'[%(asctime)s] '
'[%(name)s] '
'[%(filename)s:%(funcName)s:%(lineno)d] '
'<%(levelname)s> '
'%(message)s'
)
if console_format_type == CONSOLE_FORMAT_TYPE_CONDENSED:
format_string = (
'[%(asctime)s] '
'[%(filename)s:%(lineno)d] '
'<%(levelname)s> '
'%(message)s'
)
elif console_format_type == CONSOLE_FORMAT_TYPE_MINIMAL:
format_string = (
'[%(asctime)s] '
'<%(levelname)s> '
'%(message)s'
)
format_date = "%Y-%m-%d %H:%M:%S"
# color or not
if self.log_settings['console_color_output_enabled']:
formatter_console = CustomConsoleFormatter(format_string, datefmt=format_date)
else:
formatter_console = logging.Formatter(format_string, datefmt=format_date)
print(f"PREC: {console_iso_precision}")
# this one needs lambda self, ...
# logging.Formatter.formatTime = (
formatter_console.formatTime = (
lambda record, datefmt=None:
datetime
.fromtimestamp(record.created)
.astimezone()
.isoformat(sep="T", timespec=console_iso_precision)
)
console_handler.set_name(handler_name)
console_handler.setLevel(log_level_console.name)
# do not show exceptions logs on console
@@ -614,7 +697,8 @@ class Log(LogParent):
formatter_file_handler = logging.Formatter(
(
# time stamp
'[%(asctime)s.%(msecs)03d] '
# '[%(asctime)s.%(msecs)03d] '
'[%(asctime)s] '
# log name
'[%(name)s] '
# filename + pid
@@ -628,6 +712,13 @@ class Log(LogParent):
),
datefmt="%Y-%m-%dT%H:%M:%S",
)
formatter_file_handler.formatTime = (
lambda record, datefmt=None:
datetime
.fromtimestamp(record.created)
.astimezone()
.isoformat(sep="T", timespec="microseconds")
)
file_handler.set_name(handler_name)
file_handler.setLevel(log_level_file.name)
# do not show errors flagged with console (they are from exceptions)

View File

@@ -6,7 +6,7 @@ Log logging_handling.log testing
import sys
from pathlib import Path
# this is for testing only
from corelibs.logging_handling.log import Log, Logger
from corelibs.logging_handling.log import Log, Logger, CONSOLE_FORMAT_TYPE_MINIMAL, CONSOLE_ISO_TIME_MICROSECONDS
from corelibs.debug_handling.debug_helpers import exception_stack, call_stack
from corelibs.logging_handling.logging_level_handling.logging_level import LoggingLevel
@@ -24,7 +24,10 @@ def main():
# "log_level_console": None,
"log_level_file": 'DEBUG',
# "console_color_output_enabled": False,
"per_run_log": True
"per_run_log": True,
# Set console log type
"console_format_type": CONSOLE_FORMAT_TYPE_MINIMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MICROSECONDS,
}
)
logn = Logger(log.get_logger_settings())

View File

@@ -11,6 +11,12 @@ from corelibs.logging_handling.log import (
Log,
LogParent,
LogSettings,
CONSOLE_FORMAT_TYPE_NORMAL,
CONSOLE_FORMAT_TYPE_CONDENSED,
CONSOLE_FORMAT_TYPE_MINIMAL,
CONSOLE_ISO_TIME_MILLISECONDS,
CONSOLE_ISO_TIME_SECONDS,
CONSOLE_ISO_TIME_MICROSECONDS,
)
from corelibs.logging_handling.logging_level_handling.logging_level import LoggingLevel
@@ -33,6 +39,8 @@ def basic_log_settings() -> LogSettings:
"per_run_log": False,
"console_enabled": True,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,
@@ -99,6 +107,143 @@ class TestLogSettingsParsing:
assert log.log_settings["console_enabled"] == Log.DEFAULT_LOG_SETTINGS["console_enabled"]
assert log.log_settings["per_run_log"] == Log.DEFAULT_LOG_SETTINGS["per_run_log"]
def test_parse_console_format_type_normal(self, tmp_log_path: Path):
"""Test parsing with console_format_type set to normal"""
settings: dict[str, Any] = {
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
}
log = Log(
log_path=tmp_log_path,
log_name="test",
log_settings=settings # type: ignore
)
assert log.log_settings["console_format_type"] == CONSOLE_FORMAT_TYPE_NORMAL
def test_parse_console_format_type_condensed(self, tmp_log_path: Path):
"""Test parsing with console_format_type set to condensed"""
settings: dict[str, Any] = {
"console_format_type": CONSOLE_FORMAT_TYPE_CONDENSED,
}
log = Log(
log_path=tmp_log_path,
log_name="test",
log_settings=settings # type: ignore
)
assert log.log_settings["console_format_type"] == CONSOLE_FORMAT_TYPE_CONDENSED
def test_parse_console_format_type_minimal(self, tmp_log_path: Path):
"""Test parsing with console_format_type set to minimal"""
settings: dict[str, Any] = {
"console_format_type": CONSOLE_FORMAT_TYPE_MINIMAL,
}
log = Log(
log_path=tmp_log_path,
log_name="test",
log_settings=settings # type: ignore
)
assert log.log_settings["console_format_type"] == CONSOLE_FORMAT_TYPE_MINIMAL
def test_parse_console_format_type_invalid(self, tmp_log_path: Path):
"""Test parsing with invalid console_format_type falls back to default"""
settings: dict[str, Any] = {
"console_format_type": "invalid_format",
}
log = Log(
log_path=tmp_log_path,
log_name="test",
log_settings=settings # type: ignore
)
# Should fall back to default
assert log.log_settings["console_format_type"] == Log.DEFAULT_LOG_SETTINGS["console_format_type"]
def test_parse_console_iso_precision_seconds(self, tmp_log_path: Path):
"""Test parsing with console_iso_precision set to seconds"""
settings: dict[str, Any] = {
"console_iso_precision": CONSOLE_ISO_TIME_SECONDS,
}
log = Log(
log_path=tmp_log_path,
log_name="test",
log_settings=settings # type: ignore
)
assert log.log_settings["console_iso_precision"] == CONSOLE_ISO_TIME_SECONDS
def test_parse_console_iso_precision_milliseconds(self, tmp_log_path: Path):
"""Test parsing with console_iso_precision set to milliseconds"""
settings: dict[str, Any] = {
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
}
log = Log(
log_path=tmp_log_path,
log_name="test",
log_settings=settings # type: ignore
)
assert log.log_settings["console_iso_precision"] == CONSOLE_ISO_TIME_MILLISECONDS
def test_parse_console_iso_precision_microseconds(self, tmp_log_path: Path):
"""Test parsing with console_iso_precision set to microseconds"""
settings: dict[str, Any] = {
"console_iso_precision": CONSOLE_ISO_TIME_MICROSECONDS,
}
log = Log(
log_path=tmp_log_path,
log_name="test",
log_settings=settings # type: ignore
)
assert log.log_settings["console_iso_precision"] == CONSOLE_ISO_TIME_MICROSECONDS
def test_parse_console_iso_precision_invalid(self, tmp_log_path: Path):
"""Test parsing with invalid console_iso_precision falls back to default"""
settings: dict[str, Any] = {
"console_iso_precision": "invalid_precision",
}
log = Log(
log_path=tmp_log_path,
log_name="test",
log_settings=settings # type: ignore
)
# Should fall back to default
assert log.log_settings["console_iso_precision"] == Log.DEFAULT_LOG_SETTINGS["console_iso_precision"]
def test_parse_both_console_settings_valid(self, tmp_log_path: Path):
"""Test parsing with both console_format_type and console_iso_precision set"""
settings: dict[str, Any] = {
"console_format_type": CONSOLE_FORMAT_TYPE_CONDENSED,
"console_iso_precision": CONSOLE_ISO_TIME_MICROSECONDS,
}
log = Log(
log_path=tmp_log_path,
log_name="test",
log_settings=settings # type: ignore
)
assert log.log_settings["console_format_type"] == CONSOLE_FORMAT_TYPE_CONDENSED
assert log.log_settings["console_iso_precision"] == CONSOLE_ISO_TIME_MICROSECONDS
def test_parse_both_console_settings_invalid(self, tmp_log_path: Path):
"""Test parsing with both console settings invalid falls back to defaults"""
settings: dict[str, Any] = {
"console_format_type": "invalid_format",
"console_iso_precision": "invalid_precision",
}
log = Log(
log_path=tmp_log_path,
log_name="test",
log_settings=settings # type: ignore
)
# Should fall back to defaults
assert log.log_settings["console_format_type"] == Log.DEFAULT_LOG_SETTINGS["console_format_type"]
assert log.log_settings["console_iso_precision"] == Log.DEFAULT_LOG_SETTINGS["console_iso_precision"]
# MARK: Test Spacer Constants
class TestSpacerConstants:
@@ -160,6 +305,8 @@ class TestParametrized:
("per_run_log", True, "not_bool"),
("console_enabled", False, 123),
("console_color_output_enabled", True, None),
("console_format_type", CONSOLE_FORMAT_TYPE_NORMAL, "invalid_format"),
("console_iso_precision", CONSOLE_ISO_TIME_MILLISECONDS, "invalid_precision"),
("add_start_info", False, []),
("add_end_info", True, {}),
])

View File

@@ -13,6 +13,8 @@ from corelibs.logging_handling.log import (
LogParent,
LogSettings,
CustomConsoleFormatter,
CONSOLE_FORMAT_TYPE_NORMAL,
CONSOLE_ISO_TIME_MILLISECONDS,
)
from corelibs.logging_handling.logging_level_handling.logging_level import LoggingLevel
@@ -35,6 +37,8 @@ def basic_log_settings() -> LogSettings:
"per_run_log": False,
"console_enabled": True,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,
@@ -169,6 +173,8 @@ class TestLogInitialization:
"per_run_log": False,
"console_enabled": False,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,
@@ -190,6 +196,8 @@ class TestLogInitialization:
"per_run_log": True,
"console_enabled": False,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,
@@ -256,6 +264,8 @@ class TestLogInitialization:
"per_run_log": False,
"console_enabled": True,
"console_color_output_enabled": True,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,

View File

@@ -11,6 +11,8 @@ from corelibs.logging_handling.log import (
Log,
LogSettings,
CustomConsoleFormatter,
CONSOLE_FORMAT_TYPE_NORMAL,
CONSOLE_ISO_TIME_MILLISECONDS,
)
from corelibs.logging_handling.logging_level_handling.logging_level import LoggingLevel
@@ -33,6 +35,8 @@ def basic_log_settings() -> LogSettings:
"per_run_log": False,
"console_enabled": True,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,

View File

@@ -11,6 +11,8 @@ from corelibs.logging_handling.log import (
Log,
LogSettings,
CustomHandlerFilter,
CONSOLE_FORMAT_TYPE_NORMAL,
CONSOLE_ISO_TIME_MILLISECONDS,
)
from corelibs.logging_handling.logging_level_handling.logging_level import LoggingLevel
@@ -33,6 +35,8 @@ def basic_log_settings() -> LogSettings:
"per_run_log": False,
"console_enabled": True,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,

View File

@@ -11,6 +11,8 @@ from corelibs.logging_handling.log import (
Log,
LogParent,
LogSettings,
CONSOLE_FORMAT_TYPE_NORMAL,
CONSOLE_ISO_TIME_MILLISECONDS,
)
from corelibs.logging_handling.logging_level_handling.logging_level import LoggingLevel
@@ -33,6 +35,8 @@ def basic_log_settings() -> LogSettings:
"per_run_log": False,
"console_enabled": True,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,
@@ -61,6 +65,8 @@ class TestHandlerManagement:
"per_run_log": False,
"console_enabled": False,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,

View File

@@ -10,6 +10,8 @@ from corelibs.logging_handling.log import (
Log,
Logger,
LogSettings,
CONSOLE_FORMAT_TYPE_NORMAL,
CONSOLE_ISO_TIME_MILLISECONDS,
)
from corelibs.logging_handling.logging_level_handling.logging_level import LoggingLevel
@@ -32,6 +34,8 @@ def basic_log_settings() -> LogSettings:
"per_run_log": False,
"console_enabled": True,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,

View File

@@ -10,6 +10,8 @@ import pytest
from corelibs.logging_handling.log import (
Log,
LogSettings,
CONSOLE_FORMAT_TYPE_NORMAL,
CONSOLE_ISO_TIME_MILLISECONDS,
)
from corelibs.logging_handling.logging_level_handling.logging_level import LoggingLevel
@@ -32,6 +34,8 @@ def basic_log_settings() -> LogSettings:
"per_run_log": False,
"console_enabled": True,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,
@@ -88,6 +92,8 @@ class TestEdgeCases:
"per_run_log": False,
"console_enabled": False,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": True, # Enable end info
"log_queue": None,

View File

@@ -12,6 +12,8 @@ import pytest
from corelibs.logging_handling.log import (
Log,
LogSettings,
CONSOLE_FORMAT_TYPE_NORMAL,
CONSOLE_ISO_TIME_MILLISECONDS,
)
from corelibs.logging_handling.logging_level_handling.logging_level import LoggingLevel
@@ -34,6 +36,8 @@ def basic_log_settings() -> LogSettings:
"per_run_log": False,
"console_enabled": True,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": None,
@@ -68,6 +72,8 @@ class TestQueueListener:
"per_run_log": False,
"console_enabled": False,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": mock_queue, # type: ignore
@@ -103,6 +109,8 @@ class TestQueueListener:
"per_run_log": False,
"console_enabled": False,
"console_color_output_enabled": False,
"console_format_type": CONSOLE_FORMAT_TYPE_NORMAL,
"console_iso_precision": CONSOLE_ISO_TIME_MILLISECONDS,
"add_start_info": False,
"add_end_info": False,
"log_queue": mock_queue, # type: ignore