Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Server crash: Error: Unknown error #4363

Closed
sveisvei opened this issue Jun 28, 2022 · 9 comments · Fixed by #4471
Closed

Server crash: Error: Unknown error #4363

sveisvei opened this issue Jun 28, 2022 · 9 comments · Fixed by #4471
Labels
support Questions, discussions, and general support
Milestone

Comments

@sveisvei
Copy link

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/@hapi+hoek@9.2.1/node_modules/@hapi/hoek/lib/error.js:23:19)
    at Object.module.exports [as assert] (./node_modules/.pnpm/@hapi+hoek@9.2.1/node_modules/@hapi/hoek/lib/assert.js:20:11)
    at Response._marshal (./node_modules/.pnpm/@hapi+hapi@20.2.2/node_modules/@hapi/hapi/lib/response.js:566:14)
    at exports.content (./node_modules/.pnpm/@hapi+hapi@20.2.2/node_modules/@hapi/hapi/lib/headers.js:41:24)
    at Object.internals.marshal (./node_modules/.pnpm/@hapi+hapi@20.2.2/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/@hapi+hapi@20.2.2/node_modules/@hapi/hapi/lib/transmit.js:52:9)
    at async Object.exports.send (./node_modules/.pnpm/@hapi+hapi@20.2.2/node_modules/@hapi/hapi/lib/transmit.js:23:13)
    at async Request._reply (./node_modules/.pnpm/@hapi+hapi@20.2.2/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/@hapi+subtext@7.0.3/node_modules/@hapi/subtext/lib/index.js:200:32)
      at Object.internals.parse (./node_modules/.pnpm/@hapi+subtext@7.0.3/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/@hapi+subtext@7.0.3/node_modules/@hapi/subtext/lib/index.js:57:30)
      at async internals.payload (./node_modules/.pnpm/@hapi+hapi@20.2.2/node_modules/@hapi/hapi/lib/route.js:430:35)
      at async Request._lifecycle (./node_modules/.pnpm/@hapi+hapi@20.2.2/node_modules/@hapi/hapi/lib/request.js:371:32)
      at async Request._execute (./node_modules/.pnpm/@hapi+hapi@20.2.2/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/@hapi+bourne@2.0.0/node_modules/@hapi/bourne/lib/index.js:19:22)
        at Object.internals.object (./node_modules/.pnpm/@hapi+subtext@7.0.3/node_modules/@hapi/subtext/lib/index.js:197:27)
        at Object.internals.parse (./node_modules/.pnpm/@hapi+subtext@7.0.3/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/@hapi+subtext@7.0.3/node_modules/@hapi/subtext/lib/index.js:57:30)
        at async internals.payload (./node_modules/.pnpm/@hapi+hapi@20.2.2/node_modules/@hapi/hapi/lib/route.js:430:35)
        at async Request._lifecycle (./node_modules/.pnpm/@hapi+hapi@20.2.2/node_modules/@hapi/hapi/lib/request.js:371:32)
        at async Request._execute (./node_modules/.pnpm/@hapi+hapi@20.2.2/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.

@sveisvei sveisvei added the support Questions, discussions, and general support label Jun 28, 2022
@kanongil
Copy link
Contributor

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':

Hoek.assert(this._state === 'prepare');

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:

hapi/lib/core.js

Lines 553 to 557 in b8ba0ad

if (request) {
const error = Boom.badRequest();
error.output.headers = { connection: 'close' };
request._reply(error);
}

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
Copy link
Contributor

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

hapi/lib/request.js

Lines 370 to 376 in b8ba0ad

try {
var response = await (typeof func === 'function' ? func(this) : this._invoke(func));
}
catch (err) {
Bounce.rethrow(err, 'system');
response = this._core.Response.wrap(err, this);
}

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

@kanongil
Copy link
Contributor

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

@sveisvei
Copy link
Author

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

@kanongil
Copy link
Contributor

kanongil commented Jun 29, 2022

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:

hapi/test/transmit.js

Lines 564 to 567 in b8ba0ad

const client = Net.connect(server.info.port, () => {
client.write('GET / HTTP/1.1\r\naccept-encoding: gzip\r\n\r\n');
});

@sveisvei
Copy link
Author

I will try to make a Pull Request.

@sveisvei
Copy link
Author

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

sveisvei added a commit to sveisvei/hapi that referenced this issue Jun 30, 2022
@sveisvei
Copy link
Author

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

@kanongil
Copy link
Contributor

kanongil commented Nov 7, 2023

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.

@Marsup Marsup added this to the 21.3.5 milestone Mar 14, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
support Questions, discussions, and general support
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants