Merge pull request #703 from aoberoi/accept-logger-object-option

New logging implementation

docs/_pages/rtm_client.md

@@ -311,17 +311,41 @@ A simpler alternative is to fetch the state you need from the Web API whenever y
 
 ### Customizing the logger
 
-The `RTMClient` also logs interesting events as it operates. By default, the log level is set to `info` and it should
-not log anything as long as nothing goes wrong.
+The `RTMClient` also logs interesting events as it operates. By default, the log level is set to `LogLevel.INFO` and it
+should not log anything as long as nothing goes wrong.
 
 You can adjust the log level by setting the `logLevel` option to any of the values found in the `LogLevel` top-level
 export.
 
-You can also capture the logs without writing them to stdout by setting the `logger` option. It should be set to a
-function that takes `fn(level: string, message: string)`.
+```javascript
+const fs = require('fs');
+const { RTMClient, LogLevel } = require('@slack/client');
+
+// increased logging, great for debugging
+const rtm = new RTMClient(token, { logLevel: LogLevel.DEBUG });
+```
+
+There are four logging levels: `LogLevel.DEBUG`, `LogLevel.INFO`, `LogLevel.WARN`, `LogLevel.ERROR`. Here they appear in
+order of increasing severity, which means that using `LogLevel.ERROR` will output the least number of messages, and only
+the most important.
+
+You can also capture the logs without writing them to stdout by setting the `logger` option. The option should be set
+to an object that has the following methods:
+
+**Logger**
+
+| Method       | Parameters        | Return type |
+|--------------|-------------------|-------------|
+| `setLevel()` | `level: LogLevel` | `void`      |
+| `setName()`  | `name: string`    | `void`      |
+| `debug()`    | `...msgs: any[]`  | `void`      |
+| `info()`     | `...msgs: any[]`  | `void`      |
+| `warn()`     | `...msgs: any[]`  | `void`      |
+| `error()`    | `...msgs: any[]`  | `void`      |
+
 
-**NOTE** `logLevel: LogLevel.DEBUG` should not be used in production. Debug is helpful for diagnosing issues but it is a
-bad idea to use this in production because it will log the contents of messages.
+**NOTE**: While the use of logging functions is deprecated, the `logger` option will still currently accept a function
+whose method signature matches `fn(level: string, message: string)`
 
 ```javascript
 const fs = require('fs');
@@ -334,11 +358,15 @@ const logStream = fs.createWriteStream('/tmp/app.log');
 const token = process.env.SLACK_TOKEN;
 logStream.on('open', () => {
   const rtm = new RTMClient(token, {
-    // increased logging, great for debugging
-    logLevel: LogLevel.DEBUG,
-    logger: (level, message) => {
-      // write to disk
-      logStream.write(`[${level}]: ${message}`);
+    // write all messages to disk
+    logger: {
+      debug(...msgs) { logStream.write(JSON.stringify(msgs)); }
+      info(...msgs) { logStream.write(JSON.stringify(msgs)); }
+      warn(...msgs) { logStream.write(JSON.stringify(msgs)); }
+      error(...msgs) { logStream.write(JSON.stringify(msgs)); }
+      // these methods are noops because this custom logger will write everything to disk (all levels)
+      setLevel(){},
+      setName(){},
     }
   });
 });

docs/_pages/web_client.md

@@ -17,10 +17,13 @@ headings:
     - title: Custom agent for proxy support
     - title: OAuth token exchange
     - title: Using legacy message attachments
+<<<<<<< HEAD
+=======
     - title: Using a callback instead of a Promise (deprecated)
     - title: Calling methods on behalf of users (deprecated)
     - title: Using refresh tokens (deprecated)
     - title: Manually handling token rotation (deprecated)
+>>>>>>> master
 
 ---
 
@@ -388,14 +391,41 @@ failing with `Error`s which have a `code` property set to `errorCode.HTTPError`.
 
 ### Customizing the logger
 
-The `WebClient` also logs interesting events as it operates. By default, the log level is set to `info` and it should
-not log anything as long as nothing goes wrong.
+The `WebClient` also logs interesting events as it operates. By default, the log level is set to `LogLevel.INFO` and it
+should not log anything as long as nothing goes wrong.
 
 You can adjust the log level by setting the `logLevel` option to any of the values found in the `LogLevel` top-level
 export.
 
-You can also capture the logs without writing them to stdout by setting the `logger` option. It should be set to a
-function that takes `fn(level: string, message: string)`.
+```javascript
+const fs = require('fs');
+const { WebClient, LogLevel } = require('@slack/client');
+
+// increased logging, great for debugging
+const web = new WebClient(token, { logLevel: LogLevel.DEBUG });
+```
+
+There are four logging levels: `LogLevel.DEBUG`, `LogLevel.INFO`, `LogLevel.WARN`, `LogLevel.ERROR`. Here they appear in
+order of increasing severity, which means that using `LogLevel.ERROR` will output the least number of messages, and only
+the most important.
+
+You can also capture the logs without writing them to stdout by setting the `logger` option. The option should be set
+to an object that has the following methods:
+
+**Logger**
+
+| Method       | Parameters        | Return type |
+|--------------|-------------------|-------------|
+| `setLevel()` | `level: LogLevel` | `void`      |
+| `setName()`  | `name: string`    | `void`      |
+| `debug()`    | `...msgs: any[]`  | `void`      |
+| `info()`     | `...msgs: any[]`  | `void`      |
+| `warn()`     | `...msgs: any[]`  | `void`      |
+| `error()`    | `...msgs: any[]`  | `void`      |
+
+
+**NOTE**: While the use of logging functions is deprecated, the `logger` option will still currently accept a function
+whose method signature matches `fn(level: string, message: string)`.
 
 ```javascript
 const fs = require('fs');
