From 75558add17a14142d51205f20a2f535fc91f3a34 Mon Sep 17 00:00:00 2001 From: syuilo Date: Sun, 3 Feb 2019 16:45:13 +0900 Subject: [PATCH] Better logging --- src/index.ts | 5 --- src/misc/logger.ts | 13 +++++--- src/remote/activitypub/models/image.ts | 7 ++--- src/remote/activitypub/models/note.ts | 14 ++++----- src/remote/activitypub/models/person.ts | 20 ++++++------ src/server/api/limiter.ts | 8 ++--- src/server/index.ts | 2 +- src/services/drive/add-file.ts | 42 +++++++++++++------------ src/services/drive/upload-from-url.ts | 13 ++++---- src/tools/add-emoji.ts | 3 -- src/tools/resync-remote-user.ts | 3 -- 11 files changed, 62 insertions(+), 68 deletions(-) diff --git a/src/index.ts b/src/index.ts index d023ed58d..a42eec1a6 100644 --- a/src/index.ts +++ b/src/index.ts @@ -8,7 +8,6 @@ require('events').EventEmitter.defaultMaxListeners = 128; import * as os from 'os'; import * as cluster from 'cluster'; -import * as debug from 'debug'; import chalk from 'chalk'; import * as portscanner from 'portscanner'; import * as isRoot from 'is-root'; @@ -30,10 +29,6 @@ const bootLogger = logger.createSubLogger('boot', 'magenta'); const clusterLog = logger.createSubLogger('cluster', 'orange'); const ev = new Xev(); -if (process.env.NODE_ENV != 'production' && process.env.DEBUG == null) { - debug.enable('misskey'); -} - //#region Command line argument definitions program .version(pkg.version) diff --git a/src/misc/logger.ts b/src/misc/logger.ts index 5440edab7..8fbff9638 100644 --- a/src/misc/logger.ts +++ b/src/misc/logger.ts @@ -31,19 +31,24 @@ export default class Logger { } public error(message: string | Error): void { // 実行を継続できない状況で使う - this.log(chalk.red.bold('ERROR'), chalk.red.bold(message.toString())); + this.log(chalk.red('ERR '), chalk.red(message.toString())); } public warn(message: string, important = false): void {　// 実行を継続できるが改善すべき状況で使う - this.log(chalk.yellow.bold('WARN'), chalk.yellow.bold(message), important); + this.log(chalk.yellow('WARN'), chalk.yellow(message), important); } public succ(message: string, important = false): void { // 何かに成功した状況で使う - this.log(chalk.blue.green('DONE'), chalk.green.bold(message), important); + this.log(chalk.green('DONE'), chalk.green(message), important); } public info(message: string, important = false): void { // それ以外 - this.log(chalk.blue.bold('INFO'), message, important); + this.log(chalk.blue('INFO'), message, important); } + public debug(message: string, important = false): void { // デバッグ用に使う + if (process.env.NODE_ENV != 'production') { + this.log(chalk.gray('VERB'), chalk.gray(message), important); + } + } } diff --git a/src/remote/activitypub/models/image.ts b/src/remote/activitypub/models/image.ts index ae353f5ef..ef0b24e89 100644 --- a/src/remote/activitypub/models/image.ts +++ b/src/remote/activitypub/models/image.ts @@ -1,12 +1,11 @@ -import * as debug from 'debug'; - import uploadFromUrl from '../../../services/drive/upload-from-url'; import { IRemoteUser } from '../../../models/user'; import DriveFile, { IDriveFile } from '../../../models/drive-file'; import Resolver from '../resolver'; import fetchMeta from '../../../misc/fetch-meta'; +import { apLogger } from '../logger'; -const log = debug('misskey:activitypub'); +const logger = apLogger; /** * Imageを作成します。 @@ -23,7 +22,7 @@ export async function createImage(actor: IRemoteUser, value: any): Promise { - console.log(`extractEmojis: ${e}`); + logger.info(`extractEmojis: ${e}`); return [] as IEmoji[]; }); @@ -215,7 +215,7 @@ export async function extractEmojis(tags: ITag[], host_: string) { return exists; } - log(`register emoji host=${host}, name=${name}`); + logger.info(`register emoji host=${host}, name=${name}`); return await Emoji.insert({ host, diff --git a/src/remote/activitypub/models/person.ts b/src/remote/activitypub/models/person.ts index 16f1086b8..a4173c5e8 100644 --- a/src/remote/activitypub/models/person.ts +++ b/src/remote/activitypub/models/person.ts @@ -1,6 +1,5 @@ import * as mongo from 'mongodb'; import { toUnicode } from 'punycode'; -import * as debug from 'debug'; import config from '../../../config'; import User, { validateUsername, isValidName, IUser, IRemoteUser, isRemoteUser } from '../../../models/user'; @@ -20,8 +19,9 @@ import { IEmoji } from '../../../models/emoji'; import { ITag, extractHashtags } from './tag'; import Following from '../../../models/following'; import { IIdentifier } from './identifier'; +import { apLogger } from '../logger'; -const log = debug('misskey:activitypub'); +const logger = apLogger; /** * Validate Person object @@ -119,7 +119,7 @@ export async function createPerson(uri: string, resolver?: Resolver): Promise { - console.log(`extractEmojis: ${e}`); + logger.info(`extractEmojis: ${e}`); return [] as IEmoji[]; }); @@ -260,7 +260,7 @@ export async function createPerson(uri: string, resolver?: Resolver): Promise console.log(err)); + await updateFeatured(user._id).catch(err => logger.error(err)); return user; } @@ -300,7 +300,7 @@ export async function updatePerson(uri: string, resolver?: Resolver, hint?: obje const person: IPerson = object; - log(`Updating the Person: ${person.id}`); + logger.info(`Updating the Person: ${person.id}`); const [followersCount = 0, followingCount = 0, notesCount = 0] = await Promise.all([ resolver.resolve(person.followers).then( @@ -329,7 +329,7 @@ export async function updatePerson(uri: string, resolver?: Resolver, hint?: obje // カスタム絵文字取得 const emojis = await extractEmojis(person.tag, exist.host).catch(e => { - console.log(`extractEmojis: ${e}`); + logger.info(`extractEmojis: ${e}`); return [] as IEmoji[]; }); @@ -393,7 +393,7 @@ export async function updatePerson(uri: string, resolver?: Resolver, hint?: obje multi: true }); - await updateFeatured(exist._id).catch(err => console.log(err)); + await updateFeatured(exist._id).catch(err => logger.error(err)); } /** @@ -480,7 +480,7 @@ export async function updateFeatured(userId: mongo.ObjectID) { if (!isRemoteUser(user)) return; if (!user.featured) return; - log(`Updating the featured: ${user.uri}`); + logger.info(`Updating the featured: ${user.uri}`); const resolver = new Resolver(); diff --git a/src/server/api/limiter.ts b/src/server/api/limiter.ts index 192aa1977..f5c326f7d 100644 --- a/src/server/api/limiter.ts +++ b/src/server/api/limiter.ts @@ -1,11 +1,11 @@ import * as Limiter from 'ratelimiter'; -import * as debug from 'debug'; import limiterDB from '../../db/redis'; import { IEndpoint } from './endpoints'; import getAcct from '../../misc/acct/render'; import { IUser } from '../../models/user'; +import Logger from '../../misc/logger'; -const log = debug('misskey:limiter'); +const logger = new Logger('limiter'); export default (endpoint: IEndpoint, user: IUser) => new Promise((ok, reject) => { // Redisがインストールされてない場合は常に許可 @@ -49,7 +49,7 @@ export default (endpoint: IEndpoint, user: IUser) => new Promise((ok, reject) => return reject('ERR'); } - log(`@${getAcct(user)} ${endpoint.name} min remaining: ${info.remaining}`); + logger.debug(`@${getAcct(user)} ${endpoint.name} min remaining: ${info.remaining}`); if (info.remaining === 0) { reject('BRIEF_REQUEST_INTERVAL'); @@ -77,7 +77,7 @@ export default (endpoint: IEndpoint, user: IUser) => new Promise((ok, reject) => return reject('ERR'); } - log(`@${getAcct(user)} ${endpoint.name} max remaining: ${info.remaining}`); + logger.debug(`@${getAcct(user)} ${endpoint.name} max remaining: ${info.remaining}`); if (info.remaining === 0) { reject('RATE_LIMIT_EXCEEDED'); diff --git a/src/server/index.ts b/src/server/index.ts index edb78f55f..012f080f9 100644 --- a/src/server/index.ts +++ b/src/server/index.ts @@ -24,7 +24,7 @@ import { sum } from '../prelude/array'; import User from '../models/user'; import Logger from '../misc/logger'; -const logger = new Logger('server'); +const logger = new Logger('server', 'gray'); // Init app const app = new Koa(); diff --git a/src/services/drive/add-file.ts b/src/services/drive/add-file.ts index a7797351a..190c55afb 100644 --- a/src/services/drive/add-file.ts +++ b/src/services/drive/add-file.ts @@ -24,6 +24,8 @@ import fetchMeta from '../../misc/fetch-meta'; import { GenerateVideoThumbnail } from './generate-video-thumbnail'; import { driveLogger } from './logger'; +const logger = driveLogger.createSubLogger('register', 'yellow'); + /*** * Save file * @param path Path for original @@ -40,7 +42,7 @@ async function save(path: string, name: string, type: string, hash: string, size let webpublicType = 'image/jpeg'; if (!metadata.uri) { // from local instance - driveLogger.info(`creating web image of ${name}`); + logger.info(`creating web image of ${name}`); if (['image/jpeg'].includes(type)) { webpublic = await sharp(path) @@ -81,10 +83,10 @@ async function save(path: string, name: string, type: string, hash: string, size webpublicExt = 'png'; webpublicType = 'image/png'; } else { - driveLogger.info(`web image not created (not an image)`); + logger.info(`web image not created (not an image)`); } } else { - driveLogger.info(`web image not created (from remote)`); + logger.info(`web image not created (from remote)`); } // #endregion webpublic @@ -121,7 +123,7 @@ async function save(path: string, name: string, type: string, hash: string, size try { thumbnail = await GenerateVideoThumbnail(path); } catch (e) { - driveLogger.error(`GenerateVideoThumbnail failed: ${e}`); + logger.error(`GenerateVideoThumbnail failed: ${e}`); } } // #endregion thumbnail @@ -139,18 +141,18 @@ async function save(path: string, name: string, type: string, hash: string, size const webpublicKey = `${config.drive.prefix}/${uuid.v4()}.${webpublicExt}`; const thumbnailKey = `${config.drive.prefix}/${uuid.v4()}.${thumbnailExt}`; - driveLogger.info(`uploading original: ${key}`); + logger.info(`uploading original: ${key}`); const uploads = [ upload(key, fs.createReadStream(path), type) ]; if (webpublic) { - driveLogger.info(`uploading webpublic: ${webpublicKey}`); + logger.info(`uploading webpublic: ${webpublicKey}`); uploads.push(upload(webpublicKey, webpublic, webpublicType)); } if (thumbnail) { - driveLogger.info(`uploading thumbnail: ${thumbnailKey}`); + logger.info(`uploading thumbnail: ${thumbnailKey}`); uploads.push(upload(thumbnailKey, thumbnail, thumbnailType)); } @@ -200,7 +202,7 @@ async function save(path: string, name: string, type: string, hash: string, size fs.createReadStream(path).pipe(writeStream); }); - driveLogger.info(`original stored to ${originalFile._id}`); + logger.info(`original stored to ${originalFile._id}`); // #endregion store original // #region store webpublic @@ -220,7 +222,7 @@ async function save(path: string, name: string, type: string, hash: string, size writeStream.end(webpublic); }); - driveLogger.info(`web stored ${webFile._id}`); + logger.info(`web stored ${webFile._id}`); } // #endregion store webpublic @@ -240,7 +242,7 @@ async function save(path: string, name: string, type: string, hash: string, size writeStream.end(thumbnail); }); - driveLogger.info(`thumbnail stored ${tuhmFile._id}`); + logger.info(`thumbnail stored ${tuhmFile._id}`); } return originalFile; @@ -349,7 +351,7 @@ export default async function( const [hash, [mime, ext], size] = await Promise.all([calcHash, detectMime, getFileSize]); - driveLogger.info(`hash: ${hash}, mime: ${mime}, ext: ${ext}, size: ${size}`); + logger.info(`hash: ${hash}, mime: ${mime}, ext: ${ext}, size: ${size}`); // detect name const detectedName = name || (ext ? `untitled.${ext}` : 'untitled'); @@ -363,7 +365,7 @@ export default async function( }); if (much) { - driveLogger.info(`file with same hash is found: ${much._id}`); + logger.info(`file with same hash is found: ${much._id}`); return much; } } @@ -393,7 +395,7 @@ export default async function( return 0; }); - driveLogger.info(`drive usage is ${usage}`); + logger.info(`drive usage is ${usage}`); const instance = await fetchMeta(); const driveCapacity = 1024 * 1024 * (isLocalUser(user) ? instance.localDriveCapacityMb : instance.remoteDriveCapacityMb); @@ -436,12 +438,12 @@ export default async function( // Calc width and height const calcWh = async () => { - driveLogger.info('calculating image width and height...'); + logger.debug('calculating image width and height...'); // Calculate width and height const meta = await img.metadata(); - driveLogger.info(`image width and height is calculated: ${meta.width}, ${meta.height}`); + logger.debug(`image width and height is calculated: ${meta.width}, ${meta.height}`); properties['width'] = meta.width; properties['height'] = meta.height; @@ -449,7 +451,7 @@ export default async function( // Calc average color const calcAvg = async () => { - driveLogger.info('calculating average color...'); + logger.debug('calculating average color...'); try { const info = await (img as any).stats(); @@ -458,7 +460,7 @@ export default async function( const g = Math.round(info.channels[1].mean); const b = Math.round(info.channels[2].mean); - driveLogger.info(`average color is calculated: ${r}, ${g}, ${b}`); + logger.debug(`average color is calculated: ${r}, ${g}, ${b}`); const value = info.isOpaque ? [r, g, b] : [r, g, b, 255]; @@ -514,14 +516,14 @@ export default async function( } catch (e) { // duplicate key error (when already registered) if (e.code === 11000) { - driveLogger.info(`already registered ${metadata.uri}`); + logger.info(`already registered ${metadata.uri}`); driveFile = await DriveFile.findOne({ 'metadata.uri': metadata.uri, 'metadata.userId': user._id }); } else { - driveLogger.error(e); + logger.error(e); throw e; } } @@ -529,7 +531,7 @@ export default async function( driveFile = await (save(path, detectedName, mime, hash, size, metadata)); } - driveLogger.succ(`drive file has been created ${driveFile._id}`); + logger.succ(`drive file has been created ${driveFile._id}`); pack(driveFile).then(packedFile => { // Publish driveFileCreated event diff --git a/src/services/drive/upload-from-url.ts b/src/services/drive/upload-from-url.ts index ac1b04f5b..3d2269d91 100644 --- a/src/services/drive/upload-from-url.ts +++ b/src/services/drive/upload-from-url.ts @@ -1,7 +1,5 @@ import * as fs from 'fs'; import * as URL from 'url'; - -import * as debug from 'debug'; import * as tmp from 'tmp'; import * as request from 'request'; @@ -10,8 +8,9 @@ import create from './add-file'; import config from '../../config'; import { IUser } from '../../models/user'; import * as mongodb from 'mongodb'; +import { driveLogger } from './logger'; -const log = debug('misskey:drive:upload-from-url'); +const logger = driveLogger.createSubLogger('downloader'); export default async ( url: string, @@ -22,14 +21,14 @@ export default async ( force = false, link = false ): Promise => { - log(`REQUESTED: ${url}`); + logger.info(`REQUESTED: ${url}`); let name = URL.parse(url).pathname.split('/').pop(); if (!validateFileName(name)) { name = null; } - log(`name: ${name}`); + logger.info(`name: ${name}`); // Create temp file const [path, cleanup] = await new Promise<[string, any]>((res, rej) => { @@ -82,10 +81,10 @@ export default async ( try { driveFile = await create(user, path, name, null, folderId, force, link, url, uri, sensitive); - log(`got: ${driveFile._id}`); + logger.succ(`got: ${driveFile._id}`); } catch (e) { error = e; - log(`failed: ${e}`); + logger.error(`failed: ${e}`); } // clean-up diff --git a/src/tools/add-emoji.ts b/src/tools/add-emoji.ts index e40c96b79..2aa99e37a 100644 --- a/src/tools/add-emoji.ts +++ b/src/tools/add-emoji.ts @@ -1,8 +1,5 @@ -import * as debug from 'debug'; import Emoji from '../models/emoji'; -debug.enable('*'); - async function main(name: string, url: string, alias?: string): Promise { const aliases = alias != null ? [ alias ] : []; diff --git a/src/tools/resync-remote-user.ts b/src/tools/resync-remote-user.ts index 4850c768a..7db5fe82e 100644 --- a/src/tools/resync-remote-user.ts +++ b/src/tools/resync-remote-user.ts @@ -1,8 +1,5 @@ import parseAcct from '../misc/acct/parse'; import resolveUser from '../remote/resolve-user'; -import * as debug from 'debug'; - -debug.enable('*'); async function main(acct: string): Promise { const { username, host } = parseAcct(acct);