🤖 chore: Improve Assistants Run Logging (danny-avila#1801)

Author: danny-avila

api/server/services/AssistantService.js

@@ -470,13 +470,14 @@ async function processMessages(openai, messages = []) {
       }
 
       text += (content.text?.value ?? '') + ' ';
+      logger.debug('[processMessages] Processing message:', { value: text });
 
       // Process annotations if they exist
-      if (!content.text?.annotations) {
+      if (!content.text?.annotations?.length) {
         continue;
       }
 
-      logger.debug('Processing annotations:', content.text.annotations);
+      logger.debug('[processMessages] Processing annotations:', content.text.annotations);
       for (const annotation of content.text.annotations) {
         logger.debug('Current annotation:', annotation);
         let file;

api/server/services/Runs/handle.js

@@ -88,35 +88,38 @@ async function waitForRun({
   const runInfo = `user: ${openai.req.user.id} | thread_id: ${thread_id} | ${runIdLog}`;
   const raceTimeoutMs = 3000;
   let maxRetries = 5;
-  let attempt = 0;
   while (timeElapsed < timeout) {
     i++;
     logger.debug(`[heartbeat ${i}] ${runIdLog} | Retrieving run status...`);
     let updatedRun;
 
-    const startTime = Date.now();
+    let attempt = 0;
+    let startTime = Date.now();
     while (!updatedRun && attempt < maxRetries) {
       try {
         updatedRun = await withTimeout(
           retrieveRun({ thread_id, run_id, timeout: raceTimeoutMs, openai }),
           raceTimeoutMs,
-          `[heartbeat ${i}] ${runIdLog} | Run retrieval timed out at ${timeElapsed} ms. Trying again (attempt ${
+          `[heartbeat ${i}] ${runIdLog} | Run retrieval timed out after ${raceTimeoutMs} ms. Trying again (attempt ${
             attempt + 1
           } of ${maxRetries})...`,
         );
-        attempt++;
+        const endTime = Date.now();
+        logger.debug(
+          `[heartbeat ${i}] ${runIdLog} | Elapsed run retrieval time: ${endTime - startTime}`,
+        );
       } catch (error) {
-        logger.warn(`${runIdLog} | Error retrieving run status: ${error}`);
+        attempt++;
+        startTime = Date.now();
+        logger.warn(`${runIdLog} | Error retrieving run status`, error);
       }
     }
-    const endTime = Date.now();
-    logger.debug(
-      `[heartbeat ${i}] ${runIdLog} | Elapsed run retrieval time: ${endTime - startTime}`,
-    );
+
     if (!updatedRun) {
       const errorMessage = `[waitForRun] ${runIdLog} | Run retrieval failed after ${maxRetries} attempts`;
       throw new Error(errorMessage);
     }
+
     run = updatedRun;
     attempt = 0;
     const runStatus = `${runInfo} | status: ${run.status}`;

api/server/services/Runs/methods.js

@@ -44,7 +44,8 @@ async function retrieveRun({ thread_id, run_id, timeout, openai }) {
     return response.data;
   } catch (error) {
     const logMessage = '[retrieveRun] Failed to retrieve run data:';
-    if (error.response) {
+    const timedOutMessage = 'Cannot read properties of undefined (reading \'status\')';
+    if (error?.response && error?.response?.status) {
       logger.error(
         `${logMessage} The request was made and the server responded with a status code that falls out of the range of 2xx: ${
           error.message ? error.message : ''
@@ -64,9 +65,9 @@ async function retrieveRun({ thread_id, run_id, timeout, openai }) {
           request: error.request,
         },
       );
-    } else {
+    } else if (error?.message && !error?.message?.includes(timedOutMessage)) {
       logger.error(`${logMessage} Something happened in setting up the request`, {
-        message: error.message ? error.message : '',
+        message: error.message,
       });
     }
     throw error;