Node-mysql2: ETIMEDOUT error since v1.1.1

[xingped]

I have a local mysql database that I use for testing and v1.1.1 introduced some sort of bug or configuration change that is causing the error:

{ Error: connect ETIMEDOUT
    at Connection._handleTimeoutError (/home/myuser/code/itemdrop/node_modules/mysql2/lib/connection.js:166:13)
    at ontimeout (timers.js:365:14)
    at tryOnTimeout (timers.js:237:5)
    at Timer.listOnTimeout (timers.js:207:5)
  errorno: 'ETIMEDOUT',
  code: 'ETIMEDOUT',
  syscall: 'connect',
  fatal: true }

Confirmed this does not happen with v1.1.0 by downgrading my project back to that version. I'm using knexjs v0.12.2 to connect with the connection object of:

var knex = require('knex')({
    client: 'mysql2',
    connection: {
        host: 'localhost',
        user: '***',
        password: '***',
        database: 'mydb'
    }
});

[sidorares]

Hi @xingped I think default timeout is 10 seconds - do you see this error immediately or after 10?

[xingped]

I think about 10s. It's not immediate.

On Oct 14, 2016 3:50 PM, "Andrey Sidorov" [email protected] wrote:

Hi @xingped https://github.com/xingped I think default timeout is 10
seconds - do you see this error immediately or after 10?

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/sidorares/node-mysql2/issues/439#issuecomment-253938165,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAL4Z59EmzPQeuvvoT3pINIDP_UojmFdks5q0AcZgaJpZM4KXTUG
.

[sidorares]

for local server 10 seconds seems strange. The timeout is "connect timeout" and cleared as soon as first data is received. Can you try to increase timeout? It's passed as connectTimeout connection parameter

[sushantdhiman]

@xingped Have you tried master, there are some changes related to connectTimeout in master which are not released yet.

[VictorioBerra]

I am encountering this issue as well. I have not tried the version in master yet.

[sidorares]

@VictorioBerra the default timeout is quite low ( 10s ), so same advise - can you try to increase it ( say, 60s ? )

[VictorioBerra]

@sidorares I haven't tried that but I noticed that rolling back to nodejs v6.3.1 fixes this bug for me.

[VictorioBerra]

@sidorares I bumped the timeout to 60 seconds, and I ran on node v7.0.0 for a day or so and got the same errors. I am going to roll back and run on v6.3.1 (my last working version) and see if that solves this.

[sushantdhiman]

@VictorioBerra did you tried the master branch ?

[VictorioBerra]

I have not yet. When will it be pushed to NPM?

On Fri, Nov 11, 2016 at 8:39 AM, Sushant [email protected] wrote:

@VictorioBerra https://github.com/VictorioBerra did you tried the
master branch ?

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/sidorares/node-mysql2/issues/439#issuecomment-259970534,
or mute the thread
https://github.com/notifications/unsubscribe-auth/ACzG690m8gzdJs6pTuaQwzoFrSmh-cwpks5q9H4YgaJpZM4KXTUG
.

[sushantdhiman]

@VictorioBerra https://docs.npmjs.com/files/package.json#github-urls refer this documentation on using Github branches in npm install

[VictorioBerra]

@sushantdhiman I followed your advice and installed the master branch version.

Library and OS Versions

• mysql2 1.1.1
• NodeJS 7.1.0
• knexJS 0.12.6
• Pi 3 on Raspbian GNU/Linux 8.0 (jessie)

KnexJS Configuration Object

  "database": {
    "client": "mysql2",
    "debug": false,
    "connection": {
      "host": "REDACTED",
      "user": "REDACTED",
      "password": "REDACTED",
      "database": "mervin_3",
      "timezone": "CDT",
      "connectTimeout": 60000
    }
  },

I started my server at 2016-11-13T23:22:18.119Z and then approximately 14 hours later at 2016-11-14T12:08:27.224Z calls started failing as usual.

Log Output

