chore: Add temporary telemetry logs (#2284)

letta/server/rest_api/routers/v1/agents.py

@@ -17,6 +17,7 @@ from fastapi.responses import JSONResponse, StreamingResponse
 from pydantic import Field
 
 from letta.constants import DEFAULT_MESSAGE_TOOL, DEFAULT_MESSAGE_TOOL_KWARG
+from letta.log import get_logger
 from letta.orm.errors import NoResultFound
 from letta.schemas.agent import AgentState, CreateAgent, UpdateAgent
 from letta.schemas.block import (  # , BlockLabelUpdate, BlockLimitUpdate
@@ -54,6 +55,8 @@ from letta.server.server import SyncServer
 
 router = APIRouter(prefix="/agents", tags=["agents"])
 
+logger = get_logger(__name__)
+
 
 # TODO: This should be paginated
 @router.get("/", response_model=List[AgentState], operation_id="list_agents")
@@ -453,6 +456,13 @@ def get_agent_messages(
     """
     actor = server.user_manager.get_user_or_default(user_id=user_id)
 
+    # TODO: Temporary debugging logs for debugging very slow endpoint
+    import uuid
+
+    temp_rand_uuid = uuid.uuid4()
+
+    logger.info(f"[{temp_rand_uuid}] RECEIVED GET /messages for agent_id={agent_id} before={before} limit={limit}")
+
     return server.get_agent_recall_cursor(
         user_id=actor.id,
         agent_id=agent_id,
@@ -462,6 +472,7 @@ def get_agent_messages(
         return_message_object=msg_object,
         assistant_message_tool_name=assistant_message_tool_name,
         assistant_message_tool_kwarg=assistant_message_tool_kwarg,
+        temp_rand_uuid=temp_rand_uuid,
     )
 
 

letta/server/server.py

@@ -979,16 +979,32 @@ class SyncServer(Server):
         return_message_object: bool = True,
         assistant_message_tool_name: str = constants.DEFAULT_MESSAGE_TOOL,
         assistant_message_tool_kwarg: str = constants.DEFAULT_MESSAGE_TOOL_KWARG,
+        temp_rand_uuid: Optional[str] = None,
     ) -> Union[List[Message], List[LettaMessage]]:
         # TODO: Thread actor directly through this function, since the top level caller most likely already retrieved the user
+        import datetime
+
+        start_time = datetime.datetime.utcnow()
+
+        logger.info(
+            f"[{temp_rand_uuid}] {datetime.datetime.utcnow()} - Fetching actor for user_id={user_id} (Elapsed: {(datetime.datetime.utcnow() - start_time).total_seconds()}s)"
+        )
         actor = self.user_manager.get_user_or_default(user_id=user_id)
 
-        # Get the agent object (loaded in memory)
+        logger.info(
+            f"[{temp_rand_uuid}] {datetime.datetime.utcnow()} - Loading agent object for agent_id={agent_id} (Elapsed: {(datetime.datetime.utcnow() - start_time).total_seconds()}s)"
+        )
         letta_agent = self.load_agent(agent_id=agent_id, actor=actor)
 
-        # iterate over records
+        logger.info(
+            f"[{temp_rand_uuid}] {datetime.datetime.utcnow()} - Resolving start_date and end_date for filtering messages (Elapsed: {(datetime.datetime.utcnow() - start_time).total_seconds()}s)"
+        )
         start_date = self.message_manager.get_message_by_id(after, actor=actor).created_at if after else None
         end_date = self.message_manager.get_message_by_id(before, actor=actor).created_at if before else None
+
+        logger.info(
+            f"[{temp_rand_uuid}] {datetime.datetime.utcnow()} - Fetching messages for agent_id={agent_id}, start_date={start_date}, end_date={end_date}, limit={limit}, reverse={reverse} (Elapsed: {(datetime.datetime.utcnow() - start_time).total_seconds()}s)"
+        )
         records = letta_agent.message_manager.list_messages_for_agent(
             agent_id=agent_id,
             actor=actor,
@@ -998,10 +1014,15 @@ class SyncServer(Server):
             ascending=not reverse,
         )
 
+        logger.info(
+            f"[{temp_rand_uuid}] {datetime.datetime.utcnow()} - Validating message types (Elapsed: {(datetime.datetime.utcnow() - start_time).total_seconds()}s)"
+        )
         assert all(isinstance(m, Message) for m in records)
 
         if not return_message_object:
-            # If we're GETing messages in reverse, we need to reverse the inner list (generated by to_letta_message)
+            logger.info(
+                f"[{temp_rand_uuid}] {datetime.datetime.utcnow()} - Converting messages to LettaMessage objects (Elapsed: {(datetime.datetime.utcnow() - start_time).total_seconds()}s)"
+            )
             records = [
                 msg
                 for m in records
@@ -1012,8 +1033,14 @@ class SyncServer(Server):
             ]
 
         if reverse:
+            logger.info(
+                f"[{temp_rand_uuid}] {datetime.datetime.utcnow()} - Reversing message order (Elapsed: {(datetime.datetime.utcnow() - start_time).total_seconds()}s)"
+            )
             records = records[::-1]
 
+        logger.info(
+            f"[{temp_rand_uuid}] {datetime.datetime.utcnow()} - Returning {len(records)} messages (Elapsed: {(datetime.datetime.utcnow() - start_time).total_seconds()}s)"
+        )
         return records
 
     def get_server_config(self, include_defaults: bool = False) -> dict: