My node.js app seems to keep freezing.

[Tom Krones]

My node app seems to freeze (502 error) after a few hours of running.  I'm new to node and I've build a simple mysql web service.  We're getting 20k to 30k queries per day.  What could be causing this?  My code?  Not enough instances?

CPU usage is at 0%-2% each

Memory is at about 20MB-30MB out of 128MB each

Any ideas?

Thanks.

[Tom Krones]

Also, DISK is 2MB out of 1 GIG

[bellasys]

Hey Tom, 

You and I have a lot in common considering the scale and expected usage of our apps, and perhaps we can rely on each other moving forward. 

I am running a Node server extension with the same anticipated usage you post. 15-30k hits a day with low demand on transfer data and volume (suggested by your low CPU and memory usage). 

While I am not going live until Friday (1/8/2013), and we probably won't be challenging  more than 10k hits per day until March, ours is a mission critical app since it is an authentication server... 

Long story short I thought I might be able to help you out. 1st question: did yours work fine in test mode and then begin to fail while under load? Keeping in mind that 20-30k queries per day are enough to crash a system dependent on many factors; and even a seemingly steady volume like that may depend on the distribution... Node may simply be going to sleep...

On Friday, February 1, 2013 10:19:20 PM UTC-8, Tom Krones wrote:

[Tom Krones]

Hey,

Yeah, worked great before going live.  I was impressed by the speed of node.js.  

I'm still having the same issues now under load.  It's still fast but after a while (12 to 24 hours) it seems to freeze/timeout and starts returning "AppFog 502 Bad Gateway" errors.  Restarting the app fixes the issue.

Let me know if you have any ideas of what I can do to troubleshoot this.  What do you mean by node going to sleep?  

Thanks,

Tom

--
You received this message because you are subscribed to the Google Groups "AppFog Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to appfog-users...@googlegroups.com.
To post to this group, send email to appfog...@googlegroups.com.
Visit this group at http://groups.google.com/group/appfog-users?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

[bellasys]

It's common for Node to "sleep" which means actually that the server it's running on stops actively listening on the port, so it's not actually a Node behavior... I would detail this more but it doesn't sound like your problem, particularly since you have enough hits per day...

Well, I'm pretty dang slammin busy right now to look at your code but I could take a look Monday if you'd like. Off the top of my head I would say since I used to get constant 502's before I fixed the errors in my app and began to get clean hits that perhaps there's a program state that gets triggered to cause the error? How complex is your program and are there any unhandled exceptions? 

I made a lot of newb mistakes in coding my Node app because it was all new to me, and particularly where I was interfacing with MongoDB. I tend to think of 502's as an erroneous state produced by internal errors, somewhat like getting 500's with PHP which means the page can't be served, but it's because something broke in the code- and more often than not it's some branch of code that gets triggered only occasionally. Might match your issue? 

Check your code for logic or unhandled exceptions and if you can't fix it (or not sure it's the problem) you might want to apportion a secondary service to handle routine starts and stops of node (meaning re-route requests and stop node to restart) switching handlers at 10 hours of uptime to see if that can avoid the issue. 

Again, not much to go on either way...

[Tom Krones]

I found out about the crashlogs.  I took a look at them but I can't make heads or tails of them since I'm new to node.js.  I'm not sure what the hashish package is but I'm guessing one of my other packages is using it.  I installed it using 'npm install hashish'  then updated the app but the app is still crashing and I still see it in the crash log.

Here's a copy of the crashlog:

C:\Users\Tom\\nodejs>af crashlogs TomsApp

====> /logs/staging.log <====

# Logfile created on 2013-02-05 00:53:01 +0000 by logger.rb/25413

Installing dependencies. Node version 0.8.14

Installing mysql@mysql@0.9.6 from local path

Installing hashish@hashish@0.0.4 from registry

Package is not found in npm registry hashish@hashish@0.0.4

Failed getting the requested package: hashish@hashish@0.0.4

Installing require-all@require-all@0.0.5 from local path

====> /logs/stderr.log <====

events.js:71

        throw arguments[1]; // Unhandled 'error' event

                       ^

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-365d7313671d4e40105a4d158

f1247d5/app/node_modules/mysql/lib/protocol/Protocol.js:63:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

