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

node:http server doesn't handle read errors #22820

Closed
ianbrault opened this issue Mar 9, 2024 · 8 comments · Fixed by #24243 or #24946
Closed

node:http server doesn't handle read errors #22820

ianbrault opened this issue Mar 9, 2024 · 8 comments · Fixed by #24243 or #24946
Assignees
Labels
bug Something isn't working correctly node API Related to various "node:*" modules APIs node compat

Comments

@ianbrault
Copy link

Version: Deno 1.40.3

Hit the following exception while my webserver was running:

[2024.3.5 07:21:08]: GET /
[2024.3.5 07:25:00]: GET /
[2024.3.5 07:25:00]: GET /
[2024.3.5 07:25:00]: GET /
[2024.3.5 07:25:00]: GET /
error: Uncaught BadResource: Bad resource ID
    at Object.pull (ext:deno_web/06_streams.js:946:38)
    at Module.invokeCallbackFunction (ext:deno_webidl/00_webidl.js:944:16)
    at ReadableByteStreamController.pullAlgorithm (ext:deno_web/06_streams.js:3559:14)  
    at readableByteStreamControllerCallPullIfNeeded (ext:deno_web/06_streams.js:1242:49)
    at ReadableByteStreamController.[[[PullSteps]]] (ext:deno_web/06_streams.js:5979:5) 
    at readableStreamDefaultReaderRead (ext:deno_web/06_streams.js:2509:36)
    at ReadableStreamDefaultReader.read (ext:deno_web/06_streams.js:5476:5)
    at IncomingMessageForServer.read [as _read] (node:http:1176:42)
    at IncomingMessageForServer.Readable.read (ext:deno_node/_stream.mjs:2999:16)
    at flow (ext:deno_node/_stream.mjs:3371:38)

The server is using express on top of Deno:

const app = express();
// ... configure middleware ...
await mongoose.connect("mongodb://localhost:27017");
app.listen(3030, () => info(`server running on https://127.0.0.1:${port}`));

and the home route does nothing outside of sending a file:

router.get("/", (_req, res) => {
    info("GET /");
    res.sendFile("home.html", {
        root: path.getViewsDirectory("home")
    });
});

I am suspicious that the exception is due to the 4 requests within the same second.

@bartlomieju bartlomieju added bug Something isn't working correctly node compat node API Related to various "node:*" modules APIs labels Mar 9, 2024
@punarinta
Copy link

