#859: DB-update stall watchdog + UI self-heal (no more wedged 'Starting...' / frozen bar)

core/database_update_health.py

@@ -0,0 +1,82 @@
+"""Stall detection for the database-update job.
+
+The DB updater keeps a single in-memory state dict whose ``status`` is set to
+``running`` at start and only flipped to ``finished``/``error`` by the worker's
+completion/error callbacks. If the worker thread hangs — e.g. a media-server API
+call with no timeout, a DB lock — those callbacks never fire, so ``status`` stays
+``running`` forever and the UI shows a frozen progress bar with no way to recover
+(GitHub #859).
+
+This module is the single, *pure* decision for "is a running job stalled?". It
+takes the state dict plus the current wall-clock time and a timeout, and answers
+yes/no — no DB, no globals, no clock of its own. That keeps it unit-testable and
+lets the watchdog wiring in web_server.py stay a thin call. The job carries a
+``last_progress_at`` epoch timestamp that the start path and every progress/phase
+callback bump; staleness is simply "running, and that timestamp is older than the
+timeout".
+"""
+
+from __future__ import annotations
+
+from typing import Any, Mapping
+
+# 5 minutes with zero forward progress = presumed hung. A healthy scan ticks
+# progress (per-artist) far more often than this even for large libraries, so
+# the timeout won't false-positive a slow-but-working run.
+DEFAULT_STALL_TIMEOUT_SECONDS = 300
+
+
+def is_db_update_stalled(
+    state: Mapping[str, Any],
+    now: float,
+    timeout_seconds: float = DEFAULT_STALL_TIMEOUT_SECONDS,
+) -> bool:
+    """Return True when the job is ``running`` but has made no progress within
+    ``timeout_seconds``.
+
+    Conservative by design — it only ever reports a stall it can prove:
+    - Only a ``running`` job can stall (idle/finished/error never do).
+    - With no usable ``last_progress_at`` timestamp we cannot judge, so we return
+      False rather than risk killing a job we have no clock for.
+    - A non-positive timeout is treated as "disabled" (never stalls).
+    """
+    if not isinstance(state, Mapping):
+        return False
+    if state.get("status") != "running":
+        return False
+    if timeout_seconds is None or timeout_seconds <= 0:
+        return False
+    last = state.get("last_progress_at")
+    if not last:
+        return False
+    try:
+        elapsed = float(now) - float(last)
+    except (TypeError, ValueError):
+        return False
+    return elapsed >= float(timeout_seconds)
+
+
+def stalled_error_message(state: Mapping[str, Any], now: float) -> str:
+    """Build a clear, human-facing message for a stalled job, including how long
+    it has been silent and the phase it died in."""
+    last = state.get("last_progress_at") if isinstance(state, Mapping) else None
+    phase = state.get("phase") if isinstance(state, Mapping) else None
+    try:
+        secs = int(float(now) - float(last)) if last else 0
+    except (TypeError, ValueError):
+        secs = 0
+    msg = "Update appears stuck — no progress"
+    if secs > 0:
+        msg += f" for {secs}s"
+    if phase:
+        msg += f" (last phase: {phase})"
+    msg += (". The worker may be hung on the media server. Start a new update "
+            "to try again, or restart SoulSync if it keeps stalling.")
+    return msg
+
+
+__all__ = [
+    "DEFAULT_STALL_TIMEOUT_SECONDS",
+    "is_db_update_stalled",
+    "stalled_error_message",
+]

tests/test_database_update_health.py

