Bug 988965

Summary: Node.js App is not running
Product: OpenShift Online Reporter: oitozero <pedro>
Component: ContainersAssignee: Hiro Asari <hasari>
Status: CLOSED INSUFFICIENT_DATA QA Contact: libra bugs <libra-bugs>
Severity: low Docs Contact:
Priority: low    
Version: 2.xCC: dmcphers, jkeck, pedro
Target Milestone: ---Keywords: SupportQuestion
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-08-26 20:17:50 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description oitozero 2013-07-26 19:32:10 UTC
I had a node app running on node 0.10.10.
After I needed to update some code, I pushed the code to the server. 
A couple of minutes after, the app shutdown.

When I run ctl_app status, I get:

ATTR: quota_blocks=1048576
ATTR: quota_files=40000
CLIENT_RESULT: Application is not running

I have no errors on node log. Only that the database connection has shutdown.

I have already tried to restart the app a couple of times, but after a while it shutdowns.

Can anyone give me some insight on what maybe the problem?

Thanks.

Comment 1 Hiro Asari 2013-07-30 15:37:16 UTC
Could you tell us what database is shutting down?

Comment 2 Dan McPherson 2013-07-30 18:19:43 UTC
Lowing the severity until we can get more details.

Comment 3 oitozero 2013-07-31 09:35:30 UTC
http://walkking-oitozero.rhcloud.com

Database: walkking
Type: MySQL 

