From a69391b1d8ba972a9682e2733fae28133f536f03 Mon Sep 17 00:00:00 2001 From: Stan44 Date: Fri, 11 Apr 2025 23:59:50 -0500 Subject: [PATCH] toggle logging added (--debug-on) to enable logging minor bug fixes. known stutter bug in database/meta systems appears to be the delay in connecting to the database. future work: 1. intergrate firefly.dll as server module. 2. ensure full database funcctionality. 3. add toggle to use database or not. (by default we check for firefly if we don't find we default to python systems. if found we automatically use firefly.(so maybe on toggles)) 4. investigate and fix the stutter bug. --- Fbrowser.py | 63 +++++++++++++++++++----- ScanOrg101.py | 54 +++++++++++++-------- archiver.py | 9 +++- dbman.py | 121 ++++++++++++++++++++++++++++++++--------------- logging_setup.py | 44 +++++++++++++++++ metaextract.py | 76 +++++++++++++++++++++++------ 6 files changed, 281 insertions(+), 86 deletions(-) create mode 100644 logging_setup.py diff --git a/Fbrowser.py b/Fbrowser.py index 5102ecf..4bfa317 100644 --- a/Fbrowser.py +++ b/Fbrowser.py @@ -1,11 +1,13 @@ """File browser implementation with tools and audio playback. this includes a midi player""" + # flake8: noqa: E501 # This is the main file this file is the one to run. import sys import os import warnings +import argparse from PyQt6.QtWidgets import ( QApplication, QMainWindow, @@ -38,10 +40,21 @@ from ScanOrg101 import ( ArchiveExtractor, ) import mutagen +from logging_setup import setup_logging warnings.filterwarnings("ignore", category=DeprecationWarning) +# Parse command line arguments +def parse_arguments(): + """Parse command line arguments""" + parser = argparse.ArgumentParser(description="File Browser Application") + parser.add_argument( + "--debug-on", action="store_true", help="Enable debug logging mode" + ) + return parser.parse_args() + + class MetadataTooltip(QFrame): """Custom styled tooltip for displaying audio metadata""" @@ -110,8 +123,10 @@ class MetadataTooltip(QFrame): class Fbrowser(QMainWindow): """Fbrowser main class""" - def __init__(self): + def __init__(self, logger): super().__init__() + self.logger = logger + self.logger.info("Initializing Fbrowser application") self.midplay = None self.current_path = QDir.homePath() self.organizer = Organizer() @@ -129,9 +144,11 @@ class Fbrowser(QMainWindow): self.hover_position = None self.hover_path = None self.metadata_cache = {} + self.logger.debug("Fbrowser initialization complete") def init_ui(self): """initilize UI""" + self.logger.debug("Initializing UI components") self.setWindowTitle("File Browser") central_widget = QWidget() layout = QVBoxLayout(central_widget) @@ -266,13 +283,16 @@ class Fbrowser(QMainWindow): self.folder_contents_view.setMouseTracking(True) self.folder_contents_view.viewport().setMouseTracking(True) # type: ignore self.folder_contents_view.viewport().installEventFilter(self) # type: ignore + self.logger.debug("UI initialization complete") def set_volume(self, volume): """Set Volume""" self.audio_output.setVolume(volume / 100.0) + self.logger.debug(f"Volume set to {volume}%") def show_exit_popup(self): """Exit Prompt""" + self.logger.debug("Exit prompt displayed") reply = QMessageBox.question( self, "Exit", @@ -281,20 +301,24 @@ class Fbrowser(QMainWindow): QMessageBox.StandardButton.No, ) if reply == QMessageBox.StandardButton.Yes: + self.logger.info("User confirmed exit, shutting down application") sys.exit() def navigate_to_address(self): """Navigation Via Address Bar""" new_path = self.address_bar.text() + self.logger.debug(f"Navigating to address: {new_path}") if os.path.isdir(new_path): self.add_to_history(self.current_path) self.current_path = new_path self.update_file_views(new_path) else: + self.logger.warning(f"Invalid directory path: {new_path}") self.address_bar.setText(self.current_path) def add_to_history(self, path): """History""" + self.logger.debug(f"Adding path to history: {path}") # If we're not at the end of the history, truncate it if self.history_position < len(self.history) - 1: self.history = self.history[: self.history_position + 1] @@ -307,12 +331,14 @@ class Fbrowser(QMainWindow): index = self.directory_model.mapToSource(index) try: file_path = self.tree_model.filePath(index) + self.logger.debug(f"Changing directory to: {file_path}") if os.path.isdir(file_path): self.add_to_history(self.current_path) self.current_path = file_path self.update_file_views(file_path) except (OSError, IOError) as e: - print(f"Error Changing Dirs.: {e}") + self.logger.error(f"Error changing directory: {e}") + logger.debug(f"Error Changing Dirs.: {e}") def update_file_views(self, path): """Updates the File trees""" @@ -726,7 +752,7 @@ class Fbrowser(QMainWindow): self.show_metadata_tooltip(metadata) except Exception as e: - print(f"Error extracting metadata for hover: {e}") + logger.debug(f"Error extracting metadata for hover: {e}") def _get_tag(self, audio, tag_name, default_value): """Helper method to safely extract tags from audio files""" @@ -762,6 +788,7 @@ class Fbrowser(QMainWindow): def closeEvent(self, event): """Handle application close event""" + self.logger.info("Application closing") # Close database connection if hasattr(self, "organizer") and self.organizer: self.organizer.close() @@ -774,7 +801,7 @@ class Fbrowser(QMainWindow): if not self.should_auto_scan(path): return - print(f"Auto-scanning directory: {path}") + self.logger.info(f"Auto-scanning directory: {path}") # Initialize organizer with database connection if not already done if not hasattr(self.organizer, "db") or self.organizer.db is None: @@ -797,13 +824,13 @@ class Fbrowser(QMainWindow): files_to_process.append(file_path) if files_to_process: - print( + self.logger.debug( f"Found {len(files_to_process)} files without metadata, extracting..." ) self.organizer.file_list = files_to_process self.organizer.extract_metadata() else: - print( + self.logger.debug( "All files already have metadata in database, skipping extraction" ) self.progress_bar.setValue(100) @@ -817,16 +844,16 @@ class Fbrowser(QMainWindow): def auto_extract_metadata(self): """Automatically extract metadata after scanning""" if not self.organizer.file_list: - print("No audio files found to extract metadata from") + logger.debug("No audio files found to extract metadata from") return - print( + self.logger.debug( f"Auto-extracting metadata for {len(self.organizer.file_list)} files" ) # Connect signals self.organizer.on_progress_update = self.update_progress # type: ignore - self.organizer.on_metadata_complete = lambda: print("Metadata extraction complete") # type: ignore + self.organizer.on_metadata_complete = lambda: logger.debug("Metadata extraction complete") # type: ignore # Start extraction self.organizer.extract_metadata() @@ -859,8 +886,22 @@ class Fbrowser(QMainWindow): return True -if __name__ == "__main__": +def main(): + # Parse command line arguments + args = parse_arguments() + + # Setup logging + logger = setup_logging(args) + + logger.info("Starting Fbrowser application") + app = QApplication(sys.argv) - ex = Fbrowser() + ex = Fbrowser(logger) ex.show() + + logger.info("Application UI displayed") sys.exit(app.exec()) + + +if __name__ == "__main__": + main() diff --git a/ScanOrg101.py b/ScanOrg101.py index d78400a..aec6e74 100644 --- a/ScanOrg101.py +++ b/ScanOrg101.py @@ -5,6 +5,7 @@ ScanOrg101.py - Enhanced file scanning and organization module # flake8: noqa: E501 import os +import logging import concurrent.futures from collections import deque import time @@ -13,6 +14,9 @@ from dbman import FireflyDB from metaextract import MetadataExtractor, mutagen from archiver import ArchiveExtractor +# Get the logger +logger = logging.getLogger("fbroswer") + # Directory Filter Proxy Model class DirectoryFilterProxyModel(QSortFilterProxyModel): @@ -20,6 +24,7 @@ class DirectoryFilterProxyModel(QSortFilterProxyModel): super().__init__() self.setFilterCaseSensitivity(Qt.CaseSensitivity.CaseInsensitive) self.setFilterKeyColumn(0) + logger.debug("DirectoryFilterProxyModel initialized") def filterAcceptsRow(self, source_row, source_parent): source_model = self.sourceModel() @@ -57,6 +62,9 @@ class FileFilterProxyModel(QSortFilterProxyModel): ".7z", ".rar", ] + logger.debug( + "FileFilterProxyModel initialized with allowed extensions" + ) def filterAcceptsRow(self, source_row, source_parent): source_model = self.sourceModel() @@ -221,7 +229,9 @@ class FileScanner(QThread): self.progress_update.emit(progress) last_update_time = current_time except Exception as e: - print(f"Error scanning directory {dir_path}: {e}") + logger.debug( + f"Error scanning directory {dir_path}: {e}" + ) # Emit any remaining items in the final batch if batch and not self.stop_requested: @@ -268,10 +278,10 @@ class FileScanner(QThread): self.progress_update.emit(100) # Show complete for this directory return items except PermissionError: - print(f"Permission denied: {path}") + logger.debug(f"Permission denied: {path}") return [] except OSError as e: - print(f"Error accessing {path}: {e}") + logger.debug(f"Error accessing {path}: {e}") return [] def scan_single_directory_helper(self, path): @@ -293,7 +303,7 @@ class FileScanner(QThread): ): items.append((entry.path, False)) except (PermissionError, OSError) as e: - print(f"Error accessing {path}: {e}") + logger.debug(f"Error accessing {path}: {e}") return items, subdirs @@ -372,7 +382,7 @@ class Organizer: def scan_finished(self): """Handle scan completion""" - print( + logger.debug( f"Scan complete. Found {len(self.dir_list)} directories\ and {len(self.file_list)} files." ) @@ -388,13 +398,13 @@ class Organizer: def extract_metadata(self): """Extract metadata from audio files using MetadataExtractor from metaextract.py""" if not self.file_list: - print("No files to extract metadata from") + logger.debug("No files to extract metadata from") return # Verify database connection if enabled if self.use_db and self.db: if not self.db_manager.verify_database_connection(): - print( + logger.debug( "Warning: Database verification failed, continuing without database" ) self.use_db = False @@ -451,7 +461,7 @@ class Organizer: def metadata_extraction_complete(self): """Handle metadata extraction completion""" - print( + logger.debug( f"Metadata extraction complete. Artists: {len(getattr(self, 'artists', []))}, " f"Albums: {len(getattr(self, 'albums', []))}, Genres: {len(getattr(self, 'genres', []))}, " f"Years: {len(getattr(self, 'years', []))}" @@ -460,16 +470,16 @@ class Organizer: def extract_archive(self, archive_path, extraction_dir): """Extract an archive to specified directory using ArchiveExtractor from archiver.py""" if not os.path.isfile(archive_path): - print(f"Error: Archive file {archive_path} does not exist") + logger.debug(f"Error: Archive file {archive_path} does not exist") return False if not os.path.isdir(extraction_dir): - print( + logger.debug( f"Error: Extraction directory {extraction_dir} does not exist" ) return False - print(f"Extracting archive {archive_path} to {extraction_dir}") + logger.debug(f"Extracting archive {archive_path} to {extraction_dir}") # Create an ArchiveExtractor instance from archiver.py self.archive_extractor = ArchiveExtractor(archive_path, extraction_dir) @@ -482,7 +492,7 @@ class Organizer: # Define completion handler def on_extraction_complete(extracted_files): - print( + logger.debug( f"Archive extraction complete. Extracted {len(extracted_files)} files." ) # Add extracted files to our file list if they match our criteria @@ -520,7 +530,7 @@ class Organizer: ] if audio_files and self.use_db: - print( + logger.debug( f"Found {len(audio_files)} audio files in archive, extracting metadata..." ) temp_extractor = MetadataExtractor(audio_files) @@ -536,7 +546,7 @@ class Organizer: # Define error handler def on_extraction_error(error_message): - print(f"Archive extraction error: {error_message}") + logger.debug(f"Archive extraction error: {error_message}") # Connect error signal self.archive_extractor.extraction_error.connect(on_extraction_error) @@ -550,7 +560,7 @@ class Organizer: ): """Extract an archive to a specified directory or to a subdirectory in the same location""" if not os.path.isfile(archive_path): - print(f"Error: Archive file {archive_path} does not exist") + logger.debug(f"Error: Archive file {archive_path} does not exist") return False # If no target directory is specified, create one based on the archive name @@ -564,9 +574,11 @@ class Organizer: if not os.path.exists(target_directory): try: os.makedirs(target_directory) - print(f"Created directory {target_directory}") + logger.debug(f"Created directory {target_directory}") except OSError as e: - print(f"Error creating directory {target_directory}: {e}") + logger.debug( + f"Error creating directory {target_directory}: {e}" + ) return False return self.extract_archive(archive_path, target_directory) @@ -580,7 +592,7 @@ class Organizer: # Delegate to the db_manager return self.db_manager.has_metadata_in_db(file_path) except Exception as e: - print(f"Error checking metadata in database: {e}") + logger.debug(f"Error checking metadata in database: {e}") return False def get_metadata_from_db(self, file_path): @@ -592,20 +604,20 @@ class Organizer: # Delegate to the db_manager return self.db_manager.get_metadata_from_db(file_path) except Exception as e: - print(f"Error retrieving metadata from database: {e}") + logger.debug(f"Error retrieving metadata from database: {e}") return None def store_metadata(self, metadata): """Store audio file metadata in the database""" if not self.use_db or not self.db: - print("Database usage is disabled, not storing metadata") + logger.debug("Database usage is disabled, not storing metadata") return False try: # Delegate to the db_manager return self.db_manager.store_metadata(metadata) except Exception as e: - print(f"Error storing metadata in database: {e}") + logger.debug(f"Error storing metadata in database: {e}") import traceback traceback.print_exc() diff --git a/archiver.py b/archiver.py index d013f8a..50e369f 100644 --- a/archiver.py +++ b/archiver.py @@ -1,4 +1,5 @@ import os +import logging import zipfile import py7zr import rarfile # typed: ignore @@ -6,6 +7,10 @@ import rarfile # typed: ignore from PyQt6.QtCore import QThread, pyqtSignal +# Get the logger +logger = logging.getLogger("fbroswer") + + # Archive Extractor not fully tested or implemented class ArchiveExtractor(QThread): extraction_progress = pyqtSignal(int) @@ -116,7 +121,7 @@ class ArchiveExtractor(QThread): def extract_archives(self): """Extract archives""" if not self.file_list: - print("No files to extract archives from") + logger.debug("No files to extract archives from") return self.archive_extractor = ArchiveExtractor( @@ -136,7 +141,7 @@ class ArchiveExtractor(QThread): def archive_extraction_complete(self): """Handle archive extraction completion""" - print("Archive extraction complete.") + logger.debug("Archive extraction complete.") if self.on_progress_update: self.on_progress_update(100) diff --git a/dbman.py b/dbman.py index 0c6dd95..244c97a 100644 --- a/dbman.py +++ b/dbman.py @@ -1,6 +1,10 @@ +import logging from datetime import datetime from ifireflylib import IFireflyClient as FireflyDatabase +# Get the logger +logger = logging.getLogger("fbroswer") + class FireflyDB: def __init__(self): @@ -11,12 +15,14 @@ class FireflyDB: self.albums = set() self.genres = set() self.years = set() + logger.debug("FireflyDB instance initialized") def connect_to( self, use_db=False, db_host="localhost", db_port=6379, db_password=None ): # Set the use_db flag self.use_db = use_db + logger.info(f"Database usage set to: {use_db}") # Metadata organization self.artists = set() @@ -26,26 +32,30 @@ class FireflyDB: if use_db: try: - print(f"Connecting to FireflyDB at {db_host}:{db_port}") + logger.info(f"Connecting to FireflyDB at {db_host}:{db_port}") self.db = FireflyDatabase( host=db_host, port=db_port, password=db_password ) # Test connection if not self.db.ping(): - print( - "Warning: Could not connect to FireflyDB. Continuing without database." + logger.warning( + "Could not connect to FireflyDB. Continuing without database." ) self.use_db = False self.db = None else: - print("Successfully connected to FireflyDB") + logger.info("Successfully connected to FireflyDB") # Store connection timestamp timestamp = str(datetime.now()) - print(f"Setting last_connection timestamp: {timestamp}") + logger.debug( + f"Setting last_connection timestamp: {timestamp}" + ) self.db.string_ops.string_set("last_connection", timestamp) - print("Connection timestamp stored successfully") + logger.debug("Connection timestamp stored successfully") except Exception as e: - print(f"Error connecting to FireflyDB: {e}") + logger.error( + f"Error connecting to FireflyDB: {e}", exc_info=True + ) import traceback traceback.print_exc() @@ -55,6 +65,7 @@ class FireflyDB: def close(self): """Close database connection when done""" if self.db: + logger.info("Closing database connection") self.db.close() self.db = None @@ -65,17 +76,20 @@ class FireflyDB: try: key = f"audio:{file_path}" - # Use hash_exists to check if the key exists in the database - exists = self.db.hash_ops.hash_exists(key, "title") + # Use hash_field_exists to check if the key exists in the database + exists = self.db.hash_ops.hash_field_exists(key, "title") + logger.debug( + f"Metadata check for {file_path}: {'exists' if exists else 'not found'}" + ) return exists except Exception as e: - print(f"Error checking metadata in database: {e}") + logger.error(f"Error checking metadata in database: {e}") return False def store_metadata(self, metadata): """Store audio file metadata in the database""" if not self.use_db or not self.db: - print("Database usage is disabled, not storing metadata") + logger.info("Database usage is disabled, not storing metadata") return False try: @@ -84,42 +98,42 @@ class FireflyDB: key = f"audio:{file_path}" # Log the storage attempt - print(f"Storing metadata for {file_path} in FireflyDB") - print(f"Metadata fields: {list(metadata.keys())}") + logger.info(f"Storing metadata for {file_path} in FireflyDB") + logger.debug(f"Metadata fields: {list(metadata.keys())}") # Store as a hash with all metadata fields success = True for field, value in metadata.items(): if field != "file_path": # Skip using file_path as a field - print(f" Setting field {field}={value}") + logger.debug(f" Setting field {field}={value}") # Use the direct hash_set method instead of hash_ops result = self.db.hash_ops.hash_set(key, field, value) if not result: - print( + logger.warning( f" Failed to store field {field} for {file_path}" ) success = False else: - print(f" Successfully stored field {field}") + logger.debug(f" Successfully stored field {field}") # Add to index lists for quick lookup if "artist" in metadata and metadata["artist"]: artist_key = f"index:artist:{metadata['artist']}" - print(f" Adding to artist index: {artist_key}") + logger.debug(f" Adding to artist index: {artist_key}") self.db.list_ops.list_right_push(artist_key, file_path) if "album" in metadata and metadata["album"]: album_key = f"index:album:{metadata['album']}" - print(f" Adding to album index: {album_key}") + logger.debug(f" Adding to album index: {album_key}") self.db.list_ops.list_right_push(album_key, file_path) if "genre" in metadata and metadata["genre"]: genre_key = f"index:genre:{metadata['genre']}" - print(f" Adding to genre index: {genre_key}") + logger.debug(f" Adding to genre index: {genre_key}") self.db.list_ops.list_right_push(genre_key, file_path) # Add to a master list of all audio files for easy retrieval - print(" Adding to master audio files list") + logger.debug(" Adding to master audio files list") self.db.list_ops.list_right_push("all_audio_files", file_path) # Store timestamp of when metadata was added @@ -128,19 +142,38 @@ class FireflyDB: # Verify storage by retrieving one field if "title" in metadata: retrieved_title = self.db.hash_ops.hash_get(key, "title") - print(f" Verification - Retrieved title: {retrieved_title}") + logger.debug( + f" Verification - Retrieved title: {retrieved_title}" + ) + + # Strip quotes if present in the retrieved value + if retrieved_title and isinstance(retrieved_title, str): + if retrieved_title.startswith( + '"' + ) and retrieved_title.endswith('"'): + retrieved_title = retrieved_title[1:-1] + + # Compare the cleaned value if retrieved_title != metadata["title"]: - print( + logger.warning( f" Verification failed: expected '{metadata['title']}', got '{retrieved_title}'" ) - success = False + # Don't mark as failure if it's just a quoting issue + if retrieved_title.strip('"') == metadata["title"]: + logger.info( + " Verification passed after stripping quotes" + ) + else: + success = False - print( + logger.info( f"Metadata storage {'successful' if success else 'partially failed'} for {file_path}" ) return success except Exception as e: - print(f"Error storing metadata in database: {e}") + logger.error( + f"Error storing metadata in database: {e}", exc_info=True + ) import traceback traceback.print_exc() @@ -158,10 +191,14 @@ class FireflyDB: if metadata: # Add the file path to the metadata metadata["file_path"] = file_path + logger.debug( + f"Retrieved metadata for {file_path} from database" + ) return metadata + logger.debug(f"No metadata found for {file_path} in database") return None except Exception as e: - print(f"Error retrieving metadata from database: {e}") + logger.error(f"Error retrieving metadata from database: {e}") return None def search_by_artist(self, artist): @@ -171,9 +208,10 @@ class FireflyDB: try: key = f"index:artist:{artist}" - return self.db.list_range(key, 0, -1) + logger.debug(f"Searching for files by artist: {artist}") + return self.db.list_ops.list_range(key, 0, -1) except Exception as e: - print(f"Error searching by artist: {e}") + logger.error(f"Error searching by artist: {e}") return [] # Similar methods for album and genre searches @@ -191,27 +229,31 @@ class FireflyDB: # Store in database if enabled if self.use_db and self.db: + logger.debug( + f"Storing metadata for {metadata.get('file_path', 'unknown file')} in database" + ) db_success = self.store_metadata(metadata) if db_success: - print( + logger.info( f"Successfully stored metadata for {metadata.get('file_path', 'unknown file')} in database" ) else: - print( + logger.warning( f"Failed to store metadata for {metadata.get('file_path', 'unknown file')} in database" ) def verify_database_connection(self): """Verify that the database connection is working properly""" if not self.use_db or not self.db: - print("Database usage is disabled") + logger.info("Database usage is disabled") return False try: # Test ping + logger.debug("Testing database connection with ping") ping_result = self.db.ping() if not ping_result: - print("Database ping failed") + logger.warning("Database ping failed") return False # Test basic operations @@ -219,14 +261,17 @@ class FireflyDB: test_value = "connection_test" # Test string operations - string_set_result = self.db.string_set(test_key, test_value) + logger.debug("Testing string operations") + string_set_result = self.db.string_ops.string_set( + test_key, test_value + ) if not string_set_result: - print("Failed to set test string in database") + logger.warning("Failed to set test string in database") return False string_get_result = self.db.string_get(test_key) if string_get_result != test_value: - print( + logger.warning( f"String get test failed. Expected '{test_value}', got '{string_get_result}'" ) return False @@ -234,8 +279,10 @@ class FireflyDB: # Clean up self.db.delete(test_key) - print("Database connection verified successfully") + logger.info("Database connection verified successfully") return True except Exception as e: - print(f"Database verification failed with error: {e}") + logger.error( + f"Database verification failed with error: {e}", exc_info=True + ) return False diff --git a/logging_setup.py b/logging_setup.py new file mode 100644 index 0000000..0be0d56 --- /dev/null +++ b/logging_setup.py @@ -0,0 +1,44 @@ +import logging +import argparse + + +def setup_logging(args=None): + """ + Configure logging based on command line arguments + + Args: + args: The parsed command line arguments + + Returns: + A configured logger instance + """ + # Create logger + logger = logging.getLogger("fbroswer") + + # Set level based on debug flag + if args and args.debug_on: + logger.setLevel(logging.DEBUG) + # Create more verbose formatter for debug mode + formatter = logging.Formatter( + "%(asctime)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(message)s" + ) + else: + logger.setLevel(logging.CRITICAL) + # Create simpler formatter for normal operation + formatter = logging.Formatter( + "%(asctime)s - %(levelname)s - %(message)s" + ) + + # Create console handler + console_handler = logging.StreamHandler() + console_handler.setFormatter(formatter) + + # Add handler to logger + logger.addHandler(console_handler) + + # Optionally add file handler for persistent logs + file_handler = logging.FileHandler("fbroswer.log") + file_handler.setFormatter(formatter) + logger.addHandler(file_handler) + + return logger diff --git a/metaextract.py b/metaextract.py index af168dc..ca29efb 100644 --- a/metaextract.py +++ b/metaextract.py @@ -1,10 +1,15 @@ import os +import logging import concurrent.futures import mutagen from datetime import datetime from PyQt6.QtCore import QThread, pyqtSignal +# Get the logger +logger = logging.getLogger("fbroswer") + + # Metadata Extractor class MetadataExtractor(QThread): metadata_extracted = pyqtSignal(dict) @@ -24,16 +29,24 @@ class MetadataExtractor(QThread): self.genres = set() self.years = set() + logger.debug( + f"MetadataExtractor initialized with {len(file_list)} files" + ) + def run(self): total_files = len(self.file_list) processed_files = 0 + logger.info(f"Starting metadata extraction for {total_files} files") + with concurrent.futures.ThreadPoolExecutor() as executor: futures = [] for file_path in self.file_list: if self.stop_requested: + logger.debug("Metadata extraction stopped by user request") break if file_path in self.metadata_cache: + logger.debug(f"Using cached metadata for {file_path}") self.metadata_extracted.emit( self.metadata_cache[file_path] ) @@ -48,36 +61,68 @@ class MetadataExtractor(QThread): for future in concurrent.futures.as_completed(futures): if self.stop_requested: + logger.debug( + "Metadata extraction stopped during processing" + ) break try: metadata = future.result() if metadata: self.metadata_extracted.emit(metadata) except Exception as e: - print(f"Error extracting metadata: {e}") + logger.error( + f"Error extracting metadata: {e}", exc_info=True + ) processed_files += 1 - self.progress_update.emit( - int(processed_files / total_files * 100) - ) + progress = int(processed_files / total_files * 100) + logger.debug(f"Metadata extraction progress: {progress}%") + self.progress_update.emit(progress) + logger.info("Metadata extraction complete") self.extraction_complete.emit() def extract_metadata(self, file_path): try: if not os.path.isfile(file_path): + logger.warning(f"File does not exist: {file_path}") return None # Skip non-audio files if not file_path.lower().endswith( (".mp3", ".wav", ".flac", ".m4a", ".wma", ".mid", ".midi") ): + logger.debug(f"Skipping non-audio file: {file_path}") return None - print(f"Extracting metadata for {file_path}") - audio = mutagen.File(file_path) # type: ignore + logger.info(f"Extracting metadata for {file_path}") + + # Add additional error handling for mutagen + try: + audio = mutagen.File(file_path) # type: ignore + except (OSError, IOError) as e: + logger.error(f"Mutagen error reading file {file_path}: {e}") + # Return basic metadata without audio tags + file_size_mb = os.path.getsize(file_path) / (1024 * 1024) + return { + "file_path": file_path, + "artist": "Unknown Artist", + "album": "Unknown Album", + "title": os.path.basename(file_path), + "genre": "Unknown Genre", + "year": "Unknown Year", + "size_mb": f"{file_size_mb:.2f}", + "filename": os.path.basename(file_path), + "extension": os.path.splitext(file_path)[1].lower(), + "last_modified": str( + datetime.fromtimestamp(os.path.getmtime(file_path)) + ), + "extracted_at": str(datetime.now()), + "error": str(e), + } + if not audio: - print(f"No metadata found for {file_path}") + logger.warning(f"No metadata found for {file_path}") return None # Get file size in MB @@ -101,14 +146,14 @@ class MetadataExtractor(QThread): "extracted_at": str(datetime.now()), } - print(f"Extracted metadata: {metadata}") + logger.debug(f"Extracted metadata: {metadata}") # Cache the result self.metadata_cache[file_path] = metadata return metadata except Exception as e: - print(f"Error processing {file_path}: {e}") + logger.error(f"Error processing {file_path}: {e}", exc_info=True) import traceback traceback.print_exc() @@ -122,19 +167,20 @@ class MetadataExtractor(QThread): if isinstance(value, list) and len(value) > 0: return str(value[0]) return str(value) - except Exception: - pass + except Exception as e: + logger.debug(f"Error extracting tag {tag_name}: {e}") return default_value def stop(self): + logger.info("Stopping metadata extraction") self.stop_requested = True def metadata_extraction_complete(self): """Handle metadata extraction completion""" - print( - f"Metadata extraction complete. Artists: {len(self.artists)},\ - Albums: {len(self.albums)}, Genres: {len(self.genres)},\ - Years: {len(self.years)}" + logger.info( + f"Metadata extraction complete. Artists: {len(self.artists)}, " + f"Albums: {len(self.albums)}, Genres: {len(self.genres)}, " + f"Years: {len(self.years)}" ) if self.on_metadata_complete: self.on_metadata_complete()