@@ -0,0 +1,92 @@
+"""Seam tests for the database-update stall watchdog (GitHub #859).
+
+A DB-update job can hang (media-server call with no timeout, DB lock) and sit at
+status='running' forever because the worker's finished/error callbacks never
+fire. `is_db_update_stalled` is the pure decision that lets the watchdog flip
+such a job to 'error' so the UI recovers. These tests pin that decision —
+including the conservative cases where it must NOT false-positive.
+"""
+
+from __future__ import annotations
+
+from core.database_update_health import (
+    DEFAULT_STALL_TIMEOUT_SECONDS,
+    is_db_update_stalled,
+    stalled_error_message,
+)
+
+
+def _state(**over):
+    base = {"status": "running", "phase": "Incremental: scanning",
+            "processed": 2, "total": 3, "progress": 66.7, "last_progress_at": 1000.0}
+    base.update(over)
+    return base
+
+
+def test_running_and_heartbeat_stale_is_stalled():
+    # last tick at t=1000, now=1000+timeout → exactly at the boundary counts.
+    now = 1000.0 + DEFAULT_STALL_TIMEOUT_SECONDS
+    assert is_db_update_stalled(_state(), now) is True
+
+
+def test_running_and_heartbeat_fresh_is_not_stalled():
+    now = 1000.0 + 5  # ticked 5s ago, well within timeout
+    assert is_db_update_stalled(_state(), now) is False
+
+
+def test_just_under_timeout_is_not_stalled():
+    now = 1000.0 + DEFAULT_STALL_TIMEOUT_SECONDS - 0.001
+    assert is_db_update_stalled(_state(), now) is False
+
+
+def test_non_running_statuses_never_stall():
+    now = 1000.0 + 10_000  # very stale heartbeat
+    for status in ("idle", "finished", "error"):
+        assert is_db_update_stalled(_state(status=status), now) is False, status
+
+
+def test_missing_heartbeat_cannot_judge():
+    # No usable timestamp → we refuse to kill a job we have no clock for.
+    now = 1_000_000.0
+    assert is_db_update_stalled(_state(last_progress_at=0), now) is False
+    assert is_db_update_stalled(_state(last_progress_at=None), now) is False
+    s = _state()
+    del s["last_progress_at"]
+    assert is_db_update_stalled(s, now) is False
+
+
+def test_non_positive_timeout_disables_watchdog():
+    now = 1000.0 + 10_000
+    assert is_db_update_stalled(_state(), now, timeout_seconds=0) is False
+    assert is_db_update_stalled(_state(), now, timeout_seconds=-1) is False
+
+
+def test_bad_inputs_are_safe():
+    assert is_db_update_stalled(None, 123.0) is False
+    assert is_db_update_stalled("not a dict", 123.0) is False
+    assert is_db_update_stalled(_state(last_progress_at="oops"), 1_000_000.0) is False
+
+
+def test_custom_timeout_respected():
+    now = 1000.0 + 120
+    assert is_db_update_stalled(_state(), now, timeout_seconds=60) is True
+    assert is_db_update_stalled(_state(), now, timeout_seconds=180) is False
+
+
+def test_stalled_message_is_informative():
+    now = 1000.0 + 360
+    msg = stalled_error_message(_state(phase="Incremental: scanning"), now)
+    assert "stuck" in msg.lower()
+    assert "360s" in msg
+    assert "Incremental: scanning" in msg
+
+
+def test_issue_859_frozen_running_job_is_caught():
+    """Regression: the reported state — running, frozen at 2/3 (66.7%), heartbeat
+    long stale — is detected as stalled so the card can self-heal."""
+    state = _state(status="running", processed=2, total=3, progress=66.7,
+                   last_progress_at=1000.0)
+    now = 1000.0 + DEFAULT_STALL_TIMEOUT_SECONDS + 30
+    assert is_db_update_stalled(state, now) is True
+    # And a healthy job that's actively ticking is left alone.
+    assert is_db_update_stalled(_state(last_progress_at=now - 2), now) is False

web_server.py

@@ -973,6 +973,10 @@ db_update_state = {
     "removed_artists": 0,
     "removed_albums": 0,
     "removed_tracks": 0,
+    # Heartbeat epoch (seconds): bumped at start and on every progress/phase
+    # callback. The stall watchdog (core.database_update_health) flips a job to
+    # 'error' when this goes stale while status is still 'running' (#859).
+    "last_progress_at": 0,
 }
 _db_update_automation_id = None  # Set when automation triggers DB update, used by callbacks
 db_update_lock = threading.Lock()
@@ -8099,7 +8103,8 @@ def request_incremental_database_update():
         with db_update_lock:
             db_update_state.update({
                 "status": "running", "phase": "Initializing...",
-                "progress": 0, "current_item": "", "processed": 0, "total": 0, "error_message": ""
+                "progress": 0, "current_item": "", "processed": 0, "total": 0, "error_message": "",
+                "last_progress_at": time.time(),  # seed heartbeat for the stall watchdog
             })
         db_update_executor.submit(_run_db_update_task, False, active_server)
 
