"Cannot set headers after they are sent to the client" (ERR_HTTP_HEADERS_SENT) with AmazonDaxClient

[rchl]

• Review the documentation: https://docs.sentry.io/
• Search for existing issues: https://github.com/getsentry/sentry-javascript/issues
• Use the latest release: https://github.com/getsentry/sentry-javascript/releases
• Provide a link to the affected event from your Sentry account

Package + Version

• @sentry/browser
• @sentry/node
• raven-js
• raven-node (raven for node)
• other:

Version:

6.17.5

Description

This affects a complicated setup that I can't provide reproduction for easily.

The setup is:

• and express backend with express-session middleware running
• custom session store that retrieves and stores session in a DynamoDB database and uses AmazonDaxClient for DB operations

Steps are:

• navigate to express route that just returns some data res.json('OK')
• The express-middleware reads the session before handling the route and tries to save it on res.end() (which express-session wraps)
• When the saving of the session fails the dax client emits an error event:
  
• The emitted event seems to get handled by Sentry itself in the code linked below, resulting in the next express middleware running, even though the previous one has already responded to the request:
  

  sentry-javascript/packages/node/src/handlers.ts

  Lines 393 to 416 in a79c097

  	}
  	return function sentryRequestMiddleware(
  	req: http.IncomingMessage,
  	res: http.ServerResponse,
  	next: (error?: any) => void,
  	): void {
  	if (options && options.flushTimeout && options.flushTimeout > 0) {
  	// eslint-disable-next-line @typescript-eslint/unbound-method
  	const _end = res.end;
  	res.end = function (chunk?: any | (() => void), encoding?: string | (() => void), cb?: () => void): void {
  	void flush(options.flushTimeout)
  	.then(() => {
  	_end.call(this, chunk, encoding, cb);
  	})
  	.then(null, e => {
  	logger.error(e);
  	});
  	};
  	}
  	const local = domain.create();
  	local.add(req);
  	local.add(res);
  	local.on('error', next);

• The difference with and without Sentry is that this.domain is not defined in the code below when Sentry is not used
  

When the issue triggers then we are getting the ERR_HTTP_HEADERS_SENT error from Node because some later error middleware runs even though we've responded already.

[AbhiPrasad]

Thanks for the detailed issue. Could you provide your Sentry.init config. Are you using tracing?

I assume there's a conflict with domains here, but I'm not familiar enough with express middlewares to be certain. I'm putting this in our backlog to address, but PRs welcome for anyone who wants to help out!

[rchl]

The init options are not relevant because I have reproduced that even without initializing Sentry. It's just about the the Sentry requestHandler apparently.

Here is minimal reproduction that reproduces with minimal dummy express-session store:
https://github.com/rchl/sentry-bug-repro

[edennis]

I'm also getting the same error. I've used git-bisect to determine that the regression was introduced in 6.14.0 (6.13.3 works fine).

[souredoutlook]

@lobsterkatie Just confirming that the ongoing solution to this for affected users has been to downgrade to 6.13.3

[AbhiPrasad]

Pushed this up in priority - in the mean time, PRs are welcome if any one wants to take a look and help us out!

[rchl]

Getting the same error doesn't mean that the root issue is the same. This error can trigger for various reasons.

I don't quite see how my specific issue could be fixed without maybe refactoring how things fundamentally work.

[timfish]

I just tested your sentry-bug-repro example with 7.16.0 and since #5627, next is no longer called and because the domain error is no longer handled, the process terminates.

The output I get is:

> node src/index.mjs

Example app listening at http://localhost:8123
node:events:491
      throw er; // Unhandled 'error' event
      ^

Error: Dummy Error
    at RequestObject.emitError (file:///Users/tim/Documents/Repositories/sentry-bug-repro-main/src/session-store.mjs:6:28)
    at Timeout._onTimeout (file:///Users/tim/Documents/Repositories/sentry-bug-repro-main/src/session-store.mjs:21:25)
    at listOnTimeout (node:internal/timers:564:17)
    at process.processTimers (node:internal/timers:507:7)
Emitted 'error' event on Domain instance at:
    at RequestObject.emit (node:domain:540:12)
    at RequestObject.emitError (file:///Users/tim/Documents/Repositories/sentry-bug-repro-main/src/session-store.mjs:6:14)
    at Timeout._onTimeout (file:///Users/tim/Documents/Repositories/sentry-bug-repro-main/src/session-store.mjs:21:25)
    at listOnTimeout (node:internal/timers:564:17)
    at process.processTimers (node:internal/timers:507:7) {
  domainEmitter: RequestObject {
    _events: [Object: null prototype] {},
    _eventsCount: 0,
    _maxListeners: undefined,
    [Symbol(kCapture)]: false
  },
  domainThrown: false
}

Node.js v18.9.0

[timfish]

@AbhiPrasad can probably confirm, but I think this is blocked on async_hooks support (#3660).

[AbhiPrasad]

Can folks not explicitly catch and manage the error here? The issue with domain and next() was that we were incorrectly forwarding it.

[timfish]

It's happening in some third-party middleware.

I suppose I can try and wrap our call to next() in the domain. Let me try that....

[timfish]

I suppose I can try and wrap our call to next() in the domain. Let me try that....

There is no way to do this unfortunately since next is sync and the error is thrown in an async context.

custom session store that retrieves and stores session in a DynamoDB database and uses AmazonDaxClient for DB operations

@rchl I changed your code to catch the error and pass it onto the callback like this, rather than allow an unhandledrejection:

  set(sid, data, cb) {
    const request = new RequestObject();
    new Promise((resolve) => {
      // Delaying a bit to also trigger the ERR_HTTP_HEADERS_SENT error.
      setTimeout(() => {
        try {
          request.emitError();
          cb();
        } catch (e) {
          cb(e);
        }
      });
    });
  }

With 7.16.0, I get the following output, even when NOT using the Sentry handler:

Example app listening at http://localhost:8123
THIS ERROR HANDLER SHOULD NOT RUN!
Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client
    at new NodeError (node:internal/errors:393:5)
    at ServerResponse.setHeader (node:_http_outgoing:607:11)
    at ServerResponse.header (/Users/tim/Documents/Repositories/sentry-bug-repro-main/node_modules/express/lib/response.js:776:10)
    at ServerResponse.contentType (/Users/tim/Documents/Repositories/sentry-bug-repro-main/node_modules/express/lib/response.js:604:15)
    at ServerResponse.send (/Users/tim/Documents/Repositories/sentry-bug-repro-main/node_modules/express/lib/response.js:145:14)
    at file:///Users/tim/Documents/Repositories/sentry-bug-repro-main/src/index.mjs:23:7
    at Layer.handle_error (/Users/tim/Documents/Repositories/sentry-bug-repro-main/node_modules/express/lib/router/layer.js:71:5)
    at trim_prefix (/Users/tim/Documents/Repositories/sentry-bug-repro-main/node_modules/express/lib/router/index.js:321:13)
    at /Users/tim/Documents/Repositories/sentry-bug-repro-main/node_modules/express/lib/router/index.js:284:7
    at Function.process_params (/Users/tim/Documents/Repositories/sentry-bug-repro-main/node_modules/express/lib/router/index.js:341:12)

[timfish]

I've just tested it and the ERR_HTTP_HEADERS_SENT error is actually caused by the call to res.send("FAIL"). Due to the async nature of the error and the fact that you've already called res.status(200).send("Hello World!").

The assertion that THIS ERROR HANDLER SHOULD NOT RUN is not true. All error handlers are called in order of registration.

So to fix your issue:

• Update to the latest version of the SDK
• Catch async errors and pass them to the callback:

      try {
        request.emitError();
        cb();
      } catch (e) {
        cb(e);
      }

• You can't send after previously res.status().send()

Please feel free to re-open this issue if you have any new information or you believe the above is not true.

[rchl]

@timfish I think this alone fixes the whole issue:

I just tested your sentry-bug-repro example with 7.16.0 and since #5627, next is no longer called and because the domain error is no longer handled, the process terminates.

I could discuss other points that you've raised but I think it's not really relevant given the above.
I think other issues that remain after Sentry is no longer listening to domain error would be in either dax client or express-session.

Thanks for handling it.