diff --git a/backend/services/encoding_errors.py b/backend/services/encoding_errors.py index 3589778f6..59690c772 100644 --- a/backend/services/encoding_errors.py +++ b/backend/services/encoding_errors.py @@ -15,6 +15,44 @@ }) +# Sentinel code stamped on an EncodingWorkerInfraError so log filters and the +# park/retry path can tell a runtime worker-infra failure apart from a real +# GCE VM-start failure. +WORKER_INFRA_FAILURE_CODE = "worker_infra_failure" + + +# Substrings (matched case-insensitively) that identify a worker-side *infrastructure* +# failure — the VM booted and accepted the job but then could not talk to GCP to do +# real work. The canonical case (job 6452888e, 2026-08-31) was a fallback VM that +# could not reach the metadata server to fetch its default service-account token: +# "Failed to retrieve https://metadata.google.internal/.../service-accounts/default/ +# ... Compute Engine Metadata server unavailable ... SSLCertVerificationError ..." +# These are properties of the *VM*, not the encode job — the same work will succeed on +# a healthy worker, so they must be retried/re-dispatched rather than failing the job. +# Kept deliberately specific so a genuine encode error (bad codec, corrupt input) never +# matches. Compared lowercase. +WORKER_INFRA_ERROR_MARKERS: FrozenSet[str] = frozenset({ + "metadata.google.internal", + "metadata server unavailable", + "compute engine metadata", + "service-accounts/default", + "sslcertverificationerror", + "certificate_verify_failed", + "could not automatically determine credentials", + "defaultcredentialserror", +}) + + +def is_worker_infra_error(message: str) -> bool: + """True if a worker-reported error string looks like a VM-level infra/auth + failure (metadata server unreachable, SSL/cert, missing credentials) rather + than a genuine problem with the encode job itself.""" + if not message: + return False + lowered = message.lower() + return any(marker in lowered for marker in WORKER_INFRA_ERROR_MARKERS) + + class EncodingWorkerStartError(Exception): """Raised when an attempt to start an encoding worker VM fails. @@ -44,6 +82,20 @@ class EncodingWorkerCapacityError(EncodingWorkerStartError): """ +class EncodingWorkerInfraError(EncodingWorkerStartError): + """A worker VM accepted the job but then hit a VM-level infrastructure/auth + failure mid-run (e.g. it could not reach the GCE metadata server to fetch its + service-account token — job 6452888e, 2026-08-31). + + Subclasses ``EncodingWorkerStartError`` on purpose: the failure is a property + of the *worker*, not the encode job, so it should flow through the same + recoverable path as a VM-start failure (the render worker parks the job for + auto-retry; the final-encode Cloud Run Job retries). Before raising this, + callers demote the offending VM so the retry lands on a healthy worker rather + than looping on the broken one. + """ + + # Marker the encoding worker writes into a job's status when it was interrupted # by a worker-process restart (OOM, deploy, crash). Kept in sync with # gce_encoding/persistence.py `_RESTART_FAIL_CODE`. diff --git a/backend/services/encoding_service.py b/backend/services/encoding_service.py index ae6f59356..57d27f837 100644 --- a/backend/services/encoding_service.py +++ b/backend/services/encoding_service.py @@ -28,10 +28,13 @@ from backend.config import get_settings from backend.services.encoding_errors import ( ENCODING_RESTART_FAILURE_CODE, + WORKER_INFRA_FAILURE_CODE, EncodingJobLostError, EncodingJobNotFoundError, EncodingWorkerCapacityError, + EncodingWorkerInfraError, EncodingWorkerStartError, + is_worker_infra_error, ) logger = logging.getLogger(__name__) @@ -854,6 +857,42 @@ async def wait_for_completion( f"Encoding job {job_id} was lost by the worker (restarted mid-run)", job_id=job_id, ) + # A VM-level infra/auth failure (metadata server unreachable, SSL/cert, + # missing credentials) is a property of the *worker*, not this job — the + # same work succeeds on a healthy VM. Demote the broken worker and raise + # a recoverable signal so the render worker parks for auto-retry (and the + # final-encode Cloud Run Job retries) instead of failing the customer's + # job outright. See job 6452888e (2026-08-31). worker_url is the VM the + # job ran on; zone comes from active_override for logging. + if is_worker_infra_error(str(error)): + logger.warning( + f"[job:{job_id}] Worker reported an infrastructure/auth failure " + f"(not a job problem) — demoting the worker and retrying: {error}" + ) + failed_vm = "" + if self._worker_manager: + # Capture the offending VM before demoting (which clears the + # active_override), then demote and force URL re-resolution so + # the retry lands on a different worker. + try: + failed_vm = self._worker_manager.get_config().active_override_vm or "" + except Exception: # noqa: BLE001 — vm name is only for logging + failed_vm = "" + try: + self._worker_manager.demote_active_worker( + reason=f"job {job_id}: {error}" + ) + except Exception as demote_err: # noqa: BLE001 + logger.warning( + f"[job:{job_id}] Could not demote worker after infra " + f"failure (continuing to retry anyway): {demote_err}" + ) + self._invalidate_cached_url() + raise EncodingWorkerInfraError( + f"Encoding worker infrastructure failure for job {job_id}: {error}", + vm_name=failed_vm, + code=WORKER_INFRA_FAILURE_CODE, + ) raise RuntimeError(f"Encoding job {job_id} failed: {error}") await asyncio.sleep(poll_interval) diff --git a/backend/services/encoding_worker_manager.py b/backend/services/encoding_worker_manager.py index dfe96bce1..e8493ce3d 100644 --- a/backend/services/encoding_worker_manager.py +++ b/backend/services/encoding_worker_manager.py @@ -586,6 +586,55 @@ def _clear_active_override(self) -> None: }) logger.info("Cleared active_override (primary is healthy again)") + def demote_active_worker(self, reason: str = "") -> None: + """Demote the currently-serving fallback worker after a runtime infra failure. + + Called when a worker VM accepted a job but then failed with a VM-level + infrastructure/auth error (e.g. it could not reach the metadata server — + job 6452888e). We only act when a *fallback* VM is serving (active_override + set): record a capacity-state cooldown for that VM's (machine_type, zone) so + ``ordered_candidates`` deprioritises its family for the cooldown window, then + clear the override so the retry re-resolves selection from the primary. When + the primary pair is serving we deliberately do nothing here — a metadata blip + on the stable c4d pair is vanishingly rare and family-demoting it would push + all traffic onto slow fallbacks; a bounded retry on the primary is safer. + + Best-effort: never raises. Selection/telemetry hint only. + """ + from backend.services.encoding_worker_preference import cooldown_key + + try: + config = self.get_config() + except Exception as e: # noqa: BLE001 — must never break the failure path + logger.warning("demote_active_worker: could not read config (%s): %s", reason, e) + return + + vm = config.active_override_vm + zone = config.active_override_zone + if not vm: + # Primary pair was serving — see docstring; leave selection untouched. + logger.warning( + "Active encoding worker hit an infra failure while the primary was " + "serving; leaving selection unchanged for bounded retry: %s", reason, + ) + return + + key = cooldown_key({"vm_name": vm, "zone": zone}) + if key: + try: + self._doc_ref().set( + {"capacity_state": {key: datetime.now(UTC).isoformat()}}, merge=True + ) + logger.warning( + "Demoted fallback encoding worker %s (%s) after infra failure: %s", + vm, key, reason, + ) + except Exception as e: # noqa: BLE001 + logger.warning( + "demote_active_worker: could not record cooldown for %s: %s", key, e + ) + self._clear_active_override() + # ------------------------------------------------------------------ # Compute operation helpers # ------------------------------------------------------------------ diff --git a/backend/services/match_judge/service.py b/backend/services/match_judge/service.py index 91b60d865..d32ec0f19 100644 --- a/backend/services/match_judge/service.py +++ b/backend/services/match_judge/service.py @@ -106,8 +106,13 @@ async def judge_match( try: ai_verdict = await ai(artist, title, candidates, audio_tier) except Exception: - logger.exception( - "match-judge AI verification failed; keeping catalog verdict" + # Graceful degradation: a transient Vertex/Gemini blip just means we + # keep the catalog verdict. Log at WARNING (with traceback) so it does + # not page as a red "new error pattern" — it self-heals and needs no + # action. Downgraded 2026-08-31 after a single benign occurrence alerted. + logger.warning( + "match-judge AI verification failed; keeping catalog verdict", + exc_info=True, ) return catalog_verdict if ai_verdict.confident and ai_verdict.kind != KIND_NONE: @@ -122,7 +127,12 @@ async def judge_match( try: return await ai(artist, title, candidates, audio_tier) except Exception: - logger.exception("match-judge AI call failed; returning no-suggestion") + # Graceful degradation: returning no-suggestion is a safe fallback (the + # user just gets no auto-match). Log at WARNING (with traceback) so a + # transient AI blip does not page as a red "new error pattern". + logger.warning( + "match-judge AI call failed; returning no-suggestion", exc_info=True + ) return MatchVerdict( KIND_NONE, True, artist, title, engine="ai", reason="ai failed" ) diff --git a/backend/tests/test_encoding_errors.py b/backend/tests/test_encoding_errors.py new file mode 100644 index 000000000..f7e9aab17 --- /dev/null +++ b/backend/tests/test_encoding_errors.py @@ -0,0 +1,61 @@ +"""Tests for encoding worker error classification helpers.""" + +from backend.services.encoding_errors import ( + EncodingWorkerInfraError, + EncodingWorkerStartError, + is_worker_infra_error, +) + + +# The verbatim worker-reported error from the prod incident (job 6452888e). +_METADATA_FAILURE = ( + "Failed to retrieve https://metadata.google.internal/computeMetadata/v1/instance/" + "service-accounts/default/?recursive=true from the Google Compute Engine metadata " + "service. Compute Engine Metadata server unavailable. Last exception: " + "HTTPSConnectionPool(host='metadata.google.internal', port=443): Max retries " + "exceeded with url: /computeMetadata/v1/instance/service-accounts/default/" + "?recursive=true (Caused by SSLError(SSLCertVerificationError(1, '[SSL: " + "CERTIFICATE_VERIFY_FAILED] certificate verify failed: unable to get local issuer " + "certificate (_ssl.c:1018)')))" +) + + +class TestIsWorkerInfraError: + def test_metadata_failure_is_infra(self): + assert is_worker_infra_error(_METADATA_FAILURE) is True + + def test_matches_are_case_insensitive(self): + assert is_worker_infra_error(_METADATA_FAILURE.upper()) is True + + def test_individual_markers(self): + for msg in ( + "Compute Engine Metadata server unavailable", + "SSLCertVerificationError: certificate_verify_failed", + "google.auth.exceptions.DefaultCredentialsError: could not automatically " + "determine credentials", + "GET /computeMetadata/v1/instance/service-accounts/default/ failed", + ): + assert is_worker_infra_error(msg) is True, msg + + def test_genuine_encode_error_is_not_infra(self): + # Real ffmpeg / input problems must stay terminal, never masquerade as infra. + for msg in ( + "ffmpeg exploded", + "Invalid data found when processing input", + "Unknown encoder 'libx265'", + "Output file is empty, nothing was encoded", + "", + ): + assert is_worker_infra_error(msg) is False, msg + + def test_none_is_not_infra(self): + assert is_worker_infra_error(None) is False # type: ignore[arg-type] + + +class TestEncodingWorkerInfraError: + def test_is_recoverable_start_error_subclass(self): + """Subclassing EncodingWorkerStartError is what routes it through the render + worker's park-for-auto-retry path (and the final-encode Cloud Run Job retry).""" + err = EncodingWorkerInfraError("boom", vm_name="encoding-worker-fallback-c4a") + assert isinstance(err, EncodingWorkerStartError) + assert err.vm_name == "encoding-worker-fallback-c4a" diff --git a/backend/tests/test_encoding_service.py b/backend/tests/test_encoding_service.py index 96474e5b0..bf37b0e01 100644 --- a/backend/tests/test_encoding_service.py +++ b/backend/tests/test_encoding_service.py @@ -746,6 +746,58 @@ async def mock_get_status(job_id, worker_url=None): except RuntimeError: pass + @pytest.mark.asyncio + async def test_worker_infra_failure_raises_infra_error_and_demotes(self, encoding_service): + """A metadata/auth failure reported by the worker is a VM problem, not a job + problem (job 6452888e): raise the recoverable EncodingWorkerInfraError, demote + the broken worker and invalidate the URL cache so the retry lands elsewhere.""" + from backend.services.encoding_errors import EncodingWorkerInfraError + + metadata_error = ( + "Failed to retrieve https://metadata.google.internal/computeMetadata/v1/" + "instance/service-accounts/default/?recursive=true from the Google Compute " + "Engine metadata service. Compute Engine Metadata server unavailable. Last " + "exception: SSLError(SSLCertVerificationError(1, '[SSL: CERTIFICATE_VERIFY_" + "FAILED] certificate verify failed: unable to get local issuer certificate'))" + ) + + async def mock_get_status(job_id, worker_url=None): + return {"status": "failed", "error": metadata_error} + + mock_manager = MagicMock() + mock_manager.get_config.return_value.active_override_vm = "encoding-worker-fallback-c4a" + encoding_service._worker_manager = mock_manager + + with patch.object(encoding_service, "get_job_status", side_effect=mock_get_status), \ + patch.object(encoding_service, "_invalidate_cached_url") as mock_invalidate, \ + patch("asyncio.sleep", new_callable=AsyncMock), \ + patch("asyncio.get_event_loop") as mock_loop: + mock_loop.return_value.time.return_value = 0 + with pytest.raises(EncodingWorkerInfraError) as exc_info: + await encoding_service.wait_for_completion("j1") + + # Captured the offending VM, demoted it, and forced URL re-resolution. + assert exc_info.value.vm_name == "encoding-worker-fallback-c4a" + mock_manager.demote_active_worker.assert_called_once() + mock_invalidate.assert_called_once() + + @pytest.mark.asyncio + async def test_worker_infra_failure_without_manager_still_recoverable(self, encoding_service): + """Even with no worker manager wired (static-URL fallback), an infra failure is + classified as recoverable (EncodingWorkerInfraError), never a terminal error.""" + from backend.services.encoding_errors import EncodingWorkerInfraError + + async def mock_get_status(job_id, worker_url=None): + return {"status": "failed", "error": "Compute Engine Metadata server unavailable"} + + encoding_service._worker_manager = None + with patch.object(encoding_service, "get_job_status", side_effect=mock_get_status), \ + patch("asyncio.sleep", new_callable=AsyncMock), \ + patch("asyncio.get_event_loop") as mock_loop: + mock_loop.return_value.time.return_value = 0 + with pytest.raises(EncodingWorkerInfraError): + await encoding_service.wait_for_completion("j1") + @pytest.mark.asyncio async def test_pending_does_not_count_toward_run_timeout(self, encoding_service): """Time spent queued (pending) is bounded by queue_timeout, not the per-run diff --git a/backend/tests/test_encoding_worker_manager.py b/backend/tests/test_encoding_worker_manager.py index e1c6caf25..877c09c65 100644 --- a/backend/tests/test_encoding_worker_manager.py +++ b/backend/tests/test_encoding_worker_manager.py @@ -1072,3 +1072,67 @@ def test_legacy_candidates_without_flag_use_position(self, manager, mock_db, moc assert result["fell_back"] is False assert result["vm_name"] == "encoding-worker-blue" + + +# --------------------------------------------------------------------------- +# demote_active_worker: skip a broken fallback VM after a runtime infra failure +# --------------------------------------------------------------------------- + +class TestDemoteActiveWorker: + """A worker VM that accepted a job but then hit a VM-level infra/auth failure + (e.g. could not reach the metadata server — job 6452888e) must be demoted so + the retry lands on a healthy worker.""" + + def test_demotes_fallback_and_clears_override(self, manager): + """When a fallback is serving, record its family cooldown then clear the + override so selection re-resolves from the primary.""" + doc_ref = manager._doc_ref() + doc_ref.get.return_value.exists = True + doc_ref.get.return_value.to_dict.return_value = _make_firestore_data( + active_override_vm="encoding-worker-fallback-c4a", + active_override_ip="10.128.0.99", + active_override_zone="us-central1-c", + active_override_set_at="2026-08-31T12:00:00Z", + ) + + manager.demote_active_worker(reason="job 6452888e: metadata server unavailable") + + # Recorded a cooldown for the fallback's (machine_type@zone). + assert doc_ref.set.called + set_args, set_kwargs = doc_ref.set.call_args + assert "capacity_state" in set_args[0] + assert "c4-highcpu-32@us-central1-c" in set_args[0]["capacity_state"] + assert set_kwargs.get("merge") is True + + # Cleared the active_override so the retry starts from the primary. + override_clears = [ + c for c in doc_ref.update.call_args_list + if c.args and "active_override_vm" in c.args[0] + ] + assert override_clears, "expected active_override to be cleared" + assert override_clears[-1].args[0]["active_override_vm"] is None + + def test_no_op_when_primary_is_serving(self, manager): + """When no fallback override is set (primary pair serving), demote is a no-op: + we don't family-demote the fast c4d primary on a rare blip.""" + doc_ref = manager._doc_ref() + doc_ref.get.return_value.exists = True + doc_ref.get.return_value.to_dict.return_value = _make_firestore_data() # no override + + manager.demote_active_worker(reason="job zzz: metadata server unavailable") + + assert not doc_ref.set.called + override_clears = [ + c for c in doc_ref.update.call_args_list + if c.args and "active_override_vm" in c.args[0] + ] + assert not override_clears + + def test_never_raises_on_config_read_failure(self, manager): + """Demotion is best-effort telemetry — a Firestore hiccup must not break the + failure path it runs on.""" + doc_ref = manager._doc_ref() + doc_ref.get.side_effect = RuntimeError("firestore unavailable") + + # Should swallow the error rather than propagate. + manager.demote_active_worker(reason="job qqq") diff --git a/backend/tests/test_render_video_worker_capacity.py b/backend/tests/test_render_video_worker_capacity.py index 1f3622eb3..cc4678fc5 100644 --- a/backend/tests/test_render_video_worker_capacity.py +++ b/backend/tests/test_render_video_worker_capacity.py @@ -237,3 +237,52 @@ async def test_generic_start_error_also_parks_for_retry(): c.kwargs.get("new_status") == JobStatus.RENDER_PENDING_CAPACITY for c in transitions ), "Worker must park on generic start error, not fail hard" + + +@pytest.mark.asyncio +async def test_worker_infra_error_parks_for_retry(): + """A worker-side infra/auth failure (metadata server unreachable — job 6452888e) + must park for auto-retry, not fail the customer's job. + + EncodingWorkerInfraError subclasses EncodingWorkerStartError precisely so it + flows through the same park path; before this fix the failure arrived as a bare + RuntimeError and hit fail_job, losing the job after the encoding VM demotion. + """ + from backend.workers import render_video_worker as rvw + from backend.services.encoding_errors import ( + EncodingWorkerInfraError, + WORKER_INFRA_FAILURE_CODE, + ) + + infra_error = EncodingWorkerInfraError( + "Encoding worker infrastructure failure for job test-job-id: " + "Compute Engine Metadata server unavailable ... SSLCertVerificationError", + vm_name="encoding-worker-fallback-c4a", + code=WORKER_INFRA_FAILURE_CODE, + ) + + mock_job_manager = MagicMock() + mock_job_manager.get_job.return_value = _build_minimal_job() + mock_job_manager.transition_to_state.return_value = True + + mock_encoding_service = MagicMock() + mock_encoding_service.is_enabled = True + mock_encoding_service.render_video_on_gce = AsyncMock(side_effect=infra_error) + + with patch.object(rvw, "JobManager", return_value=mock_job_manager), \ + patch.object(rvw, "StorageService"), \ + patch.object(rvw, "get_settings"), \ + patch.object(rvw, "create_job_logger", return_value=MagicMock()), \ + patch.object(rvw, "setup_job_logging", return_value=MagicMock()), \ + patch.object(rvw, "validate_worker_can_run", return_value=None), \ + patch.object(rvw, "get_encoding_service", return_value=mock_encoding_service): + + result = await rvw.process_render_video("test-job-id") + + assert result is False + mock_job_manager.fail_job.assert_not_called() + transitions = mock_job_manager.transition_to_state.call_args_list + assert any( + c.kwargs.get("new_status") == JobStatus.RENDER_PENDING_CAPACITY + for c in transitions + ), "Worker must park on worker infra failure, not fail hard" diff --git a/docs/TROUBLESHOOTING.md b/docs/TROUBLESHOOTING.md index f653e8c10..c51fed7f5 100644 --- a/docs/TROUBLESHOOTING.md +++ b/docs/TROUBLESHOOTING.md @@ -79,6 +79,8 @@ Since v0.184.2, in-flight status polls are also **pinned to the worker that acce Since **v0.194.0**, a mid-run job loss is also **auto-recovered**: the encoding worker processes heavy renders/encodes **one at a time** (`heavy_executor`, `ENCODING_HEAVY_CONCURRENCY=1`) so it can no longer OOM from concurrent 4K encodes (the trigger for the 2026-08-15 Arctic Monkeys batch failure — 3 concurrent encodes OOM-killed the 32 GB fallback worker and restarted it, wiping its in-memory jobs). If the worker *does* restart mid-render (deploy/crash), `wait_for_completion` now raises `EncodingJobLostError` and the render/encode worker **resubmits the job under a fresh `_retry_`** (bounded by `ENCODING_RESUBMIT_MAX=2`) instead of failing. To confirm serialization is live on a worker: `curl -s localhost:8080/health` shows `queue_length` growing while `active_jobs` stays 1 under load. **Note:** `main.py` ships in the wheel but the running uvicorn process only picks up worker-side changes (executor split, `queue_position`) on a **fresh boot / service restart** — `ensure_latest_wheel` alone does not reload the app process. +Since **v0.217.0**, a **worker-side infrastructure/auth failure** is also auto-recovered rather than failing the customer's job. When a fallback VM boots and accepts a job but then can't do real work — e.g. it can't reach the GCE metadata server to fetch its service-account token (`Failed to retrieve https://metadata.google.internal/.../service-accounts/default/ … Compute Engine Metadata server unavailable … SSLCertVerificationError`, job `6452888e`, 2026-08-31) — `wait_for_completion` now classifies it via `is_worker_infra_error()` and raises `EncodingWorkerInfraError` (a subclass of `EncodingWorkerStartError`) instead of a bare `RuntimeError`. Before raising, it **demotes the broken worker** (`EncodingWorkerManager.demote_active_worker()` records a capacity-state cooldown for that fallback's `machine_type@zone` and clears `active_override`) and invalidates the URL cache, so the retry **prefers a different worker** (the cooldown deprioritises that family in `ordered_candidates`). It is a preference, not a hard exclusion — if no better candidate can start, the same fallback family can still be selected; the bounded retry then handles a repeat, and a VM that fails repeatedly should be rebooted/re-imaged. The render worker then **parks the job for auto-retry** (its existing `except EncodingWorkerStartError` path) and the final-encode Cloud Run Job retries — no manual intervention. This is deliberately scoped to *fallback* VMs: a metadata blip on the stable c4d primary pair is vanishingly rare, and family-demoting the fast primary would push all traffic onto slow fallbacks, so the primary case is left to a bounded retry. If a job is stuck after this, grep logs for `Demoted fallback encoding worker` to see which VM was skipped; the VM itself may need a reboot/re-image if the failure recurs on it specifically. + Since **v0.194.2**, the CI deploy handles that restart automatically even during a c4d Spot stockout. The old blue-green only targeted the c4d primary/secondary; when both were down it rolled back and **never refreshed the serving n2 fallback** (recorded as `active_override_vm`), so worker-side changes didn't reach prod until a manual restart (`primary_version` in the config doc went stale). The deploy is now **capacity-aware** (`infrastructure/encoding-worker/deploy_promote.py`): it validates the new wheel on a *fresh* green worker selected from the **ranked 6-family pool** (`select_green_candidates` → the shared `encoding_worker_preference.ordered_candidates` — fastest-first with capacity cooldown; the c4d secondary if it can start, else the fastest available fallback family, never the current override so it keeps serving) — then **promotes** the green (primary/secondary swap for a c4d green, or sets `active_override` for a fallback green) and drains+stops the retired worker. A c4d green also **clears a stale override** so traffic returns to the fresh primary. Zero-downtime, and it works while c4d is exhausted. Last resort if no separate green can start: an in-place restart of the serving override (brief blip, covered by auto-resubmit). --- diff --git a/frontend/e2e/production/happy-path-real-user.spec.ts b/frontend/e2e/production/happy-path-real-user.spec.ts index 07936a7a5..559244d54 100644 --- a/frontend/e2e/production/happy-path-real-user.spec.ts +++ b/frontend/e2e/production/happy-path-real-user.spec.ts @@ -708,14 +708,22 @@ test.describe('E2E Happy Path - Real User with Full UI Interactions', () => { console.log(' WARNING: Loading indicator timeout - checking for video anyway'); } - // Now check for the video element or an error message + // Now check for the video element or an error message. Scope the alert + // lookup to the modal — a page-level `[role="alert"]` notifications region + // is always present and empty, which previously logged a spurious + // "Preview error:" with no text (run #151). const videoElement = reviewPage.locator('video'); - const errorAlert = reviewPage.locator('[role="alert"]'); - - // Check if there's an error - if (await errorAlert.isVisible({ timeout: 5000 }).catch(() => false)) { - const errorText = await errorAlert.textContent(); - console.log(` WARNING: Preview error: ${errorText}`); + const errorAlert = previewModal.locator('[role="alert"]'); + + // Check if there's a *real* error (non-empty alert text inside the modal). + // Gate on isVisible() (immediate — it does not auto-wait) so the happy path + // with no alert doesn't block on textContent()'s default 30s wait-for-element. + let alertText = ''; + if (await errorAlert.first().isVisible().catch(() => false)) { + alertText = ((await errorAlert.first().textContent().catch(() => '')) || '').trim(); + } + if (alertText) { + console.log(` WARNING: Preview error: ${alertText}`); // Continue anyway - we can still proceed to instrumental even if preview failed } else if (await videoElement.isVisible({ timeout: 10000 }).catch(() => false)) { console.log(' Video element visible in modal'); @@ -727,11 +735,34 @@ test.describe('E2E Happy Path - Real User with Full UI Interactions', () => { await reviewPage.screenshot({ path: 'test-results/07d-preview-ready.png', fullPage: true }); - // Click "Proceed to Instrumental Review" button in the modal - // This button saves corrections and navigates to the instrumental selection UI - const proceedBtn = reviewPage.getByRole('button', { name: /proceed to instrumental/i }); - await expect(proceedBtn).toBeVisible({ timeout: TIMEOUTS.action }); - console.log(' Found "Proceed to Instrumental Review" button'); + // Locate the "Proceed to Instrumental Review" button (saves corrections and + // navigates to instrumental selection). A transient encoder cold-start can + // leave the preview modal in an error/closed state (the encoder was offline + // during run #151) — but proceeding to instrumental does NOT depend on the + // preview succeeding. Recover once by reloading the review page and re-opening + // the preview modal rather than failing the whole smoke test on flaky infra. + // The final assertion below stays authoritative: if the button never appears + // even after recovery, generation really is broken and the test fails. + // Require the button to be present AND enabled: ReviewChangesModal keeps it + // visible but disabled when there are no lyrics, so a visibility-only check + // could accept an unusable button (and the later click would just time out). + const proceedName = /proceed to instrumental/i; + let proceedBtn = reviewPage.getByRole('button', { name: proceedName }); + if (!(await proceedBtn.isEnabled({ timeout: TIMEOUTS.action }).catch(() => false))) { + console.log(' WARNING: Proceed button not ready (missing/disabled) after preview — recovering (reload review + reopen preview)...'); + await gotoWithRetry(reviewPage, reviewUrl); + await reviewPage.waitForTimeout(3000); + await reviewPage.evaluate(() => window.scrollTo(0, document.body.scrollHeight)); + const reopenBtn = reviewPage.getByRole('button', { name: /preview video/i }); + if (await reopenBtn.isVisible({ timeout: TIMEOUTS.action }).catch(() => false)) { + await reopenBtn.click(); + await expect(reviewPage.getByRole('dialog')).toBeVisible({ timeout: TIMEOUTS.action }); + console.log(' Re-opened preview modal after recovery'); + } + proceedBtn = reviewPage.getByRole('button', { name: proceedName }); + } + await expect(proceedBtn).toBeEnabled({ timeout: TIMEOUTS.action }); + console.log(' Found enabled "Proceed to Instrumental Review" button'); await proceedBtn.click(); console.log(' Clicked "Proceed to Instrumental Review" button'); diff --git a/pyproject.toml b/pyproject.toml index 55e3ba915..7de364788 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -1,6 +1,6 @@ [tool.poetry] name = "karaoke-gen" -version = "0.216.0" +version = "0.217.0" description = "Generate karaoke videos with synchronized lyrics. Handles the entire process from downloading audio and lyrics to creating the final video with title screens." authors = ["Andrew Beveridge "] license = "MIT"