You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@superset.apache.org by el...@apache.org on 2026/07/31 21:36:19 UTC
(superset) 01/01: chore(reports): thread cache-key/execution-id log context through screenshot capture logs
This is an automated email from the ASF dual-hosted git repository.
eschutho pushed a commit to branch fix-screenshot-log-context-tracing
in repository https://gitbox.apache.org/repos/asf/superset.git
commit 560e52c4aeffb96d5debf67eaaec0de49dc4aa8b
Author: Elizabeth Thompson <es...@gmail.com>
AuthorDate: Fri Jul 31 21:36:08 2026 +0000
chore(reports): thread cache-key/execution-id log context through screenshot capture logs
The screenshot capture code is reached by two call paths that identify
their runs differently: scheduled reports carry an execution_id (already
threaded end-to-end via log_context since #42253), while thumbnails and
direct PDF/screenshot downloads are identified by their cache_key -- which
was never passed down. BaseScreenshot.compute_and_cache had the cache_key
in hand and get_screenshot already accepted a log_context parameter, but
the two were never connected, so every capture-layer log line produced by
a thumbnail or direct-download run is anonymous: there is no way to join
"trying to generate screenshot" / webdriver navigation / readiness /
capture-result log lines to the cached digest they were computing.
This threads the existing optional log_context through the remaining
capture-layer log lines, and populates it on the thumbnail path:
- screenshots.py: compute_and_cache passes
log_context=f"cache_key={cache_key}" into get_screenshot and
resize_image; the thumbnail lifecycle log lines (generate/fail/resize/
cache-updated) now include the cache_key; driver() accepts log_context
for its Playwright-unavailable fallback notice.
- webdriver.py: the non-tiled Playwright log lines (navigation, headstart,
element/chart-container waits, screenshot result), the entire
WebDriverSelenium.get_screenshot path, and find_unexpected_errors (both
engines) now append the context suffix.
- screenshot_utils.py: the non-budget tiled log lines (dimensions, tile
count, scroll, capture, skip, combine) and combine_screenshot_tiles gain
the same suffix.
Log-line/plumbing only -- no behavior change. Split out of #42118 per its
scope reduction to tiled-path budgeting; the readiness log lines added by
#42253/#42427 already carry log_context and are untouched.
Co-Authored-By: Claude <no...@anthropic.com>
---
superset/utils/screenshot_utils.py | 37 ++++--
superset/utils/screenshots.py | 54 ++++++--
superset/utils/webdriver.py | 162 +++++++++++++++++-------
tests/unit_tests/utils/screenshot_test.py | 21 +++
tests/unit_tests/utils/test_screenshot_utils.py | 4 +-
tests/unit_tests/utils/webdriver_test.py | 13 +-
6 files changed, 218 insertions(+), 73 deletions(-)
diff --git a/superset/utils/screenshot_utils.py b/superset/utils/screenshot_utils.py
index 868b8e731d5..4dbe7f6e055 100644
--- a/superset/utils/screenshot_utils.py
+++ b/superset/utils/screenshot_utils.py
@@ -207,12 +207,16 @@ CHART_CONTAINER_READY_JS = f"""
"""
-def combine_screenshot_tiles(screenshot_tiles: list[bytes]) -> bytes:
+def combine_screenshot_tiles(
+ screenshot_tiles: list[bytes], log_context: str | None = None
+) -> bytes:
"""
Combine multiple screenshot tiles into a single vertical image.
Args:
screenshot_tiles: List of screenshot bytes in PNG format
+ log_context: Optional identifier (e.g. report execution id, or a
+ thumbnail cache key) appended to log lines for tracing.
Returns:
Combined screenshot as bytes
@@ -223,6 +227,7 @@ def combine_screenshot_tiles(screenshot_tiles: list[bytes]) -> bytes:
if len(screenshot_tiles) == 1:
return screenshot_tiles[0]
+ context_suffix = f" [{log_context}]" if log_context else ""
try:
# Open all images
images = [Image.open(io.BytesIO(tile)) for tile in screenshot_tiles]
@@ -246,7 +251,7 @@ def combine_screenshot_tiles(screenshot_tiles: list[bytes]) -> bytes:
return output.getvalue()
except Exception as e:
- logger.exception("Failed to combine screenshot tiles: %s", e)
+ logger.exception("Failed to combine screenshot tiles: %s%s", e, context_suffix)
# Return the first tile as fallback
return screenshot_tiles[0]
@@ -309,16 +314,17 @@ def take_tiled_screenshot(
dashboard_top = element_info["top"]
logger.info(
- "Dashboard: %sx%spx at (%s, %s)",
+ "Dashboard: %sx%spx at (%s, %s)%s",
dashboard_width,
dashboard_height,
dashboard_left,
dashboard_top,
+ context_suffix,
)
# Calculate number of tiles needed
num_tiles = max(1, (dashboard_height + tile_height - 1) // tile_height)
- logger.info("Taking %s screenshot tiles", num_tiles)
+ logger.info("Taking %s screenshot tiles%s", num_tiles, context_suffix)
screenshot_tiles = []
@@ -328,7 +334,11 @@ def take_tiled_screenshot(
page.evaluate(f"window.scrollTo(0, {scroll_y})")
logger.debug(
- "Scrolled window to %s for tile %s/%s", scroll_y, i + 1, num_tiles
+ "Scrolled window to %s for tile %s/%s%s",
+ scroll_y,
+ i + 1,
+ num_tiles,
+ context_suffix,
)
# Wait for scroll to settle and content to load
page.wait_for_timeout(SCROLL_SETTLE_TIMEOUT_MS)
@@ -401,13 +411,14 @@ def take_tiled_screenshot(
logger.warning(
"Skipping tile %s/%s due to invalid clip dimensions: "
"x=%s, y=%s, width=%s, height=%s "
- "(element may be scrolled out of viewport)",
+ "(element may be scrolled out of viewport).%s",
i + 1,
num_tiles,
clip_x,
clip_y,
dashboard_width,
clip_height,
+ context_suffix,
)
continue
@@ -423,11 +434,19 @@ def take_tiled_screenshot(
tile_screenshot = page.screenshot(type="png", clip=clip)
screenshot_tiles.append(tile_screenshot)
- logger.debug("Captured tile %s/%s with clip %s", i + 1, num_tiles, clip)
+ logger.debug(
+ "Captured tile %s/%s with clip %s%s",
+ i + 1,
+ num_tiles,
+ clip,
+ context_suffix,
+ )
# Combine all tiles
- logger.info("Combining screenshot tiles...")
- combined_screenshot = combine_screenshot_tiles(screenshot_tiles)
+ logger.info("Combining screenshot tiles...%s", context_suffix)
+ combined_screenshot = combine_screenshot_tiles(
+ screenshot_tiles, log_context=log_context
+ )
return combined_screenshot
diff --git a/superset/utils/screenshots.py b/superset/utils/screenshots.py
index 750ec54b597..3b513102cae 100644
--- a/superset/utils/screenshots.py
+++ b/superset/utils/screenshots.py
@@ -190,7 +190,10 @@ class BaseScreenshot:
self.screenshot = None
def driver(
- self, window_size: WindowSize | None = None, user: User | None = None
+ self,
+ window_size: WindowSize | None = None,
+ user: User | None = None,
+ log_context: str | None = None,
) -> WebDriverProxy:
window_size = window_size or self.window_size
if feature_flag_manager.is_feature_enabled("PLAYWRIGHT_REPORTS_AND_THUMBNAILS"):
@@ -199,11 +202,13 @@ class BaseScreenshot:
return WebDriverPlaywright(self.driver_type, window_size)
# Playwright not available, falling back to Selenium
+ context_suffix = f" [{log_context}]" if log_context else ""
logger.info(
"PLAYWRIGHT_REPORTS_AND_THUMBNAILS enabled but Playwright not "
"installed. Falling back to Selenium (WebGL/Canvas charts may "
- "not render correctly). %s",
+ "not render correctly). %s%s",
PLAYWRIGHT_INSTALL_MESSAGE,
+ context_suffix,
)
# Use Selenium as default/fallback
@@ -215,7 +220,7 @@ class BaseScreenshot:
window_size: WindowSize | None = None,
log_context: str | None = None,
) -> bytes | None:
- driver = self.driver(window_size, user)
+ driver = self.driver(window_size, user, log_context=log_context)
try:
self.screenshot = driver.get_screenshot(
self.url, self.element, user, log_context=log_context
@@ -310,22 +315,38 @@ class BaseScreenshot:
image = None
# Assuming all sorts of things can go wrong with Selenium
try:
- logger.info("trying to generate screenshot")
+ logger.info(
+ "trying to generate screenshot for cache_key=%s", cache_key
+ )
with event_logger.log_context(
f"screenshot.compute.{self.thumbnail_type}"
):
- image = self.get_screenshot(user=user, window_size=window_size)
+ image = self.get_screenshot(
+ user=user,
+ window_size=window_size,
+ log_context=f"cache_key={cache_key}",
+ )
except Exception as ex: # pylint: disable=broad-except
logger.warning(
- "Failed at generating thumbnail %s", ex, exc_info=True
+ "Failed at generating thumbnail for cache_key=%s: %s",
+ cache_key,
+ ex,
+ exc_info=True,
)
cache_payload.error()
if image and window_size != thumb_size:
try:
- image = self.resize_image(image, thumb_size=thumb_size)
+ image = self.resize_image(
+ image,
+ thumb_size=thumb_size,
+ log_context=f"cache_key={cache_key}",
+ )
except Exception as ex: # pylint: disable=broad-except
logger.warning(
- "Failed at resizing thumbnail %s", ex, exc_info=True
+ "Failed at resizing thumbnail for cache_key=%s: %s",
+ cache_key,
+ ex,
+ exc_info=True,
)
cache_payload.error()
image = None
@@ -344,7 +365,9 @@ class BaseScreenshot:
logger.info("Caching thumbnail: %s", cache_key)
self.cache.set(cache_key, cache_payload.to_dict())
logger.info(
- "Updated thumbnail cache; Status: %s", cache_payload.get_status()
+ "Updated thumbnail cache for %s; Status: %s",
+ cache_key,
+ cache_payload.get_status(),
)
except LockAlreadyHeldException:
logger.info(
@@ -359,16 +382,23 @@ class BaseScreenshot:
output: str = "png",
thumb_size: WindowSize | None = None,
crop: bool = True,
+ log_context: str | None = None,
) -> bytes:
+ context_suffix = f" [{log_context}]" if log_context else ""
thumb_size = thumb_size or cls.thumb_size
img = Image.open(BytesIO(img_bytes))
- logger.debug("Selenium image size: %s", str(img.size))
+ logger.debug("Selenium image size: %s%s", str(img.size), context_suffix)
if crop and img.size[1] != cls.window_size[1]:
desired_ratio = float(cls.window_size[1]) / cls.window_size[0]
desired_width = int(img.size[0] * desired_ratio)
- logger.debug("Cropping to: %s*%s", str(img.size[0]), str(desired_width))
+ logger.debug(
+ "Cropping to: %s*%s%s",
+ str(img.size[0]),
+ str(desired_width),
+ context_suffix,
+ )
img = img.crop((0, 0, img.size[0], desired_width))
- logger.debug("Resizing to %s", str(thumb_size))
+ logger.debug("Resizing to %s%s", str(thumb_size), context_suffix)
img = img.resize(thumb_size, Image.Resampling.LANCZOS)
new_img = BytesIO()
if output != "png":
diff --git a/superset/utils/webdriver.py b/superset/utils/webdriver.py
index 75eeb1d2497..4fe9f860f44 100644
--- a/superset/utils/webdriver.py
+++ b/superset/utils/webdriver.py
@@ -237,14 +237,17 @@ class WebDriverPlaywright(WebDriverProxy):
)
@staticmethod
- def find_unexpected_errors(page: Page) -> list[str]:
+ def find_unexpected_errors(page: Page, log_context: str | None = None) -> list[str]:
error_messages = []
+ context_suffix = f" [{log_context}]" if log_context else ""
try:
alert_divs = page.get_by_role("alert").all()
logger.debug(
- "%i alert elements have been found in the screenshot", len(alert_divs)
+ "%i alert elements have been found in the screenshot%s",
+ len(alert_divs),
+ context_suffix,
)
for alert_div in alert_divs:
@@ -274,9 +277,12 @@ class WebDriverPlaywright(WebDriverProxy):
[error_as_html],
)
except PlaywrightError:
- logger.exception("Failed to update error messages using alert_div")
+ logger.exception(
+ "Failed to update error messages using alert_div%s",
+ context_suffix,
+ )
except PlaywrightError:
- logger.exception("Failed to capture unexpected errors")
+ logger.exception("Failed to capture unexpected errors%s", context_suffix)
return error_messages
@@ -426,12 +432,14 @@ class WebDriverPlaywright(WebDriverProxy):
log_context: str | None = None,
) -> bytes | None:
screenshot_started_at = time.monotonic()
+ context_suffix = f" [{log_context}]" if log_context else ""
if not PLAYWRIGHT_AVAILABLE:
logger.info(
"Playwright not available - falling back to Selenium. "
"Note: WebGL/Canvas charts may not render correctly with Selenium. "
- "%s",
+ "%s%s",
PLAYWRIGHT_INSTALL_MESSAGE,
+ context_suffix,
)
return None
@@ -461,50 +469,66 @@ class WebDriverPlaywright(WebDriverProxy):
)
except PlaywrightTimeout:
logger.exception(
- "Web event %s not detected. Page %s might not have been fully loaded", # noqa: E501
+ "Web event %s not detected. Page %s might not have been fully loaded%s", # noqa: E501
app.config["SCREENSHOT_PLAYWRIGHT_WAIT_EVENT"],
url,
+ context_suffix,
)
selenium_headstart = app.config["SCREENSHOT_SELENIUM_HEADSTART"]
- logger.debug("Sleeping for %i seconds", selenium_headstart)
+ logger.debug(
+ "Sleeping for %i seconds%s", selenium_headstart, context_suffix
+ )
page.wait_for_timeout(selenium_headstart * 1000)
element: Locator
try:
try:
# page didn't load
logger.debug(
- "Wait for the presence of %s at url: %s", element_name, url
+ "Wait for the presence of %s at url: %s%s",
+ element_name,
+ url,
+ context_suffix,
)
element = page.locator(f".{element_name}")
element.wait_for()
except PlaywrightTimeout:
- logger.exception("Timed out requesting url %s", url)
+ logger.exception(
+ "Timed out requesting url %s%s", url, context_suffix
+ )
raise
try:
# chart containers didn't render
- logger.debug("Wait for chart containers to draw at url: %s", url)
+ logger.debug(
+ "Wait for chart containers to draw at url: %s%s",
+ url,
+ context_suffix,
+ )
slice_container_locator = page.locator(".chart-container")
for slice_container_elem in slice_container_locator.all():
slice_container_elem.wait_for()
except PlaywrightTimeout:
logger.exception(
- "Timed out waiting for chart containers to draw at url %s",
+ "Timed out waiting for chart containers to draw at url %s%s",
url,
+ context_suffix,
)
raise
selenium_animation_wait = app.config[
"SCREENSHOT_SELENIUM_ANIMATION_WAIT"
]
if app.config["SCREENSHOT_REPLACE_UNEXPECTED_ERRORS"]:
- unexpected_errors = WebDriverPlaywright.find_unexpected_errors(page)
+ unexpected_errors = WebDriverPlaywright.find_unexpected_errors(
+ page, log_context=log_context
+ )
if unexpected_errors:
logger.warning(
- "%i errors found in the screenshot. URL: %s. Errors are: %s", # noqa: E501
+ "%i errors found in the screenshot. URL: %s. Errors are: %s%s", # noqa: E501
len(unexpected_errors),
url,
unexpected_errors,
+ context_suffix,
)
# Detect large dashboards and use tiled screenshots if enabled
tiled_enabled = app.config.get("SCREENSHOT_TILED_ENABLED", False)
@@ -532,9 +556,11 @@ class WebDriverPlaywright(WebDriverProxy):
if dashboard_height == 0:
logger.warning(
"Could not determine dashboard height for element %s "
- "at url %s; falling back to standard screenshot behavior",
+ "at url %s; falling back to standard screenshot "
+ "behavior%s",
element_name,
url,
+ context_suffix,
)
# Use tiled screenshots for large dashboards
@@ -546,9 +572,10 @@ class WebDriverPlaywright(WebDriverProxy):
if use_tiled:
logger.info(
"Large dashboard detected: %s charts, %spx height. "
- "Using tiled screenshots.",
+ "Using tiled screenshots.%s",
chart_count,
dashboard_height,
+ context_suffix,
)
# set viewport height to tile height for easier calculations
page.set_viewport_size(
@@ -571,25 +598,28 @@ class WebDriverPlaywright(WebDriverProxy):
# guessing at a "safer" fallback.
logger.warning(
"Tiled screenshot failed for url %s and no "
- "safe fallback exists; failing the capture",
+ "safe fallback exists; failing the capture%s",
url,
+ context_suffix,
)
raise PlaywrightTimeout(
f"Tiled screenshot failed for url {url}"
)
logger.debug(
- "Tiled screenshot result: %d bytes for url: %s",
+ "Tiled screenshot result: %d bytes for url: %s%s",
len(img),
url,
+ context_suffix,
)
else:
logger.debug(
"Dashboard below tiling threshold "
"(%s charts, %spx height); using standard screenshot "
- "for url: %s",
+ "for url: %s%s",
chart_count,
dashboard_height,
url,
+ context_suffix,
)
# Standard screenshot captures the full element including
# below-the-fold content, so wait for all viewport-visible
@@ -604,28 +634,32 @@ class WebDriverPlaywright(WebDriverProxy):
)
if selenium_animation_wait > 0:
logger.debug(
- "Wait %i seconds for chart animation",
+ "Wait %i seconds for chart animation%s",
selenium_animation_wait,
+ context_suffix,
)
page.wait_for_timeout(selenium_animation_wait * 1000)
logger.debug(
- "Taking screenshot of url %s as user %s",
+ "Taking screenshot of url %s as user %s%s",
url,
user.username if user else "None",
+ context_suffix,
)
img = WebDriverPlaywright._get_screenshot(
page, element, element_name
)
logger.debug(
- "Screenshot result: %d bytes for url: %s",
+ "Screenshot result: %d bytes for url: %s%s",
len(img) if img else 0,
url,
+ context_suffix,
)
else:
logger.debug(
"Tiled screenshots disabled; using standard screenshot "
- "for url: %s",
+ "for url: %s%s",
url,
+ context_suffix,
)
# Standard screenshot captures the full element including
# below-the-fold content, so wait for all viewport-visible
@@ -640,29 +674,34 @@ class WebDriverPlaywright(WebDriverProxy):
)
if selenium_animation_wait > 0:
logger.debug(
- "Wait %i seconds for chart animation",
+ "Wait %i seconds for chart animation%s",
selenium_animation_wait,
+ context_suffix,
)
page.wait_for_timeout(selenium_animation_wait * 1000)
logger.debug(
- "Taking screenshot of url %s as user %s",
+ "Taking screenshot of url %s as user %s%s",
url,
user.username if user else "None",
+ context_suffix,
)
img = WebDriverPlaywright._get_screenshot(
page, element, element_name
)
logger.debug(
- "Screenshot result: %d bytes for url: %s",
+ "Screenshot result: %d bytes for url: %s%s",
len(img) if img else 0,
url,
+ context_suffix,
)
except PlaywrightTimeout:
raise
except PlaywrightError:
logger.exception(
- "Encountered an unexpected error when requesting url %s", url
+ "Encountered an unexpected error when requesting url %s%s",
+ url,
+ context_suffix,
)
finally:
context.close()
@@ -866,13 +905,18 @@ class WebDriverSelenium(WebDriverProxy):
self._driver = None
@staticmethod
- def find_unexpected_errors(driver: WebDriver) -> list[str]:
+ def find_unexpected_errors(
+ driver: WebDriver, log_context: str | None = None
+ ) -> list[str]:
error_messages = []
+ context_suffix = f" [{log_context}]" if log_context else ""
try:
alert_divs = driver.find_elements(By.XPATH, "//div[@role = 'alert']")
logger.debug(
- "%i alert elements have been found in the screenshot", len(alert_divs)
+ "%i alert elements have been found in the screenshot%s",
+ len(alert_divs),
+ context_suffix,
)
for alert_div in alert_divs:
@@ -915,9 +959,12 @@ class WebDriverSelenium(WebDriverProxy):
f"arguments[0].innerHTML = '{error_as_html}'", alert_div
)
except WebDriverException:
- logger.exception("Failed to update error messages using alert_div")
+ logger.exception(
+ "Failed to update error messages using alert_div%s",
+ context_suffix,
+ )
except WebDriverException:
- logger.exception("Failed to capture unexpected errors")
+ logger.exception("Failed to capture unexpected errors%s", context_suffix)
return error_messages
@@ -928,6 +975,7 @@ class WebDriverSelenium(WebDriverProxy):
user: User | None = None,
log_context: str | None = None,
) -> bytes | None:
+ context_suffix = f" [{log_context}]" if log_context else ""
# If a user is passed explicitly and differs from the stored user,
# update and re-authenticate
if user and user != self._user:
@@ -938,7 +986,7 @@ class WebDriverSelenium(WebDriverProxy):
driver.get(url)
img: bytes | None = None
selenium_headstart = app.config["SCREENSHOT_SELENIUM_HEADSTART"]
- logger.debug("Sleeping for %i seconds", selenium_headstart)
+ logger.debug("Sleeping for %i seconds%s", selenium_headstart, context_suffix)
sleep(selenium_headstart)
# WebDriver cleanup is intentionally not performed in this method. When the
@@ -949,27 +997,37 @@ class WebDriverSelenium(WebDriverProxy):
try:
# page didn't load
logger.debug(
- "Wait for the presence of %s at url: %s", element_name, url
+ "Wait for the presence of %s at url: %s%s",
+ element_name,
+ url,
+ context_suffix,
)
element = WebDriverWait(driver, self._screenshot_locate_wait).until(
EC.presence_of_element_located((By.CLASS_NAME, element_name))
)
except TimeoutException:
logger.warning(
- "Selenium timed out requesting url %s", url, exc_info=True
+ "Selenium timed out requesting url %s%s",
+ url,
+ context_suffix,
+ exc_info=True,
)
raise
try:
# chart containers didn't render
- logger.debug("Wait for chart containers to draw at url: %s", url)
+ logger.debug(
+ "Wait for chart containers to draw at url: %s%s",
+ url,
+ context_suffix,
+ )
WebDriverWait(driver, self._screenshot_locate_wait).until(
EC.visibility_of_all_elements_located(
(By.CLASS_NAME, "chart-container")
)
)
except TimeoutException:
- logger.info("Timeout Exception caught")
+ logger.info("Timeout Exception caught%s", context_suffix)
# Fallback to allow a screenshot of an empty dashboard
try:
WebDriverWait(driver, 0).until(
@@ -979,8 +1037,9 @@ class WebDriverSelenium(WebDriverProxy):
)
except Exception:
logger.warning(
- "Selenium timed out waiting for dashboard to draw at url %s",
+ "Selenium timed out waiting for dashboard to draw at url %s%s",
url,
+ context_suffix,
exc_info=True,
)
raise
@@ -988,36 +1047,47 @@ class WebDriverSelenium(WebDriverProxy):
try:
# charts took too long to load
logger.debug(
- "Wait for loading element of charts to be gone at url: %s", url
+ "Wait for loading element of charts to be gone at url: %s%s",
+ url,
+ context_suffix,
)
WebDriverWait(driver, self._screenshot_load_wait).until_not(
EC.presence_of_all_elements_located((By.CLASS_NAME, "loading"))
)
except TimeoutException:
logger.warning(
- "Selenium timed out waiting for charts to load at url %s",
+ "Selenium timed out waiting for charts to load at url %s%s",
url,
+ context_suffix,
exc_info=True,
)
raise
selenium_animation_wait = app.config["SCREENSHOT_SELENIUM_ANIMATION_WAIT"]
- logger.debug("Wait %i seconds for chart animation", selenium_animation_wait)
+ logger.debug(
+ "Wait %i seconds for chart animation%s",
+ selenium_animation_wait,
+ context_suffix,
+ )
sleep(selenium_animation_wait)
logger.debug(
- "Taking a PNG screenshot of url %s as user %s",
+ "Taking a PNG screenshot of url %s as user %s%s",
url,
self._user.username if self._user else "None",
+ context_suffix,
)
if app.config["SCREENSHOT_REPLACE_UNEXPECTED_ERRORS"]:
- unexpected_errors = WebDriverSelenium.find_unexpected_errors(driver)
+ unexpected_errors = WebDriverSelenium.find_unexpected_errors(
+ driver, log_context=log_context
+ )
if unexpected_errors:
logger.warning(
- "%i errors found in the screenshot. URL: %s. Errors are: %s",
+ "%i errors found in the screenshot. URL: %s. Errors are: %s%s",
len(unexpected_errors),
url,
unexpected_errors,
+ context_suffix,
)
img = element.screenshot_as_png
@@ -1026,19 +1096,21 @@ class WebDriverSelenium(WebDriverProxy):
raise
except StaleElementReferenceException:
logger.warning(
- "Selenium got a stale element while requesting url %s",
+ "Selenium got a stale element while requesting url %s%s",
url,
+ context_suffix,
exc_info=True,
)
raise
except WebDriverException:
logger.warning(
- "Encountered an unexpected error when requesting url %s",
+ "Encountered an unexpected error when requesting url %s%s",
url,
+ context_suffix,
exc_info=True,
)
raise
except Exception as ex:
- logger.warning("exception in webdriver", exc_info=ex)
+ logger.warning("exception in webdriver%s", context_suffix, exc_info=ex)
raise
return img
diff --git a/tests/unit_tests/utils/screenshot_test.py b/tests/unit_tests/utils/screenshot_test.py
index b7f7de6032e..b4032850d91 100644
--- a/tests/unit_tests/utils/screenshot_test.py
+++ b/tests/unit_tests/utils/screenshot_test.py
@@ -126,6 +126,27 @@ class TestComputeAndCache:
cache_payload: ScreenshotCachePayloadType = screenshot_obj.cache.get("key")
assert cache_payload["status"] == "Updated"
+ def test_passes_cache_key_log_context_to_capture(
+ self, mocker: MockerFixture, screenshot_obj
+ ):
+ """compute_and_cache must thread its cache_key into the capture layer
+ as log_context, so every webdriver/screenshot log line produced by a
+ thumbnail or direct-download run can be traced back to the exact
+ cached entry it was computing (reports already do this with their
+ execution_id)."""
+ mocks = self._setup_compute_and_cache(mocker, screenshot_obj)
+ cache_key = screenshot_obj.get_cache_key()
+ screenshot_obj.compute_and_cache(force=False)
+
+ get_screenshot: MagicMock = mocks.get("get_screenshot")
+ get_screenshot.assert_called_once()
+ assert (
+ get_screenshot.call_args.kwargs["log_context"] == f"cache_key={cache_key}"
+ )
+ resize_image: MagicMock = mocks.get("resize_image")
+ resize_image.assert_called_once()
+ assert resize_image.call_args.kwargs["log_context"] == f"cache_key={cache_key}"
+
def test_screenshot_error(self, mocker: MockerFixture, screenshot_obj):
mocks = self._setup_compute_and_cache(mocker, screenshot_obj)
get_screenshot: MagicMock = mocks.get("get_screenshot")
diff --git a/tests/unit_tests/utils/test_screenshot_utils.py b/tests/unit_tests/utils/test_screenshot_utils.py
index 43829001596..91351d3e0aa 100644
--- a/tests/unit_tests/utils/test_screenshot_utils.py
+++ b/tests/unit_tests/utils/test_screenshot_utils.py
@@ -231,10 +231,10 @@ class TestTakeTiledScreenshot:
# Should log dashboard dimensions with lazy logging format
mock_logger.info.assert_any_call(
- "Dashboard: %sx%spx at (%s, %s)", 800, 5000, 50, 100
+ "Dashboard: %sx%spx at (%s, %s)%s", 800, 5000, 50, 100, ""
)
# Should log number of tiles with lazy logging format
- mock_logger.info.assert_any_call("Taking %s screenshot tiles", 3)
+ mock_logger.info.assert_any_call("Taking %s screenshot tiles%s", 3, "")
def test_exception_handling_returns_none(self):
"""Test that exceptions are handled and None is returned."""
diff --git a/tests/unit_tests/utils/webdriver_test.py b/tests/unit_tests/utils/webdriver_test.py
index c6fa18e9dc9..9e92c5aba59 100644
--- a/tests/unit_tests/utils/webdriver_test.py
+++ b/tests/unit_tests/utils/webdriver_test.py
@@ -627,7 +627,7 @@ class TestWebDriverPlaywrightErrorHandling:
assert result == []
mock_logger.exception.assert_called_once_with(
- "Failed to capture unexpected errors"
+ "Failed to capture unexpected errors%s", ""
)
@patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True)
@@ -838,7 +838,7 @@ class TestWebDriverPlaywrightErrorHandling:
# not installed) accepting unrelated exceptions.
assert exc_info.value is timeout
mock_logger.exception.assert_any_call(
- "Timed out requesting url %s", "http://example.com"
+ "Timed out requesting url %s%s", "http://example.com", ""
)
@patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True)
@@ -920,10 +920,12 @@ class TestWebDriverPlaywrightErrorHandling:
assert result == b"fake_screenshot"
mock_logger.warning.assert_any_call(
- "Could not determine dashboard height for element %s at url %s; "
- "falling back to standard screenshot behavior",
+ "Could not determine dashboard height for element %s "
+ "at url %s; falling back to standard screenshot "
+ "behavior%s",
"dashboard",
"http://example.com",
+ "",
)
@patch("superset.utils.webdriver.PLAYWRIGHT_AVAILABLE", True)
@@ -999,8 +1001,9 @@ class TestWebDriverPlaywrightErrorHandling:
mock_element.screenshot.assert_not_called()
mock_logger.warning.assert_any_call(
"Tiled screenshot failed for url %s and no safe fallback "
- "exists; failing the capture",
+ "exists; failing the capture%s",
"http://example.com",
+ "",
)