misc: remove sensitive data from log (#71)

package.json

@@ -40,7 +40,7 @@
     "morgan": "^1.10.0",
     "nanoid": "^3.2.0",
     "pug": "^3.0.3",
-    "ringcentral-chatbot-core": "^1.5.4-beta.1",
+    "ringcentral-chatbot-core": "^1.6.1",
     "sequelize": "^6.29.0",
     "serverless-http": "^2.6.0"
   }

src/server/handlers/interactiveMessages.js

@@ -12,6 +12,7 @@ const { getAdaptiveCardFromTemplate } = require('../utils/getAdaptiveCardFromTem
 const authTokenTemplate = require('../adaptiveCards/authToken.json');
 const messageCardTemplate = require('../adaptiveCards/message.json');
 const stateOperationLogTemplate = require('../adaptiveCards/stateOperationLog.json');
+const { errorLogger } = require('../utils/logger');
 
 async function saveAuthToken(authToken, body) {
   if (authToken) {
@@ -83,7 +84,7 @@ async function notificationInteractiveMessages(req, res) {
         );
       }
     } else {
-      console.error(e && e.message);
+      errorLogger(e);
     }
   }
   res.status(200);
@@ -162,7 +163,7 @@ async function addOperationLogIntoCard(bot, cardId, data, user) {
       await bot.updateAdaptiveCard(cardId, newCard);
     }
   } catch (e) {
-    console.error(e && e.message);
+    errorLogger(e);
   }
 }
 
