bito-code-review[bot] commented on code in PR #42624:
URL: https://github.com/apache/superset/pull/42624#discussion_r3694423638
##########
superset/commands/report/execute.py:
##########
@@ -123,6 +131,137 @@ def resolve_executor_user(model: ReportSchedule) ->
tuple["User", str]:
return user, username
+def log_report_delivery_phase(
+ report_context: ReportExecutionContext | None,
+ recipient_type: ReportRecipientType | None,
+ phase: str,
+ *,
+ enforce_budget: bool,
+) -> None:
+ """Enforce and log a notification phase when executing a report."""
+
+ if report_context is None:
+ return
+ deadline = report_context.deadline
+ if enforce_budget:
+ deadline.timeout_seconds(
+ "notification_delivery",
+ reserve_seconds=report_context.cleanup_reserve_seconds,
+ )
+ logger.info(
+ "report_delivery_%s %s recipient_type=%s elapsed_seconds=%.2f "
+ "remaining_seconds=%.2f",
+ phase,
+ report_context.log_context,
+ recipient_type,
+ deadline.elapsed_seconds,
+ deadline.remaining_seconds,
+ )
+
+
Review Comment:
<!-- Bito Reply -->
The suggestion to add unit tests for `log_report_delivery_phase` is
appropriate. Adding these tests ensures that the function's logic—specifically
the conditional budget enforcement and the logging behavior—is verified and
protected against future regressions.
##########
superset/utils/webdriver.py:
##########
@@ -982,57 +1247,193 @@ def get_screenshot( # noqa: C901
logger.debug(
"Wait for the presence of %s at url: %s", element_name, url
)
- element = WebDriverWait(driver,
self._screenshot_locate_wait).until(
- EC.presence_of_element_located((By.CLASS_NAME,
element_name))
- )
+ element = WebDriverWait(
+ driver,
+ phase_timeout(
+ "dashboard_mount",
+ self._screenshot_locate_wait,
+ (
+ report_execution_context.readiness_reserve_seconds
+ if report_execution_context
+ else 0.0
+ ),
+ ),
+ ).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
)
raise
- try:
- # chart containers didn't render
- logger.debug("Wait for chart containers to draw at url: %s",
url)
- WebDriverWait(driver, self._screenshot_locate_wait).until(
- EC.visibility_of_all_elements_located(
- (By.CLASS_NAME, "chart-container")
- )
+ if report_execution_context and element_name in {
+ "standalone",
+ "chart-container",
+ }:
+ readiness_predicate = (
+ REPORT_CHART_HOLDERS_READY_JS
+ if element_name == "standalone"
+ else CHART_CONTAINER_READY_JS
+ )
+ readiness_timeout = phase_timeout(
+ "chart_readiness",
+ None,
+ report_execution_context.readiness_reserve_seconds,
)
- except TimeoutException:
- logger.info("Timeout Exception caught")
- # Fallback to allow a screenshot of an empty dashboard
try:
- WebDriverWait(driver, 0).until(
+ WebDriverWait(driver, readiness_timeout).until(
+ lambda webdriver: webdriver.execute_script(
+ f"return ({readiness_predicate})()"
+ )
+ )
+ holder_states = (
+ driver.execute_script(
+ f"return ({FIND_CHART_HOLDER_STATES_JS})()"
+ )
+ if element_name == "standalone"
+ else [
+ {
+ "chartId": report_execution_context.chart_id,
+ "state": "rendered",
+ }
+ ]
+ )
+ ready_states = {"rendered", "empty", "error",
"virtualized"}
+ deadline = report_execution_context.deadline
+ logger.info(
+ "report_readiness_ready url=%s expected_holders=%s "
+ "mounted_holders=%s ready_holders=%s
elapsed_seconds=%s "
+ "remaining_seconds=%s%s",
+ url,
+ report_execution_context.expected_chart_count,
+ len(holder_states),
+ sum(
+ holder.get("state") in ready_states
+ for holder in holder_states
+ ),
+ (f"{deadline.elapsed_seconds:.2f}" if deadline else
None),
Review Comment:
<!-- Bito Reply -->
The suggestion to remove the conditional guard is appropriate. Since
`deadline` is assigned unconditionally from `report_execution_context.deadline`
on line 1301, the `if deadline else None` check on line 1313 is redundant and
can be simplified to direct attribute access.
**superset/utils/webdriver.py**
```
(f"{deadline.elapsed_seconds:.2f}" if deadline else None),
```
##########
superset/commands/report/execute.py:
##########
@@ -123,6 +131,137 @@ def resolve_executor_user(model: ReportSchedule) ->
tuple["User", str]:
return user, username
+def log_report_delivery_phase(
+ report_context: ReportExecutionContext | None,
+ recipient_type: ReportRecipientType | None,
+ phase: str,
+ *,
+ enforce_budget: bool,
+) -> None:
+ """Enforce and log a notification phase when executing a report."""
+
+ if report_context is None:
+ return
+ deadline = report_context.deadline
+ if enforce_budget:
+ deadline.timeout_seconds(
+ "notification_delivery",
+ reserve_seconds=report_context.cleanup_reserve_seconds,
+ )
+ logger.info(
+ "report_delivery_%s %s recipient_type=%s elapsed_seconds=%.2f "
+ "remaining_seconds=%.2f",
+ phase,
+ report_context.log_context,
+ recipient_type,
+ deadline.elapsed_seconds,
+ deadline.remaining_seconds,
+ )
+
+
+def persist_owned_report_execution_terminal_error(
+ report_schedule_id: int,
+ execution_id: UUID,
+ error_message: str,
+ terminal_reason: str,
+ report_context: ReportExecutionContext | None = None,
+) -> bool:
+ """
+ Terminalize this command's WORKING row from its application-owned boundary.
+
+ Report states normally persist their terminal result before re-raising. If
+ that first write loses its transaction or database connection, the command
+ boundary is the last safe in-process retry: it still has Flask application
+ context and knows the execution UUID it owns. A compare against the latest
+ active WORKING row prevents an old worker from changing the schedule state
+ after a newer execution has started.
+ """
+
+ try:
+ # The state-machine transaction has already rolled back on its way to
+ # this boundary. Roll back again so a failed terminal flush cannot
leave
+ # the scoped session unusable for the retry.
+ db.session.rollback() # pylint: disable=consider-using-transaction
+ working_log = (
+ db.session.query(ReportExecutionLog)
+ .filter(
+ ReportExecutionLog.report_schedule_id == report_schedule_id,
+ ReportExecutionLog.uuid == execution_id,
+ ReportExecutionLog.state == ReportState.WORKING,
+ ReportExecutionLog.error_message.is_(None),
+ )
+ .first()
+ )
+ if working_log is None:
+ return False
+
+ latest_working_log = (
+ db.session.query(ReportExecutionLog)
+ .filter(
+ ReportExecutionLog.report_schedule_id == report_schedule_id,
+ ReportExecutionLog.state == ReportState.WORKING,
+ ReportExecutionLog.error_message.is_(None),
+ )
+ .order_by(ReportExecutionLog.end_dttm.desc())
+ .first()
+ )
+ report_schedule = working_log.report_schedule
+ owns_schedule_state = (
+ report_schedule.last_state == ReportState.WORKING
+ and latest_working_log is not None
+ and latest_working_log.uuid == execution_id
+ )
+ ended_at = datetime.now(timezone.utc).replace(tzinfo=None)
+ working_log.state = ReportState.ERROR
+ working_log.error_message = error_message
+ working_log.end_dttm = ended_at
+ if owns_schedule_state:
+ report_schedule.last_state = ReportState.ERROR
+ report_schedule.last_eval_dttm = ended_at
+
+ db.session.commit() # pylint: disable=consider-using-transaction
+ log_context = (
+ report_context.log_context
+ if report_context is not None
+ else (
+ f"capture_kind=report execution_id={execution_id} "
+ f"report_schedule_id={report_schedule_id} "
+ f"dashboard_id={report_schedule.dashboard_id} "
+ f"chart_id={report_schedule.chart_id}"
+ )
+ )
+ elapsed_seconds = (
+ f"{report_context.deadline.elapsed_seconds:.2f}"
+ if report_context is not None
+ else "unknown"
+ )
+ remaining_seconds = (
+ f"{report_context.deadline.remaining_seconds:.2f}"
+ if report_context is not None
+ else "unknown"
+ )
+ logger.info(
+ "report_execution_terminal %s state=%s terminal_reason=%s "
+ "elapsed_seconds=%s remaining_seconds=%s",
+ log_context,
+ ReportState.ERROR.value,
+ terminal_reason,
+ elapsed_seconds,
+ remaining_seconds,
+ )
+ return True
+ except Exception: # noqa: BLE001 # never mask the report's original
exception
+ db.session.rollback() # pylint: disable=consider-using-transaction
+ logger.exception(
+ "Failed terminal persistence retry for report execution "
+ "capture_kind=report execution_id=%s report_schedule_id=%s "
+ "terminal_reason=terminal_persistence_retry_failed",
+ execution_id,
+ report_schedule_id,
+ )
+ return False
Review Comment:
<!-- Bito Reply -->
The suggestion to add a test for the exception handler in
`persist_owned_report_execution_terminal_error` is appropriate. Exercising the
`except Exception` block at line 253 is necessary to verify that the session
rollback and the `terminal_persistence_retry_failed` exception logging occur as
expected when terminal persistence fails.
**superset/commands/report/execute.py**
```
except Exception: # noqa: BLE001 # never mask the report's original
exception
db.session.rollback() # pylint: disable=consider-using-transaction
logger.exception(
"Failed terminal persistence retry for report execution "
"capture_kind=report execution_id=%s report_schedule_id=%s "
"terminal_reason=terminal_persistence_retry_failed",
execution_id,
report_schedule_id,
)
return False
```
##########
superset/utils/webdriver.py:
##########
@@ -982,57 +1247,193 @@ def get_screenshot( # noqa: C901
logger.debug(
"Wait for the presence of %s at url: %s", element_name, url
)
- element = WebDriverWait(driver,
self._screenshot_locate_wait).until(
- EC.presence_of_element_located((By.CLASS_NAME,
element_name))
- )
+ element = WebDriverWait(
+ driver,
+ phase_timeout(
+ "dashboard_mount",
+ self._screenshot_locate_wait,
+ (
+ report_execution_context.readiness_reserve_seconds
+ if report_execution_context
+ else 0.0
+ ),
+ ),
+ ).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
)
raise
- try:
- # chart containers didn't render
- logger.debug("Wait for chart containers to draw at url: %s",
url)
- WebDriverWait(driver, self._screenshot_locate_wait).until(
- EC.visibility_of_all_elements_located(
- (By.CLASS_NAME, "chart-container")
- )
+ if report_execution_context and element_name in {
+ "standalone",
+ "chart-container",
+ }:
+ readiness_predicate = (
+ REPORT_CHART_HOLDERS_READY_JS
+ if element_name == "standalone"
+ else CHART_CONTAINER_READY_JS
+ )
+ readiness_timeout = phase_timeout(
+ "chart_readiness",
+ None,
+ report_execution_context.readiness_reserve_seconds,
)
- except TimeoutException:
- logger.info("Timeout Exception caught")
- # Fallback to allow a screenshot of an empty dashboard
try:
- WebDriverWait(driver, 0).until(
+ WebDriverWait(driver, readiness_timeout).until(
+ lambda webdriver: webdriver.execute_script(
+ f"return ({readiness_predicate})()"
+ )
+ )
+ holder_states = (
+ driver.execute_script(
+ f"return ({FIND_CHART_HOLDER_STATES_JS})()"
+ )
+ if element_name == "standalone"
+ else [
+ {
+ "chartId": report_execution_context.chart_id,
+ "state": "rendered",
+ }
+ ]
+ )
+ ready_states = {"rendered", "empty", "error",
"virtualized"}
+ deadline = report_execution_context.deadline
+ logger.info(
+ "report_readiness_ready url=%s expected_holders=%s "
+ "mounted_holders=%s ready_holders=%s
elapsed_seconds=%s "
+ "remaining_seconds=%s%s",
+ url,
+ report_execution_context.expected_chart_count,
+ len(holder_states),
+ sum(
+ holder.get("state") in ready_states
+ for holder in holder_states
+ ),
+ (f"{deadline.elapsed_seconds:.2f}" if deadline else
None),
+ (f"{deadline.remaining_seconds:.2f}" if deadline else
None),
+ f" [{log_context}]" if log_context else "",
+ )
+ except TimeoutException:
+ holder_states = (
+ driver.execute_script(
+ f"return ({FIND_CHART_HOLDER_STATES_JS})()"
+ )
+ if element_name == "standalone"
+ else [
+ {
+ "chartId": report_execution_context.chart_id,
+ "state": "not_ready",
+ }
+ ]
+ )
+ ready_states = {"rendered", "empty", "error",
"virtualized"}
+ ready_holders = sum(
+ holder.get("state") in ready_states for holder in
holder_states
+ )
+ deadline = report_execution_context.deadline
+ logger.warning(
+ "report_readiness_terminal url=%s expected_holders=%s "
+ "mounted_holders=%s ready_holders=%s
elapsed_seconds=%s "
+ "remaining_seconds=%s effective_wait_seconds=%.2f%s "
+ "terminal_reason=readiness_timeout states=%s; "
+ "aborting before capture or delivery",
+ url,
+ report_execution_context.expected_chart_count,
+ len(holder_states),
+ ready_holders,
+ (f"{deadline.elapsed_seconds:.2f}" if deadline else
None),
Review Comment:
<!-- Bito Reply -->
The suggestion to remove the `if deadline else None` guard is correct. Since
`deadline` is unconditionally assigned on line 1334, the conditional check is
redundant and can be simplified to direct attribute access.
**superset/utils/webdriver.py**
```
(f"{deadline.elapsed_seconds:.2f}" if deadline else None),
(f"{deadline.remaining_seconds:.2f}" if deadline
else None),
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
