Service races when port is in use (this was under pm2)

[JigmeDatse]

I was working on setting things up in pm2, and ended up looking at my CPU graph and saw that it was getting pegged at 100%, and the issue that I was seeing was related to the AS attempting to request the ports (AS and ident) and failing.

I'm not sure if this issue exists when running straight from node, or if the service itself is running into this issue, but from what it looked like, I think that the node instance wasn't quitting, but kept running. I could try to duplicate, but I'm not sure how to right off the top of my head.

[kegsay]

I don't recall off the top of my head if we do exit 1 if the port is in use. Obviously we should.

[t3chguy]

If the Ident Port is in use it'll error out with

Loading config file /opt/matrix-appservice-irc/config.yaml
2017-04-19 18:11:54 INFO:irc-ident Configuring ident server => {"enabled":true,"port":1113}
/opt/matrix-appservice-irc/node_modules/olm/olm.js:19
"undefined"!==typeof module&&(module.exports=a);process.on("uncaughtException",function(a){if(!(a instanceof T))throw a;});a.inspect=function(){return"[Emscripten Module object]"}}else if(ma)a.print||(a.print=print),"undefined"!=typeof printErr&&(a.printErr=printErr),a.read="undefined"!=typeof read?read:function(){throw"no read() available (jsc?)";},a.readBinary=function(a){if("function"===typeof readbuffer)return new Uint8Array(readbuffer(a));a=read(a,"binary");z("object"===typeof a);return a},"undefined"!=
                                                                                                                ^

Error: listen EADDRINUSE 0.0.0.0:1113
    at Object.exports._errnoException (util.js:1050:11)
    at exports._exceptionWithHostPort (util.js:1073:20)
    at Server.setupListenHandle [as _listen2] (net.js:1263:14)
    at listenInCluster (net.js:1304:12)
    at doListen (net.js:1428:7)
    at _combinedTickCallback (internal/process/next_tick.js:83:11)
    at process._tickCallback (internal/process/next_tick.js:104:9)
    at Module.runMain (module.js:607:11)
    at run (bootstrap_node.js:423:7)
    at startup (bootstrap_node.js:147:9)
    at bootstrap_node.js:538:3

[t3chguy]

If the AS Port is in use it'll error out with

Loading config file /opt/matrix-appservice-irc/config.yaml
2017-04-19 18:13:36 INFO:irc-ident Configuring ident server => {"enabled":true,"port":1114}
2017-04-19 18:13:36 INFO:DataStore Indexes checked on 'id' for store.
2017-04-19 18:13:36 INFO:DataStore Indexes checked on 'matrix_id' for store.
2017-04-19 18:13:36 INFO:DataStore Indexes checked on 'remote_id' for store.
2017-04-19 18:13:36 INFO:DataStore Indexes checked on 'localpart' for store.
2017-04-19 18:13:36 INFO:DataStore Indexes checked on 'user id' for store.
2017-04-19 18:13:36 INFO:DataStore Private key loaded from passkey.pem - IRC password encryption enabled.
2017-04-19 18:13:36 INFO:DataStore Indexes checked for ident username for eu.irc.esper.net on users database
/opt/matrix-appservice-irc/node_modules/olm/olm.js:19
"undefined"!==typeof module&&(module.exports=a);process.on("uncaughtException",function(a){if(!(a instanceof T))throw a;});a.inspect=function(){return"[Emscripten Module object]"}}else if(ma)a.print||(a.print=print),"undefined"!=typeof printErr&&(a.printErr=printErr),a.read="undefined"!=typeof read?read:function(){throw"no read() available (jsc?)";},a.readBinary=function(a){if("function"===typeof readbuffer)return new Uint8Array(readbuffer(a));a=read(a,"binary");z("object"===typeof a);return a},"undefined"!=
                                                                                                                ^

Error: listen EADDRINUSE :::8011
    at Object.exports._errnoException (util.js:1050:11)
    at exports._exceptionWithHostPort (util.js:1073:20)
    at Server.setupListenHandle [as _listen2] (net.js:1263:14)
    at listenInCluster (net.js:1304:12)
    at Server.listen (net.js:1402:7)
    at Function.app.listen (/opt/matrix-appservice-irc/node_modules/express/lib/application.js:595:24)
    at AppService.listen (/opt/matrix-appservice-irc/node_modules/matrix-appservice/lib/app-service.js:184:14)
    at Bridge.run (/opt/matrix-appservice-irc/node_modules/matrix-appservice-bridge/lib/bridge.js:258:21)
    at IrcBridge.<anonymous> (/opt/matrix-appservice-irc/lib/bridge/IrcBridge.js:235:24)
    at Generator.next (<anonymous>)
    at Generator.tryCatcher (/opt/matrix-appservice-irc/node_modules/bluebird/js/release/util.js:16:23)
    at PromiseSpawn._promiseFulfilled (/opt/matrix-appservice-irc/node_modules/bluebird/js/release/generators.js:97:49)
    at Async._drainQueue (/opt/matrix-appservice-irc/node_modules/bluebird/js/release/async.js:138:12)
    at Async._drainQueues (/opt/matrix-appservice-irc/node_modules/bluebird/js/release/async.js:143:10)
    at Immediate.Async.drainQueues (/opt/matrix-appservice-irc/node_modules/bluebird/js/release/async.js:17:14)
    at runCallback (timers.js:672:20)
    at tryOnImmediate (timers.js:645:5)
    at processImmediate [as _immediateCallback] (timers.js:617:5)

[t3chguy]

So my guess is its pm2 trying to restart it stupidly quickly and the expensive startup is repeated over and over consuming loads of CPU

[JigmeDatse]

OK, that was mostly my suspicion as well.

[Half-Shot]

I think we're likely to not fix this. I suggest using docker / systemd or another management process that gives you some delay.