Fix server crash when client passes malformed JSON (#826)

* Fix server crash when client passes malformed JSON

* Take remarks into account

---------

Co-authored-by: Florent FAYOLLE <[email protected]>

app/server/lib/Client.ts

@@ -526,11 +526,19 @@ export class Client {
     }
   }
 
+  private async _onMessage(message: string): Promise<void> {
+    try {
+      await this._onMessageImpl(message);
+    } catch (err) {
+      this._log.warn(null, 'onMessage error received for message "%s": %s', shortDesc(message), err.stack);
+    }
+  }
+
   /**
    * Processes a request from a client. All requests from a client get a response, at least to
    * indicate success or failure.
    */
-  private async _onMessage(message: string): Promise<void> {
+  private async _onMessageImpl(message: string): Promise<void> {
     const request = JSON.parse(message);
     if (request.beat) {
       // this is a heart beat, to keep the websocket alive.  No need to reply.

test/server/Comm.ts

@@ -188,6 +188,24 @@ describe('Comm', function() {
       ]);
     });
 
+    it('should only log warning for malformed JSON data', async function () {
+      const logMessages  = await testUtils.captureLog('warn', async () => {
+        ws.send('foobar');
+      }, {waitForFirstLog: true});
+      testUtils.assertMatchArray(logMessages, [
+        /^warn: Client.* Unexpected token.*/
+      ]);
+    });
+
+    it('should log warning when null value is passed', async function () {
+      const logMessages  = await testUtils.captureLog('warn', async () => {
+        ws.send('null');
+      }, {waitForFirstLog: true});
+      testUtils.assertMatchArray(logMessages, [
+        /^warn: Client.*Cannot read properties of null*/
+      ]);
+    });
+
     it("should support app-level events correctly", async function() {
       comm!.broadcastMessage('fooType' as any, 'hello');
       comm!.broadcastMessage('barType' as any, 'world');

test/server/testUtils.ts

@@ -126,25 +126,32 @@ export function setTmpLogLevel(level: string, optCaptureFunc?: (level: string, m
  */
 export async function captureLog(
   minLevel: string, callback: (messages: string[]) => void|Promise<void>,
-  options: {timestamp: boolean} = {timestamp: false}
+  options: {timestamp?: boolean, waitForFirstLog?: boolean} = {timestamp: false, waitForFirstLog: false}
 ): Promise<string[]> {
   const messages: string[] = [];
   const prevLogLevel = log.transports.file.level;
   const name = _.uniqueId('CaptureLog');
 
-  function capture(level: string, msg: string, meta: any) {
-    if ((log as any).levels[level] <= (log as any).levels[minLevel]) {  // winston types are off?
-      const timePrefix = options.timestamp ? new Date().toISOString() + ' ' : '';
-      messages.push(`${timePrefix}${level}: ${msg}${meta ? ' ' + serialize(meta) : ''}`);
+  const captureFirstLogPromise = new Promise((resolve) => {
+    function capture(level: string, msg: string, meta: any) {
+      if ((log as any).levels[level] <= (log as any).levels[minLevel]) {  // winston types are off?
+        const timePrefix = options.timestamp ? new Date().toISOString() + ' ' : '';
+        messages.push(`${timePrefix}${level}: ${msg}${meta ? ' ' + serialize(meta) : ''}`);
+        resolve(null);
+      }
     }
-  }
 
-  if (!process.env.VERBOSE) {
-    log.transports.file.level = -1 as any;   // Suppress all log output.
-  }
-  log.add(CaptureTransport as any, { captureFunc: capture, name, level: minLevel});  // types are off.
+    if (!process.env.VERBOSE) {
+      log.transports.file.level = -1 as any;   // Suppress all log output.
+    }
+    log.add(CaptureTransport as any, { captureFunc: capture, name, level: minLevel});  // types are off.
+  });
+
   try {
     await callback(messages);
+    if (options.waitForFirstLog) {
+      await captureFirstLogPromise;
+    }
   } finally {
     log.remove(name);
     log.transports.file.level = prevLogLevel;