MySQL server disconnects after a few hours despite using pools

[gregcarlin]

We are using pool.query to query a MySQL database, but after running our website for a few hours we get an error:

Error: Connection lost: The server closed the connection. 
at Protocol.end (/opt/node-v0.10.20-linux-x64/IM/node_modules/mysql/lib/protocol/Protocol.js:73:13)
at Socket.onend (stream.js:79:10)
at Socket.EventEmitter.emit (events.js:117:20)
at _stream_readable.js:920:16
at process._tickCallback (node.js:415:13)

And our server can no longer connect to the MySQL database. We are using pools, so I thought the pool would automatically reconnect to the DB. Here's the code we use to create the pool:

pool = mysql.createPool({
  connectionLimit    : 10,
  host               : creds.mysql_host,
  port               : creds.mysql_port,
  database           : creds.mysql_db,
  user               : creds.mysql_user,
  password           : creds.mysql_pass,
  multipleStatements : true
});

And when we query the pool we do

pool.query("statement", [inputs], callback);

I have found similar issues online when people are using pool.getConnection without calling connection.release(), but we are using pool.query and cannot release the connection manually.

[dougwilson]

Unfortunately it's not really possible to give an answer with just that information. When those errors occur, gave you taken a look in the server logs to see if this library is trying to make new connections? You can use the debug feature of this library as well to see what is happening when you get those errors as well.

[dougwilson]

You can may be able to drop in the "mysql2" library and determine if it has the same behavior or not.

[sidorares]

to me it looks like server or network issue, but logs would help indeed

[gregcarlin]

Here's a selection of the log from the node server, with debug turned on in node-mysql.

Error: Connection lost: The server closed the connection.
    at Protocol.end (/home/jgrader/JGrader/JGrader/node_modules/mysql/lib/protocol/Protocol.js:103:13)
    at Socket.<anonymous> (/home/jgrader/JGrader/JGrader/node_modules/mysql/lib/Connection.js:88:28)
    at Socket.emit (events.js:129:20)
    at _stream_readable.js:908:16
    at process._tickCallback (node.js:355:11)
Node NOT Exiting...
Error: Connection lost: The server closed the connection.
    at Protocol.end (/home/jgrader/JGrader/JGrader/node_modules/mysql/lib/protocol/Protocol.js:103:13)
    at Socket.<anonymous> (/home/jgrader/JGrader/JGrader/node_modules/mysql/lib/Connection.js:88:28)
    at Socket.emit (events.js:129:20)
    at _stream_readable.js:908:16
    at process._tickCallback (node.js:355:11)
Node NOT Exiting...
GET / 304 6.543 ms - -
GET /stylesheets/reset.css 304 3.232 ms - -
GET /javascripts/landing.js 304 3.734 ms - -
GET /javascripts/jquery-2.1.1.min.js 304 3.347 ms - -
GET /images/star.png 304 2.072 ms - -
GET /stylesheets/landing.css 304 1.734 ms - -
GET /images/home.jpg 304 1.305 ms - -
{ [Error: Cannot enqueue Query after fatal error.] code: 'PROTOCOL_ENQUEUE_AFTER_FATAL_ERROR', fatal: false }

The server continues to serve pages after this, but cannot connect to the DB. There are no other errors reported. The first two errors are printed by a piece of code I implemented from StackOverflow to keep the server running in the event of an error:

process.on('uncaughtException', function (err) {
  console.error(err.stack);
  console.log("Node NOT Exiting...");
});

I also have code to catch MySQL errors, but it does not seem to be triggering.

pool.on('error', function(err) {
  console.log("MySQL ERROR");
  console.log("CODE: " + err.code);
  console.log("STACK:");
  console.log(err.stack);
});

Every time the server tries to connect to the DB, this is printed:

{ [Error: Cannot enqueue Query after fatal error.] code: 'PROTOCOL_ENQUEUE_AFTER_FATAL_ERROR', fatal: false }

After the server is restarted, everything works again (until a few hours later).

[dougwilson]

So by debug, we meant enabling debug on this module :) Just add debug: true to your MySQL configuration. Otherwise we still don't have enough information.

I also have code to catch MySQL errors, but it does not seem to be triggering.

As for this, the only reason this module would be trying to throw is if you called certain methods on this module and did not pass it a callback function. If you do that an an error is encountered, depending on the method, it may throw that error instead. I can't really tell you more without seeing your code, though.

Also, adding that "uncaughtException" handler is a really bad idea. Please at lest take in and understand the warning from http://nodejs.org/api/process.html#process_event_uncaughtexception ; if you are getting uncaught exceptions and wondering why perhaps the pool becomes broken, that article may help understand a possible reason.

[gregcarlin]

I did add debug: true, I'm pretty sure it wouldn't print the Error: Cannot enqueue Query after fatal error without that. So I definitely need to take that uncaughtException handler out, I'll probably replace it with the forever module, but that still leaves the question of why we are getting the Connection lost: The server closed the connection error. What else do you recommend looking at to find the cause of this? Here is the end of the MySQL error log, although, if I'm reading the dates correctly, these messages are all from last November. Also, if you want to see the full code, feel free to check out the repo, although I'm sure you have better things to do than dig through our code :)

[dougwilson]

but that still leaves the question of why we are getting the Connection lost: The server closed the connection error

Right. When you have debug: true, there should be a bunch of MySQL packets printed as you're doing activity. I at least need to see the last few MySQL packets before those errors occurred.

[dougwilson]

So in your code, I see two createConnection calls https://github.com/gregthegeek/JGrader/search?utf8=%E2%9C%93&q=createConnection which would definitely cause those errors you posted above. Are you see that's not where the errors are coming from, rather than from the pool?

In two of your files, you create connections when the files load and just leave them hanging there. After some time, the server is going to close those two connections and you'll get those errors emitted. Interesting that you also are seeing exactly two of those errors :) I'm 99% sure that's where your errors are coming from, not from the pool.

[gregcarlin]

Holy shit... I forgot we even had connection code in those files, no one's looked in there in months. I'm pretty sure that's it, I'll make the changes and confirm within 24 hours. Thanks so much!

[dougwilson]

No problem, keep us posted, we're here to help :)

[gregcarlin]

The issue seems to have disappeared... thanks again! We really appreciate the help!

[dougwilson]

No problem :) Feel free to open a new issue if you need anything.