2016-11-14T12:08:27.221Z - ESC[31merrorESC[39m: MessageHandler Error thrown in message handler!
2016-11-14T12:08:27.224Z - ESC[31merrorESC[39m: MessageHandler Error: read ETIMEDOUT
    at exports._errnoException (util.js:1022:11)
    at TCP.onread (net.js:572:26)

About 5 minutes later at 2016-11-14T12:53:19.994Z I start getting these:

2016-11-14T12:53:19.994Z - ESC[31merrorESC[39m: MessageHandler Error thrown in message handler!
2016-11-14T12:53:19.996Z - ESC[31merrorESC[39m: MessageHandler Error: Can't add new command when connection is in closed state
    at Connection._addCommandClosedState (/home/mervin/mervin-3/node_modules/mysql2/lib/connection.js:145:13)
    at Connection.query (/home/mervin/mervin-3/node_modules/mysql2/lib/connection.js:515:15)
    at /home/mervin/mervin-3/node_modules/knex/lib/dialects/mysql/index.js:152:18
    at Promise._execute (/home/mervin/mervin-3/node_modules/bluebird/js/release/debuggability.js:299:9)
    at Promise._resolveFromExecutor (/home/mervin/mervin-3/node_modules/bluebird/js/release/promise.js:481:18)
    at new Promise (/home/mervin/mervin-3/node_modules/bluebird/js/release/promise.js:77:14)
    at Client_MySQL2._query (/home/mervin/mervin-3/node_modules/knex/lib/dialects/mysql/index.js:146:12)
    at Client_MySQL2.query (/home/mervin/mervin-3/node_modules/knex/lib/client.js:189:17)
    at Runner.<anonymous> (/home/mervin/mervin-3/node_modules/knex/lib/runner.js:138:36)
    at Runner.tryCatcher (/home/mervin/mervin-3/node_modules/bluebird/js/release/util.js:16:23)
    at Runner.query (/home/mervin/mervin-3/node_modules/bluebird/js/release/method.js:15:34)
    at /home/mervin/mervin-3/node_modules/knex/lib/runner.js:61:21
    at tryCatcher (/home/mervin/mervin-3/node_modules/bluebird/js/release/util.js:16:23)
    at /home/mervin/mervin-3/node_modules/bluebird/js/release/using.js:185:26
    at tryCatcher (/home/mervin/mervin-3/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/home/mervin/mervin-3/node_modules/bluebird/js/release/promise.js:510:31)
    at Promise._settlePromise (/home/mervin/mervin-3/node_modules/bluebird/js/release/promise.js:567:18)
    at Promise._settlePromise0 (/home/mervin/mervin-3/node_modules/bluebird/js/release/promise.js:612:10)
    at Promise._settlePromises (/home/mervin/mervin-3/node_modules/bluebird/js/release/promise.js:691:18)
    at Promise._fulfill (/home/mervin/mervin-3/node_modules/bluebird/js/release/promise.js:636:18)
    at PromiseArray._resolve (/home/mervin/mervin-3/node_modules/bluebird/js/release/promise_array.js:125:19)
    at PromiseArray._promiseFulfilled (/home/mervin/mervin-3/node_modules/bluebird/js/release/promise_array.js:143:14)

Things I remember doing was an apt-get upgrade, updating nodeJS with nvm, and then running npm update which looks like it only updated knexjs.

Do you guys have any idea on how I can code in a solution for this? Why doesnt KnesJS try to reconnect automatically? Maybe I can catch ETIMEDOUT and reconnect? Is this bad practice? Could updating my OS have started causing network connection issues?

[VictorioBerra]

After formatting my Raspberry Pi and re-installing Raspbian I no longer get these timeouts.

[shnhrrsn]

Running into this as well on Node 6.9.1, Knex 0.10 and mysql2 1.1.0 through 1.1.2 (we’ve been testing various versions). After about 12-13 hours of the process running these errors start.

We haven‘t tested the official mysql client yet, but we were previously using mariasql with Knex and weren’t experiencing this problem -- it popped up upon switching to mysql2.

[VictorioBerra]

Which OS on what kind of hardware?

On Dec 5, 2016 11:27 AM, "Shaun Harrison" [e-mail] wrote:

Running into this as well on Node 6.9.1, Knex 0.10 and mysql2 1.1.0
through 1.1.2 (we’ve been testing various versions). After about 12-13
hours of the process running these errors start.

We haven‘t tested the official mysql client yet, but we were previously
using mariasql https://www.npmjs.com/package/mariasql with Knex and
weren’t experiencing this problem -- it popped up upon switching to mysql2.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/sidorares/node-mysql2/issues/439#issuecomment-264918374,
or mute the thread
https://github.com/notifications/unsubscribe-auth/ACzG68Bsd8xEK5OJn2oKmBOuiJDFURfkks5rFEmIgaJpZM4KXTUG
.

[shnhrrsn]

Env is docker based on this image: https://github.com/mhart/alpine-node

Seeing this running on docker locally on Mac as well as in production through AWS’s elastic beanstalk

[wkrueger]

Got that error while playing with https://github.com/wkrueger/blog-draft, after a few hours uptime (without usage) on ubuntu 16 + mysql (+pm2)

willian@ghost-03:~$ mysql --version
mysql  Ver 14.14 Distrib 5.7.17, for Linux (x86_64) using  EditLine wrapper

[kendru]

I'm running a node service in docker, and I have been running into this issue periodically using both the 7.7 and 7.7-alpine tags of the official node docker image.

[shnhrrsn]

FWIW I tried so many different versions and combinations and eventually just switched to the official mysql npm and all problems went away.

[sidorares]

@kendru can you help us reproduce this? Maybe you could reduce it to a single dockerfile I can run locally?

[wkrueger]

My guess of what happened here is:
That was a personal testing website with no acesses. So eventually the database would drop the connection due to inactivity, and initially I havent had set a connection pool. Connection pool seemed to have fixed it (I also hooked that kind of error to kill the process so it could get restarted by pm2).

[sidorares]

@wkrueger my personal advice is to always use connection pool, even under low load ( it's more about proper error handling rather than efficient use of connections )

[kendru]

In my case, I have a connection pool set up and a scheduled job that will trigger 3 to 4 queries every few minutes.
@sidorares I'll try to get a minimal repro sometime in the next few days

[sidorares]

thanks @kendru !

[geshan]

I am seeing this on docker mhart/alpine 6.9 node even with connection pooling.

[sidorares]

@geshan would you be able to prepare some image that can reliably reproduce issue? So that I can pull it and debug on my side

[geshan]

I am getting this in the mhart/alpine-node:6 with the following errors:

Can't add new command when connection is in closed state and This socket has been ended by the other party.

[chunkiat82]

any update on this?

[sidorares]

@chunkiat82 I need some reliable way to reproduce this before I start debugging

[chunkiat82]

@sidorares yes, it seems to be inconsistent for me, now i ran into connection closed issue. If i manage to reproduce it again, i will pass a docker image with the setup for you to debug

[sushantdhiman]

@chunkiat82 Not sure if this relates to your case but here goes https://github.com/sequelize/sequelize/blob/2429146758e444716fe6f29897a787dd2dc37d48/lib/dialects/mysql/connection-manager.js#L85-L89

I observed connection can throw error two times, so you probably need to take care of that. Even if first error is protocol lost or something due to network error, that connection will throw another timeout error.

We need to cancel timeout handler when error event is observed, IIRC we only do that for successful connection case.