Liran Cohen Liran Cohen - 4 months ago 39
Node.js Question

Open shift node + mongodb cant start

I'm trying to deploy a Node 6.0 server along with mongo 3.2 onto openshift.
I've managed to create an app using the Node DIY cartridge as found here : http://cartreflect-claytondev.rhcloud.com/reflect?github=connyay/openshift-node-diy

and add to it a mongo DIY cartridge as well : https://raw.githubusercontent.com/icflorescu/openshift-cartridge-mongodb/master/metadata/manifest.yml

In addition i've added .Openshift\action_hooks files that call npm install as part of the build script.

Now to the weird part, after pushing changes and dependency finish installing i get the normal message saying deployment was successful. However my server keep returning 503 error when trying to access it. I tried to call rhc tail to track down what went wrong during server boot but all i got is this log from mongodb:

2016-08-02T10:24:41.848-0400 I STORAGE [main] Engine custom option: cache_size=256M
2016-08-02T10:24:41.858-0400 I CONTROL [initandlisten] MongoDB starting : pid=263740 port=27017 dbpath=/var/lib/openshift/57a0601f0c1e66334d000014/app-root/data/.mongodb/data 64-bit host=ex-std-node712.prod.rhcloud.com
2016-08-02T10:24:41.858-0400 I CONTROL [initandlisten] db version v3.2.7
2016-08-02T10:24:41.858-0400 I CONTROL [initandlisten] git version: 4249c1d2b5999ebbf1fdf3bc0e0e3b3ff5c0aaf2
2016-08-02T10:24:41.858-0400 I CONTROL [initandlisten] allocator: tcmalloc
2016-08-02T10:24:41.858-0400 I CONTROL [initandlisten] modules: none
2016-08-02T10:24:41.858-0400 I CONTROL [initandlisten] build environment:
2016-08-02T10:24:41.858-0400 I CONTROL [initandlisten] distarch: x86_64
2016-08-02T10:24:41.858-0400 I CONTROL [initandlisten] target_arch: x86_64
2016-08-02T10:24:41.858-0400 I CONTROL [initandlisten] options: { net: { bindIp: "127.7.166.130", unixDomainSocket: { enabled: false } }, storage: { dbPath: "/var/lib/openshift/57a0601f0c1e66334d000014/app-root/data/.mongodb/data", engine: "wiredTiger", wiredTiger: { engineConfig: { configString: "cache_size=256M" } } }, systemLog: { logAppend: true, logRotate: "reopen", quiet: true } }
2016-08-02T10:24:41.920-0400 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=8G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),cache_size=256M
2016-08-02T10:24:42.466-0400 I CONTROL [initandlisten]
2016-08-02T10:24:42.466-0400 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2016-08-02T10:24:42.466-0400 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2016-08-02T10:24:42.466-0400 I CONTROL [initandlisten]
2016-08-02T10:24:42.466-0400 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2016-08-02T10:24:42.466-0400 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2016-08-02T10:24:42.466-0400 I CONTROL [initandlisten]
2016-08-02T10:24:42.466-0400 I CONTROL [initandlisten] ** WARNING: soft rlimits too low. rlimits set to 350 processes, 1024 files. Number of processes should be at least 512 : 0.5 times number of files.
2016-08-02T10:24:42.466-0400 I CONTROL [initandlisten]
2016-08-02T10:24:42.473-0400 I FTDC [initandlisten] Initializing full-time diagnostic data capture with directory '/var/lib/openshift/57a0601f0c1e66334d000014/app-root/data/.mongodb/data/diagnostic.data'
2016-08-02T10:24:42.515-0400 I NETWORK [HostnameCanonicalizationWorker] Starting hostname canonicalization worker
2016-08-02T10:24:42.521-0400 I NETWORK [initandlisten] waiting for connections on port 27017


followed by this error log (apparently thrown by node though couldn't be found as a file:

> MyApp-API@0.1.0 start /var/lib/openshift/57a0601f0c1e66334d000014/app-root/runtime/repo
> NODE_ENV=development;DEBUG=*,-not_this,-morgan;node ./bin/www

Port 8080 is already in use

npm ERR! Linux 2.6.32-573.26.1.el6.x86_64
npm ERR! argv "/var/lib/openshift/57a0601f0c1e66334d000014/node-diy/bin/node/bin/node" "/var/lib/openshift/57a0601f0c1e66334d000014/node-diy/bin/node/bin/npm" "start"
npm ERR! node v5.11.1
npm ERR! npm v3.8.6
npm ERR! code ELIFECYCLE
npm ERR! MyApp-API@0.1.0 start: `NODE_ENV=development;DEBUG=*,-not_this,-morgan;node ./bin/www`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the MyApp-API@0.1.0 start script 'NODE_ENV=development;DEBUG=*,-not_this,-morgan;node ./bin/www'.
npm ERR! Make sure you have the latest version of node.js and npm installed.
npm ERR! If you do, this is most likely a problem with the MyApp-API package,
npm ERR! not with npm itself.
npm ERR! Tell the author that this fails on your system:
npm ERR! NODE_ENV=development;DEBUG=*,-not_this,-morgan;node ./bin/www
npm ERR! You can get information on how to open an issue for this project with:
npm ERR! npm bugs MyApp-API
npm ERR! Or if that isn't available, you can get their info via:
npm ERR! npm owner ls MyApp-API
npm ERR! There is likely additional logging output above.

npm ERR! Please include the following file with any support request:
npm ERR! /var/lib/openshift/57a0601f0c1e66334d000014/app-root/runtime/repo/npm-debug.log


what am i missing here ? there dont seems to be any real error message here. It just says that my scripts.start script is failing, some suggested it might be something with environment variables but im not exactly sure which might be able to mess things up like this

Edit

i should also mention that i've set my www app setup to use the openshift variables when available:

var port = normalizePort(process.env.OPENSHIFT_NODEDIY_PORT || '3000');
app.set('port', port);

var ip = process.env.OPENSHIFT_NODEDIY_IP || localhost; //'192.168.1.16'
app.set('ip', ip);


and the mongo connection:

var mongodb_connection_string = 'mongodb://localhost/' + db_name;
//take advantage of openshift env vars when available:
if(process.env.MONGODB_URL){
mongodb_connection_string = process.env.MONGODB_URL + db_name;
}


Edit 2
I eventually managed to find the log file that store the node error i was getting, it seems that rhc tail did not return the full stack but only the few last lines. The entire log actually revealed more details on the issue (see edited error above)

Answer

so i finally figured out what was wrong.

It seems that the default node project created by my IDE (currently webstorm) was configured to listen to a port regardless on the ip, so my www script had this :

var port = normalizePort(process.env.OPENSHIFT_NODEDIY_PORT || '3000');
app.set('port', port);

var ip = process.env.OPENSHIFT_NODEDIY_IP || localhost;
app.set('ip', ip);

/**
 * Create HTTP server.
 */

var server = http.createServer(app);

/**
 * Listen on provided port, on all network interfaces.
 */

server.listen(port);

so at the last line you see i just listen to port and ignore the ip, changing the last line to

server.listen(port, ip);

fixed the issue.