Gambit is crashing when New Relic is enabled

[aaronschachter]

Gambit keeps crashing with at=error code=H10 desc="App crashed"

Let's try turning off New Relic. Here's a stack trace that leads us to think it's worth a shot:

2017-03-10T15:07:12.115644+00:00 app[web.1]:        function: 'Connection.connect',
2017-03-10T15:07:12.115645+00:00 app[web.1]:        line: 389,
2017-03-10T15:07:12.115645+00:00 app[web.1]:        method: 'connect',
2017-03-10T15:07:12.115646+00:00 app[web.1]:        native: false },
2017-03-10T15:07:12.115646+00:00 app[web.1]:      { column: 14,
2017-03-10T15:07:12.115647+00:00 app[web.1]:        file: '/app/node_modules/mongodb-core/lib/connection/pool.js',
2017-03-10T15:07:12.115647+00:00 app[web.1]:        function: '_createConnection',
2017-03-10T15:07:12.115639+00:00 app[web.1]:        native: false },
2017-03-10T15:07:12.115648+00:00 app[web.1]:        line: 1059,
2017-03-10T15:07:12.115648+00:00 app[web.1]:        method: null,
2017-03-10T15:07:12.115649+00:00 app[web.1]:        native: false },
2017-03-10T15:07:12.115650+00:00 app[web.1]:      { column: 13,
2017-03-10T15:07:12.115650+00:00 app[web.1]:        file: '/app/node_modules/mongodb-core/lib/connection/pool.js',
2017-03-10T15:07:12.115651+00:00 app[web.1]:        function: null,
2017-03-10T15:07:12.115651+00:00 app[web.1]:        line: 1151,
2017-03-10T15:07:12.115652+00:00 app[web.1]:        method: null,
2017-03-10T15:07:12.115652+00:00 app[web.1]:        native: false },
2017-03-10T15:07:12.115653+00:00 app[web.1]:      { column: 39,
2017-03-10T15:07:12.115653+00:00 app[web.1]:        file: '/app/node_modules/mongodb-core/lib/connection/pool.js',
2017-03-10T15:07:12.115654+00:00 app[web.1]:        function: 'waitForAuth',
2017-03-10T15:07:12.115654+00:00 app[web.1]:        line: 1082,
2017-03-10T15:07:12.115655+00:00 app[web.1]:        method: null,
2017-03-10T15:07:12.115655+00:00 app[web.1]:        native: false },
2017-03-10T15:07:12.115656+00:00 app[web.1]:      { column: 5,
2017-03-10T15:07:12.115657+00:00 app[web.1]:        file: '/app/node_modules/mongodb-core/lib/connection/pool.js',
2017-03-10T15:07:12.115657+00:00 app[web.1]:        function: null,
2017-03-10T15:07:12.115658+00:00 app[web.1]:        line: 1090,
2017-03-10T15:07:12.115658+00:00 app[web.1]:        method: null,
2017-03-10T15:07:12.115659+00:00 app[web.1]:        native: false },
2017-03-10T15:07:12.115659+00:00 app[web.1]:      { column: 21,
2017-03-10T15:07:12.115660+00:00 app[web.1]:        file: '/app/node_modules/mongodb-core/lib/connection/pool.js',
2017-03-10T15:07:12.115660+00:00 app[web.1]:        function: null,
2017-03-10T15:07:12.115661+00:00 app[web.1]:        line: 957,
2017-03-10T15:07:12.115662+00:00 app[web.1]:        method: null,
2017-03-10T15:07:12.115662+00:00 app[web.1]:        native: false },
2017-03-10T15:07:12.115663+00:00 app[web.1]:      { column: 28,
2017-03-10T15:07:12.115663+00:00 app[web.1]:        file: '/app/node_modules/newrelic/lib/transaction/tracer/index.js',
2017-03-10T15:07:12.115664+00:00 app[web.1]:        function: 'wrapped',
2017-03-10T15:07:12.115670+00:00 app[web.1]:        line: 183,
2017-03-10T15:07:12.115671+00:00 app[web.1]:        method: null,
2017-03-10T15:07:12.115671+00:00 app[web.1]:        native: false },
2017-03-10T15:07:12.115672+00:00 app[web.1]:      { column: 7,
2017-03-10T15:07:12.115672+00:00 app[web.1]:        file: 'internal/process/next_tick.js',
2017-03-10T15:07:12.115673+00:00 app[web.1]:        function: '_combinedTickCallback',
2017-03-10T15:07:12.115674+00:00 app[web.1]:        line: 73,
2017-03-10T15:07:12.115674+00:00 app[web.1]:        method: null,
2017-03-10T15:07:12.115675+00:00 app[web.1]:        native: false },
2017-03-10T15:07:12.115675+00:00 app[web.1]:      { column: 9,
2017-03-10T15:07:12.115676+00:00 app[web.1]:        file: 'internal/process/next_tick.js',
2017-03-10T15:07:12.115676+00:00 app[web.1]:        function: 'process._tickDomainCallback [as _tickCallback]',
2017-03-10T15:07:12.115677+00:00 app[web.1]:        line: 128,
2017-03-10T15:07:12.115677+00:00 app[web.1]:        method: '_tickDomainCallback [as _tickCallback]',
2017-03-10T15:07:12.115678+00:00 app[web.1]:        native: false } ],
2017-03-10T15:07:12.115679+00:00 app[web.1]:   stack: 
2017-03-10T15:07:12.115679+00:00 app[web.1]:    [ 'TypeError: "listener" argument must be a function',
2017-03-10T15:07:12.115680+00:00 app[web.1]:      '    at Socket.once (events.js:307:11)',
2017-03-10T15:07:12.115681+00:00 app[web.1]:      '    at Socket.connect (net.js:943:10)',
2017-03-10T15:07:12.115682+00:00 app[web.1]:      '    at wrappedConnect (/app/node_modules/newrelic/lib/instrumentation/core/net.js:53:31)',
2017-03-10T15:07:12.115682+00:00 app[web.1]:      '    at wrapped (/app/node_modules/newrelic/lib/transaction/tracer/index.js:183:28)',
2017-03-10T15:07:12.115683+00:00 app[web.1]:      '    at Tracer.addSegment (/app/node_modules/newrelic/lib/transaction/tracer/index.js:83:48)',
2017-03-10T15:07:12.115684+00:00 app[web.1]:      '    at Socket.connectWrapper [as connect] (/app/node_modules/newrelic/lib/instrumentation/core/net.js:43:27)',
2017-03-10T15:07:12.115684+00:00 app[web.1]:      '    at Object.exports.connect.exports.createConnection (net.js:76:35)',
2017-03-10T15:07:12.115685+00:00 app[web.1]:      '    at Connection.connect (/app/node_modules/mongodb-core/lib/connection/connection.js:389:11)',
2017-03-10T15:07:12.115685+00:00 app[web.1]:      '    at _createConnection (/app/node_modules/mongodb-core/lib/connection/pool.js:1059:14)',
2017-03-10T15:07:12.115686+00:00 app[web.1]:      '    at /app/node_modules/mongodb-core/lib/connection/pool.js:1151:13',
2017-03-10T15:07:12.115687+00:00 app[web.1]:      '    at waitForAuth (/app/node_modules/mongodb-core/lib/connection/pool.js:1082:39)',
2017-03-10T15:07:12.115687+00:00 app[web.1]:      '    at /app/node_modules/mongodb-core/lib/connection/pool.js:1090:5',
2017-03-10T15:07:12.115688+00:00 app[web.1]:      '    at /app/node_modules/mongodb-core/lib/connection/pool.js:957:21',
2017-03-10T15:07:12.115689+00:00 app[web.1]:      '    at wrapped (/app/node_modules/newrelic/lib/transaction/tracer/index.js:183:28)',
2017-03-10T15:07:12.115689+00:00 app[web.1]:      '    at _combinedTickCallback (internal/process/next_tick.js:73:7)',
2017-03-10T15:07:12.115690+00:00 app[web.1]:      '    at process._tickDomainCallback [as _tickCallback] (internal/process/next_tick.js:128:9)' ] }

[aaronschachter]

This TypeError looks like it might be causing the crash -- and has still occurred after deploying 3.4.5. I've disabled New Relic on production and keeping 👀 on the logs...

[sergiitk]

Might be related to 1.37.1 upgrade:
https://docs.newrelic.com/docs/release-notes/agent-release-notes/nodejs-release-notes/node-agent-1371

Agent now wraps emit on http request/response objects instead of relying on listeners.

Might worth trying to downgrade to 1.37.0

[aaronschachter]

We tried pinning to 1.37.0 in 3.4.6 but still got the crash. Have set the NEW_RELIC_ENABLED config variable to false for now.

[vhain]

are you using Node 7.2.2 ? if yes, nodejs/node#11762 there is bug. use another version for now

[sergiitk]

@vhain Thank you for the advice!
We are using 4.4.8. Upgrade to 6.10.x is on the way, #815.

[aaronschachter]

I haven't been able to replicate this locally or on staging. Only seems to get triggered when there's a substantial amount of requests. We'll deploy the 6.10.x upgrade next week and can try enabling New Relic again... although getting some load testing in place should help us test theories in other places besides production (#810 , #704)