From 2c95553d27d87857c9eccf9f305f46e8964f9d44 Mon Sep 17 00:00:00 2001 From: Claudiu Lataretu Date: Thu, 7 Sep 2023 17:25:50 +0300 Subject: [PATCH 1/2] SERVICES-1828: use nestjs-metrics for metrics collection Signed-off-by: Claudiu Lataretu --- package-lock.json | 81 ++++++++++++++++++++++++++++++++++ package.json | 1 + src/utils/metrics.collector.ts | 81 ++++++---------------------------- 3 files changed, 96 insertions(+), 67 deletions(-) diff --git a/package-lock.json b/package-lock.json index 11ffaa88c..ce24a8fd0 100644 --- a/package-lock.json +++ b/package-lock.json @@ -17,6 +17,7 @@ "@multiversx/sdk-data-api-client": "^0.5.8", "@multiversx/sdk-exchange": "^0.2.17", "@multiversx/sdk-native-auth-server": "1.0.7", + "@multiversx/sdk-nestjs-monitoring": "^2.0.0-beta.2", "@multiversx/sdk-network-providers": "^2.0.0", "@nestjs/apollo": "^12.0.7", "@nestjs/axios": "^3.0.0", @@ -3155,6 +3156,19 @@ "node": ">= 6" } }, + "node_modules/@multiversx/sdk-nestjs-monitoring": { + "version": "2.0.0-beta.2", + "resolved": "https://registry.npmjs.org/@multiversx/sdk-nestjs-monitoring/-/sdk-nestjs-monitoring-2.0.0-beta.2.tgz", + "integrity": "sha512-T16l8U4eEUpE+XxHj0VkPhrprBvC6C+noxN15BhrKir7gnKl3Ut5A9bkvBaczJ0DvvXhMSQei0XaGbu8JL7ErA==", + "dependencies": { + "prom-client": "^14.0.1", + "winston": "^3.7.2", + "winston-daily-rotate-file": "^4.6.1" + }, + "peerDependencies": { + "@nestjs/common": "^10.x" + } + }, "node_modules/@multiversx/sdk-network-providers": { "version": "2.0.0", "resolved": "https://registry.npmjs.org/@multiversx/sdk-network-providers/-/sdk-network-providers-2.0.0.tgz", @@ -8981,6 +8995,14 @@ "node": "^10.12.0 || >=12.0.0" } }, + "node_modules/file-stream-rotator": { + "version": "0.6.1", + "resolved": "https://registry.npmjs.org/file-stream-rotator/-/file-stream-rotator-0.6.1.tgz", + "integrity": "sha512-u+dBid4PvZw17PmDeRcNOtCP9CCK/9lRN2w+r1xIS7yOL9JFrIBKTvrYsxT4P0pGtThYTn++QS5ChHaUov3+zQ==", + "dependencies": { + "moment": "^2.29.1" + } + }, "node_modules/file-type": { "version": "17.1.6", "resolved": "https://registry.npmjs.org/file-type/-/file-type-17.1.6.tgz", @@ -12634,6 +12656,14 @@ "node": ">=0.10.0" } }, + "node_modules/object-hash": { + "version": "2.2.0", + "resolved": "https://registry.npmjs.org/object-hash/-/object-hash-2.2.0.tgz", + "integrity": "sha512-gScRMn0bS5fH+IuwyIFgnh9zBdo4DV+6GhygmWM9HyNJSgS0hScp1f5vjtm7oIIOiT9trXrShAkLFSc2IqKNgw==", + "engines": { + "node": ">= 6" + } + }, "node_modules/object-inspect": { "version": "1.12.3", "resolved": "https://registry.npmjs.org/object-inspect/-/object-inspect-1.12.3.tgz", @@ -16451,6 +16481,23 @@ "node": ">= 12.0.0" } }, + "node_modules/winston-daily-rotate-file": { + "version": "4.7.1", + "resolved": "https://registry.npmjs.org/winston-daily-rotate-file/-/winston-daily-rotate-file-4.7.1.tgz", + "integrity": "sha512-7LGPiYGBPNyGHLn9z33i96zx/bd71pjBn9tqQzO3I4Tayv94WPmBNwKC7CO1wPHdP9uvu+Md/1nr6VSH9h0iaA==", + "dependencies": { + "file-stream-rotator": "^0.6.1", + "object-hash": "^2.0.1", + "triple-beam": "^1.3.0", + "winston-transport": "^4.4.0" + }, + "engines": { + "node": ">=8" + }, + "peerDependencies": { + "winston": "^3" + } + }, "node_modules/winston-transport": { "version": "4.5.0", "resolved": "https://registry.npmjs.org/winston-transport/-/winston-transport-4.5.0.tgz", @@ -19108,6 +19155,16 @@ } } }, + "@multiversx/sdk-nestjs-monitoring": { + "version": "2.0.0-beta.2", + "resolved": "https://registry.npmjs.org/@multiversx/sdk-nestjs-monitoring/-/sdk-nestjs-monitoring-2.0.0-beta.2.tgz", + "integrity": "sha512-T16l8U4eEUpE+XxHj0VkPhrprBvC6C+noxN15BhrKir7gnKl3Ut5A9bkvBaczJ0DvvXhMSQei0XaGbu8JL7ErA==", + "requires": { + "prom-client": "^14.0.1", + "winston": "^3.7.2", + "winston-daily-rotate-file": "^4.6.1" + } + }, "@multiversx/sdk-network-providers": { "version": "2.0.0", "resolved": "https://registry.npmjs.org/@multiversx/sdk-network-providers/-/sdk-network-providers-2.0.0.tgz", @@ -23489,6 +23546,14 @@ "flat-cache": "^3.0.4" } }, + "file-stream-rotator": { + "version": "0.6.1", + "resolved": "https://registry.npmjs.org/file-stream-rotator/-/file-stream-rotator-0.6.1.tgz", + "integrity": "sha512-u+dBid4PvZw17PmDeRcNOtCP9CCK/9lRN2w+r1xIS7yOL9JFrIBKTvrYsxT4P0pGtThYTn++QS5ChHaUov3+zQ==", + "requires": { + "moment": "^2.29.1" + } + }, "file-type": { "version": "17.1.6", "resolved": "https://registry.npmjs.org/file-type/-/file-type-17.1.6.tgz", @@ -26191,6 +26256,11 @@ "resolved": "https://registry.npmjs.org/object-assign/-/object-assign-4.1.1.tgz", "integrity": "sha512-rJgTQnkUnH1sFw8yT6VSU3zD3sWmu6sZhIseY8VX+GRu3P6F7Fu+JNDoXfklElbLJSnc3FUQHVe4cU5hj+BcUg==" }, + "object-hash": { + "version": "2.2.0", + "resolved": "https://registry.npmjs.org/object-hash/-/object-hash-2.2.0.tgz", + "integrity": "sha512-gScRMn0bS5fH+IuwyIFgnh9zBdo4DV+6GhygmWM9HyNJSgS0hScp1f5vjtm7oIIOiT9trXrShAkLFSc2IqKNgw==" + }, "object-inspect": { "version": "1.12.3", "resolved": "https://registry.npmjs.org/object-inspect/-/object-inspect-1.12.3.tgz", @@ -28942,6 +29012,17 @@ } } }, + "winston-daily-rotate-file": { + "version": "4.7.1", + "resolved": "https://registry.npmjs.org/winston-daily-rotate-file/-/winston-daily-rotate-file-4.7.1.tgz", + "integrity": "sha512-7LGPiYGBPNyGHLn9z33i96zx/bd71pjBn9tqQzO3I4Tayv94WPmBNwKC7CO1wPHdP9uvu+Md/1nr6VSH9h0iaA==", + "requires": { + "file-stream-rotator": "^0.6.1", + "object-hash": "^2.0.1", + "triple-beam": "^1.3.0", + "winston-transport": "^4.4.0" + } + }, "winston-transport": { "version": "4.5.0", "resolved": "https://registry.npmjs.org/winston-transport/-/winston-transport-4.5.0.tgz", diff --git a/package.json b/package.json index e8306dcb3..48f155806 100644 --- a/package.json +++ b/package.json @@ -34,6 +34,7 @@ "@multiversx/sdk-data-api-client": "^0.5.8", "@multiversx/sdk-exchange": "^0.2.17", "@multiversx/sdk-native-auth-server": "1.0.7", + "@multiversx/sdk-nestjs-monitoring": "^2.0.0-beta.2", "@multiversx/sdk-network-providers": "^2.0.0", "@nestjs/apollo": "^12.0.7", "@nestjs/axios": "^3.0.0", diff --git a/src/utils/metrics.collector.ts b/src/utils/metrics.collector.ts index 26bbae82a..9d9702a12 100644 --- a/src/utils/metrics.collector.ts +++ b/src/utils/metrics.collector.ts @@ -1,21 +1,18 @@ -import { register, Histogram, collectDefaultMetrics, Gauge } from 'prom-client'; +import { MetricsService } from '@multiversx/sdk-nestjs-monitoring'; +import { register, Histogram, Gauge } from 'prom-client'; export class MetricsCollector { private static fieldDurationHistogram: Histogram; private static queryDurationHistogram: Histogram; private static queryCpuHistogram: Histogram; - private static redisDurationHistogram: Histogram; - private static externalCallsHistogram: Histogram; private static awsQueryDurationHistogram: Histogram; private static dataApiQueryDurationHistogram: Histogram; private static gasDifferenceHistogram: Histogram; private static guestQueriesGauge: Gauge; - private static guestHitsGauge: Gauge; - private static guestNoCacheHitsGauge: Gauge; - private static guestHitQueriesGauge: Gauge; private static currentNonceGauge: Gauge; private static lastProcessedNonceGauge: Gauge; - private static isDefaultMetricsRegistered = false; + + private static baseMetrics = new MetricsService(); static ensureIsInitialized() { if (!MetricsCollector.fieldDurationHistogram) { @@ -45,24 +42,6 @@ export class MetricsCollector { }); } - if (!MetricsCollector.redisDurationHistogram) { - MetricsCollector.redisDurationHistogram = new Histogram({ - name: 'redis_duration', - help: 'The time it takes to get from redis', - labelNames: ['redis'], - buckets: [], - }); - } - - if (!MetricsCollector.externalCallsHistogram) { - MetricsCollector.externalCallsHistogram = new Histogram({ - name: 'external_apis', - help: 'External Calls', - labelNames: ['system', 'func'], - buckets: [], - }); - } - if (!MetricsCollector.awsQueryDurationHistogram) { MetricsCollector.awsQueryDurationHistogram = new Histogram({ name: 'aws_query', @@ -106,14 +85,6 @@ export class MetricsCollector { }); } - if (!MetricsCollector.guestNoCacheHitsGauge) { - MetricsCollector.guestNoCacheHitsGauge = new Gauge({ - name: 'guest_no_cache_hits', - help: 'Request no-cache hits for guest users', - labelNames: [], - }); - } - if (!MetricsCollector.guestQueriesGauge) { MetricsCollector.guestQueriesGauge = new Gauge({ name: 'guest_queries', @@ -121,27 +92,6 @@ export class MetricsCollector { labelNames: ['operation'], }); } - - if (!MetricsCollector.guestHitsGauge) { - MetricsCollector.guestHitsGauge = new Gauge({ - name: 'guest_hits', - help: 'Request hits for guest users', - labelNames: [], - }); - } - - if (!MetricsCollector.guestHitQueriesGauge) { - MetricsCollector.guestHitQueriesGauge = new Gauge({ - name: 'guest_hit_queries', - help: 'Distinct queries for guest hit caching', - labelNames: [], - }); - } - - if (!MetricsCollector.isDefaultMetricsRegistered) { - MetricsCollector.isDefaultMetricsRegistered = true; - collectDefaultMetrics(); - } } static setFieldDuration(name: string, path: string, duration: number) { @@ -167,19 +117,13 @@ export class MetricsCollector { static setRedisDuration(action: string, duration: number) { MetricsCollector.ensureIsInitialized(); - MetricsCollector.externalCallsHistogram - .labels('redis', action) - .observe(duration); - MetricsCollector.redisDurationHistogram - .labels(action) - .observe(duration); + MetricsCollector.baseMetrics.setExternalCall('redis', duration); + MetricsCollector.baseMetrics.setRedisDuration(action, duration); } static setExternalCall(system: string, func: string, duration: number) { MetricsCollector.ensureIsInitialized(); - MetricsCollector.externalCallsHistogram - .labels(system, func) - .observe(duration); + MetricsCollector.baseMetrics.setExternalCall(system, duration); } static setAWSQueryDuration(queryName: string, duration: number) { @@ -224,20 +168,23 @@ export class MetricsCollector { static incrementGuestHits() { MetricsCollector.ensureIsInitialized(); - MetricsCollector.guestHitsGauge.inc(); + MetricsService.incrementGuestHits(); } static incrementGuestNoCacheHits() { MetricsCollector.ensureIsInitialized(); - MetricsCollector.guestNoCacheHitsGauge.inc(); + MetricsService.incrementGuestNoCacheHits(); } static setGuestHitQueries(count: number) { MetricsCollector.ensureIsInitialized(); - MetricsCollector.guestHitQueriesGauge.set(count); + MetricsService.setGuestHitQueries(count); } static async getMetrics(): Promise { - return register.metrics(); + const baseMetrics = await MetricsCollector.baseMetrics.getMetrics(); + const currentMetrics = await register.metrics(); + + return baseMetrics + '\n' + currentMetrics; } } From 2e42ae2c4216fe27ed6bd54a3fabd3ba5a67ee59 Mon Sep 17 00:00:00 2001 From: Claudiu Lataretu Date: Fri, 8 Sep 2023 12:15:55 +0300 Subject: [PATCH 2/2] SERVICES-1828: use CpuProfiler from nestjs-monitoring Signed-off-by: Claudiu Lataretu --- src/utils/cpu.profiler.ts | 105 ------------------------------- src/utils/logging.interceptor.ts | 4 +- 2 files changed, 2 insertions(+), 107 deletions(-) delete mode 100644 src/utils/cpu.profiler.ts diff --git a/src/utils/cpu.profiler.ts b/src/utils/cpu.profiler.ts deleted file mode 100644 index 5c24400c5..000000000 --- a/src/utils/cpu.profiler.ts +++ /dev/null @@ -1,105 +0,0 @@ -import { Logger } from '@nestjs/common'; -import async_hooks from 'async_hooks'; -import { randomUUID } from 'crypto'; -import { PerformanceProfiler } from './performance.profiler'; - -export class CpuProfiler { - private static readonly asyncHookDict: Record = {}; - private static readonly profilerDict: Record = {}; - private static hook?: async_hooks.AsyncHook; - private readonly contextId = randomUUID(); - private readonly logger = new Logger(CpuProfiler.name); - private readonly performanceProfiler = new PerformanceProfiler(); - - constructor() { - this.start(); - } - - private start() { - CpuProfiler.ensureIsProfiling(); - - CpuProfiler.profilerDict[this.contextId] = { - duration: 0, - }; - - const asyncId = async_hooks.executionAsyncId(); - CpuProfiler.asyncHookDict[asyncId] = { - requestId: this.contextId, - timestamp: 0, - }; - } - - stop(description?: string): number { - this.performanceProfiler.stop(); - - const duration = CpuProfiler.profilerDict[this.contextId]?.duration; - - delete CpuProfiler.profilerDict[this.contextId]; - - if (description) { - this.logger.log(`${description}: ${this.performanceProfiler.duration.toFixed(3)}ms, CPU time ${duration.toFixed(3)}ms`); - } - - return duration; - } - - static enable() { - CpuProfiler.ensureIsProfiling().enable(); - } - - static disable() { - CpuProfiler.ensureIsProfiling().disable(); - } - - private static ensureIsProfiling(): async_hooks.AsyncHook { - if (!CpuProfiler.hook) { - CpuProfiler.hook = async_hooks.createHook({ init: onInit, destroy: onDestroy, before: onBefore, after: onAfter }).enable(); - } - - return CpuProfiler.hook; - - // eslint-disable-next-line @typescript-eslint/no-this-alias - function onInit(asyncId: number, _: string, triggerAsyncId: number) { - const previousValue = CpuProfiler.asyncHookDict[triggerAsyncId]; - if (previousValue) { - CpuProfiler.asyncHookDict[asyncId] = { - requestId: previousValue.requestId, - timestamp: 0, - }; - } - } - - function onDestroy(asyncId: number) { - const value = CpuProfiler.asyncHookDict[asyncId]; - if (value) { - delete CpuProfiler.asyncHookDict[asyncId]; - } - - } - - function onBefore(asyncId: number) { - const value = CpuProfiler.asyncHookDict[asyncId]; - if (value) { - value.timestamp = CpuProfiler.now(); - } - } - - function onAfter(asyncId: number) { - const asyncHookItem = CpuProfiler.asyncHookDict[asyncId]; - if (asyncHookItem) { - const requestId = asyncHookItem.requestId; - const requestItem = CpuProfiler.profilerDict[requestId]; - if (requestItem && asyncHookItem.timestamp > 0) { - CpuProfiler.profilerDict[requestId].duration += CpuProfiler.now() - asyncHookItem.timestamp; - } - - delete CpuProfiler.asyncHookDict[asyncId]; - } - } - } - - private static now() { - const hrTime = process.hrtime(); - return hrTime[0] * 1000 + hrTime[1] / 1000000; - } -} diff --git a/src/utils/logging.interceptor.ts b/src/utils/logging.interceptor.ts index bd470147b..fdc0a65e6 100644 --- a/src/utils/logging.interceptor.ts +++ b/src/utils/logging.interceptor.ts @@ -7,7 +7,7 @@ import { import { GqlContextType, GqlExecutionContext } from '@nestjs/graphql'; import { Observable } from 'rxjs'; import { tap } from 'rxjs/operators'; -import { CpuProfiler } from './cpu.profiler'; +import { CpuProfiler } from '@multiversx/sdk-nestjs-monitoring'; import { MetricsCollector } from './metrics.collector'; import { PerformanceProfiler } from './performance.profiler'; @@ -29,7 +29,7 @@ export class LoggingInterceptor implements NestInterceptor { const profiler = new PerformanceProfiler(); const cpuProfiler = new CpuProfiler(); - + return next.handle().pipe( tap(() => { profiler.stop();