Merge pull request #3182 from huridocs/error_message_multitenant

[HOTFIX] formatMessage takes into account current tenant

app/api/config.ts

@@ -23,6 +23,7 @@ export const config = {
   multiTenant: process.env.MULTI_TENANT || false,
   clusterMode: CLUSTER_MODE,
   defaultTenant: <Tenant>{
+    name: 'default',
     dbName: process.env.DATABASE_NAME || 'uwazi_development',
     indexName: process.env.INDEX_NAME || 'uwazi_development',
     uploadedDocuments: UPLOADS_FOLDER || `${rootPath}/uploaded_documents/`,

app/api/log/errorLog.js

@@ -15,18 +15,19 @@ const createFileTransport = () =>
     format: winston.format.combine(winston.format.timestamp(), formatter),
   });
 
-const consoleTransport = new winston.transports.Console({
-  handleExceptions: true,
-  level: 'error',
-  format: winston.format.combine(winston.format.timestamp(), formatter),
-});
+const createConsoleTransport = () =>
+  new winston.transports.Console({
+    handleExceptions: true,
+    level: 'error',
+    format: winston.format.combine(winston.format.timestamp(), formatter),
+  });
 
 export const createErrorLog = () => {
   DATABASE_NAME = process.env.DATABASE_NAME ? process.env.DATABASE_NAME : 'localhost';
   LOGS_DIR = process.env.LOGS_DIR ? process.env.LOGS_DIR : './log';
 
   const logger = winston.createLogger({
-    transports: [createFileTransport(), consoleTransport],
+    transports: [createFileTransport(), createConsoleTransport()],
   });
 
   logger.closeGraylog = (cb = () => {}) => {

app/api/log/formatMessage.js

@@ -1,7 +1,14 @@
+import { tenants } from 'api/tenants';
+import { config } from 'api/config';
+
 export default function formatMessage(info, instanceName) {
   const message = info.message && info.message.join ? info.message.join('\n') : info.message;
 
-  const result = `${info.timestamp} [${instanceName}] ${message}`;
+  let tenantName = instanceName;
+  if (info.shouldBeMultiTenantContext) {
+    const tenant = tenants.current();
+    tenantName = tenant.name === config.defaultTenant.name ? instanceName : tenant.name;
+  }
 
-  return result;
+  return `${info.timestamp} [${tenantName}] ${message}`;
 }

app/api/log/specs/GrayLogTransport.spec.js

@@ -1,3 +1,4 @@
+import { tenants } from 'api/tenants';
 import GrayLogTransport from '../GrayLogTransport';
 
 describe('GrayLogTransport', () => {
@@ -10,13 +11,16 @@ describe('GrayLogTransport', () => {
     expect(aTransport.graylog.constructor.name).toBe('graylog');
   });
 
-  it('should pass log call to graylog2 instance', () => {
+  it('should pass log call to graylog2 instance', async () => {
     const aTransport = new GrayLogTransport({
       instance_name: 'some_name',
     });
 
     spyOn(aTransport.graylog, 'log');
-    aTransport.log('message', () => {});
+
+    await tenants.run(async () => {
+      aTransport.log('message', () => {});
+    });
 
     expect(aTransport.graylog.log).toHaveBeenCalled();
   });

app/api/log/specs/errorLog.spec.js

@@ -1,3 +1,4 @@
+import { tenants } from 'api/tenants';
 import { createErrorLog } from '../errorLog';
 
 describe('errorLog', () => {
@@ -9,47 +10,66 @@ describe('errorLog', () => {
     expect(anErrorLog.transports.length).toBe(2);
   });
 
-  it('should call 2 transports with instance name and message', () => {
+  it('should call 2 transports with instanceName and message', () => {
     const anErrorLog = createErrorLog();
 
     spyOn(anErrorLog.transports[0], 'log');
     spyOn(anErrorLog.transports[1], 'log');
 
     anErrorLog.error('a message');
 
-    let fileArgs = anErrorLog.transports[0].log.calls.mostRecent().args[0];
-    fileArgs = Object.getOwnPropertySymbols(fileArgs).map(s => fileArgs[s]);
+    const fileArgs = anErrorLog.transports[0].log.calls.mostRecent().args[0];
+    expect(fileArgs[Symbol.for('message')]).toContain('[localhost] a message');
 
-    expect(fileArgs[1]).toContain('a message');
-    expect(fileArgs[1]).toContain('[localhost]');
+    const consoleArgs = anErrorLog.transports[1].log.calls.mostRecent().args[0];
+    expect(consoleArgs[Symbol.for('message')]).toContain('[localhost] a message');
+  });
+
+  describe('when passing multitenant flag', () => {
+    it('should call 2 transports with tenant name and message', async () => {
+      const anErrorLog = createErrorLog();
+
+      spyOn(anErrorLog.transports[0], 'log');
+      spyOn(anErrorLog.transports[1], 'log');
+
+      tenants.add({ name: 'tenant' });
 
-    let consoleArgs = anErrorLog.transports[1].log.calls.mostRecent().args[0];
-    consoleArgs = Object.getOwnPropertySymbols(consoleArgs).map(s => consoleArgs[s]);
+      await tenants.run(async () => {
+        anErrorLog.error('a message', { shouldBeMultiTenantContext: true });
+      }, 'tenant');
 
-    expect(consoleArgs[1]).toContain('a message');
-    expect(consoleArgs[1]).toContain('[localhost]');
+      const fileArgs = anErrorLog.transports[0].log.calls.mostRecent().args[0];
+      expect(fileArgs[Symbol.for('message')]).toContain('[tenant] a message');
+
+      const consoleArgs = anErrorLog.transports[1].log.calls.mostRecent().args[0];
+      expect(consoleArgs[Symbol.for('message')]).toContain('[tenant] a message');
+    });
   });
 
-  it('should overwritte logs path from env vars', () => {
+  it('should overwritte logs path from env vars', async () => {
     process.env.LOGS_DIR = './some_dir';
 
     const anErrorLog = createErrorLog();
 
     expect(anErrorLog.transports[0].dirname).toBe('./some_dir');
     expect(anErrorLog.transports[0].filename).toBe('error.log');
 
-    anErrorLog.error('a message');
+    await tenants.run(async () => {
+      anErrorLog.error('a message');
+    });
   });
 
-  it('should overwritte instance name from env vars', () => {
+  it('should overwritte instance name from env vars', async () => {
     process.env.DATABASE_NAME = 'my_instance';
 
     const anErrorLog = createErrorLog();
 
     spyOn(anErrorLog.transports[0], 'log');
     spyOn(anErrorLog.transports[1], 'log');
 
-    anErrorLog.error('a message');
+    await tenants.run(async () => {
+      anErrorLog.error('a message');
+    });
 
     let calledArgs = anErrorLog.transports[0].log.calls.mostRecent().args[0];
     calledArgs = Object.getOwnPropertySymbols(calledArgs).map(s => calledArgs[s]);

app/api/socketio/setupSockets.ts

@@ -27,7 +27,7 @@ const setupSockets = (server: Server, app: Application) => {
   const io: SocketIoServer = socketIo(server);
 
   io.on('connection', socket => {
-    socket.join(socket.request.headers.tenant || tenants.defaultTenantName);
+    socket.join(socket.request.headers.tenant || config.defaultTenant.name);
   });
 
   io.emitToCurrentTenant = (event, ...args) => {

app/api/socketio/specs/socketClusterMode.spec.ts

@@ -92,15 +92,21 @@ describe('socket middlewares setup', () => {
     return events;
   };
 
-  const requestTestRoute = async (tenant: string = '') =>
-    request(server)
-      .get('/api/test')
-      .set('tenant', tenant)
-      .expect(response => {
-        if (response.status !== 200) {
-          throw new Error(response.text);
-        }
+  const requestTestRoute = async (tenant?: string) => {
+    const req = request(server).get('/api/test');
+
+    if (tenant) {
+      req.set('tenant', tenant).catch(e => {
+        throw e;
       });
+    }
+
+    return req.expect(response => {
+      if (response.status !== 200) {
+        throw new Error(response.text);
+      }
+    });
+  };
 
   describe('when performing a request to tenant1', () => {
     it('should only emit socket events to tenant1 sockets', async () => {

app/api/tenants/index.ts

@@ -0,0 +1 @@
+export { tenants } from './tenantContext';

app/api/tenants/tenantContext.ts

@@ -16,13 +16,11 @@ export type Tenant = {
 class Tenants {
   storage = new AsyncLocalStorage<string>();
 
-  defaultTenantName = 'default';
-
   tenants: { [k: string]: Tenant };
 
   constructor() {
     this.tenants = {
-      [this.defaultTenantName]: { name: this.defaultTenantName, ...config.defaultTenant },
+      [config.defaultTenant.name]: config.defaultTenant,
     };
   }
 
@@ -42,9 +40,12 @@ class Tenants {
     });
   }
 
-  async run(cb: () => Promise<void>, tenantName?: string): Promise<void> {
+  async run(
+    cb: () => Promise<void>,
+    tenantName: string = config.defaultTenant.name
+  ): Promise<void> {
     return new Promise((resolve, reject) => {
-      this.storage.run(tenantName || this.defaultTenantName, () => {
+      this.storage.run(tenantName, () => {
         cb()
           .then(resolve)
           .catch(reject);

app/api/utils/handleError.js

@@ -79,7 +79,7 @@ const prettifyError = (error, { req = {}, uncaught = false } = {}) => {
   return result;
 };
 
-export default (_error, { req = {}, uncaught = false } = {}) => {
+export default (_error, { req = undefined, uncaught = false } = {}) => {
   const error = _error || new Error('undefined error occurred');
   const responseToClientError = error.json;
 
@@ -89,8 +89,13 @@ export default (_error, { req = {}, uncaught = false } = {}) => {
 
   const result = prettifyError(error, { req, uncaught });
 
+  let errorOptions = {};
+  if (req) {
+    errorOptions.shouldBeMultiTenantContext = true;
+  }
+
   if (result.code === 500) {
-    errorLog.error(result.prettyMessage);
+    errorLog.error(result.prettyMessage, errorOptions);
   } else if (result.code === 400) {
     debugLog.debug(result.prettyMessage);
   }

app/api/utils/specs/error_handling_middleware.spec.js

@@ -27,20 +27,23 @@ describe('Error handling middleware', () => {
     req.originalUrl = 'url';
     middleware(error, req, res, next);
 
-    expect(errorLog.error).toHaveBeenCalledWith('\nurl: url\nerror');
+    expect(errorLog.error).toHaveBeenCalledWith('\nurl: url\nerror', {
+      shouldBeMultiTenantContext: true,
+    });
   });
 
   it('should log the error body', () => {
     const error = { message: 'error', code: 500 };
     req.body = { param: 'value', param2: 'value2' };
     middleware(error, req, res, next);
     expect(errorLog.error).toHaveBeenCalledWith(
-      `\nbody: ${JSON.stringify(req.body, null, ' ')}\nerror`
+      `\nbody: ${JSON.stringify(req.body, null, ' ')}\nerror`,
+      { shouldBeMultiTenantContext: true }
     );
 
     req.body = {};
     middleware(error, req, res, next);
-    expect(errorLog.error).toHaveBeenCalledWith('\nerror');
+    expect(errorLog.error).toHaveBeenCalledWith('\nerror', { shouldBeMultiTenantContext: true });
   });
 
   it('should log the error query', () => {
@@ -49,7 +52,8 @@ describe('Error handling middleware', () => {
     middleware(error, req, res, next);
 
     expect(errorLog.error).toHaveBeenCalledWith(
-      `\nquery: ${JSON.stringify(req.query, null, ' ')}\nerror`
+      `\nquery: ${JSON.stringify(req.query, null, ' ')}\nerror`,
+      { shouldBeMultiTenantContext: true }
     );
   });
 });

app/api/utils/specs/handleError.spec.js

@@ -23,7 +23,7 @@ describe('handleError', () => {
       const error = new Error('error');
       handleError(error);
 
-      expect(errorLog.error).toHaveBeenCalledWith(`\n${error.stack}`);
+      expect(errorLog.error).toHaveBeenCalledWith(`\n${error.stack}`, {});
     });
   });
 
@@ -38,7 +38,7 @@ describe('handleError', () => {
       expect(errorLog.error).not.toHaveBeenCalled();
 
       handleError(createError('test error'));
-      expect(errorLog.error).toHaveBeenCalledWith('\ntest error');
+      expect(errorLog.error).toHaveBeenCalledWith('\ntest error', {});
     });
   });
 

app/server.js

@@ -45,7 +45,6 @@ const uncaughtError = error => {
 
 process.on('unhandledRejection', uncaughtError);
 process.on('uncaughtException', uncaughtError);
-http.on('error', handleError);
 
 const oneYear = 31557600;
 

package.json

@@ -1,6 +1,6 @@
 {
   "name": "uwazi",
-  "version": "1.8.0",
+  "version": "1.8.1",
   "description": "Uwazi is a free, open-source solution for organising, analysing and publishing your documents.",
   "main": "server.js",
   "repository": {