diff --git a/app/server/lib/Client.ts b/app/server/lib/Client.ts index e78ef3d934..359f302084 100644 --- a/app/server/lib/Client.ts +++ b/app/server/lib/Client.ts @@ -526,11 +526,19 @@ export class Client { } } + private async _onMessage(message: string): Promise { + 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 { + private async _onMessageImpl(message: string): Promise { const request = JSON.parse(message); if (request.beat) { // this is a heart beat, to keep the websocket alive. No need to reply. diff --git a/test/server/Comm.ts b/test/server/Comm.ts index 3d95dffe5d..15ecc81732 100644 --- a/test/server/Comm.ts +++ b/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'); diff --git a/test/server/testUtils.ts b/test/server/testUtils.ts index 3f0a5cb678..a394a00576 100644 --- a/test/server/testUtils.ts +++ b/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, - options: {timestamp: boolean} = {timestamp: false} + options: {timestamp?: boolean, waitForFirstLog?: boolean} = {timestamp: false, waitForFirstLog: false} ): Promise { 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;