diff --git a/packages/backend/src/boot/master.ts b/packages/backend/src/boot/master.ts index 30f9477ccf..0b417b077e 100644 --- a/packages/backend/src/boot/master.ts +++ b/packages/backend/src/boot/master.ts @@ -28,7 +28,7 @@ const bootLogger = logger.createSubLogger('boot', 'magenta', false); const themeColor = chalk.hex('#86b300'); function greet() { - if (!envOption.quiet) { + if (!envOption.quiet && !envOption.logJson) { //#region Misskey logo const v = `v${meta.version}`; console.log(themeColor(' _____ _ _ ')); @@ -46,7 +46,7 @@ function greet() { } bootLogger.info('Welcome to Misskey!'); - bootLogger.info(`Misskey v${meta.version}`, null, true); + bootLogger.info(`Misskey v${meta.version}`, { version: meta.version, hostname: os.hostname(), pid: process.pid }, true); } /** diff --git a/packages/backend/src/core/LoggerService.ts b/packages/backend/src/core/LoggerService.ts index 96d9b09992..a3d371a303 100644 --- a/packages/backend/src/core/LoggerService.ts +++ b/packages/backend/src/core/LoggerService.ts @@ -16,6 +16,6 @@ export class LoggerService { @bindThis public getLogger(domain: string, color?: KEYWORD | undefined, store?: boolean) { - return new Logger(domain, color, store); + return new Logger(domain); } } diff --git a/packages/backend/src/env.ts b/packages/backend/src/env.ts index ba44cfa2e6..317b35b652 100644 --- a/packages/backend/src/env.ts +++ b/packages/backend/src/env.ts @@ -9,6 +9,7 @@ const envOption = { noDaemons: false, disableClustering: false, verbose: false, + logJson: false, withLogTime: false, quiet: false, }; diff --git a/packages/backend/src/logger.ts b/packages/backend/src/logger.ts index d4705af601..a29500eabc 100644 --- a/packages/backend/src/logger.ts +++ b/packages/backend/src/logger.ts @@ -50,6 +50,19 @@ export default class Logger { return; } + if (envOption.logJson) { + console.log(JSON.stringify({ + time: new Date().toISOString(), + level: level, + message: message, + data: data, + important: important, + context: [this.context].concat(subContexts).join('.'), + cluster: cluster.isPrimary ? 'primary' : `worker-${cluster.worker!.id}`, + })); + return; + } + const time = dateFormat(new Date(), 'HH:mm:ss'); const worker = cluster.isPrimary ? '*' : cluster.worker!.id; const l = diff --git a/packages/backend/src/postgres.ts b/packages/backend/src/postgres.ts index 2d14537bbb..4685f0ed0e 100644 --- a/packages/backend/src/postgres.ts +++ b/packages/backend/src/postgres.ts @@ -80,8 +80,9 @@ import { MiBubbleGameRecord } from '@/models/BubbleGameRecord.js'; import { MiReversiGame } from '@/models/ReversiGame.js'; import { Config } from '@/config.js'; -import MisskeyLogger from '@/logger.js'; import { bindThis } from '@/decorators.js'; +import { envOption } from './env.js'; +import MisskeyLogger from '@/logger.js'; export const dbLogger = new MisskeyLogger('db'); @@ -90,6 +91,8 @@ const sqlLogger = dbLogger.createSubLogger('sql', 'gray', false); class MyCustomLogger implements Logger { @bindThis private highlight(sql: string) { + if (envOption.logJson) return sql; + return highlight.highlight(sql, { language: 'sql', ignoreIllegals: true, }); @@ -97,7 +100,7 @@ class MyCustomLogger implements Logger { @bindThis public logQuery(query: string, parameters?: any[]) { - sqlLogger.info(this.highlight(query).substring(0, 100)); + sqlLogger.debug(this.highlight(query)); } @bindThis diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index ce999d9cef..5dfa05ed84 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -9,6 +9,7 @@ import type { Config } from '@/config.js'; import { DI } from '@/di-symbols.js'; import type Logger from '@/logger.js'; import { bindThis } from '@/decorators.js'; +import { envOption } from '@/env.js'; import { WebhookDeliverProcessorService } from './processors/WebhookDeliverProcessorService.js'; import { EndedPollNotificationProcessorService } from './processors/EndedPollNotificationProcessorService.js'; import { DeliverProcessorService } from './processors/DeliverProcessorService.js'; @@ -41,6 +42,7 @@ import { CleanProcessorService } from './processors/CleanProcessorService.js'; import { AggregateRetentionProcessorService } from './processors/AggregateRetentionProcessorService.js'; import { QueueLoggerService } from './QueueLoggerService.js'; import { QUEUE, baseQueueOptions } from './const.js'; +import type { InboxJobData } from './types.js'; // ref. https://github.com/misskey-dev/misskey/pull/7635#issue-971097019 function httpRelatedBackoff(attemptsMade: number) { @@ -68,13 +70,31 @@ function getJobInfo(job: Bull.Job | undefined, increment = false): string { return `id=${job.id} attempts=${currentAttempts}/${maxAttempts} age=${formated}`; } +function renderError(e: Error): any { + if (e) { // 何故かeがundefinedで来ることがある + return { + ...Object.getOwnPropertyNames(e).reduce((acc, key) => { + //@ts-expect-error Element implicitly has an 'any' type because expression of type 'string' can't be used to index type 'Error'. + acc[key] = e[key]; + return acc; + }, {} as Record), + }; + } else { + return { + stack: '?', + message: '?', + name: '?', + }; + } +} + @Injectable() export class QueueProcessorService implements OnApplicationShutdown { private logger: Logger; private systemQueueWorker: Bull.Worker; private dbQueueWorker: Bull.Worker; private deliverQueueWorker: Bull.Worker; - private inboxQueueWorker: Bull.Worker; + private inboxQueueWorker: Bull.Worker; private webhookDeliverQueueWorker: Bull.Worker; private relationshipQueueWorker: Bull.Worker; private objectStorageQueueWorker: Bull.Worker; @@ -118,22 +138,6 @@ export class QueueProcessorService implements OnApplicationShutdown { ) { this.logger = this.queueLoggerService.logger; - function renderError(e: Error): any { - if (e) { // 何故かeがundefinedで来ることがある - return { - stack: e.stack, - message: e.message, - name: e.name, - }; - } else { - return { - stack: '?', - message: '?', - name: '?', - }; - } - } - //#region system this.systemQueueWorker = new Bull.Worker(QUEUE.SYSTEM, (job) => { switch (job.name) { @@ -155,8 +159,8 @@ export class QueueProcessorService implements OnApplicationShutdown { this.systemQueueWorker .on('active', (job) => systemLogger.debug(`active id=${job.id}`)) .on('completed', (job, result) => systemLogger.debug(`completed(${result}) id=${job.id}`)) - .on('failed', (job, err) => systemLogger.warn(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) })) - .on('error', (err: Error) => systemLogger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('failed', (job, err) => systemLogger.warn(`failed(${err.message}) id=${job ? job.id : '-'}`, { err: renderError(err), data: job?.data })) + .on('error', (err: Error) => systemLogger.error('error', { err: renderError(err) })) .on('stalled', (jobId) => systemLogger.warn(`stalled id=${jobId}`)); //#endregion @@ -194,8 +198,8 @@ export class QueueProcessorService implements OnApplicationShutdown { this.dbQueueWorker .on('active', (job) => dbLogger.debug(`active id=${job.id}`)) .on('completed', (job, result) => dbLogger.debug(`completed(${result}) id=${job.id}`)) - .on('failed', (job, err) => dbLogger.warn(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) })) - .on('error', (err: Error) => dbLogger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('failed', (job, err) => dbLogger.warn(`failed(${err.message}) id=${job ? job.id : '-'}`, { err: renderError(err), job })) + .on('error', (err: Error) => dbLogger.error('error', { err: renderError(err) })) .on('stalled', (jobId) => dbLogger.warn(`stalled id=${jobId}`)); //#endregion @@ -218,8 +222,8 @@ export class QueueProcessorService implements OnApplicationShutdown { this.deliverQueueWorker .on('active', (job) => deliverLogger.debug(`active ${getJobInfo(job, true)} to=${job.data.to}`)) .on('completed', (job, result) => deliverLogger.debug(`completed(${result}) ${getJobInfo(job, true)} to=${job.data.to}`)) - .on('failed', (job, err) => deliverLogger.warn(`failed(${err.stack}) ${getJobInfo(job)} to=${job ? job.data.to : '-'}`)) - .on('error', (err: Error) => deliverLogger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('failed', (job, err) => deliverLogger.warn(`failed(${err.message}) ${getJobInfo(job)} id=${job ? job.id : '-'} to=${job?.data.to}`, { err: renderError(err), data: job?.data })) + .on('error', (err: Error) => deliverLogger.error('error', { err: renderError(err) })) .on('stalled', (jobId) => deliverLogger.warn(`stalled id=${jobId}`)); //#endregion @@ -242,8 +246,11 @@ export class QueueProcessorService implements OnApplicationShutdown { this.inboxQueueWorker .on('active', (job) => inboxLogger.debug(`active ${getJobInfo(job, true)}`)) .on('completed', (job, result) => inboxLogger.debug(`completed(${result}) ${getJobInfo(job, true)}`)) - .on('failed', (job, err) => inboxLogger.warn(`failed(${err.stack}) ${getJobInfo(job)} activity=${job ? (job.data.activity ? job.data.activity.id : 'none') : '-'}`, { job, e: renderError(err) })) - .on('error', (err: Error) => inboxLogger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('failed', (job, err) => inboxLogger.warn( + `failed(${err.message}) ${getJobInfo(job)} activity=${job ? (job.data.activity ? job.data.activity.id : 'none') : '-'}`, + { err: renderError(err), data: (job && !envOption.logJson) ? { activity: JSON.stringify(job.data.activity), signature: JSON.stringify(job.data.signature) } : null }, + )) + .on('error', (err: Error) => inboxLogger.error('error', { err: renderError(err) })) .on('stalled', (jobId) => inboxLogger.warn(`stalled id=${jobId}`)); //#endregion @@ -266,8 +273,8 @@ export class QueueProcessorService implements OnApplicationShutdown { this.webhookDeliverQueueWorker .on('active', (job) => webhookLogger.debug(`active ${getJobInfo(job, true)} to=${job.data.to}`)) .on('completed', (job, result) => webhookLogger.debug(`completed(${result}) ${getJobInfo(job, true)} to=${job.data.to}`)) - .on('failed', (job, err) => webhookLogger.warn(`failed(${err.stack}) ${getJobInfo(job)} to=${job ? job.data.to : '-'}`)) - .on('error', (err: Error) => webhookLogger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('failed', (job, err) => webhookLogger.warn(`failed(${err.message}) ${getJobInfo(job)} to=${job ? job.data.to : '-'}`, { err: renderError(err) })) + .on('error', (err: Error) => webhookLogger.error('error', { err: renderError(err) })) .on('stalled', (jobId) => webhookLogger.warn(`stalled id=${jobId}`)); //#endregion @@ -295,8 +302,8 @@ export class QueueProcessorService implements OnApplicationShutdown { this.relationshipQueueWorker .on('active', (job) => relationshipLogger.debug(`active id=${job.id}`)) .on('completed', (job, result) => relationshipLogger.debug(`completed(${result}) id=${job.id}`)) - .on('failed', (job, err) => relationshipLogger.warn(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) })) - .on('error', (err: Error) => relationshipLogger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('failed', (job, err) => relationshipLogger.warn(`failed(${err.message}) id=${job ? job.id : '-'}`, { err: renderError(err), job })) + .on('error', (err: Error) => relationshipLogger.error('error', { err: renderError(err) })) .on('stalled', (jobId) => relationshipLogger.warn(`stalled id=${jobId}`)); //#endregion @@ -318,8 +325,8 @@ export class QueueProcessorService implements OnApplicationShutdown { this.objectStorageQueueWorker .on('active', (job) => objectStorageLogger.debug(`active id=${job.id}`)) .on('completed', (job, result) => objectStorageLogger.debug(`completed(${result}) id=${job.id}`)) - .on('failed', (job, err) => objectStorageLogger.warn(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) })) - .on('error', (err: Error) => objectStorageLogger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('failed', (job, err) => objectStorageLogger.warn(`failed(${err.message}) id=${job ? job.id : '-'}`, { err: renderError(err), job })) + .on('error', (err: Error) => objectStorageLogger.error('error', { err: renderError(err) })) .on('stalled', (jobId) => objectStorageLogger.warn(`stalled id=${jobId}`)); //#endregion diff --git a/pnpm-lock.yaml b/pnpm-lock.yaml index 5e29c1162b..a113ab8eac 100644 --- a/pnpm-lock.yaml +++ b/pnpm-lock.yaml @@ -6646,7 +6646,7 @@ packages: ts-dedent: 2.2.0 type-fest: 2.19.0 vue: 3.4.21(typescript@5.3.3) - vue-component-type-helpers: 1.8.27 + vue-component-type-helpers: 2.0.5 transitivePeerDependencies: - encoding - supports-color @@ -11636,7 +11636,7 @@ packages: fast-json-stringify: 5.8.0 find-my-way: 7.7.0 light-my-request: 5.11.0 - pino: 8.17.0 + pino: 8.19.0 process-warning: 3.0.0 proxy-addr: 2.0.7 rfdc: 1.3.0 @@ -16037,8 +16037,8 @@ packages: resolution: {integrity: sha512-KO0m2f1HkrPe9S0ldjx7za9BJjeHqBku5Ch8JyxETxT8dEFGz1PwgrHaOQupVYitpzbFSYm7nnljxD8dik2c+g==} dev: false - /pino@8.17.0: - resolution: {integrity: sha512-ey+Mku+PVPhvxglLXMg1l1zQMwSHuNrKC3MD40EDZbkckJmmuY7DYZLIOwwjZ8ix/Nvhe9dZt5H99cgkot9bAw==} + /pino@8.19.0: + resolution: {integrity: sha512-oswmokxkav9bADfJ2ifrvfHUwad6MLp73Uat0IkQWY3iAw5xTRoznXbXksZs8oaOUMpmhVWD+PZogNzllWpJaA==} hasBin: true dependencies: atomic-sleep: 1.0.0 @@ -16046,7 +16046,7 @@ packages: on-exit-leak-free: 2.1.0 pino-abstract-transport: 1.1.0 pino-std-serializers: 6.1.0 - process-warning: 2.2.0 + process-warning: 3.0.0 quick-format-unescaped: 4.0.4 real-require: 0.2.0 safe-stable-stringify: 2.4.2 @@ -19445,6 +19445,10 @@ packages: resolution: {integrity: sha512-6bnLkn8O0JJyiFSIF0EfCogzeqNXpnjJ0vW/SZzNHfe6sPx30lTtTXlE5TFs2qhJlAtDFybStVNpL73cPe3OMQ==} dev: true + /vue-component-type-helpers@2.0.5: + resolution: {integrity: sha512-v9N4ufDSnd8YHcDq/vURPjxDyBVak5ZVAQ6aGNIrf7ZAj/VxRKpLZXFHEaqt9yHkWi0/TZp76Jmf8yNJxDQi4g==} + dev: true + /vue-demi@0.14.7(vue@3.4.21): resolution: {integrity: sha512-EOG8KXDQNwkJILkx/gPcoL/7vH+hORoBaKgGe+6W7VFMvCYJfmF2dGbvgDroVnI8LU7/kTu8mbjRZGBU1z9NTA==} engines: {node: '>=12'}