@@ -284,7 +285,7 @@ async function botInteractiveMessagesHandler(req, res) {
           trackResult = 'permissionDenied';
         }
       } else {
-        console.error(e && e.message);
+        errorLogger(e);
       }
       if (!res.headersSent) {
         res.status(200);
@@ -297,7 +298,7 @@ async function botInteractiveMessagesHandler(req, res) {
       });
     }
   } catch (e) {
-    console.error(e && e.message);
+    errorLogger(e);
     if (!res.headersSent) {
       res.status(500);
       res.send('Internal error');

src/server/index.js

@@ -8,13 +8,17 @@ const notificationRoute = require('./routes/notification');
 const subscriptionRoute = require('./routes/subscription');
 const { botHandler } = require('./bot/handler');
 const { botConfig } = require('./bot/config');
+const { errorLogger } = require('./utils/logger');
 
 const app = express()
 app.use(morgan(function (tokens, req, res) {
   let url = tokens.url(req, res);
   if (url.indexOf('/bot-notify/') === 0) {
     url = `/bot-notify/[MASK]-${url.slice(-5)}`; // mask from log
   }
+  if (url.indexOf('/bot/oauth') === 0) {
+    url = '/bot/oauth'; // mask from log
+  }
   return [
     tokens.method(req, res),
     url,
@@ -40,4 +44,13 @@ app.post('/interactive-messages', notificationRoute.interactiveMessages);
 extendBotApp(app, [], botHandler, botConfig);
 app.post('/bot-notify/:id', notificationRoute.botNotification);
 
+app.use(function (err, req, res, next) {
+  errorLogger(err);
+  if (res.headersSent) {
+    return next(err);
+  }
+  res.status(500);
+  res.json({ result: 'error', message: 'Internal server error' });
+});
+
 exports.app = app;

src/server/routes/notification.js

@@ -4,7 +4,7 @@ const Bot = require('ringcentral-chatbot-core/dist/models/Bot').default;
 const { decodeToken } = require('../utils/jwt');
 const { sendAdaptiveCardToRCWebhook } = require('../utils/messageHelper');
 const { Analytics } = require('../utils/analytics');
-
+const { errorLogger } = require('../utils/logger');
 const { Webhook } = require('../models/webhook');
 const { notificationInteractiveMessages, botInteractiveMessagesHandler } = require('../handlers/interactiveMessages');
 
@@ -36,7 +36,7 @@ async function notification(req, res) {
     res.status(200);
     res.send('ok');
   } catch (e) {
-    console.error(e && e.message);
+    errorLogger(e);
     res.status(500);
     res.send('error');
   }
@@ -68,7 +68,7 @@ async function botNotification(req, res) {
         userId: bot.id,
         accountId: bot.token && bot.token.creator_account_id,
       });
-      analytics.trackBotAction('cardPosted', {
+      await analytics.trackBotAction('cardPosted', {
         chatId: groupId,
       });
     }

src/server/routes/subscription.js

@@ -1,5 +1,6 @@
 const { Webhook } = require('../models/webhook');
 const { RCWebhook } = require('../models/rc-webhook');
+const { errorLogger } = require('../utils/logger');
 
 // Setup page for install add-in
 async function setup(req, res) {
@@ -72,7 +73,7 @@ async function createWebhook(req, res) {
       webhookUri: `${process.env.APP_SERVER}/notify/${bugsnagWebhook.id}`,
     });
   } catch (e) {
-    console.error(e);
+    errorLogger(e);
     res.status(500);
     res.send('Internal server error');
     return;

src/server/utils/logger.js

@@ -0,0 +1,33 @@
+
+function logErrorResponse(response) {
+  const status = response.status;
+  const data = response.data;
+  const headers = response.headers || {};
+  const rcRequestId = headers['rcrequestid'];
+  console.error(
+    'Response error: ', status,
+    ' RequestId: ', rcRequestId,
+    ' Data: ',
+    data
+  );
+}
+
+function errorLogger(error) {
+  if (!error) {
+    return;
+  }
+  if (error.response) {
+    // https://axios-http.com/docs/handling_errors
+    // The request was made and the server responded with a status code
+    logErrorResponse(error.response);
+    return;
+  }
+  if (error.request) {
+    // The request was made but no response was received
+    console.error('Request error: ', error.code);
+    return;
+  }
+  console.error('Error: ', error.message);
+}
+
+exports.errorLogger = errorLogger;

tests/bot.test.js

@@ -159,6 +159,90 @@ describe('Bot', () => {
     rcGroupScope.done();
   });
 
+  it('should send response 500 when fetch group message 500', async () => {
+    const rcGroupScope = nock(process.env.RINGCENTRAL_SERVER)
+      .get(uri => uri.includes(`/restapi/v1.0/glip/groups/${groupId}`))
+      .reply(500, {
+        message: 'Service Unavailable'
+      }, {
+        rcrequestid: 'xxxxxx'
+      });
+    const res = await request(server).post('/bot/webhook').send({
+      "uuid": "5794186355105264737",
+      "event": "/restapi/v1.0/glip/posts",
+      "timestamp": "2022-02-11T09:49:55.091Z",
+      "subscriptionId": "0a7fb1f2-9e7c-456f-8078-148d1e7c3638",
+      "ownerId": botId,
+      "body": {
+        "id": "5852045316",
+        "groupId": groupId,
+        "type": "TextMessage",
+        "text": `![:Person](${botId}) help`,
+        "creatorId": "170848004",
+        "addedPersonIds": null,
+        "creationTime": "2022-02-11T09:49:54.614Z",
+        "lastModifiedTime": "2022-02-11T09:49:54.614Z",
+        "attachments": null,
+        "activity": null,
+        "title": null,
+        "iconUri": null,
+        "iconEmoji": null,
+        "mentions": [
+          {
+            "id": botId,
+            "type": "Person",
+            "name": "Bugsnag Bot"
+          }
+        ],
+        "eventType": "PostAdded"
+      }
+    });
+    expect(res.status).toEqual(500);
+    expect(res.body.message).toEqual('Internal server error');
+    rcGroupScope.done();
+  });
+
+  it('should send response 500 when fetch group message 503', async () => {
+    const rcGroupScope = nock(process.env.RINGCENTRAL_SERVER)
+      .get(uri => uri.includes(`/restapi/v1.0/glip/groups/${groupId}`))
+      .reply(503, {
+        message: 'Service Unavailable'
+      });
+    const res = await request(server).post('/bot/webhook').send({
+      "uuid": "5794186355105264737",
+      "event": "/restapi/v1.0/glip/posts",
+      "timestamp": "2022-02-11T09:49:55.091Z",
+      "subscriptionId": "0a7fb1f2-9e7c-456f-8078-148d1e7c3638",
+      "ownerId": botId,
+      "body": {
+        "id": "5852045316",
+        "groupId": groupId,
+        "type": "TextMessage",
+        "text": `![:Person](${botId}) help`,
+        "creatorId": "170848004",
+        "addedPersonIds": null,
+        "creationTime": "2022-02-11T09:49:54.614Z",
+        "lastModifiedTime": "2022-02-11T09:49:54.614Z",
+        "attachments": null,
+        "activity": null,
+        "title": null,
+        "iconUri": null,
+        "iconEmoji": null,
+        "mentions": [
+          {
+            "id": botId,
+            "type": "Person",
+            "name": "Bugsnag Bot"
+          }
+        ],
+        "eventType": "PostAdded"
+      }
+    });
+    expect(res.status).toEqual(500);
+    expect(res.body.message).toEqual('Internal server error');
+    rcGroupScope.done();
+  });
+
   it('should send authorize card when bot get authorize command', async () => {
     const rcCardScope = nock(process.env.RINGCENTRAL_SERVER)
       .post(uri => uri.includes(`/restapi/v1.0/glip/chats/${groupId}/adaptive-cards`))