Improve logging #42

CHANGELOG.md

@@ -1,3 +1,12 @@
+## 5.0.0-next.2
+
+### Changes
+
+* Improve logging from Elastalert ([#42](https://github.com/Karql/elastalert2-server/issues/42))
+** Use dedicated logger for elastalert 
+** Convert multiline log into singleline
+** Remove whitespaces
+
 ## 5.0.0-next.1
 
 ### Changes

TODO.md

@@ -14,6 +14,6 @@
 14) `metadataHandler` fix `getQueryString` -> `(<any>request.query).rule_name)`
 15) `scripts/replace_templates.sh` probably not needed
 16) Better error handling and documentation - for now global error handling in `elastalert_server.ts` https://tsoa-community.github.io/docs/error-handling.html#setting-up-error-handling
-17) Logging requst change RouteLogger to morgan (https://rsbh.dev/blog/rest-api-with-express-typescript)
+17) Logging requst change RouteLogger to ~~morgan (https://rsbh.dev/blog/rest-api-with-express-typescript)~~ bunyan-middleware (https://www.npmjs.com/package/bunyan-middleware)
 18) Split logic form metadata.controller.ts to metadata.service.ts 
 19) Migrate latest fixes from https://github.com/johnsusek/elastalert-server

package.json

@@ -1,6 +1,6 @@
 {
   "name": "elastalert2-server",
-  "version": "5.0.0-next.1",
+  "version": "5.0.0-next.2",
   "description": "A server that runs ElastAlert2 and exposes REST API's for manipulating rules and alerts.",
   "license": "MIT",
   "main": "index.js",

src/common/logger/bunyan_instance.ts

@@ -1,7 +1,12 @@
 import bunyan from 'bunyan';
 
-const logger = bunyan.createLogger({
-  name: 'elastalert-server'
-});
+const logger = {
+  ElastalertServer: bunyan.createLogger({
+    name: 'elastalert-server'
+  }),
+  Elastalert: bunyan.createLogger({
+    name: 'elastalert'
+  })
+}
 
 export default logger;

src/common/logger/index.ts

@@ -2,24 +2,34 @@ import bunyan from './bunyan_instance';
 
 export default class Logger {
   private serviceName: string;
+  private loggerType: "ElastalertServer" | "Elastalert";
 
-  constructor (serviceName: string) {
+  constructor (serviceName: string, loggerType: "ElastalertServer" | "Elastalert" = "ElastalertServer") {
     this.serviceName = serviceName;
+    this.loggerType = loggerType;
+  }
+
+  debug (...messages: any[]) {
+    this.getLogger().debug(this.serviceName + ': ', ...messages);
   }
 
   info (...messages: any[]) {
-    bunyan.info(this.serviceName + ': ', ...messages);
+    this.getLogger().info(this.serviceName + ': ', ...messages);
   }
 
   warn (...messages: any[]) {
-    bunyan.warn(this.serviceName + ': ', ...messages);
+    this.getLogger().warn(this.serviceName + ': ', ...messages);
   }
 
   error (...messages: any[]) {
-    bunyan.error(this.serviceName + ': ', ...messages);
+    this.getLogger().error(this.serviceName + ': ', ...messages);
   }
 
-  debug (...messages: any[]) {
-    bunyan.debug(this.serviceName + ': ', ...messages);
+  fatal (...messages: any[]) {
+    this.getLogger().fatal(this.serviceName + ': ', ...messages);
+  }
+
+  private getLogger() {
+    return bunyan[this.loggerType];
   }
 }

src/services/process.service.ts

@@ -3,13 +3,17 @@ import config from '../common/config';
 import Logger from '../common/logger';
 import { Status } from '../common/status.model';
 
-let logger = new Logger('ProcessService');
+const logger = new Logger('ProcessService');
+
+const ElastalertSplitLogsRegexp = /(?<level>DEBUG|INFO|WARNING|ERROR|CRITICAL):(?<type>\S+?):(?<message>.*?)(?=(?:(?:DEBUG|INFO|WARNING|ERROR|CRITICAL):\S+:)|$)/sg;
+const ElastalertCleanMessageRegexp = /\n|\s{2,}/g;
+const ElastalertLoggers: { [Key: string]: Logger } = {};
 
 export default class ProcessService {
   private _onExitCallbacks: {(): void;}[];
   private _status: Status;
   private _process: ChildProcessWithoutNullStreams | null;
-
+  
   constructor() {
     this._onExitCallbacks = [];
     this._status = Status.IDLE;
@@ -52,11 +56,12 @@ export default class ProcessService {
     });
 
     // Redirect stdin/stderr to logger
+    // create_index does not use logger
     if (indexCreate.stdout && indexCreate.stdout.toString() !== '') {
-      logger.info(indexCreate.stdout.toString());
+      this.logElastalert("INFO", "create_index", indexCreate.stdout.toString())
     }
     if (indexCreate.stderr && indexCreate.stderr.toString() !== '') {
-      logger.error(indexCreate.stderr.toString());
+      this.logElastalert("ERROR", "create_index", indexCreate.stderr.toString())
     }
 
     // Set listeners for index create exit
@@ -109,10 +114,10 @@ export default class ProcessService {
 
     // Redirect stdin/stderr to logger
     this._process.stdout.on('data', (data) => {
-      logger.info(data.toString());
+      this.processElastalertLogs(data.toString());
     });
     this._process.stderr.on('data', (data) => {
-      logger.error(data.toString());
+      this.processElastalertLogs(data.toString());
     });
 
     // Set listeners for ElastAlert exit
@@ -155,4 +160,70 @@ export default class ProcessService {
       logger.info('ElastAlert is not running');
     }
   }
-}
+
+  private getElastalertLogger(type: string): Logger {
+    if (ElastalertLoggers[type] === undefined) {
+      ElastalertLoggers[type] = new Logger(type, "Elastalert");
+    }
+
+    return ElastalertLoggers[type];
+  }
+
+  public processElastalertLogs(logs: string) {
+    if (logs == null || logs.trim() === '') {
+      return;
+    }
+
+    let matches = logs.matchAll(ElastalertSplitLogsRegexp);
+    let anyMatch = false;
+
+    for (const match of matches) {
+      if (match.groups === undefined) {
+        break;
+      }
+
+      let level = match.groups['level'];
+      let type = match.groups['type'];
+      let msg = match.groups['message'];
+
+      this.logElastalert(level, type, msg);
+      anyMatch = true;
+    }
+
+    if (!anyMatch) {
+      logger.warn(`No matches while process elastalert log: ${logs}`);
+    }
+  }
+
+  private logElastalert(level: string, type: string, msg: string) {
+    let elastalertLogger = this.getElastalertLogger(type);
+    msg = msg.trim();
+    msg = msg.replace(ElastalertCleanMessageRegexp, ' ');
+
+    switch (level) {
+        case "DEBUG": {
+          elastalertLogger.debug(msg);
+          break;
+        } 
+        case "INFO": {
+          elastalertLogger.info(msg);
+          break;
+        }
+        case "WARNING": {
+          elastalertLogger.warn(msg);
+        }
+        case "ERROR": {
+          elastalertLogger.error(msg);
+          break;          
+        }
+        case "CRITICAL": {
+          elastalertLogger.fatal(msg);
+          break;
+        }
+        default: {
+          elastalertLogger.info(msg);
+          break;
+        }
+    }
+  }
+}

tsconfig.json

@@ -4,9 +4,9 @@
 
     /* Basic Options */
     // "incremental": true,                         /* Enable incremental compilation */
-    "target": "es5",                                /* Specify ECMAScript target version: 'ES3' (default), 'ES5', 'ES2015', 'ES2016', 'ES2017', 'ES2018', 'ES2019', 'ES2020', or 'ESNEXT'. */
+    "target": "ES2015",                             /* Specify ECMAScript target version: 'ES3' (default), 'ES5', 'ES2015', 'ES2016', 'ES2017', 'ES2018', 'ES2019', 'ES2020', or 'ESNEXT'. */
     "module": "commonjs",                           /* Specify module code generation: 'none', 'commonjs', 'amd', 'system', 'umd', 'es2015', 'es2020', or 'ESNext'. */
-    // "lib": [],                                   /* Specify library files to be included in the compilation. */
+    "lib": ["es2020.string"],                       /* Specify library files to be included in the compilation. */
     "allowJs": false,                             /* Allow javascript files to be compiled. */
     // "checkJs": true,                             /* Report errors in .js files. */
     // "jsx": "preserve",                           /* Specify JSX code generation: 'preserve', 'react-native', 'react', 'react-jsx' or 'react-jsxdev'. */