restify / clients

HttpClient, StringClient, and JsonClient extracted from restify
MIT License
57 stars 34 forks source link

feat: add more context for Request/Connect/DNSTimeoutErrors #109

Closed DonutEspresso closed 6 years ago

DonutEspresso commented 7 years ago

Addresses #104.

Here are example errors of both classes:

{ ConnectTimeoutError: GET request to http://169.254.1.10/foo?a=1 failed to obtain connected socket within 100ms
    at buildConnectTimeoutError (/Users/aliu/Sandbox/restify-clients/lib/HttpClient.js:153:12)
    at Timeout.connectTimeout [as _onTimeout] (/Users/aliu/Sandbox/restify-clients/lib/HttpClient.js:231:23)
    at ontimeout (timers.js:365:14)
    at tryOnTimeout (timers.js:237:5)
    at Timer.listOnTimeout (timers.js:207:5)
  name: 'ConnectTimeoutError',
  jse_shortmsg: 'GET request to http://169.254.1.10/foo?a=1 failed to obtain connected socket within 100ms',
  jse_info: { fullUrl: 'http://169.254.1.10/foo?a=1', connectTimeout: 100 },
  message: 'GET request to http://169.254.1.10/foo?a=1 failed to obtain connected socket within 100ms' }
{ RequestTimeoutError: GET request to http://127.0.0.1:53927/str/request_timeout failed to complete within 150ms
    at buildRequestTimeoutError (/Users/aliu/Sandbox/restify-clients/lib/HttpClient.js:124:12)
    at Timeout.requestTimeout [as _onTimeout] (/Users/aliu/Sandbox/restify-clients/lib/HttpClient.js:383:31)
    at ontimeout (timers.js:365:14)
    at tryOnTimeout (timers.js:237:5)
    at Timer.listOnTimeout (timers.js:207:5)
  name: 'RequestTimeoutError',
  jse_shortmsg: 'GET request to http://127.0.0.1:53927/str/request_timeout failed to complete within 150ms',
  jse_info:
   { fullUrl: 'http://127.0.0.1:53927/str/request_timeout',
     requestTimeout: 150 },
  message: 'GET request to http://127.0.0.1:53927/str/request_timeout failed to complete within 150ms' }

I'm looking for feedback on two items:

1) Do we want to attach more fields onto the verror infoobject? The full URL can be parsed by url.parse() to get any of the derived fields (hostname, path, protocol, port, etc.) but I'm happy to directly attach the results of url.parse() to the info object as well.

2) The initial feedback in #104 sounded like we might want to have an underlying error which could be used as a cause for ConnectTimeout or RequestTimeout - but both of these seem pretty low level as is, so I decided to just attach the relevant metadata directly into info object. Would be happy to hear alternative approaches here.

coveralls commented 7 years ago

Coverage Status

Coverage increased (+0.2%) to 84.605% when pulling bbfd6401613be733dc8fbe6712196bf77dbc7f2b on verror-info into 85374f87db9f4469de2605b6b15632b317cc12be on master.

coveralls commented 7 years ago

Coverage Status

Coverage increased (+0.6%) to 86.759% when pulling cfdc819ce09ad05a488e5e9c4a14b24d6360d463 on verror-info into e0f36ef2e606e7ee544d8c95d966191ef0d18637 on master.

DonutEspresso commented 7 years ago

@davepacheco took a stab using the initial feedback in your issue. There are some open questions though, would appreciate your thoughts.

davepacheco commented 7 years ago

This looks great! Thanks for providing all the notes about the change. The one extra thing it would be nice to have as an informational property is the request method, since you can't get that from the fullUrl.

Also: if you make a request to a DNS name that was resolved to a specific IP address, is this going to show up in fullUrl using the DNS name or the IP address? We usually find that both are pretty valuable, but the IP address is probably more valuable if we have to choose (because we can figure out what service it was part of if we have the IP, but if we have the DNS name, we can never figure out which instance it was).

Related to #104: there's still the problem that this may not be a connection timeout at all, but rather a DNS timeout. I'm not sure if the name can be changed in a compatible way, but at least the message reflects what really happened here.

Thanks again for doing this. It's going to be a huge help for us.

davepacheco commented 7 years ago

Another thing that would be nice in the VError info is the socket's source IP and port so that we can correlate these issues with logs on the server side (even in the case of a connect timeout, because it's possible we handled this connection, only after the client gave up on it).

DonutEspresso commented 6 years ago

Sorry for dropping the ball on this! Circled back around and made all the proposed changes, including #111. There are now 3 errors depending on when things go awry: DNSTimeoutError, ConnectTimeoutError, and RequestTimeoutError.

All errors return the following fields on the info object: address, fullUrl, method, port, as well as the timeout value that triggered the error.

DonutEspresso commented 6 years ago

I forgot to add - tests won't pass here until restify/errors#86 lands, as we need to standardize on the use of VError (and .info) across all created error types before this PR can work as intended.

DonutEspresso commented 6 years ago

Thanks @hekike, all feedback addressed! Also updated package.json to point restify-errors at the commit needed so that tests will pass. Will point that to latest once a new version is published.

DonutEspresso commented 6 years ago

Bunch of work to rebase master. Once tests pass, this is good to go.