# 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) 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: # We can choose to make a copy of the record if there's any concern # about it being modified before processing, though typically not an issue. # For now, put the original record. self.handler_queue.put_nowait(record) except 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) # Can be very verbose 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() ): # print("DEBUG: Global log queue processor: Tk root instance gone. Stopping.", flush=True) _logging_system_active = False # Stop if root is gone _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 # Check before processing each item try: record = _global_log_queue.get_nowait() processed_count += 1 # Dispatch to actual handlers 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 # Should not happen due to outer loop condition, but defensive except Exception as e_proc_item: print( f"Error processing a log item from global queue: {e_proc_item}", flush=True, ) # Potentially re-queue or log to a failsafe if critical 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 ) # else: print(f"DEBUG: Not rescheduling _process_global_log_queue. Active: {_logging_system_active}", flush=True) def setup_logging( gui_log_widget: Optional[tk.Text] = None, root_tk_instance: Optional[tk.Tk] = None, logging_config_dict: Optional[Dict[str, Any]] = None, ): global _global_log_queue, _actual_console_handler, _actual_file_handler global _actual_tkinter_handler, _logging_system_active, _tk_root_instance_for_processing global _log_processor_after_id, _base_formatter print("INFO: Configuring centralized queued logging system...", flush=True) if _logging_system_active: print( "INFO: Logging system already active. Shutting down existing to reconfigure.", flush=True, ) shutdown_logging_system() # Ensure clean state before re-setup if logging_config_dict is None: print( "Warning: No logging_config_dict. Using basic console-only defaults for queued logging.", flush=True, ) 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", "colors": { logging.INFO: "black", logging.DEBUG: "blue", logging.WARNING: "orange", logging.ERROR: "red", logging.CRITICAL: "purple", }, "queue_poll_interval_ms": 100, # For TkinterTextHandler's internal queue "enable_console": True, "enable_file": False, } # --- Extract Config --- 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") level_colors = logging_config_dict.get("colors", {}) tkinter_handler_poll_ms = logging_config_dict.get( "queue_poll_interval_ms", 100 ) # For TkinterTextHandler's internal queue 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() # Initialize the global queue for LogRecords _tk_root_instance_for_processing = root_tk_instance # Store for the after() loop # --- Configure Root Logger --- root_logger = logging.getLogger() # Remove ALL existing handlers from the root logger to ensure clean state for handler in root_logger.handlers[:]: try: handler.close() # Close handler first root_logger.removeHandler(handler) print( f"DEBUG: Removed and closed old handler from root: {handler}", flush=True, ) except Exception as e_rem: print(f"Error removing/closing old handler {handler}: {e_rem}", flush=True) root_logger.handlers = [] # Ensure it's empty root_logger.setLevel(root_log_level) print( f"INFO: Root logger level set to {logging.getLevelName(root_logger.level)}.", flush=True, ) # --- Configure Specific Logger Levels --- for logger_name, level in specific_levels.items(): named_logger = logging.getLogger(logger_name) named_logger.setLevel(level) # Ensure propagation is on if they are not root, or if they should also go to root's QueuePuttingHandler named_logger.propagate = True print( f"INFO: Logger '{logger_name}' level set to {logging.getLevelName(named_logger.level)}.", flush=True, ) # --- Create Actual Handlers (but don't add to root logger yet) --- if enable_console: try: _actual_console_handler = logging.StreamHandler() # Defaults to stderr _actual_console_handler.setFormatter(_base_formatter) _actual_console_handler.setLevel( logging.DEBUG ) # Let console handler decide based on record level 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 ) # 5MB 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) # Let file handler decide 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 gui_log_widget and root_tk_instance: is_widget_valid = ( isinstance(gui_log_widget, (tk.Text, ScrolledText)) and hasattr(gui_log_widget, "winfo_exists") and gui_log_widget.winfo_exists() ) if is_widget_valid: try: _actual_tkinter_handler = TkinterTextHandler( text_widget=gui_log_widget, level_colors=level_colors, root_tk_instance_for_widget_update=root_tk_instance, # Pass root for its own after loop internal_poll_interval_ms=tkinter_handler_poll_ms, ) _actual_tkinter_handler.setFormatter(_base_formatter) _actual_tkinter_handler.setLevel( logging.DEBUG ) # Let Tkinter handler decide print("INFO: Actual TkinterTextHandler created.", flush=True) except Exception as e: print( f"ERROR: Failed to create actual TkinterTextHandler: {e}", flush=True, ) _actual_tkinter_handler = None else: print( "ERROR: GUI log widget invalid or non-existent, cannot create TkinterTextHandler.", flush=True, ) elif gui_log_widget and not root_tk_instance: print( "WARNING: GUI log widget provided, but root_tk_instance missing for TkinterTextHandler.", flush=True, ) # --- Add ONLY the QueuePuttingHandler to the root logger --- if _global_log_queue is not None: queue_putter = QueuePuttingHandler(handler_queue=_global_log_queue) queue_putter.setLevel( logging.DEBUG ) # Capture all messages from root level downwards root_logger.addHandler(queue_putter) print( f"INFO: QueuePuttingHandler added to root logger. All logs will go to global queue.", flush=True, ) else: print( "CRITICAL ERROR: Global log queue not initialized. Logging will not function correctly.", flush=True, ) # Fallback to basic console if queue setup failed badly if not _actual_console_handler: # If even this failed _bf = logging.Formatter( "%(asctime)s - %(name)s - %(levelname)s - %(message)s" ) _ch = logging.StreamHandler() _ch.setFormatter(_bf) root_logger.addHandler(_ch) print("CRITICAL: Added basic emergency console logger.", flush=True) # --- Start the global log queue processor (if root_tk_instance is available) --- _logging_system_active = True if ( _tk_root_instance_for_processing and _tk_root_instance_for_processing.winfo_exists() ): if ( _log_processor_after_id ): # Cancel previous if any (shouldn't happen if shutdown was called) 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 with Tkinter.after (ID: {_log_processor_after_id}).", flush=True, ) elif root_tk_instance is None and ( gui_log_widget is not None or enable_file or enable_console ): # This case means we want logging but have no Tkinter root to schedule the queue processor. # This is problematic for GUI logging. For console/file, logs will just queue up. # A dedicated thread could process the queue if no Tkinter available, but adds complexity. print( "WARNING: No Tkinter root instance provided to setup_logging. " "Logs will be queued but not processed by GUI/File/Console handlers unless _process_global_log_queue is run manually or by another mechanism.", flush=True, ) elif not (enable_console or enable_file or gui_log_widget): print( "INFO: No log output handlers (console, file, gui) are enabled. Logs will be queued but not displayed.", flush=True, ) print("INFO: Centralized queued logging system setup complete.", flush=True) # Test log test_logger = logging.getLogger("FlightMonitor.LoggerTest") test_logger.info( "Logging system initialized. This is a test message from setup_logging." ) 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 print("INFO: Initiating shutdown of centralized logging system...", flush=True) _logging_system_active = False # Signal processor to stop 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) except Exception as e_cancel: print( f"Warning: Error cancelling log processor task: {e_cancel}", flush=True ) _log_processor_after_id = None # Attempt to process any remaining logs in the global queue print( "INFO: Processing any remaining logs in the global queue before full shutdown...", flush=True, ) 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 # Stop if error during final processing 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, ) # Close actual handlers if _actual_tkinter_handler: try: print("INFO: Closing actual TkinterTextHandler.", flush=True) _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) _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) _actual_file_handler.close() except Exception as e: print(f"Error closing FileHandler: {e}", flush=True) _actual_file_handler = None # Clear the root logger's handlers (should only be the QueuePuttingHandler) root_logger = logging.getLogger() for handler in root_logger.handlers[:]: try: if isinstance( handler, QueuePuttingHandler ): # Specifically target our handler handler.close() root_logger.removeHandler(handler) print( f"INFO: Removed and closed QueuePuttingHandler: {handler}", flush=True, ) except Exception as e_rem_qph: print(f"Error removing QueuePuttingHandler: {e_rem_qph}", flush=True) _global_log_queue = None # Allow it to be garbage collected _tk_root_instance_for_processing = None # Clear reference _base_formatter = None print("INFO: Centralized logging system shutdown complete.", flush=True)