Posting to Endpoint with Express using Content-Type: application/json does not emit events to req.on('close')

[elucidsoft]

Is there an existing issue for this?

• I have searched the existing issues

Current behavior

The req.on('close') event is not emitting when the content-type: applicaiton/json header is set. This makes no sense, the content-type header should not change the behavior when the connection is closed. This use to work, the behavior has somehow changed in either upgrade 7 or 8. We just observed this behavior, but we have done several nestjs upgrades and we are not sure when the behavior started. This took an extremely long time to track down, and is rather critical to our workflow, can please advise a temp workaround for us would be very helpful!!

Minimum reproduction code

https://github.com/elucidsoft/nestjs-broken-middleware

Steps to reproduce

1. npm i
2. npm run start:debug

Working without Header

1. Use insomnia or curl or whatever tool you want to post to the http://localhost:3020/test endpoint, with the content-type: header NOT set.
2. Examine console output of 'Inside test', followed by '-- Connection Closed --'
3. Event emitted properly.

Broken with application/json Content-Type header

1. Use insomnia or curl or whatever tool you want to post to the http://localhost:3020/test endpoint, with the content-type: application/json header set.
2. Examing console output of only 'Inside test' but no '-- Connection Closed --'
3. Event did NOT emit properly.

Expected behavior

Event should emit no matter the content-type set.

Package

• I don't know. Or some 3rd-party package
• @nestjs/common
• @nestjs/core
• @nestjs/microservices
• @nestjs/platform-express
• @nestjs/platform-fastify
• @nestjs/platform-socket.io
• @nestjs/platform-ws
• @nestjs/testing
• @nestjs/websockets
• Other (see below)

Other package

No response

NestJS version

9.1.4

Packages versions

  "dependencies": {
    "@nestjs/common": "^8.0.0",
    "@nestjs/core": "^8.0.0",
    "@nestjs/platform-express": "^8.0.0",
    "body-parser": "^1.20.1",
    "reflect-metadata": "^0.1.13",
    "rxjs": "^7.5.5"
  },
  "devDependencies": {
    "@nestjs/cli": "^8.0.0",
    "@nestjs/schematics": "^8.0.0",
    "@nestjs/testing": "^8.0.0",
    "@types/express": "^4.17.13",
    "@types/jest": "^28.1.4",
    "@types/node": "^18.0.3",
    "@types/supertest": "^2.0.12",
    "@typescript-eslint/eslint-plugin": "^5.30.5",
    "@typescript-eslint/parser": "^5.30.5",
    "eslint": "^8.19.0",
    "eslint-config-prettier": "^8.5.0",
    "eslint-plugin-prettier": "^4.2.1",
    "jest": "^28.1.2",
    "prettier": "^2.7.1",
    "source-map-support": "^0.5.21",
    "supertest": "^6.2.4",
    "ts-jest": "^28.0.5",
    "ts-loader": "^9.3.1",
    "ts-node": "^10.8.2",
    "tsconfig-paths": "^4.0.0",
    "typescript": "^4.7.4"
  },

I also verified this is broken in 8.x

Node.js version

16.14.2

In which operating systems have you tested?

• macOS
• Windows
• Linux

Other

I verified this behavior on multiple platforms of Linux, inside docker, and outside docker, with multiple REST clients. All observed same behavior.

[elucidsoft]

I added an express version to the repo, so you can run them from same repo to see that express behaves as you would expect, and nestjs is not.

[micalevisk]

btw you forgot to call app.use(bodyParser.json()) in the Express version. But yeah, it does triggers the 'close' event.

---

I just tested your repro with v8 and v9. None of them emits the 'close' nor the 'end' event on that req object when bodyParse is not false 🤔 Even when we use our own body-parser middleware

[micalevisk]

after investigating that a bit, I found this weird(?) behavior:

nest/packages/core/router/router-execution-context.ts

Lines 139 to 151 in 8e3af06

	const fnApplyPipes = this.createPipesFn(pipes, paramsOptions);
	const handler =
	<TRequest, TResponse>(
	args: any[],
	req: TRequest,
	res: TResponse,
	next: Function,
	) =>
	async () => {
	fnApplyPipes && (await fnApplyPipes(args, req, res, next));
	return callback.apply(instance, args);
	};

adding const onClose = () => console.log('----------'); req.on('close', onClose)

right before L149, it will make that onClose be called. But when we move that line to after L149, onClose won't get called. Maybe that's due to how the event loop works or there is something wrong with RouterExecutionContext#createPipesFn. Note that this only happens when the body-parser middleware is evaluated

[micalevisk]

I just tested something: if we remove the await from inside handler's returns by making that fnApplyPipes sync, the 'close' event got emitted in controller's method. So I guess that this has something to do on how the event loops works. But the 'end' event still didn't got emitted

Here's an up-to-date reproduction: https://gitlab.com/micalevisk/nestjs-issue-10389

[WiseBird]

@elucidsoft Were you able to find a workaround for this issue?

[micalevisk]

another thing that I observed:

nest/packages/core/router/router-execution-context.ts

Lines 141 to 151 in 15cb568

	const handler =
	<TRequest, TResponse>(
	args: any[],
	req: TRequest,
	res: TResponse,
	next: Function,
	) =>
	async () => {
	fnApplyPipes && (await fnApplyPipes(args, req, res, next));
	return callback.apply(instance, args);
	};

if we drop the await from L149 and make createPipesFn return a synchronous function, it will work as we expect. But when we add a new line right after L149 using an await like this: await new Promise((resolve) => setTimeout(resolve, 0)); it will work just the same as having await on L149. No ideia why is this tho