nest icon indicating copy to clipboard operation
nest copied to clipboard

Server not shutting down and SSE events not disconnecting and retrying correctly - when enableShutdownHooks used with @Sse

Open johnjesse opened this issue 2 years ago • 4 comments

Is there an existing issue for this?

  • [X] I have searched the existing issues and there is one that was closed about a year ago where they couldn't produce a repro #6643

Current behavior

See the repository I've added

It has a client and a server

The client is a simple app made with create-react-app it just listens to the event source at /sse. The server is a starter app made with nest new.

  1. If you start both the client and the server and open a browser at localhost:3001 with the developer tools console open, you can see the status of the event source being logged every few seconds, as well as the messages received from the server being logged.

  2. If you now stop the server - ending the process using ctrl+c, the event source should be unexpectedly closed and the client should try to reconnect. But it doesn't - it continues to think the event source still exists - and it receives messages from it.

  3. If you go into /server/src/main.ts and comment out line 9 app.enableShutdownHooks(); and repeat the above steps - you'll see it behave as expected, when you then restart the server the client correctly reconnects.

Minimum reproduction code

https://github.com/johnjesse/Nest-issue-repro

Steps to reproduce

See above

Expected behavior

The SSE event should close on the server side, so the client will then try and reconnect - and no longer receive events from the terminated source.

Package

  • [ ] I don't know. Or some 3rd-party package
  • [ ] @nestjs/common
  • [x] @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

^8.0.0

Packages versions

{
  "name": "server",
  "version": "0.0.1",
  "description": "",
  "author": "",
  "private": true,
  "license": "UNLICENSED",
  "scripts": {
    "prebuild": "rimraf dist",
    "build": "nest build",
    "format": "prettier --write \"src/**/*.ts\" \"test/**/*.ts\"",
    "start": "nest start",
    "start:dev": "nest start --watch",
    "start:debug": "nest start --debug --watch",
    "start:prod": "node dist/main",
    "lint": "eslint \"{src,apps,libs,test}/**/*.ts\" --fix",
    "test": "jest",
    "test:watch": "jest --watch",
    "test:cov": "jest --coverage",
    "test:debug": "node --inspect-brk -r tsconfig-paths/register -r ts-node/register node_modules/.bin/jest --runInBand",
    "test:e2e": "jest --config ./test/jest-e2e.json"
  },
  "dependencies": {
    "@nestjs/common": "^8.0.0",
    "@nestjs/core": "^8.0.0",
    "@nestjs/platform-express": "^8.0.0",
    "reflect-metadata": "^0.1.13",
    "rimraf": "^3.0.2",
    "rxjs": "^7.2.0"
  },
  "devDependencies": {
    "@nestjs/cli": "^8.0.0",
    "@nestjs/schematics": "^8.0.0",
    "@nestjs/testing": "^8.0.0",
    "@types/express": "^4.17.13",
    "@types/jest": "27.4.1",
    "@types/node": "^16.0.0",
    "@types/supertest": "^2.0.11",
    "@typescript-eslint/eslint-plugin": "^5.0.0",
    "@typescript-eslint/parser": "^5.0.0",
    "eslint": "^8.0.1",
    "eslint-config-prettier": "^8.3.0",
    "eslint-plugin-prettier": "^4.0.0",
    "jest": "^27.2.5",
    "prettier": "^2.3.2",
    "source-map-support": "^0.5.20",
    "supertest": "^6.1.3",
    "ts-jest": "^27.0.3",
    "ts-loader": "^9.2.3",
    "ts-node": "^10.0.0",
    "tsconfig-paths": "^3.10.1",
    "typescript": "^4.3.5"
  },
  "jest": {
    "moduleFileExtensions": [
      "js",
      "json",
      "ts"
    ],
    "rootDir": "src",
    "testRegex": ".*\\.spec\\.ts$",
    "transform": {
      "^.+\\.(t|j)s$": "ts-jest"
    },
    "collectCoverageFrom": [
      "**/*.(t|j)s"
    ],
    "coverageDirectory": "../coverage",
    "testEnvironment": "node"
  }
}

Node.js version

17.8.0

In which operating systems have you tested?

  • [X] macOS
  • [ ] Windows
  • [ ] Linux

Other

No response

johnjesse avatar May 03 '22 18:05 johnjesse

Came across this issue and decided to try it on my repo as well. Turns out I can readily reproduce it on both Windows (Windows 10 Build 19043) and macOS (macOS Monterey Version 12.4).

Steps to reproduce:

  1. Clone https://github.com/KasimAhmic/minimon
  2. Run yarn run init in the project root
  3. Open two terminals
  4. In terminal 1, run yarn start:client
  5. In terminal 2, run yarn start:server
  6. Verify you are receiving data on the client
    • The dials should be moving and the timestamps in the bottom right should be updating
  7. Ctrl + C in terminal 2 (the server)

Expected behavior:

  • There is a message logged to the console about the application shutting down
  • The server goes down and the client starts to see error messages in their console (EventSource disconnection)

Observed behavior:

  • There is NO message logged to the console about the application shutting down
  • The data is still being streamed to the client

Furthermore, I noticed if I kill the client as well, or if I kill the terminal that was used to start the server, that's when I finally get the expected behavior above. Not entirely sure what to make of this piece but it's worth sharing.

EDIT: This issue still persists with Nest 9.0

KasimAhmic avatar Jul 05 '22 14:07 KasimAhmic

I also noticed even if I call Eventsource.close() on the client side, the request will only terminate after the timeout set in the container settings and keeps using resources.

renannery avatar Aug 31 '22 20:08 renannery

between this issue and https://github.com/nestjs/nest/issues/10131 it seems like the shutdown hook isn't quite trying hard enough. What happens with websockets with gateways? Does it shut those down properly including connected clients? I know plenty of clients have reconnect operations that might mean the server wouldn't shut down there as well.

ghost avatar Sep 07 '22 02:09 ghost

I will take a look at this, this week. We will need to keep track of open connections/sockets on our httpServer instances. And when closing our httpServer, these open connections need to be destroyed.

tolgap avatar Oct 03 '22 15:10 tolgap

Let's track this here https://github.com/nestjs/nest/pull/10345

kamilmysliwiec avatar Nov 07 '22 09:11 kamilmysliwiec