fix(metrics): added Redis Latency metric

Author: andris9

lib/consts.js

@@ -155,6 +155,9 @@ module.exports = {
 
     NONCE_BYTES: 16,
 
+    // milliseconds
+    ALLOWED_REDIS_LATENCY: 15,
+
     generateWebhookTable() {
         let entries = [];
 

lib/routes-ui.js

@@ -72,7 +72,8 @@ const {
     DEFAULT_DELIVERY_ATTEMPTS,
     DEFAULT_MAX_BODY_SIZE,
     MAX_FORM_TTL,
-    NONCE_BYTES
+    NONCE_BYTES,
+    ALLOWED_REDIS_LATENCY
 } = consts;
 
 config.api = config.api || {
@@ -835,7 +836,15 @@ function applyRoutes(server, call) {
                     menuDashboard: true,
                     stats,
                     counterList,
-                    hasAccounts
+                    hasAccounts,
+                    redisPing: {
+                        key: 'redisPing',
+                        title: 'Redis Latency',
+                        color: typeof stats.redisPing !== 'number' ? 'warning' : stats.redisPing < ALLOWED_REDIS_LATENCY ? 'success' : 'danger',
+                        icon: 'clock',
+                        comment: 'How many milliseconds does it take to run Redis commands',
+                        value: typeof stats.redisPing !== 'number' ? '\u2013' : humanize.numberFormat(stats.redisPing || 0, 0, '.', ' ')
+                    }
                 },
                 {
                     layout: 'app'

server.js

@@ -378,6 +378,11 @@ const metrics = {
         help: 'Redis uptime in seconds'
     }),
 
+    redisPing: new promClient.Gauge({
+        name: 'redis_latency',
+        help: 'Redis latency in milliseconds'
+    }),
+
     redisRejectedConnectionsTotal: new promClient.Gauge({
         name: 'redis_rejected_connections_total',
         help: 'Number of connections rejected by Redis'
@@ -1212,6 +1217,64 @@ function checkUpgrade() {
     });
 }
 
+// measure Redis ping once in every 10 seconds
+
+let redisPingCounter = [];
+
+function getRedisPing() {
+    if (redisPingCounter.length < 14) {
+        return null;
+    }
+    let entries = redisPingCounter
+        .slice(-34)
+        .map(entry => entry[1])
+        .sort((a, b) => a - b);
+
+    // remove 2 highest and lowest
+    entries.shift();
+    entries.shift();
+    entries.pop();
+    entries.pop();
+
+    let sum = 0;
+    for (let entry of entries) {
+        sum += entry;
+    }
+
+    return Math.round(sum / entries.length);
+}
+
+const REDIS_PING_TIMEOUT = 10 * 1000;
+let redisPingTimer = false;
+const processRedisPing = async () => {
+    try {
+        let startTime = Date.now();
+        await redis.ping();
+        let endTime = Date.now();
+        let duration = endTime - startTime;
+        redisPingCounter.push([endTime, duration]);
+        if (redisPingCounter.length > 300) {
+            redisPingCounter = redisPingCounter.slice(0, 150);
+        }
+        return duration;
+    } catch (err) {
+        logger.error({ msg: 'Failed to run Redis ping', err });
+    }
+};
+
+const redisPingHandler = async () => {
+    await processRedisPing();
+    redisPingTimer = setTimeout(checkRedisPing, REDIS_PING_TIMEOUT);
+    redisPingTimer.unref();
+};
+
+function checkRedisPing() {
+    clearTimeout(redisPingTimer);
+    redisPingHandler().catch(err => {
+        logger.error('Failed to process Redis Ping', err);
+    });
+}
+
 async function updateQueueCounters() {
     metrics.emailengineConfig.set({ version: 'v' + packageData.version }, 1);
     metrics.emailengineConfig.set({ config: 'uvThreadpoolSize' }, Number(process.env.UV_THREADPOOL_SIZE));
@@ -1245,6 +1308,9 @@ async function updateQueueCounters() {
         metrics.redisVersion.set({ version: 'v' + redisInfo.redis_version }, 1);
 
         metrics.redisUptimeInSeconds.set(Number(redisInfo.uptime_in_seconds) || 0);
+
+        metrics.redisPing.set((await processRedisPing()) || 0);
+
         metrics.redisRejectedConnectionsTotal.set(Number(redisInfo.rejected_connections) || 0);
         metrics.redisConfigMaxclients.set(Number(redisInfo.maxclients) || 0);
         metrics.redisConnectedClients.set(Number(redisInfo.connected_clients) || 0);
@@ -1306,7 +1372,7 @@ async function onCommand(worker, message) {
                 }
             }
 
-            return { connections };
+            return { connections, redisPing: await getRedisPing() };
         }
 
         case 'imapWorkerCount': {
@@ -2176,6 +2242,9 @@ startApplication()
         upgradeCheckTimer = setTimeout(checkUpgrade, UPGRADE_CHECK_TIMEOUT);
         upgradeCheckTimer.unref();
 
+        redisPingTimer = setTimeout(checkRedisPing, REDIS_PING_TIMEOUT);
+        redisPingTimer.unref();
+
         queueEvents.notify = new QueueEvents('notify', Object.assign({}, queueConf));
         queueEvents.submit = new QueueEvents('submit', Object.assign({}, queueConf));
         queueEvents.documents = new QueueEvents('documents', Object.assign({}, queueConf));

views/dashboard.hbs

@@ -211,6 +211,27 @@
         </div>
         {{/if}}
 
+        <div class="col-xl-3 col-md-6 mb-4">
+            <div class="card border-left-{{redisPing.color}} shadow">
+                <div class="card-body">
+                    <div class="row no-gutters align-items-center">
+                        <div class="col mr-2">
+                            <div class="text-xs font-weight-bold text-gray-800 text-uppercase mb-1" {{#if
+                                redisPing.comment}}title="{{redisPing.comment}}" data-toggle="tooltip"
+                                data-placement="top" {{/if}} style="cursor: default;">
+                                {{redisPing.title}}</div>
+                            <div class="h5 mb-0 font-weight-bold text-gray-800">
+                                {{redisPing.value}}
+                            </div>
+                        </div>
+                        <div class="col-auto">
+                            <i class="fas fa-{{redisPing.icon}} fa-2x text-gray-300"></i>
+                        </div>
+                    </div>
+                </div>
+            </div>
+        </div>
+
     </div>