Server crash: Error: Unknown error

[sveisvei]

Support plan

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

Context

• node version: v16.15.0
• module version with issue: 20.2.2
• last module version without issue: ?
• environment (e.g. node, browser, native): node
• used with hapi application
• any other relevant information:

What are you trying to achieve or the steps to reproduce?

So playing with some invalid headers, I found a bug.

Test case hapi server

"use strict";

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

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

  server.route({
    method: "*",
    path: "/{p*}",
    options: {
      payload: {
        parse: true, // turning this off, will remove the issue
      },
    },
    handler: (req, h) => {
      console.log("handler");
      return h.response("fail").code(404);
    },
  });

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

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

init();

command to reproduce the crash:

nc 127.0.0.1 8080 < body.txt

body.txt

POST / HTTP/1.1
Host: localhost
Content-Length: 5
Transfer Encoding:chunked

1
Z\n\Q\n\n

What was the result you got?

Error: Unknown error
    at new module.exports (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hoek/lib/error.js:23:19)
    at Object.module.exports [as assert] (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hoek/lib/assert.js:20:11)
    at Response._marshal (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/response.js:566:14)
    at exports.content (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/headers.js:41:24)
    at Object.internals.marshal (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/transmit.js:41:15)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async Object.internals.fail (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/transmit.js:52:9)
    at async Object.exports.send (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/transmit.js:23:13)
    at async Request._reply (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/request.js:457:9)

Inspecting the request.response surfaces this stack:

Error: Invalid request payload JSON format
      at Object.internals.object (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/subtext/lib/index.js:200:32)
      at Object.internals.parse (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/subtext/lib/index.js:110:22)
      at processTicksAndRejections (node:internal/process/task_queues:96:5)
      at async Object.exports.parse (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/subtext/lib/index.js:57:30)
      at async internals.payload (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/route.js:430:35)
      at async Request._lifecycle (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/request.js:371:32)
      at async Request._execute (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/request.js:281:9) {
    data: SyntaxError: Unexpected token Z in JSON at position 2
        at JSON.parse (<anonymous>)
        at Object.exports.parse (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/bourne/lib/index.js:19:22)
        at Object.internals.object (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/subtext/lib/index.js:197:27)
        at Object.internals.parse (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/subtext/lib/index.js:110:22)
        at processTicksAndRejections (node:internal/process/task_queues:96:5)
        at async Object.exports.parse (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/subtext/lib/index.js:57:30)
        at async internals.payload (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/route.js:430:35)
        at async Request._lifecycle (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/request.js:371:32)
        at async Request._execute (./node_modules/.pnpm/@[email protected]/node_modules/@hapi/hapi/lib/request.js:281:9)

So my assumption is that the there is some missing cleanup while handling the actual error response.

What result did you expect?

Server should not die.

[kanongil]

Thanks for the report. I have investigated the issue, and have an understanding on what is going on.

The crash itself happens when Hapi encounters an inconsistent internal state here, where this._state === 'close': https://github.com/hapijs/hapi/blob/b8ba0adc7c3255995cb56a9a740c4f9750b80e6b/lib/response.js#L566

Now, how does Hapi get into this inconsistent state? This happens because your crafted request initially looks OK, and Hapi starts the regular request processing chain. However, before this processing is completed, the connection emits an 'clientError' event (with error HPE_INVALID_METHOD) which is handled here: https://github.com/hapijs/hapi/blob/b8ba0adc7c3255995cb56a9a740c4f9750b80e6b/lib/core.js#L553-L557

This logic sends an immediate custom response, but is not designed to work while the regular request processing is active! This means that the regular request processing will continue to run, and eventually crash the server once it tries to set a new response.

The fix will probably be to stop or limit the regular request processing once the 'clientError' is triggered.

[kanongil]

A bit further analysis show that the error is isolated to lifecycle handlers that return any response, during which a 'clientError' event is triggered. That this triggers during payload parsing makes sense.

The fix will be to add another

if (this._isReplied) {
    return;
}

after

https://github.com/hapijs/hapi/blob/b8ba0adc7c3255995cb56a9a740c4f9750b80e6b/lib/request.js#L370-L376

since the state can change during the await, and this._setResponse(response) must never be called when this._isReplied is set.

[kanongil]

I don't have time to create a PR with a failing testcase, so hope someone else can finish this.

[sveisvei]

I tried to use server.inject to reproduce this, but was unable to - any tips how this can be done?

[kanongil]

Yeah, server.inject() cannot be used for this connection level issue, as it does not use a real connection.

You will need to start() the server and send your payload with a simple client similar to this: https://github.com/hapijs/hapi/blob/b8ba0adc7c3255995cb56a9a740c4f9750b80e6b/test/transmit.js#L564-L567

[sveisvei]

I will try to make a Pull Request.

[sveisvei]

I have fixed the issue, but having trouble getting coverage for _setResponse to 100% after the change...

[sveisvei]

@kanongil Do you have any suggestion what to do here to get the coverage up?

[kanongil]

Had another look into this, and it seems that my analysis was slightly wrong.

Node errors with HPE_INVALID_METHOD, which was strange since POST is valid but now I understand. It is because the request is considered complete before the end of the payload, and the error is from trying to parse what it thinks is a pipelined request.

Hapi seems gets a clientError on the socket for what is supposed to be the next request. Changing the response to the current request based on this, is not really correct. I have made a fix for this in #4471.

This fix means that this case won't fail anymore, but return a code 400 due to the malformed JSON in the request, and another code 400 due to the malformed pipelined request.