Got: Timeout causes incomplete response to be cached

[UltCombo]

Describe the bug

• Node.js version: 8.11.2
• OS & version: Manjaro Linux

Actual behavior

Using latest version ([email protected]).

When a cacheable request fails due to timeout error, subsequent requests to the same resource will receive an incomplete response of the first request from cache.

Expected behavior

Got should not cache responses from timed out requests.

Code to reproduce

const http = require('http');
const { extend: gotExtend } = require('got');

const got = gotExtend({
    json: true,
    cache: new Map(),
    retry: 0,
    timeout: 50,
});

http.createServer((req, res) => {
  res.writeHead(200, {
    'cache-control': 'public, must-revalidate, max-age=60',
  });
  res.write('{"a":1');
  setTimeout(() => {
    res.end('}');
  }, 100);
}).listen(3000, () => {
  // This will fail with TimeoutError.
  got('http://127.0.0.1:3000').then(console.log, console.error);

  setTimeout(() => {
    // This will fail with ParseError as it will use incomplete response from cache.
    got('http://127.0.0.1:3000').then(console.log, console.error);
  }, 100);
});

Output:

{ TimeoutError: Timeout awaiting 'request' for 50ms
    at ClientRequest.request.once.error (/home/ult/workspace/service-rails-web-api/node_modules/got/source/request-as-event-emitter.js:160:14)
    at Object.onceWrapper (events.js:315:30)
    at emitOne (events.js:121:20)
    at ClientRequest.emit (events.js:211:7)
    at ClientRequest.origin.emit.args [as emit] (/home/ult/workspace/service-rails-web-api/node_modules/@szmarczak/http-timer/source/index.js:36:11)
    at Immediate.timeoutHandler (/home/ult/workspace/service-rails-web-api/node_modules/got/source/utils/timed-out.js:63:11)
    at runCallback (timers.js:814:20)
    at tryOnImmediate (timers.js:768:5)
    at processImmediate [as _immediateCallback] (timers.js:745:5)
  name: 'TimeoutError',
  code: 'ETIMEDOUT',
  host: '127.0.0.1:3000',
  hostname: '127.0.0.1',
  method: 'GET',
  path: '/',
  socketPath: undefined,
  protocol: 'http:',
  url: 'http://127.0.0.1:3000/',
  event: 'request' }
{ ParseError: Unexpected end of JSON input in "http://127.0.0.1:3000/":
{"a":1...
    at EventEmitter.emitter.on (/home/ult/workspace/service-rails-web-api/node_modules/got/source/as-promise.js:65:26)
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:188:7)
  name: 'ParseError',
  host: '127.0.0.1:3000',
  hostname: '127.0.0.1',
  method: 'GET',
  path: '/',
  socketPath: undefined,
  protocol: 'http:',
  url: 'http://127.0.0.1:3000/',
  statusCode: 200,
  statusMessage: 'OK' }

Interestingly, if retry: 0 is removed (thus enabling Got's default retry logic), both requests fail with ParseError when I would expect them to fail with TimeoutError. This is because retry performs subsequent requests to the same resource and exhibit the same problem.

I looked around got and cacheable-request's code bases but I'm not sure what's the issue, likely related to how got handles timeout timers and request abortion.

Checklist

• [x] I have read the documentation.
• [x] I have tried my code with the latest version of Node.js and Got.

[UltCombo]

Sent PR to cacheable-request: https://github.com/lukechilds/cacheable-request/pull/63

[thomassuckow]

So your change to cacheable-request will change ParseError to a TimeoutError correct?

[FabricioMatteMassive]

@thomassuckow In this specific test case, yes. However, the PR fixes the root cause of the issue, which was cacheable-request caching responses for requests that timed out and were aborted by Got.

This means if a subsequent request succeeds within the time limit, the client will now get a successful response instead of a ParseError.

[lukechilds]

This should be resolved now as of [email protected].