@@ -408,11 +438,15 @@ const logStream = fs.createWriteStream('/tmp/app.log');
 const token = process.env.SLACK_TOKEN;
 logStream.on('open', () => {
   const web = new WebClient(token, {
-    // increased logging, great for debugging
-    logLevel: LogLevel.DEBUG,
-    logger: (level, message) => {
-      // write to disk
-      logStream.write(`[${level}]: ${message}`);
+    // write all messages to disk
+    logger: {
+      debug(...msgs) { logStream.write(JSON.stringify(msgs)); }
+      info(...msgs) { logStream.write(JSON.stringify(msgs)); }
+      warn(...msgs) { logStream.write(JSON.stringify(msgs)); }
+      error(...msgs) { logStream.write(JSON.stringify(msgs)); }
+      // these methods are noops because this custom logger will write everything to disk (all levels)
+      setLevel(){},
+      setName(){},
     }
   });
 });

package.json

@@ -45,7 +45,6 @@
   "dependencies": {
     "@types/form-data": "^2.2.1",
     "@types/is-stream": "^1.1.0",
-    "@types/loglevel": "^1.5.3",
     "@types/node": ">=6.0.0",
     "@types/p-cancelable": "^0.3.0",
     "@types/p-queue": "^2.3.1",
@@ -57,7 +56,6 @@
     "finity": "^0.5.4",
     "form-data": "^2.3.1",
     "is-stream": "^1.1.0",
-    "loglevel": "^1.6.1",
     "object.entries": "^1.0.4",
     "object.getownpropertydescriptors": "^2.0.3",
     "object.values": "^1.0.4",
@@ -79,7 +77,7 @@
     "lint-staged": "^6.1.0",
     "mocha": "^5.0.0",
     "nock": "^9.1.6",
-    "nyc": "^11.4.1",
+    "nyc": "^13.3.0",
     "p-is-promise": "^1.1.0",
     "shx": "^0.2.2",
     "sinon": "^4.2.2",

src/KeepAlive.ts

@@ -1,15 +1,16 @@
 import { RTMClient, ErrorCode } from './';
 import EventEmitter = require('eventemitter3'); // tslint:disable-line:import-name no-require-imports
-import { LogLevel, Logger, LoggingFunc, getLogger, loggerFromLoggingFunc } from './logger';
+import { LogLevel, Logger, LoggingFunc, getLogger, loggerFromLoggingFunc, isLoggingFunc } from './logger';
 import { errorWithCode } from './errors';
 const pkg = require('../package.json'); // tslint:disable-line:no-require-imports no-var-requires
 
 export interface KeepAliveOptions {
-  logger?: LoggingFunc;
+  /** Custom logger. Using a LoggingFunc is deprecated. */
+  logger?: Logger | LoggingFunc;
   logLevel?: LogLevel;
-  // how long (in ms) to wait before sending a ping message to keep the connection alive
+  /** How long (in ms) to wait before sending a ping message to keep the connection alive */
   clientPingTimeout?: number;
-  // how long (in ms) to wait for the acknowledgement of a ping message before considering the connection dead
+  /** How long (in ms) to wait for the acknowledgement of a ping message before considering the connection dead */
   serverPongTimeout?: number; // NOTE: this must be less than clientPingTimeout
 }
 
@@ -94,12 +95,12 @@ export class KeepAlive extends EventEmitter {
     this.recommendReconnect = false;
 
     // Logging
-    if (logger !== undefined) {
-      this.logger = loggerFromLoggingFunc(KeepAlive.loggerName, logger);
+    if (logger !== undefined && isLoggingFunc(logger)) {
+      this.logger = loggerFromLoggingFunc(KeepAlive.loggerName, logger, logLevel);
+      this.logger.warn('Using a logging function is deprecated. Use a Logger object instead.');
     } else {
-      this.logger = getLogger(KeepAlive.loggerName);
+      this.logger = getLogger(KeepAlive.loggerName, logLevel, logger);
     }
-    this.logger.setLevel(logLevel);
   }
 
   /**

src/RTMClient.ts

@@ -5,7 +5,7 @@ import WebSocket = require('ws'); // tslint:disable-line:import-name no-require-
 import Finity, { StateMachine } from 'finity'; // tslint:disable-line:import-name
 import PQueue = require('p-queue'); // tslint:disable-line:import-name no-require-imports
 import PCancelable = require('p-cancelable'); // tslint:disable-line:import-name no-require-imports
-import { LogLevel, Logger, LoggingFunc, getLogger, loggerFromLoggingFunc } from './logger';
+import { LogLevel, Logger, LoggingFunc, getLogger, loggerFromLoggingFunc, isLoggingFunc } from './logger';
 import { RetryOptions } from './retry-policies';
 import { KeepAlive } from './KeepAlive';
 import { WebClient, WebAPICallResult, WebAPICallError, ErrorCode, CodedError } from './';
@@ -345,12 +345,12 @@ export class RTMClient extends EventEmitter {
     }, this);
 
     // Logging
-    if (logger !== undefined) {
-      this.logger = loggerFromLoggingFunc(RTMClient.loggerName, logger);
+    if (logger !== undefined && isLoggingFunc(logger)) {
+      this.logger = loggerFromLoggingFunc(RTMClient.loggerName, logger, logLevel);
+      this.logger.warn('Using a logging function is deprecated. Use a Logger object instead.');
     } else {
-      this.logger = getLogger(RTMClient.loggerName);
+      this.logger = getLogger(RTMClient.loggerName, logLevel, logger);
     }
-    this.logger.setLevel(logLevel);
 
     this.stateMachine = Finity.start(this.stateMachineConfig);
 
@@ -617,8 +617,9 @@ export class RTMClient extends EventEmitter {
       event = JSON.parse(data);
     } catch (parseError) {
       // prevent application from crashing on a bad message, but log an error to bring attention
-      this.logger.error(`unable to parse incoming websocket message: ${parseError.message}\n` +
-        `    message contents: "${data}"`);
+      this.logger.error(
+        `unable to parse incoming websocket message: ${parseError.message}\n    message contents: "${data}"`,
+      );
       return;
     }
 
@@ -657,7 +658,8 @@ export default RTMClient;
 // NOTE: add an experimental flag to turn off KeepAlive
 export interface RTMClientOptions {
   slackApiUrl?: string;
-  logger?: LoggingFunc;
+  /** Custom logger. Using a LoggingFunc is deprecated. */
+  logger?: Logger | LoggingFunc;
   logLevel?: LogLevel;
   retryConfig?: RetryOptions;
   agent?: Agent;

src/WebClient.spec.js

@@ -52,22 +52,31 @@ describe('WebClient', function () {
     });
   });
 
-  describe('has an option to provide a logging function', function () {
+  describe('has a logger option', function () {
     beforeEach(function () {
       this.capture = new CaptureConsole();
       this.capture.startCapture();
+      this.logger = {
+        debug: sinon.spy(),
+        info: sinon.spy(),
+        warn: sinon.spy(),
+        error: sinon.spy(),
+        setLevel: sinon.spy(),
+        setName: sinon.spy(),
+      };
     });
-    it('sends logs to the function and not to stdout', function () {
-      const output = [];
-      const stub = function (level, message) {
-        output.push([level, message]);
-      }
+    it('sends logs to a logger and not to stdout', function () {
+      const debuggingClient = new WebClient(token, { logLevel: LogLevel.DEBUG, logger: this.logger });
+      assert.isTrue(this.logger.debug.called);
+      const capturedOutput = this.capture.getCapturedText();
+      assert.isEmpty(capturedOutput);
+    });
+    it('sends logs to a logger function and not to stdout', function () {
+      const stub = sinon.stub();
       const debuggingClient = new WebClient(token, { logLevel: LogLevel.DEBUG, logger: stub });
-      assert.isAtLeast(output.length, 1);
-      const firstOutput = output[0];
-      assert.lengthOf(firstOutput, 2);
-      const firstOutputLevel = firstOutput[0];
-      assert.equal(firstOutputLevel, 'debug');
+      assert.isTrue(stub.called);
+      const call = stub.lastCall;
+      assert.isTrue(call.calledWithMatch('debug'));
       const capturedOutput = this.capture.getCapturedText();
       assert.isEmpty(capturedOutput);
     });
@@ -102,15 +111,18 @@ describe('WebClient', function () {
       });
 
       it('should send warnings to logs', function() {
-        const output = [];
-        const stub = function (level, message) {
-          output.push([level, message]);
-        }
-        const warnClient = new WebClient(token, { logLevel: LogLevel.WARN, logger: stub });
+        const logger = {
+          debug: sinon.spy(),
+          info: sinon.spy(),
+          warn: sinon.spy(),
+          error: sinon.spy(),
+          setLevel: sinon.spy(),
+          setName: sinon.spy(),
+        };
+        const warnClient = new WebClient(token, { logLevel: LogLevel.WARN, logger });
         return warnClient.apiCall('method')
-          .then((result) => {
-            assert.isNotEmpty(output);
-            assert.lengthOf(output, 2, 'two logs pushed onto output');
+          .then(() => {
+            assert.isTrue(logger.warn.calledTwice);
           });
       });
 
@@ -1132,6 +1144,15 @@ describe('WebClient', function () {
       this.capture.stopCapture();
       done();
     });
+    it('should warn when using a logging func', function (done) {
+      const stub = sinon.spy();
+      new WebClient(token, { logger: stub });
+      assert.isTrue(stub.called);
+      const call = stub.firstCall;
+      assert.isTrue(call.calledWithMatch('warn'));
+      this.capture.stopCapture();
+      done();
+    });
   });
 
   afterEach(function () {

src/WebClient.ts

@@ -14,7 +14,7 @@ import axios, { AxiosInstance, AxiosResponse } from 'axios';
 import FormData = require('form-data'); // tslint:disable-line:no-require-imports import-name
 import { awaitAndReduce, callbackify, getUserAgent, delay, AgentOption, TLSOptions, agentForScheme } from './util';
 import { CodedError, errorWithCode, ErrorCode } from './errors';
-import { LogLevel, Logger, LoggingFunc, getLogger, loggerFromLoggingFunc } from './logger';
+import { LogLevel, Logger, LoggingFunc, getLogger, loggerFromLoggingFunc, isLoggingFunc } from './logger';
 import retryPolicies, { RetryOptions } from './retry-policies';
 import Method, * as methods from './methods'; // tslint:disable-line:import-name
 
@@ -160,12 +160,12 @@ export class WebClient extends EventEmitter {
     this.rejectRateLimitedCalls = rejectRateLimitedCalls;
 
     // Logging
-    if (logger !== undefined) {
-      this.logger = loggerFromLoggingFunc(WebClient.loggerName, logger);
+    if (logger !== undefined && isLoggingFunc(logger)) {
+      this.logger = loggerFromLoggingFunc(WebClient.loggerName, logger, logLevel);
+      this.logger.warn('Using a logging function is deprecated. Use a Logger object instead.');
     } else {
-      this.logger = getLogger(WebClient.loggerName);
+      this.logger = getLogger(WebClient.loggerName, logLevel, logger);
     }
-    this.logger.setLevel(logLevel);
 
     this.axios = axios.create({
       baseURL: slackApiUrl,
@@ -299,7 +299,7 @@ export class WebClient extends EventEmitter {
 
               // log warnings in response metadata
               if (result.response_metadata !== undefined && result.response_metadata.warnings !== undefined) {
-                result.response_metadata.warnings.forEach(this.logger.warn);
+                result.response_metadata.warnings.forEach(this.logger.warn.bind(this.logger));
               }
 
               if (!result.ok) {
@@ -882,7 +882,8 @@ export default WebClient;
 
 export interface WebClientOptions {
   slackApiUrl?: string;
-  logger?: LoggingFunc;
+  /** Custom logger. Using a LoggingFunc is deprecated. */
+  logger?: Logger | LoggingFunc;
   logLevel?: LogLevel;
   maxRequestConcurrency?: number;
   retryConfig?: RetryOptions;

src/index.ts

@@ -1,4 +1,5 @@
 export {
+  Logger,
   LoggingFunc,
   LogLevel,
 } from './logger';