When mount loopback 3 app into loopback 4, Cannot set headers after they are sent to the client (Error [ERR_HTTP_HEADERS_SENT])

[rmsgit]

Hi all, I'm trying to mount loopback 3 app into loopback 4 app. Currently, I successfully mounted according to the official documentation. But when I trying to do a load test (virtual users: 300 / sec, timeout: 10s), "ERR_HTTP_HEADERS_SENT" error is throwing. When I trying with lb3 or lb4 individually it's never happening for this load. Additionally, when I increase timeout duration in load test, the rate of error accruing is decreasing.

(node:10426) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag --unhandled-rejections=strict (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 117)
2021-01-05T07:23:07.000Z - info: IP: ::ffff:127.0.0.1, CustomerId: XXXXXXXXXXXXXXXX, login. User
(node:10426) UnhandledPromiseRejectionWarning: Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client
at ServerResponse.setHeader (_http_outgoing.js:526:11)
at ServerResponse.header (<project_path>/node_modules/express/lib/response.js:771:10)
at ServerResponse.json (<project_path>/node_modules/express/lib/response.js:264:10)
at <project_path>/lb3app/server/boot/user.js:47:8
at tokenHandler (<project_path>/node_modules/loopback/common/models/user.js:287:9)
at <project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/relation-definition.js:1919:13
at <project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/dao.js:427:21
at doNotify (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
at doNotify (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
at doNotify (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
at doNotify (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
at Function.ObserverMixin._notifyBaseObservers (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:178:5)
at Function.ObserverMixin.notifyObserversOf (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
at Function.ObserverMixin._notifyBaseObservers (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:176:15)
at Function.ObserverMixin.notifyObserversOf (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
at Function.ObserverMixin._notifyBaseObservers (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:176:15)
at Function.ObserverMixin.notifyObserversOf (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
at Function.ObserverMixin._notifyBaseObservers (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:176:15)
at Function.ObserverMixin.notifyObserversOf (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
at AccessToken. (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/dao.js:426:25)
at AccessToken.next (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/hooks.js:93:12)
at AccessToken. (<project_path>/node_modules/loopback/node_modules/loopback-datasource-juggler/lib/dao.js:414:26)

[jannyHou]

But when I trying to do a load test (virtual users: 300 / sec, timeout: 10s), "ERR_HTTP_HEADERS_SENT" error is throwing.

@rmsgit Could you post some code example that we can test and reproduce your issue?

[fikret-buyukisik-bam]

TLDR:
This is happening if you use a callback remote method instead of async one and if you cancel the request in the middle.

Here is the example code from the forked example project:
https://github.com/fikret-buyukisik-bam/loopback-next/tree/discussion-7196
The change:
fikret-buyukisik-bam/loopback-next@master...discussion-7196

Long version:

Description of the issue and the example code:
This issue is only happening for remote endpoints with a callback, within a loopback 3 application mounted under a loopback 4 application.
It is happening when a request is canceled in the middle. (Which is the case for an angular application if you refresh angular application quickly, angular client will cancel the previous calls and re-call them again)
So in order to manually cancel via postman, i have introduced an artificial delay of 5 seconds to the "CoffeeShops/greet" endpoint of example loopback-next/examples/lb3-application

This problem is not happening for vanilla loopback 3 application or vanilla loopback 4 endpoints

You can see the specific code under the "The Change" link.

Steps to reproduce:

1. install, build, run the example project under examples/lb3-application
2. call the api with postman, url: http://localhost:3000/api/CoffeeShops/greet
3. immediately after calling, cancel the request via cancel button in postman
4. observe the application crashing

[cjbeery24]

I'm running into this same issue. Any updates?

[cjbeery24]

Adding this to my application seems to keep the node process from crashing, allowing pages to refresh with no issues. Not sure this is a good idea, though.

process.on('uncaughtException', (reason, promise) => {
   console.log('uncaughtException at:', reason.stack ?? reason);
});

[achrinza]

#8802 has been opened to track this as a bug. I'm not familiar with LB3 so it's been placed in the icebox to be picked up at some point with no ETA at the moment.

We're always open to merging community contributions to fix this at the LB4-side.