@@ -15723,7 +15728,8 @@ def _db_update_progress_callback(current_item, processed, total, percentage):
             "current_item": current_item,
             "processed": processed,
             "total": total,
-            "progress": percentage
+            "progress": percentage,
+            "last_progress_at": time.time(),  # heartbeat for the stall watchdog
         })
     _update_automation_progress(_db_update_automation_id,
                                 progress=percentage, processed=processed, total=total,
@@ -15733,6 +15739,7 @@ def _db_update_phase_callback(phase):
     logger.info(f"[DB Phase] {phase}")
     with db_update_lock:
         db_update_state["phase"] = phase
+        db_update_state["last_progress_at"] = time.time()  # heartbeat for the stall watchdog
     _update_automation_progress(_db_update_automation_id, phase=phase)
 
 def _db_update_artist_callback(artist_name, success, details, album_count, track_count):
@@ -15853,6 +15860,44 @@ def _db_update_error_callback(error_message):
     # Add activity for database update error
     add_activity_item("", "Database Update Failed", error_message, "Now")
 
+
+def _check_db_update_stall():
+    """Watchdog: flip a hung 'running' DB-update job to 'error' so the UI can
+    recover (#859). A worker that blocks indefinitely (media-server call with no
+    timeout, DB lock) never fires its finished/error callback, so the job would
+    otherwise sit at 'running' forever with a frozen progress bar.
+
+    Idempotent — only acts on the running→stalled transition (after the flip,
+    status != 'running' so the pure check returns False and we don't re-fire).
+    Safe to call from the status endpoint and the 1s broadcast loop. Returns True
+    only on the transition."""
+    from core.database_update_health import (
+        DEFAULT_STALL_TIMEOUT_SECONDS,
+        is_db_update_stalled,
+        stalled_error_message,
+    )
+    try:
+        timeout = config_manager.get('database.update_stall_timeout_seconds',
+                                     DEFAULT_STALL_TIMEOUT_SECONDS)
+    except Exception:
+        timeout = DEFAULT_STALL_TIMEOUT_SECONDS
+    now = time.time()
+    with db_update_lock:
+        if not is_db_update_stalled(db_update_state, now, timeout):
+            return False
+        msg = stalled_error_message(db_update_state, now)
+        db_update_state["status"] = "error"
+        db_update_state["error_message"] = msg
+        db_update_state["phase"] = "Stalled"
+    logger.error(f"[DB Update Watchdog] {msg}")
+    # The hung worker paused enrichment/maintenance workers and won't resume them
+    # itself — resume here so a stall doesn't leave them parked indefinitely.
+    try:
+        _resume_workers_after_scan()
+    except Exception as e:
+        logger.debug(f"[DB Update Watchdog] resume workers failed: {e}")
+    return True
+
 _workers_paused_by_scan = set()  # Track which workers WE paused (don't resume manually-paused ones)
 
 def _pause_workers_for_scan():
@@ -16719,7 +16764,10 @@ def start_database_update():
         db_update_state.update({
             "status": "running",
             "phase": f"{scan_type}: Initializing...",
-            "progress": 0, "current_item": "", "processed": 0, "total": 0, "error_message": ""
+            "progress": 0, "current_item": "", "processed": 0, "total": 0, "error_message": "",
+            # Seed the heartbeat now so a worker that hangs during init (before the
+            # first progress/phase callback) is still caught by the stall watchdog.
+            "last_progress_at": time.time(),
         })
 
         # Add activity for database update start
@@ -16737,6 +16785,7 @@ def start_database_update():
 @app.route('/api/database/update/status', methods=['GET'])
 def get_database_update_status():
     """Endpoint to poll for the current update status."""
+    _check_db_update_stall()  # self-heal a hung job before reporting (#859)
     with db_update_lock:
         # Debug: Log current state occasionally
         if db_update_state["status"] == "running":
@@ -37158,6 +37207,7 @@ def _emit_tool_progress_loop():
             logger.debug(f"Error emitting duplicate cleaner status: {e}")
         # DB Update
         try:
+            _check_db_update_stall()  # self-heal a hung job, then broadcast (#859)
             with db_update_lock:
                 socketio.emit('tool:db-update', dict(db_update_state))
         except Exception as e:

webui/static/sync-services.js

@@ -4063,7 +4063,11 @@ async function handleDbUpdateButtonClick() {
         }
 
         try {
-            button.disabled = true;
+            // Leave the button ENABLED while "Starting..." so it doubles as a
+            // cancel affordance — a wedged start (#859) must stay clickable. A
+            // second click reads "Starting..." and falls through to the stop
+            // branch below, so there's no double-start risk.
+            button.disabled = false;
             button.textContent = 'Starting...';
             const response = await fetch('/api/database/update', {
                 method: 'POST',
@@ -4072,14 +4076,19 @@ async function handleDbUpdateButtonClick() {
                 // scan takes precedence server-side, so send only its flag.
                 body: JSON.stringify(isDeepScan ? { deep_scan: true } : { full_refresh: isFullRefresh })
             });
+            const data = await response.json().catch(() => ({}));
 
-            if (response.ok) {
+            // Check BOTH the HTTP status and the body's success flag — a 200 with
+            // success:false must not be mistaken for a started job (#859).
+            if (response.ok && data.success !== false) {
                 showToast('Database update started!', 'success');
                 // Start polling immediately to get live status
                 checkAndUpdateDbProgress();
+                // Socket-independent safety net: recovers the card from
+                // "Starting..." even if the WebSocket goes quiet/half-open (#859).
+                armDbUpdateSafetyPoll();
             } else {
-                const errorData = await response.json();
+                showToast(`Error: ${data.error || 'Failed to start update.'}`, 'error');
-                showToast(`Error: ${errorData.error}`, 'error');
                 button.disabled = false;
                 button.textContent = 'Update Database';
             }

webui/static/wishlist-tools.js

@@ -8280,6 +8280,30 @@ function updateDbProgressFromData(data) {
     updateDbProgressUI(data);
 }
 
+// Socket-independent safety net for the DB-updater card. The 1s WebSocket
+// broadcast normally drives the card, but if the socket goes quiet/half-open the
+// card can wedge on "Starting..." with a frozen bar and no recovery (#859). This
+// polls /status directly, applies the same idempotent UI update, and stops itself
+// once the job is no longer running.
+let _dbUpdateSafetyPoll = null;
+function armDbUpdateSafetyPoll() {
+    if (_dbUpdateSafetyPoll) { clearInterval(_dbUpdateSafetyPoll); _dbUpdateSafetyPoll = null; }
+    const tick = async () => {
+        try {
+            const r = await fetch('/api/database/update/status');
+            if (!r.ok) return;
+            const state = await r.json();
+            updateDbProgressUI(state);
+            if (state.status !== 'running') {
+                clearInterval(_dbUpdateSafetyPoll);
+                _dbUpdateSafetyPoll = null;
+            }
+        } catch (e) { /* transient — keep the safety net armed */ }
+    };
+    tick();  // immediate: flip off "Starting..." as soon as the server confirms state
+    _dbUpdateSafetyPoll = setInterval(tick, 5000);
+}
+
 function updateDbProgressUI(state) {
     const button = document.getElementById('db-update-button');
     const phaseLabel = document.getElementById('db-phase-label');
@@ -8311,6 +8335,17 @@ function updateDbProgressUI(state) {
             progressBar.style.backgroundColor = 'rgb(var(--accent-rgb))'; // Green for normal
         }
 
+        // Reset the bar/label so a finished/idle/error card doesn't keep showing a
+        // frozen partial bar from the previous run (e.g. "2/3 artists 66.7%" left
+        // over after completion) — the #859 confusion. Finished → full bar; any
+        // other terminal state → cleared bar. The phase label carries the summary.
+        if (state.status === 'finished') {
+            progressBar.style.width = '100%';
+        } else {
+            progressBar.style.width = '0%';
+        }
+        progressLabel.textContent = '';
+
         if (state.status === 'finished' || state.status === 'error') {
             // Final stats refresh after completion/error
             setTimeout(fetchAndUpdateDbStats, 500);