Error resolving route - layer.match is not a function

[keerthy-cf]

Hi,

We are running into an issue where we are seeing sometimes express server going to a bad state and all requests started to fail with the following stack trace.

Versions
"express": "4.16.1"
"inversify-express-utils: "6.3.2"

TypeError: layer.match is not a function
at matchLayer (/sample-api/node_modules/inversify-express-utils/node_modules/express/lib/router/index.js:574:18)
at next (/sample-api/node_modules/inversify-express-utils/node_modules/express/lib/router/index.js:220:15)
at Function.handle (/sample-api/node_modules/inversify-express-utils/node_modules/express/lib/router/index.js:174:3)
at Function.handle (/sample-api/node_modules/inversify-express-utils/node_modules/express/lib/application.js:174:10)
at Server.app (/sample-api/node_modules/inversify-express-utils/node_modules/express/lib/express.js:39:9)
at emitTwo (events.js:126:13)
at Server.emit (events.js:214:7)
at Server.wrapped (/sample-api/node_modules/newrelic/lib/transaction/tracer/index.js:181:22)
at Server.wrappedHandler (/sample-api/node_modules/newrelic/lib/instrumentation/core/http.js:215:47)
at Server.wrapped (/sample-api/node_modules/newrelic/lib/transaction/tracer/index.js:181:22)
at Server.wrapTransactionInvocation (/sample-api/node_modules/newrelic/lib/transaction/tracer/index.js:108:8)
at Server.wrappedEmit [as emit] (/sample-api/node_modules/newrelic/lib/instrumentation/core/http.js:487:28)
at parserOnIncoming (_http_server.js:660:12)
at HTTPParser.parserOnHeadersComplete (_http_common.js:119:17)

Looking at the latest code, it seems fine. Can you please check and update ?

[dougwilson]

Hi @keerthy-cf I'm sorry you're having issues here. I have honestly never seen that error before (myself or reported), so definitely strange. The error is saying that the layer variable is defined, but there was no match property on it. All the objects in the layers array should be of the Layer type (which have this method: https://github.com/expressjs/express/blob/master/lib/router/layer.js#L110).

Is there any way we can reproduce the issue to determine what is happening?

[keerthy-cf]

Hi @dougwilson
Ya it's very starange as layer object always have match defined during the creation. There is no proper repro for this. We are running into this problem randomly once in a while and all of a sudden this error will start happening. Once went to this state we have to restart the process to get it back to working. 3 instances of this occurrence in last one week.

[keerthy-cf]

I saw some stackoverflow link but with no clear resolution there too - https://stackoverflow.com/questions/54761100/layer-match-is-not-a-function

[dougwilson]

Hi @keerthy-cf thanks for that link. Yea, it also doesn't have any indication as to the cause, and as such, there is no clear course of action to make a fix. If there is anything you can provide to help, be it a fix to the issue, a heap dump at the time of the error, code that you're running, that would help a lot.

[freenerd]

We experienced this problem on a production server as well. It only affected one instance. Stacktrace is below, showing that this triggered even without inversify-express-utils in the loop as well.

Annoyingly we don't know the trigger so were not able to replicate. @dougwilson if we encounter this problem again in production, how'd you like us to go about a head dump? Easiest thing to capture for us seems to be a coredump through gcore

TypeError: layer.match is not a function
    at matchLayer (/usr/local/src/app/node_modules/express/lib/router/index.js:574:18)
    at next (/usr/local/src/app/node_modules/express/lib/router/index.js:220:15)
    at Function.handle (/usr/local/src/app/node_modules/express/lib/router/index.js:174:3)
    at Function.handle (/usr/local/src/app/node_modules/express/lib/application.js:174:10)
    at Server.app (/usr/local/src/app/node_modules/express/lib/express.js:39:9)
    at emitTwo (events.js:126:13)
    at Server.emit (events.js:214:7)
    at parserOnIncoming (_http_server.js:619:12)
    at HTTPParser.parserOnHeadersComplete (_http_common.js:115:23)

Express version: "4.16.3"

[dougwilson]

I'm not familiar with gcore do cannot comment on that. As long as I can open the v8 heap using the v8 debugger, then it is fine.

You can also send the node process the USR2 signal when it is in this state to get a dump.

Or you can use https://www.npmjs.com/package/heapdump and add some logic to see when this error happens and write out the dump.

[webdevian]

We have started getting this in production more and more in the last few weeks. Our symptoms and attempts to diagnose it are the same as @keerthy-cf

[dougwilson]

So there has been no release of Express recently and I have looked at the stack trace and code and no solution came to mind. All I can guess is something is manipulating Express internals? The error itself happens within a try block and is forwarded like any other error to be written as a response.

Until there is some kind of reproduction case here or heap dump or something, there isn't much I can do, unless you have any suggestions?

[thomasboyt]

I've noticed this error happens only in production in my app, and tracked it down to the @sentry/node package, specifically when both the Sentry requestHandler and errorHandler middlewares are being used. I'm not sure if this is actually a bug with Sentry, a bug with my usage of Sentry, or a bug in a dependency used by Sentry. Curious if anyone else on this issue has had this issue who is not using Sentry.

Should note I'm specifically using @sentry/node 4.6.1, as well as an async-function wrapper for errors (https://github.com/thomasboyt/jam-buds/blob/master/api/src/util/wrapAsyncRoute.ts).

[thomasboyt]

Updating @sentry/node to 5.1.0 seems to have fixed this issue for me. Again, no idea if it's the only package that causes this issue, so don't know if this is resolved, but for anyone else running into this issue it may be worth checking.

[dougwilson]

Thanks @thomasboyt . Was this the same cause for you @keerthy-cf @freenerd and @webdevian ?

[MeetChopra]

Yes, I think this was the same cause for me too, just updated it @dougwilson

[keerthy-cf]

We updated to node 10 and retained sentry @4.6.2 and ran into a memory leak problem caused by node 10 + sentry 4.6.2 described here getsentry/sentry-javascript#1762. Now our current setup is node 11 + sentry @4.6.2 and have not seen the issue so far. Mostly looks like something to do with sentry but not clear as what exactly caused this.

With respect to updating @sentry/node to 5.1.0, there seems to be a memory leak issue along side node 10 / 11 described in the same link - getsentry/sentry-javascript#1762.
So do have a watch on this.

[webdevian]

@dougwilson We found that it happens whenever headers are sent twice. We found a culprit package that was calling a callback twice (openexchangerates/npm-exchange-rates#9) and thought replacing that had fixed it, but we've had one more incident since.

We do use Sentry (@sentry/node@^4.5.3) so it looks likely that that is the cause, I will try upgrading that now.

[dougwilson]

Any reproduction steps narrowing it down to something express can fix would be helpful, otherwise I think we can close this issue as a known bug (that's fixed) in a third party module?

[dougwilson]

Closing since I guess the answer is no.

[nehemiah-tzur]

I am trying to do the following: app._router.stack.splice(0, 0, express.json()); and getting the error above.

My goal is to insert a route at the begging of my app after the app has been exported. I am doing this for testing purposes.