session icon indicating copy to clipboard operation
session copied to clipboard

Async session stores don't work with newer versions of nodejs

Open mrbrianevans opened this issue 1 year ago • 1 comments

Prerequisites

  • [X] I have written a descriptive issue title
  • [X] I have searched existing issues to ensure the bug has not already been reported

Fastify version

4.27.0

Plugin version

10.8.0

Node.js version

20.x

Operating system

Linux

Operating system version (i.e. 20.04, 11.3, 10)

docker

Description

This was reported in https://github.com/fastify/session/issues/252 but the issue was closed due to a particular implementation flaw by the poster. However the problem seems more widespread than just his issue with handling errors.

Asynchronous methods on the session store (which is required by almost any production session store to persist in a database) cause an error with node versions starting at node 20. Works fine with node 19.

As a minimum repoducible example, I've narrowed it down to adding a simple setTimeout in the default in-memory store causes the bug to occur.

import {EventEmitter} from 'node:events'
import util from 'node:util'
+ import { setTimeout } from "timers/promises";

function Store (storeMap = new Map()) {
  this.store = storeMap
  EventEmitter.call(this)
}

util.inherits(Store, EventEmitter)

Store.prototype.set = async function set (sessionId, session, callback) {
  this.store.set(sessionId, session)
+  await setTimeout(50)
  callback()
}

Store.prototype.get = function get (sessionId, callback) {
  const session = this.store.get(sessionId)
  callback(null, session)
}

Store.prototype.destroy = function destroy (sessionId, callback) {
  this.store.delete(sessionId)
  callback()
}

export {Store}

When using this store in a fastify app such as (simplified)

const fastify = Fastify({})
await fastify.register(import('@fastify/session'), {
  ...
  store: new Store()
})

It throws this error and exits the process

Error [ERR_HTTP_HEADERS_SENT]: Cannot write headers after they are sent to the client

This is on Node.js v20.13.1 but it affects any version of node since 20.x. Previously known working version was node 19.

Link to code that reproduces the bug

No response

Expected Behavior

I expect it to work on node 20 the same way it did on node 19 or prior.

Any sensible session store requires some asynchronous operation to set and get, so if my diagnosis is correct, this is a major issue.

mrbrianevans avatar May 25 '24 13:05 mrbrianevans

Thanks for reporting! Would you like to send a Pull Request to address this issue? Remember to add unit tests.

mcollina avatar May 25 '24 15:05 mcollina

We are facing the same problem. It is hard to narrow down, but imho a critical bug.

phal0r avatar Jul 22 '24 21:07 phal0r

Looking through the code, I don't think any methods of session store is allowed to be async function. That would be the cause of forking promise.

We are facing the same problem. It is hard to narrow down, but imho a critical bug.

It is also hard for us to pin point the cause if no reproducible code is provided.

climba03003 avatar Jul 23 '24 04:07 climba03003

I'm having a similar issue, although my Node.js version is v18.17.1. I'm getting an error like this:

Error: Cannot set headers after they are sent to the client
    at new NodeError (node:internal/errors:405:5)
    at ServerResponse.setHeader (node:_http_outgoing:648:11)
    at ServerResponse.writeHead (node:_http_server:381:21)
    at onSendEnd <project-folder>/node_modules/fastify/lib/reply.js:571:9)
    at wrapOnSendEnd (<project-folder>/node_modules/fastify/lib/reply.js:537:5)
    at next (<project-folder>/node_modules/fastify/lib/hooks.js:224:7)
    at <project-folder>node_modules/@fastify/session/lib/fastifySession.js:202:9
    at <project-folder>/node_modules/@fastify/session/lib/session.js:180:11
    at Immediate.<anonymous> (<project-folder>/node_modules/@quixo3/prisma-session-store/dist/lib/utils/defer.js:16:18)
    at processImmediate (node:internal/timers:476:21)

I'm trying to use a session store made for the Prisma ORM. In this error I'm using the @quixo3/prisma-session-store store which is designed for Express.js but should work according to the documentation which states that @fastify/session is "Compatible to stores from express-session."

I also tried writing my own session store which doesn't have async functions and it works, but I seemingly randomly get this in my logs which is very annoying:

