feat: adding debug logger (#64)

Author: jorge-ibm

README.md

@@ -59,6 +59,26 @@ import { getAuthenticatorFromEnvironment } from 'ibm-cloud-sdk-core';
 const iamAuthenticator = getAuthenticatorFromEnvironment('my-service');
 ```
 
+## Logging
+This package uses [debug](https://www.npmjs.com/package/debug) for logging.
+
+- Logging is disabled by default.
+- Logging has been configured to use log levels which are assumed to be numerically ascending from most important to least important.
+- In order to see the log output, set the environment variable ``DEBUG`` including the desired log level.
+  - ```DEBUG=ibm-cloud-sdk-core:error``` enables error logs
+  - ```DEBUG=ibm-cloud-sdk-core:warning``` enables warning logs and below
+  - ```DEBUG=ibm-cloud-sdk-core:info``` enables info logs and below
+  - ```DEBUG=ibm-cloud-sdk-core:verbose``` enables verbose logs and below
+  - ```DEBUG=ibm-cloud-sdk-core:debug``` enables debug logs and below
+
+To see the output from all of the debugging levels you can use:
+
+``DEBUG=ibm-cloud-sdk-core*``
+
+The debug logger can be configured to be used for more than one library. In example, you can set a comma-separated string:
+
+``DEBUG=ibm-cloud-sdk-core:debug,other-lib:debug``
+
 ## Issues
 If you encounter an issue with this project, you are welcome to submit a [bug report](https://github.com/IBM/node-sdk-core/issues).
 Before opening a new issue, please search for similar issues. It's possible that someone has already reported it.

auth/token-managers/iam-token-manager.ts

@@ -17,6 +17,7 @@
 import extend = require('extend');
 import { OutgoingHttpHeaders } from 'http';
 import { getMissingParams } from '../../lib/helper';
+import logger from '../../lib/logger';
 import { computeBasicAuthHeader, validateInput } from '../utils';
 import { JwtTokenManager, TokenManagerOptions } from './jwt-token-manager';
 
@@ -43,7 +44,7 @@ interface Options extends TokenManagerOptions {
 }
 
 // this interface is a representation of the response
-// object from the IAM service, hence the snake_case 
+// object from the IAM service, hence the snake_case
 // parameter names
 export interface IamTokenData {
   access_token: string;
@@ -74,7 +75,7 @@ export class IamTokenManager extends JwtTokenManager {
     super(options);
 
     validateInput(options, this.requiredOptions);
-    
+
     this.apikey = options.apikey;
 
     this.url = this.url || 'https://iam.cloud.ibm.com/identity/token';
@@ -87,7 +88,7 @@ export class IamTokenManager extends JwtTokenManager {
     }
     if (onlyOne(options.clientId, options.clientSecret)) {
       // tslint:disable-next-line
-      console.log(CLIENT_ID_SECRET_WARNING);
+      logger.warn(CLIENT_ID_SECRET_WARNING);
     }
   }
 
@@ -98,7 +99,7 @@ export class IamTokenManager extends JwtTokenManager {
    * If these values are not set, no Authorization header will be
    * set on the request (it is not required).
    *
-   * @param {string} clientId - The client id 
+   * @param {string} clientId - The client id
    * @param {string} clientSecret - The client secret
    * @returns {void}
    */
@@ -107,7 +108,7 @@ export class IamTokenManager extends JwtTokenManager {
     this.clientSecret = clientSecret;
     if (onlyOne(clientId, clientSecret)) {
       // tslint:disable-next-line
-      console.log(CLIENT_ID_SECRET_WARNING);
+      logger.warn(CLIENT_ID_SECRET_WARNING);
     }
   }
 
@@ -140,7 +141,7 @@ export class IamTokenManager extends JwtTokenManager {
         rejectUnauthorized: !this.disableSslVerification,
       }
     };
-    
+
     return this.requestWrapperInstance.sendRequest(parameters);
   }
 }

auth/token-managers/jwt-token-manager.ts

@@ -17,6 +17,7 @@
 import extend = require('extend');
 import { OutgoingHttpHeaders } from 'http';
 import jwt = require('jsonwebtoken');
+import logger from '../../lib/logger';
 import { RequestWrapper } from '../../lib/request-wrapper';
 
 function getCurrentTime(): number {
@@ -123,7 +124,9 @@ export class JwtTokenManager {
    * @returns {Promise}
    */
   protected requestToken(): Promise<any> {
-    const err = new Error('`requestToken` MUST be overridden by a subclass of JwtTokenManagerV1.');
+    const errMsg = '`requestToken` MUST be overridden by a subclass of JwtTokenManagerV1.';
+    const err = new Error(errMsg);
+    logger.error(errMsg);
     return Promise.reject(err);
   }
 
@@ -156,7 +159,9 @@ export class JwtTokenManager {
     const accessToken = tokenResponse[this.tokenName];
 
     if (!accessToken) {
-      throw new Error('Access token not present in response');
+      const err = 'Access token not present in response';
+      logger.error(err);
+      throw new Error(err);
     }
 
     this.expireTime = this.calculateTimeForNewToken(accessToken);
@@ -184,7 +189,9 @@ export class JwtTokenManager {
       const timeToLive = exp - iat;
       timeForNewToken = exp - (timeToLive * (1.0 - fractionOfTtl));
     } else {
-      throw new Error('Access token recieved is not a valid JWT');
+      const err = 'Access token recieved is not a valid JWT'
+      logger.error(err);
+      throw new Error(err);
     }
 
     return timeForNewToken;

auth/utils/read-credentials-file.ts

@@ -2,6 +2,7 @@ import dotenv = require('dotenv');
 import fs = require('fs');
 import os = require('os');
 import path = require('path');
+import logger from '../../lib/logger';
 
 const filename: string = 'ibm-credentials.env';
 
@@ -36,6 +37,7 @@ export function readCredentialsFile() {
     filepathToUse = homeDir;
   } else {
     // file does not exist anywhere, will not be used
+    logger.info('Credential file does not exist. Will not be used');
     return {};
   }
 

lib/base-service.ts

@@ -21,6 +21,7 @@ import semver = require('semver');
 import vcapServices = require('vcap_services');
 import { AuthenticatorInterface, checkCredentials, readExternalSources } from '../auth';
 import { stripTrailingSlash } from './helper';
+import logger from './logger';
 import { RequestWrapper } from './request-wrapper';
 
 export interface UserOptions {
@@ -65,9 +66,9 @@ export class BaseService {
    */
   constructor(userOptions: UserOptions) {
     if (!(this instanceof BaseService)) {
-      throw new Error(
-        'the "new" keyword is required to create service instances'
-      );
+      const err = 'the "new" keyword is required to create service instances';
+      logger.error(`Error creating an instance of BaseService: ${err}`);
+      throw new Error(err);
     }
 
     const _options = {} as BaseServiceOptions;
@@ -85,6 +86,7 @@ export class BaseService {
     // check serviceUrl for common user errors
     const credentialProblems = checkCredentials(options, ['serviceUrl']);
     if (credentialProblems) {
+      logger.error(credentialProblems.message);
       throw credentialProblems;
     }
 

lib/helper.ts

@@ -19,6 +19,7 @@ import fileType = require('file-type');
 import { isReadable } from 'isstream';
 import { lookup } from 'mime-types';
 import { basename } from 'path';
+import logger from './logger';
 
 export interface FileObject {
   value: NodeJS.ReadableStream | Buffer | string;
@@ -129,6 +130,7 @@ export function getMissingParams(
  * @returns {boolean} true if 'text' has html tags
  */
 export function isHTML(text: string): boolean {
+  logger.debug(`Determining if the text ${text} is HTML.`);
   return /<[a-z][\s\S]*>/i.test(text);
 }
 
@@ -144,6 +146,7 @@ export function getFormat(
   formats: string[]
 ): string {
   if (!formats || !params) {
+    logger.debug(`No formats to parse in getFormat. Returning null`);
     return null;
   }
   for (const item of formats) {
@@ -152,6 +155,7 @@ export function getFormat(
     }
   }
 
+  logger.debug(`No formats to parse in getFormat. Returning null`);
   return null;
 }
 

lib/logger.ts

@@ -0,0 +1,31 @@
+import logger = require('debug');
+const debug = logger('ibm-cloud-sdk-core:debug');
+const error = logger('ibm-cloud-sdk-core:error');
+const info = logger('ibm-cloud-sdk-core:info');
+const verbose = logger('ibm-cloud-sdk-core:verbose');
+const warn = logger('ibm-cloud-sdk-core:warning');
+
+// enable loggers if axios flag is set & mimic log levels severity
+if (process.env.NODE_DEBUG === 'axios') {
+  debug.enabled = true;
+}
+if (debug.enabled) {
+  verbose.enabled = true;
+}
+if (verbose.enabled) {
+  info.enabled = true;
+}
+if (info.enabled) {
+  warn.enabled = true;
+}
+if (warn.enabled) {
+  error.enabled = true;
+}
+// export loggers;
+export default {
+  debug,
+  error,
+  info,
+  verbose,
+  warn
+}

lib/request-wrapper.ts

@@ -21,6 +21,7 @@ import https = require('https');
 import querystring = require('querystring');
 import { PassThrough as readableStream } from 'stream';
 import { buildRequestFileObject, getMissingParams, isEmptyObject, isFileData, isFileWithMetadata } from './helper';
+import logger from './logger';
 
 const isBrowser = typeof window === 'object';
 const globalTransactionId = 'x-global-transaction-id';
@@ -67,42 +68,42 @@ export class RequestWrapper {
     this.axiosInstance = axios.create(axiosConfig);
 
     // set debug interceptors
-    if(process.env.NODE_DEBUG === 'axios') {
+    if(process.env.NODE_DEBUG === 'axios' || process.env.DEBUG) {
       this.axiosInstance.interceptors.request.use(config => {
-        console.debug('Request:');
+        logger.debug('Request:');
         try {
-          console.debug(JSON.stringify(config, null, 2));
+          logger.debug(JSON.stringify(config, null, 2));
         } catch {
-          console.debug(config)
+          logger.error(config)
         }
 
         return config;
       }, error => {
-        console.debug('Error:');
+        logger.error('Error: ');
         try {
-          console.debug(JSON.stringify(error, null, 2));
+          logger.error(JSON.stringify(error, null, 2));
         } catch {
-          console.debug(error);
+          logger.error(error);
         }
 
         return Promise.reject(error);
       });
 
       this.axiosInstance.interceptors.response.use(response => {
-        console.debug('Response:');
+        logger.debug('Response:');
         try {
-          console.debug(JSON.stringify(response, null, 2));
+          logger.debug(JSON.stringify(response, null, 2));
         } catch {
-          console.debug(response)
+          logger.error(response);
         }
 
         return response;
       }, error => {
-        console.debug('Error:');
+        logger.error('Error: ');
         try {
-          console.debug(JSON.stringify(error, null, 2));
+          logger.error(JSON.stringify(error, null, 2));
         } catch {
-          console.debug(error);
+          logger.error(error);
         }
 
         return Promise.reject(error);
@@ -259,6 +260,7 @@ export class RequestWrapper {
         // ignore the error, use the object, and tack on a warning
         errorBody = axiosError.data;
         errorBody.warning = 'Body contains circular reference';
+        logger.error(`Failed to stringify axiosError: ${e}`);
       }
 
       error.body = errorBody;
@@ -385,5 +387,6 @@ function parseServiceErrorMessage(response: any): string | undefined {
     message = response.errorMessage;
   }
 
+  logger.info(`Parsing service error message: ${message}`);
   return message;
 }