Better logging

11 files changed, 62 insertions, 68 deletions

diff --git a/src/index.ts b/src/index.ts
index d023ed58da..a42eec1a6f 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 5440edab74..8fbff9638d 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 ae353f5efc..ef0b24e890 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<IDriv
 		throw new Error('invalid image: url not privided');
 	}
 
-	log(`Creating the Image: ${image.url}`);
+	logger.info(`Creating the Image: ${image.url}`);
 
 	const instance = await fetchMeta();
 	const cache = instance.cacheRemoteFiles;
diff --git a/src/remote/activitypub/models/note.ts b/src/remote/activitypub/models/note.ts
index 1b61435aa2..790f2f9590 100644
--- a/src/remote/activitypub/models/note.ts
+++ b/src/remote/activitypub/models/note.ts
@@ -1,5 +1,4 @@
 import * as mongo from 'mongodb';
-import * as debug from 'debug';
 
 import config from '../../../config';
 import Resolver from '../resolver';
@@ -16,8 +15,9 @@ import { toUnicode } from 'punycode';
 import { unique, concat, difference } from '../../../prelude/array';
 import { extractPollFromQuestion } from './question';
 import vote from '../../../services/note/polls/vote';
+import { apLogger } from '../logger';
 
-const log = debug('misskey:activitypub');
+const logger = apLogger;
 
 /**
  * Noteをフェッチします。
@@ -53,13 +53,13 @@ export async function createNote(value: any, resolver?: Resolver, silent = false
 	const object = await resolver.resolve(value) as any;
 
 	if (object == null || object.type !== 'Note') {
-		log(`invalid note: ${object}`);
+		logger.error(`invalid note: ${object}`);
 		return null;
 	}
 
 	const note: INoteActivityStreamsObject = object;
 
-	log(`Creating the Note: ${note.id}`);
+	logger.info(`Creating the Note: ${note.id}`);
 
 	// 投稿者をフェッチ
 	const actor = await resolvePerson(note.attributedTo, null, resolver) as IRemoteUser;
@@ -116,14 +116,14 @@ export async function createNote(value: any, resolver?: Resolver, silent = false
 	if (reply && reply.poll && text != null) {
 		const m = text.match(/([0-9])$/);
 		if (m) {
-			log(`vote from AP: actor=${actor.username}@${actor.host}, note=${note.id}, choice=${m[0]}`);
+			logger.info(`vote from AP: actor=${actor.username}@${actor.host}, note=${note.id}, choice=${m[0]}`);
 			await vote(actor, reply, Number(m[1]));
 			return null;
 		}
 	}
 
 	const emojis = await extractEmojis(note.tag, actor.host).catch(e => {
-		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 16f1086b86..a4173c5e82 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<IU
 
 	const person: IPerson = object;
 
-	log(`Creating the Person: ${person.id}`);
+	logger.info(`Creating the Person: ${person.id}`);
 
 	const [followersCount = 0, followingCount = 0, notesCount = 0] = await Promise.all([
 		resolver.resolve(person.followers).then(
@@ -183,7 +183,7 @@ export async function createPerson(uri: string, resolver?: Resolver): Promise<IU
 			throw new Error('already registered');
 		}
 
-		console.error(e);
+		logger.error(e);
 		throw e;
 	}
 
@@ -247,7 +247,7 @@ export async function createPerson(uri: string, resolver?: Resolver): Promise<IU
 
 	//#region カスタム絵文字取得
 	const emojis = await extractEmojis(person.tag, host).catch(e => {
-		console.log(`extractEmojis: ${e}`);
+		logger.info(`extractEmojis: ${e}`);
 		return [] as IEmoji[];
 	});
 
@@ -260,7 +260,7 @@ export async function createPerson(uri: string, resolver?: Resolver): Promise<IU
 	});
 	//#endregion
 
-	await updateFeatured(user._id).catch(err => 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 192aa19770..f5c326f7d1 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 edb78f55f7..012f080f98 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 a7797351ae..190c55afb3 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 ac1b04f5b5..3d2269d917 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<IDriveFile> => {
-	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 e40c96b79d..2aa99e37ae 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<any> {
 	const aliases = alias != null ? [ alias ] : [];
 
diff --git a/src/tools/resync-remote-user.ts b/src/tools/resync-remote-user.ts
index 4850c768a0..7db5fe82ef 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<any> {
 	const { username, host } = parseAcct(acct);