New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error: Handshake inactivity timeout with Node.js v6.2.0 and RDS #1434

Closed
mklueh opened this Issue May 31, 2016 · 9 comments

Comments

Projects
None yet
3 participants
@mklueh

mklueh commented May 31, 2016

I know there is another issue related to an older Node.js version, but I´m facing the same one on the latest Node.js version as well as v4.x.

I´ve also tried several timeout settings, but it´s not getting better.

pool = require('mysql').createPool({
    connectionLimit : 1000,
    connectTimeout  : 60 * 60 * 1000,
    aquireTimeout   : 60 * 60 * 1000,
    timeout         : 60 * 60 * 1000,
    host            : process.env.DB_HOST,
    user            : process.env.DB_USERNAME,
    password        : process.env.DB_PASSWORD,
    database        : process.env.DB_DATABASE
});
Error: Handshake inactivity timeout
    at Handshake.<anonymous> (/home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/protocol/Protocol.js:160:17)
    at emitNone (events.js:86:13)
    at Handshake.emit (events.js:185:7)
    at Handshake._onTimeout (/home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/protocol/sequences/Sequence.js:116:8)
    at tryOnTimeout (timers.js:224:11)
    at Timer.listOnTimeout (timers.js:198:5)
    --------------------
    at Protocol._enqueue (/home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/protocol/Protocol.js:141:48)
    at Protocol.handshake (/home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/protocol/Protocol.js:52:41)
    at PoolConnection.connect (/home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/Connection.js:123:18)
    at Pool.getConnection (/home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/Pool.js:45:23)
    at Pool.releaseConnection (/home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/Pool.js:146:10)
    at Pool._removeConnection (/home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/Pool.js:269:8)
    at Pool._purgeConnection (/home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/Pool.js:250:8)
    at Ping.onOperationComplete [as _callback] (/home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/Pool.js:91:12)
    at Ping.Sequence.end (/home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/protocol/sequences/Sequence.js:96:24)
    at /home/ubuntu/node/nodejs-chat-server/node_modules/mysql/lib/protocol/Protocol.js:399:18
@dougwilson

This comment has been minimized.

Member

dougwilson commented May 31, 2016

Hi @mklueh, yes, there is an issue with 4.2.0 (that specific version), but you're not using it. I haven't seen this reported before on 6.2.0, and at least some testing here seems to show the timers are working just fine on that version.

Do you think you can walk me through enough such that I can actively reproduce the issue? Then I can attach a debugger to the runtime and determine why it is happening, otherwise, I'm not sure what I can look into :S

@mklueh

This comment has been minimized.

mklueh commented Jun 1, 2016

I´ve tested it on a local database and I got the error too.

It seems to happen when the CPU of the server is at 100%

@dougwilson

This comment has been minimized.

Member

dougwilson commented Jun 1, 2016

Ah. It that case, I can reproduce. Debugging what I have shows that the event loop is getting overwhelmed, and so what is happening is that the node process just doesn't have enough time to even read from the socket before the wall clock ticks past the timeout.

Unfortunately there is no solution to thus besides either you set all your timeouts to Infinity (effectively disabling them, along with the control they provide to prevent your app from running away) or you just cannot run an event loop system under that kind of load (or maybe this is a bug in Node.js itself?).

@mklueh

This comment has been minimized.

mklueh commented Jun 1, 2016

Oh, so maybe I´m going to open an issue within the Node Github repo.

I need to make some measurements for my university degree, so I´ll stay at some distance to the threshold which causes the crashes. Good to have your explanation in case I have to justify myself for any sideeffects.

@dougwilson

This comment has been minimized.

Member

dougwilson commented Sep 28, 2016

Hi @mklueh your last response didn't seem like there was anything to act on here, and it's been a few months. I'm going to close this issue, but please let me know if you would like it re-opened!

@dougwilson dougwilson closed this Sep 28, 2016

@dougwilson dougwilson self-assigned this Sep 28, 2016

@nmeri17

This comment has been minimized.

nmeri17 commented Dec 10, 2016

