set context.step_id and context.task_id at the beginning of execute_step and unset at the end + auto log step_id & task_id (#3803)

This commit is contained in:
Shuchang Zheng
2025-10-23 16:32:28 -07:00
committed by GitHub
parent 5b80614aac
commit d55b9637c4
4 changed files with 40 additions and 436 deletions

View File

@@ -232,8 +232,6 @@ class ForgeAgent:
"Created new step for workflow run", "Created new step for workflow run",
workflow_id=workflow.workflow_id, workflow_id=workflow.workflow_id,
workflow_run_id=workflow_run.workflow_run_id, workflow_run_id=workflow_run.workflow_run_id,
step_id=step.step_id,
task_id=task.task_id,
order=step.order, order=step.order,
retry_index=step.retry_index, retry_index=step.retry_index,
) )
@@ -304,6 +302,11 @@ class ForgeAgent:
cua_response: OpenAIResponse | None = None, cua_response: OpenAIResponse | None = None,
llm_caller: LLMCaller | None = None, llm_caller: LLMCaller | None = None,
) -> Tuple[Step, DetailedAgentStepOutput | None, Step | None]: ) -> Tuple[Step, DetailedAgentStepOutput | None, Step | None]:
# set the step_id and task_id in the context
context = skyvern_context.ensure_context()
context.step_id = step.step_id
context.task_id = task.task_id
# do not need to do complete verification when it's a CUA task # do not need to do complete verification when it's a CUA task
# 1. CUA executes only one action step by step -- it's pretty less likely to have a hallucination for completion or forget to return a complete # 1. CUA executes only one action step by step -- it's pretty less likely to have a hallucination for completion or forget to return a complete
# 2. It will significantly slow down CUA tasks # 2. It will significantly slow down CUA tasks
@@ -324,7 +327,6 @@ class ForgeAgent:
LOG.info( LOG.info(
"Workflow run is canceled, stopping execution inside task", "Workflow run is canceled, stopping execution inside task",
workflow_run_id=workflow_run.workflow_run_id, workflow_run_id=workflow_run.workflow_run_id,
step_id=step.step_id,
) )
step = await self.update_step( step = await self.update_step(
step, step,
@@ -341,7 +343,6 @@ class ForgeAgent:
LOG.info( LOG.info(
"Workflow run is timed out, stopping execution inside task", "Workflow run is timed out, stopping execution inside task",
workflow_run_id=workflow_run.workflow_run_id, workflow_run_id=workflow_run.workflow_run_id,
step_id=step.step_id,
) )
step = await self.update_step( step = await self.update_step(
step, step,
@@ -378,8 +379,7 @@ class ForgeAgent:
) )
return step, None, None return step, None, None
context = skyvern_context.current() override_max_steps_per_run = context.max_steps_override or None
override_max_steps_per_run = context.max_steps_override if context else None
max_steps_per_run = ( max_steps_per_run = (
override_max_steps_per_run override_max_steps_per_run
or task.max_steps_per_run or task.max_steps_per_run
@@ -502,7 +502,6 @@ class ForgeAgent:
LOG.info( LOG.info(
"Detecting files are still downloading, waiting for files to be completely downloaded.", "Detecting files are still downloading, waiting for files to be completely downloaded.",
downloading_files=downloading_files, downloading_files=downloading_files,
step_id=step.step_id,
) )
try: try:
await wait_for_download_finished( await wait_for_download_finished(
@@ -513,8 +512,6 @@ class ForgeAgent:
LOG.warning( LOG.warning(
"There're several long-time downloading files, these files might be broken", "There're several long-time downloading files, these files might be broken",
downloading_files=e.downloading_files, downloading_files=e.downloading_files,
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
@@ -632,8 +629,6 @@ class ForgeAgent:
else: else:
LOG.error( LOG.error(
"Step completed but task is not completed and next step is not created.", "Step completed but task is not completed and next step is not created.",
task_id=task.task_id,
step_id=step.step_id,
is_task_completed=is_task_completed, is_task_completed=is_task_completed,
maybe_last_step=maybe_last_step, maybe_last_step=maybe_last_step,
maybe_next_step=maybe_next_step, maybe_next_step=maybe_next_step,
@@ -641,8 +636,6 @@ class ForgeAgent:
else: else:
LOG.error( LOG.error(
"Unexpected step status after agent_step", "Unexpected step status after agent_step",
task_id=task.task_id,
step_id=step.step_id,
step_status=step.status, step_status=step.status,
) )
@@ -681,8 +674,6 @@ class ForgeAgent:
else: else:
LOG.info( LOG.info(
"Step executed but continuous execution is disabled.", "Step executed but continuous execution is disabled.",
task_id=task.task_id,
step_id=step.step_id,
is_cloud_env=settings.is_cloud_environment(), is_cloud_env=settings.is_cloud_environment(),
execute_all_steps=settings.execute_all_steps(), execute_all_steps=settings.execute_all_steps(),
next_step_id=next_step.step_id if next_step else None, next_step_id=next_step.step_id if next_step else None,
@@ -691,18 +682,10 @@ class ForgeAgent:
return step, detailed_output, next_step return step, detailed_output, next_step
# TODO (kerem): Let's add other exceptions that we know about here as custom exceptions as well # TODO (kerem): Let's add other exceptions that we know about here as custom exceptions as well
except StepUnableToExecuteError: except StepUnableToExecuteError:
LOG.error( LOG.exception("Step cannot be executed. Task execution stopped")
"Step cannot be executed. Task execution stopped",
task_id=task.task_id,
step_id=step.step_id,
)
raise raise
except TaskAlreadyTimeout: except TaskAlreadyTimeout:
LOG.warning( LOG.warning("Task is timed out, stopping execution")
"Task is timed out, stopping execution",
task_id=task.task_id,
step=step.step_id,
)
await self.clean_up_task( await self.clean_up_task(
task=task, task=task,
last_step=step, last_step=step,
@@ -714,8 +697,6 @@ class ForgeAgent:
except StepTerminationError as e: except StepTerminationError as e:
LOG.warning( LOG.warning(
"Step cannot be executed, marking task as failed", "Step cannot be executed, marking task as failed",
task_id=task.task_id,
step_id=step.step_id,
exc_info=True, exc_info=True,
) )
is_task_marked_as_failed = await self.fail_task(task, step, e.message) is_task_marked_as_failed = await self.fail_task(task, step, e.message)
@@ -728,29 +709,20 @@ class ForgeAgent:
browser_session_id=browser_session_id, browser_session_id=browser_session_id,
) )
else: else:
LOG.warning( LOG.warning("Task isn't marked as failed, after step termination. NOT clean up the task")
"Task isn't marked as failed, after step termination. NOT clean up the task",
task_id=task.task_id,
step_id=step.step_id,
)
return step, detailed_output, None return step, detailed_output, None
except FailedToSendWebhook: except FailedToSendWebhook:
LOG.exception( LOG.exception(
"Failed to send webhook", "Failed to send webhook",
task_id=task.task_id,
step_id=step.step_id,
task=task, task=task,
step=step, step=step,
) )
return step, detailed_output, next_step return step, detailed_output, next_step
except FailedToNavigateToUrl as e: except FailedToNavigateToUrl as e:
# Fail the task if we can't navigate to the URL and send the response # Fail the task if we can't navigate to the URL and send the response
LOG.error( LOG.exception(
"Failed to navigate to URL, marking task as failed, and sending webhook response", "Failed to navigate to URL, marking task as failed, and sending webhook response",
task_id=task.task_id,
step_id=step.step_id,
url=e.url, url=e.url,
error_message=e.error_message,
) )
failure_reason = f"Failed to navigate to URL. URL:{e.url}, Error:{e.error_message}" failure_reason = f"Failed to navigate to URL. URL:{e.url}, Error:{e.error_message}"
is_task_marked_as_failed = await self.fail_task(task, step, failure_reason) is_task_marked_as_failed = await self.fail_task(task, step, failure_reason)
@@ -764,11 +736,7 @@ class ForgeAgent:
browser_session_id=browser_session_id, browser_session_id=browser_session_id,
) )
else: else:
LOG.warning( LOG.warning("Task isn't marked as failed, after navigation failure. NOT clean up the task")
"Task isn't marked as failed, after navigation failure. NOT clean up the task",
task_id=task.task_id,
step_id=step.step_id,
)
return step, detailed_output, next_step return step, detailed_output, next_step
except TaskAlreadyCanceled: except TaskAlreadyCanceled:
LOG.info( LOG.info(
@@ -785,11 +753,7 @@ class ForgeAgent:
) )
return step, detailed_output, None return step, detailed_output, None
except InvalidTaskStatusTransition: except InvalidTaskStatusTransition:
LOG.warning( LOG.warning("Invalid task status transition")
"Invalid task status transition",
task_id=task.task_id,
step_id=step.step_id,
)
# TODO: shall we send task response here? # TODO: shall we send task response here?
await self.clean_up_task( await self.clean_up_task(
task=task, task=task,
@@ -803,8 +767,6 @@ class ForgeAgent:
except (UnsupportedActionType, UnsupportedTaskType, FailedToParseActionInstruction) as e: except (UnsupportedActionType, UnsupportedTaskType, FailedToParseActionInstruction) as e:
LOG.warning( LOG.warning(
"unsupported task type or action type, marking the task as failed", "unsupported task type or action type, marking the task as failed",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
) )
@@ -821,8 +783,6 @@ class ForgeAgent:
except ScrapingFailed as sfe: except ScrapingFailed as sfe:
LOG.warning( LOG.warning(
"Scraping failed, marking the task as failed", "Scraping failed, marking the task as failed",
task_id=task.task_id,
step_id=step.step_id,
exc_info=True, exc_info=True,
) )
@@ -841,11 +801,7 @@ class ForgeAgent:
) )
return step, detailed_output, None return step, detailed_output, None
except Exception as e: except Exception as e:
LOG.exception( LOG.exception("Got an unexpected exception in step, marking task as failed")
"Got an unexpected exception in step, marking task as failed",
task_id=task.task_id,
step_id=step.step_id,
)
failure_reason = f"Unexpected error: {str(e)}" failure_reason = f"Unexpected error: {str(e)}"
if isinstance(e, SkyvernException): if isinstance(e, SkyvernException):
@@ -861,12 +817,13 @@ class ForgeAgent:
browser_session_id=browser_session_id, browser_session_id=browser_session_id,
) )
else: else:
LOG.warning( LOG.warning("Task isn't marked as failed, after unexpected exception. NOT clean up the task")
"Task isn't marked as failed, after unexpected exception. NOT clean up the task",
task_id=task.task_id,
step_id=step.step_id,
)
return step, detailed_output, None return step, detailed_output, None
finally:
# remove the step_id from the context
context = skyvern_context.ensure_context()
context.step_id = None
context.task_id = None
async def fail_task(self, task: Task, step: Step | None, reason: str | None) -> bool: async def fail_task(self, task: Task, step: Step | None, reason: str | None) -> bool:
try: try:
@@ -885,22 +842,16 @@ class ForgeAgent:
except TaskAlreadyCanceled: except TaskAlreadyCanceled:
LOG.info( LOG.info(
"Task is already canceled. Can't fail the task.", "Task is already canceled. Can't fail the task.",
task_id=task.task_id,
step_id=step.step_id if step else "",
) )
return False return False
except InvalidTaskStatusTransition: except InvalidTaskStatusTransition:
LOG.warning( LOG.warning(
"Invalid task status transition while failing a task", "Invalid task status transition while failing a task",
task_id=task.task_id,
step_id=step.step_id if step else "",
) )
return False return False
except Exception: except Exception:
LOG.exception( LOG.exception(
"Failed to update status and failure reason in database. Task might going to be time_out", "Failed to update status and failure reason in database. Task might going to be time_out",
task_id=task.task_id,
step_id=step.step_id if step else "",
reason=reason, reason=reason,
) )
return True return True
@@ -932,8 +883,6 @@ class ForgeAgent:
try: try:
LOG.info( LOG.info(
"Starting agent step", "Starting agent step",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
) )
@@ -1072,8 +1021,6 @@ class ForgeAgent:
if len(actions) == 0: if len(actions) == 0:
LOG.info( LOG.info(
"No actions to execute, marking step as failed", "No actions to execute, marking step as failed",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
) )
@@ -1087,8 +1034,6 @@ class ForgeAgent:
# Execute the actions # Execute the actions
LOG.info( LOG.info(
"Executing actions", "Executing actions",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
actions=actions, actions=actions,
@@ -1139,8 +1084,6 @@ class ForgeAgent:
if context.refresh_working_page: if context.refresh_working_page:
LOG.warning( LOG.warning(
"Detected the signal to reload the page, going to reload and skip the rest of the actions", "Detected the signal to reload the page, going to reload and skip the rest of the actions",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
) )
await browser_state.reload_page() await browser_state.reload_page()
@@ -1153,8 +1096,6 @@ class ForgeAgent:
status=ActionStatus.completed, status=ActionStatus.completed,
organization_id=task.organization_id, organization_id=task.organization_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
action_order=action_idx, action_order=action_idx,
) )
@@ -1169,8 +1110,6 @@ class ForgeAgent:
if previous_action_idx is not None: if previous_action_idx is not None:
LOG.warning( LOG.warning(
"Duplicate action element id.", "Duplicate action element id.",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
action=action, action=action,
) )
@@ -1181,8 +1120,6 @@ class ForgeAgent:
if len(previous_result) > 0 and previous_result[-1].success: if len(previous_result) > 0 and previous_result[-1].success:
LOG.info( LOG.info(
"Previous action succeeded, but we'll still continue.", "Previous action succeeded, but we'll still continue.",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
previous_action=previous_action, previous_action=previous_action,
previous_result=previous_result, previous_result=previous_result,
@@ -1190,8 +1127,6 @@ class ForgeAgent:
else: else:
LOG.warning( LOG.warning(
"Previous action failed, so handle the next action.", "Previous action failed, so handle the next action.",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
previous_action=previous_action, previous_action=previous_action,
previous_result=previous_result, previous_result=previous_result,
@@ -1257,8 +1192,6 @@ class ForgeAgent:
if results and results[-1].success: if results and results[-1].success:
LOG.info( LOG.info(
"Action succeeded", "Action succeeded",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
action_idx=action_idx, action_idx=action_idx,
@@ -1268,8 +1201,6 @@ class ForgeAgent:
if results[-1].skip_remaining_actions: if results[-1].skip_remaining_actions:
LOG.warning( LOG.warning(
"Going to stop executing the remaining actions", "Going to stop executing the remaining actions",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
action_idx=action_idx, action_idx=action_idx,
@@ -1281,8 +1212,6 @@ class ForgeAgent:
elif results and isinstance(action, DecisiveAction): elif results and isinstance(action, DecisiveAction):
LOG.warning( LOG.warning(
"DecisiveAction failed, but not stopping execution and not retrying the step", "DecisiveAction failed, but not stopping execution and not retrying the step",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
action_idx=action_idx, action_idx=action_idx,
@@ -1292,8 +1221,6 @@ class ForgeAgent:
elif results and not results[-1].success and not results[-1].stop_execution_on_failure: elif results and not results[-1].success and not results[-1].stop_execution_on_failure:
LOG.warning( LOG.warning(
"Action failed, but not stopping execution", "Action failed, but not stopping execution",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
action_idx=action_idx, action_idx=action_idx,
@@ -1304,8 +1231,6 @@ class ForgeAgent:
if action_node.next is not None: if action_node.next is not None:
LOG.warning( LOG.warning(
"Action failed, but have duplicated element id in the action list. Continue excuting.", "Action failed, but have duplicated element id in the action list. Continue excuting.",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
action_idx=action_idx, action_idx=action_idx,
@@ -1317,8 +1242,6 @@ class ForgeAgent:
LOG.warning( LOG.warning(
"Action failed, marking step as failed", "Action failed, marking step as failed",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
action_idx=action_idx, action_idx=action_idx,
@@ -1336,8 +1259,6 @@ class ForgeAgent:
LOG.info( LOG.info(
"Actions executed successfully, marking step as completed", "Actions executed successfully, marking step as completed",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
action_results=action_results, action_results=action_results,
@@ -1430,8 +1351,6 @@ class ForgeAgent:
except CancelledError: except CancelledError:
LOG.exception( LOG.exception(
"CancelledError in agent_step, marking step as failed", "CancelledError in agent_step, marking step as failed",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
) )
@@ -1453,8 +1372,6 @@ class ForgeAgent:
except Exception as e: except Exception as e:
LOG.exception( LOG.exception(
"Unexpected exception in agent_step, marking step as failed", "Unexpected exception in agent_step, marking step as failed",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
) )
@@ -1721,8 +1638,6 @@ class ForgeAgent:
LOG.info( LOG.info(
"UI-TARS action generation starts", "UI-TARS action generation starts",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
) )
@@ -1753,8 +1668,6 @@ class ForgeAgent:
LOG.info( LOG.info(
"UI-TARS action generation completed", "UI-TARS action generation completed",
task_id=task.task_id,
step_id=step.step_id,
actions_count=len(actions), actions_count=len(actions),
) )
@@ -1765,8 +1678,6 @@ class ForgeAgent:
) -> CompleteVerifyResult: ) -> CompleteVerifyResult:
LOG.info( LOG.info(
"Checking if user goal is achieved after re-scraping the page", "Checking if user goal is achieved after re-scraping the page",
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
scroll = True scroll = True
@@ -1829,8 +1740,6 @@ class ForgeAgent:
except Exception: except Exception:
LOG.exception( LOG.exception(
"Failed to check user goal complete, skipping", "Failed to check user goal complete, skipping",
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
return None return None
@@ -1871,8 +1780,6 @@ class ForgeAgent:
except Exception: except Exception:
LOG.error( LOG.error(
"Failed to record screenshot after action", "Failed to record screenshot after action",
task_id=task.task_id,
step_id=step.step_id,
exc_info=True, exc_info=True,
) )
@@ -1885,12 +1792,7 @@ class ForgeAgent:
data=html.encode(), data=html.encode(),
) )
except Exception: except Exception:
LOG.error( LOG.exception("Failed to record html after action")
"Failed to record html after action",
task_id=task.task_id,
step_id=step.step_id,
exc_info=True,
)
try: try:
video_artifacts = await app.BROWSER_MANAGER.get_video_artifacts( video_artifacts = await app.BROWSER_MANAGER.get_video_artifacts(
@@ -1903,12 +1805,7 @@ class ForgeAgent:
data=video_artifact.video_data, data=video_artifact.video_data,
) )
except Exception: except Exception:
LOG.error( LOG.exception("Failed to record video after action")
"Failed to record video after action",
task_id=task.task_id,
step_id=step.step_id,
exc_info=True,
)
async def initialize_execution_state( async def initialize_execution_state(
self, self,
@@ -1967,18 +1864,10 @@ class ForgeAgent:
pass pass
elif scrape_type == ScrapeType.STOPLOADING: elif scrape_type == ScrapeType.STOPLOADING:
LOG.info( LOG.info("Try to stop loading the page before scraping")
"Try to stop loading the page before scraping",
task_id=task.task_id,
step_id=step.step_id,
)
await browser_state.stop_page_loading() await browser_state.stop_page_loading()
elif scrape_type == ScrapeType.RELOAD: elif scrape_type == ScrapeType.RELOAD:
LOG.info( LOG.info("Try to reload the page before scraping")
"Try to reload the page before scraping",
task_id=task.task_id,
step_id=step.step_id,
)
await browser_state.reload_page() await browser_state.reload_page()
max_screenshot_number = settings.MAX_NUM_SCREENSHOTS max_screenshot_number = settings.MAX_NUM_SCREENSHOTS
@@ -2030,12 +1919,7 @@ class ForgeAgent:
except (FailedToTakeScreenshot, ScrapingFailed) as e: except (FailedToTakeScreenshot, ScrapingFailed) as e:
if idx < len(SCRAPE_TYPE_ORDER) - 1: if idx < len(SCRAPE_TYPE_ORDER) - 1:
continue continue
LOG.error( LOG.exception(f"{e.__class__.__name__} happened in two normal attempts and reload-page retry")
f"{e.__class__.__name__} happened in two normal attempts and reload-page retry",
task_id=task.task_id,
step_id=step.step_id,
exc_info=True,
)
raise e raise e
if scraped_page is None: if scraped_page is None:
@@ -2048,8 +1932,6 @@ class ForgeAgent:
) )
LOG.info( LOG.info(
"Scraped website", "Scraped website",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
num_elements=len(scraped_page.elements), num_elements=len(scraped_page.elements),
@@ -2408,8 +2290,6 @@ class ForgeAgent:
if action_result.success: if action_result.success:
LOG.info( LOG.info(
"Extracted information for task", "Extracted information for task",
task_id=task.task_id,
step_id=step.step_id,
extracted_information=action_result.data, extracted_information=action_result.data,
) )
return action_result.data return action_result.data
@@ -2503,15 +2383,9 @@ class ForgeAgent:
except TargetClosedError: except TargetClosedError:
LOG.warning( LOG.warning(
"Failed to take screenshot before sending task response, page is closed", "Failed to take screenshot before sending task response, page is closed",
task_id=task.task_id,
step_id=last_step.step_id,
) )
except Exception: except Exception:
LOG.exception( LOG.exception("Failed to take screenshot before sending task response")
"Failed to take screenshot before sending task response",
task_id=task.task_id,
step_id=last_step.step_id,
)
if task.organization_id: if task.organization_id:
try: try:
@@ -2821,8 +2695,6 @@ class ForgeAgent:
} }
LOG.debug( LOG.debug(
"Updating step in db", "Updating step in db",
task_id=step.task_id,
step_id=step.step_id,
diff=update_comparison, diff=update_comparison,
) )
@@ -2831,8 +2703,6 @@ class ForgeAgent:
duration_seconds = (datetime.now(UTC) - step.created_at.replace(tzinfo=UTC)).total_seconds() duration_seconds = (datetime.now(UTC) - step.created_at.replace(tzinfo=UTC)).total_seconds()
LOG.info( LOG.info(
"Step duration metrics", "Step duration metrics",
task_id=step.task_id,
step_id=step.step_id,
duration_seconds=duration_seconds, duration_seconds=duration_seconds,
step_status=status, step_status=status,
organization_id=step.organization_id, organization_id=step.organization_id,
@@ -2910,8 +2780,6 @@ class ForgeAgent:
if step.retry_index >= max_retries_per_step: if step.retry_index >= max_retries_per_step:
LOG.warning( LOG.warning(
"Step failed after max retries, marking task as failed", "Step failed after max retries, marking task as failed",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
max_retries=settings.MAX_RETRIES_PER_STEP, max_retries=settings.MAX_RETRIES_PER_STEP,
@@ -2941,8 +2809,6 @@ class ForgeAgent:
else: else:
LOG.warning( LOG.warning(
"Step failed, retrying", "Step failed, retrying",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
) )
@@ -3016,7 +2882,7 @@ class ForgeAgent:
) )
return MaxStepsReasonResponse.model_validate(json_response) return MaxStepsReasonResponse.model_validate(json_response)
except Exception: except Exception:
LOG.warning("Failed to summary the failure reason", task_id=task.task_id, step_id=step.step_id) LOG.warning("Failed to summary the failure reason")
if steps_results: if steps_results:
last_step_result = steps_results[-1] last_step_result = steps_results[-1]
return MaxStepsReasonResponse( return MaxStepsReasonResponse(
@@ -3086,11 +2952,7 @@ class ForgeAgent:
) )
return json_response.get("reasoning", "") return json_response.get("reasoning", "")
except Exception: except Exception:
LOG.warning( LOG.warning("Failed to summarize the failure reason for max retries")
"Failed to summarize the failure reason for max retries",
task_id=task.task_id,
step_id=step.step_id,
)
if steps_results: if steps_results:
last_step_result = steps_results[-1] last_step_result = steps_results[-1]
return f"Retry Step {last_step_result['order']}: {last_step_result['actions_result']}" return f"Retry Step {last_step_result['order']}: {last_step_result['actions_result']}"
@@ -3107,8 +2969,6 @@ class ForgeAgent:
if step.is_goal_achieved(): if step.is_goal_achieved():
LOG.info( LOG.info(
"Step completed and goal achieved, marking task as completed", "Step completed and goal achieved, marking task as completed",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
output=step.output, output=step.output,
@@ -3124,8 +2984,6 @@ class ForgeAgent:
if step.is_terminated(): if step.is_terminated():
LOG.info( LOG.info(
"Step completed and terminated by the agent, marking task as terminated", "Step completed and terminated by the agent, marking task as terminated",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
output=step.output, output=step.output,
@@ -3148,8 +3006,6 @@ class ForgeAgent:
if isinstance(task_block, ActionBlock) and step.is_success(): if isinstance(task_block, ActionBlock) and step.is_success():
LOG.info( LOG.info(
"Step completed for the action block, marking task as completed", "Step completed for the action block, marking task as completed",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
output=step.output, output=step.output,
@@ -3164,8 +3020,6 @@ class ForgeAgent:
if step.order + 1 >= max_steps_per_run: if step.order + 1 >= max_steps_per_run:
LOG.info( LOG.info(
"Step completed but max steps reached, marking task as failed", "Step completed but max steps reached, marking task as failed",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
max_steps=max_steps_per_run, max_steps=max_steps_per_run,
@@ -3193,8 +3047,6 @@ class ForgeAgent:
else: else:
LOG.info( LOG.info(
"Step completed, creating next step", "Step completed, creating next step",
task_id=task.task_id,
step_id=step.step_id,
step_order=step.order, step_order=step.order,
step_retry=step.retry_index, step_retry=step.retry_index,
) )
@@ -3311,7 +3163,7 @@ class ForgeAgent:
and (task.totp_verification_url or task.totp_identifier) and (task.totp_verification_url or task.totp_identifier)
and task.organization_id and task.organization_id
): ):
LOG.info("Need verification code", step_id=step.step_id) LOG.info("Need verification code")
workflow_id = workflow_permanent_id = None workflow_id = workflow_permanent_id = None
if task.workflow_run_id: if task.workflow_run_id:
workflow_run = await app.DATABASE.get_workflow_run(task.workflow_run_id) workflow_run = await app.DATABASE.get_workflow_run(task.workflow_run_id)

View File

@@ -146,8 +146,6 @@ async def _check_svg_eligibility(
_mark_element_as_dropped(element, hashed_key=None) _mark_element_as_dropped(element, hashed_key=None)
return False return False
task_id = task.task_id if task else None
step_id = step.step_id if step else None
element_id = element.get("id", "") element_id = element.get("id", "")
try: try:
@@ -172,8 +170,6 @@ async def _check_svg_eligibility(
LOG.warning( LOG.warning(
"Failed to get the blocking element for the svg, going to continue parsing the svg", "Failed to get the blocking element for the svg, going to continue parsing the svg",
exc_info=True, exc_info=True,
task_id=task_id,
step_id=step_id,
) )
return True return True
@@ -185,8 +181,6 @@ async def _convert_svg_to_string(
step: Step | None = None, step: Step | None = None,
) -> None: ) -> None:
"""Convert an SVG element to a string description. Assumes element has already passed eligibility checks.""" """Convert an SVG element to a string description. Assumes element has already passed eligibility checks."""
task_id = task.task_id if task else None
step_id = step.step_id if step else None
element_id = element.get("id", "") element_id = element.get("id", "")
svg_element = _remove_skyvern_attributes(element) svg_element = _remove_skyvern_attributes(element)
@@ -202,8 +196,6 @@ async def _convert_svg_to_string(
except Exception: except Exception:
LOG.warning( LOG.warning(
"Failed to loaded SVG cache", "Failed to loaded SVG cache",
task_id=task_id,
step_id=step_id,
exc_info=True, exc_info=True,
key=svg_key, key=svg_key,
) )
@@ -221,8 +213,6 @@ async def _convert_svg_to_string(
LOG.warning( LOG.warning(
"SVG element is too large to convert, going to drop the svg element.", "SVG element is too large to convert, going to drop the svg element.",
element_id=element_id, element_id=element_id,
task_id=task_id,
step_id=step_id,
length=len(svg_html), length=len(svg_html),
key=svg_key, key=svg_key,
) )
@@ -251,8 +241,6 @@ async def _convert_svg_to_string(
LOG.info( LOG.info(
"Failed to convert SVG to string due to llm error. Will retry if haven't met the max try attempt after 3s.", "Failed to convert SVG to string due to llm error. Will retry if haven't met the max try attempt after 3s.",
exc_info=True, exc_info=True,
task_id=task_id,
step_id=step_id,
element_id=element_id, element_id=element_id,
key=svg_key, key=svg_key,
retry=retry, retry=retry,
@@ -273,8 +261,6 @@ async def _convert_svg_to_string(
LOG.info( LOG.info(
"Failed to convert SVG to string shape by secondary llm. Will retry if haven't met the max try attempt after 3s.", "Failed to convert SVG to string shape by secondary llm. Will retry if haven't met the max try attempt after 3s.",
exc_info=True, exc_info=True,
task_id=task_id,
step_id=step_id,
element_id=element_id, element_id=element_id,
retry=retry, retry=retry,
) )
@@ -286,8 +272,6 @@ async def _convert_svg_to_string(
LOG.warning( LOG.warning(
"Reaching the max try to convert svg element, going to drop the svg element.", "Reaching the max try to convert svg element, going to drop the svg element.",
element_id=element_id, element_id=element_id,
task_id=task_id,
step_id=step_id,
key=svg_key, key=svg_key,
length=len(svg_html), length=len(svg_html),
) )
@@ -312,8 +296,6 @@ async def _convert_css_shape_to_string(
) -> None: ) -> None:
element_id: str = element.get("id", "") element_id: str = element.get("id", "")
task_id = task.task_id if task else None
step_id = step.step_id if step else None
shape_element = _remove_skyvern_attributes(element) shape_element = _remove_skyvern_attributes(element)
svg_html = json_to_html(shape_element) svg_html = json_to_html(shape_element)
hash_object = hashlib.sha256() hash_object = hashlib.sha256()
@@ -327,8 +309,6 @@ async def _convert_css_shape_to_string(
except Exception: except Exception:
LOG.warning( LOG.warning(
"Failed to loaded CSS shape cache", "Failed to loaded CSS shape cache",
task_id=task_id,
step_id=step_id,
exc_info=True, exc_info=True,
key=shape_key, key=shape_key,
) )
@@ -344,8 +324,6 @@ async def _convert_css_shape_to_string(
if await locater.count() == 0: if await locater.count() == 0:
LOG.info( LOG.info(
"No locater found to convert css shape", "No locater found to convert css shape",
task_id=task_id,
step_id=step_id,
element_id=element_id, element_id=element_id,
key=shape_key, key=shape_key,
) )
@@ -354,8 +332,6 @@ async def _convert_css_shape_to_string(
if not await locater.is_visible(timeout=settings.BROWSER_ACTION_TIMEOUT_MS): if not await locater.is_visible(timeout=settings.BROWSER_ACTION_TIMEOUT_MS):
LOG.info( LOG.info(
"element is not visible on the page, going to abort conversion", "element is not visible on the page, going to abort conversion",
task_id=task_id,
step_id=step_id,
element_id=element_id, element_id=element_id,
key=shape_key, key=shape_key,
) )
@@ -366,8 +342,6 @@ async def _convert_css_shape_to_string(
if blocked: if blocked:
LOG.debug( LOG.debug(
"element is blocked by another element, going to abort conversion", "element is blocked by another element, going to abort conversion",
task_id=task_id,
step_id=step_id,
element_id=element_id, element_id=element_id,
key=shape_key, key=shape_key,
) )
@@ -380,8 +354,6 @@ async def _convert_css_shape_to_string(
LOG.info( LOG.info(
"Failed to make the element visible, going to abort conversion", "Failed to make the element visible, going to abort conversion",
exc_info=True, exc_info=True,
task_id=task_id,
step_id=step_id,
element_id=element_id, element_id=element_id,
key=shape_key, key=shape_key,
) )
@@ -411,8 +383,6 @@ async def _convert_css_shape_to_string(
LOG.info( LOG.info(
"Failed to convert css shape due to llm error. Will retry if haven't met the max try attempt after 3s.", "Failed to convert css shape due to llm error. Will retry if haven't met the max try attempt after 3s.",
exc_info=True, exc_info=True,
task_id=task_id,
step_id=step_id,
element_id=element_id, element_id=element_id,
retry=retry, retry=retry,
key=shape_key, key=shape_key,
@@ -433,8 +403,6 @@ async def _convert_css_shape_to_string(
LOG.info( LOG.info(
"Failed to convert css shape to string shape by secondary llm. Will retry if haven't met the max try attempt after 3s.", "Failed to convert css shape to string shape by secondary llm. Will retry if haven't met the max try attempt after 3s.",
exc_info=True, exc_info=True,
task_id=task_id,
step_id=step_id,
element_id=element_id, element_id=element_id,
retry=retry, retry=retry,
key=shape_key, key=shape_key,
@@ -446,8 +414,6 @@ async def _convert_css_shape_to_string(
else: else:
LOG.info( LOG.info(
"Max css shape convertion retry, going to abort the convertion.", "Max css shape convertion retry, going to abort the convertion.",
task_id=task_id,
step_id=step_id,
element_id=element_id, element_id=element_id,
key=shape_key, key=shape_key,
) )
@@ -457,8 +423,6 @@ async def _convert_css_shape_to_string(
LOG.warning( LOG.warning(
"Failed to convert css shape to string shape by LLM", "Failed to convert css shape to string shape by LLM",
key=shape_key, key=shape_key,
task_id=task_id,
step_id=step_id,
element_id=element_id, element_id=element_id,
exc_info=True, exc_info=True,
) )

View File

@@ -29,6 +29,8 @@ def add_kv_pairs_to_msg(logger: logging.Logger, method_name: str, event_dict: Ev
event_dict["organization_id"] = context.organization_id event_dict["organization_id"] = context.organization_id
if context.organization_name: if context.organization_name:
event_dict["organization_name"] = context.organization_name event_dict["organization_name"] = context.organization_name
if context.step_id:
event_dict["step_id"] = context.step_id
if context.task_id: if context.task_id:
event_dict["task_id"] = context.task_id event_dict["task_id"] = context.task_id
if context.run_id: if context.run_id:

View File

@@ -151,8 +151,6 @@ def is_ul_or_listbox_element_factory(
LOG.debug( LOG.debug(
"Failed to element in the incremental page", "Failed to element in the incremental page",
element_id=element_id, element_id=element_id,
step_id=step.step_id,
task_id=task.task_id,
exc_info=True, exc_info=True,
) )
return False return False
@@ -582,8 +580,6 @@ async def handle_click_action(
LOG.warning( LOG.warning(
"Try to click on a disabled element", "Try to click on a disabled element",
action_type=action.action_type, action_type=action.action_type,
task_id=task.task_id,
step_id=step.step_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
) )
return [ActionFailure(InteractWithDisabledElement(skyvern_element.get_id()))] return [ActionFailure(InteractWithDisabledElement(skyvern_element.get_id()))]
@@ -597,8 +593,6 @@ async def handle_click_action(
LOG.info( LOG.info(
"Page count before download file action", "Page count before download file action",
initial_page_count=initial_page_count, initial_page_count=initial_page_count,
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
results: list[ActionResult] = [] results: list[ActionResult] = []
@@ -618,24 +612,18 @@ async def handle_click_action(
"Page count after download file action", "Page count after download file action",
initial_page_count=initial_page_count, initial_page_count=initial_page_count,
page_count_after_download=page_count_after_download, page_count_after_download=page_count_after_download,
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
if page_count_after_download > initial_page_count and browser_state and browser_state.browser_context: if page_count_after_download > initial_page_count and browser_state and browser_state.browser_context:
if results and results[-1].download_triggered: if results and results[-1].download_triggered:
LOG.info( LOG.info(
"Download triggered, closing the extra page", "Download triggered, closing the extra page",
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
if page == browser_state.browser_context.pages[-1]: if page == browser_state.browser_context.pages[-1]:
LOG.warning( LOG.warning(
"The extra page is the current page, closing it", "The extra page is the current page, closing it",
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
# close the extra page # close the extra page
@@ -643,8 +631,6 @@ async def handle_click_action(
else: else:
LOG.info( LOG.info(
"No download triggered, not closing the extra page", "No download triggered, not closing the extra page",
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
else: else:
@@ -694,8 +680,6 @@ async def handle_click_action(
LOG.warning( LOG.warning(
"Failed to do sequential logic for the click action, skipping", "Failed to do sequential logic for the click action, skipping",
exc_info=True, exc_info=True,
step_id=step.step_id,
task_id=task.task_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
) )
return results return results
@@ -770,11 +754,7 @@ async def handle_sequential_click_for_dropdown(
) )
verify_result = CompleteVerifyResult.model_validate(response) verify_result = CompleteVerifyResult.model_validate(response)
if verify_result.user_goal_achieved: if verify_result.user_goal_achieved:
LOG.info( LOG.info("User goal achieved, exiting the sequential click logic")
"User goal achieved, exiting the sequential click logic",
step_id=step.step_id,
task_id=task.task_id,
)
return None return None
dropdown_menu_element = await locate_dropdown_menu( dropdown_menu_element = await locate_dropdown_menu(
@@ -799,8 +779,6 @@ async def handle_sequential_click_for_dropdown(
if dropdown_select_context.is_date_related: if dropdown_select_context.is_date_related:
LOG.info( LOG.info(
"The dropdown is date related, exiting the sequential click logic and skipping the remaining actions", "The dropdown is date related, exiting the sequential click logic and skipping the remaining actions",
step_id=step.step_id,
task_id=task.task_id,
) )
result = ActionSuccess() result = ActionSuccess()
result.skip_remaining_actions = True result.skip_remaining_actions = True
@@ -808,8 +786,6 @@ async def handle_sequential_click_for_dropdown(
LOG.info( LOG.info(
"Found the dropdown menu element after clicking, triggering the sequential click logic", "Found the dropdown menu element after clicking, triggering the sequential click logic",
step_id=step.step_id,
task_id=task.task_id,
element_id=dropdown_menu_element.get_id(), element_id=dropdown_menu_element.get_id(),
) )
@@ -858,8 +834,6 @@ async def handle_click_to_download_file_action(
"Number of files in download directory before click", "Number of files in download directory before click",
num_downloaded_files_before=len(list_files_before), num_downloaded_files_before=len(list_files_before),
download_dir=download_dir, download_dir=download_dir,
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
@@ -872,8 +846,6 @@ async def handle_click_to_download_file_action(
"ClickAction with download failed", "ClickAction with download failed",
exc_info=True, exc_info=True,
action=action, action=action,
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
return [ActionFailure(e, download_triggered=False)] return [ActionFailure(e, download_triggered=False)]
@@ -897,8 +869,6 @@ async def handle_click_to_download_file_action(
"Found new files in download directory after click", "Found new files in download directory after click",
num_downloaded_files_after=len(list_files_after), num_downloaded_files_after=len(list_files_after),
download_dir=download_dir, download_dir=download_dir,
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
break break
@@ -907,8 +877,6 @@ async def handle_click_to_download_file_action(
except asyncio.TimeoutError: except asyncio.TimeoutError:
LOG.warning( LOG.warning(
"No file to download after click", "No file to download after click",
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
return [ActionSuccess(download_triggered=False)] return [ActionSuccess(download_triggered=False)]
@@ -927,8 +895,6 @@ async def handle_click_to_download_file_action(
LOG.info( LOG.info(
"File downloading hasn't completed, wait for a while", "File downloading hasn't completed, wait for a while",
downloading_files=downloading_files, downloading_files=downloading_files,
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
try: try:
@@ -939,8 +905,6 @@ async def handle_click_to_download_file_action(
LOG.warning( LOG.warning(
"There're several long-time downloading files, these files might be broken", "There're several long-time downloading files, these files might be broken",
downloading_files=e.downloading_files, downloading_files=e.downloading_files,
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
@@ -984,7 +948,6 @@ async def _handle_multi_field_totp_sequence(
LOG.debug( LOG.debug(
"Using multi-field TOTP flow - using NEXT TOTP due to <20s expiry", "Using multi-field TOTP flow - using NEXT TOTP due to <20s expiry",
task_id=task.task_id,
action_idx=action_index, action_idx=action_index,
current_totp=totp.now(), current_totp=totp.now(),
next_totp=current_totp, next_totp=current_totp,
@@ -1004,7 +967,6 @@ async def _handle_multi_field_totp_sequence(
# If it does, something went wrong with the first digit, so fail the action # If it does, something went wrong with the first digit, so fail the action
LOG.error( LOG.error(
"TOTP cache missing for subsequent digit - first digit may have failed", "TOTP cache missing for subsequent digit - first digit may have failed",
task_id=task.task_id,
action_idx=action_index, action_idx=action_index,
cache_key=cache_key, cache_key=cache_key,
) )
@@ -1021,7 +983,6 @@ async def _handle_multi_field_totp_sequence(
if current_time >= totp_valid_until: if current_time >= totp_valid_until:
LOG.error( LOG.error(
"Cached TOTP has expired during multi-field sequence", "Cached TOTP has expired during multi-field sequence",
task_id=task.task_id,
action_idx=action_index, action_idx=action_index,
current_time=current_time, current_time=current_time,
totp_valid_until=totp_valid_until, totp_valid_until=totp_valid_until,
@@ -1031,7 +992,6 @@ async def _handle_multi_field_totp_sequence(
LOG.debug( LOG.debug(
"Using multi-field TOTP flow - reusing cached TOTP", "Using multi-field TOTP flow - reusing cached TOTP",
task_id=task.task_id,
action_idx=action_index, action_idx=action_index,
totp=current_totp, totp=current_totp,
current_time=current_time, current_time=current_time,
@@ -1050,7 +1010,6 @@ async def _handle_multi_field_totp_sequence(
LOG.debug( LOG.debug(
"6th digit: TOTP not yet valid, waiting until valid_from", "6th digit: TOTP not yet valid, waiting until valid_from",
task_id=task.task_id,
action_idx=action_index, action_idx=action_index,
current_time=current_time, current_time=current_time,
totp_valid_from=totp_valid_from, totp_valid_from=totp_valid_from,
@@ -1062,7 +1021,6 @@ async def _handle_multi_field_totp_sequence(
LOG.debug( LOG.debug(
"6th digit: Finished waiting, TOTP is now valid", "6th digit: Finished waiting, TOTP is now valid",
task_id=task.task_id,
action_idx=action_index, action_idx=action_index,
) )
@@ -1116,8 +1074,6 @@ async def handle_input_text_action(
LOG.warning( LOG.warning(
"Try to input text on a disabled element", "Try to input text on a disabled element",
action_type=action.action_type, action_type=action.action_type,
task_id=task.task_id,
step_id=step.step_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
) )
return [ActionFailure(InteractWithDisabledElement(skyvern_element.get_id()))] return [ActionFailure(InteractWithDisabledElement(skyvern_element.get_id()))]
@@ -1131,8 +1087,6 @@ async def handle_input_text_action(
if await skyvern_element.get_selectable(): if await skyvern_element.get_selectable():
LOG.info( LOG.info(
"Input element is selectable, doing select actions", "Input element is selectable, doing select actions",
task_id=task.task_id,
step_id=step.step_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
action=action, action=action,
) )
@@ -1163,8 +1117,6 @@ async def handle_input_text_action(
except Exception: except Exception:
LOG.info( LOG.info(
"Failed to clear up the input, but continue to input", "Failed to clear up the input, but continue to input",
task_id=task.task_id,
step_id=step.step_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
) )
@@ -1174,8 +1126,6 @@ async def handle_input_text_action(
# sometimes we notice `press_key()` raise a timeout but actually the dropdown is opened. # sometimes we notice `press_key()` raise a timeout but actually the dropdown is opened.
LOG.info( LOG.info(
"Timeout to press ArrowDown to open dropdown, ignore the timeout and continue to execute the action", "Timeout to press ArrowDown to open dropdown, ignore the timeout and continue to execute the action",
task_id=task.task_id,
step_id=step.step_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
action=action, action=action,
) )
@@ -1194,8 +1144,6 @@ async def handle_input_text_action(
if len(incremental_element) == 0: if len(incremental_element) == 0:
LOG.info( LOG.info(
"No new element detected, indicating it couldn't be a selectable auto-completion input", "No new element detected, indicating it couldn't be a selectable auto-completion input",
task_id=task.task_id,
step_id=step.step_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
action=action, action=action,
) )
@@ -1230,16 +1178,12 @@ async def handle_input_text_action(
if select_result.action_result is None: if select_result.action_result is None:
LOG.info( LOG.info(
"It might not be a selectable auto-completion input, exit the custom selection mode", "It might not be a selectable auto-completion input, exit the custom selection mode",
task_id=task.task_id,
step_id=step.step_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
action=action, action=action,
) )
else: else:
LOG.warning( LOG.warning(
"Custom selection returned an error, continue to input text", "Custom selection returned an error, continue to input text",
task_id=task.task_id,
step_id=step.step_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
action=action, action=action,
err_msg=select_result.action_result.exception_message, err_msg=select_result.action_result.exception_message,
@@ -1249,8 +1193,6 @@ async def handle_input_text_action(
LOG.warning( LOG.warning(
"Failed to do custom selection transformed from input action, continue to input text", "Failed to do custom selection transformed from input action, continue to input text",
exc_info=True, exc_info=True,
task_id=task.task_id,
step_id=step.step_id,
) )
await skyvern_element.scroll_into_view() await skyvern_element.scroll_into_view()
finally: finally:
@@ -1261,8 +1203,6 @@ async def handle_input_text_action(
if blocking_element and exist: if blocking_element and exist:
LOG.info( LOG.info(
"Find a blocking element to the current element, going to blur the blocking element first", "Find a blocking element to the current element, going to blur the blocking element first",
task_id=task.task_id,
step_id=step.step_id,
blocking_element=blocking_element.get_locator(), blocking_element=blocking_element.get_locator(),
) )
if await blocking_element.get_locator().count(): if await blocking_element.get_locator().count():
@@ -1344,8 +1284,6 @@ async def handle_input_text_action(
LOG.info( LOG.info(
"Failed to find the blocking element, continue with the original element", "Failed to find the blocking element, continue with the original element",
exc_info=True, exc_info=True,
task_id=task.task_id,
step_id=step.step_id,
) )
if is_totp_value: if is_totp_value:
@@ -1374,7 +1312,6 @@ async def handle_input_text_action(
else: else:
LOG.error( LOG.error(
"TOTP too short for action index", "TOTP too short for action index",
task_id=task.task_id,
action_idx=action_index, action_idx=action_index,
totp_length=len(current_totp) if current_totp else 0, totp_length=len(current_totp) if current_totp else 0,
) )
@@ -1449,16 +1386,12 @@ async def handle_input_text_action(
# These are expected during page navigation/auto-submit, silently continue # These are expected during page navigation/auto-submit, silently continue
LOG.debug( LOG.debug(
"Playwright error during incremental element processing (likely page navigation)", "Playwright error during incremental element processing (likely page navigation)",
task_id=task.task_id,
step_id=step.step_id,
error_type=type(inc_error).__name__, error_type=type(inc_error).__name__,
error_message=error_message, error_message=error_message,
) )
else: else:
LOG.warning( LOG.warning(
"Unexpected Playwright error during incremental element processing", "Unexpected Playwright error during incremental element processing",
task_id=task.task_id,
step_id=step.step_id,
error_type=type(inc_error).__name__, error_type=type(inc_error).__name__,
error_message=str(inc_error), error_message=str(inc_error),
) )
@@ -1467,8 +1400,6 @@ async def handle_input_text_action(
# Handle any other unexpected errors during incremental element processing # Handle any other unexpected errors during incremental element processing
LOG.warning( LOG.warning(
"Unexpected error during incremental element processing", "Unexpected error during incremental element processing",
task_id=task.task_id,
step_id=step.step_id,
error_type=type(inc_error).__name__, error_type=type(inc_error).__name__,
error_message=str(inc_error), error_message=str(inc_error),
) )
@@ -1480,11 +1411,7 @@ async def handle_input_text_action(
except Exception as e: except Exception as e:
# Handle any other unexpected errors during text input # Handle any other unexpected errors during text input
LOG.exception( LOG.exception("Failed to input the value or finish the auto completion")
"Failed to input the value or finish the auto completion",
task_id=task.task_id,
step_id=step.step_id,
)
raise e raise e
finally: finally:
# HACK: force to finish missing auto completion input # HACK: force to finish missing auto completion input
@@ -1492,8 +1419,6 @@ async def handle_input_text_action(
LOG.debug( LOG.debug(
"Trigger input-selection hack, pressing Tab to choose one", "Trigger input-selection hack, pressing Tab to choose one",
action=action, action=action,
task_id=task.task_id,
step_id=step.step_id,
) )
await skyvern_element.press_key("Tab") await skyvern_element.press_key("Tab")
@@ -1536,8 +1461,6 @@ async def handle_upload_file_action(
LOG.warning( LOG.warning(
"Try to upload file on a disabled element", "Try to upload file on a disabled element",
action_type=action.action_type, action_type=action.action_type,
task_id=task.task_id,
step_id=step.step_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
) )
return [ActionFailure(InteractWithDisabledElement(skyvern_element.get_id()))] return [ActionFailure(InteractWithDisabledElement(skyvern_element.get_id()))]
@@ -1700,8 +1623,6 @@ async def handle_select_option_action(
LOG.warning( LOG.warning(
"Try to select on a disabled element", "Try to select on a disabled element",
action_type=action.action_type, action_type=action.action_type,
task_id=task.task_id,
step_id=step.step_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
) )
return [ActionFailure(InteractWithDisabledElement(skyvern_element.get_id()))] return [ActionFailure(InteractWithDisabledElement(skyvern_element.get_id()))]
@@ -1710,8 +1631,6 @@ async def handle_select_option_action(
LOG.info( LOG.info(
"SelectOptionAction is on <select>", "SelectOptionAction is on <select>",
action=action, action=action,
task_id=task.task_id,
step_id=step.step_id,
) )
try: try:
@@ -1719,8 +1638,6 @@ async def handle_select_option_action(
except Exception: except Exception:
LOG.warning( LOG.warning(
"Failed to find the blocking element, continue to select on the original <select>", "Failed to find the blocking element, continue to select on the original <select>",
task_id=task.task_id,
step_id=step.step_id,
exc_info=True, exc_info=True,
) )
return await normal_select( return await normal_select(
@@ -1733,10 +1650,7 @@ async def handle_select_option_action(
) )
if blocking_element is None: if blocking_element is None:
LOG.info( LOG.info("Try to scroll the element into view, then detecting the blocking element")
"Try to scroll the element into view, then detecting the blocking element",
step_id=step.step_id,
)
try: try:
await skyvern_element.scroll_into_view() await skyvern_element.scroll_into_view()
blocking_element, exist = await skyvern_element.find_blocking_element(dom=dom) blocking_element, exist = await skyvern_element.find_blocking_element(dom=dom)
@@ -1744,7 +1658,6 @@ async def handle_select_option_action(
LOG.warning( LOG.warning(
"Failed to find the blocking element when scrolling into view, fallback to normal select", "Failed to find the blocking element when scrolling into view, fallback to normal select",
action=action, action=action,
step_id=step.step_id,
exc_info=True, exc_info=True,
) )
return await normal_select( return await normal_select(
@@ -1757,8 +1670,6 @@ async def handle_select_option_action(
) )
LOG.info( LOG.info(
"<select> is blocked by another element, going to select on the blocking element", "<select> is blocked by another element, going to select on the blocking element",
task_id=task.task_id,
step_id=step.step_id,
blocking_element=blocking_element.get_id(), blocking_element=blocking_element.get_id(),
) )
select_action = SelectOptionAction( select_action = SelectOptionAction(
@@ -1774,8 +1685,6 @@ async def handle_select_option_action(
LOG.info( LOG.info(
"SelectOptionAction is on <input> checkbox", "SelectOptionAction is on <input> checkbox",
action=action, action=action,
task_id=task.task_id,
step_id=step.step_id,
) )
check_action = CheckboxAction(element_id=action.element_id, is_checked=True) check_action = CheckboxAction(element_id=action.element_id, is_checked=True)
return await handle_checkbox_action(check_action, page, scraped_page, task, step) return await handle_checkbox_action(check_action, page, scraped_page, task, step)
@@ -1784,8 +1693,6 @@ async def handle_select_option_action(
LOG.info( LOG.info(
"SelectOptionAction is on <input> radio", "SelectOptionAction is on <input> radio",
action=action, action=action,
task_id=task.task_id,
step_id=step.step_id,
) )
click_action = ClickAction(element_id=action.element_id) click_action = ClickAction(element_id=action.element_id)
return await chain_click(task, scraped_page, page, click_action, skyvern_element) return await chain_click(task, scraped_page, page, click_action, skyvern_element)
@@ -1795,8 +1702,6 @@ async def handle_select_option_action(
LOG.info( LOG.info(
"SelectOptionAction is on <input> button", "SelectOptionAction is on <input> button",
action=action, action=action,
task_id=task.task_id,
step_id=step.step_id,
) )
click_action = ClickAction(element_id=action.element_id) click_action = ClickAction(element_id=action.element_id)
return await chain_click(task, scraped_page, page, click_action, skyvern_element) return await chain_click(task, scraped_page, page, click_action, skyvern_element)
@@ -1832,8 +1737,6 @@ async def handle_select_option_action(
LOG.info( LOG.info(
"No incremental elements detected for the input element, trying to press Arrowdown to trigger the dropdown", "No incremental elements detected for the input element, trying to press Arrowdown to trigger the dropdown",
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
task_id=task.task_id,
step_id=step.step_id,
) )
await skyvern_element.scroll_into_view() await skyvern_element.scroll_into_view()
await skyvern_element.press_key("ArrowDown") await skyvern_element.press_key("ArrowDown")
@@ -1915,8 +1818,6 @@ async def handle_select_option_action(
"Try to select by value in custom select", "Try to select by value in custom select",
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
value=suggested_value, value=suggested_value,
task_id=task.task_id,
step_id=step.step_id,
) )
try: try:
await incremental_scraped.start_listen_dom_increment(await skyvern_element.get_element_handler()) await incremental_scraped.start_listen_dom_increment(await skyvern_element.get_element_handler())
@@ -1929,8 +1830,6 @@ async def handle_select_option_action(
LOG.info( LOG.info(
"fail to open dropdown by clicking, try to press arrow down to open", "fail to open dropdown by clicking, try to press arrow down to open",
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
task_id=task.task_id,
step_id=step.step_id,
) )
await skyvern_element.scroll_into_view() await skyvern_element.scroll_into_view()
await skyvern_element.press_key("ArrowDown") await skyvern_element.press_key("ArrowDown")
@@ -2038,8 +1937,6 @@ async def handle_complete_action(
if not action.verified and task.navigation_goal: if not action.verified and task.navigation_goal:
LOG.info( LOG.info(
"CompleteAction hasn't been verified, going to verify the user goal", "CompleteAction hasn't been verified, going to verify the user goal",
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
try: try:
@@ -2047,8 +1944,6 @@ async def handle_complete_action(
except Exception as e: except Exception as e:
LOG.exception( LOG.exception(
"Failed to verify the complete action", "Failed to verify the complete action",
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
return [ActionFailure(exception=e)] return [ActionFailure(exception=e)]
@@ -2058,8 +1953,6 @@ async def handle_complete_action(
LOG.info( LOG.info(
"CompleteAction has been verified successfully", "CompleteAction has been verified successfully",
task_id=task.task_id,
step_id=step.step_id,
workflow_run_id=task.workflow_run_id, workflow_run_id=task.workflow_run_id,
) )
action.verified = True action.verified = True
@@ -2092,7 +1985,7 @@ async def handle_extract_action(
extracted_data = scrape_action_result.scraped_data extracted_data = scrape_action_result.scraped_data
return [ActionSuccess(data=extracted_data)] return [ActionSuccess(data=extracted_data)]
else: else:
LOG.warning("No data extraction goal, skipping extract action", step_id=step.step_id) LOG.warning("No data extraction goal, skipping extract action")
return [ActionFailure(exception=Exception("No data extraction goal"))] return [ActionFailure(exception=Exception("No data extraction goal"))]
@@ -2156,8 +2049,6 @@ async def handle_verification_code_action(
) -> list[ActionResult]: ) -> list[ActionResult]:
LOG.info( LOG.info(
"Setting verification code in skyvern context", "Setting verification code in skyvern context",
task_id=task.task_id,
step_id=step.step_id,
verification_code=action.verification_code, verification_code=action.verification_code,
) )
current_context = skyvern_context.ensure_context() current_context = skyvern_context.ensure_context()
@@ -2299,7 +2190,6 @@ async def chain_click(
try: try:
LOG.info( LOG.info(
"Chain click: it's a label element. going to try for-click", "Chain click: it's a label element. going to try for-click",
task_id=task.task_id,
action=action, action=action,
element=str(skyvern_element), element=str(skyvern_element),
locator=locator, locator=locator,
@@ -2316,7 +2206,6 @@ async def chain_click(
# since it's a click action, the target element we're searching should only be INPUT # since it's a click action, the target element we're searching should only be INPUT
LOG.info( LOG.info(
"Chain click: it's a label element. going to check for input of the direct children", "Chain click: it's a label element. going to check for input of the direct children",
task_id=task.task_id,
action=action, action=action,
element=str(skyvern_element), element=str(skyvern_element),
locator=locator, locator=locator,
@@ -2336,7 +2225,6 @@ async def chain_click(
try: try:
LOG.info( LOG.info(
"Chain click: it's a non-label element. going to find the bound label element by attribute id and click", "Chain click: it's a non-label element. going to find the bound label element by attribute id and click",
task_id=task.task_id,
action=action, action=action,
element=str(skyvern_element), element=str(skyvern_element),
locator=locator, locator=locator,
@@ -2353,7 +2241,6 @@ async def chain_click(
# so we check the direct parent if it's a label element # so we check the direct parent if it's a label element
LOG.info( LOG.info(
"Chain click: it's a non-label element. going to find the bound label element by direct parent", "Chain click: it's a non-label element. going to find the bound label element by direct parent",
task_id=task.task_id,
action=action, action=action,
element=str(skyvern_element), element=str(skyvern_element),
locator=locator, locator=locator,
@@ -2368,7 +2255,6 @@ async def chain_click(
if not await skyvern_element.is_visible(): if not await skyvern_element.is_visible():
LOG.info( LOG.info(
"Chain click: exit since the element is not visible on the page anymore", "Chain click: exit since the element is not visible on the page anymore",
task_id=task.task_id,
action=action, action=action,
element=str(skyvern_element), element=str(skyvern_element),
locator=locator, locator=locator,
@@ -2382,7 +2268,6 @@ async def chain_click(
if not blocked: if not blocked:
LOG.info( LOG.info(
"Chain click: exit since the element is not blocking by any element", "Chain click: exit since the element is not blocking by any element",
task_id=task.task_id,
action=action, action=action,
element=str(skyvern_element), element=str(skyvern_element),
locator=locator, locator=locator,
@@ -2392,7 +2277,6 @@ async def chain_click(
try: try:
LOG.info( LOG.info(
"Chain click: element is blocked by an non-interactable element, try to click by the coordinates", "Chain click: element is blocked by an non-interactable element, try to click by the coordinates",
task_id=task.task_id,
action=action, action=action,
element=str(skyvern_element), element=str(skyvern_element),
locator=locator, locator=locator,
@@ -2407,7 +2291,6 @@ async def chain_click(
LOG.info( LOG.info(
"Chain click: element is blocked by an non-interactable element, going to use javascript click instead of playwright click", "Chain click: element is blocked by an non-interactable element, going to use javascript click instead of playwright click",
task_id=task.task_id,
action=action, action=action,
element=str(skyvern_element), element=str(skyvern_element),
locator=locator, locator=locator,
@@ -2423,7 +2306,6 @@ async def chain_click(
try: try:
LOG.debug( LOG.debug(
"Chain click: verifying the blocking element is parent or sibling of the target element", "Chain click: verifying the blocking element is parent or sibling of the target element",
task_id=task.task_id,
action=action, action=action,
element=str(blocking_element), element=str(blocking_element),
locator=locator, locator=locator,
@@ -2433,7 +2315,6 @@ async def chain_click(
) or await blocking_element.is_sibling_of(await skyvern_element.get_element_handler()): ) or await blocking_element.is_sibling_of(await skyvern_element.get_element_handler()):
LOG.info( LOG.info(
"Chain click: element is blocked by other elements, going to click on the blocking element", "Chain click: element is blocked by other elements, going to click on the blocking element",
task_id=task.task_id,
action=action, action=action,
element=str(blocking_element), element=str(blocking_element),
locator=locator, locator=locator,
@@ -2566,11 +2447,7 @@ async def choose_auto_completion_dropdown(
new_elements_ids=new_interactable_element_ids, new_elements_ids=new_interactable_element_ids,
local_datetime=datetime.now(skyvern_context.ensure_context().tz_info).isoformat(), local_datetime=datetime.now(skyvern_context.ensure_context().tz_info).isoformat(),
) )
LOG.info( LOG.info("Confirm if it's an auto completion dropdown")
"Confirm if it's an auto completion dropdown",
step_id=step.step_id,
task_id=task.task_id,
)
json_response = await app.AUTO_COMPLETION_LLM_API_HANDLER( json_response = await app.AUTO_COMPLETION_LLM_API_HANDLER(
prompt=auto_completion_confirm_prompt, step=step, prompt_name="auto-completion-choose-option" prompt=auto_completion_confirm_prompt, step=step, prompt_name="auto-completion-choose-option"
) )
@@ -2580,8 +2457,6 @@ async def choose_auto_completion_dropdown(
LOG.info( LOG.info(
"Decided to directly search with the current value", "Decided to directly search with the current value",
value=text, value=text,
step_id=step.step_id,
task_id=task.task_id,
) )
await skyvern_element.press_key("Enter") await skyvern_element.press_key("Enter")
return result return result
@@ -2607,8 +2482,6 @@ async def choose_auto_completion_dropdown(
LOG.info( LOG.info(
"Find a suitable option to choose", "Find a suitable option to choose",
element_id=element_id, element_id=element_id,
step_id=step.step_id,
task_id=task.task_id,
) )
locator = current_frame.locator(f'[{SKYVERN_ID_ATTR}="{element_id}"]') locator = current_frame.locator(f'[{SKYVERN_ID_ATTR}="{element_id}"]')
@@ -2624,8 +2497,6 @@ async def choose_auto_completion_dropdown(
"Failed to choose the auto completion dropdown", "Failed to choose the auto completion dropdown",
exc_info=True, exc_info=True,
input_value=text, input_value=text,
task_id=task.task_id,
step_id=step.step_id,
) )
result.action_result = ActionFailure(exception=e) result.action_result = ActionFailure(exception=e)
return result return result
@@ -2659,8 +2530,6 @@ async def input_or_auto_complete_input(
) -> ActionResult | None: ) -> ActionResult | None:
LOG.info( LOG.info(
"Trigger auto completion", "Trigger auto completion",
task_id=task.task_id,
step_id=step.step_id,
element_id=skyvern_element.get_id(), element_id=skyvern_element.get_id(),
) )
@@ -2682,8 +2551,6 @@ async def input_or_auto_complete_input(
LOG.info( LOG.info(
"Try the potential value for auto completion", "Try the potential value for auto completion",
step_id=step.step_id,
task_id=task.task_id,
input_value=current_value, input_value=current_value,
) )
result = await choose_auto_completion_dropdown( result = await choose_auto_completion_dropdown(
@@ -2704,8 +2571,6 @@ async def input_or_auto_complete_input(
LOG.info( LOG.info(
"Stop generating potential values for the auto-completion since it's a search bar", "Stop generating potential values for the auto-completion since it's a search bar",
context=input_or_select_context, context=input_or_select_context,
step_id=step.step_id,
task_id=task.task_id,
) )
return None return None
@@ -2731,8 +2596,6 @@ async def input_or_auto_complete_input(
LOG.info( LOG.info(
"Ask LLM to give potential values based on the current value", "Ask LLM to give potential values based on the current value",
current_value=current_value, current_value=current_value,
step_id=step.step_id,
task_id=task.task_id,
potential_value_count=AUTO_COMPLETION_POTENTIAL_VALUES_COUNT, potential_value_count=AUTO_COMPLETION_POTENTIAL_VALUES_COUNT,
) )
json_respone = await app.SECONDARY_LLM_API_HANDLER( json_respone = await app.SECONDARY_LLM_API_HANDLER(
@@ -2745,15 +2608,11 @@ async def input_or_auto_complete_input(
if not value: if not value:
LOG.info( LOG.info(
"Empty potential value, skip this attempt", "Empty potential value, skip this attempt",
step_id=step.step_id,
task_id=task.task_id,
value=each_value, value=each_value,
) )
continue continue
LOG.info( LOG.info(
"Try the potential value for auto completion", "Try the potential value for auto completion",
step_id=step.step_id,
task_id=task.task_id,
input_value=value, input_value=value,
) )
result = await choose_auto_completion_dropdown( result = await choose_auto_completion_dropdown(
@@ -2777,8 +2636,6 @@ async def input_or_auto_complete_input(
if current_attemp < MAX_AUTO_COMPLETE_ATTEMP: if current_attemp < MAX_AUTO_COMPLETE_ATTEMP:
LOG.info( LOG.info(
"Ask LLM to tweak the current value based on tried input values", "Ask LLM to tweak the current value based on tried input values",
step_id=step.step_id,
task_id=task.task_id,
current_value=current_value, current_value=current_value,
current_attemp=current_attemp, current_attemp=current_attemp,
) )
@@ -2802,8 +2659,6 @@ async def input_or_auto_complete_input(
return ActionFailure(ErrEmptyTweakValue(reasoning=context_reasoning, current_value=current_value)) return ActionFailure(ErrEmptyTweakValue(reasoning=context_reasoning, current_value=current_value))
LOG.info( LOG.info(
"Ask LLM tweaked the current value with a new value", "Ask LLM tweaked the current value with a new value",
step_id=step.step_id,
task_id=task.task_id,
field_information=input_or_select_context.field, field_information=input_or_select_context.field,
current_value=current_value, current_value=current_value,
new_value=new_current_value, new_value=new_current_value,
@@ -2814,8 +2669,6 @@ async def input_or_auto_complete_input(
LOG.warning( LOG.warning(
"Auto completion didn't finish, this might leave the input value to be empty.", "Auto completion didn't finish, this might leave the input value to be empty.",
context=input_or_select_context, context=input_or_select_context,
step_id=step.step_id,
task_id=task.task_id,
) )
return None return None
@@ -2856,8 +2709,6 @@ async def sequentially_select_from_dropdown(
LOG.info( LOG.info(
"Exit custom selection mode since it's a non-force search bar", "Exit custom selection mode since it's a non-force search bar",
context=input_or_select_context, context=input_or_select_context,
task_id=task.task_id,
step_id=step.step_id,
) )
return None return None
@@ -2898,16 +2749,12 @@ async def sequentially_select_from_dropdown(
LOG.warning( LOG.warning(
"Reaching the max selection depth", "Reaching the max selection depth",
depth=i, depth=i,
task_id=task.task_id,
step_id=step.step_id,
) )
break break
LOG.info( LOG.info(
"Seems to be a multi-level selection, continue to select until it finishes", "Seems to be a multi-level selection, continue to select until it finishes",
selected_time=i + 1, selected_time=i + 1,
task_id=task.task_id,
step_id=step.step_id,
) )
# wait to load new options # 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)
@@ -2927,8 +2774,6 @@ async def sequentially_select_from_dropdown(
LOG.info( LOG.info(
"No incremental element detected for the next level selection, going to quit the custom select mode", "No incremental element detected for the next level selection, going to quit the custom select mode",
selected_time=i + 1, selected_time=i + 1,
task_id=task.task_id,
step_id=step.step_id,
) )
return single_select_result return single_select_result
@@ -2938,16 +2783,12 @@ async def sequentially_select_from_dropdown(
if single_select_result.action_type is not None and single_select_result.action_type == ActionType.INPUT_TEXT: if single_select_result.action_type is not None and single_select_result.action_type == ActionType.INPUT_TEXT:
LOG.info( LOG.info(
"It's an input mini action, going to continue the select action", "It's an input mini action, going to continue the select action",
step_id=step.step_id,
task_id=task.task_id,
) )
continue continue
if continue_until_close: if continue_until_close:
LOG.info( LOG.info(
"Continue the selecting until the dropdown menu is closed", "Continue the selecting until the dropdown menu is closed",
step_id=step.step_id,
task_id=task.task_id,
) )
continue continue
@@ -2971,17 +2812,13 @@ async def sequentially_select_from_dropdown(
prompt=prompt, screenshots=[screenshot], step=step, prompt_name="confirm-multi-selection-finish" prompt=prompt, screenshots=[screenshot], step=step, prompt_name="confirm-multi-selection-finish"
) )
if json_response.get("is_mini_goal_finished", False): if json_response.get("is_mini_goal_finished", False):
LOG.info("The user has finished the selection for the current opened dropdown", step_id=step.step_id) LOG.info("The user has finished the selection for the current opened dropdown")
return single_select_result return single_select_result
else: else:
if input_or_select_context.is_date_related: if input_or_select_context.is_date_related:
if skyvern_element.get_tag_name() == InteractiveElement.INPUT and action.option.label: if skyvern_element.get_tag_name() == InteractiveElement.INPUT and action.option.label:
try: try:
LOG.info( LOG.info("Try to input the date directly")
"Try to input the date directly",
step_id=step.step_id,
task_id=task.task_id,
)
await skyvern_element.input_sequentially(action.option.label) await skyvern_element.input_sequentially(action.option.label)
result = CustomSingleSelectResult(skyvern_frame=skyvern_frame) result = CustomSingleSelectResult(skyvern_frame=skyvern_frame)
result.action_result = ActionSuccess() result.action_result = ActionSuccess()
@@ -2991,8 +2828,6 @@ async def sequentially_select_from_dropdown(
LOG.warning( LOG.warning(
"Failed to input the date directly", "Failed to input the date directly",
exc_info=True, exc_info=True,
step_id=step.step_id,
task_id=task.task_id,
) )
if single_select_result and single_select_result.action_result: if single_select_result and single_select_result.action_result:
@@ -3073,11 +2908,7 @@ async def select_from_emerging_elements(
navigation_payload_str=json.dumps(task.navigation_payload), navigation_payload_str=json.dumps(task.navigation_payload),
local_datetime=datetime.now(skyvern_context.ensure_context().tz_info).isoformat(), local_datetime=datetime.now(skyvern_context.ensure_context().tz_info).isoformat(),
) )
LOG.info( LOG.info("Calling LLM to find the match element")
"Calling LLM to find the match element",
step_id=step.step_id,
task_id=task.task_id,
)
llm_api_handler = LLMAPIHandlerFactory.get_override_llm_api_handler(task.llm_key, default=app.LLM_API_HANDLER) llm_api_handler = LLMAPIHandlerFactory.get_override_llm_api_handler(task.llm_key, default=app.LLM_API_HANDLER)
json_response = await llm_api_handler(prompt=prompt, step=step, prompt_name="custom-select") json_response = await llm_api_handler(prompt=prompt, step=step, prompt_name="custom-select")
@@ -3086,8 +2917,6 @@ async def select_from_emerging_elements(
"LLM response for the matched element", "LLM response for the matched element",
matched_value=value, matched_value=value,
response=json_response, response=json_response,
step_id=step.step_id,
task_id=task.task_id,
) )
action_type_str: str = json_response.get("action_type", "") or "" action_type_str: str = json_response.get("action_type", "") or ""
@@ -3211,11 +3040,7 @@ async def select_from_dropdown(
local_datetime=datetime.now(skyvern_context.tz_info).isoformat(), local_datetime=datetime.now(skyvern_context.tz_info).isoformat(),
) )
LOG.info( LOG.info("Calling LLM to find the match element")
"Calling LLM to find the match element",
step_id=step.step_id,
task_id=task.task_id,
)
json_response = await app.CUSTOM_SELECT_AGENT_LLM_API_HANDLER(prompt=prompt, step=step, prompt_name="custom-select") json_response = await app.CUSTOM_SELECT_AGENT_LLM_API_HANDLER(prompt=prompt, step=step, prompt_name="custom-select")
value: str | None = json_response.get("value", None) value: str | None = json_response.get("value", None)
single_select_result.value = value single_select_result.value = value
@@ -3226,8 +3051,6 @@ async def select_from_dropdown(
"LLM response for the matched element", "LLM response for the matched element",
matched_value=value, matched_value=value,
response=json_response, response=json_response,
step_id=step.step_id,
task_id=task.task_id,
) )
action_type: str = json_response.get("action_type", "") or "" action_type: str = json_response.get("action_type", "") or ""
@@ -3242,8 +3065,6 @@ async def select_from_dropdown(
LOG.info( LOG.info(
"The selected option is not relevant to the target value", "The selected option is not relevant to the target value",
element_id=element_id, element_id=element_id,
task_id=task.task_id,
step_id=step.step_id,
) )
return single_select_result return single_select_result
@@ -3251,8 +3072,6 @@ async def select_from_dropdown(
LOG.info( LOG.info(
"No clickable option found, but found input element to search", "No clickable option found, but found input element to search",
element_id=element_id, element_id=element_id,
task_id=task.task_id,
step_id=step.step_id,
) )
try: try:
actual_value = await get_actual_value_of_parameter_if_secret(task=task, parameter=value) actual_value = await get_actual_value_of_parameter_if_secret(task=task, parameter=value)
@@ -3439,8 +3258,6 @@ async def locate_dropdown_menu(
if not element_id: if not element_id:
LOG.debug( LOG.debug(
"Skip the element without id for the dropdown menu confirm", "Skip the element without id for the dropdown menu confirm",
step_id=step.step_id,
task_id=task.task_id,
element=element_dict, element=element_dict,
) )
continue continue
@@ -3451,8 +3268,6 @@ async def locate_dropdown_menu(
LOG.debug( LOG.debug(
"Failed to get head element in the incremental page", "Failed to get head element in the incremental page",
element_id=element_id, element_id=element_id,
step_id=step.step_id,
task_id=task.task_id,
exc_info=True, exc_info=True,
) )
continue continue
@@ -3465,8 +3280,6 @@ async def locate_dropdown_menu(
): ):
LOG.debug( LOG.debug(
"Skip the element since it's too far away from the anchor element", "Skip the element since it's too far away from the anchor element",
step_id=step.step_id,
task_id=task.task_id,
element_id=element_id, element_id=element_id,
) )
continue continue
@@ -3475,8 +3288,6 @@ async def locate_dropdown_menu(
LOG.info( LOG.info(
"Failed to calculate the distance between the elements", "Failed to calculate the distance between the elements",
element_id=element_id, element_id=element_id,
step_id=step.step_id,
task_id=task.task_id,
exc_info=True, exc_info=True,
) )
continue continue
@@ -3484,8 +3295,6 @@ async def locate_dropdown_menu(
if not await skyvern_frame.get_element_visible(await head_element.get_element_handler()): if not await skyvern_frame.get_element_visible(await head_element.get_element_handler()):
LOG.debug( LOG.debug(
"Skip the element since it's invisible", "Skip the element since it's invisible",
step_id=step.step_id,
task_id=task.task_id,
element_id=element_id, element_id=element_id,
) )
continue continue
@@ -3499,8 +3308,6 @@ async def locate_dropdown_menu(
await SkyvernElement.create_from_incremental(incremental_scraped, ul_or_listbox_element_id) await SkyvernElement.create_from_incremental(incremental_scraped, ul_or_listbox_element_id)
LOG.info( LOG.info(
"Confirm it's an opened dropdown menu since it includes <ul> or <role='listbox'>", "Confirm it's an opened dropdown menu since it includes <ul> or <role='listbox'>",
step_id=step.step_id,
task_id=task.task_id,
element_id=element_id, element_id=element_id,
) )
return await SkyvernElement.create_from_incremental( return await SkyvernElement.create_from_incremental(
@@ -3510,8 +3317,6 @@ async def locate_dropdown_menu(
LOG.debug( LOG.debug(
"Failed to get <ul> or <role='listbox'> element in the incremental page", "Failed to get <ul> or <role='listbox'> element in the incremental page",
element_id=element_id, element_id=element_id,
step_id=step.step_id,
task_id=task.task_id,
exc_info=True, exc_info=True,
) )
# check if opening react-datetime datepicker: https://github.com/arqex/react-datetime # check if opening react-datetime datepicker: https://github.com/arqex/react-datetime
@@ -3520,8 +3325,6 @@ async def locate_dropdown_menu(
LOG.info( LOG.info(
"Confirm it's an opened React-Datetime datepicker", "Confirm it's an opened React-Datetime datepicker",
element_id=element_id, element_id=element_id,
step_id=step.step_id,
task_id=task.task_id,
) )
return head_element return head_element
@@ -3534,8 +3337,6 @@ async def locate_dropdown_menu(
dropdown_confirm_prompt = prompt_engine.load_prompt("opened-dropdown-confirm") dropdown_confirm_prompt = prompt_engine.load_prompt("opened-dropdown-confirm")
LOG.debug( LOG.debug(
"Confirm if it's an opened dropdown menu", "Confirm if it's an opened dropdown menu",
step_id=step.step_id,
task_id=task.task_id,
element=element_dict, element=element_dict,
) )
json_response = await app.SECONDARY_LLM_API_HANDLER( json_response = await app.SECONDARY_LLM_API_HANDLER(
@@ -3545,8 +3346,6 @@ async def locate_dropdown_menu(
if is_opened_dropdown_menu: if is_opened_dropdown_menu:
LOG.info( LOG.info(
"Opened dropdown menu found", "Opened dropdown menu found",
step_id=step.step_id,
task_id=task.task_id,
element_id=element_id, element_id=element_id,
) )
return await SkyvernElement.create_from_incremental(incre_page=incremental_scraped, element_id=element_id) return await SkyvernElement.create_from_incremental(incre_page=incremental_scraped, element_id=element_id)
@@ -3571,8 +3370,6 @@ async def try_to_find_potential_scrollable_element(
LOG.debug( LOG.debug(
"Found 'ul or listbox' element in children list", "Found 'ul or listbox' element in children list",
element_id=found_element_id, element_id=found_element_id,
step_id=step.step_id,
task_id=task.task_id,
) )
try: try:
@@ -3581,8 +3378,6 @@ async def try_to_find_potential_scrollable_element(
LOG.debug( LOG.debug(
"Failed to get head element by found element id, use the original element id", "Failed to get head element by found element id, use the original element id",
element_id=found_element_id, element_id=found_element_id,
step_id=step.step_id,
task_id=task.task_id,
exc_info=True, exc_info=True,
) )
return skyvern_element return skyvern_element
@@ -3601,11 +3396,7 @@ async def scroll_down_to_load_all_options(
page_by_page: bool = False, page_by_page: bool = False,
is_continue: Callable[[IncrementalScrapePage], Awaitable[bool]] | None = None, is_continue: Callable[[IncrementalScrapePage], Awaitable[bool]] | None = None,
) -> None: ) -> None:
LOG.info( LOG.info("Scroll down the dropdown menu to load all options")
"Scroll down the dropdown menu to load all options",
step_id=step.step_id if step else "none",
task_id=task.task_id if task else "none",
)
timeout = settings.BROWSER_ACTION_TIMEOUT_MS timeout = settings.BROWSER_ACTION_TIMEOUT_MS
dropdown_menu_element_handle = await scrollable_element.get_locator().element_handle(timeout=timeout) dropdown_menu_element_handle = await scrollable_element.get_locator().element_handle(timeout=timeout)
@@ -3643,8 +3434,6 @@ async def scroll_down_to_load_all_options(
LOG.info( LOG.info(
"Current incremental elements count during the scrolling", "Current incremental elements count during the scrolling",
num=current_num, num=current_num,
step_id=step.step_id if step else "none",
task_id=task.task_id if task else "none",
) )
if is_continue is not None and not await is_continue(incremental_scraped): if is_continue is not None and not await is_continue(incremental_scraped):
@@ -3692,8 +3481,6 @@ async def normal_select(
LOG.info( LOG.info(
"Parsed input/select context", "Parsed input/select context",
context=input_or_select_context, context=input_or_select_context,
task_id=task.task_id,
step_id=step.step_id,
) )
await skyvern_element.refresh_select_options() await skyvern_element.refresh_select_options()
@@ -4005,7 +3792,6 @@ async def _get_input_or_select_context(
if isinstance(json_response, list): if isinstance(json_response, list):
LOG.warning( LOG.warning(
"LLM returned list instead of dict for input/select context parsing", "LLM returned list instead of dict for input/select context parsing",
step_id=step.step_id,
original_response_type=type(json_response).__name__, original_response_type=type(json_response).__name__,
original_response_length=len(json_response) if json_response else 0, original_response_length=len(json_response) if json_response else 0,
first_item_type=type(json_response[0]).__name__ if json_response else None, first_item_type=type(json_response[0]).__name__ if json_response else None,