SXXXXXXX_MarkdownConverter/markdownconverter/utils/logger.py
2025-06-17 15:18:44 +02:00

629 lines
24 KiB
Python

# FlightMonitor/utils/logger.py
import logging
import logging.handlers # For RotatingFileHandler
import tkinter as tk
from tkinter.scrolledtext import ScrolledText
from queue import Queue, Empty as QueueEmpty # Renamed for clarity
from typing import Optional, Dict, Any
# --- Module-level globals for the new centralized logging queue system ---
_global_log_queue: Optional[Queue[logging.LogRecord]] = None
_actual_console_handler: Optional[logging.StreamHandler] = None
_actual_file_handler: Optional[logging.handlers.RotatingFileHandler] = None
_actual_tkinter_handler: Optional["TkinterTextHandler"] = None # Forward declaration
_log_processor_after_id: Optional[str] = None
_logging_system_active: bool = False
_tk_root_instance_for_processing: Optional[tk.Tk] = None
_base_formatter: Optional[logging.Formatter] = None # Store the main formatter
# Interval for polling the global log queue by the GUI thread processor
GLOBAL_LOG_QUEUE_POLL_INTERVAL_MS = 50
class TkinterTextHandler(logging.Handler):
"""
A logging handler that directs log messages to a Tkinter Text widget.
This handler itself is now called by _process_global_log_queue,
which runs in the GUI thread. Its internal queue is for batching updates
to the Text widget if needed, or could be simplified later.
"""
def __init__(
self,
text_widget: tk.Text, # ScrolledText is a tk.Text
level_colors: Dict[int, str],
# root_tk_instance and queue_poll_interval_ms for its own internal queue might be redundant
# if _process_global_log_queue handles batching, but kept for now.
# For now, this handler will still use its own internal queue and after loop for safety.
root_tk_instance_for_widget_update: tk.Tk,
internal_poll_interval_ms: int = 100,
):
super().__init__()
self.text_widget = text_widget
self.level_colors = level_colors
self._is_active = True # Internal active state for this specific handler
self._widget_update_queue = Queue()
self._root_for_widget_update = root_tk_instance_for_widget_update
self._internal_poll_interval_ms = internal_poll_interval_ms
self._internal_after_id: Optional[str] = None
if not (
self.text_widget
and hasattr(self.text_widget, "winfo_exists")
and self.text_widget.winfo_exists()
):
print(
"ERROR: TkinterTextHandler initialized with an invalid or non-existent text_widget.",
flush=True,
)
self._is_active = False
return
if not (
self._root_for_widget_update
and hasattr(self._root_for_widget_update, "winfo_exists")
and self._root_for_widget_update.winfo_exists()
):
print(
"ERROR: TkinterTextHandler initialized with an invalid root for widget update.",
flush=True,
)
self._is_active = False
return
if self._is_active:
self._configure_tags()
self._process_widget_update_queue() # Start its own update loop
def _configure_tags(self):
if not self._is_active or not self.text_widget.winfo_exists():
return
for level, color_value in self.level_colors.items():
level_name = logging.getLevelName(level)
if color_value:
try:
self.text_widget.tag_config(level_name, foreground=color_value)
except tk.TclError:
print(
f"Warning: Could not configure tag for {level_name} in TkinterTextHandler.",
flush=True,
)
def emit(self, record: logging.LogRecord):
# This emit is called by _process_global_log_queue (already in GUI thread)
if not self._is_active or not self.text_widget.winfo_exists():
# This case should ideally not happen if setup is correct
# print(
# f"DEBUG: TkinterTextHandler.emit called but inactive or widget gone. Record: {record.getMessage()}",
# flush=True,
# )
return
try:
msg = self.format(
record
) # Format the record using the formatter set on this handler
level_name = record.levelname
# Put in its own queue for batched widget updates
self._widget_update_queue.put_nowait((level_name, msg))
except Exception as e:
print(
f"Error in TkinterTextHandler.emit (to internal queue): {e}", flush=True
)
def _process_widget_update_queue(self):
if (
not self._is_active
or not self.text_widget.winfo_exists()
or not self._root_for_widget_update.winfo_exists()
):
self._is_active = False
if self._internal_after_id and self._root_for_widget_update.winfo_exists():
try:
self._root_for_widget_update.after_cancel(self._internal_after_id)
except Exception:
pass
self._internal_after_id = None
# print("DEBUG: TkinterTextHandler._process_widget_update_queue stopping (inactive/widget gone).", flush=True)
return
had_messages = False
try:
while not self._widget_update_queue.empty():
had_messages = True
level_name, msg = self._widget_update_queue.get_nowait()
if self.text_widget.winfo_exists():
self.text_widget.configure(state=tk.NORMAL)
self.text_widget.insert(tk.END, msg + "\n", (level_name,))
self.text_widget.configure(state=tk.DISABLED)
else: # Widget destroyed during processing
self._is_active = False
break
self._widget_update_queue.task_done()
if had_messages and self.text_widget.winfo_exists():
self.text_widget.see(tk.END)
except tk.TclError as e_tcl:
print(
f"TkinterTextHandler TclError during widget update: {e_tcl}. Handler stopping.",
flush=True,
)
self._is_active = False
except Exception as e_update:
print(
f"Unexpected error updating TkinterTextHandler widget: {e_update}. Handler stopping.",
flush=True,
)
self._is_active = False
if self._is_active and self._root_for_widget_update.winfo_exists():
self._internal_after_id = self._root_for_widget_update.after(
self._internal_poll_interval_ms, self._process_widget_update_queue
)
else: # Ensure it's cleaned up if we are stopping
if self._internal_after_id and self._root_for_widget_update.winfo_exists():
try:
self._root_for_widget_update.after_cancel(self._internal_after_id)
except Exception:
pass
self._internal_after_id = None
def close(self):
# print("INFO: TkinterTextHandler close called.", flush=True) # Reduced verbosity
self._is_active = False
if (
self._internal_after_id
and hasattr(self, "_root_for_widget_update")
and self._root_for_widget_update
and self._root_for_widget_update.winfo_exists()
):
try:
self._root_for_widget_update.after_cancel(self._internal_after_id)
except Exception:
pass
self._internal_after_id = None
# Drain its internal queue
while not self._widget_update_queue.empty():
try:
self._widget_update_queue.get_nowait()
self._widget_update_queue.task_done()
except Exception:
break
super().close()
class QueuePuttingHandler(logging.Handler):
"""
A simple handler that puts any received LogRecord into a global queue.
"""
def __init__(self, handler_queue: Queue[logging.LogRecord]):
super().__init__()
self.handler_queue = handler_queue
def emit(self, record: logging.LogRecord):
try:
self.handler_queue.put_nowait(record)
except queue.Full: # Standard library 'queue.Full'
print(
f"CRITICAL: Global log queue is full! Log record for '{record.name}' might be lost.",
flush=True,
)
except Exception as e:
print(
f"CRITICAL: Error putting log record into global queue: {e}", flush=True
)
def _process_global_log_queue():
"""
GUI Thread: Periodically processes LogRecords from the _global_log_queue
and dispatches them to the actual configured handlers.
"""
global _logging_system_active, _log_processor_after_id
# print(f"DEBUG: _process_global_log_queue called. Active: {_logging_system_active}", flush=True)
if not _logging_system_active:
if (
_log_processor_after_id
and _tk_root_instance_for_processing
and _tk_root_instance_for_processing.winfo_exists()
):
try:
_tk_root_instance_for_processing.after_cancel(_log_processor_after_id)
except Exception:
pass
_log_processor_after_id = None
return
if not (
_tk_root_instance_for_processing
and _tk_root_instance_for_processing.winfo_exists()
):
_logging_system_active = False
_log_processor_after_id = None
return
processed_count = 0
try:
while _global_log_queue and not _global_log_queue.empty():
if not _logging_system_active:
break
try:
record = _global_log_queue.get_nowait()
processed_count += 1
if _actual_console_handler:
try:
_actual_console_handler.handle(record)
except Exception as e_con:
print(f"Error in console_handler.handle: {e_con}", flush=True)
if _actual_file_handler:
try:
_actual_file_handler.handle(record)
except Exception as e_file:
print(f"Error in file_handler.handle: {e_file}", flush=True)
if _actual_tkinter_handler:
try:
_actual_tkinter_handler.handle(record)
except Exception as e_tk:
print(f"Error in tkinter_handler.handle: {e_tk}", flush=True)
_global_log_queue.task_done()
except QueueEmpty:
break
except Exception as e_proc_item:
print(
f"Error processing a log item from global queue: {e_proc_item}",
flush=True,
)
except Exception as e_outer_loop:
print(
f"Critical error in _process_global_log_queue outer loop: {e_outer_loop}",
flush=True,
)
if _logging_system_active and _tk_root_instance_for_processing.winfo_exists():
_log_processor_after_id = _tk_root_instance_for_processing.after(
GLOBAL_LOG_QUEUE_POLL_INTERVAL_MS, _process_global_log_queue
)
def setup_basic_logging( # MODIFIED: Renamed from setup_logging
root_tk_instance_for_processor: Optional[
tk.Tk
], # MODIFIED: Now mandatory for processor
logging_config_dict: Optional[Dict[str, Any]] = None,
):
global _global_log_queue, _actual_console_handler, _actual_file_handler
global _logging_system_active, _tk_root_instance_for_processing
global _log_processor_after_id, _base_formatter, _actual_tkinter_handler # _actual_tkinter_handler should be None here
# This function should only be called ONCE.
if _logging_system_active:
print(
"WARNING: setup_basic_logging called but logging system is already active. Ignoring call.",
flush=True,
)
return
print("INFO: Configuring basic centralized queued logging system...", flush=True)
_actual_tkinter_handler = None # Ensure it's None at basic setup
if logging_config_dict is None:
print(
"Warning: No logging_config_dict. Using basic console-only defaults for queued logging.",
flush=True,
)
# Simplified default, as Tkinter parts are handled by add_tkinter_handler
logging_config_dict = {
"default_root_level": logging.INFO,
"specific_levels": {},
"format": "%(asctime)s [%(levelname)-8s] %(name)-25s : %(message)s",
"date_format": "%Y-%m-%d %H:%M:%S",
"enable_console": True,
"enable_file": False,
}
root_log_level = logging_config_dict.get("default_root_level", logging.INFO)
specific_levels = logging_config_dict.get("specific_levels", {})
log_format_str = logging_config_dict.get(
"format", "%(asctime)s [%(levelname)-8s] %(name)-25s : %(message)s"
)
log_date_format_str = logging_config_dict.get("date_format", "%Y-%m-%d %H:%M:%S")
enable_console = logging_config_dict.get("enable_console", True)
enable_file = logging_config_dict.get("enable_file", False)
_base_formatter = logging.Formatter(log_format_str, datefmt=log_date_format_str)
_global_log_queue = Queue()
_tk_root_instance_for_processing = root_tk_instance_for_processor
root_logger = logging.getLogger()
for handler in root_logger.handlers[
:
]: # Clear any pre-existing handlers (e.g. from basicConfig)
try:
handler.close()
root_logger.removeHandler(handler)
except Exception:
pass
root_logger.handlers = []
root_logger.setLevel(root_log_level)
print(
f"INFO: Root logger level set to {logging.getLevelName(root_logger.level)}.",
flush=True,
)
for logger_name, level in specific_levels.items():
named_logger = logging.getLogger(logger_name)
named_logger.setLevel(level)
named_logger.propagate = True
print(
f"INFO: Logger '{logger_name}' level set to {logging.getLevelName(named_logger.level)}.",
flush=True,
)
if enable_console:
try:
_actual_console_handler = logging.StreamHandler()
_actual_console_handler.setFormatter(_base_formatter)
_actual_console_handler.setLevel(logging.DEBUG)
print("INFO: Actual ConsoleHandler created.", flush=True)
except Exception as e:
print(f"ERROR: Failed to create actual ConsoleHandler: {e}", flush=True)
_actual_console_handler = None
if enable_file:
try:
file_path = logging_config_dict.get("file_path", "flight_monitor_app.log")
file_max_bytes = logging_config_dict.get("file_max_bytes", 5 * 1024 * 1024)
file_backup_count = logging_config_dict.get("file_backup_count", 3)
_actual_file_handler = logging.handlers.RotatingFileHandler(
file_path,
maxBytes=file_max_bytes,
backupCount=file_backup_count,
encoding="utf-8",
)
_actual_file_handler.setFormatter(_base_formatter)
_actual_file_handler.setLevel(logging.DEBUG)
print(
f"INFO: Actual RotatingFileHandler created for '{file_path}'.",
flush=True,
)
except Exception as e:
print(
f"ERROR: Failed to create actual FileHandler for '{file_path}': {e}",
flush=True,
)
_actual_file_handler = None
if _global_log_queue is not None:
queue_putter = QueuePuttingHandler(handler_queue=_global_log_queue)
queue_putter.setLevel(logging.DEBUG)
root_logger.addHandler(queue_putter)
print(f"INFO: QueuePuttingHandler added to root logger.", flush=True)
else:
print(
"CRITICAL ERROR: Global log queue not initialized in basic setup!",
flush=True,
)
_logging_system_active = True
if (
_tk_root_instance_for_processing
and _tk_root_instance_for_processing.winfo_exists()
):
if _log_processor_after_id: # Should be None here, but defensive
try:
_tk_root_instance_for_processing.after_cancel(_log_processor_after_id)
except Exception:
pass
_log_processor_after_id = _tk_root_instance_for_processing.after(
GLOBAL_LOG_QUEUE_POLL_INTERVAL_MS, _process_global_log_queue
)
print(
f"INFO: Global log queue processor scheduled (ID: {_log_processor_after_id}).",
flush=True,
)
elif not _tk_root_instance_for_processing:
print(
"WARNING: No Tkinter root instance for processor. Logs will queue but not be dispatched by this setup function alone.",
flush=True,
)
print("INFO: Basic centralized queued logging system setup complete.", flush=True)
logging.getLogger("FlightMonitor.LoggerTest").info(
"Basic logging initialized. This is a test from setup_basic_logging."
)
def add_tkinter_handler( # NEW FUNCTION
gui_log_widget: tk.Text,
root_tk_instance_for_gui_handler: tk.Tk,
logging_config_dict: Dict[str, Any],
):
global _actual_tkinter_handler, _base_formatter
if not _logging_system_active:
print(
"ERROR: Cannot add Tkinter handler, basic logging system not active.",
flush=True,
)
return
if not _base_formatter:
print("ERROR: Cannot add Tkinter handler, base formatter not set.", flush=True)
return
print("INFO: Attempting to add TkinterTextHandler...", flush=True)
if _actual_tkinter_handler: # If one already exists, close and prepare to replace
print(
"INFO: Existing TkinterTextHandler found, closing it before adding new one.",
flush=True,
)
try:
_actual_tkinter_handler.close()
except Exception as e_close_old_tk:
print(
f"Warning: Error closing old TkinterTextHandler: {e_close_old_tk}",
flush=True,
)
_actual_tkinter_handler = None
is_widget_valid = (
isinstance(gui_log_widget, (tk.Text, ScrolledText))
and hasattr(gui_log_widget, "winfo_exists")
and gui_log_widget.winfo_exists()
)
is_root_valid = (
root_tk_instance_for_gui_handler
and hasattr(root_tk_instance_for_gui_handler, "winfo_exists")
and root_tk_instance_for_gui_handler.winfo_exists()
)
if is_widget_valid and is_root_valid:
try:
level_colors = logging_config_dict.get("colors", {})
tkinter_handler_poll_ms = logging_config_dict.get(
"queue_poll_interval_ms", 100
)
_actual_tkinter_handler = TkinterTextHandler(
text_widget=gui_log_widget,
level_colors=level_colors,
root_tk_instance_for_widget_update=root_tk_instance_for_gui_handler,
internal_poll_interval_ms=tkinter_handler_poll_ms,
)
_actual_tkinter_handler.setFormatter(_base_formatter)
_actual_tkinter_handler.setLevel(logging.DEBUG)
print(
"INFO: TkinterTextHandler added and configured successfully.",
flush=True,
)
logging.getLogger("FlightMonitor.LoggerTest").info(
"TkinterTextHandler added. This is a test from add_tkinter_handler."
)
except Exception as e:
print(
f"ERROR: Failed to create and add TkinterTextHandler: {e}", flush=True
)
_actual_tkinter_handler = None
else:
if not is_widget_valid:
print(
"ERROR: GUI log widget invalid or non-existent, cannot add TkinterTextHandler.",
flush=True,
)
if not is_root_valid:
print(
"ERROR: Root Tk instance for GUI handler invalid or non-existent.",
flush=True,
)
def get_logger(name: str) -> logging.Logger:
"""
Retrieves a logger instance by name.
Module-level loggers should use `get_logger(__name__)`.
"""
return logging.getLogger(name)
def shutdown_logging_system():
"""
Shuts down the centralized logging system, processing remaining logs
and closing actual handlers.
"""
global _logging_system_active, _log_processor_after_id
global _actual_console_handler, _actual_file_handler, _actual_tkinter_handler
global _global_log_queue, _tk_root_instance_for_processing
if (
not _logging_system_active and not _global_log_queue
): # Extra check if it was never really active
print(
"INFO: Logging system shutdown called, but system was not fully active or already shut down.",
flush=True,
)
return
print("INFO: Initiating shutdown of centralized logging system...", flush=True)
_logging_system_active = False
if (
_log_processor_after_id
and _tk_root_instance_for_processing
and _tk_root_instance_for_processing.winfo_exists()
):
try:
_tk_root_instance_for_processing.after_cancel(_log_processor_after_id)
# print("INFO: Cancelled global log queue processor task.", flush=True) # Reduced verbosity
except Exception as e_cancel:
print(
f"Warning: Error cancelling log processor task: {e_cancel}", flush=True
)
_log_processor_after_id = None
# print("INFO: Processing any remaining logs in the global queue before full shutdown...", flush=True) # Reduced
if _global_log_queue:
final_processed_count = 0
while not _global_log_queue.empty():
try:
record = _global_log_queue.get_nowait()
final_processed_count += 1
if _actual_console_handler:
_actual_console_handler.handle(record)
if _actual_file_handler:
_actual_file_handler.handle(record)
if _actual_tkinter_handler:
_actual_tkinter_handler.handle(record)
_global_log_queue.task_done()
except QueueEmpty:
break
except Exception as e_final_proc:
print(f"Error during final log processing: {e_final_proc}", flush=True)
break
# if final_processed_count > 0: print(f"INFO: Processed {final_processed_count} remaining log messages.", flush=True)
# else: print("INFO: No remaining log messages in global queue to process.", flush=True)
if _actual_tkinter_handler:
try:
# print("INFO: Closing actual TkinterTextHandler.", flush=True) # Reduced
_actual_tkinter_handler.close()
except Exception as e:
print(f"Error closing TkinterTextHandler: {e}", flush=True)
_actual_tkinter_handler = None
if _actual_console_handler:
try:
# print("INFO: Closing actual ConsoleHandler.", flush=True) # Reduced
_actual_console_handler.close()
except Exception as e:
print(f"Error closing ConsoleHandler: {e}", flush=True)
_actual_console_handler = None
if _actual_file_handler:
try:
# print("INFO: Closing actual FileHandler.", flush=True) # Reduced
_actual_file_handler.close()
except Exception as e:
print(f"Error closing FileHandler: {e}", flush=True)
_actual_file_handler = None
root_logger = logging.getLogger()
for handler in root_logger.handlers[:]:
try:
if isinstance(handler, QueuePuttingHandler):
handler.close()
root_logger.removeHandler(handler)
# print(f"INFO: Removed and closed QueuePuttingHandler: {handler}", flush=True) # Reduced
except Exception as e_rem_qph:
print(f"Error removing QueuePuttingHandler: {e_rem_qph}", flush=True)
_global_log_queue = None
_tk_root_instance_for_processing = None
_base_formatter = None
print("INFO: Centralized logging system shutdown complete.", flush=True)