Files
Medios-Macina/SYS/logger.py
T

330 lines
9.2 KiB
Python
Raw Normal View History

2025-11-25 20:09:33 -08:00
"""Unified logging utility for automatic file and function name tracking."""
import sys
2026-02-09 17:45:57 -08:00
import logging
2025-12-11 12:47:30 -08:00
import threading
2025-11-25 20:09:33 -08:00
from pathlib import Path
2026-04-16 17:18:50 -07:00
from typing import Any, Optional, Sequence
2025-11-25 20:09:33 -08:00
# SYS.rich_display deferred: rich (~100ms) loaded lazily on first log output.
_rich_display_mod: Any = None
def _console_for(file):
global _rich_display_mod
if _rich_display_mod is None:
import SYS.rich_display as _m
_rich_display_mod = _m
return _rich_display_mod.console_for(file)
2025-12-20 23:57:44 -08:00
2026-02-09 17:45:57 -08:00
logger = logging.getLogger(__name__)
2026-01-22 01:53:13 -08:00
# Global DB logger set later to avoid circular imports
_DB_LOGGER = None
def set_db_logger(func):
global _DB_LOGGER
_DB_LOGGER = func
2025-11-25 20:09:33 -08:00
_DEBUG_ENABLED = False
2025-12-11 12:47:30 -08:00
_thread_local = threading.local()
2025-12-29 17:05:03 -08:00
2025-12-11 12:47:30 -08:00
def set_thread_stream(stream):
"""Set a custom output stream for the current thread."""
_thread_local.stream = stream
2025-12-29 17:05:03 -08:00
2025-12-11 12:47:30 -08:00
def get_thread_stream():
"""Get the custom output stream for the current thread, if any."""
2025-12-29 17:05:03 -08:00
return getattr(_thread_local, "stream", None)
2025-11-25 20:09:33 -08:00
def set_debug(enabled: bool) -> None:
"""Enable or disable debug logging."""
global _DEBUG_ENABLED
_DEBUG_ENABLED = enabled
2025-12-29 17:05:03 -08:00
2025-12-11 12:47:30 -08:00
def is_debug_enabled() -> bool:
"""Check if debug logging is enabled."""
return _DEBUG_ENABLED
2025-12-29 17:05:03 -08:00
2026-04-16 17:18:50 -07:00
def _debug_output_suppressed() -> bool:
try:
stderr_name = getattr(sys.stderr, "name", "")
return "nul" in str(stderr_name).lower() or "/dev/null" in str(stderr_name)
except Exception:
return False
def _debug_output_file(file=None):
stream = get_thread_stream()
if stream is not None:
return stream
if file is not None:
return file
return sys.stderr
def _is_rich_renderable(value: Any) -> bool:
if value is None:
return False
if isinstance(value, (str, bytes, bytearray)):
return False
return bool(
hasattr(value, "__rich_console__")
or hasattr(value, "__rich__")
or value.__class__.__module__.startswith("rich.")
)
def _caller_location(depth: int = 1) -> tuple[str, str]:
import inspect as _inspect
frame = _inspect.currentframe()
2026-04-16 17:18:50 -07:00
current = frame
try:
for _ in range(max(0, int(depth))):
if current is None:
break
current = current.f_back
if current is None:
return "", ""
return Path(current.f_code.co_filename).stem, current.f_code.co_name
finally:
del frame
def _debug_db_log(*, caller_name: str, message: str, level: str = "DEBUG") -> None:
if not _DB_LOGGER:
return
try:
_DB_LOGGER(level, caller_name, message)
except Exception:
pass
def debug_panel(
title: str,
rows: Sequence[tuple[str, Any]],
*,
file=None,
border_style: str = "cyan",
) -> None:
"""Render a compact key/value debug panel when debug logging is enabled."""
if not _DEBUG_ENABLED or _debug_output_suppressed():
return
target_file = _debug_output_file(file)
try:
from rich.panel import Panel
from rich.table import Table as RichTable
grid = RichTable.grid(padding=(0, 1))
grid.add_column("Key", style="cyan", no_wrap=True)
grid.add_column("Value")
for key, val in rows:
try:
grid.add_row(str(key), str(val))
except Exception:
grid.add_row(str(key), "<unprintable>")
debug(
Panel(
grid,
title=str(title or "Debug"),
expand=False,
border_style=border_style,
),
file=target_file,
)
file_name, func_name = _caller_location(depth=2)
caller_name = f"{file_name}.{func_name}" if file_name and func_name else ""
_debug_db_log(
caller_name=caller_name,
message=f"[{title}] " + "; ".join(f"{k}={v}" for k, v in rows),
)
except Exception:
debug(title, list(rows), file=target_file)
2025-11-25 20:09:33 -08:00
def debug(*args, **kwargs) -> None:
"""Print debug message if debug logging is enabled.
2025-12-29 17:05:03 -08:00
2026-04-26 15:08:35 -07:00
Automatically routes through log() so debug output keeps the caller prefix.
2025-11-25 20:09:33 -08:00
"""
if not _DEBUG_ENABLED:
return
2025-12-29 17:05:03 -08:00
2025-12-11 12:47:30 -08:00
# Check if stderr has been redirected to /dev/null (quiet mode)
# If so, skip output to avoid queuing in background worker's capture
2026-04-16 17:18:50 -07:00
if _debug_output_suppressed():
return
2025-12-29 17:05:03 -08:00
2026-04-16 17:18:50 -07:00
target_file = _debug_output_file(kwargs.pop("file", None))
if len(args) == 1 and _is_rich_renderable(args[0]):
renderable = args[0]
_console_for(target_file).print(renderable)
2026-04-16 17:18:50 -07:00
file_name, func_name = _caller_location(depth=1)
caller_name = f"{file_name}.{func_name}" if file_name and func_name else ""
_debug_db_log(caller_name=caller_name, message=f"<rich:{type(renderable).__name__}>")
return
2025-12-29 17:05:03 -08:00
2025-11-25 20:09:33 -08:00
# Use the same logic as log()
2026-04-16 17:18:50 -07:00
log(*args, file=target_file, **kwargs)
2025-11-25 20:09:33 -08:00
2025-12-20 23:57:44 -08:00
def debug_inspect(
obj,
*,
title: str | None = None,
file=None,
methods: bool = False,
docs: bool = False,
private: bool = False,
dunder: bool = False,
sort: bool = True,
all: bool = False,
value: bool = True,
) -> None:
"""Rich-inspect an object when debug logging is enabled.
Uses the same stream / quiet-mode behavior as `debug()` and prepends a
`[file.function]` prefix when debug is enabled.
"""
if not _DEBUG_ENABLED:
return
# Mirror debug() quiet-mode guard.
2026-04-16 17:18:50 -07:00
if _debug_output_suppressed():
return
2025-12-20 23:57:44 -08:00
# Resolve destination stream.
2026-04-16 17:18:50 -07:00
file = _debug_output_file(file)
2025-12-20 23:57:44 -08:00
# Compute caller prefix (same as log()).
prefix = None
import inspect as _inspect
frame = _inspect.currentframe()
2025-12-20 23:57:44 -08:00
if frame is not None and frame.f_back is not None:
caller_frame = frame.f_back
try:
file_name = Path(caller_frame.f_code.co_filename).stem
func_name = caller_frame.f_code.co_name
prefix = f"[{file_name}.{func_name}]"
finally:
del caller_frame
if frame is not None:
del frame
# Render.
from rich import inspect as rich_inspect
console = _console_for(file)
2025-12-20 23:57:44 -08:00
# If the caller provides a title, treat it as authoritative.
# Only fall back to the automatic [file.func] prefix when no title is supplied.
effective_title = title
if not effective_title and prefix:
effective_title = prefix
2025-12-21 05:10:09 -08:00
# Show full identifiers (hashes/paths) without Rich shortening.
# Guard for older Rich versions which may not support max_* parameters.
try:
rich_inspect(
obj,
console=console,
title=effective_title,
methods=methods,
docs=docs,
private=private,
dunder=dunder,
sort=sort,
all=all,
value=value,
max_string=100_000,
max_length=100_000,
2026-01-19 06:24:09 -08:00
) # type: ignore[call-arg]
2025-12-21 05:10:09 -08:00
except TypeError:
rich_inspect(
obj,
console=console,
title=effective_title,
methods=methods,
docs=docs,
private=private,
dunder=dunder,
sort=sort,
all=all,
value=value,
)
2025-12-20 23:57:44 -08:00
2025-11-25 20:09:33 -08:00
def log(*args, **kwargs) -> None:
"""Print with automatic file.function prefix.
2025-12-29 17:05:03 -08:00
2025-11-25 20:09:33 -08:00
Automatically prepends [filename.function_name] to all output.
Defaults to stdout if not specified.
2025-12-29 17:05:03 -08:00
2025-11-25 20:09:33 -08:00
Example:
log("Upload started") # Output: [add_file.run] Upload started
"""
2025-12-05 03:42:57 -08:00
# When debug is disabled, suppress the automatic prefix for cleaner user-facing output.
add_prefix = _DEBUG_ENABLED
2025-11-25 20:09:33 -08:00
# Get the calling frame
import inspect as _inspect
frame = _inspect.currentframe()
2025-11-25 20:09:33 -08:00
if frame is None:
2025-12-20 23:57:44 -08:00
file = kwargs.pop("file", sys.stdout)
sep = kwargs.pop("sep", " ")
end = kwargs.pop("end", "\n")
_console_for(file).print(*args, sep=sep, end=end)
2025-11-25 20:09:33 -08:00
return
2025-12-29 17:05:03 -08:00
2025-11-25 20:09:33 -08:00
caller_frame = frame.f_back
if caller_frame is None:
2025-12-20 23:57:44 -08:00
file = kwargs.pop("file", sys.stdout)
sep = kwargs.pop("sep", " ")
end = kwargs.pop("end", "\n")
_console_for(file).print(*args, sep=sep, end=end)
2025-11-25 20:09:33 -08:00
return
2025-12-29 17:05:03 -08:00
2025-11-25 20:09:33 -08:00
try:
# Get file name without extension
file_name = Path(caller_frame.f_code.co_filename).stem
2025-12-29 17:05:03 -08:00
2025-11-25 20:09:33 -08:00
# Get function name
func_name = caller_frame.f_code.co_name
2025-12-29 17:05:03 -08:00
2025-12-11 12:47:30 -08:00
# Check for thread-local stream first
stream = get_thread_stream()
if stream:
2025-12-29 17:05:03 -08:00
kwargs["file"] = stream
2025-11-25 20:09:33 -08:00
# Set default to stdout if not specified
2025-12-29 17:05:03 -08:00
elif "file" not in kwargs:
kwargs["file"] = sys.stdout
2025-12-20 23:57:44 -08:00
file = kwargs.pop("file", sys.stdout)
sep = kwargs.pop("sep", " ")
end = kwargs.pop("end", "\n")
2025-12-05 03:42:57 -08:00
if add_prefix:
prefix = f"[{file_name}.{func_name}]"
_console_for(file).print(prefix, *args, sep=sep, end=end)
2025-12-05 03:42:57 -08:00
else:
_console_for(file).print(*args, sep=sep, end=end)
2026-01-22 01:53:13 -08:00
# Log to database if available
if _DB_LOGGER:
try:
msg = sep.join(map(str, args))
level = "DEBUG" if add_prefix else "INFO"
_DB_LOGGER(level, f"{file_name}.{func_name}", msg)
except Exception:
pass
2025-11-25 20:09:33 -08:00
finally:
del frame
del caller_frame