Merge pull request #34 from SukkaW/fancy-log

refactor: completely rewrite the logger

Author: SukkaW

.travis.yml

@@ -8,9 +8,9 @@ cache:
     - node_modules
 
 node_js:
-  - "8"
   - "10"
-  - "node"
+  - "12"
+  - "14"
 
 script:
   - npm run eslint

README.md

@@ -4,7 +4,7 @@
 [![NPM version](https://badge.fury.io/js/hexo-log.svg)](https://www.npmjs.com/package/hexo-log)
 [![Coverage Status](https://coveralls.io/repos/hexojs/hexo-log/badge.svg?branch=master)](https://coveralls.io/r/hexojs/hexo-log?branch=master)
 
-Logger for Hexo, based on [bunyan] with better console output.
+Logger for Hexo.
 
 ## Installation
 
@@ -15,22 +15,19 @@ $ npm install hexo-log --save
 ## Usage
 
 ``` js
-var log = require('hexo-log')({
+const log = require('hexo-log')({
   debug: false,
   silent: false
-});
+})
 
 log.info('Hello world');
 ```
 
 Option | Description | Default
 --- | --- | ---
-`debug` | Display debug message and save log to `debug.log` file. | `false`
-`silent` | Don't display message in console. | `false`
-`name` | Name | `hexo`
+`debug` | Display debug message. | `false`
+`silent` | Don't display any message in console. | `false`
 
 ## License
 
 MIT
-
-[bunyan]: https://github.com/trentm/node-bunyan

lib/log.js

@@ -1,10 +1,16 @@
 'use strict';
 
-const bunyan = require('hexo-bunyan');
+const { Console } = require('console');
 const chalk = require('chalk');
-const Writable = require('stream').Writable;
 
-const levelNames = {
+const TRACE = 10;
+const DEBUG = 20;
+const INFO = 30;
+const WARN = 40;
+const ERROR = 50;
+const FATAL = 60;
+
+const LEVEL_NAMES = {
   10: 'TRACE',
   20: 'DEBUG',
   30: 'INFO ',
@@ -13,7 +19,7 @@ const levelNames = {
   60: 'FATAL'
 };
 
-const levelColors = {
+const LEVEL_COLORS = {
   10: 'gray',
   20: 'gray',
   30: 'green',
@@ -22,77 +28,89 @@ const levelColors = {
   60: 'bgRed'
 };
 
-function ConsoleStream(env) {
-  Writable.call(this, {objectMode: true});
+const console = new Console({
+  stdout: process.stdout,
+  stderr: process.stderr,
+  colorMode: false
+});
 
-  this.debug = env.debug;
-}
+class Logger {
+  constructor(options = {}) {
+    const silent = options.silent || false;
+    this._debug = options.debug || false;
 
-require('util').inherits(ConsoleStream, Writable);
+    this.level = INFO;
 
-ConsoleStream.prototype._write = function(data, enc, callback) {
-  const level = data.level;
-  let msg = '';
+    if (silent) {
+      this.level = FATAL + 10;
+    }
 
-  // Time
-  if (this.debug) {
-    msg += chalk.gray(formatTime(data.time)) + ' ';
+    if (this._debug) {
+      this.level = TRACE;
+    }
   }
 
-  // Level
-  msg += chalk[levelColors[level]](levelNames[level]) + ' ';
+  _writeLogOutput(level, consoleArgs) {
+    if (this._debug) {
+      const str = new Date().toISOString().substring(11, 23) + ' ';
 
-  // Message
-  msg += data.msg + '\n';
+      if (level === TRACE || level >= WARN) {
+        process.stderr.write(chalk[LEVEL_COLORS[DEBUG]](str));
+      } else {
+        process.stdout.write(chalk[LEVEL_COLORS[DEBUG]](str));
+      }
+    }
 
-  // Error
-  if (data.err) {
-    const err = data.err.stack || data.err.message;
-    if (err) msg += chalk.yellow(err) + '\n';
+    if (level >= this.level) {
+      const str = chalk[LEVEL_COLORS[level]](LEVEL_NAMES[level]) + ' ';
+      if (level === TRACE || level >= WARN) {
+        process.stderr.write(str);
+      } else {
+        process.stdout.write(str);
+      }
+
+      if (level === TRACE) {
+        console.trace(...consoleArgs);
+      } else if (level < INFO) {
+        console.debug(...consoleArgs);
+      } else if (level < WARN) {
+        console.info(...consoleArgs);
+      } else if (level < ERROR) {
+        console.warn(...consoleArgs);
+      } else {
+        console.error(...consoleArgs);
+      }
+    }
   }
 
-  if (level >= 40) {
-    process.stderr.write(msg);
-  } else {
-    process.stdout.write(msg);
+  trace(...args) {
+    this._writeLogOutput(TRACE, args);
   }
 
-  callback();
-};
-
-function formatTime(date) {
-  return date.toISOString().substring(11, 23);
-}
+  debug(...args) {
+    this._writeLogOutput(DEBUG, args);
+  }
 
-function createLogger(options) {
-  options = options || {};
+  info(...args) {
+    this._writeLogOutput(INFO, args);
+  }
 
-  const streams = [];
+  warn(...args) {
+    this._writeLogOutput(WARN, args);
+  }
 
-  if (!options.silent) {
-    streams.push({
-      type: 'raw',
-      level: options.debug ? 'trace' : 'info',
-      stream: new ConsoleStream(options)
-    });
+  error(...args) {
+    this._writeLogOutput(ERROR, args);
   }
 
-  if (options.debug) {
-    streams.push({
-      level: 'trace',
-      path: 'debug.log'
-    });
+  fatal(...args) {
+    this._writeLogOutput(FATAL, args);
   }
+}
 
-  const logger = bunyan.createLogger({
-    name: options.name || 'hexo',
-    streams,
-    serializers: {
-      err: bunyan.stdSerializers.err
-    }
-  });
+function createLogger(options) {
+  const logger = new Logger(options);
 
-  // Alias for logger levels
   logger.d = logger.debug;
   logger.i = logger.info;
   logger.w = logger.warn;

package.json

@@ -29,7 +29,6 @@
   ],
   "license": "MIT",
   "dependencies": {
-    "hexo-bunyan": "^2.0.0",
     "chalk": "^3.0.0"
   },
   "devDependencies": {
@@ -43,6 +42,6 @@
     "sinon": "^8.0.1"
   },
   "engines": {
-    "node": ">=8.6.0"
+    "node": ">=10.13.0"
   }
 }

test/index.js

@@ -1,12 +1,37 @@
 'use strict';
 
-const should = require('chai').should(); // eslint-disable-line
+require('chai').should();
 const rewire = require('rewire');
 const sinon = require('sinon');
 
+const noop = () => {};
+const fakeConsole = {
+  trace: noop,
+  debug: noop,
+  info: noop,
+  warn: noop,
+  error: noop
+};
+const fakeProcess = {
+  process: {
+    stderr: {
+      write: noop
+    },
+    stdout: {
+      write: noop
+    }
+  }
+};
+
+const logger = require('../lib/log');
+
 describe('hexo-log', () => {
-  const logger = require('../lib/log');
-  const loggerModule = rewire('../lib/log');
+  let loggerModule;
+
+  beforeEach(() => {
+    sinon.restore();
+    loggerModule = rewire('../lib/log');
+  });
 
   it('add alias for levels', () => {
     const log = logger();
@@ -18,70 +43,305 @@ describe('hexo-log', () => {
     log.log.should.eql(log.info);
   });
 
-  it('default name is hexo', () => {
-    const log = logger();
+  it('trace - should call console.trace', () => {
+    const spy = sinon.spy();
+    loggerModule.__set__('console.trace', spy);
+
+    loggerModule.__with__(fakeProcess)(() => {
+      const log = loggerModule({ debug: true });
+      log.trace('test');
+    });
 
-    log.fields.name.should.eql('hexo');
+    spy.called.should.be.true;
   });
 
-  it('options.name', () => {
-    const log = logger({ name: 'foo' });
+  it('trace - with stderr and no stdout', () => {
+    const stdoutSpy = sinon.spy();
+    const stderrSpy = sinon.spy();
 
-    log.fields.name.should.eql('foo');
-  });
+    loggerModule.__set__('console', fakeConsole);
 
-  it('level should be trace if options.debug is true', () => {
-    const log = logger({ debug: true });
+    loggerModule.__with__({
+      process: {
+        stderr: {
+          write: stderrSpy
+        },
+        stdout: {
+          write: stdoutSpy
+        }
+      }
+    })(() => {
+      const log = loggerModule({ debug: true });
+      log.trace('test');
+    });
 
-    log.streams[0].level.should.eql(10);
+    stderrSpy.called.should.be.true;
+    stdoutSpy.called.should.be.false;
   });
 
-  it('should add file stream if options.debug is true', () => {
-    const log = logger({ debug: true });
+  it('debug - should call console.debug', () => {
+    const spy = sinon.spy();
+    loggerModule.__set__('console.debug', spy);
+
+    loggerModule.__with__(fakeProcess)(() => {
+      const log = loggerModule({ debug: true });
+      log.debug('test');
+    });
 
-    log.streams[1].path.should.eql('debug.log');
+    spy.called.should.be.true;
   });
 
-  it('should remove console stream if options.silent is true', () => {
-    const log = logger({ silent: true });
+  it('debug - with stdout and no stderr', () => {
+    const stdoutSpy = sinon.spy();
+    const stderrSpy = sinon.spy();
 
-    log.streams.length.should.eql(0);
+    loggerModule.__set__('console', fakeConsole);
+
+    loggerModule.__with__({
+      process: {
+        stderr: {
+          write: stderrSpy
+        },
+        stdout: {
+          write: stdoutSpy
+        }
+      }
+    })(() => {
+      const log = loggerModule({ debug: true });
+      log.debug('test');
+    });
+
+    stderrSpy.called.should.be.false;
+    stdoutSpy.called.should.be.true;
   });
 
-  it('should display time if options.debug is true', () => {
+  it('info - should call console.info', () => {
     const spy = sinon.spy();
-    const now = new Date();
+    loggerModule.__set__('console.info', spy);
+
+    loggerModule.__with__(fakeProcess)(() => {
+      const log = loggerModule({ debug: true });
+      log.info('test');
+    });
+
+    spy.called.should.be.true;
+  });
+
+  it('info - with stdout and no stderr', () => {
+    const stdoutSpy = sinon.spy();
+    const stderrSpy = sinon.spy();
+
+    loggerModule.__set__('console', fakeConsole);
 
     loggerModule.__with__({
       process: {
+        stderr: {
+          write: stderrSpy
+        },
         stdout: {
-          write: spy
+          write: stdoutSpy
         }
       }
     })(() => {
-      sinon.useFakeTimers(now.valueOf());
       const log = loggerModule({ debug: true });
       log.info('test');
-      sinon.restore();
     });
 
-    spy.args[0][0].should.contain(now.toISOString().substring(11, 23));
+    stderrSpy.called.should.be.false;
+    stdoutSpy.called.should.be.true;
+  });
+
+  it('warn - should call console.warn', () => {
+    const spy = sinon.spy();
+    loggerModule.__set__('console.warn', spy);
+
+    loggerModule.__with__(fakeProcess)(() => {
+      const log = loggerModule({ debug: true });
+      log.warn('test');
+    });
+
+    spy.called.should.be.true;
+  });
+
+  it('warn - with stderr and no stdout', () => {
+    const stdoutSpy = sinon.spy();
+    const stderrSpy = sinon.spy();
+
+    loggerModule.__set__('console', fakeConsole);
+
+    loggerModule.__with__({
+      process: {
+        stderr: {
+          write: stderrSpy
+        },
+        stdout: {
+          write: stdoutSpy
+        }
+      }
+    })(() => {
+      const log = loggerModule({ debug: true });
+      log.warn('test');
+    });
+
+    stderrSpy.called.should.be.true;
+    stdoutSpy.called.should.be.false;
+  });
+
+  it('error - should call console.error', () => {
+    const spy = sinon.spy();
+    loggerModule.__set__('console.error', spy);
+
+    loggerModule.__with__(fakeProcess)(() => {
+      const log = loggerModule({ debug: true });
+      log.error('test');
+    });
+
+    spy.called.should.be.true;
   });
 
-  it('should print error to process.stderr stream', () => {
+  it('error - with stderr and no stdout', () => {
+    const stdoutSpy = sinon.spy();
+    const stderrSpy = sinon.spy();
+
+    loggerModule.__set__('console', fakeConsole);
+
+    loggerModule.__with__({
+      process: {
+        stderr: {
+          write: stderrSpy
+        },
+        stdout: {
+          write: stdoutSpy
+        }
+      }
+    })(() => {
+      const log = loggerModule({ debug: true });
+      log.error('test');
+    });
+
+    stderrSpy.called.should.be.true;
+    stdoutSpy.called.should.be.false;
+  });
+
+  it('fatal - should call console.error', () => {
     const spy = sinon.spy();
+    loggerModule.__set__('console.error', spy);
+
+    loggerModule.__with__(fakeProcess)(() => {
+      const log = loggerModule({ debug: true });
+      log.fatal('test');
+    });
+
+    spy.called.should.be.true;
+  });
+
+  it('fatal - with stderr and no stdout', () => {
+    const stdoutSpy = sinon.spy();
+    const stderrSpy = sinon.spy();
+
+    loggerModule.__set__('console', fakeConsole);
 
     loggerModule.__with__({
       process: {
         stderr: {
+          write: stderrSpy
+        },
+        stdout: {
+          write: stdoutSpy
+        }
+      }
+    })(() => {
+      const log = loggerModule({ debug: true });
+      log.fatal('test');
+    });
+
+    stderrSpy.called.should.be.true;
+    stdoutSpy.called.should.be.false;
+  });
+
+  it('options.debug - should display time', () => {
+    const spy = sinon.spy();
+    const now = new Date();
+
+    loggerModule.__set__('console', fakeConsole);
+
+    loggerModule.__with__({
+      process: {
+        stdout: {
           write: spy
         }
       }
     })(() => {
-      const log = loggerModule();
+      sinon.useFakeTimers(now.valueOf());
+      const log = loggerModule({ debug: true });
+      log.info('test');
+      sinon.restore();
+    });
+
+    spy.args[0][0].should.contain(now.toISOString().substring(11, 23));
+  });
+
+  it('options.silent - should not display anything', () => {
+    const consoleTraceSpy = sinon.spy();
+    const consoleDebugSpy = sinon.spy();
+    const consoleInfoSpy = sinon.spy();
+    const consoleWarnSpy = sinon.spy();
+    const consoleErrorSpy = sinon.spy();
+
+    loggerModule.__set__('console.trace', consoleTraceSpy);
+    loggerModule.__set__('console.debug', consoleDebugSpy);
+    loggerModule.__set__('console.info', consoleInfoSpy);
+    loggerModule.__set__('console.warn', consoleWarnSpy);
+    loggerModule.__set__('console.error', consoleErrorSpy);
+
+    loggerModule.__with__(fakeProcess)(() => {
+      const log = loggerModule({ silent: true });
+      log.trace('test');
+      log.debug('test');
+      log.info('test');
+      log.warn('test');
       log.error('test');
+      log.fatal('test');
     });
 
-    spy.calledOnce.should.be.true;
+    consoleTraceSpy.called.should.be.false;
+    consoleDebugSpy.called.should.be.false;
+    consoleInfoSpy.called.should.be.false;
+    consoleWarnSpy.calledOnce.should.be.false;
+    consoleErrorSpy.calledTwice.should.be.false;
+  });
+});
+
+describe('hexo-log example', () => {
+  const log = logger({ debug: true });
+  const log2 = logger();
+  it('log.trace()', () => {
+    log.trace('Hello, World!');
+    log2.trace('Hello, World!');
+  });
+
+  it('log.debug()', () => {
+    log.debug('Hello, World!');
+    log2.debug('Hello, World!');
+  });
+
+  it('log.info()', () => {
+    log.info('Hello, World!');
+    log2.info('Hello, World!');
+  });
+
+  it('log.warn()', () => {
+    log.warn('Hello, World!');
+    log2.warn('Hello, World!');
+  });
+
+  it('log.error()', () => {
+    log.error('Hello, World!');
+    log2.error('Hello, World!');
+  });
+
+  it('log.fatal()', () => {
+    log.fatal('Hello, World!');
+    log2.fatal('Hello, World!');
   });
 });