-
Notifications
You must be signed in to change notification settings - Fork 18k
fix(reports): time-budget tiled screenshot to fail cleanly instead of hitting Celery kill #42118
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -87,6 +87,29 @@ def resolve_screenshot_task_budget_seconds( | |
| return None | ||
|
|
||
|
|
||
| # Fallback wall-clock budget, in seconds, for the entire tiled-screenshot | ||
| # operation (element lookup plus all per-tile readiness/animation waits | ||
| # combined), used when resolve_screenshot_task_budget_seconds() returns None | ||
| # (no Celery task context -- e.g. synchronous thumbnail generation -- or no | ||
| # usable task limit). The non-tiled readiness path treats None as "keep the | ||
| # configured SCREENSHOT_LOAD_WAIT" because it makes exactly one bounded wait; | ||
| # the tiled path cannot, because its per-tile waits accumulate: with N tiles, | ||
| # an uncapped load_wait allows N * load_wait of total wall-clock time, so the | ||
| # operation still needs one fixed total ceiling. Sized against the longest | ||
| # Celery hard task_time_limit observed in production for report execution | ||
| # (1740s), minus the same 300s cleanup margin the runtime derivation reserves | ||
| # for combining tiles, building the PDF, and delivering the notification. | ||
| TILED_SCREENSHOT_TOTAL_WAIT_BUDGET_SECONDS = 1440 # 1740s limit - 300s margin | ||
|
|
||
|
|
||
| class ScreenshotTaskBudgetExceededError(RuntimeError): | ||
| """Raised when no safe task budget remains before screenshot capture.""" | ||
|
|
||
|
|
||
| class TiledScreenshotBudgetExceededError(ScreenshotTaskBudgetExceededError): | ||
| """Raised when the tiled-screenshot time budget runs out mid-capture.""" | ||
|
|
||
|
|
||
| try: | ||
| from playwright.sync_api import TimeoutError as PlaywrightTimeout | ||
| except ImportError: | ||
|
|
@@ -251,7 +274,7 @@ def combine_screenshot_tiles(screenshot_tiles: list[bytes]) -> bytes: | |
| return screenshot_tiles[0] | ||
|
|
||
|
|
||
| def take_tiled_screenshot( | ||
| def take_tiled_screenshot( # noqa: C901 | ||
| page: "Page", | ||
| element_name: str, | ||
| tile_height: int, | ||
|
|
@@ -274,6 +297,12 @@ def take_tiled_screenshot( | |
|
|
||
| Returns: | ||
| Combined screenshot bytes or None if failed | ||
|
|
||
| Raises: | ||
| TiledScreenshotBudgetExceededError: If the total time budget for the | ||
| tiled-screenshot operation runs out before every tile has been | ||
| verifiably captured. Callers must treat this as a hard failure | ||
| rather than fall back to an unchecked/partial screenshot. | ||
| """ | ||
| context_suffix = f" [{log_context}]" if log_context else "" | ||
| # Set right before re-raising the per-tile readiness timeout below, and | ||
|
|
@@ -286,6 +315,15 @@ def take_tiled_screenshot( | |
| # match `except PlaywrightTimeout` and incorrectly propagate instead of | ||
| # degrading to `None` like every other unexpected error in this function. | ||
| readiness_timeout = False | ||
| # Cap the whole tiled operation against the running Celery task's own | ||
| # time limit, using the same runtime derivation as the non-tiled | ||
| # readiness wait (#42253/#42427). Unlike that path, a None budget does | ||
| # not mean "keep the configured timeout": per-tile waits accumulate, so | ||
| # the operation falls back to a fixed total ceiling instead. | ||
| wait_budget_seconds = resolve_screenshot_task_budget_seconds(log_context) | ||
| if wait_budget_seconds is None: | ||
| wait_budget_seconds = float(TILED_SCREENSHOT_TOTAL_WAIT_BUDGET_SECONDS) | ||
| start_time = time.monotonic() | ||
| try: | ||
| # Get the target element | ||
| element = page.locator(f".{element_name}") | ||
|
|
@@ -320,9 +358,44 @@ def take_tiled_screenshot( | |
| num_tiles = max(1, (dashboard_height + tile_height - 1) // tile_height) | ||
| logger.info("Taking %s screenshot tiles", num_tiles) | ||
|
|
||
| screenshot_tiles = [] | ||
| screenshot_tiles: list[bytes] = [] | ||
|
|
||
| def _raise_if_budget_exhausted(elapsed: float, remaining_budget: float) -> None: | ||
| if remaining_budget > 0: | ||
| return | ||
| # A customer-side chart-loading issue (a slow/hung dashboard), | ||
| # not a Superset system fault, so this is a WARNING rather | ||
| # than an ERROR -- consistent with #38130/#38441, which | ||
| # deliberately downgraded screenshot timeout logs the same way. | ||
| logger.warning( | ||
| "Tiled screenshot time budget exhausted on tile %s/%s: " | ||
| "%s/%s tiles captured so far, %.1fs elapsed of a %.1fs " | ||
| "budget. Aborting instead of capturing remaining tiles " | ||
| "unchecked.%s", | ||
| i + 1, | ||
| num_tiles, | ||
| len(screenshot_tiles), | ||
| num_tiles, | ||
| elapsed, | ||
| wait_budget_seconds, | ||
| context_suffix, | ||
| ) | ||
| raise TiledScreenshotBudgetExceededError( | ||
| f"Tiled screenshot budget of " | ||
| f"{wait_budget_seconds:.1f}s exhausted " | ||
| f"after {len(screenshot_tiles)}/{num_tiles} tiles" | ||
| ) | ||
|
|
||
| for i in range(num_tiles): | ||
| # Check the time budget before starting this tile's readiness wait. | ||
| # If it's already exhausted, we can no longer verify this (or any | ||
| # later) tile is actually ready to capture -- fail loudly instead | ||
| # of silently snapshotting a spinner or blank chart, or running | ||
| # past the Celery task time limit and getting SIGKILLed. | ||
| elapsed = time.monotonic() - start_time | ||
| remaining_budget = wait_budget_seconds - elapsed | ||
| _raise_if_budget_exhausted(elapsed, remaining_budget) | ||
|
|
||
| # Calculate scroll position to show this tile's content | ||
| scroll_y = dashboard_top + (i * tile_height) | ||
|
|
||
|
|
@@ -332,17 +405,31 @@ def take_tiled_screenshot( | |
| ) | ||
| # Wait for scroll to settle and content to load | ||
| page.wait_for_timeout(SCROLL_SETTLE_TIMEOUT_MS) | ||
|
|
||
| # Recompute the remaining budget after the scroll-settle sleep -- | ||
| # which itself consumes real wall-clock time -- rather than | ||
| # reusing the value from before it, so the readiness-check | ||
| # timeout below is capped against a fresh number instead of a | ||
| # stale one that would let each tile overrun the budget by up | ||
| # to one settle interval. | ||
| tile_wait_start = time.monotonic() | ||
| elapsed = tile_wait_start - start_time | ||
| remaining_budget = wait_budget_seconds - elapsed | ||
| _raise_if_budget_exhausted(elapsed, remaining_budget) | ||
|
|
||
| # Wait for every chart holder visible in the current viewport to reach | ||
| # a terminal state (rendered chart or error/empty state). Only check | ||
| # a terminal state (rendered chart or error/empty state), capped at | ||
| # whatever remains of the total time budget so a slow dashboard | ||
| # degrades gracefully instead of exceeding it. Only check | ||
| # viewport-visible chart holders to avoid blocking on virtualization | ||
| # placeholders rendered for off-screen charts. A holder that hasn't | ||
| # mounted anything yet does not satisfy this check -- unlike checking | ||
| # for the absence of `.loading`, which passes vacuously in that case. | ||
| tile_wait_start = time.monotonic() | ||
| tile_load_wait = min(load_wait, remaining_budget) | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Suggestion: The spinner timeout is derived from a stale remaining-budget value that was computed before the mandatory scroll-settle sleep. This lets each tile wait up to one extra settle interval beyond the declared global budget, so total runtime can still exceed the intended cap. Recompute the remaining budget immediately before Severity Level: Major
|
||
| try: | ||
| page.wait_for_function( | ||
| CHART_HOLDERS_READY_JS, | ||
| timeout=load_wait * 1000, | ||
| timeout=tile_load_wait * 1000, | ||
| ) | ||
| except PlaywrightTimeout: | ||
| elapsed = time.monotonic() - tile_wait_start | ||
|
|
@@ -354,14 +441,21 @@ def take_tiled_screenshot( | |
| # made the same call for the other screenshot timeout paths. | ||
| logger.warning( | ||
| "Timed out after %.2fs waiting for %s chart container(s) to " | ||
| "become ready on tile %s/%s (load_wait=%ss)%s; unready chart " | ||
| "holders (chart id, state): %s. Aborting tiled screenshot " | ||
| "rather than capturing a blank or partially-loaded tile.", | ||
| "become ready on tile %s/%s (waited %.1fs of a %ss requested " | ||
| "load_wait; %.1fs elapsed of a %.1fs total budget; %s/%s " | ||
| "tiles captured so far)%s; unready chart holders (chart id, " | ||
| "state): %s. Aborting tiled screenshot rather than capturing " | ||
| "a blank or partially-loaded tile.", | ||
| elapsed, | ||
| len(unready_chart_holders), | ||
| i + 1, | ||
| num_tiles, | ||
| tile_load_wait, | ||
| load_wait, | ||
| time.monotonic() - start_time, | ||
| wait_budget_seconds, | ||
| len(screenshot_tiles), | ||
| num_tiles, | ||
| context_suffix, | ||
| unready_chart_holders, | ||
| ) | ||
|
|
@@ -377,12 +471,36 @@ def take_tiled_screenshot( | |
| load_wait, | ||
| context_suffix, | ||
| ) | ||
| readiness_wait_elapsed = time.monotonic() - tile_wait_start | ||
|
|
||
| # Wait for chart animations (e.g. ECharts) to finish after spinner clears. | ||
| # The global animation wait before tiling only covers the first tile; | ||
| # subsequent tiles need their own wait after data loads. | ||
| # subsequent tiles need their own wait after data loads. Capped at | ||
| # whatever remains of the budget; unlike the readiness wait above this | ||
| # is cosmetic settling, not a readiness check, so we simply skip it | ||
| # (rather than raise) once the budget runs out. | ||
| animation_wait_elapsed = 0.0 | ||
| if animation_wait > 0: | ||
| page.wait_for_timeout(animation_wait * 1000) | ||
| elapsed = time.monotonic() - start_time | ||
| remaining_budget = wait_budget_seconds - elapsed | ||
| tile_animation_wait = max(0, min(animation_wait, remaining_budget)) | ||
| if tile_animation_wait > 0: | ||
| animation_wait_start = time.monotonic() | ||
| page.wait_for_timeout(tile_animation_wait * 1000) | ||
| animation_wait_elapsed = time.monotonic() - animation_wait_start | ||
|
Comment on lines
+482
to
+490
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Suggestion: After the capped animation wait completes, the code proceeds directly to Severity Level: Major
|
||
|
|
||
| # Per-tile timing breakdown so slow dashboards can be profiled from | ||
| # logs alone. DEBUG rather than INFO: this fires once per tile, and | ||
| # large dashboards can have dozens of tiles per report run. | ||
| logger.debug( | ||
| "Tile %s/%s timing: %.2fs waiting for chart readiness, " | ||
| "%.2fs waiting for animations.%s", | ||
| i + 1, | ||
| num_tiles, | ||
| readiness_wait_elapsed, | ||
| animation_wait_elapsed, | ||
| context_suffix, | ||
| ) | ||
|
|
||
| # Calculate what portion of the element we want to capture for this tile | ||
| tile_start_in_element = i * tile_height | ||
|
|
@@ -431,6 +549,12 @@ def take_tiled_screenshot( | |
|
|
||
| return combined_screenshot | ||
|
|
||
| except TiledScreenshotBudgetExceededError: | ||
| # Budget exhaustion must fail cleanly, not be swallowed into the | ||
| # generic `return None` degradation below -- the raise carries the | ||
| # budget diagnostics to the caller, which fails the capture loudly | ||
| # (#42273) instead of receiving an anonymous empty result. | ||
| raise | ||
| except Exception as e: | ||
| if readiness_timeout: | ||
| # Let the per-tile readiness timeout propagate so the caller | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
🟡 Non-blocking (owner's call) — tiled budget clock resets instead of accounting for pre-capture time.
wait_budget_secondsis derived from the Celery task limit, but elapsed is measured from this localstart_time, sopage.goto(bounded 60s), the 3sSELENIUM_HEADSTART, the 30selement.wait_for, and dimension probing all run before the clock starts — the tiled path effectively gets a fresh full budget. The non-tiled_wait_for_charts_readyavoids this by threadingscreenshot_started_atfrom the top ofget_screenshotand subtracting already-elapsed time; the tiled call site doesn't pass it.Not a correctness bug: in the common case the 20%/300s margin (and the soft→hard gap) absorbs the difference, and a soft-limit overrun is still caught cleanly as
SoftTimeLimitExceededrather than the SIGKILL this PR targets. It's just a looser guarantee than the non-tiled path — worth a conscious decision.If you want both paths on one clock, it's 3 coordinated one-liners (⚠️ applying the suggestion below alone will
NameErroruntil the other two land):screenshot_started_at: float | None = Noneto thetake_tiled_screenshotsignature;screenshot_started_at=screenshot_started_atfrom thetake_tiled_screenshot(...)call inwebdriver.py.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Good catch, and agreed it deserved both-paths-on-one-clock: implemented exactly as suggested (all three coordinated changes) in follow-up #42661, with tests pinning that pre-capture elapsed time now reduces the first tile's capped wait, and that the omitted-anchor default is unchanged.