Merge pull request #901 from mountaindude/889

889

src/config/log_appender_xml/engine/LocalLogConfig.xml

@@ -1,5 +1,32 @@
 <?xml version="1.0" encoding="UTF-8"?>
 <configuration>
+    <!-- Appender to capture Qix performance metrics, then send it to Butler SOS -->
+    <appender name="QixPerf" type="log4net.Appender.UdpAppender">
+        <param name="threshold" value="info" />
+        <param name="remoteAddress" value="FQDN or IP of server where Butler SOS is running" />
+        <param name="remotePort" value="9996" />
+        <param name="encoding" value="utf-8" />
+        <layout type="log4net.Layout.PatternLayout">
+            <converter>
+                <param name="name" value="rownum" />
+                <param name="type" value="Qlik.Sense.Logging.log4net.Layout.Pattern.CounterPatternConverter" /> 
+            </converter> 
+            <converter>
+                <param name="name" value="hostname" />
+                <param name="type" value="Qlik.Sense.Logging.log4net.Layout.Pattern.HostNamePatternConverter" />
+            </converter>
+            <converter>
+                  <param name="name" value="longIso8601date" /> 
+                  <param name="type" value="Qlik.Sense.Logging.log4net.Layout.Pattern.Iso8601TimeOffsetPatternConverter" /> 
+            </converter>
+            <converter> 
+                  <param name="name" value="user" /> 
+                  <param name="type" value="Qlik.Sense.Logging.log4net.Layout.Pattern.ServiceUserNameCachedPatternConverter" /> 
+            </converter> 
+            <param name="conversionpattern" value="/qseow-qix-perf/;%rownum{9999};%longIso8601date;%date;%level;%hostname;%logger;%user;%property{ProxySessionId};%property{ActiveUserDirectory};%property{ActiveUserId};%property{EngineTimestamp};%property{SessionId};%property{DocId};%property{RequestId};%property{Method};%property{ProcessTime};%property{WorkTime};%property{LockTime};%property{ValidateTime};%property{TraverseTime};%property{Handle};%property{ObjectId};%property{NetRAM};%property{PeakRAM};%property{ObjectType}" />
+        </layout>
+    </appender>
+
     <!-- Generic appender for detecting warnings and errors -->
     <appender name="LogEvent" type="log4net.Appender.UdpAppender">
         <param name="threshold" value="warn" />
@@ -32,6 +59,11 @@
     </appender>
 
 
+    <!-- Send Qix performance info to Butler SOS -->
+    <logger name="QixPerformance.Engine.Engine">
+        <appender-ref ref="QixPerf" />
+    </logger>
+
     <!-- Send UDP message to Butler SOS on warnings and errors -->
     <logger name="Performance.Engine">
         <appender-ref ref="LogEvent" />

src/globals.js

@@ -333,7 +333,7 @@ class Settings {
         }
 
         // ------------------------------------
