merge: Reduce federation log spam (maybe resolves #689) (!649)

View MR for information: https://activitypub.software/TransFem-org/Sharkey/-/merge_requests/649

Closes #689

Approved-by: dakkar <dakkar@thenautilus.net>
Approved-by: Marie <github@yuugi.dev>
This commit is contained in:
Hazelnoot 2024-10-10 19:43:39 +00:00
commit ffff1dfc7d

View file

@ -67,7 +67,7 @@ function getJobInfo(job: Bull.Job | undefined, increment = false): string {
// onActiveとかonCompletedのattemptsMadeがなぜか0始まりなのでインクリメントする // onActiveとかonCompletedのattemptsMadeがなぜか0始まりなのでインクリメントする
const currentAttempts = job.attemptsMade + (increment ? 1 : 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}`; return `id=${job.id} attempts=${currentAttempts}/${maxAttempts} age=${formated}`;
} }
@ -126,20 +126,30 @@ export class QueueProcessorService implements OnApplicationShutdown {
) { ) {
this.logger = this.queueLoggerService.logger; this.logger = this.queueLoggerService.logger;
function renderError(e: Error): any { function renderError(e?: Error) {
if (e) { // 何故かeがundefinedで来ることがある // 何故かeがundefinedで来ることがある
return { if (!e) return '?';
stack: e.stack,
message: e.message, if (e instanceof Bull.UnrecoverableError || e.name === 'AbortError') {
name: e.name, return `${e.name}: ${e.message}`;
};
} else {
return {
stack: '?',
message: '?',
name: '?',
};
} }
return {
stack: e.stack,
message: e.message,
name: e.name,
};
}
function renderJob(job?: Bull.Job) {
if (!job) return '?';
return {
name: job.name || undefined,
info: getJobInfo(job),
failedReason: job.failedReason || undefined,
data: job.data,
};
} }
//#region system //#region system
@ -173,15 +183,15 @@ export class QueueProcessorService implements OnApplicationShutdown {
.on('active', (job) => logger.debug(`active id=${job.id}`)) .on('active', (job) => logger.debug(`active id=${job.id}`))
.on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`))
.on('failed', (job, err: Error) => { .on('failed', (job, err: Error) => {
logger.error(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); logger.error(`failed(${err.name}: ${err.message}) id=${job?.id ?? '?'}`, { job: renderJob(job), e: renderError(err) });
if (config.sentryForBackend) { if (config.sentryForBackend) {
Sentry.captureMessage(`Queue: System: ${job?.name ?? '?'}: ${err.message}`, { Sentry.captureMessage(`Queue: System: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, {
level: 'error', level: 'error',
extra: { job, err }, extra: { job, err },
}); });
} }
}) })
.on('error', (err: Error) => logger.error(`error ${err.stack}`, { 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}`)); .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`));
} }
//#endregion //#endregion
@ -238,15 +248,15 @@ export class QueueProcessorService implements OnApplicationShutdown {
.on('active', (job) => logger.debug(`active id=${job.id}`)) .on('active', (job) => logger.debug(`active id=${job.id}`))
.on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`))
.on('failed', (job, err) => { .on('failed', (job, err) => {
logger.error(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); logger.error(`failed(${err.name}: ${err.message}) id=${job?.id ?? '?'}`, { job: renderJob(job), e: renderError(err) });
if (config.sentryForBackend) { if (config.sentryForBackend) {
Sentry.captureMessage(`Queue: DB: ${job?.name ?? '?'}: ${err.message}`, { Sentry.captureMessage(`Queue: DB: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, {
level: 'error', level: 'error',
extra: { job, err }, extra: { job, err },
}); });
} }
}) })
.on('error', (err: Error) => logger.error(`error ${err.stack}`, { 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}`)); .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`));
} }
//#endregion //#endregion
@ -278,15 +288,15 @@ export class QueueProcessorService implements OnApplicationShutdown {
.on('active', (job) => logger.debug(`active ${getJobInfo(job, true)} to=${job.data.to}`)) .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('completed', (job, result) => logger.debug(`completed(${result}) ${getJobInfo(job, true)} to=${job.data.to}`))
.on('failed', (job, err) => { .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) { if (config.sentryForBackend) {
Sentry.captureMessage(`Queue: Deliver: ${err.message}`, { Sentry.captureMessage(`Queue: Deliver: ${err.name}: ${err.message}`, {
level: 'error', level: 'error',
extra: { job, err }, extra: { job, err },
}); });
} }
}) })
.on('error', (err: Error) => logger.error(`error ${err.stack}`, { 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}`)); .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`));
} }
//#endregion //#endregion
@ -318,15 +328,15 @@ export class QueueProcessorService implements OnApplicationShutdown {
.on('active', (job) => logger.debug(`active ${getJobInfo(job, true)}`)) .on('active', (job) => logger.debug(`active ${getJobInfo(job, true)}`))
.on('completed', (job, result) => logger.debug(`completed(${result}) ${getJobInfo(job, true)}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) ${getJobInfo(job, true)}`))
.on('failed', (job, err) => { .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}: ${err.message}) ${getJobInfo(job)} activity=${job ? (job.data.activity ? job.data.activity.id : 'none') : '-'}`, { job: renderJob(job), e: renderError(err) });
if (config.sentryForBackend) { if (config.sentryForBackend) {
Sentry.captureMessage(`Queue: Inbox: ${err.message}`, { Sentry.captureMessage(`Queue: Inbox: ${err.name}: ${err.message}`, {
level: 'error', level: 'error',
extra: { job, err }, extra: { job, err },
}); });
} }
}) })
.on('error', (err: Error) => logger.error(`error ${err.stack}`, { 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}`)); .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`));
} }
//#endregion //#endregion
@ -358,15 +368,15 @@ export class QueueProcessorService implements OnApplicationShutdown {
.on('active', (job) => logger.debug(`active ${getJobInfo(job, true)} to=${job.data.to}`)) .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('completed', (job, result) => logger.debug(`completed(${result}) ${getJobInfo(job, true)} to=${job.data.to}`))
.on('failed', (job, err) => { .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) { if (config.sentryForBackend) {
Sentry.captureMessage(`Queue: UserWebhookDeliver: ${err.message}`, { Sentry.captureMessage(`Queue: UserWebhookDeliver: ${err.name}: ${err.message}`, {
level: 'error', level: 'error',
extra: { job, err }, extra: { job, err },
}); });
} }
}) })
.on('error', (err: Error) => logger.error(`error ${err.stack}`, { 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}`)); .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`));
} }
//#endregion //#endregion
@ -398,15 +408,15 @@ export class QueueProcessorService implements OnApplicationShutdown {
.on('active', (job) => logger.debug(`active ${getJobInfo(job, true)} to=${job.data.to}`)) .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('completed', (job, result) => logger.debug(`completed(${result}) ${getJobInfo(job, true)} to=${job.data.to}`))
.on('failed', (job, err) => { .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) { if (config.sentryForBackend) {
Sentry.captureMessage(`Queue: SystemWebhookDeliver: ${err.message}`, { Sentry.captureMessage(`Queue: SystemWebhookDeliver: ${err.name}: ${err.message}`, {
level: 'error', level: 'error',
extra: { job, err }, extra: { job, err },
}); });
} }
}) })
.on('error', (err: Error) => logger.error(`error ${err.stack}`, { 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}`)); .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`));
} }
//#endregion //#endregion
@ -445,15 +455,15 @@ export class QueueProcessorService implements OnApplicationShutdown {
.on('active', (job) => logger.debug(`active id=${job.id}`)) .on('active', (job) => logger.debug(`active id=${job.id}`))
.on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`))
.on('failed', (job, err) => { .on('failed', (job, err) => {
logger.error(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); logger.error(`failed(${err.name}: ${err.message}) id=${job?.id ?? '?'}`, { job: renderJob(job), e: renderError(err) });
if (config.sentryForBackend) { if (config.sentryForBackend) {
Sentry.captureMessage(`Queue: Relationship: ${job?.name ?? '?'}: ${err.message}`, { Sentry.captureMessage(`Queue: Relationship: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, {
level: 'error', level: 'error',
extra: { job, err }, extra: { job, err },
}); });
} }
}) })
.on('error', (err: Error) => logger.error(`error ${err.stack}`, { 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}`)); .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`));
} }
//#endregion //#endregion
@ -486,15 +496,15 @@ export class QueueProcessorService implements OnApplicationShutdown {
.on('active', (job) => logger.debug(`active id=${job.id}`)) .on('active', (job) => logger.debug(`active id=${job.id}`))
.on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`)) .on('completed', (job, result) => logger.debug(`completed(${result}) id=${job.id}`))
.on('failed', (job, err) => { .on('failed', (job, err) => {
logger.error(`failed(${err.stack}) id=${job ? job.id : '-'}`, { job, e: renderError(err) }); logger.error(`failed(${err.name}: ${err.message}) id=${job?.id ?? '?'}`, { job: renderJob(job), e: renderError(err) });
if (config.sentryForBackend) { if (config.sentryForBackend) {
Sentry.captureMessage(`Queue: ObjectStorage: ${job?.name ?? '?'}: ${err.message}`, { Sentry.captureMessage(`Queue: ObjectStorage: ${job?.name ?? '?'}: ${err.name}: ${err.message}`, {
level: 'error', level: 'error',
extra: { job, err }, extra: { job, err },
}); });
} }
}) })
.on('error', (err: Error) => logger.error(`error ${err.stack}`, { 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}`)); .on('stalled', (jobId) => logger.warn(`stalled id=${jobId}`));
} }
//#endregion //#endregion