Merge pull request #222 from TogetherCrew/debug-hivemind-slash-command

debug: add more logs to check hivemind slash command
TogetherCrew · Sep 16, 2024 · 8c3247f · 8c3247f
2 parents 10413ba + 68ece1d
commit 8c3247f
Show file tree

Hide file tree

Showing 3 changed files with 46 additions and 11 deletions.
diff --git a/package-lock.json b/package-lock.json
diff --git a/package.json b/package.json
@@ -22,8 +22,6 @@
     "cleanupCompletedJobs": "node ./lib/scripts/cleanupCompletedJobs.js",
     "deleteRnDAOGuildCommands": "node ./lib/scripts/deleteRnDAOGuildCommands.js",
     "fetchInitialData": "node ./lib/scripts/fetchInitialData.js"
-
-
   },
   "repository": {
     "type": "git",
@@ -53,6 +51,7 @@
     "mongoose": "^6.11.1",
     "node-fetch": "^2.6.7",
     "npm": "^10.4.0",
+    "perf_hooks": "^0.0.1",
     "pino": "^8.18.0",
     "redis": "^4.6.6"
   },

diff --git a/src/commands/info/question.ts b/src/commands/info/question.ts
@@ -6,6 +6,7 @@ import RabbitMQ, { Event, Queue as RabbitMQQueue } from '@togethercrew.dev/tc-me
 import { type ChatInputCommandInteraction_broker } from '../../interfaces/Hivemind.interface';
 import { handleBigInts, removeCircularReferences } from '../../utils/obj';
 import parentLogger from '../../config/logger';
+import { performance } from 'perf_hooks';
 
 const logger = parentLogger.child({ command: 'question' });
 
@@ -18,12 +19,21 @@ export default {
     ),
 
   async execute(interaction: ChatInputCommandInteraction_broker) {
+    const start = performance.now(); // Start high-resolution timer
     logger.info({ interaction_id: interaction.id, user: interaction.user }, 'question command started');
+
     try {
+      // Platform fetch stage
+      const stage1Start = performance.now(); // Start time for platform check
       const platform = await platformService.getPlatformByFilter({
         name: 'discord',
         'metadata.id': interaction.guildId,
       });
+      const stage1End = performance.now();
+      logger.info({ interaction_id: interaction.id }, `Platform fetch took ${stage1End - stage1Start} ms`);
+
+      // Hivemind check stage
+      const stage2Start = performance.now(); // Start time for Hivemind check
       const hivemindDiscordPlatform = await moduleService.getModuleByFilter({
         'options.platforms': {
           $elemMatch: {
@@ -32,29 +42,47 @@ export default {
           },
         },
       });
+      const stage2End = performance.now();
+      logger.info({ interaction_id: interaction.id }, `Hivemind check took ${stage2End - stage2Start} ms`);
+
+      // Hivemind not found, return response
       if (!hivemindDiscordPlatform) {
-        return await interactionService.createInteractionResponse(interaction, {
+        const stage3Start = performance.now(); // Start time for interaction response
+        await interactionService.createInteractionResponse(interaction, {
           type: 4,
           data: {
             content:
               'The **/question** command uses TogetherCrew Hivemind AI to help answer questions about your community.\nTo enable this feature, ask your community manager to configure the Hivemind module on [togethercrew app](https://app.togethercrew.com).\n**Note**: once configured, it can take up to 24 hours for Hivemind to start working.',
             flags: 64,
           },
         });
+        const stage4End = performance.now();
+        logger.info({ interaction_id: interaction.id }, `Response creation took ${stage4End - stage3Start} ms`);
+        return;
       }
-      const serializedInteraction = interactionService.constructSerializableInteraction(interaction);
-      const processedInteraction = handleBigInts(serializedInteraction);
-      const cleanInteraction = removeCircularReferences(processedInteraction); // Pass processedInteraction here
-      const serializedData = JSON.stringify(cleanInteraction, null, 2);
-      RabbitMQ.publish(RabbitMQQueue.HIVEMIND, Event.HIVEMIND.INTERACTION_CREATED, { interaction: serializedData });
+
+      const stage4Start = performance.now(); // Start time for deferred interaction response
       await interactionService.createInteractionResponse(interaction, {
         type: 5,
         data: { flags: 64 },
       });
-      logger.info({ interaction_id: interaction.id, user: interaction.user }, 'question command ended');
+      const stage4End = performance.now();
+      logger.info({ interaction_id: interaction.id }, `Deferred response took ${stage4End - stage4Start} ms`);
+
+      // Interaction processing stage
+      const stage5Start = performance.now(); // Start time for interaction processing
+      const serializedInteraction = interactionService.constructSerializableInteraction(interaction);
+      const processedInteraction = handleBigInts(serializedInteraction);
+      const cleanInteraction = removeCircularReferences(processedInteraction);
+      const serializedData = JSON.stringify(cleanInteraction, null, 2);
+      RabbitMQ.publish(RabbitMQQueue.HIVEMIND, Event.HIVEMIND.INTERACTION_CREATED, { interaction: serializedData });
+      const stage5End = performance.now();
+      logger.info({ interaction_id: interaction.id }, `Interaction processing took ${stage5End - stage5Start} ms`);
+
+      logger.info({ interaction_id: interaction.id, user: interaction.user }, `question command ended`);
+      logger.info(`Total execution time: ${performance.now() - start} ms`);
     } catch (error) {
-      logger.error(error, 'question command is failed');
-      logger.error({ interaction_id: interaction.id, user: interaction.user }, 'question command is failed');
+      logger.error(error, 'question command failed');
       await interactionService.createInteractionResponse(interaction, {
         type: 4,
         data: {
@@ -63,6 +91,7 @@ export default {
           flags: 64,
         },
       });
+      logger.info(`Error handling time: ${performance.now() - start} ms`);
     }
   },
 };