sidorares / node-mysql2

:zap: fast mysqljs/mysql compatible mysql driver for node.js
https://sidorares.github.io/node-mysql2/
MIT License
4.08k stars 620 forks source link

Pools with mysqlrouter do not create new connections #1577

Open ceecko opened 2 years ago

ceecko commented 2 years ago

I'm running MySQL8 in InnoDB Cluster with 3 nodes. MySQLRouter is used to connect to the cluster.

When a connection is closed due to wait_timeout in MySQL, the pool throws an error and does not create a new connection. Using: mysql2 v2.3.3

A simple code to recreate - make sure you have wait_timeout = 5 in MySQL:

const mysql = require('mysql2');

(async () => {
  const pool = mysql.createPool({
    connectionLimit: 10,
    host: '127.0.0.1',
    port: 6446,
    user: 'root',
    password: '',
    database: 'mysql',
  })

  const c = pool.promise()
  const first = await c.query('select 1+1')

  // wait for 6 seconds
  await new Promise(resolve => setTimeout(resolve, 6000))

  const second = await c.query('select 1+1')
})()

The first query runs fine. The second throws an error:

Error: Connection lost: The server closed the connection.
    at PromisePool.query (C:\node\node_modules\mysql2\promise.js:341:22)
    at C:\node\test.js:20:26 {
  code: 'PROTOCOL_CONNECTION_LOST',
  errno: undefined,
  sql: undefined,
  sqlState: undefined,
  sqlMessage: undefined
}

When not using MySQLRouter, but connecting to the primary directly, both queries are executed. There's a warning printed to the console though with the second query

Warning: got packets out of order. Expected 2 but received 0
patrick-othmer commented 2 years ago

I have the same issue but with a MariaDB 10.6 cluster.

michal-kralik commented 2 years ago

@sidorares here's my investigation of the issue. Looking for feedback what the best approach for implementation would be here since you have more experience with the library. I'll be happy to submit a PR once we agree on the approach.

MySQL 5.7 - closes connection at the wait_timeout and second query creates a new connection. MySQL 8.0.29 - sends an error packet at the wait_timeout which closes the connection. Second query creates a new connection. MySQL Router 8.0.29 - nothing happens at the wait_timeout. The second query receives an error as a response

Add command: Query
        Sending query command: select 1+1
0 51 <== Query#unknown name(0,,15)
0 51 <== 0b0000000373656c65637420312b31
Warning: got packets out of order. Expected 1 but received 0
 raw: ffbf0f23485930303054686520636c69656e742077617320646973636f6e6e656374656420627920746865207365727665722062656361757365206f6620696e61637469766974792e2053656520776169745f74696d656f757420616e6420696e7465726163746976655f74696d656f757420666f7220636f6e6669677572696e672074686973206265686176696f722e
Trace
    at PoolConnection.handlePacket (/home/michal/node/test-mysql2/node_modules/mysql2/lib/connection.js:427:17)
    at PacketParser.onPacket (/home/michal/node/test-mysql2/node_modules/mysql2/lib/connection.js:85:12)
    at PacketParser.executeStart (/home/michal/node/test-mysql2/node_modules/mysql2/lib/packet_parser.js:75:16)
    at Socket.<anonymous> (/home/michal/node/test-mysql2/node_modules/mysql2/lib/connection.js:92:25)
    at Socket.emit (node:events:537:28)
    at addChunk (node:internal/streams/readable:324:12)
    at readableAddChunk (node:internal/streams/readable:297:9)
    at Readable.push (node:internal/streams/readable:234:10)
    at TCP.onStreamRead (node:internal/stream_base_commons:190:23)
0 51 ==> Query#unknown name(0,Error,149)
/home/michal/node/test-mysql2/node_modules/mysql2/promise.js:341
    const localErr = new Error();
                     ^

Error: The client was disconnected by the server because of inactivity. See wait_timeout and interactive_timeout for configuring this behavior.
    at PromisePool.query (/home/michal/node/test-mysql2/node_modules/mysql2/promise.js:341:22)
    at /home/michal/node/test-mysql2/test.js:24:26 {
  code: 'ER_CLIENT_INTERACTION_TIMEOUT',
  errno: 4031,
  sql: 'select 1+1',
  sqlState: 'HY000',
  sqlMessage: 'The client was disconnected by the server because of inactivity. See wait_timeout and interactive_timeout for configuring this behavior.'
}

Node.js v18.4.0

With MySQL Router, creating a third query throws a PROTOCOL_CONNECTION_LOST error, no packets are received but the connection is closed and properly destroyed.

This may be a bug in MySQL Router or a feature - not sure which one it is :)

Here are my thoughts on the implementation:

  1. If the query returns ER_CLIENT_INTERACTION_TIMEOUT error, it should be safe to automatically retry
  2. Query with a callback - a simple change for example on this level
  3. Query without a callback - a bigger change since error event is emitted here and the change would have to touch this part I think
  4. Query stream - probably the same as "without callback"?

Let me know your thoughts. Happy to discuss/debug further.

michal-kralik commented 2 years ago

I also opened a ticket with MySQL Router in case it's a bug on their end https://bugs.mysql.com/bug.php?id=107651

david-szabo97 commented 7 months ago

Looks like this is fixed since MySQL Router v8.0.32

https://dev.mysql.com/doc/relnotes/mysql-router/8.0/en/news-8-0-32.html

MySQL Router did not close connections if they were closed by the server, but not closed by the client. The connection persisted > indefinitely. As of this release, MySQL Router closes the client connection when the server connection is closed. (Bug #34401798)