-        // Track user events and log events
+        // Track user events and log event counts
         if (this.config.get('Butler-SOS.qlikSenseEvents.eventCount.enable') === true) {
             this.udpEvents = new UdpEvents(this.logger);
         } else {
@@ -410,6 +410,14 @@ class Settings {
         tagValuesLogEvent.push('windows_user');
         tagValuesLogEvent.push('engine_exe_version');
 
+        // Performance log event tags
+        tagValuesLogEvent.push('method');
+        tagValuesLogEvent.push('object_type');
+        tagValuesLogEvent.push('proxy_session_id');
+        tagValuesLogEvent.push('session_id');
+        tagValuesLogEvent.push('event_activity_source');
+        tagValuesLogEvent.push('object_id');
+
         // Check if there are any extra log event tags in the config file
         if (
             this.config.has('Butler-SOS.logEvents.tags') &&
@@ -615,6 +623,16 @@ class Settings {
                                 context: Influx.FieldType.STRING,
                                 session_id: Influx.FieldType.STRING,
                                 raw_event: Influx.FieldType.STRING,
+
+                                // engine performance fields
+                                process_time: Influx.FieldType.FLOAT,
+                                work_time: Influx.FieldType.FLOAT,
+                                lock_time: Influx.FieldType.FLOAT,
+                                validate_time: Influx.FieldType.FLOAT,
+                                traverse_time: Influx.FieldType.FLOAT,
+                                handle: Influx.FieldType.INTEGER,
+                                net_ram: Influx.FieldType.INTEGER,
+                                peak_ram: Influx.FieldType.INTEGER,
                             },
                             tags: tagValuesLogEvent,
                         },
@@ -740,7 +758,7 @@ class Settings {
             const dbName = this.config.get('Butler-SOS.influxdbConfig.v1Config.dbName');
 
             if (
-                influx &&
+                this.influx &&
                 this.config.get('Butler-SOS.influxdbConfig.enable') === true &&
                 dbName?.length > 0
             ) {

src/lib/config-obfuscate.js

@@ -22,11 +22,31 @@ function configObfuscate(config) {
             accountId: element.accountId.toString().substring(0, 3) + '*'.repeat(10),
         }));
 
-        // Obfuscate Butler-SOS.iuserEvents.udpServerConfig.serverHost, keep first 3 chars, mask the rest with *
+        // Obfuscate Butler-SOS.userEvents.udpServerConfig.serverHost, keep first 3 chars, mask the rest with *
         obfuscatedConfig['Butler-SOS'].userEvents.udpServerConfig.serverHost =
             obfuscatedConfig['Butler-SOS'].userEvents.udpServerConfig.serverHost.substring(0, 3) +
             '*'.repeat(10);
 
+        // Obfuscate Butler-SOS.logEvents.enginePerformanceMonitor.monitorFilter.appSpecific.app[].include[], which is an array of objects, each with the following properties:
+        // - appId: keep first 5 chars, mask the rest with *
+        // - appName: keep first 5 chars, mask the rest with *
+        obfuscatedConfig[
+            'Butler-SOS'
+        ].logEvents.enginePerformanceMonitor.monitorFilter.appSpecific.app.forEach((element) => {
+            element.include = element.include.map((includeElement) => {
+                if (includeElement.appId) {
+                    includeElement.appId = includeElement.appId.substring(0, 5) + '*'.repeat(10);
+                }
+
+                if (includeElement.appName) {
+                    includeElement.appName =
+                        includeElement.appName.substring(0, 5) + '*'.repeat(10);
+                }
+
+                return includeElement;
+            });
+        });
+
         // Obfuscate Butler-SOS.iuserEvents.sendToMQTT.postTo.everythingTopic.topic, keep first 10 chars, mask the rest with *
         obfuscatedConfig['Butler-SOS'].userEvents.sendToMQTT.postTo.everythingTopic.topic =
             obfuscatedConfig[

src/lib/post-to-influxdb.js

@@ -993,16 +993,16 @@ export async function postLogEventToInfluxdb(msg) {
                     };
                 } else if (msg.source === 'qseow-qix-perf') {
                     tags = {
-                        host: msg.host,
-                        level: msg.level,
-                        source: msg.source,
-                        log_row: msg.log_row,
-                        subsystem: msg.subsystem,
-                        method: msg.method,
-                        object_type: msg.object_type,
-                        proxy_session_id: msg.proxy_session_id,
-                        session_id: msg.session_id,
-                        event_activity_source: msg.event_activity_source,
+                        host: msg.host?.length > 0 ? msg.host : '<Unknown>',
+                        level: msg.level?.length > 0 ? msg.level : '<Unknown>',
+                        source: msg.source?.length > 0 ? msg.source : '<Unknown>',
+                        log_row: msg.log_row?.length > 0 ? msg.log_row : '-1',
+                        subsystem: msg.subsystem?.length > 0 ? msg.subsystem : '<Unknown>',
+                        method: msg.method?.length > 0 ? msg.method : '<Unknown>',
+                        object_type: msg.object_type?.length > 0 ? msg.object_type : '<Unknown>',
+                        proxy_session_id: msg.proxy_session_id?.length > 0 ? msg.proxy_session_id : '-1',
+                        session_id: msg.session_id?.length > 0 ? msg.session_id : '-1',
+                        event_activity_source: msg.event_activity_source?.length > 0 ? msg.event_activity_source : '<Unknown>',
                     };
 
                     // Tags that are empty in some cases. Only add if they are non-empty
@@ -1321,6 +1321,13 @@ export async function storeEventCountInfluxDB() {
     const logEvents = await globals.udpEvents.getLogEvents();
     const userEvents = await globals.udpEvents.getUserEvents();
 
+    // Debug
+    globals.logger.debug(`EVENT COUNT INFLUXDB: Log events: ${JSON.stringify(logEvents, null, 2)}`);
+
+    globals.logger.debug(
+        `EVENT COUNT INFLUXDB: User events: ${JSON.stringify(userEvents, null, 2)}`
+    );
+
     // InfluxDB 1.x
     if (globals.config.get('Butler-SOS.influxdbConfig.version') === 1) {
         const points = [];
@@ -1337,7 +1344,7 @@ export async function storeEventCountInfluxDB() {
                 measurement: measurementName,
                 tags: {
                     event_type: 'log',
-                    event_name: event.eventName,
+                    source: event.source,
                     host: event.host,
                     subsystem: event.subsystem,
                 },
@@ -1371,7 +1378,7 @@ export async function storeEventCountInfluxDB() {
                 measurement: measurementName,
                 tags: {
                     event_type: 'user',
-                    event_name: event.eventName,
+                    source: event.source,
                     host: event.host,
                     subsystem: event.subsystem,
                 },
@@ -1451,7 +1458,7 @@ export async function storeEventCountInfluxDB() {
             for (const event of logEvents) {
                 const point = new Point(measurementName)
                     .tag('event_type', 'log')
-                    .tag('event_name', event.eventName)
+                    .tag('source', event.source)
                     .tag('host', event.host)
                     .tag('subsystem', event.subsystem)
                     .intField('counter', event.counter);
@@ -1480,7 +1487,7 @@ export async function storeEventCountInfluxDB() {
             for (const event of userEvents) {
                 const point = new Point(measurementName)
                     .tag('event_type', 'user')
-                    .tag('event_name', event.eventName)
+                    .tag('source', event.source)
                     .tag('host', event.host)
                     .tag('subsystem', event.subsystem)
                     .intField('counter', event.counter);
@@ -1527,6 +1534,15 @@ export async function storeRejectedEventCountInfluxDB() {
     // Get array of rejected log events
     const rejectedLogEvents = await globals.rejectedEvents.getRejectedLogEvents();
 
+    // Debug
+    globals.logger.debug(
+        `REJECTED EVENT COUNT INFLUXDB: Rejected log events: ${JSON.stringify(
+            rejectedLogEvents,
+            null,
+            2
+        )}`
+    );
+
     // InfluxDB 1.x
     if (globals.config.get('Butler-SOS.influxdbConfig.version') === 1) {
         const points = [];
@@ -1541,22 +1557,22 @@ export async function storeRejectedEventCountInfluxDB() {
         //
         // Use counter and process_time as fields
         for (const event of rejectedLogEvents) {
-            if (event.eventName === 'qseow-qix-perf') {
-                // For each unique combination of eventName, appId, appName, .method and objectType,
+            if (event.source === 'qseow-qix-perf') {
+                // For each unique combination of source, appId, appName, .method and objectType,
                 // write the counter and processTime properties to InfluxDB
                 //
-                // Use eventName, appId,appName,  method and objectType as tags
+                // Use source, appId,appName,  method and objectType as tags
 
                 const tags = {
-                    event_name: event.eventName,
+                    source: event.source,
                     app_id: event.appId,
                     method: event.method,
                     object_type: event.objectType,
                 };
 
                 // Tags that are empty in some cases. Only add if they are non-empty
-                if (msg?.app_name?.length > 0) {
-                    tags.app_name = msg.app_name;
+                if (event?.appName?.length > 0) {
+                    tags.app_name = event.appName;
                     tags.app_name_set = 'true';
                 } else {
                     tags.app_name_set = 'false';
@@ -1598,7 +1614,7 @@ export async function storeRejectedEventCountInfluxDB() {
                 const point = {
                     measurement: measurementName,
                     tags: {
-                        event_name: event.eventName,
+                        source: event.source,
                     },
                     fields: {
                         counter: event.counter,
@@ -1664,13 +1680,13 @@ export async function storeRejectedEventCountInfluxDB() {
             //
             // Use counter and process_time as fields
             for (const event of rejectedLogEvents) {
-                if (event.eventName === 'qseow-qix-perf') {
-                    // For each unique combination of eventName, appId, appName, .method and objectType,
+                if (event.source === 'qseow-qix-perf') {
+                    // For each unique combination of source, appId, appName, .method and objectType,
                     // write the counter and processTime properties to InfluxDB
                     //
-                    // Use eventName, appId,appName,  method and objectType as tags
+                    // Use source, appId,appName,  method and objectType as tags
                     let point = new Point(measurementName)
-                        .tag('event_name', event.eventName)
+                        .tag('source', event.source)
                         .tag('app_id', event.appId)
                         .tag('method', event.method)
                         .tag('object_type', event.objectType)
@@ -1706,7 +1722,7 @@ export async function storeRejectedEventCountInfluxDB() {
                     points.push(point);
                 } else {
                     let point = new Point(measurementName)
-                        .tag('event_name', event.eventName)
+                        .tag('source', event.source)
                         .intField('counter', event.counter);
 
                     points.push(point);