lalog - npm Package Compare versions

Comparing version 0.5.0 to 0.6.0

CHANGELOG.md

 # Changelog
 
+### 0.6.0
+
+- Add transient logging feature.
+
 ### 0.5.0
@@ -4,0 +8,0 @@

lib/index.js

 const isObject = require('lodash/isObject');
 const debug = require('debug');
 const uuid = require('uuid');
-const loggly = require('./loggly-wrapper');
 
+const {
+  logBatch,
+  logSingle,
+} = require('./loggly-wrapper');
+
+/**
+ * @type {Array<import('../typings').LevelEnum>}
+ */
 const levels = ['trace', 'info', 'warn', 'error', 'fatal', 'security'];
@@ -10,5 +17,7 @@ const errorLevel = levels.indexOf('error');
 const getInitialLogLevel = () => {
-  const { LALOG_LEVEL } = process.env;
-  if (LALOG_LEVEL && levels.includes(LALOG_LEVEL)) {
-    return levels.indexOf(LALOG_LEVEL);
+  /** @type {import('../typings').LevelEnum} */
+  // @ts-ignore Type 'string' is not assignable to type 'LevelEnum'
+  const laLogLevel = process.env.LALOG_LEVEL;
+  if (levels.includes(laLogLevel)) {
+    return levels.indexOf(laLogLevel);
   }
@@ -20,8 +29,26 @@ return levels.indexOf('error');
 
+/**
+ * @type {import('../typings').Logger}
+ */
 class Logger {
+  /**
+   * Create an instance of Logger
+   * @param {import('../typings').LogOptions} options
+   */
   constructor(options) {
     const {
-      serviceName, moduleName, presets, addTrackId,
+      addTrackId,
+      moduleName,
+      presets,
+      serviceName,
+      isTransient,
     } = options;
 
+    this.isTransient = !!isTransient;
+
+    /**
+     * @type {Array|null}
+     */
+    this.logCollector = isTransient ? [] : null;
+
     this.presets = Object.assign(
@@ -44,7 +71,23 @@ { module: moduleName },
 
-    levels.forEach((level, index) => {
-      this[level] = this.write.bind(this, index);
-      this.timeEnd[level] = this.writeTimeEnd.bind(this, index);
-    });
+    // Listed like this so that Typescript can type each log level.
+    // Previously this was setup using a loop but Typescript couldn't type it
+    this.trace = this.write.bind(this, levels.indexOf('trace'));
+    this.info = this.write.bind(this, levels.indexOf('info'));
+    this.warn = this.write.bind(this, levels.indexOf('warn'));
+    this.error = this.write.bind(this, levels.indexOf('error'));
+    this.fatal = this.write.bind(this, levels.indexOf('fatal'));
+    this.security = this.write.bind(this, levels.indexOf('security'));
+
+    this.timeEnd.trace = this.writeTimeEnd.bind(this, levels.indexOf('trace'));
+    this.timeEnd.info = this.writeTimeEnd.bind(this, levels.indexOf('info'));
+    this.timeEnd.warn = this.writeTimeEnd.bind(this, levels.indexOf('warn'));
+    this.timeEnd.error = this.writeTimeEnd.bind(this, levels.indexOf('error'));
+    this.timeEnd.fatal = this.writeTimeEnd.bind(this, levels.indexOf('fatal'));
+    this.timeEnd.security = this.writeTimeEnd.bind(this, levels.indexOf('security'));
+
     this.timers = {};
+    /**
+     * Start a timer log - same as console.time()
+     * @param {string} label - label to use when calling timeEnd()
+     */
     this.time = (label) => {
@@ -55,2 +98,9 @@ this.timers[label] = Date.now();
 
+  /**
+    * Create an instance of Logger
+    * @static
+    * @param {import('../typings').LogOptions} options
+    * @returns {import('../typings').Logger}
+    * @memberof Logger
+    */
   static create(options) {
@@ -60,2 +110,8 @@ return new Logger(options);
 
+  /**
+   * Get an array of all available log levels
+   * @static
+   * @returns {Array<import('../typings').LevelEnum>}
+   * @memberof Logger
+   */
   static allLevels() {
@@ -65,2 +121,8 @@ return levels;
 
+  /**
+   * Get the current log level
+   * @static
+   * @returns {import('../typings').LevelEnum}
+   * @memberof Logger
+   */
   static getLevel() {
@@ -70,2 +132,9 @@ return levels[currentLevelIndex];
 
+  /**
+   * Change the minimum level to write logs
+   * @static
+   * @param {import('../typings').LevelEnum} newLevelName
+   * @returns {import('../typings').LevelEnum}
+   * @memberof Logger
+   */
   static setLevel(newLevelName) {
@@ -80,2 +149,9 @@ const previousLevel = Logger.getLevel();
 
+  /**
+   * Parse the Express request (req) object for logging
+   * @static
+   * @param {Object} req
+   * @returns {Object}
+   * @memberof Logger
+   */
   static parseReq(req) {
@@ -94,4 +170,11 @@ return {
 
+  /**
+   * Format milliseconds to a string for logging
+   * @static
+   * @param {number} milliseconds
+   * @returns {string}
+   * @memberof Logger
+   */
   static formatMilliseconds(milliseconds) {
-    const date = new Date(null);
+    const date = new Date(0);
     date.setMilliseconds(milliseconds);
@@ -101,2 +184,10 @@ return date.toISOString().substr(11, 12);
 
+  /**
+   * [Private] Write the timer label end
+   * @param {number} levelIndex
+   * @param {string} label
+   * @param {object} [extraLogData={}]
+   * @returns {Promise}
+   * @memberof Logger
+   */
   writeTimeEnd(levelIndex, label, extraLogData = {}) {
@@ -120,9 +211,10 @@ const time = this.timers[label];
   /**
-   * Log to Loggly or other destination
-   * @param {Number} levelIndex - severity of error
-   * @param {Object} logObj - the object to log
-   * @param {Object} response - the Express response object and status to send a canned error
-   * @returns {Promise} - a promise
+   * Write log to destination
+   * @param {number} levelIndex
+   * @param {object} logData
+   * @param {object=} response
+   * @returns {Promise}
+   * @memberof Logger
    */
-  write(levelIndex, logData, response) {
+  async write(levelIndex, logData, response) {
     if (!isObject(logData)) {
@@ -134,2 +226,5 @@ // eslint-disable-next-line no-console
 
+    /**
+     * @type {object}
+     */
     const logObj = Object.assign({}, this.presets, logData);
@@ -149,3 +244,17 @@
 
-    if (levelIndex >= currentLevelIndex) {
+    // When do we log?
+    // - If !isTransient and levelIndex >= currentLevelIndex
+    //   - normal logging - current logic
+    // - If isTransient and levelIndex < currentLevelIndex
+    //   - push this log item onto the array
+    // - If isTransient and levelIndex >= currentLevelIndex and !isTransientTriggered
+    //   - set isTransientTriggered to true
+    //   - push this log item onto the array
+    //   - bulk log everything in array
+    //   - empty array (for early GC)
+    // - If isTransientTriggered
+    //   - log everything
+
+
+    if (levelIndex >= currentLevelIndex || this.isTransient) {
       logObj.level = levels[levelIndex];
@@ -163,3 +272,8 @@
         logObj.fullStack = logObj.err.stack.split('\n').slice(1);
-        logObj.shortStack = logObj.fullStack.filter(i => !i.includes('/node_modules/'));
+        /**
+         * Checks if string includes node_modules
+         * @param {string} i
+         */
+        const hasNodeModules = i => !i.includes('/node_modules/');
+        logObj.shortStack = logObj.fullStack.filter(hasNodeModules);
         if (!logObj.msg) {
@@ -175,4 +289,14 @@ logObj.msg = logObj.err.message;
 
-      this.debug(logObj);
-      return loggly({ tag: this.tag, logObj });
+      if (this.logCollector !== null && !this.isTransientTriggered) {
+        this.logCollector.push(logObj);
+        if (levelIndex >= currentLevelIndex) {
+          // Need to batch log here
+          this.isTransientTriggered = true;
+          await logBatch({ tag: this.tag, logObj: this.logCollector });
+          this.logCollector = null; // Can GC right away now that this array is no longer needed
+        }
+      } else {
+        this.debug(logObj);
+        return logSingle({ tag: this.tag, logObj });
+      }
     }
@@ -179,0 +303,0 @@ return Promise.resolve();

lib/loggly-wrapper.js

@@ -1,15 +0,33 @@
-
+const _ = require('lodash');
 const fetch = require('node-fetch');
 
-module.exports = async (options) => {
+/**
+ * Write log to Loggly
+ * @param {object} options
+ * @param {string} options.tag
+ * @param {string=} options.logglyToken
+ * @param {string} options.logObj
+ * @param {boolean} bulk
+ */
+const log = async (options, bulk) => {
   const {
     tag,
     logglyToken = process.env.LOGGLY_TOKEN,
-    logObj,
+    logObj: body,
   } = options;
+
+
+  const pathPart = bulk ? 'bulk' : 'inputs';
+
   if (logglyToken) {
-    let url;
-    let fetchOptions;
+    /**
+     * @type {string}
+     */
+    let url = '';
+    /**
+     * @type {import('node-fetch').RequestInit}
+     */
+    let fetchOptions = {};
     try {
-      url = `https://logs-01.loggly.com/inputs/${logglyToken}/tag/${tag}/`;
+      url = `https://logs-01.loggly.com/${pathPart}/${logglyToken}/tag/${tag}/`;
       fetchOptions = {
@@ -21,5 +39,11 @@ headers: {
         method: 'POST',
-        body: JSON.stringify(logObj),
+        body,
       };
 
+      /**
+       * @type {import('node-fetch').Response}
+       */
+      // @ts-ignore Cannot invoke an expression whose type lacks a call signature...
+      // ts-ignore seems to be needed because of a bug in the node-fetch typing file.
+      // Try and remove the ignore if this typing file is updated
       const result = await fetch(url, fetchOptions);
@@ -48,1 +72,52 @@
 };
+
+/**
+ * Log a single log object
+ * @param {object} options
+ * @param {string} options.tag
+ * @param {string=} options.logglyToken
+ * @param {object} options.logObj
+ */
+const logSingle = (options) => {
+  const { logObj } = options;
+  if (!_.isObject(logObj)) {
+    // eslint-disable-next-line no-console
+    console.error(`Expected an Object in logSingle but got ${typeof logObj}`);
+    return Promise.resolve();
+  }
+
+  const body = JSON.stringify(logObj);
+  return log({
+    ...options,
+    logObj: body,
+  }, false);
+};
+
+/**
+ * Log an array of logs
+ * @param {object} options
+ * @param {string} options.tag
+ * @param {string=} options.logglyToken
+ * @param {Array<object>} options.logObj
+ */
+const logBatch = async (options) => {
+  const { logObj } = options;
+  if (!_.isArray(logObj)) {
+    // eslint-disable-next-line no-console
+    console.error(`Expected an Array in logBatch but got ${typeof logObj}`);
+    return Promise.resolve();
+  }
+
+  // https://stackoverflow.com/questions/52248377/typescript-array-map-with-json-stringify-produces-error
+  // @ts-ignore - no idea why typescript can't handle this .map()
+  const body = logObj.map(JSON.stringify).join('\n');
+  return log({
+    ...options,
+    logObj: body,
+  }, true);
+};
+
+module.exports = {
+  logBatch,
+  logSingle,
+};

package.json

@@ -9,3 +9,3 @@ {
     "lodash": "4.17.10",
-    "node-fetch": "2.1.2",
+    "node-fetch": "2.2.0",
     "uuid": "3.3.2"
@@ -15,9 +15,14 @@ },
   "devDependencies": {
+    "@types/debug": "0.0.30",
+    "@types/lodash": "4.14.116",
+    "@types/node-fetch": "2.1.2",
+    "@types/uuid": "3.4.4",
     "eslint": "4.19.1",
     "eslint-config-airbnb-base": "13.0.0",
     "eslint-plugin-import": "2.13.0",
-    "eslint-plugin-jest": "21.17.0",
+    "eslint-plugin-jest": "21.22.0",
     "eslint-plugin-security": "1.4.0",
     "jest": "23.2.0",
-    "pre-commit": "1.2.2"
+    "pre-commit": "1.2.2",
+    "typescript": "3.0.3"
   },
@@ -38,4 +43,3 @@ "engines": {
     "run": [
-      "lint",
-      "coverage"
+      "test"
     ],
@@ -53,5 +57,5 @@ "silent": false
     "lintfix": "eslint --ext .js . --fix",
-    "test": "npm run lint && npm run coverage"
+    "test": "npm run lint && npm run coverage && tsc"
   },
-  "version": "0.5.0"
+  "version": "0.6.0"
 }

README.md

@@ -65,4 +65,5 @@ # lalog
   moduleName: 'module-name',
-  presets: {}, // optional
-  addTrackId: true, // options
+  presets: {}, // optional - defaults to empty object if missing or not a valid object
+  addTrackId: true, // optional - defaults to false
+  isTransient: true, // optional - defaults to false
 });
@@ -79,2 +80,18 @@ ```
 - The `moduleName` is added to `presets` as `module`.
+- If `isTransient` is set to true then all calls to logger will be saved and written in batch mode, in
+sequence, to the destination if any of the log calls triggers a write. This flag is called `isTransient`
+because typically you will only use it for short lived transient loggers. The typical use case is when
+you attach a logger to the `req`/`request` object in a web request. You would then probably call the
+logger with trace, info and warn calls that would not be written if your level is set to `error`. If
+`error()` is called you would also want all the previous logs to be written so that you can see what
+happened before the `error()` was called. The `isTransient` flag causes the logger to store all of 
+those logs and write then in this scenario.
+  - More notes on `isTransient`
+  - You would almost always want to also set `trackId` to `true` when you set `isTransient` to `true`
+  so that you can easily find/filter the associated log messages.
+  - You don't want to use this for long lived loggers as they may accumulate too many logs (local
+  memory issues) and if the log messages are too big then they may error when writing to the
+  destination.
+  - Possible future feature is to provide a maximum number of log messages to
+  accumulate if `isTransient` is set.
 
@@ -81,0 +98,0 @@ ### Write Log Messages

test/lib/index.test.js

@@ -43,3 +43,6 @@ const Logger = require('../../lib');
   test('should create all log level methods with .create()', () => {
-    const localLogger = Logger.create('mock-service', 'mock-module');
+    const localLogger = Logger.create({
+      serviceName: 'mock-service',
+      moduleName: 'mock-module',
+    });
     ['trace', 'info', 'warn', 'error', 'fatal', 'security'].forEach((level) => {
@@ -46,0 +49,0 @@ expect(typeof localLogger[level]).toBe('function');

test/lib/loggly-wrapper.test.js

 /* eslint-disable no-console */
 
-process.env.LOGGLY_TOKEN = 'test-loggly-token';
-process.env.LOGGLY_SUBDOMAIN = 'test-loggly-subdomain';
-
 const fetch = require('node-fetch');
@@ -11,2 +8,3 @@
 const Logger = require('../../lib');
+const { logSingle, logBatch } = require('../../lib/loggly-wrapper');
 
@@ -30,2 +28,3 @@ const logger = Logger.create({
     global.console.warn = jest.fn();
+    process.env.LOGGLY_TOKEN = 'test-loggly-token';
     fetch.mockReset();
@@ -350,4 +349,40 @@ });
   });
+
+  test('should create a transient logger', async () => {
+    let previousLevel = Logger.getLevel();
+    previousLevel = Logger.setLevel('error');
+
+    const testLogger = new Logger({
+      serviceName: 'fake-service-1',
+      moduleName: 'fake-module-1',
+      isTransient: true,
+    });
+
+    await testLogger.trace({});
+    expect(fetch).not.toHaveBeenCalled();
+
+    await testLogger.info({});
+    expect(fetch).not.toHaveBeenCalled();
+
+    await testLogger.warn({});
+    expect(fetch).not.toHaveBeenCalled();
+
+    await testLogger.error({});
+    expect(fetch).toHaveBeenCalled();
+    expect(fetch.mock.calls[0][0]).toBe('https://logs-01.loggly.com/bulk/test-loggly-token/tag/fake-service-1-development/');
+
+    Logger.setLevel(previousLevel);
+  });
+
+  test('should console.error if log param is not an object in logSingle', async () => {
+    await logSingle(true);
+    expect(console.error).toHaveBeenCalledTimes(1);
+  });
+
+  test('should console.error if log param is not an array in logBatch', async () => {
+    await logBatch(true);
+    expect(console.error).toHaveBeenCalledTimes(1);
+  });
 });
 
 /* eslint-enable no-console */

Fixed alerts

Environment variable access

Supply chain risk

Package accesses environment variables, which may be a sign of credential stuffing or data theft.

Found 2 instances in 1 package

Improved metrics

Total package byte prevSize

45884

increased by49.45%

Number of package files

17

increased by13.33%

Lines of code

989

increased by46.95%

Number of lines in readme file

155

increased by12.32%

Number of low supply chain risk alerts

6

decreased by-14.29%

Worsened metrics

Dev dependency count

12

increased by71.43%

Number of medium supply chain risk alerts

33

increased by17.86%

Dependency changes

• + Addednode-fetch@2.2.0(transitive)

• - Removednode-fetch@2.1.2(transitive)

• Updatednode-fetch@2.2.0