@ianbrault do you know, by the way, if there's any way to catch this exception on a global level to prevent server restart?
I tried both globalThis.addEventListener('error', ... and globalThis.addEventListener('unhandledrejection', ... but none seems to help.

@ianbrault
Copy link
Author

@punarinta I am not aware if there's a way to catch this but perhaps someone with more knowledge on the matter can chime in

@bartlomieju bartlomieju changed the title Bad resource ID exception when reading incoming server messages node:http server doesn't handle read errors Apr 2, 2024
@punarinta
Copy link

Thank you!
@bartlomieju do you maybe know what should be the way catch such exceptions on the top level?

@satyarohith
Copy link
Member

@ianbrault, thanks for opening the issue. I created an example to reproduce the bug but it resulted in a different error. Is it possible for you to share an example that reproduces the error that you mentioned?

Example:

import express from 'express';

const app = express();

app.get("/", (_req, res) => {
  console.info("GET /");
  res.sendFile("home.html", {
    root: import.meta.dirname,
  });
});

const port = 3000;
app.listen(port, () => {
  console.log(`Server listening on port ${port}`);
});

The error I encountered is the following which is triggered after wrk finishes its testing:

GET /
error: Uncaught (in promise) TypeError: The stream controller cannot close or enqueue.
    at ReadableStreamDefaultController.enqueue (ext:deno_web/06_streams.js:6057:13)
    at Function.#enqueue (node:http:1352:18)
    at ServerResponse.write [as _write] (node:http:1391:32)
    at writeOrBuffer (ext:deno_node/_stream.mjs:3947:16)
    at _write (ext:deno_node/_stream.mjs:3892:14)
    at ServerResponse.Writable.write (ext:deno_node/_stream.mjs:3895:14)
    at ReadStream.ondata (ext:deno_node/_stream.mjs:3179:26)
    at ReadStream.emit (ext:deno_node/_stream.mjs:1851:9)
    at addChunk (ext:deno_node/_stream.mjs:2873:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2852:13)

@bartlomieju
Copy link
Member

From @lucacasonato the issue should be fixable by wrapping Controller.enqueue function and checking if the stream has been closed.

@ianbrault
Copy link
Author

ianbrault commented Jun 2, 2024

@satyarohith I have not been able to reproduce using wrk locally but for an example with some additional detail:

import express from "npm:[email protected]";
import mongoose from "npm:mongoose@^6.7";

import * as path from "$std/path/mod.ts";

function getViewsDirectory(app: string): string {
    const filePath = path.fromFileUrl(import.meta.url);
    const dirPath = path.dirname(filePath)
    return path.join(dirPath, app, "views");
}

const router = express.Router();

router.get("/", (_req, res) => {
    info("GET /");
    res.sendFile("home.html", {
        root: path.getViewsDirectory("home")
    });
});

const app = express();
app.use(express.json());
app.use(express.urlencoded({extended: true}));
app.use(router);

await mongoose.connect("mongodb://localhost:27017");

const port = 3030;
app.listen(port, () => console.log(`server running on https://127.0.0.1:${port}`));

@raaymax
Copy link

raaymax commented Jun 15, 2024

I got here from #15203, I have similar problem with server sent events.

import express from "express";
const app = express();


app.get('/sse', async (req, res) => {
  res.header('Content-Type', 'text/event-stream')
  req.once('close', () => {
    if (req.aborted) {
      console.log('request closed')
    }
  })
  while(true) {
    res.write('data: hello\n\n')
    await new Promise(resolve => setTimeout(resolve, 1000))
  }
});

app.listen(8000, () => console.log('Server listening on port 8000'))

After closing connection "request closed" should be displayed (this works in node)
Instead I get following error:

error: Uncaught (in promise) TypeError: The stream controller cannot close or enqueue.
    at ReadableStreamDefaultController.enqueue (ext:deno_web/06_streams.js:6064:13)
    at Function.#enqueue (node:http:1042:18)
    at ServerResponse.write [as _write] (node:http:1075:32)
    at writeOrBuffer (ext:deno_node/_stream.mjs:3956:16)
    at _write (ext:deno_node/_stream.mjs:3901:14)
    at ServerResponse.Writable.write (ext:deno_node/_stream.mjs:3904:14)
    at file:///.../test.js:13:9
    at eventLoopTick (ext:core/01_core.js:207:9)

@bageren
Copy link

bageren commented Jul 15, 2024

@satyarohith

We've been seeing a similar issue in our production environment for a while now:

error: Uncaught (in promise) BadResource: Bad resource ID
    at Object.pull (ext:deno_web/06_streams.js:937:38)
    at Module.invokeCallbackFunction (ext:deno_webidl/00_webidl.js:981:16)
    at ReadableByteStreamController.pullAlgorithm (ext:deno_web/06_streams.js:3558:14)
    at readableByteStreamControllerCallPullIfNeeded (ext:deno_web/06_streams.js:1233:49)
    at ReadableByteStreamController.[[[PullSteps]]] (ext:deno_web/06_streams.js:5985:5)
    at readableStreamDefaultReaderRead (ext:deno_web/06_streams.js:2508:36)
    at ReadableStreamDefaultReader.read (ext:deno_web/06_streams.js:5482:5)
    at IncomingMessageForServer.read [as _read] (node:http:1284:42)
    at IncomingMessageForServer.Readable.read (ext:deno_node/_stream.mjs:2996:16)
    at resume_ (ext:deno_node/_stream.mjs:3346:16)

I found this issue an prayed that upgrading Deno would solve it. Unfortunately it didn't - I've just seen it again on 1.45.2.

We are using Apollo server with express middleware. It seems to happen (in some cases 🤷) when our frontend sends a GraphQL request, cancels it shortly after and then sends another request:
Screenshot 2024-07-15 at 16 59 32

Unfortunately I've been unable to make a minimal reproducible example.

It would be greatly appreciated if someone could help investigate this. I'd be happy to provide more details if needed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working correctly node API Related to various "node:*" modules APIs node compat
Projects
None yet
7 participants