From 0d84d2f2febb3d86bdc7d81161702d23cf7fd608 Mon Sep 17 00:00:00 2001 From: Omni Date: Wed, 31 Dec 2025 20:56:47 +0000 Subject: [PATCH] Sync from development - prepare for v0.2.0.9 --- CHANGELOG.md | 18 +++ jackify/__init__.py | 2 +- jackify/backend/handlers/config_handler.py | 4 +- jackify/backend/handlers/menu_handler.py | 13 +- .../backend/handlers/protontricks_handler.py | 54 +++++++ jackify/backend/handlers/shortcut_handler.py | 76 ++++++++- .../backend/handlers/winetricks_handler.py | 2 +- .../services/automated_prefix_service.py | 70 ++++---- .../backend/utils/nexus_premium_detector.py | 15 +- .../gui/dialogs/completion_dialog.py | 4 +- .../gui/screens/configure_existing_modlist.py | 27 ++-- .../gui/screens/configure_new_modlist.py | 14 +- .../frontends/gui/screens/install_modlist.py | 149 +++++++++++++++++- .../gui/widgets/file_progress_list.py | 103 ------------ 14 files changed, 373 insertions(+), 178 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 2353dae..f1f9657 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,23 @@ # Jackify Changelog +## v0.2.0.9 - Critical Configuration Fixes +**Release Date:** 2025-12-31 + +### Bug Fixes +- Fixed AppID conversion bug causing Configure Existing failures +- Fixed missing MessageService import crash in Configure Existing +- Fixed RecursionError in config_handler.py logger +- Fixed winetricks automatic fallback to protontricks (was silently failing) + +### Improvements +- Added detailed progress indicators for configuration workflows +- Fixed progress bar completion showing 100% instead of 95% +- Removed debug logging noise from file progress widget +- Enhanced Premium detection diagnostics for Issue #111 +- Flatpak protontricks now auto-granted cache access for faster subsequent installs + +--- + ## v0.2.0.8 - Bug Fixes and Improvements **Release Date:** 2025-12-29 diff --git a/jackify/__init__.py b/jackify/__init__.py index 8d5011b..61dfaa6 100644 --- a/jackify/__init__.py +++ b/jackify/__init__.py @@ -5,4 +5,4 @@ This package provides both CLI and GUI interfaces for managing Wabbajack modlists natively on Linux systems. """ -__version__ = "0.2.0.8" +__version__ = "0.2.0.9" diff --git a/jackify/backend/handlers/config_handler.py b/jackify/backend/handlers/config_handler.py index f2764f3..93dac26 100644 --- a/jackify/backend/handlers/config_handler.py +++ b/jackify/backend/handlers/config_handler.py @@ -6,6 +6,7 @@ Handles application settings and configuration """ import os +import sys import json import logging import shutil @@ -211,7 +212,8 @@ class ConfigHandler: config.update(saved_config) return config except Exception as e: - logger.error(f"Error reading configuration from disk: {e}") + # Don't use logger here - can cause recursion if logger tries to access config + print(f"Warning: Error reading configuration from disk: {e}", file=sys.stderr) return self.settings.copy() def reload_config(self): diff --git a/jackify/backend/handlers/menu_handler.py b/jackify/backend/handlers/menu_handler.py index 10c16fe..623de67 100644 --- a/jackify/backend/handlers/menu_handler.py +++ b/jackify/backend/handlers/menu_handler.py @@ -571,15 +571,19 @@ class ModlistMenuHandler: self.logger.warning(f"[DEBUG] Could not find AppID for {context['name']} with exe {context['mo2_exe_path']}") set_modlist_result = self.modlist_handler.set_modlist(context) self.logger.debug(f"[DEBUG] set_modlist returned: {set_modlist_result}") + + # Check GUI mode early to avoid input() calls in GUI context + import os + gui_mode = os.environ.get('JACKIFY_GUI_MODE') == '1' + if not set_modlist_result: print(f"{COLOR_ERROR}\nError setting up context for configuration.{COLOR_RESET}") self.logger.error(f"set_modlist failed for {context.get('name')}") - input(f"\n{COLOR_PROMPT}Press Enter to continue...{COLOR_RESET}") + if not gui_mode: + input(f"\n{COLOR_PROMPT}Press Enter to continue...{COLOR_RESET}") return False # --- Resolution selection logic for GUI mode --- - import os - gui_mode = os.environ.get('JACKIFY_GUI_MODE') == '1' selected_resolution = context.get('resolution', None) if gui_mode: # If resolution is provided, set it and do not prompt @@ -654,7 +658,8 @@ class ModlistMenuHandler: print("NOTE: If you experience ENB issues, consider using GE-Proton 10-14 instead of") print(" Valve's Proton 10 (known ENB compatibility issues in Valve's Proton 10).") print("") - print("Detailed log available at: ~/Jackify/logs/Configure_New_Modlist_workflow.log") + from jackify.shared.paths import get_jackify_logs_dir + print(f"Detailed log available at: {get_jackify_logs_dir()}/Configure_New_Modlist_workflow.log") # Only wait for input in CLI mode, not GUI mode if not gui_mode: input(f"{COLOR_PROMPT}Press Enter to return to the menu...{COLOR_RESET}") diff --git a/jackify/backend/handlers/protontricks_handler.py b/jackify/backend/handlers/protontricks_handler.py index 4f03440..20a5dbc 100644 --- a/jackify/backend/handlers/protontricks_handler.py +++ b/jackify/backend/handlers/protontricks_handler.py @@ -777,6 +777,56 @@ class ProtontricksHandler: self.logger.error(f"Error running protontricks-launch: {e}") return None + def _ensure_flatpak_cache_access(self, cache_path: Path) -> bool: + """ + Ensure flatpak protontricks has filesystem access to the winetricks cache. + + Args: + cache_path: Path to winetricks cache directory + + Returns: + True if access granted or already exists, False on failure + """ + if self.which_protontricks != 'flatpak': + return True # Not flatpak, no action needed + + try: + # Check if flatpak already has access to this path + result = subprocess.run( + ['flatpak', 'override', '--user', '--show', 'com.github.Matoking.protontricks'], + capture_output=True, + text=True, + timeout=10 + ) + + if result.returncode == 0: + # Check if cache path is already in filesystem overrides + cache_str = str(cache_path.resolve()) + if f'filesystems=' in result.stdout and cache_str in result.stdout: + self.logger.debug(f"Flatpak protontricks already has access to cache: {cache_str}") + return True + + # Grant access to cache directory + self.logger.info(f"Granting flatpak protontricks access to winetricks cache: {cache_path}") + result = subprocess.run( + ['flatpak', 'override', '--user', 'com.github.Matoking.protontricks', + f'--filesystem={cache_path.resolve()}'], + capture_output=True, + text=True, + timeout=10 + ) + + if result.returncode == 0: + self.logger.info("Successfully granted flatpak protontricks cache access") + return True + else: + self.logger.warning(f"Failed to grant flatpak cache access: {result.stderr}") + return False + + except Exception as e: + self.logger.warning(f"Could not configure flatpak cache access: {e}") + return False + def install_wine_components(self, appid, game_var, specific_components: Optional[List[str]] = None): """ Install the specified Wine components into the given prefix using protontricks. @@ -820,6 +870,10 @@ class ProtontricksHandler: from jackify.shared.paths import get_jackify_data_dir jackify_cache_dir = get_jackify_data_dir() / 'winetricks_cache' jackify_cache_dir.mkdir(parents=True, exist_ok=True) + + # Ensure flatpak protontricks has access to cache (no-op for native) + self._ensure_flatpak_cache_access(jackify_cache_dir) + env['WINETRICKS_CACHE'] = str(jackify_cache_dir) self.logger.info(f"Using winetricks cache: {jackify_cache_dir}") if specific_components is not None: diff --git a/jackify/backend/handlers/shortcut_handler.py b/jackify/backend/handlers/shortcut_handler.py index 4ebfe51..0a23543 100644 --- a/jackify/backend/handlers/shortcut_handler.py +++ b/jackify/backend/handlers/shortcut_handler.py @@ -955,7 +955,10 @@ class ShortcutHandler: def get_appid_for_shortcut(self, shortcut_name: str, exe_path: Optional[str] = None) -> Optional[str]: """ - Find the current AppID for a given shortcut name and (optionally) executable path using protontricks. + Find the current AppID for a given shortcut name and (optionally) executable path. + + Primary method: Read directly from shortcuts.vdf (reliable, no external dependencies) + Fallback method: Use protontricks (if available) Args: shortcut_name (str): The name of the Steam shortcut. @@ -965,15 +968,22 @@ class ShortcutHandler: Optional[str]: The found AppID string, or None if not found or error occurs. """ self.logger.info(f"Attempting to find current AppID for shortcut: '{shortcut_name}' (exe_path: '{exe_path}')") + try: - from .protontricks_handler import ProtontricksHandler # Local import + appid = self.get_appid_from_vdf(shortcut_name, exe_path) + if appid: + self.logger.info(f"Successfully found AppID {appid} from shortcuts.vdf") + return appid + + self.logger.info("AppID not found in shortcuts.vdf, trying protontricks as fallback...") + from .protontricks_handler import ProtontricksHandler pt_handler = ProtontricksHandler(self.steamdeck) if not pt_handler.detect_protontricks(): - self.logger.error("Protontricks not detected") + self.logger.warning("Protontricks not detected - cannot use as fallback") return None result = pt_handler.run_protontricks("-l") if not result or result.returncode != 0: - self.logger.error(f"Protontricks failed to list applications: {result.stderr if result else 'No result'}") + self.logger.warning(f"Protontricks fallback failed: {result.stderr if result else 'No result'}") return None # Build a list of all shortcuts found_shortcuts = [] @@ -1022,8 +1032,64 @@ class ShortcutHandler: self.logger.exception("Traceback:") return None + def get_appid_from_vdf(self, shortcut_name: str, exe_path: Optional[str] = None) -> Optional[str]: + """ + Get AppID directly from shortcuts.vdf by reading the file and matching shortcut name/exe. + This is more reliable than using protontricks since it doesn't depend on external tools. + + Args: + shortcut_name (str): The name of the Steam shortcut. + exe_path (Optional[str]): The path to the executable for additional validation. + + Returns: + Optional[str]: The AppID as a string, or None if not found. + """ + self.logger.info(f"Looking up AppID from shortcuts.vdf for shortcut: '{shortcut_name}' (exe: '{exe_path}')") + + if not self.shortcuts_path or not os.path.isfile(self.shortcuts_path): + self.logger.warning(f"Shortcuts.vdf not found at {self.shortcuts_path}") + return None + + try: + shortcuts_data = VDFHandler.load(self.shortcuts_path, binary=True) + if not shortcuts_data or 'shortcuts' not in shortcuts_data: + self.logger.warning("No shortcuts found in shortcuts.vdf") + return None + + shortcut_name_clean = shortcut_name.strip().lower() + + for idx, shortcut in shortcuts_data['shortcuts'].items(): + name = shortcut.get('AppName', shortcut.get('appname', '')).strip() + + if name.lower() == shortcut_name_clean: + appid = shortcut.get('appid') + + if appid: + if exe_path: + vdf_exe = shortcut.get('Exe', shortcut.get('exe', '')).strip('"').strip() + exe_path_norm = os.path.abspath(os.path.expanduser(exe_path)).lower() + vdf_exe_norm = os.path.abspath(os.path.expanduser(vdf_exe)).lower() + + if vdf_exe_norm == exe_path_norm: + self.logger.info(f"Found AppID {appid} for shortcut '{name}' with matching exe '{vdf_exe}'") + return str(int(appid) & 0xFFFFFFFF) + else: + self.logger.debug(f"Found shortcut '{name}' but exe doesn't match: '{vdf_exe}' vs '{exe_path}'") + continue + else: + self.logger.info(f"Found AppID {appid} for shortcut '{name}' (no exe validation)") + return str(int(appid) & 0xFFFFFFFF) + + self.logger.warning(f"No matching shortcut found in shortcuts.vdf for '{shortcut_name}'") + return None + + except Exception as e: + self.logger.error(f"Error reading shortcuts.vdf: {e}") + self.logger.exception("Traceback:") + return None + # --- Discovery Methods Moved from ModlistHandler --- - + def _scan_shortcuts_for_executable(self, executable_name: str) -> List[Dict[str, str]]: """ Scans the user's shortcuts.vdf file for entries pointing to a specific executable. diff --git a/jackify/backend/handlers/winetricks_handler.py b/jackify/backend/handlers/winetricks_handler.py index 8d9b74b..e6e8c39 100644 --- a/jackify/backend/handlers/winetricks_handler.py +++ b/jackify/backend/handlers/winetricks_handler.py @@ -468,7 +468,7 @@ class WinetricksHandler: from .protontricks_handler import ProtontricksHandler steamdeck = os.path.exists('/home/deck') protontricks_handler = ProtontricksHandler(steamdeck) - protontricks_available = protontricks_handler.is_available() + protontricks_available = protontricks_handler.detect_protontricks() if protontricks_available: self.logger.warning("=" * 80) diff --git a/jackify/backend/services/automated_prefix_service.py b/jackify/backend/services/automated_prefix_service.py index 3ce5708..a4ebcaf 100644 --- a/jackify/backend/services/automated_prefix_service.py +++ b/jackify/backend/services/automated_prefix_service.py @@ -493,54 +493,54 @@ exit""" def detect_actual_prefix_appid(self, initial_appid: int, shortcut_name: str) -> Optional[int]: """ After Steam restart, detect the actual prefix AppID that was created. - Use protontricks -l to find the actual positive AppID. - + Uses direct VDF file reading to find the actual AppID. + Args: initial_appid: The initial (negative) AppID from shortcuts.vdf shortcut_name: Name of the shortcut for logging - + Returns: The actual (positive) AppID of the created prefix, or None if not found """ try: - logger.info(f"Using protontricks -l to detect actual AppID for shortcut: {shortcut_name}") - - # Wait up to 30 seconds for the shortcut to appear in protontricks + logger.info(f"Using VDF to detect actual AppID for shortcut: {shortcut_name}") + + # Wait up to 30 seconds for Steam to process the shortcut for i in range(30): try: - # Use the existing protontricks handler - from jackify.backend.handlers.protontricks_handler import ProtontricksHandler - protontricks_handler = ProtontricksHandler(steamdeck or False) - result = protontricks_handler.run_protontricks('-l') - - if result.returncode == 0: - lines = result.stdout.strip().split('\n') - - # Look for our shortcut name in the protontricks output - for line in lines: - if shortcut_name in line and 'Non-Steam shortcut:' in line: - # Extract AppID from line like "Non-Steam shortcut: Tuxborn (3106560878)" - if '(' in line and ')' in line: - appid_str = line.split('(')[1].split(')')[0] - actual_appid = int(appid_str) - logger.info(f" Found shortcut in protontricks: {line.strip()}") - logger.info(f" Initial AppID: {initial_appid}") - logger.info(f" Actual AppID: {actual_appid}") - return actual_appid - - logger.debug(f"Shortcut '{shortcut_name}' not found in protontricks yet (attempt {i+1}/30)") - time.sleep(1) - - except subprocess.TimeoutExpired: - logger.warning(f"protontricks -l timed out on attempt {i+1}") + from ..handlers.shortcut_handler import ShortcutHandler + from ..handlers.path_handler import PathHandler + + path_handler = PathHandler() + shortcuts_path = path_handler._find_shortcuts_vdf() + + if shortcuts_path: + from ..handlers.vdf_handler import VDFHandler + shortcuts_data = VDFHandler.load(shortcuts_path, binary=True) + + if shortcuts_data and 'shortcuts' in shortcuts_data: + for idx, shortcut in shortcuts_data['shortcuts'].items(): + app_name = shortcut.get('AppName', shortcut.get('appname', '')).strip() + + if app_name.lower() == shortcut_name.lower(): + appid = shortcut.get('appid') + if appid: + actual_appid = int(appid) & 0xFFFFFFFF + logger.info(f"Found shortcut '{app_name}' in shortcuts.vdf") + logger.info(f" Initial AppID (signed): {initial_appid}") + logger.info(f" Actual AppID (unsigned): {actual_appid}") + return actual_appid + + logger.debug(f"Shortcut '{shortcut_name}' not found in VDF yet (attempt {i+1}/30)") time.sleep(1) + except Exception as e: - logger.warning(f"Error running protontricks -l on attempt {i+1}: {e}") + logger.warning(f"Error reading shortcuts.vdf on attempt {i+1}: {e}") time.sleep(1) - - logger.error(f"Shortcut '{shortcut_name}' not found in protontricks after 30 seconds") + + logger.error(f"Shortcut '{shortcut_name}' not found in shortcuts.vdf after 30 seconds") return None - + except Exception as e: logger.error(f"Error detecting actual prefix AppID: {e}") return None diff --git a/jackify/backend/utils/nexus_premium_detector.py b/jackify/backend/utils/nexus_premium_detector.py index cd219db..0812414 100644 --- a/jackify/backend/utils/nexus_premium_detector.py +++ b/jackify/backend/utils/nexus_premium_detector.py @@ -15,29 +15,32 @@ _KEYWORD_PHRASES = ( ) -def is_non_premium_indicator(line: str) -> bool: +def is_non_premium_indicator(line: str) -> tuple[bool, str | None]: """ Return True if the engine output line indicates a Nexus non-premium scenario. Args: line: Raw line emitted from the jackify-engine process. + + Returns: + Tuple of (is_premium_error: bool, matched_pattern: str | None) """ if not line: - return False + return False, None normalized = line.strip().lower() if not normalized: - return False + return False, None # Direct phrase detection for phrase in _KEYWORD_PHRASES[:6]: if phrase in normalized: - return True + return True, phrase # Manual download + Nexus URL implies premium requirement in current workflows. if "manual download" in normalized and ("nexusmods.com" in normalized or "nexus mods" in normalized): - return True + return True, "manual download + nexusmods.com" - return False + return False, None diff --git a/jackify/frontends/gui/dialogs/completion_dialog.py b/jackify/frontends/gui/dialogs/completion_dialog.py index 8575528..b6b3ac4 100644 --- a/jackify/frontends/gui/dialogs/completion_dialog.py +++ b/jackify/frontends/gui/dialogs/completion_dialog.py @@ -16,6 +16,8 @@ from PySide6.QtWidgets import ( from PySide6.QtCore import Qt from PySide6.QtGui import QPixmap, QIcon +from jackify.shared.paths import get_jackify_logs_dir + logger = logging.getLogger(__name__) @@ -198,6 +200,6 @@ Modlist Install and Configuration complete!: NOTE: If you experience ENB issues, consider using GE-Proton 10-14 instead of Valve's Proton 10 (known ENB compatibility issues in Valve's Proton 10). -Detailed log available at: ~/Jackify/logs/Configure_New_Modlist_workflow.log""" +Detailed log available at: {get_jackify_logs_dir()}/Configure_New_Modlist_workflow.log""" return completion_text \ No newline at end of file diff --git a/jackify/frontends/gui/screens/configure_existing_modlist.py b/jackify/frontends/gui/screens/configure_existing_modlist.py index f1d7aa9..a7bfcf5 100644 --- a/jackify/frontends/gui/screens/configure_existing_modlist.py +++ b/jackify/frontends/gui/screens/configure_existing_modlist.py @@ -22,6 +22,7 @@ from jackify.backend.services.api_key_service import APIKeyService from jackify.backend.services.resolution_service import ResolutionService from jackify.backend.handlers.config_handler import ConfigHandler from ..dialogs import SuccessDialog +from jackify.frontends.gui.services.message_service import MessageService def debug_print(message): """Print debug message only if debug mode is enabled""" @@ -522,22 +523,20 @@ class ConfigureExistingModlistScreen(QWidget): message_lower = text.lower() # Update progress indicator based on key status messages - if "creating steam shortcut" in message_lower: - self.progress_indicator.set_status("Creating Steam shortcut...", 10) - elif "restarting steam" in message_lower or "restart steam" in message_lower: - self.progress_indicator.set_status("Restarting Steam...", 20) - elif "steam restart" in message_lower and "success" in message_lower: - self.progress_indicator.set_status("Steam restarted successfully", 30) - elif "creating proton prefix" in message_lower or "prefix creation" in message_lower: - self.progress_indicator.set_status("Creating Proton prefix...", 50) - elif "prefix created" in message_lower or "prefix creation" in message_lower and "success" in message_lower: - self.progress_indicator.set_status("Proton prefix created", 70) + if "setting protontricks permissions" in message_lower or "permissions" in message_lower: + self.progress_indicator.set_status("Setting permissions...", 20) + elif "applying curated registry" in message_lower or "registry" in message_lower: + self.progress_indicator.set_status("Applying registry files...", 40) + elif "installing wine components" in message_lower or "wine component" in message_lower: + self.progress_indicator.set_status("Installing wine components...", 60) + elif "dotnet" in message_lower and "fix" in message_lower: + self.progress_indicator.set_status("Applying dotnet fixes...", 75) + elif "setting ownership" in message_lower or "ownership and permissions" in message_lower: + self.progress_indicator.set_status("Setting permissions...", 85) elif "verifying" in message_lower: - self.progress_indicator.set_status("Verifying setup...", 80) + self.progress_indicator.set_status("Verifying setup...", 90) elif "steam integration complete" in message_lower or "configuration complete" in message_lower: - self.progress_indicator.set_status("Configuration complete", 95) - elif "complete" in message_lower and not "prefix" in message_lower: - self.progress_indicator.set_status("Finishing up...", 90) + self.progress_indicator.set_status("Configuration complete", 100) # Update activity window with generic configuration status # Only update if message contains meaningful progress (not blank lines or separators) diff --git a/jackify/frontends/gui/screens/configure_new_modlist.py b/jackify/frontends/gui/screens/configure_new_modlist.py index f02c73d..44c2bb4 100644 --- a/jackify/frontends/gui/screens/configure_new_modlist.py +++ b/jackify/frontends/gui/screens/configure_new_modlist.py @@ -612,12 +612,18 @@ class ConfigureNewModlistScreen(QWidget): self.progress_indicator.set_status("Creating Proton prefix...", 50) elif "prefix created" in message_lower or "prefix creation" in message_lower and "success" in message_lower: self.progress_indicator.set_status("Proton prefix created", 70) + elif "applying curated registry" in message_lower or "registry" in message_lower: + self.progress_indicator.set_status("Applying registry files...", 75) + elif "installing wine components" in message_lower or "wine component" in message_lower: + self.progress_indicator.set_status("Installing wine components...", 80) + elif "dotnet" in message_lower and "fix" in message_lower: + self.progress_indicator.set_status("Applying dotnet fixes...", 85) + elif "setting ownership" in message_lower or "ownership and permissions" in message_lower: + self.progress_indicator.set_status("Setting permissions...", 90) elif "verifying" in message_lower: - self.progress_indicator.set_status("Verifying setup...", 80) + self.progress_indicator.set_status("Verifying setup...", 95) elif "steam integration complete" in message_lower or "configuration complete" in message_lower: - self.progress_indicator.set_status("Configuration complete", 95) - elif "complete" in message_lower and not "prefix" in message_lower: - self.progress_indicator.set_status("Finishing up...", 90) + self.progress_indicator.set_status("Configuration complete", 100) # Update activity window with generic configuration status # Only update if message contains meaningful progress (not blank lines or separators) diff --git a/jackify/frontends/gui/screens/install_modlist.py b/jackify/frontends/gui/screens/install_modlist.py index 6b71bd6..4de59d5 100644 --- a/jackify/frontends/gui/screens/install_modlist.py +++ b/jackify/frontends/gui/screens/install_modlist.py @@ -1881,6 +1881,26 @@ class InstallModlistScreen(QWidget): ) return + # Log authentication status at install start (Issue #111 diagnostics) + import logging + logger = logging.getLogger(__name__) + auth_method = self.auth_service.get_auth_method() + logger.info("=" * 60) + logger.info("Authentication Status at Install Start") + logger.info(f"Method: {auth_method or 'UNKNOWN'}") + logger.info(f"Token length: {len(api_key)} chars") + if len(api_key) >= 8: + logger.info(f"Token (partial): {api_key[:4]}...{api_key[-4:]}") + + if auth_method == 'oauth': + token_handler = self.auth_service.token_handler + token_info = token_handler.get_token_info() + if 'expires_in_minutes' in token_info: + logger.info(f"OAuth expires in: {token_info['expires_in_minutes']:.1f} minutes") + if token_info.get('refresh_token_likely_expired'): + logger.warning(f"OAuth refresh token age: {token_info['refresh_token_age_days']:.1f} days (may need re-auth)") + logger.info("=" * 60) + modlist_name = self.modlist_name_edit.text().strip() missing_fields = [] if not modlist_name: @@ -2129,6 +2149,9 @@ class InstallModlistScreen(QWidget): # R&D: Progress state manager for parsing self.progress_state_manager = progress_state_manager self._premium_signal_sent = False + # Rolling buffer for Premium detection diagnostics + self._engine_output_buffer = [] + self._buffer_size = 10 def cancel(self): self.cancelled = True @@ -2196,10 +2219,71 @@ class InstallModlistScreen(QWidget): from jackify.backend.handlers.config_handler import ConfigHandler config_handler = ConfigHandler() debug_mode = config_handler.get('debug_mode', False) - if not self._premium_signal_sent and is_non_premium_indicator(decoded): + + # Check for Premium detection + is_premium_error, matched_pattern = is_non_premium_indicator(decoded) + if not self._premium_signal_sent and is_premium_error: self._premium_signal_sent = True + + # DIAGNOSTIC LOGGING: Capture false positive details + import logging + logger = logging.getLogger(__name__) + logger.warning("=" * 80) + logger.warning("PREMIUM DETECTION TRIGGERED - DIAGNOSTIC DUMP (Issue #111)") + logger.warning("=" * 80) + logger.warning(f"Matched pattern: '{matched_pattern}'") + logger.warning(f"Triggering line: '{decoded.strip()}'") + + # Detailed auth diagnostics + logger.warning("") + logger.warning("AUTHENTICATION DIAGNOSTICS:") + logger.warning(f" Auth value present: {'YES' if self.api_key else 'NO'}") + if self.api_key: + logger.warning(f" Auth value length: {len(self.api_key)} chars") + if len(self.api_key) >= 8: + logger.warning(f" Auth value (partial): {self.api_key[:4]}...{self.api_key[-4:]}") + + # Determine auth method and get detailed status + auth_method = self.auth_service.get_auth_method() + logger.warning(f" Auth method: {auth_method or 'UNKNOWN'}") + + if auth_method == 'oauth': + # Get detailed OAuth token status + token_handler = self.auth_service.token_handler + token_info = token_handler.get_token_info() + + logger.warning(" OAuth Token Status:") + logger.warning(f" Has token file: {token_info.get('has_token', False)}") + logger.warning(f" Has refresh token: {token_info.get('has_refresh_token', False)}") + + if 'expires_in_minutes' in token_info: + logger.warning(f" Expires in: {token_info['expires_in_minutes']:.1f} minutes") + logger.warning(f" Is expired: {token_info.get('is_expired', False)}") + logger.warning(f" Expires soon (5min): {token_info.get('expires_soon_5min', False)}") + + if 'refresh_token_age_days' in token_info: + logger.warning(f" Refresh token age: {token_info['refresh_token_age_days']:.1f} days") + logger.warning(f" Refresh token likely expired: {token_info.get('refresh_token_likely_expired', False)}") + + if token_info.get('error'): + logger.warning(f" Error: {token_info['error']}") + + logger.warning("") + logger.warning("Previous engine output (last 10 lines):") + for i, buffered_line in enumerate(self._engine_output_buffer, 1): + logger.warning(f" -{len(self._engine_output_buffer) - i + 1}: {buffered_line}") + logger.warning("") + logger.warning("If user HAS Premium, this is a FALSE POSITIVE") + logger.warning("Report to: https://github.com/Omni-guides/Jackify/issues/111") + logger.warning("=" * 80) + self.premium_required_detected.emit(decoded.strip() or "Nexus Premium required") + # Maintain rolling buffer of engine output for diagnostics + self._engine_output_buffer.append(decoded.strip()) + if len(self._engine_output_buffer) > self._buffer_size: + self._engine_output_buffer.pop(0) + # R&D: Process through progress parser if self.progress_state_manager: updated = self.progress_state_manager.process_line(decoded) @@ -2221,12 +2305,71 @@ class InstallModlistScreen(QWidget): line, buffer = buffer.split(b'\n', 1) line = ansi_escape.sub(b'', line) decoded = line.decode('utf-8', errors='replace') - + # Notify when Nexus requires Premium before continuing - if not self._premium_signal_sent and is_non_premium_indicator(decoded): + is_premium_error, matched_pattern = is_non_premium_indicator(decoded) + if not self._premium_signal_sent and is_premium_error: self._premium_signal_sent = True + + # DIAGNOSTIC LOGGING: Capture false positive details + import logging + logger = logging.getLogger(__name__) + logger.warning("=" * 80) + logger.warning("PREMIUM DETECTION TRIGGERED - DIAGNOSTIC DUMP (Issue #111)") + logger.warning("=" * 80) + logger.warning(f"Matched pattern: '{matched_pattern}'") + logger.warning(f"Triggering line: '{decoded.strip()}'") + + # Detailed auth diagnostics + logger.warning("") + logger.warning("AUTHENTICATION DIAGNOSTICS:") + logger.warning(f" Auth value present: {'YES' if self.api_key else 'NO'}") + if self.api_key: + logger.warning(f" Auth value length: {len(self.api_key)} chars") + if len(self.api_key) >= 8: + logger.warning(f" Auth value (partial): {self.api_key[:4]}...{self.api_key[-4:]}") + + # Determine auth method and get detailed status + auth_method = self.auth_service.get_auth_method() + logger.warning(f" Auth method: {auth_method or 'UNKNOWN'}") + + if auth_method == 'oauth': + # Get detailed OAuth token status + token_handler = self.auth_service.token_handler + token_info = token_handler.get_token_info() + + logger.warning(" OAuth Token Status:") + logger.warning(f" Has token file: {token_info.get('has_token', False)}") + logger.warning(f" Has refresh token: {token_info.get('has_refresh_token', False)}") + + if 'expires_in_minutes' in token_info: + logger.warning(f" Expires in: {token_info['expires_in_minutes']:.1f} minutes") + logger.warning(f" Is expired: {token_info.get('is_expired', False)}") + logger.warning(f" Expires soon (5min): {token_info.get('expires_soon_5min', False)}") + + if 'refresh_token_age_days' in token_info: + logger.warning(f" Refresh token age: {token_info['refresh_token_age_days']:.1f} days") + logger.warning(f" Refresh token likely expired: {token_info.get('refresh_token_likely_expired', False)}") + + if token_info.get('error'): + logger.warning(f" Error: {token_info['error']}") + + logger.warning("") + logger.warning("Previous engine output (last 10 lines):") + for i, buffered_line in enumerate(self._engine_output_buffer, 1): + logger.warning(f" -{len(self._engine_output_buffer) - i + 1}: {buffered_line}") + logger.warning("") + logger.warning("If user HAS Premium, this is a FALSE POSITIVE") + logger.warning("Report to: https://github.com/Omni-guides/Jackify/issues/111") + logger.warning("=" * 80) + self.premium_required_detected.emit(decoded.strip() or "Nexus Premium required") + # Maintain rolling buffer of engine output for diagnostics + self._engine_output_buffer.append(decoded.strip()) + if len(self._engine_output_buffer) > self._buffer_size: + self._engine_output_buffer.pop(0) + # R&D: Process through progress parser from jackify.backend.handlers.config_handler import ConfigHandler config_handler = ConfigHandler() diff --git a/jackify/frontends/gui/widgets/file_progress_list.py b/jackify/frontends/gui/widgets/file_progress_list.py index 31fc0e1..6b443d2 100644 --- a/jackify/frontends/gui/widgets/file_progress_list.py +++ b/jackify/frontends/gui/widgets/file_progress_list.py @@ -492,27 +492,13 @@ class FileProgressList(QWidget): # Widget doesn't exist - create it (only clear when creating new widget) # CRITICAL FIX: Remove all item widgets before clear() to prevent orphaned widgets - _debug_log(f"[WIDGET_FIX] About to clear list_widget for summary widget - count={self.list_widget.count()}") for i in range(self.list_widget.count()): item = self.list_widget.item(i) if item: widget = self.list_widget.itemWidget(item) if widget: - _debug_log(f"[WIDGET_FIX] Removing widget before clear (summary) - widget={widget}, parent={widget.parent()}, isWindow()={widget.isWindow()}") self.list_widget.removeItemWidget(item) - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Widget became top-level window after removeItemWidget() before clear()!") - import traceback - traceback.print_stack() self.list_widget.clear() - # Check widgets in _file_items dict after clear - for key, widget in list(self._file_items.items()): - if widget: - _debug_log(f"[WIDGET_FIX] Widget in _file_items after clear - key={key}, widget={widget}, parent={widget.parent()}, isWindow()={widget.isWindow()}") - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Widget in _file_items is a top-level window after clear()! This is the bug!") - import traceback - traceback.print_stack() self._file_items.clear() # Create new summary widget @@ -541,19 +527,8 @@ class FileProgressList(QWidget): # CRITICAL FIX: Call removeItemWidget() before takeItem() to prevent orphaned widgets widget = self.list_widget.itemWidget(item) if widget: - _debug_log(f"[WIDGET_FIX] Removing summary widget - widget={widget}, parent={widget.parent()}, isWindow()={widget.isWindow()}") self.list_widget.removeItemWidget(item) - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Summary widget became top-level window after removeItemWidget()!") - import traceback - traceback.print_stack() self.list_widget.takeItem(i) - if widget: - _debug_log(f"[WIDGET_FIX] After takeItem (summary) - widget.parent()={widget.parent()}, isWindow()={widget.isWindow()}") - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Summary widget is still a top-level window after takeItem()!") - import traceback - traceback.print_stack() break self._summary_widget = None else: @@ -568,19 +543,8 @@ class FileProgressList(QWidget): # CRITICAL FIX: Call removeItemWidget() before takeItem() to prevent orphaned widgets widget = self.list_widget.itemWidget(item) if widget: - _debug_log(f"[WIDGET_FIX] Removing transition label - widget={widget}, parent={widget.parent()}, isWindow()={widget.isWindow()}") self.list_widget.removeItemWidget(item) - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Transition label became top-level window after removeItemWidget()!") - import traceback - traceback.print_stack() self.list_widget.takeItem(i) - if widget: - _debug_log(f"[WIDGET_FIX] After takeItem (transition) - widget.parent()={widget.parent()}, isWindow()={widget.isWindow()}") - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Transition label is still a top-level window after takeItem()!") - import traceback - traceback.print_stack() break self._transition_label = None @@ -592,27 +556,13 @@ class FileProgressList(QWidget): else: # Show empty state but keep header stable # CRITICAL FIX: Remove all item widgets before clear() to prevent orphaned widgets - _debug_log(f"[WIDGET_FIX] About to clear list_widget (empty state) - count={self.list_widget.count()}") for i in range(self.list_widget.count()): item = self.list_widget.item(i) if item: widget = self.list_widget.itemWidget(item) if widget: - _debug_log(f"[WIDGET_FIX] Removing widget before clear (empty) - widget={widget}, parent={widget.parent()}, isWindow()={widget.isWindow()}") self.list_widget.removeItemWidget(item) - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Widget became top-level window after removeItemWidget() before clear()!") - import traceback - traceback.print_stack() self.list_widget.clear() - # Check widgets in _file_items dict after clear - for key, widget in list(self._file_items.items()): - if widget: - _debug_log(f"[WIDGET_FIX] Widget in _file_items after clear (empty) - key={key}, widget={widget}, parent={widget.parent()}, isWindow()={widget.isWindow()}") - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Widget in _file_items is a top-level window after clear()! This is the bug!") - import traceback - traceback.print_stack() self._file_items.clear() # Update last phase tracker @@ -661,21 +611,8 @@ class FileProgressList(QWidget): # CRITICAL FIX: Call removeItemWidget() before takeItem() to prevent orphaned widgets widget = self.list_widget.itemWidget(item) if widget: - _debug_log(f"[WIDGET_FIX] Removing widget for item_key={item_key} - widget={widget}, parent={widget.parent()}, isWindow()={widget.isWindow()}") self.list_widget.removeItemWidget(item) - # Check if widget became orphaned after removal - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Widget became top-level window after removeItemWidget()! widget={widget}") - import traceback - traceback.print_stack() self.list_widget.takeItem(i) - # Final check after takeItem - if widget: - _debug_log(f"[WIDGET_FIX] After takeItem - widget.parent()={widget.parent()}, isWindow()={widget.isWindow()}") - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Widget is still a top-level window after takeItem()! This is the bug!") - import traceback - traceback.print_stack() break del self._file_items[item_key] @@ -735,27 +672,13 @@ class FileProgressList(QWidget): def _show_transition_message(self, new_phase: str): """Show a brief 'Preparing...' message during phase transitions.""" # CRITICAL FIX: Remove all item widgets before clear() to prevent orphaned widgets - _debug_log(f"[WIDGET_FIX] About to clear list_widget (transition) - count={self.list_widget.count()}") for i in range(self.list_widget.count()): item = self.list_widget.item(i) if item: widget = self.list_widget.itemWidget(item) if widget: - _debug_log(f"[WIDGET_FIX] Removing widget before clear (transition) - widget={widget}, parent={widget.parent()}, isWindow()={widget.isWindow()}") self.list_widget.removeItemWidget(item) - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Widget became top-level window after removeItemWidget() before clear()!") - import traceback - traceback.print_stack() self.list_widget.clear() - # Check widgets in _file_items dict after clear - for key, widget in list(self._file_items.items()): - if widget: - _debug_log(f"[WIDGET_FIX] Widget in _file_items after clear (transition) - key={key}, widget={widget}, parent={widget.parent()}, isWindow()={widget.isWindow()}") - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Widget in _file_items is a top-level window after clear()! This is the bug!") - import traceback - traceback.print_stack() self._file_items.clear() # Header removed - tab label provides context @@ -781,41 +704,15 @@ class FileProgressList(QWidget): def clear(self): """Clear all file items.""" # CRITICAL FIX: Remove all item widgets before clear() to prevent orphaned widgets - _debug_log(f"[WIDGET_FIX] clear() called - count={self.list_widget.count()}") for i in range(self.list_widget.count()): item = self.list_widget.item(i) if item: widget = self.list_widget.itemWidget(item) if widget: - _debug_log(f"[WIDGET_FIX] Removing widget before clear() - widget={widget}, parent={widget.parent()}, isWindow()={widget.isWindow()}") self.list_widget.removeItemWidget(item) - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Widget became top-level window after removeItemWidget() before clear()!") - import traceback - traceback.print_stack() self.list_widget.clear() - # Check widgets in _file_items dict after clear - for key, widget in list(self._file_items.items()): - if widget: - _debug_log(f"[WIDGET_FIX] Widget in _file_items after clear() - key={key}, widget={widget}, parent={widget.parent()}, isWindow()={widget.isWindow()}") - if widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Widget in _file_items is a top-level window after clear()! This is the bug!") - import traceback - traceback.print_stack() self._file_items.clear() - if self._summary_widget: - _debug_log(f"[WIDGET_FIX] Clearing summary_widget - widget={self._summary_widget}, parent={self._summary_widget.parent()}, isWindow()={self._summary_widget.isWindow()}") - if self._summary_widget.isWindow(): - print(f"[WIDGET_FIX] ERROR: Summary widget is a top-level window in clear()!") - import traceback - traceback.print_stack() self._summary_widget = None - if self._transition_label: - _debug_log(f"[WIDGET_FIX] Clearing transition_label - widget={self._transition_label}, parent={self._transition_label.parent()}, isWindow()={self._transition_label.isWindow()}") - if self._transition_label.isWindow(): - print(f"[WIDGET_FIX] ERROR: Transition label is a top-level window in clear()!") - import traceback - traceback.print_stack() self._transition_label = None self._last_phase = None # Header removed - tab label provides context