enhance(logging): ログの情報を増やす (MisskeyIO#351)

This commit is contained in:
まっちゃとーにゅ 2024-01-11 11:41:20 +09:00 committed by GitHub
parent 38469c2b87
commit 91e4522a96
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
21 changed files with 100 additions and 57 deletions

View file

@ -71,7 +71,7 @@ if (!envOption.quiet) {
// Display detail of uncaught exception
process.on('uncaughtException', err => {
try {
logger.error(err);
logger.error('Uncaught exception', { error: err });
} catch { }
});

View file

@ -65,7 +65,7 @@ export async function masterMain() {
//await connectDb();
if (config.pidFile) fs.writeFileSync(config.pidFile, process.pid.toString());
} catch (e) {
bootLogger.error('Fatal error occurred during initialization', null, true);
bootLogger.error('Fatal error occurred during initialization', { error: e }, true);
process.exit(1);
}
@ -124,7 +124,7 @@ function loadConfigBoot(): Config {
config = loadConfig();
} catch (exception) {
if (typeof exception === 'string') {
configLogger.error(exception);
configLogger.error(exception, null, true);
process.exit(1);
} else if ((exception as any).code === 'ENOENT') {
configLogger.error('Configuration file not found', null, true);

View file

@ -11,6 +11,8 @@ import * as nsfw from 'nsfwjs';
import si from 'systeminformation';
import { Mutex } from 'async-mutex';
import { bindThis } from '@/decorators.js';
import type Logger from '@/logger.js';
import { LoggerService } from '@/core/LoggerService.js';
const _filename = fileURLToPath(import.meta.url);
const _dirname = dirname(_filename);
@ -20,11 +22,14 @@ let isSupportedCpu: undefined | boolean = undefined;
@Injectable()
export class AiService {
private logger: Logger;
private model: nsfw.NSFWJS;
private modelLoadMutex: Mutex = new Mutex();
constructor(
private loggerService: LoggerService,
) {
this.logger = this.loggerService.getLogger('ai');
}
@bindThis
@ -36,7 +41,7 @@ export class AiService {
}
if (!isSupportedCpu) {
console.error('This CPU cannot use TensorFlow.');
this.logger.error('This CPU cannot use TensorFlow.');
return null;
}
@ -59,7 +64,7 @@ export class AiService {
image.dispose();
}
} catch (err) {
console.error(err);
this.logger.error('Failed to detect sensitive', { error: err });
return null;
}
}

View file

@ -403,7 +403,7 @@ export class DriveService {
})
.catch(
err => {
this.registerLogger.error(`Upload Failed: key = ${key}, filename = ${filename}`, err);
this.registerLogger.error(`Upload Failed: key = ${key}, filename = ${filename}`, { error: err });
},
);
}
@ -620,7 +620,7 @@ export class DriveService {
userId: user ? user.id : IsNull(),
}) as MiDriveFile;
} else {
this.registerLogger.error(err as Error);
this.registerLogger.error(`failed to register ${file.uri}`, { error: err });
throw err;
}
}
@ -863,7 +863,7 @@ export class DriveService {
} catch (err) {
this.downloaderLogger.error(`Failed to create drive file: ${err}`, {
url: url,
e: err,
error: err,
});
throw err;
} finally {

View file

@ -148,7 +148,7 @@ export class EmailService {
this.logger.info(`Message sent: ${info.messageId}`);
} catch (err) {
this.logger.error(err as Error);
this.logger.error('Failed to send email', { error: err });
throw err;
}
}

View file

@ -116,7 +116,7 @@ export class FetchInstanceMetadataService {
this.logger.succ(`Successfuly updated metadata of ${instance.host}`);
} catch (e) {
this.logger.error(`Failed to update metadata of ${instance.host}: ${e}`);
this.logger.error(`Failed to update metadata of ${instance.host}: ${e}`, { error: e });
} finally {
await this.unlock(host);
}
@ -160,7 +160,7 @@ export class FetchInstanceMetadataService {
return info as NodeInfo;
} catch (err) {
this.logger.error(`Failed to fetch nodeinfo of ${instance.host}: ${err}`);
this.logger.error(`Failed to fetch nodeinfo of ${instance.host}: ${err}`, { error: err });
throw err;
}

