This is an automated email from the ASF dual-hosted git repository. alexkli pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/openwhisk-wskdebug.git
commit ff21682af597785596990e5790e81ecef635eb4e Author: Alexander Klimetschek <[email protected]> AuthorDate: Mon Apr 13 22:09:16 2020 -0700 performance: parallelize container and openwhisk tasks at startup --- src/agentmgr.js | 21 ++++++++++--------- src/debug.js | 10 +++++++++ src/debugger.js | 63 ++++++++++++++++++++++++++++++++++++++++++--------------- 3 files changed, 68 insertions(+), 26 deletions(-) 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 @@ try { 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 @@ class AgentMgr { try { const backup = await getWskActionWithoutCode(this.wsk, backupName); - if (isAgent(backup)) { + if (!backup) { + // backup is also an agent (should not happen) + 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) - // backup is useless, delete it - // await this.wsk.actions.delete(backupName); 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 @@ class AgentMgr { 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 @@ class AgentMgr { return this.actionWithCode; } - async installAgent(invoker) { + async installAgent(invoker, debugTask) { this.agentInstalled = true; let agentName; @@ -190,7 +189,7 @@ class AgentMgr { // 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 @@ class AgentMgr { // 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 @@ class AgentMgr { 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 openwhisk = require('openwhisk'); 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 @@ class Debugger { 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 + + // 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"}); + } + + // start container - get it up fast for VSCode to connect within its 10 seconds timeout + await this.invoker.startContainer(); + + debugTask(`started container: ${this.invoker.name()}`); + })(); + + // task 2 - fetch action code from openwhisk + const openwhiskTask = (async () => { + const debugTask = debug.task(); + const actionWithCode = await this.agentMgr.readActionWithCode(); + + debugTask(`got action code (${prettyBytes(actionWithCode.exec.code.length)})`); + return actionWithCode; + })(); + + // wait for both tasks 1 & 2 + const results = await Promise.all([containerTask, openwhiskTask]); + const actionWithCode = results[1]; + + // parallelize slower work using promises again - // start container - get it up fast for VSCode to connect within its 10 seconds timeout - await this.invoker.startContainer(); + // task 3 - initialize local container with code + const initTask = (async () => { + const debugTask = debug.task(); - debug(`started container: ${this.invoker.name()}`); + // /init local container + await this.invoker.init(actionWithCode); - // get code and /init local container - const actionWithCode = await this.agentMgr.readActionWithCode(); + debugTask("installed action on container"); + })(); - await this.invoker.init(actionWithCode); + // task 4 - install agent in openwhisk + const agentTask = (async () => { + const debugTask = debug.task(); - debug("installed action on container (/init)"); + // setup agent in openwhisk + await this.agentMgr.installAgent(this.invoker, debugTask); + })(); - // setup agent in openwhisk - await this.agentMgr.installAgent(this.invoker); + await Promise.all([initTask, agentTask]); if (this.argv.onStart) { console.log("On start:", this.argv.onStart); @@ -115,9 +147,8 @@ class Debugger { 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;