@dougwilson I use v6.3.1 and this happens to me too. Forgive my naivety but what do you mean by

the node process just doesn't have enough time to even read from the socket before the wall clock ticks past the timeout.

It clearly waits for the time I gave it to elapse (even when a client is attempting to make a mysql connection), then shuts down on its own.

Unfortunately there is no solution to thus besides either you set all your timeouts to Infinity

As it stands, this does me no good either. I set the acquireTimeout to Number.POSITIVE_INFINITY but the plot took a different twist. After exhausting my personal debugging bullets and sending several SOS signals to Stack Overflow, the only logical action for me is to bang my head on the wall. I try to handle errors with console.error and the compiler complains. I try using throw err and I keep getting this one below.

server.js:28
throw err;
^

Error: Connection lost: The server closed the connection.

The best thing is to post the relevant parts of my code here so you can see what is causing the compiler (yes, with the errors I'm getting, Node is definitely compiled) to scream at every little turn I make. Here goes:

myPool = mysql.createPool({host: "127.0.0.1", port: 1717, user: "root", pass: "", multipleStatements: true, acquireTimeout: Number.POSITIVE_INFINITY})
.on("connection", function(connection) {
	console.log("pulling out a connection now")
});

myPool.getConnection(function(err, connection) {
	if (err) {
		throw err;
	}
	connection.query("CREATE DATABASE five_star DEFAULT CHARACTER SET utf8 COLLATE utf8_general_mysql500_ci;CREATE TABLE five_star.users (email VARCHAR(150) NOT NULL , password VARCHAR(50) NOT NULL ) ENGINE = MyISAM;INSERT INTO users (email, password) VALUES ('vainglories17@gmail.com', '1717')",
		function(err) {
	if (err) throw err;
	else
		connection.release();
	console.log("created myPool");
});

});


app = app.use("/login", login)
.use(static(__dirname + "/public"));


function login (req, res, next) {

	if (req.method == "POST") {
		var params = req.body, resObj = {errText: "", sessName: ""};
		
		myPool.getConnection(function(err, connection) {
			if (err) {
				throw err;
			}
			connection.query("SELECT COUNT(*) FROM users WHERE email=? AND password=?", [params.email, params.pwd], function(err, numrows, rowInfo) {
			if (err) {
				throw err;
  			}

			else if (numrows/*.length >= 1*/) {
			connection.release();
  				console.log(numrows);
				req.session.name = params.email.split("@")[0];
				resObj.sessName = req.session.name;
				res.end(JSON.stringify(resObj));
			}
			else {
				resObj.errText = "Incorrect email or password";
				res.end(JSON.stringify(resObj));
			}
		});
		});
	}
	else 
		res.end("output login page here");
		next();
}
@dougwilson

This comment has been minimized.

Member

dougwilson commented Dec 11, 2016

@dougwilson I use v6.3.1 and this happens to me too. Forgive my naivety but what do you mean by
the node process just doesn't have enough time to even read from the socket before the wall clock ticks past the timeout.

Sorry, I guess the conversation in this thread was a little confusing :) This issue is that the library throws a timeout error when the server's CPU is sitting at 100%. When that happens, the Node.js process never end sup getting enough time to actually read from the socket before the wall clock-based timer expires. By the time the process is swapped back to Node.js running on the CPU, it's already past the timer expiration.

@nmeri17

This comment has been minimized.

nmeri17 commented Dec 11, 2016

Oh. Thank you for replying. So your point is, my server's CPU allocation should never utilise its allocation fully but should make room for the mysql module and its connections?

@dougwilson

This comment has been minimized.

Member

dougwilson commented Dec 11, 2016

Hi @nmeri17 I'm not certain what your server's CPU is doing, as you didn't provide that information :) You were questioning the conclusion and reproduction for the problem this specific issue is about, which was caused by CPU, so I was trying to clarify what this issue was about. This is an old, closed issue that was resolved. I'm unsure what issue you are having, but you should probably open a new issue to troubleshoot, so we don't keep sending the OP an email for every comment we make here :)

@mysqljs mysqljs locked and limited conversation to collaborators Dec 11, 2016

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.