# 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)