I have create another account (http://walkking-walkking.rhcloud.com) and I'm having the same problem.

Comment 4 Hiro Asari 2013-07-31 13:00:14 UTC
So MySQL is shutting down.

To investigate further, SSH to the MySQL gear and look at logs: mysql/log/*.log

Comment 5 oitozero 2013-07-31 13:29:24 UTC
Sorry, I misread your question. I thought you were asking what database type I was using.

MySQL is not shutting down. The database connection goes down because the server instance stops. Also, I can't get much information on node log file.

Comment 6 Hiro Asari 2013-07-31 13:45:12 UTC
Ah, OK, so MySQL server is running, but your Node.js app terminates?

Given the information thus far, I suspect the problem lies with your application, and we need to figure out the cause. Since we do not have enough information to go on with, let us first increase verbosity for your application's logging if possible, and study the resulting logs.

Comment 7 oitozero 2013-08-04 12:39:10 UTC
Same log info. Can you increase verbosity also in walkking-walkking.rhcloud.com?

## --------------------------------------------------
nodejs/logs/node.log

Error: Connection lost: The server closed the connection.
    at Protocol.end (/var/lib/openshift/51fcde2b5973ca71eb0000fe/app-root/runtime/repo/node_modules/jugglingdb-mysql/node_modules/mysql/lib/protocol/Protocol.js:72:13)
    at Socket.onend (_stream_readable.js:483:10)
    at Socket.g (events.js:175:14)
    at Socket.EventEmitter.emit (events.js:117:20)
    at _stream_readable.js:910:16
    at process._tickCallback (node.js:415:13)
npm info walkking.1 Failed to exec start script
npm ERR! weird error 8
npm ERR! not ok code 0


## --------------------------------------------------

mysql/log/mysql_error.log

130803 06:45:00 mysqld_safe Starting mysqld daemon with databases from /var/lib/openshift/51fcde2b5973ca71eb0000fe/mysql//data/
130803  6:45:00  InnoDB: Initializing buffer pool, size = 16.0M
130803  6:45:00  InnoDB: Completed initialization of buffer pool
InnoDB: The first specified data file ./ibdata1 did not exist:
InnoDB: a new database to be created!
130803  6:45:00  InnoDB: Setting file ./ibdata1 size to 10 MB
InnoDB: Database physically writes the file full: wait...
130803  6:45:00  InnoDB: Log file ./ib_logfile0 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile0 size to 5 MB
InnoDB: Database physically writes the file full: wait...
130803  6:45:01  InnoDB: Log file ./ib_logfile1 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile1 size to 5 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Doublewrite buffer not found: creating new
InnoDB: Doublewrite buffer created
InnoDB: Creating foreign key constraint system tables
InnoDB: Foreign key constraint system tables created
130803  6:45:01  InnoDB: Started; log sequence number 0 0
130803  6:45:01 [Note] Event Scheduler: Loaded 0 events
130803  6:45:01 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.1.69'  socket: '/var/lib/openshift/51fcde2b5973ca71eb0000fe/mysql//socket/mysql.sock'  port: 3306  Source distribution
130803  6:48:14 [Note] /usr/libexec/mysqld: Normal shutdown

130803  6:48:14 [Note] Event Scheduler: Purging the queue. 0 events
130803  6:48:14  InnoDB: Starting shutdown...
130803  6:48:16  InnoDB: Shutdown completed; log sequence number 0 44233
130803  6:48:16 [Note] /usr/libexec/mysqld: Shutdown complete

130803 06:48:16 mysqld_safe mysqld from pid file /var/lib/openshift/51fcde2b5973ca71eb0000fe/mysql//pid/mysql.pid ended
130803 06:50:58 mysqld_safe Starting mysqld daemon with databases from /var/lib/openshift/51fcde2b5973ca71eb0000fe/mysql//data/
130803  6:50:58  InnoDB: Initializing buffer pool, size = 16.0M
130803  6:50:58  InnoDB: Completed initialization of buffer pool
130803  6:50:58  InnoDB: Started; log sequence number 0 44233
130803  6:50:59 [Note] Event Scheduler: Loaded 0 events
130803  6:50:59 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.1.69'  socket: '/var/lib/openshift/51fcde2b5973ca71eb0000fe/mysql//socket/mysql.sock'  port: 3306  Source distribution
130803  6:54:55 [Note] /usr/libexec/mysqld: Normal shutdown

130803  6:54:55 [Note] Event Scheduler: Purging the queue. 0 events
130803  6:54:55  InnoDB: Starting shutdown...
130803  6:54:59  InnoDB: Shutdown completed; log sequence number 0 44233
130803  6:54:59 [Note] /usr/libexec/mysqld: Shutdown complete

130803 06:54:59 mysqld_safe mysqld from pid file /var/lib/openshift/51fcde2b5973ca71eb0000fe/mysql//pid/mysql.pid ended
130803 06:55:31 mysqld_safe Starting mysqld daemon with databases from /var/lib/openshift/51fcde2b5973ca71eb0000fe/mysql//data/
130803  6:55:31  InnoDB: Initializing buffer pool, size = 16.0M
130803  6:55:31  InnoDB: Completed initialization of buffer pool
130803  6:55:31  InnoDB: Started; log sequence number 0 44233
130803  6:55:31 [Note] Event Scheduler: Loaded 0 events
130803  6:55:31 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.1.69'  socket: '/var/lib/openshift/51fcde2b5973ca71eb0000fe/mysql//socket/mysql.sock'  port: 3306  Source distribution

## --------------------------------------------------
#node.js
ctl_app status 
ATTR: quota_blocks=1048576
ATTR: quota_files=40000
CLIENT_RESULT: Application is not running

#mysql
ctl_app status 
ATTR: quota_blocks=1048576
ATTR: quota_files=40000
CLIENT_RESULT: MySQL is running

Comment 8 Hiro Asari 2013-08-05 20:09:39 UTC
MySQL shutdown seems normal.

In your node.js application log, there is this line:

npm info walkking.1 Failed to exec start script
npm ERR! weird error 8
npm ERR! not ok code 0

It seems that the log is incomplete, though. Please look into nodejs/logs/node.log as to why your application is failing to start.

Comment 9 Hiro Asari 2013-08-13 00:27:04 UTC
Hi,

Is there any update on this?

Comment 10 Hiro Asari 2013-08-26 20:17:50 UTC
walkking-oitozero.rhcloud.com is no longer found in DNS.