View file

@ -32,10 +32,12 @@ import { RelayService } from '@/core/RelayService.js';
import { FederatedInstanceService } from '@/core/FederatedInstanceService.js';
import { DI } from '@/di-symbols.js';
import type { Config } from '@/config.js';
import type Logger from '@/logger.js';
import NotesChart from '@/core/chart/charts/notes.js';
import PerUserNotesChart from '@/core/chart/charts/per-user-notes.js';
import InstanceChart from '@/core/chart/charts/instance.js';
import ActiveUsersChart from '@/core/chart/charts/active-users.js';
import { LoggerService } from '@/core/LoggerService.js';
import { GlobalEventService } from '@/core/GlobalEventService.js';
import { NotificationService } from '@/core/NotificationService.js';
import { WebhookService } from '@/core/WebhookService.js';
@ -149,6 +151,7 @@ type Option = {
@Injectable()
export class NoteCreateService implements OnApplicationShutdown {
private logger: Logger;
#shutdownController = new AbortController();
constructor(
@ -217,7 +220,10 @@ export class NoteCreateService implements OnApplicationShutdown {
private instanceChart: InstanceChart,
private utilityService: UtilityService,
private userBlockingService: UserBlockingService,
) { }
private loggerService: LoggerService,
) {
this.logger = this.loggerService.getLogger('note:create');
}
@bindThis
public async create(user: {
@ -472,7 +478,7 @@ export class NoteCreateService implements OnApplicationShutdown {
throw err;
}
console.error(e);
this.logger.error(`Failed to create note: ${e}`, { error: e });
throw e;
}

View file

@ -145,7 +145,7 @@ export class RemoteUserResolveService {
private async resolveSelf(acctLower: string): Promise<ILink> {
this.logger.info(`WebFinger for ${chalk.yellow(acctLower)}`);
const finger = await this.webfingerService.webfinger(acctLower).catch(err => {
this.logger.error(`Failed to WebFinger for ${chalk.yellow(acctLower)}: ${ err.statusCode ?? err.message }`);
this.logger.error(`Failed to WebFinger for ${chalk.yellow(acctLower)}: ${ err.statusCode ?? err.message }`, { error: err });
throw new Error(`Failed to WebFinger for ${acctLower}: ${ err.statusCode ?? err.message }`);
});
const self = finger.links.find(link => link.rel != null && link.rel.toLowerCase() === 'self');

View file

@ -15,8 +15,10 @@ import { AttestationFormat, isoCBOR } from '@simplewebauthn/server/helpers';
import { DI } from '@/di-symbols.js';
import type { UserSecurityKeysRepository } from '@/models/_.js';
import type { Config } from '@/config.js';
import type Logger from '@/logger.js';
import { bindThis } from '@/decorators.js';
import { MetaService } from '@/core/MetaService.js';
import { LoggerService } from '@/core/LoggerService.js';
import { MiUser } from '@/models/_.js';
import { IdentifiableError } from '@/misc/identifiable-error.js';
import type {
@ -31,6 +33,8 @@ import type {
@Injectable()
export class WebAuthnService {
private logger: Logger;
constructor(
@Inject(DI.redis)
private redisClient: Redis.Redis,
@ -42,7 +46,9 @@ export class WebAuthnService {
private userSecurityKeysRepository: UserSecurityKeysRepository,
private metaService: MetaService,
private loggerService: LoggerService,
) {
this.logger = this.loggerService.getLogger('webauthn');
}
@bindThis
@ -118,7 +124,7 @@ export class WebAuthnService {
requireUserVerification: true,
});
} catch (error) {
console.error(error);
this.logger.error('Failed to verify registration response', { error });
throw new IdentifiableError('5c1446f8-8ca7-4d31-9f39-656afe9c5d87', 'verification failed');
}
@ -228,7 +234,7 @@ export class WebAuthnService {
requireUserVerification: true,
});
} catch (error) {
console.error(error);
this.logger.error('Failed to verify authentication response', { error });
throw new IdentifiableError('b18c89a7-5b5e-4cec-bb5b-0419f332d430', 'verification failed');
}

View file

@ -197,7 +197,7 @@ export class ApInboxService {
const resolver = this.apResolverService.createResolver();
const object = await resolver.resolve(activity.object).catch(err => {
this.logger.error(`Resolution failed: ${err}`);
this.logger.error(`Resolution failed: ${err}`, { error: err });
throw err;
});
@ -370,7 +370,7 @@ export class ApInboxService {
const resolver = this.apResolverService.createResolver();
const object = await resolver.resolve(activity.object).catch(e => {
this.logger.error(`Resolution failed: ${e}`);
this.logger.error(`Resolution failed: ${e}`, { error: e });
throw e;
});
@ -544,7 +544,7 @@ export class ApInboxService {
const resolver = this.apResolverService.createResolver();
const object = await resolver.resolve(activity.object).catch(e => {
this.logger.error(`Resolution failed: ${e}`);
this.logger.error(`Resolution failed: ${e}`, { error: e });
throw e;
});
@ -610,7 +610,7 @@ export class ApInboxService {
const resolver = this.apResolverService.createResolver();
const object = await resolver.resolve(activity.object).catch(e => {
this.logger.error(`Resolution failed: ${e}`);
this.logger.error(`Resolution failed: ${e}`, { error: e });
throw e;
});
@ -741,7 +741,7 @@ export class ApInboxService {
const resolver = this.apResolverService.createResolver();
const object = await resolver.resolve(activity.object).catch(e => {
this.logger.error(`Resolution failed: ${e}`);
this.logger.error(`Resolution failed: ${e}`, { error: e });
throw e;
});
@ -749,7 +749,7 @@ export class ApInboxService {
await this.apPersonService.updatePerson(actor.uri, resolver, object);
return 'ok: Person updated';
} else if (getApType(object) === 'Question') {
await this.apQuestionService.updateQuestion(object, resolver).catch(err => console.error(err));
await this.apQuestionService.updateQuestion(object, resolver).catch(err => this.logger.error(`err: failed to update question: ${err}`, { error: err }));
return 'ok: Question updated';
} else {
return `skip: Unknown type: ${getApType(object)}`;

View file

@ -126,6 +126,7 @@ export class ApNoteService {
resolver: { history: resolver.getHistory() },
value,
object,
error: err
});
throw new Error('invalid note');
}

View file

@ -301,7 +301,7 @@ export class ApPersonService implements OnModuleInit {
const emojis = await this.apNoteService.extractEmojis(person.tag ?? [], host)
.then(_emojis => _emojis.map(emoji => emoji.name))
.catch(err => {
this.logger.error('error occurred while fetching user emojis', { stack: err });
this.logger.error('error occurred while fetching user emojis', { error: err });
return [];
});
//#endregion
@ -369,7 +369,7 @@ export class ApPersonService implements OnModuleInit {
user = u as MiRemoteUser;
} else {
this.logger.error(e instanceof Error ? e : new Error(e as string));
this.logger.error('error occurred while creating user', { error: e });
throw e;
}
}
@ -402,7 +402,7 @@ export class ApPersonService implements OnModuleInit {
// Register to the cache
this.cacheService.uriPersonCache.set(user.uri, user);
} catch (err) {
this.logger.error('error occurred while fetching user avatar/banner', { stack: err });
this.logger.error('error occurred while fetching user avatar/banner', { error: err });
}
//#endregion

View file

@ -88,16 +88,25 @@ export default class Logger {
if (data != null) {
args.push(data);
}
console.log(...args);
if (level === 'error' || level === 'warning') {
console.error(...args);
} else {
console.log(...args);
}
}
@bindThis
public error(x: string | Error, data?: Record<string, any> | null, important = false): void { // 実行を継続できない状況で使う
if (x instanceof Error) {
data = data ?? {};
data.e = x;
data.error = x;
this.log('error', x.toString(), data, important);
} else if (typeof x === 'object') {
data = data ?? {};
data.error = data.error ?? x;
this.log('error', `${(x as any).message ?? (x as any).name ?? x}`, data, important);
} else {
this.log('error', `${x}`, data, important);
@ -105,8 +114,20 @@ export default class Logger {
}
@bindThis
public warn(message: string, data?: Record<string, any> | null, important = false): void { // 実行を継続できるが改善すべき状況で使う
this.log('warning', message, data, important);
public warn(x: string | Error, data?: Record<string, any> | null, important = false): void { // 実行を継続できるが改善すべき状況で使う
if (x instanceof Error) {
data = data ?? {};
data.error = x;
this.log('warning', x.toString(), data, important);
} else if (typeof x === 'object') {
data = data ?? {};
data.error = data.error ?? x;
this.log('warning', `${(x as any).message ?? (x as any).name ?? x}`, data, important);
} else {
this.log('warning', `${x}`, data, important);
}
}
@bindThis

View file

@ -157,8 +157,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.stack}) id=${job ? job.id : '-'}`, { job, error: renderError(err) }))
.on('error', (err: Error) => systemLogger.error(`error ${err.stack}`, { error: renderError(err) }))
.on('stalled', (jobId) => systemLogger.warn(`stalled id=${jobId}`));
//#endregion
@ -197,8 +197,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.stack}) id=${job ? job.id : '-'}`, { job, error: renderError(err) }))
.on('error', (err: Error) => dbLogger.error(`error ${err.stack}`, { error: renderError(err) }))
.on('stalled', (jobId) => dbLogger.warn(`stalled id=${jobId}`));
//#endregion
@ -222,7 +222,7 @@ export class QueueProcessorService implements OnApplicationShutdown {
.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('error', (err: Error) => deliverLogger.error(`error ${err.stack}`, { error: renderError(err) }))
.on('stalled', (jobId) => deliverLogger.warn(`stalled id=${jobId}`));
//#endregion
@ -245,8 +245,8 @@ 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.stack}) ${getJobInfo(job)} activity=${job ? (job.data.activity ? job.data.activity.id : 'none') : '-'}`, { job, error: renderError(err) }))
.on('error', (err: Error) => inboxLogger.error(`error ${err.stack}`, { error: renderError(err) }))
.on('stalled', (jobId) => inboxLogger.warn(`stalled id=${jobId}`));
//#endregion
@ -270,7 +270,7 @@ export class QueueProcessorService implements OnApplicationShutdown {
.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('error', (err: Error) => webhookLogger.error(`error ${err.stack}`, { error: renderError(err) }))
.on('stalled', (jobId) => webhookLogger.warn(`stalled id=${jobId}`));
//#endregion
@ -298,8 +298,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.stack}) id=${job ? job.id : '-'}`, { job, error: renderError(err) }))
.on('error', (err: Error) => relationshipLogger.error(`error ${err.stack}`, { error: renderError(err) }))
.on('stalled', (jobId) => relationshipLogger.warn(`stalled id=${jobId}`));
//#endregion
@ -321,8 +321,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.stack}) id=${job ? job.id : '-'}`, { job, error: renderError(err) }))
.on('error', (err: Error) => objectStorageLogger.error(`error ${err.stack}`, { error: renderError(err) }))
.on('stalled', (jobId) => objectStorageLogger.warn(`stalled id=${jobId}`));
//#endregion

View file

@ -99,7 +99,7 @@ export class ExportCustomEmojisProcessorService {
await this.downloadService.downloadUrl(emoji.originalUrl, emojiPath);
downloaded = true;
} catch (e) { // TODO: 何度か再試行
this.logger.error(e instanceof Error ? e : new Error(e as string));
this.logger.error(`Failed to download emoji '${emoji.name}': ${emoji.originalUrl}`, { error: e });
}
if (!downloaded) {

View file

@ -96,7 +96,7 @@ export class FileServerService {
@bindThis
private async errorHandler(request: FastifyRequest<{ Params?: { [x: string]: any }; Querystring?: { [x: string]: any }; }>, reply: FastifyReply, err?: any) {
this.logger.error(`${err}`);
this.logger.error('file server error', { error: err });
reply.header('Cache-Control', 'max-age=300');

View file

@ -371,14 +371,13 @@ export class ApiCallService implements OnApplicationShutdown {
this.logger.error(`Internal error occurred in ${ep.name}: ${err.message}`, {
ep: ep.name,
ps: data,
e: {
id: errId,
error: {
message: err.message,
code: err.name,
stack: err.stack,
id: errId,
},
});
console.error(err, errId);
throw new ApiError(null, {
e: {
message: err.message,

View file

@ -6,10 +6,12 @@
import ms from 'ms';
import { Injectable } from '@nestjs/common';
import { DB_MAX_IMAGE_COMMENT_LENGTH } from '@/const.js';
import type Logger from '@/logger.js';
import { IdentifiableError } from '@/misc/identifiable-error.js';
import { Endpoint } from '@/server/api/endpoint-base.js';
import { DriveFileEntityService } from '@/core/entities/DriveFileEntityService.js';
import { MetaService } from '@/core/MetaService.js';
import { LoggerService } from '@/core/LoggerService.js';
import { DriveService } from '@/core/DriveService.js';
import { ApiError } from '../../../error.js';
@ -73,9 +75,12 @@ export const paramDef = {
@Injectable()
export default class extends Endpoint<typeof meta, typeof paramDef> { // eslint-disable-line import/no-default-export
private logger: Logger;
constructor(
private driveFileEntityService: DriveFileEntityService,
private metaService: MetaService,
private loggerService: LoggerService,
private driveService: DriveService,
) {
super(meta, paramDef, async (ps, me, _, file, cleanup, ip, headers) => {
@ -109,9 +114,7 @@ export default class extends Endpoint<typeof meta, typeof paramDef> { // eslint-
});
return await this.driveFileEntityService.pack(driveFile, me, { self: true });
} catch (err) {
if (err instanceof Error || typeof err === 'string') {
console.error(err);
}
this.logger.error('Failed to create drive file', { error: err });
if (err instanceof IdentifiableError) {
if (err.id === '282f77bf-5816-4f72-9264-aa14d8261a21') throw new ApiError(meta.errors.inappropriate);
if (err.id === 'c6244ed2-a39a-4e1c-bf93-f0fbd7764fa6') throw new ApiError(meta.errors.noFreeSpace);
@ -121,5 +124,7 @@ export default class extends Endpoint<typeof meta, typeof paramDef> { // eslint-
cleanup!();
}
});
this.logger = this.loggerService.getLogger('api:drive:files:create');
}
}

View file

@ -138,8 +138,7 @@ async function discoverClientInformation(logger: Logger, httpRequestService: Htt
name: typeof name === 'string' ? name : id,
};
} catch (err) {
console.error(err);
logger.error('Error while fetching client information', { err });
logger.error('Error while fetching client information', { error: err });
if (err instanceof StatusError) {
throw new AuthorizationError('Failed to fetch client information', 'invalid_request');
} else {

View file

@ -783,9 +783,8 @@ export class ClientServerService {
path: request.routeOptions.url,
params: request.params,
query: request.query,
code: error.name,
stack: error.stack,
id: errId,
error,
});
reply.code(500);
reply.header('Cache-Control', 'max-age=10, must-revalidate');

View file

@ -12,6 +12,7 @@ import { ModuleMocker } from 'jest-mock';
import { Test } from '@nestjs/testing';
import { afterAll, beforeAll, describe, test } from '@jest/globals';
import { GlobalModule } from '@/GlobalModule.js';
import { LoggerService } from '@/core/LoggerService.js';
import { FileInfoService } from '@/core/FileInfoService.js';
//import { DI } from '@/di-symbols.js';
import { AiService } from '@/core/AiService.js';
@ -34,6 +35,7 @@ describe('FileInfoService', () => {
GlobalModule,
],
providers: [
LoggerService,
AiService,
FileInfoService,
],