Add timing logs to page readiness checks (#4582)
This commit is contained in:
@@ -589,28 +589,84 @@ class SkyvernFrame:
|
|||||||
This is designed for cached action execution to ensure the page is ready
|
This is designed for cached action execution to ensure the page is ready
|
||||||
before attempting to interact with elements.
|
before attempting to interact with elements.
|
||||||
"""
|
"""
|
||||||
|
total_start_time = time.time()
|
||||||
|
|
||||||
# 1. Wait for loading indicators to disappear (longest timeout first)
|
# 1. Wait for loading indicators to disappear (longest timeout first)
|
||||||
|
loading_indicator_duration_ms = 0.0
|
||||||
|
step_start_time = time.time()
|
||||||
|
loading_indicator_result = "success"
|
||||||
try:
|
try:
|
||||||
await self._wait_for_loading_indicators_gone(timeout_ms=loading_indicator_timeout_ms)
|
await self._wait_for_loading_indicators_gone(timeout_ms=loading_indicator_timeout_ms)
|
||||||
except (TimeoutError, asyncio.TimeoutError):
|
except (TimeoutError, asyncio.TimeoutError):
|
||||||
|
loading_indicator_result = "timeout"
|
||||||
LOG.warning("Loading indicator timeout - some indicators may still be present, proceeding")
|
LOG.warning("Loading indicator timeout - some indicators may still be present, proceeding")
|
||||||
except Exception:
|
except Exception:
|
||||||
|
loading_indicator_result = "error"
|
||||||
LOG.warning("Failed to check loading indicators, proceeding", exc_info=True)
|
LOG.warning("Failed to check loading indicators, proceeding", exc_info=True)
|
||||||
|
finally:
|
||||||
|
loading_indicator_duration_ms = (time.time() - step_start_time) * 1000
|
||||||
|
LOG.info(
|
||||||
|
"page_readiness_check",
|
||||||
|
step="loading_indicators",
|
||||||
|
result=loading_indicator_result,
|
||||||
|
duration_ms=loading_indicator_duration_ms,
|
||||||
|
timeout_ms=loading_indicator_timeout_ms,
|
||||||
|
)
|
||||||
|
|
||||||
# 2. Wait for network idle (with short timeout - some pages never go idle)
|
# 2. Wait for network idle (with short timeout - some pages never go idle)
|
||||||
|
network_idle_duration_ms = 0.0
|
||||||
|
step_start_time = time.time()
|
||||||
|
network_idle_result = "success"
|
||||||
try:
|
try:
|
||||||
await self.frame.wait_for_load_state("networkidle", timeout=network_idle_timeout_ms)
|
await self.frame.wait_for_load_state("networkidle", timeout=network_idle_timeout_ms)
|
||||||
LOG.debug("Network idle achieved")
|
|
||||||
except (TimeoutError, asyncio.TimeoutError):
|
except (TimeoutError, asyncio.TimeoutError):
|
||||||
|
network_idle_result = "timeout"
|
||||||
LOG.warning("Network idle timeout - page may have constant activity, proceeding")
|
LOG.warning("Network idle timeout - page may have constant activity, proceeding")
|
||||||
|
finally:
|
||||||
|
network_idle_duration_ms = (time.time() - step_start_time) * 1000
|
||||||
|
LOG.info(
|
||||||
|
"page_readiness_check",
|
||||||
|
step="network_idle",
|
||||||
|
result=network_idle_result,
|
||||||
|
duration_ms=network_idle_duration_ms,
|
||||||
|
timeout_ms=network_idle_timeout_ms,
|
||||||
|
)
|
||||||
|
|
||||||
# 3. Wait for DOM to stabilize
|
# 3. Wait for DOM to stabilize
|
||||||
|
dom_stability_duration_ms = 0.0
|
||||||
|
step_start_time = time.time()
|
||||||
|
dom_stability_result = "success"
|
||||||
try:
|
try:
|
||||||
await self._wait_for_dom_stable(stable_ms=dom_stable_ms, timeout_ms=dom_stability_timeout_ms)
|
await self._wait_for_dom_stable(stable_ms=dom_stable_ms, timeout_ms=dom_stability_timeout_ms)
|
||||||
except (TimeoutError, asyncio.TimeoutError):
|
except (TimeoutError, asyncio.TimeoutError):
|
||||||
|
dom_stability_result = "timeout"
|
||||||
LOG.warning("DOM stability timeout - DOM may still be changing, proceeding")
|
LOG.warning("DOM stability timeout - DOM may still be changing, proceeding")
|
||||||
except Exception:
|
except Exception:
|
||||||
|
dom_stability_result = "error"
|
||||||
LOG.warning("Failed to check DOM stability, proceeding", exc_info=True)
|
LOG.warning("Failed to check DOM stability, proceeding", exc_info=True)
|
||||||
|
finally:
|
||||||
|
dom_stability_duration_ms = (time.time() - step_start_time) * 1000
|
||||||
|
LOG.info(
|
||||||
|
"page_readiness_check",
|
||||||
|
step="dom_stability",
|
||||||
|
result=dom_stability_result,
|
||||||
|
duration_ms=dom_stability_duration_ms,
|
||||||
|
timeout_ms=dom_stability_timeout_ms,
|
||||||
|
stable_ms=dom_stable_ms,
|
||||||
|
)
|
||||||
|
|
||||||
|
# Log total page readiness check duration
|
||||||
|
total_duration_ms = (time.time() - total_start_time) * 1000
|
||||||
|
LOG.info(
|
||||||
|
"page_readiness_check_complete",
|
||||||
|
total_duration_ms=total_duration_ms,
|
||||||
|
loading_indicator_duration_ms=loading_indicator_duration_ms,
|
||||||
|
network_idle_duration_ms=network_idle_duration_ms,
|
||||||
|
dom_stability_duration_ms=dom_stability_duration_ms,
|
||||||
|
loading_indicator_result=loading_indicator_result,
|
||||||
|
network_idle_result=network_idle_result,
|
||||||
|
dom_stability_result=dom_stability_result,
|
||||||
|
)
|
||||||
|
|
||||||
async def _wait_for_loading_indicators_gone(self, timeout_ms: float = 5000) -> None:
|
async def _wait_for_loading_indicators_gone(self, timeout_ms: float = 5000) -> None:
|
||||||
"""
|
"""
|
||||||
|
|||||||
Reference in New Issue
Block a user