loopbackio / loopbackio/loopback-connector-mysql

Connection to database hangs after Error: read ETIMEDOUT

Open
#456 2 comments 1 reaction 0 assignees View on GitHub

Nobody has claimed this yet.

bug stale
Dominant language
JavaScript
Stars
126
Forks
181
Avg merge
4d 7h
Merged PRs (30d)
12

Description

We're using loopback-connector-mysql v6.0.2 and normally any time there's a database issue, the application automatically reconnects to the database without any intervention on our part.

However, we recently ran into an issue where this did not happen. Even though the database was running, the application would not reconnect to the database until I restarted it.

These were the errors in the log:

Error: Cannot enqueue Query after fatal error.
    at Protocol._validateEnqueue (/usr/src/app/node_modules/mysql/lib/protocol/Protocol.js:212:16)
    at Protocol._enqueue (/usr/src/app/node_modules/mysql/lib/protocol/Protocol.js:138:13)
    at PoolConnection.query (/usr/src/app/node_modules/mysql/lib/Connection.js:198:25)
    at runQuery (/usr/src/app/node_modules/loopback-connector-mysql/lib/mysql.js:197:16)
    at executeWithConnection (/usr/src/app/node_modules/loopback-connector-mysql/lib/mysql.js:239:7)
    at MySQL.executeSQL (/usr/src/app/node_modules/loopback-connector-mysql/lib/mysql.js:248:5)
    at /usr/src/app/node_modules/loopback-connector-mysql/node_modules/loopback-connector/lib/sql.js:597:10
    at /usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:259:9
    at doNotify (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
    at MySQL.ObserverMixin._notifyBaseObservers (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:178:5)
    at MySQL.ObserverMixin.notifyObserversOf (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
    at MySQL.ObserverMixin.notifyObserversAround (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:228:15)
    at MySQL.SQLConnector.execute (/usr/src/app/node_modules/loopback-connector-mysql/node_modules/loopback-connector/lib/sql.js:596:8)
    at MySQL._modifyOrCreate (/usr/src/app/node_modules/loopback-connector-mysql/lib/mysql.js:278:8)
    at MySQL.save.MySQL.updateOrCreate (/usr/src/app/node_modules/loopback-connector-mysql/lib/mysql.js:318:8)
    at invokeConnectorMethod (/usr/src/app/node_modules/loopback-datasource-juggler/lib/dao.js:172:21)
    at /usr/src/app/node_modules/loopback-datasource-juggler/lib/dao.js:637:13
    at doNotify (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
    at doNotify (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
    at doNotify (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
    at doNotify (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
    at Function.ObserverMixin._notifyBaseObservers (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:178:5)
    at Function.ObserverMixin.notifyObserversOf (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
    at Function.ObserverMixin._notifyBaseObservers (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:176:15)
    at Function.ObserverMixin.notifyObserversOf (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
    at Function.ObserverMixin._notifyBaseObservers (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:176:15)
    at Function.ObserverMixin.notifyObserversOf (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
    at Function.ObserverMixin._notifyBaseObservers (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:176:15) 
Error: read ETIMEDOUT
    at TCP.onStreamRead (internal/stream_base_commons.js:209:20)
    at TCP.callbackTrampoline (internal/async_hooks.js:126:14)
    --------------------
    at Protocol._enqueue (/usr/src/app/node_modules/mysql/lib/protocol/Protocol.js:144:48)
    at PoolConnection.query (/usr/src/app/node_modules/mysql/lib/Connection.js:198:25)
    at runQuery (/usr/src/app/node_modules/loopback-connector-mysql/lib/mysql.js:197:16)
    at executeWithConnection (/usr/src/app/node_modules/loopback-connector-mysql/lib/mysql.js:239:7)
    at MySQL.executeSQL (/usr/src/app/node_modules/loopback-connector-mysql/lib/mysql.js:248:5)
    at /usr/src/app/node_modules/loopback-connector-mysql/node_modules/loopback-connector/lib/sql.js:597:10
    at /usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:259:9
    at doNotify (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
    at MySQL.ObserverMixin._notifyBaseObservers (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:178:5)
    at MySQL.ObserverMixin.notifyObserversOf (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
    at MySQL.ObserverMixin.notifyObserversAround (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:228:15)
    at MySQL.SQLConnector.execute (/usr/src/app/node_modules/loopback-connector-mysql/node_modules/loopback-connector/lib/sql.js:596:8)
    at MySQL._modifyOrCreate (/usr/src/app/node_modules/loopback-connector-mysql/lib/mysql.js:278:8)
    at MySQL.save.MySQL.updateOrCreate (/usr/src/app/node_modules/loopback-connector-mysql/lib/mysql.js:318:8)
    at invokeConnectorMethod (/usr/src/app/node_modules/loopback-datasource-juggler/lib/dao.js:172:21)
    at /usr/src/app/node_modules/loopback-datasource-juggler/lib/dao.js:637:13
    at doNotify (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
    at doNotify (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
    at doNotify (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
    at doNotify (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:155:49)
    at Function.ObserverMixin._notifyBaseObservers (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:178:5)
    at Function.ObserverMixin.notifyObserversOf (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
    at Function.ObserverMixin._notifyBaseObservers (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:176:15)
    at Function.ObserverMixin.notifyObserversOf (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
    at Function.ObserverMixin._notifyBaseObservers (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:176:15)
    at Function.ObserverMixin.notifyObserversOf (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)
    at Function.ObserverMixin._notifyBaseObservers (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:176:15)
    at Function.ObserverMixin.notifyObserversOf (/usr/src/app/node_modules/loopback-datasource-juggler/lib/observer.js:153:8)

(the last error is repeated, I'm guessing for each connection in the pool).

In searching online for similar errors, using a pool seems to be the solution for this sort of problem. Of course, this connector is already using a pool, so I'm not sure what options I have to fix this. Unfortunately despite my best efforts I've been unable to reproduce that exact error and so I can't provide a way to reproduce it at this time.

My understanding is that any time a connection encounters an error, it's supposed to be released from the pool to make room for new connections. Why didn't that happen?

According to https://github.com/mysqljs/mysql/issues/2522#issuecomment-921877429, I wonder if it could be a bug in this library since we aren't calling any of the underlying methods directly:

What's so special about Error: read ETIMEDOUT at TCP.onStreamRead that prevents the pool from reconnecting to the database?

This means that you have a reference to a specific connection object in your code. That connection then emitted an error that had the .fatal property set to true, but then your code called .query on that same object after the error.

Ideally if you get a fatal error on a connection, you should either call .release on it to destroy it and call .getConnection to get a new one if you are using the pool, or just call .createConnection to create a new connection if not. Always be careful how you structure your logic, as when the TCP connection is lost from the server, ant temp tables, variables, and uncommitted transactions are lost.

I don't see a single mention of fatal in this library. Maybe some extra logic needs to be added to handle fatal errors? Even crashing the application would be preferable to it hanging, because at least then we could know to restart it.

Thanks!

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with lib/mysql.js, especially runQuery and executeWithConnection, which appear in the stack trace, and review how the connector uses the MySQL pool after connection errors. The issue lacks a reproduction or named tests, so first establish a reproducible ETIMEDOUT case; done means the connector no longer hangs and recovers or fails visibly after a fatal connection error.

Written by the indexing model from the issue text.

Assessment

Tech stack
javascript, mysql, nodejs
Domain
backend, databases
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
30/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.