diff --git a/package.json b/package.json index 948e30b6..9d81c719 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "hawk.api", - "version": "1.2.4", + "version": "1.2.5", "main": "index.ts", "license": "BUSL-1.1", "scripts": { diff --git a/src/index.ts b/src/index.ts index 6a4ebcc0..0f847d41 100644 --- a/src/index.ts +++ b/src/index.ts @@ -26,8 +26,8 @@ import PlansFactory from './models/plansFactory'; import BusinessOperationsFactory from './models/businessOperationsFactory'; import schema from './schema'; import { graphqlUploadExpress } from 'graphql-upload'; -import morgan from 'morgan'; import { metricsMiddleware, createMetricsServer, graphqlMetricsPlugin } from './metrics'; +import { requestLogger } from './utils/logger'; /** * Option to enable playground @@ -85,19 +85,17 @@ class HawkAPI { next(); }); - /** - * Setup request logger. - * Uses 'combined' format in production for Apache-style logging, - * and 'dev' format in development for colored, concise output. - */ - this.app.use(morgan(process.env.NODE_ENV === 'production' ? 'combined' : 'dev')); - /** * Add metrics middleware to track HTTP requests */ this.app.use(metricsMiddleware); this.app.use(express.json()); + + /** + * Setup request logger with custom formatters (GraphQL operation name support) + */ + this.app.use(requestLogger); this.app.use(bodyParser.urlencoded({ extended: false })); this.app.use('/static', express.static(`./static`)); diff --git a/src/metrics/mongodb.ts b/src/metrics/mongodb.ts index ce3b105c..f13087b4 100644 --- a/src/metrics/mongodb.ts +++ b/src/metrics/mongodb.ts @@ -1,5 +1,6 @@ import promClient from 'prom-client'; import { MongoClient, MongoClientOptions } from 'mongodb'; +import { Effect, sgr } from '../utils/ansi'; /** * MongoDB command duration histogram @@ -113,12 +114,155 @@ export function withMongoMetrics(options: MongoClientOptions = {}): MongoClientO }; } +/** + * Format filter/update parameters for logging + * @param params - Parameters to format + * @returns Formatted string + */ +function formatParams(params: any): string { + if (!params || Object.keys(params).length === 0) { + return ''; + } + + try { + return JSON.stringify(params); + } catch (e) { + return String(params); + } +} + +/** + * Colorize duration based on performance thresholds + * @param duration - Duration in milliseconds + * @returns Colorized duration string + */ +function colorizeDuration(duration: number): string { + let color: Effect; + + if (duration < 50) { + color = Effect.ForegroundGreen; + } else if (duration < 100) { + color = Effect.ForegroundYellow; + } else { + color = Effect.ForegroundRed; + } + + return sgr(`${duration}ms`, color); +} + +/** + * Interface for storing command information with timestamp + */ +interface StoredCommandInfo { + formattedCommand: string; + timestamp: number; +} + +/** + * Map to store formatted command information by requestId + */ +const commandInfoMap = new Map(); + +/** + * Timeout for cleaning up stale command info (30 seconds) + */ +const COMMAND_INFO_TIMEOUT_MS = 30000; + +/** + * Cleanup stale command info to prevent memory leaks + * Removes entries older than COMMAND_INFO_TIMEOUT_MS + */ +function cleanupStaleCommandInfo(): void { + const now = Date.now(); + const keysToDelete: number[] = []; + + for (const [requestId, info] of commandInfoMap.entries()) { + if (now - info.timestamp > COMMAND_INFO_TIMEOUT_MS) { + keysToDelete.push(requestId); + } + } + + if (keysToDelete.length > 0) { + console.warn(`Cleaning up ${keysToDelete.length} stale MongoDB command info entries (possible memory leak)`); + for (const key of keysToDelete) { + commandInfoMap.delete(key); + } + } +} + +/** + * Periodic cleanup interval + */ +setInterval(cleanupStaleCommandInfo, COMMAND_INFO_TIMEOUT_MS); + +/** + * Store MongoDB command details for later logging + * @param event - MongoDB command event + */ +function storeCommandInfo(event: any): void { + const collectionRaw = extractCollectionFromCommand(event.command, event.commandName); + const collection = sgr(normalizeCollectionName(collectionRaw), Effect.ForegroundGreen); + const db = event.databaseName || 'unknown db'; + const commandName = sgr(event.commandName, Effect.ForegroundRed); + const filter = event.command.filter; + const update = event.command.update; + const pipeline = event.command.pipeline; + const projection = event.command.projection; + const params = filter || update || pipeline; + const paramsStr = formatParams(params); + const projectionStr = projection ? ` projection: ${formatParams(projection)}` : ''; + + const formattedCommand = `[${event.requestId}] ${db}.${collection}.${commandName}(${paramsStr})${projectionStr}`; + + commandInfoMap.set(event.requestId, { + formattedCommand, + timestamp: Date.now(), + }); +} + +/** + * Log MongoDB command success to console + * Format: [requestId] db.collection.command(params) ✓ duration + * @param event - MongoDB command event + */ +function logCommandSucceeded(event: any): void { + const info = commandInfoMap.get(event.requestId); + const durationStr = colorizeDuration(event.duration); + + if (info) { + console.log(`${info.formattedCommand} ✓ ${durationStr}`); + commandInfoMap.delete(event.requestId); + } else { + console.log(`[${event.requestId}] ${event.commandName} ✓ ${durationStr}`); + } +} + +/** + * Log MongoDB command failure to console + * Format: [requestId] db.collection.command(params) ✗ error duration + * @param event - MongoDB command event + */ +function logCommandFailed(event: any): void { + const errorMsg = event.failure?.message || event.failure?.errmsg || 'Unknown error'; + const info = commandInfoMap.get(event.requestId); + const durationStr = colorizeDuration(event.duration); + + if (info) { + console.error(`${info.formattedCommand} ✗ ${errorMsg} ${durationStr}`); + commandInfoMap.delete(event.requestId); + } else { + console.error(`[${event.requestId}] ${event.commandName} ✗ ${errorMsg} ${durationStr}`); + } +} + /** * Setup MongoDB metrics monitoring on a MongoClient * @param client - MongoDB client to monitor */ export function setupMongoMetrics(client: MongoClient): void { client.on('commandStarted', (event) => { + storeCommandInfo(event); + // Store start time and metadata for this command const metadataKey = `${event.requestId}`; @@ -139,6 +283,8 @@ export function setupMongoMetrics(client: MongoClient): void { }); client.on('commandSucceeded', (event) => { + logCommandSucceeded(event); + const metadataKey = `${event.requestId}`; // eslint-disable-next-line @typescript-eslint/no-explicit-any const metadata = (client as any)[metadataKey]; @@ -157,6 +303,8 @@ export function setupMongoMetrics(client: MongoClient): void { }); client.on('commandFailed', (event) => { + logCommandFailed(event); + const metadataKey = `${event.requestId}`; // eslint-disable-next-line @typescript-eslint/no-explicit-any const metadata = (client as any)[metadataKey]; diff --git a/src/models/eventsFactory.js b/src/models/eventsFactory.js index d10f3aad..2c66d7a1 100644 --- a/src/models/eventsFactory.js +++ b/src/models/eventsFactory.js @@ -665,7 +665,7 @@ class EventsFactory extends Factory { async getEventRelease(eventId) { const eventOriginal = await this.findById(eventId); - if (!eventOriginal) { + if (!eventOriginal || !eventOriginal.payload.release) { return null; } diff --git a/src/mongo.ts b/src/mongo.ts index 84d80897..43b4d202 100644 --- a/src/mongo.ts +++ b/src/mongo.ts @@ -75,7 +75,9 @@ export async function setupConnections(): Promise { databases.hawk = hawkMongoClient.db(); databases.events = eventsMongoClient.db(); - // Setup metrics monitoring for both clients + /** + * Log and and measure MongoDB metrics + */ setupMongoMetrics(hawkMongoClient); setupMongoMetrics(eventsMongoClient); } catch (e) { diff --git a/src/utils/ansi.ts b/src/utils/ansi.ts new file mode 100644 index 00000000..0ccafe03 --- /dev/null +++ b/src/utils/ansi.ts @@ -0,0 +1,44 @@ +/** + * ANSI escape codes for text formatting + */ +export enum Effect { + Reset = '\x1b[0m', + Bold = '\x1b[1m', + Underline = '\x1b[4m', + CrossedOut = '\x1b[9m', + BoldOff = '\x1b[22m', + UnderlineOff = '\x1b[24m', + CrossedOutOff = '\x1b[29m', + ForegroundRed = '\x1b[31m', + ForegroundGreen = '\x1b[32m', + ForegroundYellow = '\x1b[33m', + ForegroundBlue = '\x1b[34m', + ForegroundMagenta = '\x1b[35m', + ForegroundCyan = '\x1b[36m', + ForegroundWhite = '\x1b[37m', + ForegroundGray = '\x1b[90m', + BackgroundRed = '\x1b[41m', + BackgroundGreen = '\x1b[42m', + BackgroundYellow = '\x1b[43m', + BackgroundBlue = '\x1b[44m', + BackgroundMagenta = '\x1b[45m', + BackgroundCyan = '\x1b[46m', + BackgroundWhite = '\x1b[47m', + BackgroundGray = '\x1b[100m', +}; + +/** + * ANSI escape code for setting visual effects using SGR (Select Graphic Rendition) subset + * + * @example console.log('Hello, ${sgr('world', Effect.ForegroundRed)}'); + * + * + * @param message - The message to colorize + * @param color - The color to apply + * @returns The colored message + */ +export function sgr(message: string, color: Effect | Effect[]): string { + const colorCode = Array.isArray(color) ? color.join('') : color ?? Effect.Reset; + + return `${colorCode}${message}${Effect.Reset}`; +} diff --git a/src/utils/logger.ts b/src/utils/logger.ts new file mode 100644 index 00000000..12e85d03 --- /dev/null +++ b/src/utils/logger.ts @@ -0,0 +1,41 @@ +import morgan from 'morgan'; +import express from 'express'; +import { sgr, Effect } from './ansi'; + +/** + * Setup custom GraphQL-aware morgan token. + * Extracts operation name from GraphQL requests to show query/mutation names in logs. + */ +morgan.token('graphql-operation', (req: express.Request) => { + if (req.body && req.body.operationName) { + return req.body.operationName; + } + if (req.body && req.body.query) { + /* Try to extract operation name from query string if operationName is not provided */ + const match = req.body.query.match(/(?:query|mutation)\s+(\w+)/); + const isMutation = req.body.query.includes('mutation'); + + const effect = isMutation ? Effect.ForegroundRed : Effect.ForegroundMagenta; + const prefix = sgr(isMutation ? 'mutation' : 'query', effect); + + if (match && match[1]) { + return prefix + ' ' + sgr(sgr(match[1], effect), Effect.Bold); + } + } + + return '-'; +}); + +/** + * Custom morgan format for GraphQL-aware logging. + * Development: shows method, url, operation name, status, response time, content length + * Production: Apache-style format with operation name included + */ +const customFormat = process.env.NODE_ENV === 'production' + ? ':remote-addr - :remote-user [:date[clf]] ":method :url :graphql-operation" :status :res[content-length] bytes - :response-time ms' + : ':method :url :graphql-operation :status :res[content-length] bytes - :response-time ms'; + +/** + * Configured morgan middleware with GraphQL operation name logging + */ +export const requestLogger = morgan(customFormat); diff --git a/src/utils/utils.js b/src/utils/utils.js deleted file mode 100644 index 92640628..00000000 --- a/src/utils/utils.js +++ /dev/null @@ -1,36 +0,0 @@ -const _ = require('lodash'); - -module.exports.deepMerge = deepMerge; -/** - * Merge to objects recursively - * @param {object} target - * @param {object[]} sources - * @return {object} - */ -function deepMerge(target, ...sources) { - const isObject = (item) => item && typeOf(item) === 'object'; - - return _.mergeWith({}, target, ...sources, function (_subject, _target) { - if (_.isArray(_subject) && _.isArray(_target)) { - const biggerArray = _subject.length > _target.length ? _subject : _target; - const lesser = _subject.length > _target.length ? _target : _subject; - - return biggerArray.map((el, i) => { - if (isObject(el) && isObject(lesser[i])) { - return _.mergeWith({}, el, lesser[i]); - } else { - return el; - } - }); - } - }); -} - -/** - * Returns real type of passed variable - * @param obj - * @return {string} - */ -function typeOf(obj) { - return Object.prototype.toString.call(obj).match(/\s([a-zA-Z]+)/)[1].toLowerCase(); -}