[17:24:01.131] ERROR (43756): Cannot set headers after they are sent to the client
    reqId: "req-1"
    req: {
      "method": "GET",
      "url": "/auth/callback?<redacted>",
      "hostname": "localhost:5000",
      "remoteAddress": "::1",
      "remotePort": 58452
    }
    res: {
      "statusCode": 500
    }
    err: {
      "type": "Error",
      "message": "Cannot set headers after they are sent to the client",
      "stack":
          Error: Cannot set headers after they are sent to the client
              at new NodeError (node:internal/errors:405:5)
              at ServerResponse.setHeader (node:_http_outgoing:648:11)
              at ServerResponse.writeHead (node:_http_server:381:21)
              at onSendEnd (<project-folder>/node_modules/fastify/lib/reply.js:571:9)
              at wrapOnSendEnd (<project-folder>/node_modules/fastify/lib/reply.js:537:5)
              at next (<project-folder>/node_modules/fastify/lib/hooks.js:224:7)
              at <project-folder>/node_modules/@fastify/session/lib/fastifySession.js:202:9
              at <project-folder>/node_modules/@fastify/session/lib/session.js:180:11
              at <project-folder>/src/plugins/auth/pgSessionStore.ts:43:17
      "code": "ERR_HTTP_HEADERS_SENT"
    }
[17:24:01.133] WARN (43756): Reply already sent
    reqId: "req-1"
    err: {
      "type": "FastifyError",
      "message": "Reply was already sent.",
      "stack":
          FastifyError: Reply was already sent.
              at _Reply.Reply.send (<project-folder>/node_modules/fastify/lib/reply.js:127:26)
              at defaultErrorHandler (<project-folder>/node_modules/fastify/lib/error-handler.js:92:9)
              at handleError (<project-folder>/node_modules/fastify/lib/error-handler.js:65:18)
              at onErrorHook (<project-folder>/node_modules/fastify/lib/reply.js:742:5)
              at wrapOnSendEnd (<project-folder>/node_modules/fastify/lib/reply.js:535:5)
              at next (<project-folder>/node_modules/fastify/lib/hooks.js:215:7)
              at <project-folder>/node_modules/@fastify/session/lib/fastifySession.js:193:11
              at <project-folder>/node_modules/@fastify/session/lib/session.js:176:11
              at <project-folder>/src/plugins/auth/pgSessionStore.ts:44:21
      "name": "FastifyError",
      "code": "FST_ERR_REP_ALREADY_SENT",
      "statusCode": 500
    }

I have no idea what I'm supposed to do here as the error comes from inside Fastify and @fastify/session. I have no way to affect anything in the session logic beyond the store interface and nothing I've tried seems to make these issues go away.

Fastify version is 4.16.0, @fastify/session is 10.9.0.

Ohems avatar Aug 19 '24 14:08 Ohems

{
    "level": 50,
    "time": 1725863920779,
    "pid": 1,
    "hostname": "",
    "err": {
        "type": "Error",
        "message": "Cannot write headers after they are sent to the client",
        "stack": "Error [ERR_HTTP_HEADERS_SENT]: Cannot write headers after they are sent to the client\n    at ServerResponse.writeHead (node:_http_server:345:11)\n    at safeWriteHead (/usr/src/app/node_modules/fastify/lib/reply.js:572:9)\n    at onSendEnd (/usr/src/app/node_modules/fastify/lib/reply.js:621:5)\n    at wrapOnSendEnd (/usr/src/app/node_modules/fastify/lib/reply.js:565:5)\n    at next (/usr/src/app/node_modules/fastify/lib/hooks.js:289:7)\n    at /usr/src/app/node_modules/@fastify/session/lib/fastifySession.js:202:9\n    at /usr/src/app/node_modules/@fastify/session/lib/session.js:180:11\n    at /usr/src/app/sessions/sessions.js:35:29\n    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)",
        "code": "ERR_HTTP_HEADERS_SENT",
        "isBoom": true,
        "isServer": true,
        "data": null,
        "output": {
            "statusCode": 500,
            "payload": {
                "statusCode": 500,
                "error": "Internal Server Error",
                "message": "An internal server error occurred"
            },
            "headers": {}
        }
    },
    "msg": "Cannot write headers after they are sent to the client"
}

Still seem to be getting this as well with error handling included (I posted the original issue). Issue seems to pop up mostly when we get a larger load (approx. 5k rpm) on the application.

I will try to look into this.

niels-van-den-broeck avatar Sep 09 '24 08:09 niels-van-den-broeck

I made a repo to replicate this issue and played around a bit with different configurations. This led me to find the fix (in my application code, not fastify-session) which is to ALWAYS RETURN reply in async handlers. Problem solved.

For those of you getting this issue intermittently, go through all your async handlers and ensure that you have something to the effect of

return reply.send()

mrbrianevans avatar Oct 05 '24 12:10 mrbrianevans