Obtain detailed timing info of request from response callback of Runt…

…ime (postmanlabs#1939)

README.md

@@ -192,6 +192,9 @@ For more details on [Reporters](#reporters) and writing your own [External Repor
   Allows the specification of global variables via the command line, in a key=value format. Multiple CLI global variables
   can be added by using `--global-var` multiple times, like so: `--global-var "foo=bar" --global-var "alpha=beta"`.
 
+- `--verbose`<br />
+  Show detailed information of collection run and each request sent.
+
 ### SSL Client Certificates
 
 Client certificates are an alternative to traditional authentication mechanisms. These allow their users to make authenticated requests to a server, using a public certificate, and an optional private key that verifies certificate ownership. In some cases, the private key may also be protected by a secret passphrase, providing an additional layer of authentication security.

lib/reporters/cli/index.js

@@ -162,6 +162,7 @@ PostmanCLIReporter = function (emitter, reporterOptions, options) {
         }
 
         var timingTable,
+            timings,
             timingPhases,
             size = o.response && o.response.size(),
             timingHeaders = {
@@ -181,9 +182,13 @@ PostmanCLIReporter = function (emitter, reporterOptions, options) {
         print.lf(colors.gray('[%d %s, %s, %s]'), o.response.code, o.response.reason(),
             util.filesize(size), util.prettyms(o.response.responseTime));
 
+        // if there are redirects, get timings for the last request sent
+        timings = _.last(_.get(o, 'history.execution.data'));
+        timings = timings && timings.timings;
+
         // print timing info of the request
-        if (options.verbose && o.response && o.response.timings) {
-            timingPhases = util.beautifyTime(sdk.Response.timingPhases(o.response.timings));
+        if (options.verbose && timings) {
+            timingPhases = util.beautifyTime(sdk.Response.timingPhases(timings));
 
             timingTable = new Table({
                 chars: _.defaults({ mid: '', middle: '' }, cliUtils.cliTableTemplate_Blank),

lib/run/index.js

@@ -23,7 +23,7 @@ var fs = require('fs'),
         beforePrerequest: ['events', 'item'],
         prerequest: ['executions', 'item'],
         beforeRequest: ['request', 'item'],
-        request: ['response', 'request', 'item', 'cookies'],
+        request: ['response', 'request', 'item', 'cookies', 'history'],
         beforeTest: ['events', 'item'],
         test: ['executions', 'item'],
         item: ['item'],

lib/run/summary.js

@@ -305,12 +305,18 @@ _.assign(RunSummary, {
 
             var size = _.isFunction(o.response.size) && o.response.size(),
                 time = o.response.responseTime,
-                timingPhases = sdk.Response.timingPhases(o.response.timings),
-                requestCount = summary.run.stats.requests.total;
+                requestCount = summary.run.stats.requests.total,
+                timings,
+                timingPhases;
 
             // compute the response size total
             size && (summary.run.transfers.responseTotal += (size.body || 0 + size.headers || 0));
 
+            // if there are redirects, get timings for the last request sent
+            timings = _.last(_.get(o, 'history.execution.data'));
+            timings = timings && timings.timings;
+            timingPhases = timings && sdk.Response.timingPhases(timings);
+
             (timingPhases || time) && _.forEach([
                 'dns',
                 'firstByte',

package.json

@@ -50,10 +50,10 @@
     "filesize": "4.1.2",
     "lodash": "4.17.11",
     "mkdirp": "0.5.1",
-    "postman-collection": "3.4.5",
+    "postman-collection": "3.4.6-beta.2",
     "postman-collection-transformer": "3.0.0",
-    "postman-request": "2.88.1-postman.7.1",
-    "postman-runtime": "7.10.0",
+    "postman-request": "2.88.1-postman.8-beta.1",
+    "postman-runtime": "7.11.0-beta.1",
     "pretty-ms": "4.0.0",
     "semver": "5.6.0",
     "serialised-error": "1.1.3",