diff --git a/package-lock.json b/package-lock.json index 62d869d9..73380479 100644 --- a/package-lock.json +++ b/package-lock.json @@ -26,6 +26,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" }, @@ -13114,6 +13115,12 @@ "node": ">=8" } }, + "node_modules/perf_hooks": { + "version": "0.0.1", + "resolved": "https://registry.npmjs.org/perf_hooks/-/perf_hooks-0.0.1.tgz", + "integrity": "sha512-qG/D9iA4KDme+KF4vCObJy6Bouu3BlQnmJ8jPydVPm32NJBD9ZK1ZNgXSYaZKHkVC1sKSqUiLgFvAZPUiIEnBw==", + "license": "MIT" + }, "node_modules/picocolors": { "version": "1.0.0", "resolved": "https://registry.npmjs.org/picocolors/-/picocolors-1.0.0.tgz", diff --git a/package.json b/package.json index 08a33bf3..c6c0b06f 100644 --- 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 index 5b27ca1c..e62a9f78 100644 --- 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,8 +42,13 @@ 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: @@ -41,20 +56,33 @@ export default { 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`); } }, };