add verbose flag to invoke command

Author: jthomas

README.md

@@ -111,6 +111,16 @@ $ serverless invoke --function hello --data '{"name": "OpenWhisk"}'
 }
 ```
 
+*Add the `-v` or `--verbose` flag to show more [invocation details](https://github.com/apache/incubator-openwhisk/blob/master/docs/annotations.md#annotations-specific-to-activations), e.g. activation id and duration details.*
+
+```shell
+$ serverless invoke --function hello -v
+=> action (<ACTION_NAME>) activation (<ID>) duration: 96ms (init: 83ms, wait: 35ms)
+{
+    "payload": "Hello, OpenWhisk!"
+}
+```
+
 ## Writing Functions - Node.js
 
 Here's an `index.js` file containing an example handler function.

invoke/index.js

@@ -140,6 +140,10 @@ class OpenWhiskInvoke {
   }
 
   log(invocationReply) {
+    if (this.options.verbose || this.options.v) {
+      this.logDetails(invocationReply)
+    }
+
     let color = 'white';
 
     // error response indicated in-blocking call boolean parameter, success.
@@ -158,6 +162,23 @@ class OpenWhiskInvoke {
     return BbPromise.resolve();
   }
 
+  logDetails(invocationReply) {
+    const id = `/${invocationReply.namespace}/${invocationReply.name}`
+    const actv = invocationReply.activationId
+
+    const find_time = (annotations, key) => (annotations.find(el => el.key === key) || {value: 0}).value
+    const annotations = invocationReply.annotations || []
+    const waitTime = find_time(annotations, 'waitTime')
+    const initTime = find_time(annotations, 'initTime')
+
+    const field = (name, label) => `${chalk.blue(name)} (${chalk.yellow(label)})`
+    const time = (name, value, color = 'blue') => `${chalk[color](name)}: ${chalk.green(value + 'ms')}`
+
+    const duration = (duration, init = 0, wait) => `${time('duration', duration)} (${time('init', init, 'magenta')}, ${time('wait', wait, 'magenta')})`
+
+    this.consoleLog(`${chalk.green('=>')} ${field('action', id)} ${field('activation', actv)} ${duration(invocationReply.duration, initTime, waitTime)}`)
+  }
+
   consoleLog(msg) {
     console.log(msg); // eslint-disable-line no-console
   }

invoke/tests/index.js

@@ -1,5 +1,6 @@
 'use strict';
 
+const chalk = require('chalk');
 const expect = require('chai').expect;
 const chaiAsPromised = require('chai-as-promised');
 const sinon = require('sinon');
@@ -217,4 +218,84 @@ describe('OpenWhiskInvoke', () => {
       return expect(openwhiskInvoke.invoke()).to.be.eventually.rejected;
     });
   });
+
+  describe('#log()', () => {
+    it('should log activation response result', () => {
+      const log = sandbox.stub(openwhiskInvoke, 'consoleLog');
+      openwhiskInvoke.options.log = 'result'
+      openwhiskInvoke.options.type = 'blocking'
+
+      const result = {success: true, result: { hello: "world"} };
+      return openwhiskInvoke.log({response: result}).then(() => {
+        expect(log.calledOnce).to.be.equal(true);
+        const msg = chalk.white(JSON.stringify(result.result, null, 4));
+        console.log(msg)
+        expect(log.args[0][0]).to.be.equal(msg);
+      });
+    });
+
+    it('should log verbose activation response result', () => {
+      const log = sandbox.stub(openwhiskInvoke, 'consoleLog');
+      openwhiskInvoke.options.log = 'result'
+      openwhiskInvoke.options.type = 'blocking'
+      openwhiskInvoke.options.v = true
+
+      const input = {
+        activationId: 12345,
+        name: 'blah',
+        namespace: 'workspace',
+        duration: 100,
+        annotations: [ { key: "waitTime", value: 33 } ],
+        response: { success: true, result: { hello: "world"} }
+      };
+      return openwhiskInvoke.log(input).then(() => {
+        expect(log.calledTwice).to.be.equal(true);
+        const msg = chalk.white(JSON.stringify(input.response.result, null, 4));
+
+        const field = (name, label) => `${chalk.blue(name)} (${chalk.yellow(label)})`
+        const time = (name, value, color = 'blue') => `${chalk[color](name)}: ${chalk.green(value + 'ms')}`
+      const duration = (duration, init = 0, wait) => `${time('duration', duration)} (${time('init', init, 'magenta')}, ${time('wait', wait, 'magenta')})`
+
+        const output = `${chalk.green('=>')} ${field('action', '/workspace/blah')} ${field('activation', 12345)} ${duration(100, undefined, 33)}`
+
+        expect(log.args[0][0]).to.be.equal(output);
+        expect(log.args[1][0]).to.be.equal(msg);
+      });
+    });
+
+    it('should log verbose activation coldstart response result', () => {
+      const log = sandbox.stub(openwhiskInvoke, 'consoleLog');
+      openwhiskInvoke.options.log = 'result'
+      openwhiskInvoke.options.type = 'blocking'
+      openwhiskInvoke.options.v = true
+
+      const input = {
+        activationId: 12345,
+        name: 'blah',
+        namespace: 'workspace',
+        duration: 100,
+        annotations: [ 
+          { key: "waitTime", value: 33 },
+          { key: "initTime", value: 63 }
+        ],
+        response: { success: true, result: { hello: "world"} }
+      };
+      return openwhiskInvoke.log(input).then(() => {
+        expect(log.calledTwice).to.be.equal(true);
+        const msg = chalk.white(JSON.stringify(input.response.result, null, 4));
+
+        const field = (name, label) => `${chalk.blue(name)} (${chalk.yellow(label)})`
+        const time = (name, value, color = 'blue') => `${chalk[color](name)}: ${chalk.green(value + 'ms')}`
+      const duration = (duration, init = 0, wait) => `${time('duration', duration)} (${time('init', init, 'magenta')}, ${time('wait', wait, 'magenta')})`
+
+        const output = `${chalk.green('=>')} ${field('action', '/workspace/blah')} ${field('activation', 12345)} ${duration(100, 63, 33)}`
+
+        expect(log.args[0][0]).to.be.equal(output);
+        expect(log.args[1][0]).to.be.equal(msg);
+      });
+    });
+
+
+
+  });
 });