I always got a timeout error after request completion.

I send a request in Chrome and got the response correctly. But I always got a timeout error after about 2 minutes in the server terminal. I only got error in node 18 and windows 10, if I use node 16 there is no error.

[10:52:22.928] ERROR (16820): Request timeout
    tags: [
      "connection",
      "client",
      "error"
    ]
    err: {
      "type": "Error",
      "message": "Request timeout",
      "stack":
          Error [ERR_HTTP_REQUEST_TIMEOUT]: Request timeout
              at new NodeError (node:internal/errors:399:5)
              at onRequestTimeout (node:_http_server:787:30)
              at Server.checkConnections (node:_http_server:600:7)
              at listOnTimeout (node:internal/timers:569:17)
              at process.processTimers (node:internal/timers:512:7)
      "code": "ERR_HTTP_REQUEST_TIMEOUT"
    }

Support plan

is this issue currently blocking your project? (yes):
is this issue affecting a production system? (yes):

Context

node version: v18.15.0
module version: 21.3.1
environment (e.g. node, browser, native): Windows 10, Chrome
used with (e.g. hapi application, another framework, standalone, ...): hapi-pino 12.0.0
any other relevant information:

"dependencies": {
    "@hapi/boom": "^10.0.1",
    "@hapi/hapi": "^21.3.1",
    "@hapi/inert": "^7.1.0",
    "@hapi/vision": "^7.0.1",
    "dotenv": "^16.0.3",
    "echarts": "^5.4.2",
    "hapi-pino": "^12.0.0",
    "hapi-swagger": "^16.0.1",
    "joi": "^17.9.1",
    "pino-pretty": "^10.0.0"
  },
  "devDependencies": {
    "@hapi/code": "^9.0.3",
    "@hapi/lab": "^25.1.2",
    "eslint": "^8.38.0",
    "nodemon": "^2.0.22"
  }

How can we help?

This is a demo.

"use strict";

const Hapi = require("@hapi/hapi");

const init = async () => {
  const server = Hapi.server({
    port: 8080,
    host: "0.0.0.0",
  });

  await server.register({
    plugin: require("hapi-pino"),
    options: {
      transport: {
        target: "pino-pretty",
      },
      logRequestComplete: true,
    },
  });

  server.route({
    method: "GET",
    path: "/",
    handler: (request, h) => {
      return "Hello Hapi!";
    },
  });

  await server.start();
  console.log("Server running on %s", server.info.uri);
};

process.on("unhandledRejection", (err) => {
  console.log(err);
  process.exit(1);
});

init();

Interesting. Maybe hapi doesn't properly clean up? Though it could also be a subtle node.js bug.

Interesting. Maybe hapi doesn't properly clean up? Though it could also be a subtle node.js bug.

My colleague got same error when run my demo. I found if I use firefox or curl command there is no error.

Thanks. I can confirm the Chrome?? specific issue on my macOS machine using node 19.

I bit of investigation with Wireshark show that Chrome opens an extra connection to the server, without sending any requests on it. This for some reason eventually triggers a node.js request timeout as you see.

Hapi sends a 400 Bad Request response to Chrome, but the connection stays open. This does not seem like the correct way to handle this.

While this is clearly a node.js error (ERR_HTTP_REQUEST_TIMEOUT should not trigger when only the TCP connection is open), I expect it would be prudent for Hapi to better handle this case.

Further investigation into the node.js internals shows that it is the parser that somehow thinks that an initial request on a socket starts when the connection is opened, and not when the first packet data is received. A later pipelined request on the same connection won't trigger this issue.

The request expiration logic, is triggered in an interval loop controlled by the connectionsCheckingInterval option (default 30000 ms).

The .expired() check calls into native http parser code.

I found a likely culprit, originally introduced in nodejs/node@df08d52. While the patch also applies to node 16, the effect is only seen on v18+ since this is when the server.requestTimeout default was changed from 0 to 300000.

FYI this issue likely won't be exposed when hapi is running behind a reverse proxy like nginx, which is a more typical production scenario.

@kanongil

I found a likely culprit, originally introduced in nodejs/node@df08d52. While the patch also applies to node 16, the effect is only seen on v18+ since this is when the server.requestTimeout default was changed from 0 to 300000.

FYI this issue likely won't be exposed when hapi is running behind a reverse proxy like nginx, which is a more typical production scenario.

@kanongil Thank your so much for your help. You are right, This issue won't exposed when running behind a reverse proxy. Is it possible to do something to avoid this error in dev environment without a reverse proxy ? I use swagger web client in Chrome.

You should be able to get the old behaviour by setting server.listener.requestTimeout = 0 once it is listening.

For a more long term solution, I expect that hapi should detect this case and just silently send a 408 response, similar to what node does if there is no clientError event listener. Oddly enough, this behaviour is not documented.

For those who finds out that manipulating server.listener.requestTimeout is not enough, you may need to adjust the server.listener.headersTimeout option as well.

Context

Chrome 131.0.* (some older versions did not reproduce the error)
Node.js v20.18.1
npm 10.8.2

Dependencies:

❯ npm list @hapi/hapi hapi-pino pino-pretty
├── @hapi/hapi@21.3.12
├── hapi-pino@12.1.0
└── pino-pretty@13.0.0

Details

By default, with no server options overwrite we receive ERR_HTTP_REQUEST_TIMEOUT error in about 1m after the successful request is processed and server.listener.requestTimeout = 0 makes no difference. It makes sense, since server.requestTimeout is set to 5m by default, while server.headersTimeout is set to 1m and it's the one to blame.

After testing it locally we get error within the margin of couple seconds:

Defaults, no server options overwrite: 1m 20s
Only with server.listener.requestTimeout = 0: 1m 24s
Only with server.listener.headersTimeout = 0: 5m 25s

These settings prevent the error:

const hapi = require('@hapi/hapi');

const server = hapi.server({
  port: 8080,
  host: '0.0.0.0',
});

// ...
server.listener.headersTimeout = 0;
server.listener.requestTimeout = 0;

await server.start();

IMPORTANT: this workaround is expected to be used only on non-production environment, when application doesn't have a reverse proxy in front of it. Also, issue seems to affect only requests made via Chrome, while Firefox, Safari or cURL stay error-free (at the time of writing).

server.headersTimeout
It must be set to a non-zero value (e.g. 120 seconds) to protect against potential Denial-of-Service attacks in case the server is deployed without a reverse proxy in front.

P.S.: If options are passed directly into the http[s].createServer() instead of being overwritten on the listener initialized by hapi.js, then {requestTimeout: 0} would be enough, since headersTimeout is set to MathMin(60_000, this.requestTimeout);:

const hapi = require('@hapi/hapi');
const http = require('node:http');

const server = hapi.server({
  port: 8080,
  host: '0.0.0.0',
  listener: http.createServer({
    requestTimeout: 0,
  }),
});

Navigation Menu

Repository navigation

I always got a timeout error after request completion. #4447

Support plan

Context

How can we help?

Context

Details

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

I always got a timeout error after request completion. #4447

Description

Support plan

Context

How can we help?

Activity

kanongil commented on Apr 18, 2023

galenzh commented on Apr 18, 2023

kanongil commented on Apr 18, 2023

kanongil commented on Apr 18, 2023

kanongil commented on Apr 18, 2023

galenzh commented on Apr 18, 2023

kanongil commented on Apr 20, 2023

kisaiev commented on Dec 4, 2024

Context

Details

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions