From ed0570110bf8cb8e8959591dccfa3c35999106ce Mon Sep 17 00:00:00 2001 From: Hazel K Date: Thu, 3 Oct 2024 20:38:26 -0400 Subject: [PATCH 01/10] reduce federation log spam * Don't record stack trace for unrecoverable errors. * Avoid logging duplicate stace traces. --- .../src/queue/QueueProcessorService.ts | 36 +++++++++++-------- 1 file changed, 21 insertions(+), 15 deletions(-) diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index 7a6169bf9c..6ad77a0487 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -126,8 +126,14 @@ export class QueueProcessorService implements OnApplicationShutdown { ) { this.logger = this.queueLoggerService.logger; - function renderError(e: Error): any { - if (e) { // 何故かeがundefinedで来ることがある + function renderError(e: Error) { + if (e instanceof Bull.UnrecoverableError) { + return { + stack: undefined, + message: e.message, + name: 'Bull.UnrecoverableError', + }; + } else if (e) { // 何故かeがundefinedで来ることがある return { stack: e.stack, message: e.message, @@ -173,7 +179,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err: Error) => { - logger.error(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: System: ${job?.name ?? '?'}: ${err.message}`, { level: 'error', @@ -181,7 +187,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }); } }) - .on('error', (err: Error) => logger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -238,7 +244,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: DB: ${job?.name ?? '?'}: ${err.message}`, { level: 'error', @@ -246,7 +252,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }); } }) - .on('error', (err: Error) => logger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -286,7 +292,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }); } }) - .on('error', (err: Error) => logger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -318,7 +324,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active ${getJobInfo(job, true)}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) ${getJobInfo(job, true)}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.stack}) ${getJobInfo(job)} activity=${job ? (job.data.activity ? job.data.activity.id : 'none') : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}) ${getJobInfo(job)} activity=${job ? (job.data.activity ? job.data.activity.id : 'none') : '-'}`, { job, e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: Inbox: ${err.message}`, { level: 'error', @@ -326,7 +332,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }); } }) - .on('error', (err: Error) => logger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -366,7 +372,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }); } }) - .on('error', (err: Error) => logger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -406,7 +412,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }); } }) - .on('error', (err: Error) => logger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -445,7 +451,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: Relationship: ${job?.name ?? '?'}: ${err.message}`, { level: 'error', @@ -453,7 +459,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }); } }) - .on('error', (err: Error) => logger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -486,7 +492,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: ObjectStorage: ${job?.name ?? '?'}: ${err.message}`, { level: 'error', @@ -494,7 +500,7 @@ export class QueueProcessorService implements OnApplicationShutdown { }); } }) - .on('error', (err: Error) => logger.error(`error ${err.stack}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion From 20dd66f735d9778df0371001e303549dce619260 Mon Sep 17 00:00:00 2001 From: Hazel K Date: Tue, 8 Oct 2024 10:14:26 -0400 Subject: [PATCH 02/10] improve error summaries --- .../src/queue/QueueProcessorService.ts | 48 +++++++++---------- 1 file changed, 24 insertions(+), 24 deletions(-) diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index 6ad77a0487..9c31a0386d 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -179,15 +179,15 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err: Error) => { - logger.error(`failed(${err.name}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); if (config.sentryForBackend) { - Sentry.captureMessage(`Queue: System: ${job?.name ?? '?'}: ${err.message}`, { + Sentry.captureMessage(`Queue: System: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', extra: { job, err }, }); } }) - .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -244,15 +244,15 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.name}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); if (config.sentryForBackend) { - Sentry.captureMessage(`Queue: DB: ${job?.name ?? '?'}: ${err.message}`, { + Sentry.captureMessage(`Queue: DB: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', extra: { job, err }, }); } }) - .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -284,15 +284,15 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active ${getJobInfo(job, true)} to=${job.data.to}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) ${getJobInfo(job, true)} to=${job.data.to}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.stack}) ${getJobInfo(job)} to=${job ? job.data.to : '-'}`); + logger.error(`failed(${err.name}: ${err.message}) ${getJobInfo(job)} to=${job ? job.data.to : '-'}`); if (config.sentryForBackend) { - Sentry.captureMessage(`Queue: Deliver: ${err.message}`, { + Sentry.captureMessage(`Queue: Deliver: ${err.name}: ${err.message}`, { level: 'error', extra: { job, err }, }); } }) - .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -324,15 +324,15 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active ${getJobInfo(job, true)}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) ${getJobInfo(job, true)}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.name}) ${getJobInfo(job)} activity=${job ? (job.data.activity ? job.data.activity.id : 'none') : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) ${getJobInfo(job)} activity=${job ? (job.data.activity ? job.data.activity.id : 'none') : '-'}`, { job, e: renderError(err) }); if (config.sentryForBackend) { - Sentry.captureMessage(`Queue: Inbox: ${err.message}`, { + Sentry.captureMessage(`Queue: Inbox: ${err.name}: ${err.message}`, { level: 'error', extra: { job, err }, }); } }) - .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -364,15 +364,15 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active ${getJobInfo(job, true)} to=${job.data.to}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) ${getJobInfo(job, true)} to=${job.data.to}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.stack}) ${getJobInfo(job)} to=${job ? job.data.to : '-'}`); + logger.error(`failed(${err.name}: ${err.message}) ${getJobInfo(job)} to=${job ? job.data.to : '-'}`); if (config.sentryForBackend) { - Sentry.captureMessage(`Queue: UserWebhookDeliver: ${err.message}`, { + Sentry.captureMessage(`Queue: UserWebhookDeliver: ${err.name}: ${err.message}`, { level: 'error', extra: { job, err }, }); } }) - .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -404,15 +404,15 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active ${getJobInfo(job, true)} to=${job.data.to}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) ${getJobInfo(job, true)} to=${job.data.to}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.stack}) ${getJobInfo(job)} to=${job ? job.data.to : '-'}`); + logger.error(`failed(${err.name}: ${err.message}) ${getJobInfo(job)} to=${job ? job.data.to : '-'}`); if (config.sentryForBackend) { - Sentry.captureMessage(`Queue: SystemWebhookDeliver: ${err.message}`, { + Sentry.captureMessage(`Queue: SystemWebhookDeliver: ${err.name}: ${err.message}`, { level: 'error', extra: { job, err }, }); } }) - .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -451,15 +451,15 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.name}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); if (config.sentryForBackend) { - Sentry.captureMessage(`Queue: Relationship: ${job?.name ?? '?'}: ${err.message}`, { + Sentry.captureMessage(`Queue: Relationship: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', extra: { job, err }, }); } }) - .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion @@ -492,15 +492,15 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.name}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); if (config.sentryForBackend) { - Sentry.captureMessage(`Queue: ObjectStorage: ${job?.name ?? '?'}: ${err.message}`, { + Sentry.captureMessage(`Queue: ObjectStorage: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', extra: { job, err }, }); } }) - .on('error', (err: Error) => logger.error(`error ${err.name}`, { e: renderError(err) })) + .on('error', (err: Error) => logger.error(`error ${err.name}: ${err.message}`, { e: renderError(err) })) .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`)); } //#endregion From 83869e1c470b12b3bf4b23d885514d926620662a Mon Sep 17 00:00:00 2001 From: Hazel K Date: Tue, 8 Oct 2024 10:14:33 -0400 Subject: [PATCH 03/10] fix lint errors --- packages/backend/src/queue/QueueProcessorService.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index 9c31a0386d..ab05194c90 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -126,7 +126,7 @@ export class QueueProcessorService implements OnApplicationShutdown { ) { this.logger = this.queueLoggerService.logger; - function renderError(e: Error) { + function renderError(e?: Error) { if (e instanceof Bull.UnrecoverableError) { return { stack: undefined, From 786702e076ad1af14538849512ad31c0ced7afe6 Mon Sep 17 00:00:00 2001 From: Hazel K Date: Tue, 8 Oct 2024 10:27:55 -0400 Subject: [PATCH 04/10] condense job info --- .../src/queue/QueueProcessorService.ts | 20 ++++++++++++++----- 1 file changed, 15 insertions(+), 5 deletions(-) diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index ab05194c90..8df3e09428 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -148,6 +148,16 @@ export class QueueProcessorService implements OnApplicationShutdown { } } + function renderJob(job?: Bull.Job) { + if (!job) return 'N/A'; + return { + name: job.name, + info: getJobInfo(job), + failedReason: job.failedReason || undefined, + data: job.data, + }; + } + //#region system { const processer = (job: Bull.Job) => { @@ -179,7 +189,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err: Error) => { - logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job: renderJob(job), e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: System: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', @@ -244,7 +254,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job: renderJob(job), e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: DB: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', @@ -324,7 +334,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active ${getJobInfo(job, true)}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) ${getJobInfo(job, true)}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.name}: ${err.message}) ${getJobInfo(job)} activity=${job ? (job.data.activity ? job.data.activity.id : 'none') : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) ${getJobInfo(job)} activity=${job ? (job.data.activity ? job.data.activity.id : 'none') : '-'}`, { job: renderJob(job), e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: Inbox: ${err.name}: ${err.message}`, { level: 'error', @@ -451,7 +461,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job: renderJob(job), e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: Relationship: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', @@ -492,7 +502,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job: renderJob(job), e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: ObjectStorage: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', From b4d10aa8f821e594ec9c907eb2a5bdb3c73c67d5 Mon Sep 17 00:00:00 2001 From: Hazel K Date: Tue, 8 Oct 2024 10:29:03 -0400 Subject: [PATCH 05/10] fix maxAttempts calculation --- packages/backend/src/queue/QueueProcessorService.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index 8df3e09428..5ae0c738b6 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -67,7 +67,7 @@ function getJobInfo(job: Bull.Job | undefined, increment = false): string { // onActiveとかonCompletedのattemptsMadeがなぜか0始まりなのでインクリメントする const currentAttempts = job.attemptsMade + (increment ? 1 : 0); - const maxAttempts = job.opts ? job.opts.attempts : 0; + const maxAttempts = job.opts.attempts ?? 0; return `id=${job.id} attempts=${currentAttempts}/${maxAttempts} age=${formated}`; } From f62cd8941ced74a4865aa5eae4f4a1c7aa1d30f1 Mon Sep 17 00:00:00 2001 From: Hazel K Date: Tue, 8 Oct 2024 10:33:34 -0400 Subject: [PATCH 06/10] condense error info --- .../src/queue/QueueProcessorService.ts | 25 ++++++++----------- 1 file changed, 11 insertions(+), 14 deletions(-) diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index 5ae0c738b6..c22e8d90f1 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -127,29 +127,26 @@ export class QueueProcessorService implements OnApplicationShutdown { this.logger = this.queueLoggerService.logger; function renderError(e?: Error) { + // 何故かeがundefinedで来ることがある + if (!e) return '?'; + if (e instanceof Bull.UnrecoverableError) { return { - stack: undefined, message: e.message, name: 'Bull.UnrecoverableError', }; - } else if (e) { // 何故かeがundefinedで来ることがある - return { - stack: e.stack, - message: e.message, - name: e.name, - }; - } else { - return { - stack: '?', - message: '?', - name: '?', - }; } + + return { + stack: e.stack, + message: e.message, + name: e.name, + }; } function renderJob(job?: Bull.Job) { - if (!job) return 'N/A'; + if (!job) return '?'; + return { name: job.name, info: getJobInfo(job), From d8e1e4890d28347239162e26235eb68b1ff96654 Mon Sep 17 00:00:00 2001 From: Hazel K Date: Tue, 8 Oct 2024 10:33:48 -0400 Subject: [PATCH 07/10] normalize ID logging --- packages/backend/src/queue/QueueProcessorService.ts | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index c22e8d90f1..ea039f6703 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -186,7 +186,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err: Error) => { - logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job: renderJob(job), e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job?.id ?? '?'}`, { job: renderJob(job), e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: System: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', @@ -251,7 +251,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job: renderJob(job), e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job?.id ?? '?'}`, { job: renderJob(job), e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: DB: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', @@ -458,7 +458,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job: renderJob(job), e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job?.id ?? '?'}`, { job: renderJob(job), e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: Relationship: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', @@ -499,7 +499,7 @@ export class QueueProcessorService implements OnApplicationShutdown { .on('active', (job) => logger.debug(`active id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('failed', (job, err) => { - logger.error(`failed(${err.name}: ${err.message}) id=${job ? job.id : '-'}`, { job: renderJob(job), e: renderError(err) }); + logger.error(`failed(${err.name}: ${err.message}) id=${job?.id ?? '?'}`, { job: renderJob(job), e: renderError(err) }); if (config.sentryForBackend) { Sentry.captureMessage(`Queue: ObjectStorage: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, { level: 'error', From d867c2089b3b24680df0713a2aa0914789e45670 Mon Sep 17 00:00:00 2001 From: Hazel K Date: Tue, 8 Oct 2024 10:43:51 -0400 Subject: [PATCH 08/10] further condense error details --- packages/backend/src/queue/QueueProcessorService.ts | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index ea039f6703..fba7aa2526 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -131,10 +131,7 @@ export class QueueProcessorService implements OnApplicationShutdown { if (!e) return '?'; if (e instanceof Bull.UnrecoverableError) { - return { - message: e.message, - name: 'Bull.UnrecoverableError', - }; + return `${e.name}: ${e.message}`; } return { From 5171ba7113ebc7242527768afb9ab4cec534e3b3 Mon Sep 17 00:00:00 2001 From: Hazel K Date: Tue, 8 Oct 2024 10:43:58 -0400 Subject: [PATCH 09/10] collapse AbortErrors --- packages/backend/src/queue/QueueProcessorService.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index fba7aa2526..83fce60ff0 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -130,7 +130,7 @@ export class QueueProcessorService implements OnApplicationShutdown { // 何故かeがundefinedで来ることがある if (!e) return '?'; - if (e instanceof Bull.UnrecoverableError) { + if (e instanceof Bull.UnrecoverableError || e.name === 'AbortError') { return `${e.name}: ${e.message}`; } From a5316c06ed770b60f7b4c7ff5aa8c71cc0558db7 Mon Sep 17 00:00:00 2001 From: Hazel K Date: Tue, 8 Oct 2024 11:01:24 -0400 Subject: [PATCH 10/10] don't log job name unless it has one --- packages/backend/src/queue/QueueProcessorService.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/backend/src/queue/QueueProcessorService.ts b/packages/backend/src/queue/QueueProcessorService.ts index 83fce60ff0..7fdfba55a7 100644 --- a/packages/backend/src/queue/QueueProcessorService.ts +++ b/packages/backend/src/queue/QueueProcessorService.ts @@ -145,7 +145,7 @@ export class QueueProcessorService implements OnApplicationShutdown { if (!job) return '?'; return { - name: job.name, + name: job.name || undefined, info: getJobInfo(job), failedReason: job.failedReason || undefined, data: job.data,