uNetworking / uWebSockets.js

μWebSockets for Node.js back-ends :metal:
Apache License 2.0
8.08k stars 574 forks source link

uWebSockets DELETE request handler always close connection #817

Closed webcarrot closed 2 years ago

webcarrot commented 2 years ago

I'm not sure if this is a bug or some RFC requirement (nodejs doesn't care about such details 😉 )

I only found https://support.oracle.com/knowledge/Middleware/1577216_1.html that looks similar.

Example code (test-uws.mjs):

import { App } from 'uWebSockets.js';
import { request, Agent } from 'node:http'; // same with undici/fetch

const agent = new Agent({ keepAlive: true, maxSockets: 1 }); // share same connection

let total = 0;
async function req(method) {
    try {
        const no = ++total;
        await new Promise((r) => setTimeout(r, 5));
        console.log(`${method}:START:${no}`);
        await new Promise((resolve, reject) => {
            request(
                'http://127.0.0.1:4444/',
                {
                    method,
                    agent,
                },
                (res) => {
                    res.on('data', () => {});
                    res.on('end', resolve);
                    res.once('error', reject);
                },
            ).end();
        });
        console.log(`${method}:DONE:${no}`);
    } catch (err) {
        console.error(err.message);
        process.exit(1);
    }
}

await new Promise((r) =>
    App()
        .any('/*', async (res, req) => {
            res.writeStatus('204 No Content');
            console.log(`${req.getMethod().toUpperCase()}:UWS:${total}`);
            res.end();
        })
        .listen(4444, r),
);

await req('GET');
await req('PUT');
await req('POST');
await req('DELETE'); // this one close connection on UWS side
await req('GET');

process.exit(0);

node test-uws.mjs produce:

GET:START:1
GET:UWS:1
GET:DONE:1
PUT:START:2
PUT:UWS:2
PUT:DONE:2
POST:START:3
POST:UWS:3
POST:DONE:3
DELETE:START:4
DELETE:UWS:4
DELETE:DONE:4
GET:START:5
node:events:504
      throw er; // Unhandled 'error' event
      ^

