diff --git a/superset/commands/report/execute.py b/superset/commands/report/execute.py index defbd32dde7..8f6492c4452 100644 --- a/superset/commands/report/execute.py +++ b/superset/commands/report/execute.py @@ -564,7 +564,7 @@ class BaseReportState: imges = [] for screenshot in screenshots: imge = screenshot.get_screenshot( - user=user, execution_id=str(self._execution_id) + user=user, log_context=f"execution_id={self._execution_id}" ) if imge is None: raise ReportScheduleScreenshotFailedError( diff --git a/superset/utils/screenshot_utils.py b/superset/utils/screenshot_utils.py index 69eac3a570f..3914e4ccb15 100644 --- a/superset/utils/screenshot_utils.py +++ b/superset/utils/screenshot_utils.py @@ -165,7 +165,7 @@ def take_tiled_screenshot( tile_height: int, load_wait: int = 60, animation_wait: int = 0, - execution_id: str | None = None, + log_context: str | None = None, ) -> bytes | None: """ Take a tiled screenshot of a large dashboard by scrolling and capturing sections. @@ -176,14 +176,14 @@ def take_tiled_screenshot( tile_height: Height of each tile in pixels load_wait: Seconds to wait for charts to load per tile (default 60) animation_wait: Seconds to wait for chart animations per tile (default 0) - execution_id: Report execution id, included in log lines for - correlation with the report that triggered this screenshot. - None for callers outside the report pipeline (e.g. thumbnails). + log_context: Optional identifier (e.g. report execution id, or a + cache key for thumbnails) appended to log lines so a slow/timed-out + capture can be traced back to the run that produced it. Returns: Combined screenshot bytes or None if failed """ - exec_id_suffix = f" - execution_id: {execution_id}" if execution_id else "" + context_suffix = f" [{log_context}]" if log_context else "" try: # Get the target element element = page.locator(f".{element_name}") @@ -260,7 +260,7 @@ def take_tiled_screenshot( i + 1, num_tiles, load_wait, - exec_id_suffix, + context_suffix, unready_chart_holders, ) raise @@ -272,7 +272,7 @@ def take_tiled_screenshot( num_tiles, elapsed, load_wait, - exec_id_suffix, + context_suffix, ) # Wait for chart animations (e.g. ECharts) to finish after spinner clears. @@ -336,5 +336,5 @@ def take_tiled_screenshot( # Unlike the readiness-timeout warning above, this is a genuine # system-level fault (unexpected error, not a customer chart taking # too long to load), so it stays at ERROR/exception level. - logger.exception("Tiled screenshot failed: %s%s", e, exec_id_suffix) + logger.exception("Tiled screenshot failed: %s%s", e, context_suffix) return None diff --git a/superset/utils/screenshots.py b/superset/utils/screenshots.py index c16fc960638..750ec54b597 100644 --- a/superset/utils/screenshots.py +++ b/superset/utils/screenshots.py @@ -213,12 +213,12 @@ class BaseScreenshot: self, user: User, window_size: WindowSize | None = None, - execution_id: str | None = None, + log_context: str | None = None, ) -> bytes | None: driver = self.driver(window_size, user) try: self.screenshot = driver.get_screenshot( - self.url, self.element, user, execution_id=execution_id + self.url, self.element, user, log_context=log_context ) finally: if isinstance(driver, WebDriverSelenium): diff --git a/superset/utils/webdriver.py b/superset/utils/webdriver.py index 98f4c7efcc5..c437e0cd6bf 100644 --- a/superset/utils/webdriver.py +++ b/superset/utils/webdriver.py @@ -207,13 +207,13 @@ class WebDriverProxy(ABC): url: str, element_name: str, user: User | None = None, - execution_id: str | None = None, + log_context: str | None = None, ) -> bytes | None: """ Run webdriver and return a screenshot - :param execution_id: Report execution id, for log correlation. None - for callers outside the report pipeline (e.g. thumbnails). + :param log_context: Optional identifier (e.g. report execution id, or + a cache key for thumbnails) included in log lines for tracing. """ @@ -280,7 +280,7 @@ class WebDriverPlaywright(WebDriverProxy): url: str, element_name: str, user: User | None = None, - execution_id: str | None = None, + log_context: str | None = None, ) -> bytes | None: if not PLAYWRIGHT_AVAILABLE: logger.info( @@ -416,7 +416,7 @@ class WebDriverPlaywright(WebDriverProxy): tile_height, load_wait=self._screenshot_load_wait, animation_wait=selenium_animation_wait, - execution_id=execution_id, + log_context=log_context, ) if not img: logger.warning( @@ -800,7 +800,7 @@ class WebDriverSelenium(WebDriverProxy): url: str, element_name: str, user: User | None = None, - execution_id: str | None = None, + log_context: str | None = None, ) -> bytes | None: # If a user is passed explicitly and differs from the stored user, # update and re-authenticate diff --git a/tests/unit_tests/utils/test_screenshot_utils.py b/tests/unit_tests/utils/test_screenshot_utils.py index b88b3e7093e..fc0b9567045 100644 --- a/tests/unit_tests/utils/test_screenshot_utils.py +++ b/tests/unit_tests/utils/test_screenshot_utils.py @@ -201,23 +201,27 @@ class TestTakeTiledScreenshot: call_args = mock_logger.exception.call_args assert call_args[0][0] == "Tiled screenshot failed: %s%s" assert str(call_args[0][1]) == "Unexpected error" - assert call_args[0][2] == "" # no execution_id passed + assert call_args[0][2] == "" # no log_context passed - def test_exception_handling_logs_execution_id(self): + def test_exception_handling_logs_context(self): """Genuine system faults (not a customer chart-loading issue) stay at - ERROR/exception level, and still carry the execution id for - correlation with the report that triggered this screenshot.""" + ERROR/exception level, and still carry the log context (e.g. report + execution id) for correlation with the run that triggered this + screenshot.""" mock_page = MagicMock() mock_page.locator.side_effect = Exception("Unexpected error") with patch("superset.utils.screenshot_utils.logger") as mock_logger: result = take_tiled_screenshot( - mock_page, "dashboard", tile_height=2000, execution_id="abc-123" + mock_page, + "dashboard", + tile_height=2000, + log_context="execution_id=abc-123", ) assert result is None call_args = mock_logger.exception.call_args - assert "abc-123" in call_args[0][2] + assert call_args[0][2] == " [execution_id=abc-123]" def test_screenshot_clip_parameters(self, mock_page): """Test that screenshot clipping parameters are correct.""" @@ -402,15 +406,15 @@ class TestTakeTiledScreenshot: assert warning_args[3] == 1 # tile index assert warning_args[4] == 3 # total tiles assert warning_args[5] == 30 # load_wait - assert warning_args[6] == "" # no execution_id passed + assert warning_args[6] == "" # no log_context passed # Diagnostic payload identifies chart id AND the state it's stuck in # (spinner mounted vs nothing mounted vs waiting-on-database) so a # slow query can be told apart from the virtualization race. assert warning_args[7] == [{"chartId": "42", "state": "waiting_on_database"}] - def test_timeout_warning_includes_execution_id(self, mock_page): - """The execution id is threaded through for log correlation with the - report that triggered this screenshot.""" + def test_timeout_warning_includes_log_context(self, mock_page): + """The log context (e.g. report execution id) is threaded through for + correlation with the run that triggered this screenshot.""" from superset.utils.screenshot_utils import PlaywrightTimeout mock_page.wait_for_function.side_effect = PlaywrightTimeout("timed out") @@ -428,11 +432,11 @@ class TestTakeTiledScreenshot: "dashboard", tile_height=2000, load_wait=5, - execution_id="abc-123", + log_context="execution_id=abc-123", ) warning_args = mock_logger.warning.call_args[0] - assert "abc-123" in warning_args[6] + assert warning_args[6] == " [execution_id=abc-123]" def test_chart_holder_with_nothing_mounted_blocks_wait(self, mock_page): """Regression test for the vacuous-pass race (PR #39895). @@ -496,7 +500,7 @@ class TestTakeTiledScreenshot: "dashboard", tile_height=2000, load_wait=30, - execution_id="abc-123", + log_context="execution_id=abc-123", ) # 3 tiles, all ready immediately (mock_page.wait_for_function is a @@ -515,7 +519,7 @@ class TestTakeTiledScreenshot: assert isinstance(elapsed, float) assert elapsed >= 0 assert first_call_args[4] == 30 # load_wait - assert "abc-123" in first_call_args[5] + assert first_call_args[5] == " [execution_id=abc-123]" def test_all_chart_holders_ready_passes(self, mock_page): """All chart holders rendered or errored -> wait passes, tile captured.""" diff --git a/tests/unit_tests/utils/webdriver_test.py b/tests/unit_tests/utils/webdriver_test.py index 64e1b42c8e1..fe72a135c5f 100644 --- a/tests/unit_tests/utils/webdriver_test.py +++ b/tests/unit_tests/utils/webdriver_test.py @@ -1121,7 +1121,7 @@ class TestWebDriverPlaywrightAnimationWaitOrder: 600, load_wait=30, animation_wait=2, - execution_id=None, + log_context=None, ) # The only wait_for_timeout call should be the 0ms headstart; no global # animation wait should be issued (handled per-tile by take_tiled_screenshot)