perf(SKY-10319): add caller/timeout span attrs to animation wait (#6369)

This commit is contained in:
LawyZheng 2026-06-04 11:53:18 +08:00 committed by GitHub
parent 9a93281c17
commit 07da906667
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
5 changed files with 86 additions and 23 deletions

View file

@ -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)

View file

@ -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(

View file

@ -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")

View file

@ -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)

View file

@ -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)