Add step / task / workflow run / observer metrics as logs (#1698)

Co-authored-by: Suchintan <suchintan@users.noreply.github.com>

skyvern/forge/sdk/api/llm/api_handler_factory.py

@@ -61,6 +61,7 @@ class LLMAPIHandlerFactory:
 
         async def llm_api_handler_with_router_and_fallback(
             prompt: str,
+            prompt_name: str,
             step: Step | None = None,
             observer_cruise: ObserverTask | None = None,
             observer_thought: ObserverThought | None = None,
@@ -80,6 +81,8 @@ class LLMAPIHandlerFactory:
             Returns:
                 The response from the LLM router.
             """
+            start_time = time.time()
+
             if parameters is None:
                 parameters = LLMAPIHandlerFactory.get_api_parameters(llm_config)
 
@@ -120,7 +123,6 @@ class LLMAPIHandlerFactory:
             )
             try:
                 response = await router.acompletion(model=main_model_group, messages=messages, **parameters)
-                LOG.info("LLM API call successful", llm_key=llm_key, model=llm_config.model_name)
             except litellm.exceptions.APIError as e:
                 raise LLMProviderErrorRetryableTask(llm_key) from e
             except ValueError as e:
@@ -195,6 +197,21 @@ class LLMAPIHandlerFactory:
                     ai_suggestion=ai_suggestion,
                 )
 
+            # Track LLM API handler duration
+            duration_seconds = time.time() - start_time
+            LOG.info(
+                "LLM API handler duration metrics",
+                llm_key=llm_key,
+                model=main_model_group,
+                prompt_name=prompt_name,
+                duration_seconds=duration_seconds,
+                step_id=step.step_id if step else None,
+                observer_thought_id=observer_thought.observer_thought_id if observer_thought else None,
+                organization_id=step.organization_id
+                if step
+                else (observer_thought.organization_id if observer_thought else None),
+            )
+
             return parsed_response
 
         return llm_api_handler_with_router_and_fallback
@@ -210,6 +227,7 @@ class LLMAPIHandlerFactory:
 
         async def llm_api_handler(
             prompt: str,
+            prompt_name: str,
             step: Step | None = None,
             observer_cruise: ObserverTask | None = None,
             observer_thought: ObserverThought | None = None,
@@ -217,6 +235,7 @@ class LLMAPIHandlerFactory:
             screenshots: list[bytes] | None = None,
             parameters: dict[str, Any] | None = None,
         ) -> dict[str, Any]:
+            start_time = time.time()
             active_parameters = base_parameters or {}
             if parameters is None:
                 parameters = LLMAPIHandlerFactory.get_api_parameters(llm_config)
@@ -270,14 +289,12 @@ class LLMAPIHandlerFactory:
                 # TODO (kerem): add a timeout to this call
                 # TODO (kerem): add a retry mechanism to this call (acompletion_with_retries)
                 # TODO (kerem): use litellm fallbacks? https://litellm.vercel.app/docs/tutorials/fallbacks#how-does-completion_with_fallbacks-work
-                LOG.info("Calling LLM API", llm_key=llm_key, model=llm_config.model_name)
                 response = await litellm.acompletion(
                     model=llm_config.model_name,
                     messages=messages,
                     timeout=settings.LLM_CONFIG_TIMEOUT,
                     **active_parameters,
                 )
-                LOG.info("LLM API call successful", llm_key=llm_key, model=llm_config.model_name)
             except litellm.exceptions.APIError as e:
                 raise LLMProviderErrorRetryableTask(llm_key) from e
             except CancelledError:
@@ -350,6 +367,21 @@ class LLMAPIHandlerFactory:
                     ai_suggestion=ai_suggestion,
                 )
 
+            # Track LLM API handler duration
+            duration_seconds = time.time() - start_time
+            LOG.info(
+                "LLM API handler duration metrics",
+                llm_key=llm_key,
+                prompt_name=prompt_name,
+                model=llm_config.model_name,
+                duration_seconds=duration_seconds,
+                step_id=step.step_id if step else None,
+                observer_thought_id=observer_thought.observer_thought_id if observer_thought else None,
+                organization_id=step.organization_id
+                if step
+                else (observer_thought.organization_id if observer_thought else None),
+            )
+
             return parsed_response
 
         return llm_api_handler

skyvern/forge/sdk/api/llm/models.py

@@ -79,6 +79,7 @@ class LLMAPIHandler(Protocol):
     def __call__(
         self,
         prompt: str,
+        prompt_name: str,
         step: Step | None = None,
         observer_cruise: ObserverTask | None = None,
         observer_thought: ObserverThought | None = None,