diff --git a/package.json b/package.json index 73b3ea7f34..5d7ecdbb2f 100644 --- a/package.json +++ b/package.json @@ -24,8 +24,8 @@ "build": "pnpm build-pre && pnpm -r build && pnpm build-assets", "build-storybook": "pnpm --filter frontend build-storybook", "build-misskey-js-with-types": "pnpm build-pre && pnpm --filter backend... --filter=!misskey-js build && pnpm --filter backend generate-api-json --no-build && ncp packages/backend/built/api.json packages/misskey-js/generator/api.json && pnpm --filter misskey-js update-autogen-code && pnpm --filter misskey-js build && pnpm --filter misskey-js api", - "start": "pnpm check:connect && cd packages/backend && node ./built/boot/entry.js", - "start:test": "cd packages/backend && cross-env NODE_ENV=test node ./built/boot/entry.js", + "start": "pnpm check:connect && cd packages/backend && cross-env RUN_MODE=web node ./built/boot/entry.js", + "start:test": "cd packages/backend && cross-env NODE_ENV=test RUN_MODE=test node ./built/boot/entry.js", "init": "pnpm migrate", "migrate": "cd packages/backend && pnpm migrate", "revert": "cd packages/backend && pnpm revert", diff --git a/packages/backend/scripts/check_connect.js b/packages/backend/scripts/check_connect.js index 5d6d2fca49..fae0da3ef2 100644 --- a/packages/backend/scripts/check_connect.js +++ b/packages/backend/scripts/check_connect.js @@ -7,11 +7,6 @@ import Redis from 'ioredis'; import { loadConfig } from '../built/config.js'; import { createPostgresDataSource } from '../built/postgres.js'; -const timeout = setTimeout(() => { - console.error('Timeout while connecting to databases.'); - process.exit(1); -}, 120000); - const config = loadConfig(); async function connectToPostgres() { @@ -27,6 +22,7 @@ async function connectToRedis(redisOptions) { lazyConnect: true, reconnectOnError: false, showFriendlyErrorStack: true, + connectTimeout: 10000, }); redis.on('error', e => reject(e)); @@ -60,4 +56,4 @@ const promises = Array await Promise.allSettled(promises); -clearTimeout(timeout); +process.exit(0); diff --git a/packages/backend/src/boot/master.ts b/packages/backend/src/boot/master.ts index 551ff984b1..c3a0dc6b98 100644 --- a/packages/backend/src/boot/master.ts +++ b/packages/backend/src/boot/master.ts @@ -20,6 +20,7 @@ import type { Config } from '@/config.js'; import { showMachineInfo } from '@/misc/show-machine-info.js'; import { envOption } from '@/env.js'; import { jobQueue, server } from './common.js'; +import { metricGauge } from '@/server/api/MetricsService.js'; const _filename = fileURLToPath(import.meta.url); const _dirname = dirname(_filename); @@ -31,18 +32,24 @@ const bootLogger = logger.createSubLogger('boot', 'magenta'); const themeColor = chalk.hex('#86b300'); -const mBuildInfo = new prom.Gauge({ +const mBuildInfo = metricGauge({ name: 'misskey_build_info', help: 'Misskey build information', labelNames: ['gitCommit', 'gitDescribe', 'node_version'] }); -mBuildInfo.set({ +mBuildInfo?.set({ gitCommit: meta.gitCommit || 'unknown', gitDescribe: meta.gitDescribe || 'unknown', node_version: process.version }, 1); +const mStartupTime = metricGauge({ + name: 'misskey_startup_time', + help: 'Misskey startup time', + labelNames: ['pid'] +}); + function greet() { if (!envOption.quiet) { //#region Misskey logo @@ -112,6 +119,8 @@ export async function masterMain() { }); } + mStartupTime?.set({ pid: process.pid }, Date.now()); + if (envOption.disableClustering) { if (envOption.onlyServer) { await server(); diff --git a/packages/backend/src/core/QueueModule.ts b/packages/backend/src/core/QueueModule.ts index 3fb05cda3b..c3c9256e0e 100644 --- a/packages/backend/src/core/QueueModule.ts +++ b/packages/backend/src/core/QueueModule.ts @@ -31,16 +31,18 @@ export type UserWebhookDeliverQueue = Bull.Queue; export type SystemWebhookDeliverQueue = Bull.Queue; function withMetrics(queue: Bull.Queue): Bull.Queue { - setInterval(async () => { - mActiveJobs.set({ queue: queue.name }, await queue.getActiveCount()); - mDelayedJobs.set({ queue: queue.name }, await queue.getDelayedCount()); - mWaitingJobs.set({ queue: queue.name }, await queue.getWaitingCount()); - }, 2000); - - queue.on('waiting', () => { - mJobReceivedCounter.inc({ queue: queue.name }); - }); + if (process.env.NODE_ENV !== 'test') { + setInterval(async () => { + mActiveJobs?.set({ queue: queue.name }, await queue.getActiveCount()); + mDelayedJobs?.set({ queue: queue.name }, await queue.getDelayedCount()); + mWaitingJobs?.set({ queue: queue.name }, await queue.getWaitingCount()); + }, 2000); + queue.on('waiting', () => { + mJobReceivedCounter?.inc({ queue: queue.name }); + }); + } + return queue; } diff --git a/packages/backend/src/core/activitypub/ApInboxService.ts b/packages/backend/src/core/activitypub/ApInboxService.ts index a3bd5678d4..f3aa46292e 100644 --- a/packages/backend/src/core/activitypub/ApInboxService.ts +++ b/packages/backend/src/core/activitypub/ApInboxService.ts @@ -39,17 +39,18 @@ import { ApPersonService } from './models/ApPersonService.js'; import { ApQuestionService } from './models/ApQuestionService.js'; import type { Resolver } from './ApResolverService.js'; import type { IAccept, IAdd, IAnnounce, IBlock, ICreate, IDelete, IFlag, IFollow, ILike, IObject, IReject, IRemove, IUndo, IUpdate, IMove, IPost } from './type.js'; +import { metricCounter } from '@/server/api/MetricsService.js'; + +const mInboxReceived = metricCounter({ + name: 'misskey_ap_inbox_received_total', + help: 'Total number of activities received by AP inbox', + labelNames: ['host', 'type'], +}); @Injectable() export class ApInboxService { private logger: Logger; - private mInboxReceived = new prom.Counter({ - name: 'misskey_ap_inbox_received_total', - help: 'Total number of activities received by AP inbox', - labelNames: ['host', 'type'], - }); - constructor( @Inject(DI.config) private config: Config, @@ -138,49 +139,49 @@ export class ApInboxService { if (actor.isSuspended) return; if (isCreate(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'create' }); + mInboxReceived?.inc({ host: actor.host, type: 'create' }); return await this.create(actor, activity); } else if (isDelete(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'delete' }); + mInboxReceived?.inc({ host: actor.host, type: 'delete' }); return await this.delete(actor, activity); } else if (isUpdate(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'update' }); + mInboxReceived?.inc({ host: actor.host, type: 'update' }); return await this.update(actor, activity); } else if (isFollow(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'follow' }); + mInboxReceived?.inc({ host: actor.host, type: 'follow' }); return await this.follow(actor, activity); } else if (isAccept(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'accept' }); + mInboxReceived?.inc({ host: actor.host, type: 'accept' }); return await this.accept(actor, activity); } else if (isReject(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'reject' }); + mInboxReceived?.inc({ host: actor.host, type: 'reject' }); return await this.reject(actor, activity); } else if (isAdd(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'add' }); + mInboxReceived?.inc({ host: actor.host, type: 'add' }); return await this.add(actor, activity); } else if (isRemove(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'remove' }); + mInboxReceived?.inc({ host: actor.host, type: 'remove' }); return await this.remove(actor, activity); } else if (isAnnounce(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'announce' }); + mInboxReceived?.inc({ host: actor.host, type: 'announce' }); return await this.announce(actor, activity); } else if (isLike(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'like' }); + mInboxReceived?.inc({ host: actor.host, type: 'like' }); return await this.like(actor, activity); } else if (isUndo(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'undo' }); + mInboxReceived?.inc({ host: actor.host, type: 'undo' }); return await this.undo(actor, activity); } else if (isBlock(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'block' }); + mInboxReceived?.inc({ host: actor.host, type: 'block' }); return await this.block(actor, activity); } else if (isFlag(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'flag' }); + mInboxReceived?.inc({ host: actor.host, type: 'flag' }); return await this.flag(actor, activity); } else if (isMove(activity)) { - this.mInboxReceived.inc({ host: actor.host, type: 'move' }); + mInboxReceived?.inc({ host: actor.host, type: 'move' }); return await this.move(actor, activity); } else { - this.mInboxReceived.inc({ host: actor.host, type: 'unknown' }); + mInboxReceived?.inc({ host: actor.host, type: 'unknown' }); return `unrecognized activity type: ${activity.type}`; } } @@ -491,9 +492,9 @@ export class ApInboxService { formerType = 'Note'; } - if (validPost.includes(formerType)) { + if (validPost?.includes(formerType)) { return await this.deleteNote(actor, uri); - } else if (validActor.includes(formerType)) { + } else if (validActor?.includes(formerType)) { return await this.deleteActor(actor, uri); } else { return `Unknown type ${formerType}`; diff --git a/packages/backend/src/postgres.ts b/packages/backend/src/postgres.ts index 6fce6a6faa..ed1fccddf0 100644 --- a/packages/backend/src/postgres.ts +++ b/packages/backend/src/postgres.ts @@ -7,7 +7,6 @@ import pg from 'pg'; import { DataSource, Logger } from 'typeorm'; import * as highlight from 'cli-highlight'; -import * as prom from 'prom-client'; import { createHash } from 'crypto'; import { entities as charts } from '@/core/chart/entities.js'; @@ -85,6 +84,7 @@ import { Config } from '@/config.js'; import MisskeyLogger from '@/logger.js'; import { bindThis } from '@/decorators.js'; import { MemoryKVCache } from './misc/cache.js'; +import { metricCounter, metricHistogram } from './server/api/MetricsService.js'; pg.types.setTypeParser(20, Number); @@ -125,19 +125,19 @@ function extractQueryTags(query: string): QueryTagCache { }; } -const mQueryCounter = new prom.Counter({ +const mQueryCounter = metricCounter({ name: 'misskey_postgres_query_total', help: 'Total queries to postgres', labelNames: ['join', 'from', 'hash'], }); -const mQueryErrorCounter = new prom.Counter({ +const mQueryErrorCounter = metricCounter({ name: 'misskey_postgres_query_error_total', help: 'Total errors in queries to postgres', labelNames: ['join', 'from', 'hash'], }); -const mSlowQueryHisto = new prom.Histogram({ +const mSlowQueryHisto = metricHistogram({ name: 'misskey_postgres_query_slow_duration_seconds', help: 'Duration of slow queries to postgres', labelNames: ['join', 'from', 'hash'], @@ -170,7 +170,7 @@ class MyCustomLogger implements Logger { @bindThis public logQuery(query: string, parameters?: any[]) { - mQueryCounter.inc(this.getQueryTags(query)); + mQueryCounter?.inc(this.getQueryTags(query)); if (this.metricOnly) { return; @@ -180,7 +180,7 @@ class MyCustomLogger implements Logger { @bindThis public logQueryError(error: string, query: string, parameters?: any[]) { - mQueryErrorCounter.inc(this.getQueryTags(query)); + mQueryErrorCounter?.inc(this.getQueryTags(query)); if (this.metricOnly) { return; @@ -190,7 +190,7 @@ class MyCustomLogger implements Logger { @bindThis public logQuerySlow(time: number, query: string, parameters?: any[]) { - mSlowQueryHisto.observe(this.getQueryTags(query), time); + mSlowQueryHisto?.observe(this.getQueryTags(query), time); if (this.metricOnly) { return; @@ -341,8 +341,8 @@ export function createPostgresDataSource(config: Config, isMain = false) { db: config.redis.db ?? 0, }, } : false, - logging: log ? 'all' : ['query'], - logger: (isMain || log) ? new MyCustomLogger(!log) : undefined, + logging: true, + logger: new MyCustomLogger(!log), maxQueryExecutionTime: 500, entities: entities, migrations: ['../../migration/*.js'], diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index 9a6b3d8063..b6f73c12ed 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -196,7 +196,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }) .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => { - mStalledWorkerCounter.inc({ queue: QUEUE.SYSTEM }); + mStalledWorkerCounter?.inc({ queue: QUEUE.SYSTEM }); logger.warn(`stalled id=${jobId}`); }); } @@ -256,7 +256,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }) .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => { - mStalledWorkerCounter.inc({ queue: QUEUE.DB }); + mStalledWorkerCounter?.inc({ queue: QUEUE.DB }); logger.warn(`stalled id=${jobId}`); }); } @@ -299,7 +299,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }) .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => { - mStalledWorkerCounter.inc({ queue: QUEUE.DELIVER }); + mStalledWorkerCounter?.inc({ queue: QUEUE.DELIVER }); logger.warn(`stalled id=${jobId}`); }); } @@ -342,7 +342,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }) .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => { - mStalledWorkerCounter.inc({ queue: QUEUE.INBOX }); + mStalledWorkerCounter?.inc({ queue: QUEUE.INBOX }); logger.warn(`stalled id=${jobId}`); }); } @@ -385,7 +385,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }) .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => { - mStalledWorkerCounter.inc({ queue: QUEUE.USER_WEBHOOK_DELIVER }); + mStalledWorkerCounter?.inc({ queue: QUEUE.USER_WEBHOOK_DELIVER }); logger.warn(`stalled id=${jobId}`); }); } @@ -428,7 +428,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }) .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => { - mStalledWorkerCounter.inc({ queue: QUEUE.SYSTEM_WEBHOOK_DELIVER }); + mStalledWorkerCounter?.inc({ queue: QUEUE.SYSTEM_WEBHOOK_DELIVER }); logger.warn(`stalled id=${jobId}`); }); } @@ -478,7 +478,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }) .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => { - mStalledWorkerCounter.inc({ queue: QUEUE.RELATIONSHIP }); + mStalledWorkerCounter?.inc({ queue: QUEUE.RELATIONSHIP }); logger.warn(`stalled id=${jobId}`); }); } @@ -522,7 +522,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }) .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => { - mStalledWorkerCounter.inc({ queue: QUEUE.OBJECT_STORAGE }); + mStalledWorkerCounter?.inc({ queue: QUEUE.OBJECT_STORAGE }); logger.warn(`stalled id=${jobId}`); }); } diff --git a/packages/backend/src/queue/metrics.ts b/packages/backend/src/queue/metrics.ts index a3e794d6a9..86c56daebc 100644 --- a/packages/backend/src/queue/metrics.ts +++ b/packages/backend/src/queue/metrics.ts @@ -1,30 +1,30 @@ -import * as prom from 'prom-client'; +import { metricCounter, metricGauge } from '@/server/api/MetricsService.js'; -export const mJobReceivedCounter = new prom.Counter({ +export const mJobReceivedCounter = metricCounter({ name: 'misskey_queue_jobs_received_total', help: 'Total number of jobs received by queue', labelNames: ['queue'], }); -export const mActiveJobs = new prom.Gauge({ +export const mActiveJobs = metricGauge({ name: 'misskey_queue_active_jobs', help: 'Number of active jobs in queue', labelNames: ['queue'], }); -export const mDelayedJobs = new prom.Gauge({ +export const mDelayedJobs = metricGauge({ name: 'misskey_queue_delayed_jobs', help: 'Number of delayed jobs in queue', labelNames: ['queue'], }); -export const mWaitingJobs = new prom.Gauge({ +export const mWaitingJobs = metricGauge({ name: 'misskey_queue_waiting_jobs', help: 'Number of waiting jobs in queue', labelNames: ['queue'], }); -export const mStalledWorkerCounter = new prom.Counter({ +export const mStalledWorkerCounter = metricCounter({ name: 'misskey_queue_stalled_workers_total', help: 'Total number of stalled workers', labelNames: ['queue'], diff --git a/packages/backend/src/queue/processors/InboxProcessorService.ts b/packages/backend/src/queue/processors/InboxProcessorService.ts index bd6da6c668..215cc66837 100644 --- a/packages/backend/src/queue/processors/InboxProcessorService.ts +++ b/packages/backend/src/queue/processors/InboxProcessorService.ts @@ -32,48 +32,49 @@ import { MiMeta } from '@/models/Meta.js'; import { DI } from '@/di-symbols.js'; import { QueueLoggerService } from '../QueueLoggerService.js'; import type { InboxJobData } from '../types.js'; +import { metricCounter, metricHistogram } from '@/server/api/MetricsService.js'; type UpdateInstanceJob = { latestRequestReceivedAt: Date, shouldUnsuspend: boolean, }; +const mIncomingApProcessingTime = metricHistogram({ + name: 'misskey_incoming_ap_processing_time', + help: 'Incoming AP processing time in seconds', + labelNames: ['incoming_host', 'incoming_type', 'success'], + buckets: [0.01, 0.1, 0.5, 1, 5, 10, 30, 60, 300, 1800], +}); + +const mIncomingApEvent = metricCounter({ + name: 'misskey_incoming_ap_event', + help: 'Incoming AP event', + labelNames: ['incoming_host', 'incoming_type'], +}); + +const mIncomingApEventAccepted = metricCounter({ + name: 'misskey_incoming_ap_event_accepted', + help: 'Incoming AP event accepted', + labelNames: ['incoming_host', 'incoming_type'], +}); + +const mIncomingApReject = metricCounter({ + name: 'misskey_incoming_ap_reject', + help: 'Incoming AP reject', + labelNames: ['incoming_host', 'incoming_type', 'reason'], +}); + +const mincomingApProcessingError = metricCounter({ + name: 'misskey_incoming_ap_processing_error', + help: 'Incoming AP processing error', + labelNames: ['incoming_host', 'incoming_type'], +}); + @Injectable() export class InboxProcessorService implements OnApplicationShutdown { private logger: Logger; private updateInstanceQueue: CollapsedQueue; - private mIncomingApProcessingTime = new prom.Histogram({ - name: 'misskey_incoming_ap_processing_time', - help: 'Incoming AP processing time in seconds', - labelNames: ['incoming_host', 'incoming_type', 'success'], - buckets: [0.01, 0.1, 0.5, 1, 5, 10, 30, 60, 300, 1800], - }); - - private mIncomingApEvent = new prom.Counter({ - name: 'misskey_incoming_ap_event', - help: 'Incoming AP event', - labelNames: ['incoming_host', 'incoming_type'], - }); - - private mIncomingApEventAccepted = new prom.Counter({ - name: 'misskey_incoming_ap_event_accepted', - help: 'Incoming AP event accepted', - labelNames: ['incoming_host', 'incoming_type'], - }); - - private mIncomingApReject = new prom.Counter({ - name: 'misskey_incoming_ap_reject', - help: 'Incoming AP reject', - labelNames: ['incoming_host', 'incoming_type', 'reason'], - }); - - private mincomingApProcessingError = new prom.Counter({ - name: 'misskey_incoming_ap_processing_error', - help: 'Incoming AP processing error', - labelNames: ['incoming_host', 'incoming_type'], - }); - constructor( @Inject(DI.meta) private meta: MiMeta, @@ -106,34 +107,34 @@ export class InboxProcessorService implements OnApplicationShutdown { const host = this.utilityService.toPuny(new URL(signature.keyId).hostname); - const incCounter = (counter: prom.Counter, addn_labels: U) => { + const incCounter = (counter: prom.Counter | null, addn_labels: U) => { if (Array.isArray(activity.type)) { for (const t of activity.type) { - counter.inc({ incoming_host: host.toString(), incoming_type: t, ...addn_labels }); + counter?.inc({ incoming_host: host.toString(), incoming_type: t, ...addn_labels }); } } else { - counter.inc({ incoming_host: host.toString(), incoming_type: activity.type ?? 'unknown', ...addn_labels }); + counter?.inc({ incoming_host: host.toString(), incoming_type: activity.type ?? 'unknown', ...addn_labels }); } }; - const observeHistogram = (histogram: prom.Histogram, addn_labels: U, value: number) => { + const observeHistogram = (histogram: prom.Histogram | null, addn_labels: U, value: number) => { if (Array.isArray(activity.type)) { for (const t of activity.type) { - histogram.observe({ incoming_host: host.toString(), incoming_type: t, ...addn_labels }, value); + histogram?.observe({ incoming_host: host.toString(), incoming_type: t, ...addn_labels }, value); } } else { - histogram.observe({ incoming_host: host.toString(), incoming_type: activity.type ?? 'unknown', ...addn_labels }, value); + histogram?.observe({ incoming_host: host.toString(), incoming_type: activity.type ?? 'unknown', ...addn_labels }, value); } }; if (!this.utilityService.isFederationAllowedHost(host)) { - incCounter(this.mIncomingApReject, { reason: 'host_not_allowed' }); + incCounter(mIncomingApReject, { reason: 'host_not_allowed' }); return `Blocked request: ${host}`; } const keyIdLower = signature.keyId.toLowerCase(); if (keyIdLower.startsWith('acct:')) { - incCounter(this.mIncomingApReject, { reason: 'keyid_acct' }); + incCounter(mIncomingApReject, { reason: 'keyid_acct' }); return `Old keyId is no longer supported. ${keyIdLower}`; } @@ -151,7 +152,7 @@ export class InboxProcessorService implements OnApplicationShutdown { // 対象が4xxならスキップ if (err instanceof StatusError) { if (!err.isRetryable) { - incCounter(this.mIncomingApReject, { reason: 'actor_key_unresolvable' }); + incCounter(mIncomingApReject, { reason: 'actor_key_unresolvable' }); throw new Bull.UnrecoverableError(`skip: Ignored deleted actors on both ends ${activity.actor} - ${err.statusCode}`); } throw new Error(`Error in actor ${activity.actor} - ${err.statusCode}`); @@ -161,13 +162,13 @@ export class InboxProcessorService implements OnApplicationShutdown { // それでもわからなければ終了 if (authUser == null) { - incCounter(this.mIncomingApReject, { reason: 'actor_unresolvable' }); + incCounter(mIncomingApReject, { reason: 'actor_unresolvable' }); throw new Bull.UnrecoverableError('skip: failed to resolve user'); } // publicKey がなくても終了 if (authUser.key == null) { - incCounter(this.mIncomingApReject, { reason: 'publickey_unresolvable' }); + incCounter(mIncomingApReject, { reason: 'publickey_unresolvable' }); throw new Bull.UnrecoverableError('skip: failed to resolve user publicKey'); } @@ -180,7 +181,7 @@ export class InboxProcessorService implements OnApplicationShutdown { const ldSignature = activity.signature; if (ldSignature) { if (ldSignature.type !== 'RsaSignature2017') { - incCounter(this.mIncomingApReject, { reason: 'ld_signature_unsupported' }); + incCounter(mIncomingApReject, { reason: 'ld_signature_unsupported' }); throw new Bull.UnrecoverableError(`skip: unsupported LD-signature type ${ldSignature.type}`); } @@ -194,12 +195,12 @@ export class InboxProcessorService implements OnApplicationShutdown { // keyIdからLD-Signatureのユーザーを取得 authUser = await this.apDbResolverService.getAuthUserFromKeyId(ldSignature.creator); if (authUser == null) { - incCounter(this.mIncomingApReject, { reason: 'ld_signature_user_unresolvable' }); + incCounter(mIncomingApReject, { reason: 'ld_signature_user_unresolvable' }); throw new Bull.UnrecoverableError('skip: LD-Signatureのユーザーが取得できませんでした'); } if (authUser.key == null) { - incCounter(this.mIncomingApReject, { reason: 'ld_signature_publickey_unavailable' }); + incCounter(mIncomingApReject, { reason: 'ld_signature_publickey_unavailable' }); throw new Bull.UnrecoverableError('skip: LD-SignatureのユーザーはpublicKeyを持っていませんでした'); } @@ -208,7 +209,7 @@ export class InboxProcessorService implements OnApplicationShutdown { // LD-Signature検証 const verified = await jsonLd.verifyRsaSignature2017(activity, authUser.key.keyPem).catch(() => false); if (!verified) { - incCounter(this.mIncomingApReject, { reason: 'ld_signature_verification_failed' }); + incCounter(mIncomingApReject, { reason: 'ld_signature_verification_failed' }); throw new Bull.UnrecoverableError('skip: LD-Signatureの検証に失敗しました'); } @@ -231,17 +232,17 @@ export class InboxProcessorService implements OnApplicationShutdown { // もう一度actorチェック if (authUser.user.uri !== activity.actor) { - incCounter(this.mIncomingApReject, { reason: 'ld_signature_actor_mismatch' }); + incCounter(mIncomingApReject, { reason: 'ld_signature_actor_mismatch' }); throw new Bull.UnrecoverableError(`skip: LD-Signature user(${authUser.user.uri}) !== activity.actor(${activity.actor})`); } const ldHost = this.utilityService.extractDbHost(authUser.user.uri); if (!this.utilityService.isFederationAllowedHost(ldHost)) { - incCounter(this.mIncomingApReject, { reason: 'fed_host_not_allowed' }); + incCounter(mIncomingApReject, { reason: 'fed_host_not_allowed' }); throw new Bull.UnrecoverableError(`Blocked request: ${ldHost}`); } } else { - incCounter(this.mIncomingApReject, { reason: 'ld_signature_unavailable' }); + incCounter(mIncomingApReject, { reason: 'ld_signature_unavailable' }); throw new Bull.UnrecoverableError(`skip: http-signature verification failed and no LD-Signature. keyId=${signature.keyId}`); } } @@ -251,7 +252,7 @@ export class InboxProcessorService implements OnApplicationShutdown { const signerHost = this.utilityService.extractDbHost(authUser.user.uri!); const activityIdHost = this.utilityService.extractDbHost(activity.id); if (signerHost !== activityIdHost) { - incCounter(this.mIncomingApReject, 'host_signature_mismatch'); + incCounter(mIncomingApReject, 'host_signature_mismatch'); throw new Bull.UnrecoverableError(`skip: signerHost(${signerHost}) !== activity.id host(${activityIdHost}`); } } @@ -279,7 +280,7 @@ export class InboxProcessorService implements OnApplicationShutdown { this.fetchInstanceMetadataService.fetchInstanceMetadata(i); }); - incCounter(this.mIncomingApEvent, {}); + incCounter(mIncomingApEvent, {}); // アクティビティを処理 const begin = +new Date(); @@ -292,25 +293,25 @@ export class InboxProcessorService implements OnApplicationShutdown { } catch (e) { if (e instanceof IdentifiableError) { if (e.id === '689ee33f-f97c-479a-ac49-1b9f8140af99') { - incCounter(this.mIncomingApReject, { reason: 'blocked_notes_with_prohibited_words' }); + incCounter(mIncomingApReject, { reason: 'blocked_notes_with_prohibited_words' }); return 'blocked notes with prohibited words'; } if (e.id === '85ab9bd7-3a41-4530-959d-f07073900109') { - incCounter(this.mIncomingApReject, { reason: 'actor_suspended' }); + incCounter(mIncomingApReject, { reason: 'actor_suspended' }); return 'actor has been suspended'; } if (e.id === 'd450b8a9-48e4-4dab-ae36-f4db763fda7c') { // invalid Note - incCounter(this.mIncomingApReject, { reason: 'invalid_note' }); + incCounter(mIncomingApReject, { reason: 'invalid_note' }); return e.message; } } const end = +new Date(); - observeHistogram(this.mIncomingApProcessingTime, { success: 'false' }, (end - begin) / 1000); - incCounter(this.mincomingApProcessingError, { reason: 'unknown' }); + observeHistogram(mIncomingApProcessingTime, { success: 'false' }, (end - begin) / 1000); + incCounter(mincomingApProcessingError, { reason: 'unknown' }); throw e; } - observeHistogram(this.mIncomingApProcessingTime, { success: 'true' }, (+new Date() - begin) / 1000); - incCounter(this.mIncomingApEventAccepted, {}); + observeHistogram(mIncomingApProcessingTime, { success: 'true' }, (+new Date() - begin) / 1000); + incCounter(mIncomingApEventAccepted, {}); return 'ok'; } diff --git a/packages/backend/src/server/ServerService.ts b/packages/backend/src/server/ServerService.ts index bbb0503c1e..dc48929112 100644 --- a/packages/backend/src/server/ServerService.ts +++ b/packages/backend/src/server/ServerService.ts @@ -35,7 +35,7 @@ import { makeHstsHook } from './hsts.js'; import { generateCSP } from './csp.js'; import * as prom from 'prom-client'; import { sanitizeRequestURI } from '@/misc/log-sanitization.js'; -import { MetricsService } from './api/MetricsService.js'; +import { metricCounter, metricGauge, metricHistogram, MetricsService } from './api/MetricsService.js'; const _dirname = fileURLToPath(new URL('.', import.meta.url)); @@ -55,66 +55,66 @@ function categorizeRequestPath(path: string): 'api' | 'health' | 'vite' | 'other return 'other'; } +const mRequestTime = metricHistogram({ + name: 'misskey_http_request_duration_seconds', + help: 'Duration of handling HTTP requests in seconds', + labelNames: ['host', 'cate', 'method', 'path'], + buckets: [0.001, 0.1, 0.5, 1, 2, 5], +}); + +const mRequestsReceived = metricCounter({ + name: 'misskey_http_requests_received_total', + help: 'Total number of HTTP requests received', + labelNames: [], +}); + +const mNotFoundServed = metricCounter({ + name: 'misskey_http_not_found_served_total', + help: 'Total number of HTTP 404 responses served', + labelNames: ['method', 'cate'], +}); + +const mMethodNotAllowedServed = metricCounter({ + name: 'misskey_http_method_not_allowed_served_total', + help: 'Total number of HTTP 405 responses served', + labelNames: ['method', 'cate'], +}); + +const mTooManyRequestsServed = metricCounter({ + name: 'misskey_http_too_many_requests_served_total', + help: 'Total number of HTTP 429 responses served', + labelNames: ['method', 'cate'], +}); + +const mAggregateRequestsServed = metricCounter({ + name: 'misskey_http_requests_served_total', + help: 'Total number of HTTP requests served including invalid requests', + labelNames: ['host', 'cate', 'status'], +}); + +const mRequestsServedByPath = metricCounter({ + name: 'misskey_http_requests_served_by_path', + help: 'Total number of HTTP requests served', + labelNames: ['host', 'cate', 'method', 'path', 'status'], +}); + +const mFatalErrorCount = metricCounter({ + name: 'misskey_fatal_http_errors_total', + help: 'Total number of HTTP errors that propagate to the top level', + labelNames: ['host', 'cate', 'method', 'path'], +}); + +const mLastSuccessfulRequest = metricGauge({ + name: 'misskey_http_last_successful_request_timestamp_seconds', + help: 'Unix Timestamp of the last successful HTTP request', + labelNames: [], +}); + @Injectable() export class ServerService implements OnApplicationShutdown { private logger: Logger; #fastify: FastifyInstance; - private mRequestTime = new prom.Histogram({ - name: 'misskey_http_request_duration_seconds', - help: 'Duration of handling HTTP requests in seconds', - labelNames: ['host', 'cate', 'method', 'path'], - buckets: [0.001, 0.1, 0.5, 1, 2, 5], - }); - - private mRequestsReceived = new prom.Counter({ - name: 'misskey_http_requests_received_total', - help: 'Total number of HTTP requests received', - labelNames: [], - }); - - private mNotFoundServed = new prom.Counter({ - name: 'misskey_http_not_found_served_total', - help: 'Total number of HTTP 404 responses served', - labelNames: ['method', 'cate'], - }); - - private mMethodNotAllowedServed = new prom.Counter({ - name: 'misskey_http_method_not_allowed_served_total', - help: 'Total number of HTTP 405 responses served', - labelNames: ['method', 'cate'], - }); - - private mTooManyRequestsServed = new prom.Counter({ - name: 'misskey_http_too_many_requests_served_total', - help: 'Total number of HTTP 429 responses served', - labelNames: ['method', 'cate'], - }); - - private mAggregateRequestsServed = new prom.Counter({ - name: 'misskey_http_requests_served_total', - help: 'Total number of HTTP requests served including invalid requests', - labelNames: ['host', 'cate', 'status'], - }); - - private mRequestsServedByPath = new prom.Counter({ - name: 'misskey_http_requests_served_by_path', - help: 'Total number of HTTP requests served', - labelNames: ['host', 'cate', 'method', 'path', 'status'], - }); - - private mFatalErrorCount = new prom.Counter({ - name: 'misskey_fatal_http_errors_total', - help: 'Total number of HTTP errors that propagate to the top level', - labelNames: ['host', 'cate', 'method', 'path'], - }); - - private mLastSuccessfulRequest = new prom.Gauge({ - name: 'misskey_http_last_successful_request_timestamp_seconds', - help: 'Unix Timestamp of the last successful HTTP request', - labelNames: [], - }); - constructor( @Inject(DI.config) private config: Config, @@ -160,14 +160,14 @@ export class ServerService implements OnApplicationShutdown { if (this.config.prometheusMetrics?.enable) { fastify.addHook('onRequest', (_request, reply, done) => { reply.header('x-request-received', (+new Date()).toString()); - this.mRequestsReceived.inc(); + mRequestsReceived?.inc(); done(); }); fastify.addHook('onError', (request, _reply, error, done) => { const url = new URL(request.url, this.config.url); const logPath = sanitizeRequestURI(url.pathname); - this.mFatalErrorCount.inc({ + mFatalErrorCount?.inc({ host: request.hostname, method: request.method, path: logPath, @@ -182,14 +182,14 @@ export class ServerService implements OnApplicationShutdown { const cate = categorizeRequestPath(logPath); const received = reply.getHeader('x-request-received') as string; - this.mAggregateRequestsServed.inc({ + mAggregateRequestsServed?.inc({ host: request.hostname, cate, status: reply.statusCode, }); if (reply.statusCode === 429) { - this.mTooManyRequestsServed.inc({ + mTooManyRequestsServed?.inc({ method: request.method, cate, }); @@ -199,14 +199,14 @@ export class ServerService implements OnApplicationShutdown { } if (reply.statusCode === 404) { - this.mNotFoundServed.inc({ + mNotFoundServed?.inc({ method: request.method, cate, }); if (received) { const duration = (+new Date()) - parseInt(received); - this.mRequestTime.observe({ + mRequestTime?.observe({ host: request.hostname, method: request.method, cate, @@ -218,7 +218,7 @@ export class ServerService implements OnApplicationShutdown { } if (reply.statusCode === 405) { - this.mMethodNotAllowedServed.inc({ + mMethodNotAllowedServed?.inc({ method: request.method, cate, }); @@ -229,7 +229,7 @@ export class ServerService implements OnApplicationShutdown { if (received) { const duration = (+new Date()) - parseInt(received); - this.mRequestTime.observe({ + mRequestTime?.observe({ host: request.hostname, method: request.method, cate, @@ -243,10 +243,10 @@ export class ServerService implements OnApplicationShutdown { } if (reply.statusCode <= 299) { - this.mLastSuccessfulRequest.set(+new Date() / 1000); + mLastSuccessfulRequest?.set(+new Date() / 1000); } - this.mRequestsServedByPath.inc({ + mRequestsServedByPath?.inc({ host: request.hostname, method: request.method, path: logPath, diff --git a/packages/backend/src/server/api/AuthenticateService.ts b/packages/backend/src/server/api/AuthenticateService.ts index 13a51e3797..dfb5777c13 100644 --- a/packages/backend/src/server/api/AuthenticateService.ts +++ b/packages/backend/src/server/api/AuthenticateService.ts @@ -14,6 +14,7 @@ import type { MiApp } from '@/models/App.js'; import { CacheService } from '@/core/CacheService.js'; import isNativeToken from '@/misc/is-native-token.js'; import { bindThis } from '@/decorators.js'; +import { metricCounter } from './MetricsService.js'; export class AuthenticationError extends Error { constructor(message: string) { @@ -22,16 +23,16 @@ export class AuthenticationError extends Error { } } +const mAuthenticationFailureCounter = metricCounter({ + name: 'misskey_authentication_failure_total', + help: 'Total number of authentication failures', + labelNames: ['cred_ty'], +}); + @Injectable() export class AuthenticateService implements OnApplicationShutdown { private appCache: MemoryKVCache; - private mAuthenticationFailureCounter = new prom.Counter({ - name: 'misskey_authentication_failure_total', - help: 'Total number of authentication failures', - labelNames: ['cred_ty'], - }); - constructor( @Inject(DI.usersRepository) private usersRepository: UsersRepository, @@ -58,7 +59,7 @@ export class AuthenticateService implements OnApplicationShutdown { () => this.usersRepository.findOneBy({ token }) as Promise); if (user == null) { - this.mAuthenticationFailureCounter.inc({ cred_ty: 'native' }); + mAuthenticationFailureCounter?.inc({ cred_ty: 'native' }); throw new AuthenticationError('user not found'); } @@ -73,7 +74,7 @@ export class AuthenticateService implements OnApplicationShutdown { }); if (accessToken == null) { - this.mAuthenticationFailureCounter.inc({ cred_ty: 'access_token' }); + mAuthenticationFailureCounter?.inc({ cred_ty: 'access_token' }); throw new AuthenticationError('invalid signature'); } diff --git a/packages/backend/src/server/api/MetricsService.ts b/packages/backend/src/server/api/MetricsService.ts index 034098960d..2837fdbb19 100644 --- a/packages/backend/src/server/api/MetricsService.ts +++ b/packages/backend/src/server/api/MetricsService.ts @@ -5,6 +5,30 @@ import type { Config } from '@/config.js'; import { bindThis } from "@/decorators.js"; import type { FastifyInstance, FastifyPluginOptions } from "fastify"; +export function metricGauge(conf: prom.GaugeConfiguration) : prom.Gauge | null { + if (!process.env.RUN_MODE) { + return null; + } + + return new prom.Gauge(conf); +} + +export function metricCounter(conf: prom.CounterConfiguration) : prom.Counter | null { + if (!process.env.RUN_MODE) { + return null; + } + + return new prom.Counter(conf); +} + +export function metricHistogram(conf: prom.HistogramConfiguration) : prom.Histogram | null { + if (!process.env.RUN_MODE) { + return null; + } + + return new prom.Histogram(conf); +} + /* * SPDX-FileCopyrightText: syuilo and misskey-project and yumechi * SPDX-License-Identifier: AGPL-3.0-only diff --git a/packages/backend/src/server/api/SigninApiService.ts b/packages/backend/src/server/api/SigninApiService.ts index 80cfdf5436..0327f17ea5 100644 --- a/packages/backend/src/server/api/SigninApiService.ts +++ b/packages/backend/src/server/api/SigninApiService.ts @@ -29,15 +29,16 @@ import { RateLimiterService } from './RateLimiterService.js'; import { SigninService } from './SigninService.js'; import type { AuthenticationResponseJSON } from '@simplewebauthn/types'; import type { FastifyReply, FastifyRequest } from 'fastify'; +import { metricCounter } from './MetricsService.js'; + +const mSigninFailureCounter = metricCounter({ + name: 'misskey_misskey_signin_failure', + help: 'The number of failed sign-ins', + labelNames: ['reason'], +}); @Injectable() export class SigninApiService { - private mSigninFailureCounter = new prom.Counter({ - name: 'misskey_misskey_signin_failure', - help: 'The number of failed sign-ins', - labelNames: ['reason'], - }); - constructor( @Inject(DI.config) private config: Config, @@ -100,7 +101,7 @@ export class SigninApiService { // not more than 1 attempt per second and not more than 10 attempts per hour await this.rateLimiterService.limit({ key: 'signin', duration: 60 * 60 * 1000, max: 10, minInterval: 1000 }, getIpHash(request.ip)); } catch (err) { - this.mSigninFailureCounter.inc({ reason: 'rate_limit' }); + mSigninFailureCounter?.inc({ reason: 'rate_limit' }); reply.code(429); return { error: { @@ -112,13 +113,13 @@ export class SigninApiService { } if (typeof username !== 'string') { - this.mSigninFailureCounter.inc({ reason: 'bad_form' }); + mSigninFailureCounter?.inc({ reason: 'bad_form' }); reply.code(400); return; } if (token != null && typeof token !== 'string') { - this.mSigninFailureCounter.inc({ reason: 'bad_form' }); + mSigninFailureCounter?.inc({ reason: 'bad_form' }); reply.code(400); return; } @@ -130,14 +131,14 @@ export class SigninApiService { }) as MiLocalUser; if (user == null) { - this.mSigninFailureCounter.inc({ reason: 'user_not_found' }); + mSigninFailureCounter?.inc({ reason: 'user_not_found' }); return error(404, { id: '6cc579cc-885d-43d8-95c2-b8c7fc963280', }); } if (user.isSuspended) { - this.mSigninFailureCounter.inc({ reason: 'user_suspended' }); + mSigninFailureCounter?.inc({ reason: 'user_suspended' }); return error(403, { id: 'e03a5f46-d309-4865-9b69-56282d94e1eb', }); @@ -162,7 +163,7 @@ export class SigninApiService { } if (typeof password !== 'string') { - this.mSigninFailureCounter.inc({ reason: 'bad_form' }); + mSigninFailureCounter?.inc({ reason: 'bad_form' }); reply.code(400); return; } @@ -180,7 +181,7 @@ export class SigninApiService { success: false, }); - this.mSigninFailureCounter.inc({ reason: failure?.id ?? `unknown_error_${status ?? 500}` }); + mSigninFailureCounter?.inc({ reason: failure?.id ?? `unknown_error_${status ?? 500}` }); return error(status ?? 500, failure ?? { id: '4e30e80c-e338-45a0-8c8f-44455efa3b76' }); }; @@ -188,35 +189,35 @@ export class SigninApiService { if (process.env.NODE_ENV !== 'test') { if (this.meta.enableHcaptcha && this.meta.hcaptchaSecretKey) { await this.captchaService.verifyHcaptcha(this.meta.hcaptchaSecretKey, body['hcaptcha-response']).catch(err => { - this.mSigninFailureCounter.inc({ reason: 'captcha_verification_failed_hcaptcha' }); + mSigninFailureCounter?.inc({ reason: 'captcha_verification_failed_hcaptcha' }); throw new FastifyReplyError(400, err); }); } if (this.meta.enableMcaptcha && this.meta.mcaptchaSecretKey && this.meta.mcaptchaSitekey && this.meta.mcaptchaInstanceUrl) { await this.captchaService.verifyMcaptcha(this.meta.mcaptchaSecretKey, this.meta.mcaptchaSitekey, this.meta.mcaptchaInstanceUrl, body['m-captcha-response']).catch(err => { - this.mSigninFailureCounter.inc({ reason: 'captcha_verification_failed_mcaptcha' }); + mSigninFailureCounter?.inc({ reason: 'captcha_verification_failed_mcaptcha' }); throw new FastifyReplyError(400, err); }); } if (this.meta.enableRecaptcha && this.meta.recaptchaSecretKey) { await this.captchaService.verifyRecaptcha(this.meta.recaptchaSecretKey, body['g-recaptcha-response']).catch(err => { - this.mSigninFailureCounter.inc({ reason: 'captcha_verification_failed_recaptcha' }); + mSigninFailureCounter?.inc({ reason: 'captcha_verification_failed_recaptcha' }); throw new FastifyReplyError(400, err); }); } if (this.meta.enableTurnstile && this.meta.turnstileSecretKey) { await this.captchaService.verifyTurnstile(this.meta.turnstileSecretKey, body['turnstile-response']).catch(err => { - this.mSigninFailureCounter.inc({ reason: 'captcha_verification_failed_turnstile' }); + mSigninFailureCounter?.inc({ reason: 'captcha_verification_failed_turnstile' }); throw new FastifyReplyError(400, err); }); } if (this.meta.enableTestcaptcha) { await this.captchaService.verifyTestcaptcha(body['testcaptcha-response']).catch(err => { - this.mSigninFailureCounter.inc({ reason: 'captcha_verification_failed_testcaptcha' }); + mSigninFailureCounter?.inc({ reason: 'captcha_verification_failed_testcaptcha' }); throw new FastifyReplyError(400, err); }); } diff --git a/packages/backend/test-server/entry.ts b/packages/backend/test-server/entry.ts index 04bf62d209..a6266e3440 100644 --- a/packages/backend/test-server/entry.ts +++ b/packages/backend/test-server/entry.ts @@ -5,7 +5,6 @@ import { NestFactory } from '@nestjs/core'; import { MainModule } from '@/MainModule.js'; import { ServerService } from '@/server/ServerService.js'; import { loadConfig } from '@/config.js'; -import { NestLogger } from '@/NestLogger.js'; import { INestApplicationContext } from '@nestjs/common'; const config = loadConfig(); @@ -22,10 +21,8 @@ let serverService: ServerService; async function launch() { await killTestServer(); - console.log('starting application...'); - app = await NestFactory.createApplicationContext(MainModule, { - logger: new NestLogger(), + logger: ["debug", "log", "error", "warn", "verbose"], }); serverService = app.get(ServerService); await serverService.launch(); @@ -84,7 +81,7 @@ async function startControllerEndpoints(port = config.port + 1000) { console.log('starting application...'); app = await NestFactory.createApplicationContext(MainModule, { - logger: new NestLogger(), + logger: ["debug", "log", "error", "warn", "verbose"], }); serverService = app.get(ServerService); await serverService.launch();