search

sindresorhus / got

🌐 Human-friendly and powerful HTTP request library for Node.js
MIT License
14.27k stars 935 forks source link

Form-Data POST with retries => Unhandled rejections and timeouts #1282

Closed sampok closed 4 years ago

sampok commented 4 years ago

Describe the bug

Trying to POST with retries using form-data package causes retries to fail with unhandledRejections and timeouts. The reason seems to be that form-data is a stream-like object which has reached the end in the first request. This can be worked around by buffering the form-data, for example by using get-stream package, which is ok in my case. However, maybe there could be a more elegant solution / error handling in this case?

Code to reproduce

Server responding with 503:

const express = require("express");

express()
  .post("/", (req, res) => res.status(503).send("hickup!"))
  .listen(3000);

Requesting:

const got = require("got");
const FormData = require("form-data");

process.on("unhandledRejection", (error) =>
  console.log("unhandledRejection", error)
);

(async () => {
  const form = new FormData();
  form.append("test", "data");

  try {
    await got.post("http://localhost:3000", {
      body: form,
      retry: { limit: 2, methods: ["POST"] },
      timeout: 10 * 1000,
      hooks: {
        beforeRetry: [
          (_, error) => {
            console.log(
              "log: beforeRetry - error",
              error?.response?.statusCode || error?.code
            );
          },
        ],
      },
    });
  } catch (error) {
    console.log("log: give up", error);
  }
})();

Output with trace warnings:

log: beforeRetry - error 503

// ... 10s passes ...

unhandledRejection RequestError: Timeout awaiting 'request' for 10000ms
    at ClientRequest.<anonymous> (/Users/sampo/Codeland/retry-test/node_modules/got/dist/source/core/index.js:785:25)
    at Object.onceWrapper (events.js:422:26)
    at ClientRequest.emit (events.js:327:22)
    at ClientRequest.origin.emit (/Users/sampo/Codeland/retry-test/node_modules/@szmarczak/http-timer/dist/source/index.js:39:20)
    at Socket.socketErrorListener (_http_client.js:467:9)
    at Socket.emit (events.js:315:20)
    at emitErrorNT (internal/streams/destroy.js:100:8)
    at emitErrorCloseNT (internal/streams/destroy.js:68:3)
    at processTicksAndRejections (internal/process/task_queues.js:84:21)
    at Timeout.timeoutHandler [as _onTimeout] (/Users/sampo/Codeland/retry-test/node_modules/got/dist/source/core/utils/timed-out.js:35:25)
    at listOnTimeout (internal/timers.js:551:17)
    at processTimers (internal/timers.js:492:7) {
  name: 'TimeoutError',
  code: 'ETIMEDOUT',
  timings: {
    start: 1590309829863,
    socket: 1590309829863,
    lookup: 1590309829863,
    connect: 1590309829864,
    secureConnect: undefined,
    upload: undefined,
    response: undefined,
    end: undefined,
    error: 1590309839868,
    abort: undefined,
    phases: {
      wait: 0,
      dns: 0,
      tcp: 1,
      tls: undefined,
      request: undefined,
      firstByte: undefined,
      download: undefined,
      total: 10005
    }
  },
  event: 'request'
}

log: beforeRetry - error ETIMEDOUT

(node:36516) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 end listeners added to [FormData]. Use emitter.setMaxListeners() to increase limit
    at _addListener (events.js:390:17)
    at FormData.addListener (events.js:406:10)
    at FormData.once (events.js:437:8)
    at PromisableRequest._onRequest (/Users/sampo/Codeland/retry-test/node_modules/got/dist/source/core/index.js:803:18)
    at PromisableRequest._makeRequest (/Users/sampo/Codeland/retry-test/node_modules/got/dist/source/core/index.js:921:22)
    at processTicksAndRejections (internal/process/task_queues.js:97:5)
    at async /Users/sampo/Codeland/retry-test/node_modules/got/dist/source/core/index.js:265:17

// ... 10s passes ...

log: give up RequestError: Timeout awaiting 'request' for 10000ms
    at ClientRequest.<anonymous> (/Users/sampo/Codeland/retry-test/node_modules/got/dist/source/core/index.js:785:25)
    at Object.onceWrapper (events.js:422:26)
    at ClientRequest.emit (events.js:327:22)
    at ClientRequest.origin.emit (/Users/sampo/Codeland/retry-test/node_modules/@szmarczak/http-timer/dist/source/index.js:39:20)
    at Socket.socketErrorListener (_http_client.js:467:9)
    at Socket.emit (events.js:315:20)
    at emitErrorNT (internal/streams/destroy.js:100:8)
    at emitErrorCloseNT (internal/streams/destroy.js:68:3)
    at processTicksAndRejections (internal/process/task_queues.js:84:21)
    at Timeout.timeoutHandler [as _onTimeout] (/Users/sampo/Codeland/retry-test/node_modules/got/dist/source/core/utils/timed-out.js:35:25)
    at listOnTimeout (internal/timers.js:551:17)
    at processTimers (internal/timers.js:492:7) {
  name: 'TimeoutError',
  code: 'ETIMEDOUT',
  timings: {
    start: 1590309841885,
    socket: 1590309841886,
    lookup: 1590309841886,
    connect: 1590309841887,
    secureConnect: undefined,
    upload: undefined,
    response: undefined,
    end: undefined,
    error: 1590309851887,
    abort: undefined,
    phases: {
      wait: 1,
      dns: 0,
      tcp: 1,
      tls: undefined,
      request: undefined,
      firstByte: undefined,
      download: undefined,
      total: 10002
    }
  },
  event: 'request'
}
unhandledRejection RequestError: Timeout awaiting 'request' for 10000ms
    at ClientRequest.<anonymous> (/Users/sampo/Codeland/retry-test/node_modules/got/dist/source/core/index.js:785:25)
    at Object.onceWrapper (events.js:422:26)
    at ClientRequest.emit (events.js:327:22)
    at ClientRequest.origin.emit (/Users/sampo/Codeland/retry-test/node_modules/@szmarczak/http-timer/dist/source/index.js:39:20)
    at Socket.socketErrorListener (_http_client.js:467:9)
    at Socket.emit (events.js:315:20)
    at emitErrorNT (internal/streams/destroy.js:100:8)
    at emitErrorCloseNT (internal/streams/destroy.js:68:3)
    at processTicksAndRejections (internal/process/task_queues.js:84:21)
    at Timeout.timeoutHandler [as _onTimeout] (/Users/sampo/Codeland/retry-test/node_modules/got/dist/source/core/utils/timed-out.js:35:25)
    at listOnTimeout (internal/timers.js:551:17)
    at processTimers (internal/timers.js:492:7) {
  name: 'TimeoutError',
  code: 'ETIMEDOUT',
  timings: {
    start: 1590309841885,
    socket: 1590309841886,
    lookup: 1590309841886,
    connect: 1590309841887,
    secureConnect: undefined,
    upload: undefined,
    response: undefined,
    end: undefined,
    error: 1590309851887,
    abort: undefined,
    phases: {
      wait: 1,
      dns: 0,
      tcp: 1,
      tls: undefined,
      request: undefined,
      firstByte: undefined,
      download: undefined,
      total: 10002
    }
  },
  event: 'request'
}

Checklist

szmarczak commented 4 years ago

The FormData instance is a stream. Once it's read, you cannot read it again. You need to use get-stream.