Any thoughts?

[Tom Krones]

Update:

I added error handling (to print errors to the log) and mysql connection pooling to the app.  The app is no longer "freezing" but has now started to crash (404 errors).  I need my app to be able to scale with my increase in users.  What can I do to fix these errors and stop my app from crashing?

====> /logs/staging.log <====

# Logfile created on 2013-02-06 06:56:31 +0000 by logger.rb/25413

Installing dependencies. Node version 0.8.14

Installing mysql@mysql@2.0.0-alpha7 from local path

Installing require-all@require-all@0.0.3 from local path

Installing bignum...@bignumber.js@1.0.1 from local path

Installing require-all@https://registry.npmjs.org/require-all/-/require-all-0.0.5.tgz from local path

Installing request@request@ from local path

Installing form-data@form-data from local path

Installing combined-stream@combined-stream@0.0.3 from local path

Installing delayed-stream@delayed-stream@0.0.5 from local path

Installing async@async@0.1.9 from local path

Installing mime@mime from local path

====> /logs/stderr.log <====

(node) warning: possible EventEmitter memory leak detected. 11 listeners added. Use emitter.setMaxListeners() to increase limit.

Trace

    at Connection.EventEmitter.addListener (events.js:175:15)

    at handleDisconnect (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/app.js:75:28)

    at /mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/app.js:93:13

    at Pool.getConnection (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/Pool.js:25:5)

    at QueryDB (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/app.js:73:14)

    at IncomingMessage.http.createServer.pool.getConnection.connection.on.offset (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/app.js:51:17)

    at IncomingMessage.EventEmitter.emit (events.js:93:17)

    at IncomingMessage._emitEnd (http.js:366:10)

    at HTTPParser.parserOnMessageComplete [as onMessageComplete] (http.js:149:23)

    at Socket.socket.ondata (http.js:1704:22)

(node) warning: possible EventEmitter memory leak detected. 11 listeners added. Use emitter.setMaxListeners() to increase limit.

Trace

    at Connection.EventEmitter.addListener (events.js:175:15)

    at handleDisconnect (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/app.js:75:28)

    at /mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/app.js:93:13

    at Pool.getConnection (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/Pool.js:25:5)

    at QueryDB (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/app.js:73:14)

    at IncomingMessage.http.createServer.pool.getConnection.connection.on.offset (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/app.js:51:17)

    at IncomingMessage.EventEmitter.emit (events.js:93:17)

    at IncomingMessage._emitEnd (http.js:366:10)

    at HTTPParser.parserOnMessageComplete [as onMessageComplete] (http.js:149:23)

    at Socket.socket.ondata (http.js:1704:22)

====> /logs/stdout.log <====

Wed, 06 Feb 2013 07:27:13

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/protocol/Protocol.js:72:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

Wed, 06 Feb 2013 07:34:51

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/protocol/Protocol.js:72:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

Wed, 06 Feb 2013 07:34:51

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/protocol/Protocol.js:72:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

Wed, 06 Feb 2013 07:39:14

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/protocol/Protocol.js:72:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

Wed, 06 Feb 2013 07:39:14

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/protocol/Protocol.js:72:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

Wed, 06 Feb 2013 07:41:08

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/protocol/Protocol.js:72:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

Wed, 06 Feb 2013 07:41:08

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/protocol/Protocol.js:72:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

Wed, 06 Feb 2013 07:43:35

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/protocol/Protocol.js:72:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

Wed, 06 Feb 2013 07:45:10

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/protocol/Protocol.js:72:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

Wed, 06 Feb 2013 07:47:22

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/protocol/Protocol.js:72:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

Wed, 06 Feb 2013 07:47:22

Error: Connection lost: The server closed the connection.

    at Protocol.end (/mnt/var/vcap.local/dea/apps/ta-0-887f6653d9e54cd272cde95a0954869b/app/node_modules/mysql/lib/protocol/Protocol.js:72:13)

    at Socket.onend (stream.js:66:10)

    at Socket.EventEmitter.emit (events.js:126:20)

    at TCP.onread (net.js:417:51)

To unsubscribe from this group and stop receiving emails from it, send an email to appfog-users+unsubscribe@googlegroups.com.