Error: socket hang up
    at connResetException (node:internal/errors:691:14)
    at Socket.socketOnEnd (node:_http_client:466:23)
    at Socket.emit (node:events:538:35)
    at endReadableNT (node:internal/streams/readable:1345:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
Emitted 'error' event on ClientRequest instance at:
    at Socket.socketOnEnd (node:_http_client:466:9)
    at Socket.emit (node:events:538:35)
    at endReadableNT (node:internal/streams/readable:1345:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21) {
  code: 'ECONNRESET'
}
webcarrot commented 2 years ago

Same example but in pure node:

import { request, Agent, createServer } from 'node:http';

const agent = new Agent({ keepAlive: true, maxSockets: 1 }); // share same connection

let total = 0;
async function req(method) {
    try {
        const no = ++total;
        await new Promise((r) => setTimeout(r, 5));
        console.log(`${method}:START:${no}`);
        await new Promise((resolve, reject) => {
            request(
                'http://127.0.0.1:4444/',
                {
                    method,
                    agent,
                },
                (res) => {
                    res.on('data', () => {});
                    res.on('end', resolve);
                    res.once('error', reject);
                },
            ).end();
        });
        console.log(`${method}:DONE:${no}`);
    } catch (err) {
        console.error(err.message);
        process.exit(1);
    }
}

await new Promise((r) =>
    createServer((req, res) => {
        res.statusCode = 204;
        console.log(`${req.method}:NODE:${total}`);
        res.end();
    }).listen(4444, r),
);

await req('GET');
await req('PUT');
await req('POST');
await req('DELETE');
await req('GET');

process.exit(0);

Produce:

GET:START:1
GET:NODE:1
GET:DONE:1
PUT:START:2
PUT:NODE:2
PUT:DONE:2
POST:START:3
POST:NODE:3
POST:DONE:3
DELETE:START:4
DELETE:NODE:4
DELETE:DONE:4
GET:START:5
GET:NODE:5
GET:DONE:5
webcarrot commented 2 years ago

If this behaviour is intended then the problem is that client do not receive information that connection was closed - for now, as workaround I do res.end(foo,true) for delete method handlers ( except res.tryEnd() - in this case i send by hand Connection: close header which is not optimal but should work).

uNetworkingAB commented 2 years ago

That's strange I just made a bunch of DELETE requests with curl and it worked fine (with modded HelloWorld with app.any instead of app.get):

alexhultman@DESKTOP-4SO009K:~/uWebSockets$ curl -X DELETE http://localhost:3000
Hello world!alexhultman@DESKTOP-4SO009K:~/uWebSockets$ curl -X DELETE http://localhost:3000
Hello world!alexhultman@DESKTOP-4SO009K:~/uWebSockets$ curl -X DELETE http://localhost:3000
Hello world!alexhultman@DESKTOP-4SO009K:~/uWebSockets$ curl -X DELETE http://localhost:3000
Hello world!alexhultman@DESKTOP-4SO009K:~/uWebSockets$ 
e3dio commented 2 years ago

This issue affects HEAD OPTIONS TRACE CONNECT DELETE methods from node client for latest uWS.js version. The thing in common with those methods is node http client is not sending content-length header, for POST PUT PATCH it is sending content-length: 0 header. A single curl -X DELETE http://localhost:3000 does not cause issue, but send 2 keepalive with curl -X DELETE http://localhost:3000 -X DELETE http://localhost:3000 does cause issue, is also missing content-length header. Assuming relevant code is here https://github.com/uNetworking/uWebSockets/blob/master/src/HttpParser.h#L308

uNetworkingAB commented 2 years ago

@e3dio kick ass analysis. This makes a lot of sense

uNetworkingAB commented 2 years ago

Can you try latest release, should be fixed

e3dio commented 2 years ago

All methods tested working uWS.js v20.13 node client and curl client ✔️

e3dio commented 2 years ago

Also tested new transfer-encoding: chunked feature with POST data, working as expected ✔️

webcarrot commented 2 years ago

@uNetworkingAB @e3dio uWebSockets close transfer-encoding: chunked "connections" silently:

import { App } from 'uWebSockets.js';
import { request, Agent } from 'node:http';
import { Readable } from 'node:stream';
import { randomBytes } from 'node:crypto';

const agent = new Agent({ keepAlive: true, maxSockets: 1 });

let total = 0;
async function req(method) {
    try {
        const no = ++total;
        await new Promise((r) => setTimeout(r, 5));
        console.log(`${method}:START:${no}`);
        await new Promise((resolve, reject) => {
            const req = request(
                'http://127.0.0.1:4444/',
                {
                    method,
                    agent,
                },
                (res) => {
                    res.on('data', () => {});
                    res.on('end', resolve);
                    res.once('error', reject);
                },
            ).on('error', reject);
            Readable.from(randomBytes(20000)).pipe(req);
        });
        console.log(`${method}:DONE:${no}`);
    } catch (err) {
        console.error(`ERROR:${err.message}`);
        process.exit(1);
    }
}

await new Promise((r) =>
    App()
        .any('/*', async (res, req) => {
            console.log(
                `${req.getMethod().toUpperCase()}:UWS:${total}:${req.getHeader('transfer-encoding')}`,
            );
            let byteLength = 0;
            res.onData((c, isLast) => {
                byteLength += c.byteLength;
                if (isLast) {
                    console.log('received', byteLength);
                    res.writeStatus('204 No Content');
                    res.end();
                    // workaround:
                                        // res.end(undefined, true);
                }
            });
            res.onAborted(() => {
                console.log('aborted');
                res.writeStatus('204 No Content');
                res.end();
            });
        })
        .listen(4444, r),
);

await req('POST');
await req('POST');

process.exit(0);

Produce:

POST:START:1
POST:UWS:1:chunked
received 20000
POST:DONE:1
POST:START:2
ERROR:socket hang up
e3dio commented 2 years ago

Now you are referencing different issue, transfer-encoding: chunked request connection appears to close after request, so next keep-alive request fails with error. I did not try that one, can confirm connection close and error next request, only closes after transfer-encoding: chunked request end()

e3dio commented 2 years ago

Interestingly it does work without client error when you do res.end(undefined, true) which I see you mentioned in your updated code. Probably gives the client a heads up connection is about to close, but ideally connection should not close after request

uNetworkingAB commented 2 years ago

Good tests. Can I keep them?

webcarrot commented 2 years ago

@uNetworkingAB yes

uNetworkingAB commented 2 years ago

This is a pretty mild bug though; the other bug was a regression of old functionality. This new bug is a broken new feature that doesn't affect any old usages. It's some kind of bug in the status of the chunked parser that gets uncleared and so it breaks down on next request. Need to improve its unit test to catch this.

uNetworkingAB commented 2 years ago

The bug is really just that we expect an empty trailer after chunked body, while there simply is none. So it's a simple modification to fix it.

uNetworkingAB commented 2 years ago

Fixed now:

POST:START:1 POST:UWS:1:chunked received 15 POST:DONE:1 POST:START:2 POST:UWS:2:chunked received 15 POST:DONE:2

Just need to release this

uNetworkingAB commented 2 years ago

Fixed in v20.14.0

uasan commented 2 years ago

By the way, there is a well-known vulnerability (Transfer-Encoding + Content-Length) that almost all popular HTTP servers had. https://cwe.mitre.org/data/definitions/444.html