diff --git a/synodic_client/application/bootstrap.py b/synodic_client/application/bootstrap.py index ce2d66a..1a73e47 100644 --- a/synodic_client/application/bootstrap.py +++ b/synodic_client/application/bootstrap.py @@ -20,11 +20,12 @@ from synodic_client.protocol import extract_uri_from_args from synodic_client.updater import initialize_velopack -# Parse --dev flag early so logging uses the right filename. +# Parse flags early so logging uses the right filename and level. _dev_mode = '--dev' in sys.argv[1:] +_debug = '--debug' in sys.argv[1:] set_dev_mode(_dev_mode) -configure_logging() +configure_logging(debug=_debug) initialize_velopack() if not _dev_mode: @@ -35,4 +36,4 @@ # Heavy imports happen here — PySide6, porringer, etc. from synodic_client.application.qt import application -application(uri=extract_uri_from_args(), dev_mode=_dev_mode) +application(uri=extract_uri_from_args(), dev_mode=_dev_mode, debug=_debug) diff --git a/synodic_client/application/qt.py b/synodic_client/application/qt.py index 3aab74a..af5528d 100644 --- a/synodic_client/application/qt.py +++ b/synodic_client/application/qt.py @@ -24,7 +24,7 @@ from synodic_client.application.uri import parse_uri from synodic_client.client import Client from synodic_client.config import set_dev_mode -from synodic_client.logging import configure_logging +from synodic_client.logging import configure_logging, set_debug_level from synodic_client.protocol import extract_uri_from_args from synodic_client.resolution import ( ResolvedConfig, @@ -104,7 +104,7 @@ def eventFilter(self, obj: QObject, event: QEvent) -> bool: # noqa: N802 ): geo = obj.geometry() stack = ''.join(traceback.format_stack(limit=12)) - self._diag_logger.warning( + self._diag_logger.debug( '[DIAG] Top-level window %s: class=%s title=%r geo=(%d,%d %dx%d) visible=%s\n%s', event.type().name, type(obj).__qualname__, @@ -149,7 +149,7 @@ def _init_app() -> QApplication: return app -def application(*, uri: str | None = None, dev_mode: bool = False) -> None: +def application(*, uri: str | None = None, dev_mode: bool = False, debug: bool = False) -> None: """Application entry point. Args: @@ -159,13 +159,14 @@ def application(*, uri: str | None = None, dev_mode: bool = False) -> None: log files, or single-instance locks with the user-installed application. Velopack initialisation and protocol registration are skipped. + debug: When ``True``, enable DEBUG-level file logging. """ # Activate dev-mode namespacing before anything reads config paths. set_dev_mode(dev_mode) # Configure logging before Velopack so install/uninstall hooks and # first-run diagnostics are captured in the log file. - configure_logging() + configure_logging(debug=debug) logger = logging.getLogger('synodic_client') _install_exception_hook(logger) @@ -180,6 +181,11 @@ def application(*, uri: str | None = None, dev_mode: bool = False) -> None: client, porringer, config = _init_services(logger) + # Honour the persisted debug_logging preference unless the --debug + # flag already activated it. + if not debug and config.debug_logging: + set_debug_level(enabled=True) + app = _init_app() loop = qasync.QEventLoop(app) diff --git a/synodic_client/application/screen/screen.py b/synodic_client/application/screen/screen.py index 78de44b..6933b47 100644 --- a/synodic_client/application/screen/screen.py +++ b/synodic_client/application/screen/screen.py @@ -199,8 +199,7 @@ def refresh(self) -> None: """Schedule an asynchronous rebuild of the tool list.""" if self._refresh_in_progress: return - caller = ''.join(traceback.format_stack(limit=4)) - logger.info('[DIAG] ToolsView.refresh() called, parent_visible=%s\n%s', self.isVisible(), caller) + logger.debug('ToolsView.refresh() called (visible=%s)', self.isVisible()) asyncio.create_task(self._async_refresh()) async def _async_refresh(self) -> None: @@ -1112,7 +1111,7 @@ def showEvent(self, event: QShowEvent) -> None: # noqa: N802 """[DIAG] Log every show event with a stack trace.""" geo = self.geometry() stack = ''.join(traceback.format_stack(limit=10)) - logger.warning( + logger.debug( '[DIAG] MainWindow.showEvent: geo=(%d,%d %dx%d) visible=%s\n%s', geo.x(), geo.y(), diff --git a/synodic_client/application/screen/settings.py b/synodic_client/application/screen/settings.py index 69b5684..748dd8b 100644 --- a/synodic_client/application/screen/settings.py +++ b/synodic_client/application/screen/settings.py @@ -32,7 +32,7 @@ from synodic_client.application.screen import _format_relative_time from synodic_client.application.screen.card import CardFrame from synodic_client.application.theme import SETTINGS_WINDOW_MIN_SIZE, UPDATE_STATUS_CHECKING_STYLE -from synodic_client.logging import log_path +from synodic_client.logging import log_path, set_debug_level from synodic_client.resolution import ResolvedConfig, update_user_config from synodic_client.schema import GITHUB_REPO_URL from synodic_client.startup import is_startup_registered, register_startup, remove_startup @@ -54,11 +54,14 @@ class SettingsWindow(QMainWindow): check_updates_requested = Signal() """Emitted when the user clicks the *Check for Updates* button.""" + restart_requested = Signal() + """Emitted when the user clicks the *Restart & Update* button.""" + def showEvent(self, event: QShowEvent) -> None: # noqa: N802 """[DIAG] Log every show event with a stack trace.""" geo = self.geometry() stack = ''.join(traceback.format_stack(limit=10)) - logger.warning( + logger.debug( '[DIAG] SettingsWindow.showEvent: geo=(%d,%d %dx%d) visible=%s\n%s', geo.x(), geo.y(), @@ -199,6 +202,12 @@ def _add_update_controls(self, content: QVBoxLayout) -> None: self._update_status_label = QLabel('') self._update_status_label.setTextInteractionFlags(Qt.TextInteractionFlag.TextSelectableByMouse) row.addWidget(self._update_status_label) + + self._restart_btn = QPushButton('Restart \u0026 Update') + self._restart_btn.clicked.connect(self.restart_requested.emit) + self._restart_btn.hide() + row.addWidget(self._restart_btn) + row.addStretch() content.addLayout(row) @@ -218,6 +227,12 @@ def _build_startup_section(self) -> CardFrame: def _build_advanced_section(self) -> CardFrame: """Construct the *Advanced* settings card.""" card = CardFrame('Advanced') + + self._debug_logging_check = QCheckBox('Debug logging') + self._debug_logging_check.setToolTip('Write DEBUG-level messages to the log file') + self._debug_logging_check.toggled.connect(self._on_debug_logging_changed) + card.content_layout.addWidget(self._debug_logging_check) + row = QHBoxLayout() open_log_btn = QPushButton('Open Log\u2026') open_log_btn.clicked.connect(self._open_log) @@ -254,6 +269,9 @@ def sync_from_config(self) -> None: self._auto_apply_check.setChecked(config.auto_apply) self._auto_start_check.setChecked(is_startup_registered()) + # Debug logging + self._debug_logging_check.setChecked(config.debug_logging) + # Last client update timestamp if config.last_client_update: relative = _format_relative_time(config.last_client_update) @@ -275,6 +293,7 @@ def set_update_status(self, text: str, style: str = '') -> None: def set_checking(self) -> None: """Enter the *checking* state — disable button and show status.""" self._check_updates_btn.setEnabled(False) + self._restart_btn.hide() self._update_status_label.setText('Checking\u2026') self._update_status_label.setStyleSheet(UPDATE_STATUS_CHECKING_STYLE) @@ -282,6 +301,10 @@ def reset_check_updates_button(self) -> None: """Re-enable the *Check for Updates* button after a check completes.""" self._check_updates_btn.setEnabled(True) + def show_restart_button(self) -> None: + """Show the *Restart & Update* button.""" + self._restart_btn.show() + def show(self) -> None: """Sync controls from config, then show the window.""" self.sync_from_config() @@ -313,6 +336,7 @@ def _block_signals(self) -> Iterator[None]: self._detect_updates_check, self._auto_apply_check, self._auto_start_check, + self._debug_logging_check, self._check_updates_btn, ) for w in widgets: @@ -362,6 +386,10 @@ def _on_auto_start_changed(self, checked: bool) -> None: remove_startup() self.settings_changed.emit(self._config) + def _on_debug_logging_changed(self, checked: bool) -> None: + set_debug_level(enabled=checked) + self._persist(debug_logging=checked) + @staticmethod def _open_log() -> None: """Open the log file in the system's default editor.""" diff --git a/synodic_client/application/screen/tray.py b/synodic_client/application/screen/tray.py index e82bcd4..1a4d68b 100644 --- a/synodic_client/application/screen/tray.py +++ b/synodic_client/application/screen/tray.py @@ -5,6 +5,7 @@ from PySide6.QtGui import QAction from PySide6.QtWidgets import ( QApplication, + QMainWindow, QMenu, QSystemTrayIcon, ) @@ -130,13 +131,15 @@ def _show_settings(self) -> None: """Show the settings window.""" self._settings_window.show() - def _is_user_active(self) -> bool: - """Return ``True`` when the user has a visible window. + @staticmethod + def _is_user_active() -> bool: + """Return ``True`` when the user has a visible application window. - Used by the update controllers to defer automatic updates - while the user is actively interacting with the application. + Checks all top-level ``QMainWindow`` instances (main window, + settings, install previews) so that auto-apply is deferred + whenever *any* window is open. """ - return self._window.isVisible() or self._settings_window.isVisible() + return any(w.isVisible() for w in QApplication.topLevelWidgets() if isinstance(w, QMainWindow)) def _on_settings_changed(self, config: ResolvedConfig) -> None: """React to a change made in the settings window.""" diff --git a/synodic_client/application/update_controller.py b/synodic_client/application/update_controller.py index 5a988a4..fb84024 100644 --- a/synodic_client/application/update_controller.py +++ b/synodic_client/application/update_controller.py @@ -56,7 +56,7 @@ class UpdateController: Optional pre-resolved configuration. ``None`` resolves from disk. is_user_active: Predicate returning ``True`` when the user has a visible window. - Automatic checks and auto-apply are deferred while active. + Auto-apply is deferred while active; checks still run normally. """ def __init__( @@ -99,9 +99,10 @@ def __init__( # Wire settings check-updates button self._settings_window.check_updates_requested.connect(self._on_manual_check) + self._settings_window.restart_requested.connect(self._apply_update) def set_user_active_predicate(self, predicate: Callable[[], bool]) -> None: - """Set the predicate used to defer automatic checks when the user is active. + """Set the predicate used to defer auto-apply when the user is active. Args: predicate: Returns ``True`` when the user has a visible window. @@ -200,12 +201,10 @@ def _on_manual_check(self) -> None: def _on_auto_check(self) -> None: """Handle automatic (periodic) check — silent. - Skipped when the user has a visible window to avoid disruptive - downloads and auto-apply restarts. The next timer tick retries. + The check always runs so the settings window can show the + latest status and the *last updated* timestamp stays current. + Auto-apply is gated separately by :meth:`_can_auto_apply`. """ - if self._is_user_active(): - logger.debug('Automatic update check deferred — user is active') - return self._do_check(silent=True) def _do_check(self, *, silent: bool) -> None: @@ -324,6 +323,7 @@ def _on_download_finished(self, success: bool, version: str) -> None: f'v{version} ready', UPDATE_STATUS_UP_TO_DATE_STYLE, ) + self._settings_window.show_restart_button() def _on_download_error(self, error: str) -> None: """Handle download error — show error banner.""" diff --git a/synodic_client/cli.py b/synodic_client/cli.py index 9b9a5a8..be61e88 100644 --- a/synodic_client/cli.py +++ b/synodic_client/cli.py @@ -35,8 +35,12 @@ def main( bool, typer.Option('--dev', help='Run in dev mode with isolated config, logs, and instance lock.'), ] = False, + debug: Annotated[ + bool, + typer.Option('--debug', help='Enable DEBUG-level file logging for this session.'), + ] = False, ) -> None: """Launch the Synodic Client GUI application.""" from synodic_client.application.qt import application - application(uri=uri, dev_mode=dev) + application(uri=uri, dev_mode=dev, debug=debug) diff --git a/synodic_client/logging.py b/synodic_client/logging.py index cecaf4d..3077012 100644 --- a/synodic_client/logging.py +++ b/synodic_client/logging.py @@ -1,6 +1,7 @@ """Centralised logging configuration for the Synodic Client. -Provides a rotating file handler with eager flushing. +Provides a rotating file handler with eager flushing and runtime +log-level switching via :func:`set_debug_level`. """ import logging @@ -17,6 +18,8 @@ _BACKUP_COUNT = 3 _FORMAT = '%(asctime)s [%(levelname)s] %(name)s: %(message)s' +_debug_active: bool = False + def log_path() -> Path: """Return the path to the application log file. @@ -43,13 +46,18 @@ def emit(self, record: logging.LogRecord) -> None: self.flush() -def configure_logging() -> None: +def configure_logging(*, debug: bool = False) -> None: """Set up application-wide logging. Attaches a :class:`EagerRotatingFileHandler` to the ``synodic_client`` and ``porringer`` loggers and configures :func:`logging.basicConfig` for ``INFO`` level output on *stderr*. + Args: + debug: When ``True``, set the file handler and app logger to + ``DEBUG`` level immediately. Equivalent to calling + :func:`set_debug_level` after configuration. + Safe to call more than once — subsequent calls are no-ops. """ app_logger = logging.getLogger('synodic_client') @@ -80,3 +88,26 @@ def configure_logging() -> None: porringer_logger.setLevel(logging.DEBUG) else: porringer_logger.setLevel(logging.INFO) + + if debug: + set_debug_level(enabled=True) + + +def set_debug_level(*, enabled: bool) -> None: + """Switch the app logger and file handler between DEBUG and INFO at runtime. + + Safe to call at any time. Has no effect if logging has not been + configured yet. + + Args: + enabled: ``True`` for DEBUG, ``False`` for INFO. + """ + global _debug_active # noqa: PLW0603 + _debug_active = enabled + level = logging.DEBUG if enabled else logging.INFO + + app_logger = logging.getLogger('synodic_client') + app_logger.setLevel(level) + for h in app_logger.handlers: + if isinstance(h, EagerRotatingFileHandler): + h.setLevel(level) diff --git a/synodic_client/resolution.py b/synodic_client/resolution.py index ee81c70..f366d1d 100644 --- a/synodic_client/resolution.py +++ b/synodic_client/resolution.py @@ -114,6 +114,7 @@ def _resolve_from_user(user: UserConfig) -> ResolvedConfig: auto_apply = user.auto_apply if user.auto_apply is not None else True auto_start = user.auto_start if user.auto_start is not None else True + debug_logging = user.debug_logging if user.debug_logging is not None else False return ResolvedConfig( update_source=user.update_source, @@ -125,6 +126,7 @@ def _resolve_from_user(user: UserConfig) -> ResolvedConfig: prerelease_packages=user.prerelease_packages, auto_apply=auto_apply, auto_start=auto_start, + debug_logging=debug_logging, last_client_update=user.last_client_update, last_tool_updates=user.last_tool_updates, ) diff --git a/synodic_client/schema.py b/synodic_client/schema.py index 4ba3f56..d607a46 100644 --- a/synodic_client/schema.py +++ b/synodic_client/schema.py @@ -100,6 +100,10 @@ class UserConfig(BaseModel): # auto-startup. auto_start: bool | None = None + # Enable verbose DEBUG-level logging to the log file. + # None resolves to False (INFO level). + debug_logging: bool | None = None + # ISO 8601 timestamp of the last successful client self-update. # None means no update has been recorded. last_client_update: str | None = None @@ -231,5 +235,6 @@ class ResolvedConfig: prerelease_packages: dict[str, list[str]] | None auto_apply: bool auto_start: bool + debug_logging: bool last_client_update: str | None last_tool_updates: dict[str, str] | None diff --git a/synodic_client/updater.py b/synodic_client/updater.py index c4ceb41..61761d3 100644 --- a/synodic_client/updater.py +++ b/synodic_client/updater.py @@ -7,6 +7,7 @@ For non-installed (development) environments, updates are not supported. """ +import contextlib import logging import sys from collections.abc import Callable @@ -114,6 +115,12 @@ def __init__(self, current_version: Version, config: UpdateConfig | None = None) self._velopack_manager: Any = None self._velopack_not_installed: bool = False + # Eagerly resolve the Velopack manager so that + # _current_version reflects the installed binary version + # rather than the (potentially stale) Python package metadata. + with contextlib.suppress(Exception): + self._get_velopack_manager() + logger.info( 'Updater created: version=%s, channel=%s, repo=%s', self._current_version, @@ -406,6 +413,11 @@ def initialize_velopack() -> None: return _VelopackState.initialized = True + # During post-update restarts Velopack's App.run() may exit the + # current process (to apply the update and relaunch). Each + # short-lived process writes "Initializing Velopack" to the shared + # log file before being replaced, so multiple entries followed by a + # single "initialized successfully" is expected behaviour. logger.info('Initializing Velopack (exe=%s)', sys.executable) try: app = velopack.App() diff --git a/tests/unit/qt/test_gather_packages.py b/tests/unit/qt/test_gather_packages.py index 83c703e..0627f41 100644 --- a/tests/unit/qt/test_gather_packages.py +++ b/tests/unit/qt/test_gather_packages.py @@ -41,6 +41,7 @@ def _make_config() -> ResolvedConfig: prerelease_packages=None, auto_apply=True, auto_start=False, + debug_logging=False, last_client_update=None, last_tool_updates=None, ) diff --git a/tests/unit/qt/test_settings.py b/tests/unit/qt/test_settings.py index 930eecc..33d3b08 100644 --- a/tests/unit/qt/test_settings.py +++ b/tests/unit/qt/test_settings.py @@ -27,6 +27,7 @@ def _make_config(**overrides: Any) -> ResolvedConfig: 'prerelease_packages': None, 'auto_apply': True, 'auto_start': True, + 'debug_logging': False, 'last_client_update': None, 'last_tool_updates': None, } diff --git a/tests/unit/qt/test_update_controller.py b/tests/unit/qt/test_update_controller.py index 0906755..0559377 100644 --- a/tests/unit/qt/test_update_controller.py +++ b/tests/unit/qt/test_update_controller.py @@ -38,6 +38,7 @@ def _make_config(**overrides: Any) -> ResolvedConfig: 'prerelease_packages': None, 'auto_apply': True, 'auto_start': True, + 'debug_logging': False, 'last_client_update': None, 'last_tool_updates': None, } @@ -197,6 +198,27 @@ def test_no_auto_apply_sets_ready_status() -> None: UPDATE_STATUS_UP_TO_DATE_STYLE, ) + @staticmethod + def test_no_auto_apply_shows_restart_button() -> None: + """When auto_apply=False, the restart button should be shown in settings.""" + ctrl, app, client, banner, settings = _make_controller(auto_apply=False) + ctrl._on_download_finished(True, '2.0.0') + + settings.show_restart_button.assert_called_once() + + @staticmethod + def test_user_active_shows_restart_button() -> None: + """When user is active, the restart button should be shown in settings.""" + ctrl, app, client, banner, settings = _make_controller( + auto_apply=True, + is_user_active=True, + ) + + with patch.object(ctrl, '_apply_update'): + ctrl._on_download_finished(True, '2.0.0') + + settings.show_restart_button.assert_called_once() + @staticmethod def test_download_failure_shows_error() -> None: """A failed download should show an error banner.""" @@ -213,22 +235,16 @@ def test_download_failure_shows_error() -> None: class TestUserActiveGating: - """Verify that automatic actions are deferred when the user is active.""" - - @staticmethod - def test_auto_check_skipped_when_user_active() -> None: - """_on_auto_check should not call _do_check when user is active.""" - ctrl, _app, _client, banner, settings = _make_controller(is_user_active=True) - - with patch.object(ctrl, '_do_check') as mock_check: - ctrl._on_auto_check() + """Verify that auto-apply is deferred when the user is active. - mock_check.assert_not_called() + Automatic checks always run so the settings window stays current. + Only the silent apply-and-restart is gated by ``_is_user_active``. + """ @staticmethod - def test_auto_check_proceeds_when_user_inactive() -> None: - """_on_auto_check should call _do_check when user is NOT active.""" - ctrl, _app, _client, banner, settings = _make_controller(is_user_active=False) + def test_auto_check_always_runs() -> None: + """_on_auto_check should call _do_check even when user is active.""" + ctrl, _app, _client, banner, settings = _make_controller(is_user_active=True) with patch.object(ctrl, '_do_check') as mock_check: ctrl._on_auto_check() @@ -318,6 +334,14 @@ def test_apply_update_noop_without_updater() -> None: client.apply_update_on_exit.assert_not_called() app.quit.assert_not_called() + @staticmethod + def test_restart_requested_signal_triggers_apply() -> None: + """The settings restart_requested signal should be connected to _apply_update.""" + ctrl, app, client, banner, settings = _make_controller() + + # Verify the signal was connected + settings.restart_requested.connect.assert_called_once_with(ctrl._apply_update) + # --------------------------------------------------------------------------- # Settings changed → immediate check diff --git a/tests/unit/test_cli.py b/tests/unit/test_cli.py index ca25821..9b5bbe2 100644 --- a/tests/unit/test_cli.py +++ b/tests/unit/test_cli.py @@ -36,7 +36,7 @@ def test_launches_application_without_uri() -> None: with patch('synodic_client.application.qt.application') as mock_app: result = runner.invoke(app, []) assert result.exit_code == 0 - mock_app.assert_called_once_with(uri=None, dev_mode=False) + mock_app.assert_called_once_with(uri=None, dev_mode=False, debug=False) @staticmethod def test_launches_application_with_uri() -> None: @@ -45,7 +45,7 @@ def test_launches_application_with_uri() -> None: with patch('synodic_client.application.qt.application') as mock_app: result = runner.invoke(app, [test_uri]) assert result.exit_code == 0 - mock_app.assert_called_once_with(uri=test_uri, dev_mode=False) + mock_app.assert_called_once_with(uri=test_uri, dev_mode=False, debug=False) @staticmethod def test_launches_application_with_dev_flag() -> None: @@ -53,4 +53,4 @@ def test_launches_application_with_dev_flag() -> None: with patch('synodic_client.application.qt.application') as mock_app: result = runner.invoke(app, ['--dev']) assert result.exit_code == 0 - mock_app.assert_called_once_with(uri=None, dev_mode=True) + mock_app.assert_called_once_with(uri=None, dev_mode=True, debug=False) diff --git a/tests/unit/test_config.py b/tests/unit/test_config.py index 976ccbb..1709cce 100644 --- a/tests/unit/test_config.py +++ b/tests/unit/test_config.py @@ -49,6 +49,7 @@ def test_defaults() -> None: assert config.prerelease_packages is None assert config.auto_apply is None assert config.auto_start is None + assert config.debug_logging is None @staticmethod def test_prerelease_packages_round_trip() -> None: diff --git a/tests/unit/test_resolution.py b/tests/unit/test_resolution.py index 3133485..031152a 100644 --- a/tests/unit/test_resolution.py +++ b/tests/unit/test_resolution.py @@ -38,6 +38,7 @@ def _make_resolved(**overrides: Any) -> ResolvedConfig: 'prerelease_packages': None, 'auto_apply': True, 'auto_start': True, + 'debug_logging': False, 'last_client_update': None, 'last_tool_updates': None, } diff --git a/tests/unit/test_updater.py b/tests/unit/test_updater.py index 882f7ef..887a0cb 100644 --- a/tests/unit/test_updater.py +++ b/tests/unit/test_updater.py @@ -70,7 +70,12 @@ def test_trailing_slash_stripped() -> None: @pytest.fixture def updater() -> Updater: """Create an Updater instance for testing.""" - return Updater(current_version=Version('1.0.0')) + u = Updater(current_version=Version('1.0.0')) + # Reset state cached by the eager _get_velopack_manager() call + # so each test can independently mock the Velopack SDK. + u._velopack_manager = None + u._velopack_not_installed = False + return u @pytest.fixture @@ -80,7 +85,10 @@ def updater_with_config() -> Updater: repo_url='https://github.com/test/repo', channel=UpdateChannel.DEVELOPMENT, ) - return Updater(current_version=Version('1.0.0'), config=config) + u = Updater(current_version=Version('1.0.0'), config=config) + u._velopack_manager = None + u._velopack_not_installed = False + return u class TestUpdater: