From c5243d0a584a2251c1407099667d6614f616886e Mon Sep 17 00:00:00 2001 From: Nic Jansma Date: Sat, 5 Nov 2016 21:23:01 -0400 Subject: [PATCH 1/7] Adds .timings array with dns, tcp, request and response times --- README.md | 12 +++++++++++- package.json | 1 + request.js | 37 +++++++++++++++++++++++++++++++++++-- tests/test-timing.js | 11 +++++++++++ 4 files changed, 58 insertions(+), 3 deletions(-) diff --git a/README.md b/README.md index a0b6c84d0..e1b31f6ae 100644 --- a/README.md +++ b/README.md @@ -812,7 +812,17 @@ default in Linux can be anywhere from 20-120 seconds][linux-timeout]). --- -- `time` - If `true`, the request-response cycle (including all redirects) is timed at millisecond resolution, and the result provided on the response's `elapsedTime` property. The `responseStartTime` property is also available to indicate the timestamp when the response begins. +- `time` - If `true`, the request-response cycle (including all redirects) is timed at millisecond resolution, and the result provided on the response's `elapsedTime` property. The `responseStartTime` property is also available to indicate the timestamp when the response begins. In addition, there is a `.timings` object available with the following properties: + - `start`: Timestamp when `request()` was initialized + - `socket` Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_socket) module's `socket` event fires. This happens when the socket is assigned to the request (after DNS has been resolved). + - `connect`: Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_connect) module's `connect` event fires. This happens when the server acknowledges the TCP connection. + - `response`: Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_response) module's `response` event fires. This happens when the first bytes are received from the server. + - `end`: Timestamp when the last bytes of the response are received. + - `dns`: Duration of DNS lookup (`timings.socket` - `timings.start`) + - `tcp`: Duration of TCP connection (`timings.connect` - `timings.socket`) + - `download`: Duration HTTP fetch (`timings.end` - `timings.response`) + - `total`: Duration entire HTTP round-trip (`timings.end` - `timings.start`) + - `har` - A [HAR 1.2 Request Object](http://www.softwareishard.com/blog/har-12-spec/#request), will be processed from HAR format into options overwriting matching values *(see the [HAR 1.2 section](#support-for-har-1.2) for details)* - `callback` - alternatively pass the request's callback in the options object diff --git a/package.json b/package.json index 2645565c5..c47bcd217 100644 --- a/package.json +++ b/package.json @@ -38,6 +38,7 @@ "mime-types": "~2.1.7", "node-uuid": "~1.4.7", "oauth-sign": "~0.8.1", + "performance-now": "^0.2.0", "qs": "~6.3.0", "stringstream": "~0.0.4", "tough-cookie": "~2.3.0", diff --git a/request.js b/request.js index 9528b5662..39d2b37fd 100644 --- a/request.js +++ b/request.js @@ -28,6 +28,7 @@ var http = require('http') , Multipart = require('./lib/multipart').Multipart , Redirect = require('./lib/redirect').Redirect , Tunnel = require('./lib/tunnel').Tunnel + , now = require('performance-now') var safeStringify = helpers.safeStringify , isReadStream = helpers.isReadStream @@ -713,6 +714,10 @@ Request.prototype.start = function () { // this is usually called on the first write(), end() or on nextTick() var self = this + if (self.timing) { + var startTime = now() + } + if (self._aborted) { return } @@ -749,6 +754,9 @@ Request.prototype.start = function () { if (self.timing) { self.startTime = new Date().getTime() + self.timings = { + start: startTime + } } var timeout @@ -766,6 +774,13 @@ Request.prototype.start = function () { self.emit('drain') }) self.req.on('socket', function(socket) { + if (self.timing) { + self.timings.socket = now() + socket.on('connect', function() { + self.timings.connect = now() + }) + } + var setReqTimeout = function() { // This timeout sets the amount of time to wait *between* bytes sent // from the server once connected. @@ -847,12 +862,30 @@ Request.prototype.onRequestError = function (error) { Request.prototype.onRequestResponse = function (response) { var self = this + + if (self.timing) { + self.timings.response = now() + } + debug('onRequestResponse', self.uri.href, response.statusCode, response.headers) response.on('end', function() { if (self.timing) { - self.elapsedTime += (new Date().getTime() - self.startTime) - debug('elapsed time', self.elapsedTime) + self.timings.end = now() + + self.timings.dns = self.timings.socket - self.timings.start + self.timings.tcp = self.timings.connect - self.timings.socket + self.timings.firstByte = self.timings.response - self.timings.connect + self.timings.download = self.timings.end - self.timings.response + self.timings.total = self.timings.end - self.timings.start + + debug('elapsed time', self.timings.total) + + // elapsedTime includes all redirects + self.elapsedTime += Math.round(self.timings.total) response.elapsedTime = self.elapsedTime + + // timings is just for the final fetch + response.timings = self.timings } debug('response end', self.uri.href, response.statusCode, response.headers) }) diff --git a/tests/test-timing.js b/tests/test-timing.js index 5a3636d76..0e9a7cdf9 100644 --- a/tests/test-timing.js +++ b/tests/test-timing.js @@ -31,8 +31,19 @@ tape('non-redirected request is timed', function(t) { t.equal(err, null) t.equal(typeof res.elapsedTime, 'number') t.equal(typeof res.responseStartTime, 'number') + t.equal(typeof res.timings, 'object') t.equal((res.elapsedTime > 0), true) t.equal((res.responseStartTime > r.startTime), true) + t.equal((res.timings.start > 0), true) + t.equal((res.timings.socket >= res.timings.start), true) + t.equal((res.timings.connect >= res.timings.socket), true) + t.equal((res.timings.response >= res.timings.connect), true) + t.equal((res.timings.end >= res.timings.response), true) + t.equal((res.timings.dns >= 0), true) + t.equal((res.timings.tcp > 0), true) + t.equal((res.timings.firstByte > 0), true) + t.equal((res.timings.download > 0), true) + t.equal((res.timings.total > 0), true) t.end() }) }) From c7c9431f1fadaf4b700e82218c3df9e0f2e96646 Mon Sep 17 00:00:00 2001 From: Nic Jansma Date: Sun, 4 Dec 2016 09:35:28 -0500 Subject: [PATCH 2/7] Addresses feedback --- README.md | 5 +++-- package.json | 1 - request.js | 34 ++++++++++++++++++++++++++++------ tests/test-timing.js | 2 +- 4 files changed, 32 insertions(+), 10 deletions(-) diff --git a/README.md b/README.md index e1b31f6ae..c52efd72e 100644 --- a/README.md +++ b/README.md @@ -812,7 +812,7 @@ default in Linux can be anywhere from 20-120 seconds][linux-timeout]). --- -- `time` - If `true`, the request-response cycle (including all redirects) is timed at millisecond resolution, and the result provided on the response's `elapsedTime` property. The `responseStartTime` property is also available to indicate the timestamp when the response begins. In addition, there is a `.timings` object available with the following properties: +- `time` - If `true`, the request-response cycle (including all redirects) is timed at millisecond resolution, and the result provided on the response's `elapsedTime` property. The `responseStartTime` property is also available to indicate the timestamp when the response begins. In addition, there is a `.timings` object available with the following properties: - `start`: Timestamp when `request()` was initialized - `socket` Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_socket) module's `socket` event fires. This happens when the socket is assigned to the request (after DNS has been resolved). - `connect`: Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_connect) module's `connect` event fires. This happens when the server acknowledges the TCP connection. @@ -820,7 +820,8 @@ default in Linux can be anywhere from 20-120 seconds][linux-timeout]). - `end`: Timestamp when the last bytes of the response are received. - `dns`: Duration of DNS lookup (`timings.socket` - `timings.start`) - `tcp`: Duration of TCP connection (`timings.connect` - `timings.socket`) - - `download`: Duration HTTP fetch (`timings.end` - `timings.response`) + - `firstByte`: Duration of HTTP server response (`timings.response` - `timings.connect`) + - `download`: Duration of HTTP download (`timings.end` - `timings.response`) - `total`: Duration entire HTTP round-trip (`timings.end` - `timings.start`) - `har` - A [HAR 1.2 Request Object](http://www.softwareishard.com/blog/har-12-spec/#request), will be processed from HAR format into options overwriting matching values *(see the [HAR 1.2 section](#support-for-har-1.2) for details)* diff --git a/package.json b/package.json index c47bcd217..2645565c5 100644 --- a/package.json +++ b/package.json @@ -38,7 +38,6 @@ "mime-types": "~2.1.7", "node-uuid": "~1.4.7", "oauth-sign": "~0.8.1", - "performance-now": "^0.2.0", "qs": "~6.3.0", "stringstream": "~0.0.4", "tough-cookie": "~2.3.0", diff --git a/request.js b/request.js index 39d2b37fd..1ea024119 100644 --- a/request.js +++ b/request.js @@ -28,7 +28,6 @@ var http = require('http') , Multipart = require('./lib/multipart').Multipart , Redirect = require('./lib/redirect').Redirect , Tunnel = require('./lib/tunnel').Tunnel - , now = require('performance-now') var safeStringify = helpers.safeStringify , isReadStream = helpers.isReadStream @@ -37,6 +36,7 @@ var safeStringify = helpers.safeStringify , copy = helpers.copy , version = helpers.version , globalCookieJar = cookies.jar() + , hrTimeStart var globalPool = {} @@ -92,6 +92,28 @@ function responseToJSON() { } } +function getHrTime() { + if (typeof process === 'undefined' || !process.hrtime) { + return 0 + } + + var hr = process.hrtime() + // convert to nanoseconds + return hr[0] * 1e9 + hr[1] +} + +hrTimeStart = getHrTime() + +function getTimeFromStart() { + // in the browser, use performance.now() + if (typeof performance !== 'undefined' && performance.now) { + return performance.now() + } + + // in nodejs, use process.hrtime() (converting back to milliseconds) + return (getHrTime() - hrTimeStart) / 1e6 +} + function Request (options) { // if given the method property in options, set property explicitMethod to true @@ -715,7 +737,7 @@ Request.prototype.start = function () { var self = this if (self.timing) { - var startTime = now() + var startTime = getTimeFromStart() } if (self._aborted) { @@ -775,9 +797,9 @@ Request.prototype.start = function () { }) self.req.on('socket', function(socket) { if (self.timing) { - self.timings.socket = now() + self.timings.socket = getTimeFromStart() socket.on('connect', function() { - self.timings.connect = now() + self.timings.connect = getTimeFromStart() }) } @@ -864,13 +886,13 @@ Request.prototype.onRequestResponse = function (response) { var self = this if (self.timing) { - self.timings.response = now() + self.timings.response = getTimeFromStart() } debug('onRequestResponse', self.uri.href, response.statusCode, response.headers) response.on('end', function() { if (self.timing) { - self.timings.end = now() + self.timings.end = getTimeFromStart() self.timings.dns = self.timings.socket - self.timings.start self.timings.tcp = self.timings.connect - self.timings.socket diff --git a/tests/test-timing.js b/tests/test-timing.js index 0e9a7cdf9..6cbed5f1b 100644 --- a/tests/test-timing.js +++ b/tests/test-timing.js @@ -40,7 +40,7 @@ tape('non-redirected request is timed', function(t) { t.equal((res.timings.response >= res.timings.connect), true) t.equal((res.timings.end >= res.timings.response), true) t.equal((res.timings.dns >= 0), true) - t.equal((res.timings.tcp > 0), true) + t.equal((res.timings.tcp >= 0), true) t.equal((res.timings.firstByte > 0), true) t.equal((res.timings.download > 0), true) t.equal((res.timings.total > 0), true) From 47523a2eb29ede4c7b5726a3540b7b756f2bb493 Mon Sep 17 00:00:00 2001 From: Nic Jansma Date: Tue, 6 Dec 2016 09:02:18 -0500 Subject: [PATCH 3/7] Removed double-spaces after period --- README.md | 30 +++++++++++++++--------------- 1 file changed, 15 insertions(+), 15 deletions(-) diff --git a/README.md b/README.md index c52efd72e..88c2e3c93 100644 --- a/README.md +++ b/README.md @@ -287,13 +287,13 @@ The method form takes parameters `auth(username, password, sendImmediately, bearer)`. `sendImmediately` defaults to `true`, which causes a basic or bearer -authentication header to be sent. If `sendImmediately` is `false`, then +authentication header to be sent. If `sendImmediately` is `false`, then `request` will retry with a proper authentication header after receiving a `401` response from the server (which must contain a `WWW-Authenticate` header indicating the required authentication method). Note that you can also specify basic authentication using the URL itself, as -detailed in [RFC 1738](http://www.ietf.org/rfc/rfc1738.txt). Simply pass the +detailed in [RFC 1738](http://www.ietf.org/rfc/rfc1738.txt). Simply pass the `user:password` before the host with an `@` sign: ```js @@ -358,7 +358,7 @@ request(options, callback); ## OAuth Signing -[OAuth version 1.0](https://tools.ietf.org/html/rfc5849) is supported. The +[OAuth version 1.0](https://tools.ietf.org/html/rfc5849) is supported. The default signing algorithm is [HMAC-SHA1](https://tools.ietf.org/html/rfc5849#section-3.4.2): @@ -477,7 +477,7 @@ See [the wikipedia page on HTTP Tunneling](https://en.wikipedia.org/wiki/HTTP_tu for more information. By default, when proxying `http` traffic, request will simply make a -standard proxied `http` request. This is done by making the `url` +standard proxied `http` request. This is done by making the `url` section of the initial line of the request a fully qualified url to the endpoint. @@ -493,7 +493,7 @@ request body or whatever Because a pure "http over http" tunnel offers no additional security or other features, it is generally simpler to go with a -straightforward HTTP proxy in this case. However, if you would like +straightforward HTTP proxy in this case. However, if you would like to force a tunneling proxy, you may set the `tunnel` option to `true`. You can also make a standard proxied `http` request by explicitly setting @@ -717,7 +717,7 @@ a validation step will check if the HAR Request format matches the latest spec ( The first argument can be either a `url` or an `options` object. The only required option is `uri`; all others are optional. - `uri` || `url` - fully qualified uri or a parsed url object from `url.parse()` -- `baseUrl` - fully qualified uri string used as the base url. Most useful with `request.defaults`, for example when you want to do many requests to the same domain. If `baseUrl` is `https://example.com/api/`, then requesting `/end/point?test=true` will fetch `https://example.com/api/end/point?test=true`. When `baseUrl` is given, `uri` must also be a string. +- `baseUrl` - fully qualified uri string used as the base url. Most useful with `request.defaults`, for example when you want to do many requests to the same domain. If `baseUrl` is `https://example.com/api/`, then requesting `/end/point?test=true` will fetch `https://example.com/api/end/point?test=true`. When `baseUrl` is given, `uri` must also be a string. - `method` - http method (default: `"GET"`) - `headers` - http headers (default: `{}`) @@ -727,7 +727,7 @@ The first argument can be either a `url` or an `options` object. The only requir - `qsParseOptions` - object containing options to pass to the [qs.parse](https://github.com/hapijs/qs#parsing-objects) method. Alternatively pass options to the [querystring.parse](https://nodejs.org/docs/v0.12.0/api/querystring.html#querystring_querystring_parse_str_sep_eq_options) method using this format `{sep:';', eq:':', options:{}}` - `qsStringifyOptions` - object containing options to pass to the [qs.stringify](https://github.com/hapijs/qs#stringifying) method. Alternatively pass options to the [querystring.stringify](https://nodejs.org/docs/v0.12.0/api/querystring.html#querystring_querystring_stringify_obj_sep_eq_options) method using this format `{sep:';', eq:':', options:{}}`. For example, to change the way arrays are converted to query strings using the `qs` module pass the `arrayFormat` option with one of `indices|brackets|repeat` - `useQuerystring` - If true, use `querystring` to stringify and parse - querystrings, otherwise use `qs` (default: `false`). Set this option to + querystrings, otherwise use `qs` (default: `false`). Set this option to `true` if you need arrays to be serialized as `foo=bar&foo=baz` instead of the default `foo[0]=bar&foo[1]=baz`. @@ -746,13 +746,13 @@ The first argument can be either a `url` or an `options` object. The only requir In non-chunked requests, data items with body streams are not allowed. - `preambleCRLF` - append a newline/CRLF before the boundary of your `multipart/form-data` request. - `postambleCRLF` - append a newline/CRLF at the end of the boundary of your `multipart/form-data` request. -- `json` - sets `body` to JSON representation of value and adds `Content-type: application/json` header. Additionally, parses the response body as JSON. +- `json` - sets `body` to JSON representation of value and adds `Content-type: application/json` header. Additionally, parses the response body as JSON. - `jsonReviver` - a [reviver function](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/JSON/parse) that will be passed to `JSON.parse()` when parsing a JSON response body. - `jsonReplacer` - a [replacer function](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/JSON/stringify) that will be passed to `JSON.stringify()` when stringifying a JSON request body. --- -- `auth` - A hash containing values `user` || `username`, `pass` || `password`, and `sendImmediately` (optional). See documentation above. +- `auth` - A hash containing values `user` || `username`, `pass` || `password`, and `sendImmediately` (optional). See documentation above. - `oauth` - Options for OAuth HMAC-SHA1 signing. See documentation above. - `hawk` - Options for [Hawk signing](https://github.com/hueniverse/hawk). The `credentials` key must contain the necessary signing info, [see hawk docs for details](https://github.com/hueniverse/hawk#usage-example). - `aws` - `object` containing AWS signing information. Should have the properties `key`, `secret`. Also requires the property `bucket`, unless you’re specifying your `bucket` as part of the path, or the request doesn’t use a bucket (i.e. GET Services). If you want to use AWS sign version 4 use the parameter `sign_version` with value `4` otherwise the default is version 2. **Note:** you need to `npm install aws4` first. @@ -769,7 +769,7 @@ The first argument can be either a `url` or an `options` object. The only requir --- - `encoding` - Encoding to be used on `setEncoding` of response data. If `null`, the `body` is returned as a `Buffer`. Anything else **(including the default value of `undefined`)** will be passed as the [encoding](http://nodejs.org/api/buffer.html#buffer_buffer) parameter to `toString()` (meaning this is effectively `utf8` by default). (**Note:** if you expect binary data, you should set `encoding: null`.) -- `gzip` - If `true`, add an `Accept-Encoding` header to request compressed content encodings from the server (if not already present) and decode supported content encodings in the response. **Note:** Automatic decoding of the response content is performed on the body data returned through `request` (both through the `request` stream and passed to the callback function) but is not performed on the `response` stream (available from the `response` event) which is the unmodified `http.IncomingMessage` object which may contain compressed data. See example below. +- `gzip` - If `true`, add an `Accept-Encoding` header to request compressed content encodings from the server (if not already present) and decode supported content encodings in the response. **Note:** Automatic decoding of the response content is performed on the body data returned through `request` (both through the `request` stream and passed to the callback function) but is not performed on the `response` stream (available from the `response` event) which is the unmodified `http.IncomingMessage` object which may contain compressed data. See example below. - `jar` - If `true`, remember cookies for future use (or define your custom cookie jar; see examples section) --- @@ -781,7 +781,7 @@ The first argument can be either a `url` or an `options` object. The only requir - `pool` - An object describing which agents to use for the request. If this option is omitted the request will use the global agent (as long as your options allow for it). Otherwise, request will search the pool for your custom agent. If no custom agent is found, a new agent will be created and added to the pool. **Note:** `pool` is used only when the `agent` option is not specified. - A `maxSockets` property can also be provided on the `pool` object to set the max number of sockets for all agents created (ex: `pool: {maxSockets: Infinity}`). - Note that if you are sending multiple requests in a loop and creating - multiple new `pool` objects, `maxSockets` will not work as intended. To + multiple new `pool` objects, `maxSockets` will not work as intended. To work around this, either use [`request.defaults`](#requestdefaultsoptions) with your pool options or create the pool object with the `maxSockets` property outside of the loop. @@ -814,9 +814,9 @@ default in Linux can be anywhere from 20-120 seconds][linux-timeout]). - `time` - If `true`, the request-response cycle (including all redirects) is timed at millisecond resolution, and the result provided on the response's `elapsedTime` property. The `responseStartTime` property is also available to indicate the timestamp when the response begins. In addition, there is a `.timings` object available with the following properties: - `start`: Timestamp when `request()` was initialized - - `socket` Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_socket) module's `socket` event fires. This happens when the socket is assigned to the request (after DNS has been resolved). - - `connect`: Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_connect) module's `connect` event fires. This happens when the server acknowledges the TCP connection. - - `response`: Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_response) module's `response` event fires. This happens when the first bytes are received from the server. + - `socket` Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_socket) module's `socket` event fires. This happens when the socket is assigned to the request (after DNS has been resolved). + - `connect`: Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_connect) module's `connect` event fires. This happens when the server acknowledges the TCP connection. + - `response`: Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_response) module's `response` event fires. This happens when the first bytes are received from the server. - `end`: Timestamp when the last bytes of the response are received. - `dns`: Duration of DNS lookup (`timings.socket` - `timings.start`) - `tcp`: Duration of TCP connection (`timings.connect` - `timings.socket`) @@ -1013,7 +1013,7 @@ request.get('http://10.255.255.1', {timeout: 1500}, function(err) { ``` For backwards-compatibility, response compression is not supported by default. -To accept gzip-compressed responses, set the `gzip` option to `true`. Note +To accept gzip-compressed responses, set the `gzip` option to `true`. Note that the body data passed through `request` is automatically decompressed while the response object is unmodified and will contain compressed data if the server sent a compressed response. From 21e315d9080200278002441943aec0c4a17f57c3 Mon Sep 17 00:00:00 2001 From: Nic Jansma Date: Wed, 7 Dec 2016 23:24:59 -0500 Subject: [PATCH 4/7] Removed extra space --- README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/README.md b/README.md index 88c2e3c93..a02f40bb2 100644 --- a/README.md +++ b/README.md @@ -815,7 +815,7 @@ default in Linux can be anywhere from 20-120 seconds][linux-timeout]). - `time` - If `true`, the request-response cycle (including all redirects) is timed at millisecond resolution, and the result provided on the response's `elapsedTime` property. The `responseStartTime` property is also available to indicate the timestamp when the response begins. In addition, there is a `.timings` object available with the following properties: - `start`: Timestamp when `request()` was initialized - `socket` Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_socket) module's `socket` event fires. This happens when the socket is assigned to the request (after DNS has been resolved). - - `connect`: Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_connect) module's `connect` event fires. This happens when the server acknowledges the TCP connection. + - `connect`: Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_connect) module's `connect` event fires. This happens when the server acknowledges the TCP connection. - `response`: Timestamp when the [`http`](https://nodejs.org/api/http.html#http_event_response) module's `response` event fires. This happens when the first bytes are received from the server. - `end`: Timestamp when the last bytes of the response are received. - `dns`: Duration of DNS lookup (`timings.socket` - `timings.start`) From d9e8c3d5b4ccb98cb9c51d1775bd8c668f51e655 Mon Sep 17 00:00:00 2001 From: Nic Jansma Date: Fri, 17 Feb 2017 10:06:10 -0500 Subject: [PATCH 5/7] Added deprecated notes --- request.js | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/request.js b/request.js index 1ea024119..d13609d0b 100644 --- a/request.js +++ b/request.js @@ -435,6 +435,8 @@ Request.prototype.init = function (options) { if (options.time) { self.timing = true + + // NOTE: elapsedTime is deprecated in favor of .timings self.elapsedTime = self.elapsedTime || 0 } @@ -904,6 +906,8 @@ Request.prototype.onRequestResponse = function (response) { // elapsedTime includes all redirects self.elapsedTime += Math.round(self.timings.total) + + // NOTE: elapsedTime is deprecated in favor of .timings response.elapsedTime = self.elapsedTime // timings is just for the final fetch @@ -1047,6 +1051,8 @@ Request.prototype.onRequestResponse = function (response) { responseContent.on('data', function (chunk) { if (self.timing && !self.responseStarted) { self.responseStartTime = (new Date()).getTime() + + // NOTE: responseStartTime is deprecated in favor of .timings response.responseStartTime = self.responseStartTime } self._destdata = true From a9ad38a3f7c4bc388af8af353b54fc05cfb81f63 Mon Sep 17 00:00:00 2001 From: Nic Jansma Date: Fri, 17 Feb 2017 10:06:22 -0500 Subject: [PATCH 6/7] Ensure only the properties we expect are there --- tests/test-timing.js | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/tests/test-timing.js b/tests/test-timing.js index 6cbed5f1b..0623195f6 100644 --- a/tests/test-timing.js +++ b/tests/test-timing.js @@ -44,6 +44,17 @@ tape('non-redirected request is timed', function(t) { t.equal((res.timings.firstByte > 0), true) t.equal((res.timings.download > 0), true) t.equal((res.timings.total > 0), true) + + // validate there are no unexpected properties + var propNames = [] + for (var propName in res.timings) { + if (res.timings.hasOwnProperty(propName)) { + propNames.push(propName) + } + } + t.deepEqual(propNames, ['start', 'socket', 'connect', 'response', 'end', 'dns', + 'tcp', 'firstByte', 'download', 'total']) + t.end() }) }) From 3f57975212976c88fc006e9e7b3e2cb5b53a2ddf Mon Sep 17 00:00:00 2001 From: Nic Jansma Date: Fri, 17 Feb 2017 10:10:34 -0500 Subject: [PATCH 7/7] Use performance-now instead of custom solution --- package.json | 1 + request.js | 34 ++++++---------------------------- 2 files changed, 7 insertions(+), 28 deletions(-) diff --git a/package.json b/package.json index 2645565c5..c47bcd217 100644 --- a/package.json +++ b/package.json @@ -38,6 +38,7 @@ "mime-types": "~2.1.7", "node-uuid": "~1.4.7", "oauth-sign": "~0.8.1", + "performance-now": "^0.2.0", "qs": "~6.3.0", "stringstream": "~0.0.4", "tough-cookie": "~2.3.0", diff --git a/request.js b/request.js index d13609d0b..74435bd16 100644 --- a/request.js +++ b/request.js @@ -28,6 +28,7 @@ var http = require('http') , Multipart = require('./lib/multipart').Multipart , Redirect = require('./lib/redirect').Redirect , Tunnel = require('./lib/tunnel').Tunnel + , now = require('performance-now') var safeStringify = helpers.safeStringify , isReadStream = helpers.isReadStream @@ -36,7 +37,6 @@ var safeStringify = helpers.safeStringify , copy = helpers.copy , version = helpers.version , globalCookieJar = cookies.jar() - , hrTimeStart var globalPool = {} @@ -92,28 +92,6 @@ function responseToJSON() { } } -function getHrTime() { - if (typeof process === 'undefined' || !process.hrtime) { - return 0 - } - - var hr = process.hrtime() - // convert to nanoseconds - return hr[0] * 1e9 + hr[1] -} - -hrTimeStart = getHrTime() - -function getTimeFromStart() { - // in the browser, use performance.now() - if (typeof performance !== 'undefined' && performance.now) { - return performance.now() - } - - // in nodejs, use process.hrtime() (converting back to milliseconds) - return (getHrTime() - hrTimeStart) / 1e6 -} - function Request (options) { // if given the method property in options, set property explicitMethod to true @@ -739,7 +717,7 @@ Request.prototype.start = function () { var self = this if (self.timing) { - var startTime = getTimeFromStart() + var startTime = now() } if (self._aborted) { @@ -799,9 +777,9 @@ Request.prototype.start = function () { }) self.req.on('socket', function(socket) { if (self.timing) { - self.timings.socket = getTimeFromStart() + self.timings.socket = now() socket.on('connect', function() { - self.timings.connect = getTimeFromStart() + self.timings.connect = now() }) } @@ -888,13 +866,13 @@ Request.prototype.onRequestResponse = function (response) { var self = this if (self.timing) { - self.timings.response = getTimeFromStart() + self.timings.response = now() } debug('onRequestResponse', self.uri.href, response.statusCode, response.headers) response.on('end', function() { if (self.timing) { - self.timings.end = getTimeFromStart() + self.timings.end = now() self.timings.dns = self.timings.socket - self.timings.start self.timings.tcp = self.timings.connect - self.timings.socket