diff --git a/skyvern/forge/agent.py b/skyvern/forge/agent.py index 7fc183b4d..eb660436b 100644 --- a/skyvern/forge/agent.py +++ b/skyvern/forge/agent.py @@ -2969,7 +2969,7 @@ class ForgeAgent: skyvern_frame: SkyvernFrame | None = None try: skyvern_frame = await SkyvernFrame.create_instance(frame=working_page) - await skyvern_frame.safe_wait_for_animation_end() + await skyvern_frame.safe_wait_for_animation_end(caller="post_action_artifact") except Exception: LOG.info("Failed to wait for animation end, ignore it", exc_info=True) diff --git a/skyvern/webeye/actions/handler.py b/skyvern/webeye/actions/handler.py index 6194998ea..062f58aa2 100644 --- a/skyvern/webeye/actions/handler.py +++ b/skyvern/webeye/actions/handler.py @@ -1351,7 +1351,7 @@ async def handle_click_action( LOG.info( "The element has onclick attribute, waiting for 1 second to load new elements", action=action ) - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=1) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=1, caller="click.onclick") if sequential_click_result := await handle_sequential_click_for_dropdown( action=action, @@ -1406,7 +1406,7 @@ async def handle_sequential_click_for_dropdown( if await incremental_scraped.get_incremental_elements_num() == 0: return None - await skyvern_frame.safe_wait_for_animation_end() + await skyvern_frame.safe_wait_for_animation_end(caller="click.dropdown") if page.url != scraped_page.url: LOG.info("Page URL changed after clicking, exiting the sequential click logic") return None @@ -1825,7 +1825,7 @@ async def handle_input_text_action( LOG.info("The element has onclick attribute, waiting for 1 second to load new elements", action=action) wait_sec = 1 - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=wait_sec) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=wait_sec, caller="input_text.autocomplete") incremental_element = await incremental_scraped.get_incremental_element_tree( clean_and_remove_element_tree_factory( task=task, step=step, check_filter_funcs=[check_existed_but_not_option_element_in_dom_factory(dom)] @@ -1971,7 +1971,7 @@ async def handle_input_text_action( return [ActionFailure(InvalidElementForTextInput(element_id=action.element_id, tag_name=tag_name))] # wait for blocking element to show up - await skyvern_frame.safe_wait_for_animation_end() + await skyvern_frame.safe_wait_for_animation_end(caller="input_text.blocking_check") try: blocking_element, exist = await skyvern_element.find_blocking_element( dom=dom, incremental_page=incremental_scraped @@ -2572,7 +2572,7 @@ async def handle_select_option_action( await skyvern_element.click(page=page, dom=dom, timeout=timeout) # wait for options to load - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5, caller="select_option.open") incremental_element = await incremental_scraped.get_incremental_element_tree( clean_and_remove_element_tree_factory( @@ -2588,7 +2588,7 @@ async def handle_select_option_action( await skyvern_element.scroll_into_view() await skyvern_element.press_key("ArrowDown") # wait for options to load - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5, caller="select_option.arrowdown") incremental_element = await incremental_scraped.get_incremental_element_tree( clean_and_remove_element_tree_factory( task=task, step=step, check_filter_funcs=[check_existed_but_not_option_element_in_dom_factory(dom)] @@ -2682,7 +2682,7 @@ async def handle_select_option_action( await skyvern_element.scroll_into_view() await skyvern_element.press_key("ArrowDown") - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5, caller="select_option.fallback") is_open = True result = await select_from_dropdown_by_value( @@ -3258,7 +3258,7 @@ async def _did_page_respond( ) -> bool: try: if skyvern_frame: - await skyvern_frame.safe_wait_for_animation_end() + await skyvern_frame.safe_wait_for_animation_end(caller="page_respond") return (await incremental_scraped.get_incremental_elements_num()) > 0 except Exception: LOG.debug("Failed to check incremental elements after click", exc_info=True) @@ -3617,7 +3617,7 @@ async def choose_auto_completion_dropdown( try: await skyvern_element.press_fill(text) # wait for new elemnts to load - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=1) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=1, caller="autocomplete.fill") incremental_element = await incremental_scraped.get_incremental_element_tree( clean_and_remove_element_tree_factory( task=task, step=step, check_filter_funcs=[check_existed_but_not_option_element_in_dom_factory(dom)] @@ -4016,7 +4016,7 @@ async def discover_and_select_from_full_dropdown( element_id=skyvern_element.get_id(), ) - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=1) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=1, caller="dropdown_discover.click") cleanup_func = clean_and_remove_element_tree_factory( task=task, @@ -4039,7 +4039,7 @@ async def discover_and_select_from_full_dropdown( element_id=skyvern_element.get_id(), ) - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=1) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=1, caller="dropdown_discover.arrowdown") incremental_element = await incremental_scraped.get_incremental_element_tree(cleanup_func) # If incremental detection failed (e.g. options in a different shadow root), @@ -4135,7 +4135,7 @@ async def discover_and_select_from_full_dropdown( # filter will show it as the only option. Then find and click it directly via Playwright. await skyvern_element.input_clear() await skyvern_element.press_fill(discovered_value) - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=1) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=1, caller="dropdown_discover.exact_match") # Select the first matching option via keyboard: ArrowDown highlights it, Enter confirms. # This avoids needing to locate the option element in shadow DOM. @@ -4221,7 +4221,7 @@ async def sequentially_select_from_dropdown( select_history.append(single_select_result) values.append(single_select_result.value) # wait 1s until DOM finished updating - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5, caller="sequential_select.pick") if await single_select_result.is_done(): return single_select_result @@ -4238,7 +4238,7 @@ async def sequentially_select_from_dropdown( selected_time=i + 1, ) # wait to load new options - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5, caller="sequential_select.next_level") check_filter_funcs.append( check_disappeared_element_id_in_incremental_factory(incremental_scraped=incremental_scraped) @@ -4959,13 +4959,13 @@ async def scroll_down_to_load_all_options( else: await skyvern_frame.scroll_to_element_bottom(dropdown_menu_element_handle, page_by_page) # wait until animation ends, otherwise the scroll operation could be overwritten - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5, caller="scroll_options.scroll") # scroll a little back and scroll down to trigger the loading await page.mouse.wheel(0, -1e-5) await page.mouse.wheel(0, 1e-5) # wait for while to load new options - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5, caller="scroll_options.trigger") current_num = await incremental_scraped.get_incremental_elements_num() LOG.info( @@ -4988,7 +4988,7 @@ async def scroll_down_to_load_all_options( await page.mouse.wheel(0, -scroll_pace) else: await skyvern_frame.scroll_to_element_top(dropdown_menu_element_handle) - await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5) + await skyvern_frame.safe_wait_for_animation_end(before_wait_sec=0.5, caller="scroll_options.top") async def normal_select( diff --git a/skyvern/webeye/scraper/scraper.py b/skyvern/webeye/scraper/scraper.py index 44dbd10ab..fea1ed3bc 100644 --- a/skyvern/webeye/scraper/scraper.py +++ b/skyvern/webeye/scraper/scraper.py @@ -327,7 +327,7 @@ async def _wait_for_scrape_ready(skyvern_frame: SkyvernFrame) -> None: dom_stability_timeout_ms=settings.PAGE_READY_DOM_STABILITY_TIMEOUT_MS, ) else: - await skyvern_frame.safe_wait_for_animation_end() + await skyvern_frame.safe_wait_for_animation_end(caller="scraper.scrape_ready") @traced(name="skyvern.agent.scrape") diff --git a/skyvern/webeye/utils/page.py b/skyvern/webeye/utils/page.py index 251f690fa..17e675956 100644 --- a/skyvern/webeye/utils/page.py +++ b/skyvern/webeye/utils/page.py @@ -226,7 +226,7 @@ async def _scrolling_screenshots_helper( if mode == ScreenshotMode.DETAILED: # wait until animation ends, which is triggered by scrolling - await skyvern_page.safe_wait_for_animation_end() + await skyvern_page.safe_wait_for_animation_end(caller="scrolling_screenshot") else: if draw_boxes: await skyvern_page.build_elements_and_draw_bounding_boxes(frame=frame, frame_index=frame_index) @@ -752,10 +752,18 @@ class SkyvernFrame: ) @traced(name="skyvern.browser.wait_for_animation") - async def safe_wait_for_animation_end(self, before_wait_sec: float = 0, timeout_ms: float = 3000) -> None: - # Separates the fast finished-quickly path from the timeout/error paths - # that burn the full timeout budget — explains the 124x p95/p50 ratio. + async def safe_wait_for_animation_end( + self, + before_wait_sec: float = 0, + timeout_ms: float = 3000, + caller: str = "unknown", + ) -> None: + # Fast finished-quickly path vs timeout/error paths that burn the full + # timeout budget — the 124x p95/p50 ratio in production traces. _span = otel_trace.get_current_span() + _span.set_attribute("before_wait_sec", before_wait_sec) + _span.set_attribute("timeout_ms", timeout_ms) + _span.set_attribute("caller", caller) try: await asyncio.sleep(before_wait_sec) await self.frame.wait_for_load_state("load", timeout=timeout_ms) diff --git a/tests/unit/test_animation_wait_attrs.py b/tests/unit/test_animation_wait_attrs.py new file mode 100644 index 000000000..f82b6e9e5 --- /dev/null +++ b/tests/unit/test_animation_wait_attrs.py @@ -0,0 +1,55 @@ +"""Tests for animation wait span attribute instrumentation.""" + +import ast +import inspect +import os + +from skyvern.webeye.utils.page import SkyvernFrame + + +def test_safe_wait_caller_defaults_to_unknown() -> None: + sig = inspect.signature(SkyvernFrame.safe_wait_for_animation_end) + assert "caller" in sig.parameters + assert sig.parameters["caller"].default == "unknown" + + +def test_all_production_call_sites_pass_caller() -> None: + """Every safe_wait_for_animation_end call in production code must include caller=. + + Uses AST parsing so multi-line / black-wrapped calls are handled correctly. + """ + repo_root = os.path.dirname(os.path.dirname(os.path.dirname(os.path.abspath(__file__)))) + scan_dirs = [os.path.join(repo_root, d) for d in ("skyvern", "cloud", "scripts")] + missing: list[str] = [] + + for scan_dir in scan_dirs: + if not os.path.isdir(scan_dir): + continue + for dirpath, _, filenames in os.walk(scan_dir): + if "__pycache__" in dirpath or ".venv" in dirpath: + continue + for fname in filenames: + if not fname.endswith(".py"): + continue + fpath = os.path.join(dirpath, fname) + try: + with open(fpath) as f: + tree = ast.parse(f.read(), filename=fpath) + except SyntaxError: + continue + for node in ast.walk(tree): + if not isinstance(node, ast.Await): + continue + call = node.value + if not isinstance(call, ast.Call): + continue + func = call.func + is_target = isinstance(func, ast.Attribute) and func.attr == "safe_wait_for_animation_end" + if not is_target: + continue + has_caller = any(kw.arg == "caller" for kw in call.keywords) + if not has_caller: + rel = os.path.relpath(fpath, repo_root) + missing.append(f"{rel}:{node.lineno}") + + assert not missing, "Call sites missing caller= keyword:\n" + "\n".join(f" {m}" for m in missing)