performance: parallelize container and openwhisk tasks at startup
diff --git a/src/agentmgr.js b/src/agentmgr.js
index 452e49a..e12e9f7 100644
--- a/src/agentmgr.js
+++ b/src/agentmgr.js
@@ -28,7 +28,6 @@
const fs = require('fs-extra');
const sleep = require('util').promisify(setTimeout);
const debug = require('./debug');
-const prettyBytes = require('pretty-bytes');
const clone = require('clone');
function getAnnotation(action, key) {
@@ -118,10 +117,12 @@
try {
const backup = await getWskActionWithoutCode(this.wsk, backupName);
- if (isAgent(backup)) {
+ if (!backup) {
// backup is also an agent (should not happen)
- // backup is useless, delete it
- // await this.wsk.actions.delete(backupName);
+ throw new Error(`Dang! Agent is already installed and action backup is missing.\n\nPlease redeploy your action first before running wskdebug again.`);
+
+ } else if (isAgent(backup)) {
+ // backup is also an agent (should not happen)
throw new Error(`Dang! Agent is already installed and action backup is broken (${backupName}).\n\nPlease redeploy your action first before running wskdebug again.`);
} else {
@@ -157,8 +158,6 @@
this.actionWithCode = await this.restoreAction();
} else {
this.actionWithCode = await this.wsk.actions.get(this.actionName);
- debug(`fetched action code from openwhisk (${prettyBytes(this.actionWithCode.exec.code.length)})`);
-
}
// extra sanity check
if (isAgent(this.actionWithCode)) {
@@ -168,7 +167,7 @@
return this.actionWithCode;
}
- async installAgent(invoker) {
+ async installAgent(invoker, debugTask) {
this.agentInstalled = true;
let agentName;
@@ -190,7 +189,7 @@
// agent using ngrok for forwarding
agentName = "ngrok";
agentCode = await this.ngrokAgent.getAgent(agentAction);
- debug("started local ngrok proxy");
+ debugTask("started local ngrok proxy");
} else {
this.concurrency = await this.openwhiskSupports("concurrency");
@@ -216,11 +215,13 @@
// create copy in case wskdebug gets killed hard
// do async as this can be slow for larger actions and this is part of the critical startup path
this.createBackup = (async () => {
+ const debugTask = debug.task();
+
await this.wsk.actions.update({
name: backupName,
action: agentAction
});
- debug(`created action backup ${backupName}`);
+ debugTask(`created action backup ${backupName}`);
})();
if (this.argv.verbose) {
@@ -245,7 +246,7 @@
await this.pushAgent(agentAction, agentCode, backupName);
}
}
- debug(`installed agent (${agentName}) in place of ${this.actionName}`);
+ debugTask(`installed agent '${agentName}' in place of ${this.actionName}`);
if (this.argv.verbose) {
console.log(`Agent installed.`);
diff --git a/src/debug.js b/src/debug.js
index 6e4cc49..bbe46f8 100644
--- a/src/debug.js
+++ b/src/debug.js
@@ -19,3 +19,13 @@
// common debug() instance for shared time spent measurments (+millis)
module.exports = require('debug')('wskdebug');
+
+// start a sub debug instance for logging times in parallel promises
+module.exports.task = () => {
+ const debug = require('debug')('wskdebug')
+ // trick to start time measurement from now on without logging an extra line
+ debug.log = () => {};
+ debug();
+ delete debug.log;
+ return debug;
+}
\ No newline at end of file
diff --git a/src/debugger.js b/src/debugger.js
index 91d8d79..2cce15f 100644
--- a/src/debugger.js
+++ b/src/debugger.js
@@ -25,6 +25,7 @@
const { spawnSync } = require('child_process');
const sleep = require('util').promisify(setTimeout);
const debug = require('./debug');
+const prettyBytes = require('pretty-bytes');
const prettyMilliseconds = require('pretty-ms');
/**
@@ -74,26 +75,57 @@
this.invoker = new OpenWhiskInvoker(this.actionName, actionMetadata, this.argv, this.wskProps, this.wsk);
try {
- // run build initially (would be required by starting container)
- if (this.argv.onBuild) {
- console.info("=> Build:", this.argv.onBuild);
- spawnSync(this.argv.onBuild, {shell: true, stdio: "inherit"});
- }
+ // parallelize slower work using promises
- // start container - get it up fast for VSCode to connect within its 10 seconds timeout
- await this.invoker.startContainer();
+ // task 1 - start local container
+ const containerTask = (async () => {
+ const debugTask = debug.task();
+ // run build initially (would be required by starting container)
+ if (this.argv.onBuild) {
+ console.info("=> Build:", this.argv.onBuild);
+ spawnSync(this.argv.onBuild, {shell: true, stdio: "inherit"});
+ }
- debug(`started container: ${this.invoker.name()}`);
+ // start container - get it up fast for VSCode to connect within its 10 seconds timeout
+ await this.invoker.startContainer();
- // get code and /init local container
- const actionWithCode = await this.agentMgr.readActionWithCode();
+ debugTask(`started container: ${this.invoker.name()}`);
+ })();
- await this.invoker.init(actionWithCode);
+ // task 2 - fetch action code from openwhisk
+ const openwhiskTask = (async () => {
+ const debugTask = debug.task();
+ const actionWithCode = await this.agentMgr.readActionWithCode();
- debug("installed action on container (/init)");
+ debugTask(`got action code (${prettyBytes(actionWithCode.exec.code.length)})`);
+ return actionWithCode;
+ })();
- // setup agent in openwhisk
- await this.agentMgr.installAgent(this.invoker);
+ // wait for both tasks 1 & 2
+ const results = await Promise.all([containerTask, openwhiskTask]);
+ const actionWithCode = results[1];
+
+ // parallelize slower work using promises again
+
+ // task 3 - initialize local container with code
+ const initTask = (async () => {
+ const debugTask = debug.task();
+
+ // /init local container
+ await this.invoker.init(actionWithCode);
+
+ debugTask("installed action on container");
+ })();
+
+ // task 4 - install agent in openwhisk
+ const agentTask = (async () => {
+ const debugTask = debug.task();
+
+ // setup agent in openwhisk
+ await this.agentMgr.installAgent(this.invoker, debugTask);
+ })();
+
+ await Promise.all([initTask, agentTask]);
if (this.argv.onStart) {
console.log("On start:", this.argv.onStart);
@@ -115,9 +147,8 @@
if (this.argv.condition) {
console.info(`Condition : ${this.argv.condition}`);
}
- console.info(`Startup : ${prettyMilliseconds(Date.now() - this.startTime)}`)
console.log();
- console.info(`Ready, waiting for activations! Use CTRL+C to exit`);
+ console.info(`Ready for activations. Started in ${prettyMilliseconds(Date.now() - this.startTime)}. Use CTRL+C to exit`);
this.ready = true;
