node:http server doesn't handle read errors
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.
@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.
@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
Thank you! @bartlomieju do you maybe know what should be the way catch such exceptions on the top level?
@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)
From @lucacasonato the issue should be fixable by wrapping Controller.enqueue function and checking if the stream has been closed.
@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}`));
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)
@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:
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.