Show timings during index builds (#13)

Motivation ---------- If you are watching a couchbase-index-manager via `kubectl logs` there is a 5 minute timeout if there is no console output. Modifications ------------- Include an ongoing status output every 10 seconds during the index build process. Results ------- Kubernetes logs should no longer timeout waiting for index build.
brantburnett · Mar 26, 2018 · 8a2a45a · 8a2a45a
1 parent 4d80072
commit 8a2a45a
Show file tree

Hide file tree

Showing 2 changed files with 52 additions and 4 deletions.
diff --git a/app/index-manager.js b/app/index-manager.js
@@ -1,5 +1,12 @@
 import {N1qlQuery} from 'couchbase';
 
+const WAIT_TICK_INTERVAL = 10000; // in milliseconds
+
+/**
+ * @callback tickHandler
+ * @param {number} milliseconds Milliseconds since the build wait was started
+ */
+
 /**
  * Manages Couchbase indexes
  *
@@ -69,11 +76,27 @@ export class IndexManager {
 
     /**
      * Monitors building indexes and triggers a Promise when complete
-     * @param {?number} timeoutMilliseconds Null or 0 for no timeout
+     * @param {number} [timeoutMilliseconds] Null or 0 for no timeout
+     * @param {tickHandler} [tickHandler] Tick approx every 10 seconds
+     * @param {object} [thisObj] Object to be this for tickHandler
      * @return {Promise}
      */
-    async waitForIndexBuild(timeoutMilliseconds) {
+    async waitForIndexBuild(timeoutMilliseconds, tickHandler, thisObj) {
         const startTime = Date.now();
+        let lastTick = startTime;
+
+        /** Internal to trigger the tick */
+        function testTick() {
+            const now = Date.now();
+            const interval = now - lastTick;
+            if (interval >= WAIT_TICK_INTERVAL) {
+                lastTick = now;
+
+                if (tickHandler) {
+                    tickHandler.call(thisObj, now - startTime);
+                }
+            }
+        }
 
         while (!timeoutMilliseconds ||
             (Date.now() - startTime < timeoutMilliseconds)) {
@@ -84,7 +107,13 @@ export class IndexManager {
                 return true;
             }
 
+            // Because getIndexes has a latency,
+            // To get more accurate ticks check before and after the wait
+            testTick();
+
             await new Promise((resolve) => setTimeout(resolve, 1000));
+
+            testTick();
         }
 
         // Timeout

diff --git a/app/plan.js b/app/plan.js
@@ -1,4 +1,4 @@
-import {extend} from 'lodash';
+import {extend, padStart} from 'lodash';
 import chalk from 'chalk';
 
 /**
@@ -72,7 +72,8 @@ export class Plan {
             chalk.greenBright('Building indexes...'));
         await this.manager.buildDeferredIndexes();
 
-        if (!await this.manager.waitForIndexBuild(this.options.buildTimeout)) {
+        if (!await this.manager.waitForIndexBuild(
+            this.options.buildTimeout, this.indexBuildTickHandler, this)) {
             this.options.logger.warn(
                 chalk.yellowBright('Some indexes are not online'));
         }
@@ -96,4 +97,22 @@ export class Plan {
     addMutation(...mutations) {
         this.mutations.push(...mutations);
     }
+
+    /**
+     * @private
+     * When running in Kubernetes and attaching to logs, there is a five
+     * minute timeout if there is no console output.  This tick handler
+     * ensures that output continues during that time.
+     *
+     * @param {number} milliseconds Milliseconds since the build wait started
+     */
+    indexBuildTickHandler(milliseconds) {
+        let secs = milliseconds / 1000;
+        let secsPart = padStart(Math.floor(secs % 60).toString(10), 2, '0');
+        let minsPart = Math.floor(secs / 60);
+
+        this.options.logger.log(chalk.greenBright(
+            `Building ${minsPart}m${secsPart}s...`
+        ));
+    }
 }