diff --git a/superset/config.py b/superset/config.py index 119c3b4c413c..4eb87cea2e4c 100644 --- a/superset/config.py +++ b/superset/config.py @@ -1278,8 +1278,7 @@ def sync_theme_logo_href( # Time before selenium times out after trying to locate an element on the page and wait # for that element to load for a screenshot. SCREENSHOT_LOCATE_WAIT = int(timedelta(seconds=10).total_seconds()) -# Time before selenium times out after waiting for all DOM class elements named -# "loading" are gone. +# Time before screenshot capture times out while waiting for chart readiness. SCREENSHOT_LOAD_WAIT = int(timedelta(minutes=1).total_seconds()) # Maximum time (in seconds) selenium waits for an initial page navigation # (driver.get) to complete. Without it the navigation blocks indefinitely when diff --git a/superset/utils/screenshot_utils.py b/superset/utils/screenshot_utils.py index c1b2164b6a05..868b8e731d55 100644 --- a/superset/utils/screenshot_utils.py +++ b/superset/utils/screenshot_utils.py @@ -22,6 +22,7 @@ import time from typing import TYPE_CHECKING +from celery import current_task from PIL import Image logger = logging.getLogger(__name__) @@ -29,6 +30,63 @@ # Time to wait after scrolling for content to settle and load (in milliseconds) SCROLL_SETTLE_TIMEOUT_MS = 1000 +# Runtime task-budget policy shared with the approach introduced in #42118. +# Celery exposes the effective per-task hard/soft limits only on the running +# task, so a static Superset timeout cannot reliably stay below task-level +# overrides. Reserve at most 20% (capped at five minutes) for browser cleanup, +# cache error transition, and the remaining report pipeline. +SCREENSHOT_TASK_BUDGET_MARGIN_FRACTION = 0.2 +SCREENSHOT_TASK_BUDGET_MAX_MARGIN_SECONDS = 300 + + +def resolve_screenshot_task_budget_seconds( + log_context: str | None = None, +) -> float | None: + """ + Return the safe screenshot budget derived from the active Celery task. + + Celery exposes ``request.timelimit`` as ``(hard, soft)``. Prefer the soft + limit because cleanup must finish before Celery raises it, falling back to + the hard limit when no soft limit is configured. Outside Celery, or when + the metadata is absent or malformed, return ``None`` so callers preserve + their configured standalone timeout. + """ + context_suffix = f" [{log_context}]" if log_context else "" + try: + if not current_task: + return None + timelimit = current_task.request.timelimit + if not isinstance(timelimit, (tuple, list)) or len(timelimit) != 2: + return None + hard_limit, soft_limit = timelimit + limit = soft_limit or hard_limit + if isinstance(limit, bool) or not isinstance(limit, (int, float)) or limit <= 0: + return None + margin = min( + SCREENSHOT_TASK_BUDGET_MAX_MARGIN_SECONDS, + limit * SCREENSHOT_TASK_BUDGET_MARGIN_FRACTION, + ) + budget = max(0.0, float(limit) - margin) + logger.debug( + "Screenshot budget derived from Celery task %s=%.1fs: %.1fs " + "(cleanup margin=%.1fs)%s", + "soft_time_limit" if soft_limit else "time_limit", + limit, + budget, + margin, + context_suffix, + ) + return budget + except Exception: + logger.debug( + "Failed to derive screenshot budget from Celery task context; " + "using the configured screenshot timeout%s", + context_suffix, + exc_info=True, + ) + return None + + try: from playwright.sync_api import TimeoutError as PlaywrightTimeout except ImportError: @@ -40,79 +98,113 @@ except ImportError: Page = None -# Selectors used to build a positive per-tile readiness check. A chart holder -# is only "ready" once it shows a terminal state (a rendered chart or an -# error/empty state) -- the mere absence of a `.loading` element is not -# sufficient, since a chart holder that intersects the viewport but hasn't -# mounted anything yet (e.g. its IntersectionObserver callback hasn't fired) -# would otherwise pass vacuously. -# See superset-frontend/src/dashboard/components/gridComponents/ChartHolder/ -# ChartHolder.tsx for `data-test="dashboard-component-chart-holder"`, -# superset-frontend/src/components/Chart/Chart.tsx for `.slice_container` -# (rendered chart container, `data-test="slice-container"`) and `.loading` -# (spinner, via the shared Loading component), and -# superset-frontend/packages/superset-ui-core/src/components/EmptyState for -# `.ant-empty` (e.g. "no results"/"add required control values" states). -# -# For diagnostics, each unready holder is additionally classified by *why* -# it isn't ready, distinguishing a slow query from the virtualization race: -# - "waiting_on_database": `.loading` present with no `.slice_container` -# -- Chart.tsx's `renderSpinner()` replaces the whole container while -# the initial query is in flight (`chartStatus === 'loading'`). -# - "spinner_mounted": `.loading` present *inside* `.slice_container` -# -- the chart's query finished, but it isn't in the virtualization -# viewport yet, so `renderChartContainer()` shows a bare spinner instead -# of the chart. -# - "nothing_mounted": neither `.loading` nor any ready marker present -- -# the vacuous-pass race this check exists to close. -_UNREADY_CHART_HOLDERS_JS_BODY = """ - const holders = document.querySelectorAll( - '[data-test="dashboard-component-chart-holder"]' - ); +# Production dashboard builds run ``babel-plugin-jsx-remove-data-test-id`` +# under the production BABEL_ENV (including Docker builds), so readiness must +# never depend on ``data-test`` attributes. These runtime classes are the +# production contract shared by readiness polling and diagnostics. +CHART_HOLDER_SELECTOR = ( + r'.dashboard-component-chart-holder[class*="dashboard-chart-id-"]' +) +SLICE_CONTAINER_SELECTOR = r".slice_container" +LOADING_SELECTOR = r".loading" +ALERT_SELECTOR = r'[role="alert"]' +EMPTY_SELECTOR = r".ant-empty" +MISSING_CHART_SELECTOR = r".missing-chart-container" +TERMINAL_MARKER_SELECTOR = ( + f"{SLICE_CONTAINER_SELECTOR}, {ALERT_SELECTOR}, {EMPTY_SELECTOR}, " + f"{MISSING_CHART_SELECTOR}" +) +CHART_ID_CLASS_PATTERN = r"\bdashboard-chart-id-(\d+)\b" + +# Shared body for holder readiness and timeout diagnostics. A holder is ready +# only after a terminal marker appears and its loading marker disappears. +UNREADY_CHART_HOLDERS_JS_BODY = f""" + const holders = document.querySelectorAll('{CHART_HOLDER_SELECTOR}'); const unready = []; - for (const holder of holders) { + for (const holder of holders) {{ const r = holder.getBoundingClientRect(); - if (!(r.top < window.innerHeight && r.bottom > 0)) { + if (!(r.top < window.innerHeight && r.bottom > 0)) {{ continue; - } + }} const hasSliceContainer = holder.querySelector( - '[data-test="slice-container"]' + '{SLICE_CONTAINER_SELECTOR}' ) !== null; - const stillLoading = holder.querySelector('.loading') !== null; - const isReady = hasSliceContainer || holder.querySelector( - '[role="alert"], .ant-empty, .missing-chart-container' - ) !== null; - if (stillLoading || !isReady) { - const chartIdEl = holder.querySelector('[data-test-chart-id]'); + const stillLoading = holder.querySelector('{LOADING_SELECTOR}') !== null; + const isReady = holder.querySelector('{TERMINAL_MARKER_SELECTOR}') !== null; + if (stillLoading || !isReady) {{ + const chartIdMatch = holder.className.match(/{CHART_ID_CLASS_PATTERN}/); + const chartId = chartIdMatch ? chartIdMatch[1] : null; let state; - if (stillLoading && hasSliceContainer) { + if (stillLoading && hasSliceContainer) {{ state = 'spinner_mounted'; - } else if (stillLoading) { + }} else if (stillLoading) {{ state = 'waiting_on_database'; - } else { + }} else {{ state = 'nothing_mounted'; - } - unready.push({ - chartId: chartIdEl - ? chartIdEl.getAttribute('data-test-chart-id') - : 'unknown', + }} + unready.push({{ + chartId: chartId, state: state, - }); - } - } + }}); + }} + }} """ -# Predicate for page.wait_for_function: true once every viewport-visible chart -# holder has reached a terminal state. -_TILE_READY_CHECK_JS = ( - f"() => {{ {_UNREADY_CHART_HOLDERS_JS_BODY} return unready.length === 0; }}" -) +# Diagnostic query for every chart holder, including terminal and virtualized +# states. It interpolates the same selector constants as the predicates. +FIND_CHART_HOLDER_STATES_JS = f""" +() => {{ + const holders = document.querySelectorAll('{CHART_HOLDER_SELECTOR}'); + return Array.from(holders).map(holder => {{ + const chartIdMatch = holder.className.match(/{CHART_ID_CLASS_PATTERN}/); + const chartId = chartIdMatch ? chartIdMatch[1] : null; + const r = holder.getBoundingClientRect(); + if (!(r.top < window.innerHeight && r.bottom > 0)) {{ + return {{ chartId, state: 'virtualized' }}; + }} + const hasSliceContainer = holder.querySelector( + '{SLICE_CONTAINER_SELECTOR}' + ) !== null; + const stillLoading = holder.querySelector('{LOADING_SELECTOR}') !== null; + if (stillLoading && hasSliceContainer) {{ + return {{ chartId, state: 'spinner_mounted' }}; + }} + if (stillLoading) {{ + return {{ chartId, state: 'waiting_on_database' }}; + }} + if (holder.querySelector('{ALERT_SELECTOR}') !== null) {{ + return {{ chartId, state: 'error' }}; + }} + if (holder.querySelector( + '{EMPTY_SELECTOR}, {MISSING_CHART_SELECTOR}' + ) !== null) {{ + return {{ chartId, state: 'empty' }}; + }} + if (hasSliceContainer) {{ + return {{ chartId, state: 'rendered' }}; + }} + return {{ chartId, state: 'nothing_mounted' }}; + }}); +}} +""" -# Diagnostic query for page.evaluate: chart id + state of holders still not -# ready, used to build the timeout log message. -_FIND_UNREADY_CHART_HOLDERS_JS = ( - f"() => {{ {_UNREADY_CHART_HOLDERS_JS_BODY} return unready; }}" +CHART_HOLDERS_READY_JS = ( + f"() => {{ {UNREADY_CHART_HOLDERS_JS_BODY} return unready.length === 0; }}" ) +FIND_UNREADY_CHART_HOLDERS_JS = ( + f"() => {{ {UNREADY_CHART_HOLDERS_JS_BODY} return unready; }}" +) + +# A chart capture has one target rather than dashboard holders, but needs the +# same positive terminal-state guarantee and loading exclusion. +CHART_CONTAINER_READY_JS = f""" +() => {{ + const chart = document.querySelector('.chart-container'); + return chart !== null + && chart.querySelector('{LOADING_SELECTOR}') === null + && chart.querySelector('{TERMINAL_MARKER_SELECTOR}') !== null; +}} +""" def combine_screenshot_tiles(screenshot_tiles: list[bytes]) -> bytes: @@ -249,12 +341,12 @@ def take_tiled_screenshot( tile_wait_start = time.monotonic() try: page.wait_for_function( - _TILE_READY_CHECK_JS, + CHART_HOLDERS_READY_JS, timeout=load_wait * 1000, ) except PlaywrightTimeout: elapsed = time.monotonic() - tile_wait_start - unready_chart_holders = page.evaluate(_FIND_UNREADY_CHART_HOLDERS_JS) + unready_chart_holders = page.evaluate(FIND_UNREADY_CHART_HOLDERS_JS) # A chart failing to load in time is a customer chart-loading # issue (slow query, error state, etc.), not a Superset system # fault, so this stays at WARNING -- the report still fails diff --git a/superset/utils/webdriver.py b/superset/utils/webdriver.py index cfa9618ed2fc..5fd7d94418ab 100644 --- a/superset/utils/webdriver.py +++ b/superset/utils/webdriver.py @@ -19,6 +19,7 @@ import atexit import logging +import time from abc import ABC, abstractmethod from enum import Enum from time import sleep @@ -41,7 +42,13 @@ from superset.extensions import machine_auth_provider_factory from superset.utils.retries import retry_call -from superset.utils.screenshot_utils import take_tiled_screenshot +from superset.utils.screenshot_utils import ( + CHART_CONTAINER_READY_JS, + CHART_HOLDERS_READY_JS, + FIND_CHART_HOLDER_STATES_JS, + resolve_screenshot_task_budget_seconds, + take_tiled_screenshot, +) WindowSize = tuple[int, int] logger = logging.getLogger(__name__) @@ -53,6 +60,11 @@ "pip install playwright && playwright install chromium" ) + +class ScreenshotTaskBudgetExceededError(RuntimeError): + """Raised when no safe task budget remains before screenshot capture.""" + + if TYPE_CHECKING: from typing import Any @@ -275,6 +287,137 @@ def _get_screenshot(page: Page, element: Locator, element_name: str) -> bytes: else: return element.screenshot() + @staticmethod + def _wait_for_charts_ready( + page: Page, + url: str, + load_wait: int, + element_name: str, + log_context: str | None = None, + screenshot_started_at: float | None = None, + ) -> None: + """ + Wait for every viewport-visible chart holder to reach a terminal state + (rendered, or errored/empty) before taking a standard (non-tiled) + screenshot. + + Uses the same positive readiness predicate as the tiled screenshot + path (see `take_tiled_screenshot` in screenshot_utils.py, #42119) + instead of checking for the mere absence of a `.loading` element: a + chart holder that hasn't mounted anything yet (no spinner, no + rendered content -- e.g. in the gap between page-load completing and + React/query bootstrap) would otherwise satisfy an absence-of-spinner + check immediately, producing a silently blank screenshot with no + timeout, warning, or error anywhere. + + Scoped to viewport-intersecting chart holders only, same as the tiled + path: this method's caller never resizes the browser viewport to the + full dashboard height before capturing, so DashboardVirtualization + placeholders below the fold haven't mounted anything real yet by + design and must not block this wait. + """ + context_suffix = f" [{log_context}]" if log_context else "" + ready_states = {"rendered", "empty", "error", "virtualized"} + initial_chart_holder_states = page.evaluate(FIND_CHART_HOLDER_STATES_JS) + initial_unready_chart_holders = [ + holder + for holder in initial_chart_holder_states + if holder.get("state") not in ready_states + ] + logger.debug( + "Chart holder states before readiness polling at url %s%s: %s", + url, + context_suffix, + initial_chart_holder_states, + ) + if element_name == "standalone" and not initial_chart_holder_states: + logger.warning( + "dashboard capture proceeding with zero chart holders — " + "readiness gate inactive" + ) + if initial_unready_chart_holders: + logger.info( + "Chart holders not ready before polling at url %s%s: %s", + url, + context_suffix, + initial_unready_chart_holders, + ) + task_budget = resolve_screenshot_task_budget_seconds(log_context) + elapsed = ( + max(0.0, time.monotonic() - screenshot_started_at) + if task_budget is not None and screenshot_started_at is not None + else 0.0 + ) + remaining_budget = task_budget - elapsed if task_budget is not None else None + effective_load_wait = ( + min(float(load_wait), remaining_budget) + if remaining_budget is not None + else float(load_wait) + ) + if remaining_budget is not None and effective_load_wait <= 0: + logger.warning( + "Screenshot task budget exhausted before chart readiness wait " + "at url %s%s (%.2fs elapsed of %.2fs safe budget); unready chart " + "holders (chart id, state): %s; all chart holder states: %s. " + "Aborting before capture so cleanup and cache error transition " + "can complete.", + url, + context_suffix, + elapsed, + task_budget, + initial_unready_chart_holders, + initial_chart_holder_states, + ) + raise ScreenshotTaskBudgetExceededError( + f"Screenshot task budget of {task_budget:.2f}s exhausted " + "before chart readiness" + ) + logger.debug( + "Waiting for all chart holders to reach a terminal state at " + "url: %s (SCREENSHOT_LOAD_WAIT=%ss, effective_wait=%.2fs, " + "task_budget=%s, elapsed=%.2fs)%s", + url, + load_wait, + effective_load_wait, + task_budget, + elapsed, + context_suffix, + ) + readiness_predicate = ( + CHART_CONTAINER_READY_JS + if element_name == "chart-container" + else CHART_HOLDERS_READY_JS + ) + try: + page.wait_for_function( + readiness_predicate, + timeout=effective_load_wait * 1000, + ) + except PlaywrightTimeout: + chart_holder_states = page.evaluate(FIND_CHART_HOLDER_STATES_JS) + unready_chart_holders = [ + holder + for holder in chart_holder_states + if holder.get("state") not in ready_states + ] + logger.warning( + "Timed out waiting for %s chart container(s) to become ready " + "at url %s (SCREENSHOT_LOAD_WAIT=%ss, effective_wait=%.2fs)%s; " + "unready chart " + "holders (chart id, state): %s; all chart holder states: %s. " + "Aborting screenshot rather " + "than capturing a blank or partially-loaded dashboard.", + len(unready_chart_holders), + url, + load_wait, + effective_load_wait, + context_suffix, + unready_chart_holders, + chart_holder_states, + ) + raise + logger.debug("All chart holders ready at url: %s%s", url, context_suffix) + def get_screenshot( # pylint: disable=too-many-locals, too-many-statements # noqa: C901 self, url: str, @@ -282,6 +425,7 @@ def get_screenshot( # pylint: disable=too-many-locals, too-many-statements # n user: User | None = None, log_context: str | None = None, ) -> bytes | None: + screenshot_started_at = time.monotonic() if not PLAYWRIGHT_AVAILABLE: logger.info( "Playwright not available - falling back to Selenium. " @@ -443,28 +587,16 @@ def get_screenshot( # pylint: disable=too-many-locals, too-many-statements # n url, ) # Standard screenshot captures the full element including - # below-the-fold content, so wait for all spinners globally. - try: - logger.debug( - "Waiting for all spinners to clear at url: %s " - "(SCREENSHOT_LOAD_WAIT=%ss)", - url, - self._screenshot_load_wait, - ) - page.wait_for_function( - "() => document.querySelectorAll(" - "'.loading').length === 0", - timeout=self._screenshot_load_wait * 1000, - ) - except PlaywrightTimeout: - logger.warning( - "Timed out waiting for charts to load at url %s " - "(SCREENSHOT_LOAD_WAIT=%ss)", - url, - self._screenshot_load_wait, - ) - raise - logger.debug("All spinners cleared for url: %s", url) + # below-the-fold content, so wait for all viewport-visible + # chart holders to reach a terminal state. + WebDriverPlaywright._wait_for_charts_ready( + page, + url, + self._screenshot_load_wait, + element_name, + log_context=log_context, + screenshot_started_at=screenshot_started_at, + ) if selenium_animation_wait > 0: logger.debug( "Wait %i seconds for chart animation", @@ -491,27 +623,16 @@ def get_screenshot( # pylint: disable=too-many-locals, too-many-statements # n url, ) # Standard screenshot captures the full element including - # below-the-fold content, so wait for all spinners globally. - try: - logger.debug( - "Waiting for all spinners to clear at url: %s " - "(SCREENSHOT_LOAD_WAIT=%ss)", - url, - self._screenshot_load_wait, - ) - page.wait_for_function( - "() => document.querySelectorAll('.loading').length === 0", - timeout=self._screenshot_load_wait * 1000, - ) - except PlaywrightTimeout: - logger.warning( - "Timed out waiting for charts to load at url %s " - "(SCREENSHOT_LOAD_WAIT=%ss)", - url, - self._screenshot_load_wait, - ) - raise - logger.debug("All spinners cleared for url: %s", url) + # below-the-fold content, so wait for all viewport-visible + # chart holders to reach a terminal state. + WebDriverPlaywright._wait_for_charts_ready( + page, + url, + self._screenshot_load_wait, + element_name, + log_context=log_context, + screenshot_started_at=screenshot_started_at, + ) if selenium_animation_wait > 0: logger.debug( "Wait %i seconds for chart animation", diff --git a/tests/unit_tests/utils/test_screenshot_utils.py b/tests/unit_tests/utils/test_screenshot_utils.py index fc0b9567045c..438290015968 100644 --- a/tests/unit_tests/utils/test_screenshot_utils.py +++ b/tests/unit_tests/utils/test_screenshot_utils.py @@ -23,11 +23,59 @@ from superset.utils.screenshot_utils import ( combine_screenshot_tiles, + resolve_screenshot_task_budget_seconds, + SCREENSHOT_TASK_BUDGET_MAX_MARGIN_SECONDS, SCROLL_SETTLE_TIMEOUT_MS, take_tiled_screenshot, ) +class TestResolveScreenshotTaskBudget: + def _task(self, timelimit): + task = MagicMock() + task.request.timelimit = timelimit + return task + + def test_prefers_soft_limit_and_reserves_scaled_margin(self): + task = self._task((400, 300)) + with patch("superset.utils.screenshot_utils.current_task", task): + budget = resolve_screenshot_task_budget_seconds() + + assert budget == 240 + + def test_uses_hard_limit_and_caps_cleanup_margin(self): + task = self._task((2000, None)) + with patch("superset.utils.screenshot_utils.current_task", task): + budget = resolve_screenshot_task_budget_seconds() + + assert budget == 2000 - SCREENSHOT_TASK_BUDGET_MAX_MARGIN_SECONDS + + @pytest.mark.parametrize("timelimit", [None, (), (None, None), "300", (0, 0)]) + def test_absent_or_malformed_timelimit_preserves_standalone_timeout( + self, timelimit + ): + task = self._task(timelimit) + with patch("superset.utils.screenshot_utils.current_task", task): + assert resolve_screenshot_task_budget_seconds() is None + + def test_outside_celery_preserves_standalone_timeout(self): + with patch("superset.utils.screenshot_utils.current_task", None): + assert resolve_screenshot_task_budget_seconds() is None + + def test_broken_task_metadata_preserves_standalone_timeout(self): + task = MagicMock() + type(task).request = property( + lambda self: (_ for _ in ()).throw(RuntimeError("boom")) + ) + with ( + patch("superset.utils.screenshot_utils.current_task", task), + patch("superset.utils.screenshot_utils.logger") as mock_logger, + ): + assert resolve_screenshot_task_budget_seconds("execution_id=abc") is None + + assert mock_logger.debug.call_args.kwargs["exc_info"] is True + + class TestCombineScreenshotTiles: def _create_test_image(self, width: int, height: int, color: str = "red") -> bytes: """Helper to create test PNG image bytes.""" @@ -481,15 +529,45 @@ def test_unready_holder_state_classification_embedded_in_js(self, mock_page): lets a slow query be told apart from the race during an incident. """ from superset.utils.screenshot_utils import ( - _FIND_UNREADY_CHART_HOLDERS_JS, - _TILE_READY_CHECK_JS, + CHART_HOLDERS_READY_JS, + FIND_CHART_HOLDER_STATES_JS, + FIND_UNREADY_CHART_HOLDERS_JS, ) - for js in (_TILE_READY_CHECK_JS, _FIND_UNREADY_CHART_HOLDERS_JS): + for js in (CHART_HOLDERS_READY_JS, FIND_UNREADY_CHART_HOLDERS_JS): assert "spinner_mounted" in js assert "waiting_on_database" in js assert "nothing_mounted" in js - assert "slice-container" in js + assert ".slice_container" in js + assert ( + '.dashboard-component-chart-holder[class*="dashboard-chart-id-"]' + ) in js + assert "holder.className.match(/\\bdashboard-chart-id-(\\d+)\\b/)" in js + + assert "rendered" in FIND_CHART_HOLDER_STATES_JS + assert "empty" in FIND_CHART_HOLDER_STATES_JS + assert "error" in FIND_CHART_HOLDER_STATES_JS + assert "virtualized" in FIND_CHART_HOLDER_STATES_JS + assert "waiting_on_database" in FIND_CHART_HOLDER_STATES_JS + assert ( + '.dashboard-component-chart-holder[class*="dashboard-chart-id-"]' + ) in FIND_CHART_HOLDER_STATES_JS + + def test_readiness_constants_are_production_safe(self): + from superset.utils.screenshot_utils import ( + CHART_CONTAINER_READY_JS, + CHART_HOLDERS_READY_JS, + FIND_CHART_HOLDER_STATES_JS, + FIND_UNREADY_CHART_HOLDERS_JS, + ) + + for js in ( + CHART_CONTAINER_READY_JS, + CHART_HOLDERS_READY_JS, + FIND_CHART_HOLDER_STATES_JS, + FIND_UNREADY_CHART_HOLDERS_JS, + ): + assert "data-test" not in js def test_per_tile_timing_logged_at_debug(self, mock_page): """Each tile logs how long it waited for readiness, for profiling.""" diff --git a/tests/unit_tests/utils/webdriver_test.py b/tests/unit_tests/utils/webdriver_test.py index fe72a135c5fb..a7dea405b8e5 100644 --- a/tests/unit_tests/utils/webdriver_test.py +++ b/tests/unit_tests/utils/webdriver_test.py @@ -668,7 +668,7 @@ def test_find_unexpected_errors_processes_alerts( def test_uses_wait_for_function_to_detect_spinners( self, mock_app, mock_browser_manager ): - """wait_for_function polls for spinner absence rather than snapshotting.""" + """wait_for_function polls for chart-holder readiness, not snapshotting.""" mock_user = MagicMock() mock_user.username = "test_user" mock_app.config = { @@ -701,10 +701,17 @@ def test_uses_wait_for_function_to_detect_spinners( driver = WebDriverPlaywright("chrome") driver.get_screenshot("http://example.com", "test-element", mock_user) - mock_page.wait_for_function.assert_called_once_with( - "() => document.querySelectorAll('.loading').length === 0", - timeout=60 * 1000, - ) + mock_page.wait_for_function.assert_called_once() + call_args, call_kwargs = mock_page.wait_for_function.call_args + js = call_args[0] + # The old absence-of-`.loading` predicate passed vacuously when a + # chart holder hadn't mounted anything yet; the fix requires a + # positive terminal-state check instead (same predicate as the tiled + # path, #42119). + assert "dashboard-component-chart-holder" in js + assert ".slice_container" in js + assert "data-test" not in js + assert call_kwargs["timeout"] == 60 * 1000 # Guard against reintroducing the old snapshot-based approach loading_locator_calls = [ c for c in mock_page.locator.call_args_list if c.args == (".loading",) @@ -718,7 +725,8 @@ def test_uses_wait_for_function_to_detect_spinners( def test_spinner_timeout_logs_warning_and_raises( self, mock_app, mock_logger, mock_browser_manager ): - """Spinner timeout is logged as a warning and re-raised.""" + """Readiness timeout is logged as a warning, with per-chart diagnostics, + and re-raised rather than silently capturing.""" from superset.utils.webdriver import PlaywrightTimeout mock_user = MagicMock() @@ -750,6 +758,9 @@ def test_spinner_timeout_logs_warning_and_raises( timeout = PlaywrightTimeout() mock_page.wait_for_function.side_effect = timeout + mock_page.evaluate.return_value = [ + {"chartId": "42", "state": "nothing_mounted"} + ] with patch.object(WebDriverPlaywright, "auth", return_value=mock_context): driver = WebDriverPlaywright("chrome") @@ -757,11 +768,18 @@ def test_spinner_timeout_logs_warning_and_raises( driver.get_screenshot("http://example.com", "test-element", mock_user) assert exc_info.value is timeout - mock_logger.warning.assert_any_call( - "Timed out waiting for charts to load at url %s (SCREENSHOT_LOAD_WAIT=%ss)", - "http://example.com", - 60, - ) + mock_logger.error.assert_not_called() + warning_call = mock_logger.warning.call_args + # Positional args are (format_string, count, url, load_wait, + # context_suffix, unready_chart_holders) -- assert against each + # argument's exact position rather than `x in warning_call.args`, + # which is tuple-element membership, not substring matching, but + # reads ambiguously enough that CodeQL flags it as if it were. + assert "Timed out waiting for" in warning_call.args[0] + assert warning_call.args[1] == 1 + assert warning_call.args[2] == "http://example.com" + assert warning_call.args[3] == 60 + assert warning_call.args[6] == [{"chartId": "42", "state": "nothing_mounted"}] @patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True) @patch("superset.utils.webdriver._browser_manager") @@ -867,6 +885,8 @@ def evaluate_side_effect(script): return 1 if "const target = document.querySelector" in script: return 0 + if "dashboard-component-chart-holder" in script: + return [] return None mock_page.evaluate.side_effect = evaluate_side_effect @@ -974,6 +994,362 @@ def evaluate_side_effect(script): ) +class TestWebDriverPlaywrightChartReadiness: + """Regression tests for the non-tiled vacuous-pass fix. + + The readiness predicate itself (`CHART_HOLDERS_READY_JS` / + `FIND_UNREADY_CHART_HOLDERS_JS` in screenshot_utils.py) is exercised + directly in test_screenshot_utils.py; these tests confirm the standard + (non-tiled) `get_screenshot` path wires up to that *same* shared + predicate instead of the old absence-of-`.loading` check, which passed + vacuously for a chart holder that hadn't mounted anything yet. + """ + + _base_config = { + "WEBDRIVER_OPTION_ARGS": [], + "WEBDRIVER_WINDOW": {"pixel_density": 1}, + "SCREENSHOT_PLAYWRIGHT_DEFAULT_TIMEOUT": 30000, + "SCREENSHOT_PLAYWRIGHT_WAIT_EVENT": "networkidle", + "SCREENSHOT_SELENIUM_HEADSTART": 0, + "SCREENSHOT_SELENIUM_ANIMATION_WAIT": 0, + "SCREENSHOT_REPLACE_UNEXPECTED_ERRORS": False, + "SCREENSHOT_TILED_ENABLED": False, + "SCREENSHOT_LOCATE_WAIT": 10, + "SCREENSHOT_LOAD_WAIT": 5, + "SCREENSHOT_WAIT_FOR_ERROR_MODAL_VISIBLE": 10, + "SCREENSHOT_WAIT_FOR_ERROR_MODAL_INVISIBLE": 10, + } + + def _make_pw_mocks(self, mock_browser_manager): + mock_browser = MagicMock() + mock_context = MagicMock() + mock_page = MagicMock() + mock_element = MagicMock() + + mock_browser_manager.get_browser.return_value = mock_browser + mock_browser.new_context.return_value = mock_context + mock_context.new_page.return_value = mock_page + mock_page.locator.return_value = mock_element + mock_element.screenshot.return_value = b"screenshot" + return mock_context, mock_page + + @patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True) + @patch("superset.utils.webdriver._browser_manager") + @patch("superset.utils.webdriver.app") + def test_chart_holder_with_nothing_mounted_does_not_satisfy_wait( + self, mock_app, mock_browser_manager + ): + """A chart holder present in the DOM but with nothing mounted yet (no + spinner, no rendered content -- e.g. the gap between page-load + completing and React/query bootstrap) must not satisfy the readiness + wait. The old `.loading`-absence check passed immediately in this + case, producing a silently blank screenshot. + """ + from superset.utils.webdriver import PlaywrightTimeout + + mock_user = MagicMock() + mock_user.username = "test_user" + mock_app.config = {**self._base_config} + + mock_context, mock_page = self._make_pw_mocks(mock_browser_manager) + + def fake_wait_for_function(js, timeout=None): + # Confirm the predicate sent is the shared terminal-state check + # (not the old absence-of-`.loading` check), then simulate it + # correctly reporting "not ready" for a chart holder that hasn't + # mounted anything. + assert "dashboard-component-chart-holder" in js + raise PlaywrightTimeout("Timeout waiting for chart holders") + + mock_page.wait_for_function.side_effect = fake_wait_for_function + mock_page.evaluate.return_value = [{"chartId": "7", "state": "nothing_mounted"}] + + with patch.object(WebDriverPlaywright, "auth", return_value=mock_context): + driver = WebDriverPlaywright("chrome") + with pytest.raises(PlaywrightTimeout): + driver.get_screenshot("http://example.com", "test-element", mock_user) + + # No screenshot should be captured -- fail loudly instead of + # silently returning a blank image. + mock_page.screenshot.assert_not_called() + mock_page.locator.return_value.screenshot.assert_not_called() + + @patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True) + @patch("superset.utils.webdriver._browser_manager") + @patch("superset.utils.webdriver.app") + def test_all_chart_holders_ready_passes(self, mock_app, mock_browser_manager): + """All chart holders rendered or errored -> wait passes, screenshot taken.""" + mock_user = MagicMock() + mock_user.username = "test_user" + mock_app.config = {**self._base_config} + + mock_context, mock_page = self._make_pw_mocks(mock_browser_manager) + # mock_page.wait_for_function is a no-op MagicMock by default, i.e. + # the readiness predicate is satisfied immediately. + + with patch.object(WebDriverPlaywright, "auth", return_value=mock_context): + driver = WebDriverPlaywright("chrome") + result = driver.get_screenshot( + "http://example.com", "test-element", mock_user + ) + + assert result == b"screenshot" + # Readiness diagnostics are emitted before polling so a task killed by + # an outer limit still leaves useful state in the logs. + mock_page.evaluate.assert_called_once() + assert "state: 'rendered'" in mock_page.evaluate.call_args.args[0] + + @patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True) + @patch("superset.utils.webdriver._browser_manager") + @patch("superset.utils.webdriver.app") + def test_chart_capture_uses_positive_terminal_state_predicate( + self, mock_app, mock_browser_manager + ): + """Chart captures require a terminal marker and no loading marker.""" + from superset.utils.webdriver import PlaywrightTimeout + + mock_app.config = {**self._base_config} + mock_context, mock_page = self._make_pw_mocks(mock_browser_manager) + timeout = PlaywrightTimeout("chart not ready") + mock_page.wait_for_function.side_effect = timeout + + with patch.object(WebDriverPlaywright, "auth", return_value=mock_context): + with pytest.raises(PlaywrightTimeout): + WebDriverPlaywright("chrome").get_screenshot( + "http://example.com", "chart-container", MagicMock() + ) + + predicate = mock_page.wait_for_function.call_args.args[0] + assert "document.querySelector('.chart-container')" in predicate + assert ".slice_container" in predicate + assert ".loading" in predicate + assert '[role="alert"]' in predicate + assert ".ant-empty" in predicate + assert ".missing-chart-container" in predicate + mock_page.locator.return_value.screenshot.assert_not_called() + + @patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True) + @patch("superset.utils.webdriver._browser_manager") + @patch("superset.utils.webdriver.logger") + @patch("superset.utils.webdriver.app") + def test_standalone_zero_holders_warns_before_polling( + self, mock_app, mock_logger, mock_browser_manager + ): + mock_app.config = {**self._base_config} + mock_context, mock_page = self._make_pw_mocks(mock_browser_manager) + mock_page.evaluate.return_value = [] + + with patch.object(WebDriverPlaywright, "auth", return_value=mock_context): + WebDriverPlaywright("chrome").get_screenshot( + "http://example.com", "standalone", MagicMock() + ) + + mock_logger.warning.assert_any_call( + "dashboard capture proceeding with zero chart holders — " + "readiness gate inactive" + ) + + @patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True) + @patch("superset.utils.webdriver._browser_manager") + @patch("superset.utils.webdriver.app") + def test_readiness_check_scoped_to_viewport_visible_holders( + self, mock_app, mock_browser_manager + ): + """The non-tiled readiness check only requires viewport-intersecting + chart holders to be ready, mirroring the tiled path's reasoning + (#42119). `get_screenshot`'s standard (non-tiled) branch never + resizes the browser viewport to the full dashboard height before + capturing -- only the tiled branch's `set_viewport_size` call does + that -- so a below-the-fold chart holder is a + DashboardVirtualization placeholder that hasn't mounted anything + real yet by design and must not block this wait. + """ + mock_user = MagicMock() + mock_user.username = "test_user" + mock_app.config = {**self._base_config} + + mock_context, mock_page = self._make_pw_mocks(mock_browser_manager) + + with patch.object(WebDriverPlaywright, "auth", return_value=mock_context): + driver = WebDriverPlaywright("chrome") + driver.get_screenshot("http://example.com", "test-element", mock_user) + + js = mock_page.wait_for_function.call_args[0][0] + # The predicate skips any chart holder whose bounding rect doesn't + # intersect the current viewport -- an off-screen/below-fold holder + # is excluded from the readiness requirement rather than blocking it. + assert "getBoundingClientRect" in js + assert "window.innerHeight" in js + # set_viewport_size is only ever called on the tiled branch (to + # resize to tile_height); confirming it's untouched here is what + # makes the viewport-scoped predicate necessary for this branch. + mock_page.set_viewport_size.assert_not_called() + + @patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True) + @patch("superset.utils.webdriver._browser_manager") + @patch("superset.utils.webdriver.logger") + @patch("superset.utils.webdriver.app") + def test_log_context_threaded_into_readiness_wait( + self, mock_app, mock_logger, mock_browser_manager + ): + """log_context (e.g. report execution id) is threaded through the + non-tiled readiness wait for correlation, matching #42119's + convention for the tiled path.""" + from superset.utils.webdriver import PlaywrightTimeout + + mock_user = MagicMock() + mock_user.username = "test_user" + mock_app.config = {**self._base_config} + + mock_context, mock_page = self._make_pw_mocks(mock_browser_manager) + mock_page.wait_for_function.side_effect = PlaywrightTimeout("timed out") + mock_page.evaluate.return_value = [{"chartId": "7", "state": "nothing_mounted"}] + + with patch.object(WebDriverPlaywright, "auth", return_value=mock_context): + driver = WebDriverPlaywright("chrome") + with pytest.raises(PlaywrightTimeout): + driver.get_screenshot( + "http://example.com", + "test-element", + mock_user, + log_context="execution_id=abc-123", + ) + + # context_suffix is the 6th positional arg (index 5); assert its + # exact value rather than tuple-element membership via `in`. + assert mock_logger.warning.call_args.args[5] == " [execution_id=abc-123]" + + @patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True) + @patch("superset.utils.webdriver._browser_manager") + @patch("superset.utils.webdriver.logger") + @patch("superset.utils.webdriver.app") + def test_wait_is_capped_to_remaining_runtime_task_budget( + self, mock_app, mock_logger, mock_browser_manager + ): + """Elapsed setup time is removed from the task-derived safe budget.""" + mock_user = MagicMock() + mock_user.username = "test_user" + mock_app.config = { + **self._base_config, + "SCREENSHOT_LOAD_WAIT": 600, + } + mock_context, mock_page = self._make_pw_mocks(mock_browser_manager) + + with ( + patch.object(WebDriverPlaywright, "auth", return_value=mock_context), + patch( + "superset.utils.webdriver.resolve_screenshot_task_budget_seconds", + return_value=240, + ), + patch( + "superset.utils.webdriver.time.monotonic", + side_effect=[100.0, 110.0], + ), + ): + WebDriverPlaywright("chrome").get_screenshot( + "http://example.com", "test-element", mock_user + ) + + assert mock_page.wait_for_function.call_args.kwargs["timeout"] == 230_000 + + def test_zero_load_wait_without_task_budget_preserves_playwright_no_timeout(self): + page = MagicMock() + page.evaluate.return_value = [] + + with patch( + "superset.utils.webdriver.resolve_screenshot_task_budget_seconds", + return_value=None, + ): + WebDriverPlaywright._wait_for_charts_ready( + page, + "http://example.com", + 0, + "chart-container", + ) + + page.wait_for_function.assert_called_once() + assert page.wait_for_function.call_args.kwargs["timeout"] == 0 + + @patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True) + @patch("superset.utils.webdriver._browser_manager") + @patch("superset.utils.webdriver.logger") + @patch("superset.utils.webdriver.app") + def test_exhausted_task_budget_raises_before_capture( + self, mock_app, mock_logger, mock_browser_manager + ): + """An exhausted budget fails loudly while cleanup time remains.""" + from superset.utils.webdriver import ScreenshotTaskBudgetExceededError + + mock_user = MagicMock() + mock_app.config = {**self._base_config, "SCREENSHOT_LOAD_WAIT": 600} + mock_context, mock_page = self._make_pw_mocks(mock_browser_manager) + diagnostics = [{"chartId": "17", "state": "nothing_mounted"}] + mock_page.evaluate.return_value = diagnostics + + with ( + patch.object(WebDriverPlaywright, "auth", return_value=mock_context), + patch( + "superset.utils.webdriver.resolve_screenshot_task_budget_seconds", + return_value=240, + ), + patch( + "superset.utils.webdriver.time.monotonic", + side_effect=[100.0, 341.0], + ), + ): + with pytest.raises(ScreenshotTaskBudgetExceededError): + WebDriverPlaywright("chrome").get_screenshot( + "http://example.com", "test-element", mock_user + ) + + mock_page.wait_for_function.assert_not_called() + mock_page.locator.return_value.screenshot.assert_not_called() + mock_context.close.assert_called_once() + warning_args = mock_logger.warning.call_args.args + assert "budget exhausted" in warning_args[0] + assert warning_args[5] == diagnostics + + @patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True) + @patch("superset.utils.webdriver._browser_manager") + @patch("superset.utils.webdriver.logger") + @patch("superset.utils.webdriver.app") + def test_unready_diagnostics_logged_early_and_at_failure( + self, mock_app, mock_logger, mock_browser_manager + ): + """Unready IDs/states are logged before polling and on timeout.""" + from superset.utils.webdriver import PlaywrightTimeout + + mock_user = MagicMock() + mock_user.username = "test_user" + mock_app.config = {**self._base_config} + mock_context, mock_page = self._make_pw_mocks(mock_browser_manager) + diagnostics = [{"chartId": "17", "state": "waiting_on_database"}] + mock_page.evaluate.return_value = diagnostics + mock_page.wait_for_function.side_effect = PlaywrightTimeout("timed out") + + with patch.object(WebDriverPlaywright, "auth", return_value=mock_context): + driver = WebDriverPlaywright("chrome") + with pytest.raises(PlaywrightTimeout): + driver.get_screenshot("http://example.com", "test-element", mock_user) + + mock_logger.debug.assert_any_call( + "Chart holder states before readiness polling at url %s%s: %s", + "http://example.com", + "", + diagnostics, + ) + mock_logger.info.assert_any_call( + "Chart holders not ready before polling at url %s%s: %s", + "http://example.com", + "", + diagnostics, + ) + failure_args = mock_logger.warning.call_args.args + assert failure_args[6] == diagnostics + assert failure_args[7] == diagnostics + mock_page.locator.return_value.screenshot.assert_not_called() + + class TestWebDriverPlaywrightAnimationWaitOrder: """Animation wait must run after the spinner wait, not before.""" @@ -1062,7 +1438,7 @@ def test_animation_wait_after_spinner_wait_tiled_enabled_small_dashboard( mock_context, mock_page = self._make_pw_mocks(mock_browser_manager) # Small dashboard: 3 charts, 1000px height — below both thresholds - mock_page.evaluate.side_effect = [3, 1000] + mock_page.evaluate.side_effect = [3, 1000, []] call_order: list[str] = []