By further investigating, I found out that this problem had more to do with a peace of legacy code doing silly things in emulated nested transactions.
Instead of reusing the current connection, it created a new one somewhere and, if a certain condition was fulfilled (the die of a user session for inactivity in this precise case), it would never return the connection to the pool, because the code didn't followed the app design guidelines.
This particular condition caused the bug to occurs at what seemed a "random" frequency, since a user session lifetime can heavily vary among users and app usage.
This is a very project-specific related problem relying on a bug in private code, but I let this there as a reference if someone encounter a similar issue with the mysql connector : investigate carefully to find unreleased connections.
I believed that the maxIdleTimeout parameter would avoid this cases by automaticaly returning an idl connection to the pool, but it doesn't seems to work this way.
------ EDIT -------
Even with my fixed code, the bug appeared again.
So, I conducted four types of tests :
- Raw Testing* the
@mysql/xdevapi module
- Raw testing* the
mysql2 module
- Testing the
@mysql/xdevapi module with my app architecture
- Testing the
mysql2 module with my app architecture
[*] By raw testing, I mean testing the package without any private code involved. Only the module involved.
Raw Testing
Sequential
We try to execute 500 requests, one at a time, and see what happen :
mysql2
const mysql = require('mysql2/promise');
const MAX_CON = Number.parseInt(process.argv[2]) || 120;
const NB_REQ = Number.parseInt(process.argv[3]) || 500;
(async() => {
try{
const client = new mysql.createPool(
{
host : '127.0.0.1',
port : 3306,
user : 'test',
password : 'test',
database : 'test',
connectionLimit : MAX_CON
}
);
const before = Date.now();
for(let i = 0; i < NB_REQ; i++){
const con = await client.getConnection();
await con.query('SELECT 1 from user');
await con.release();
}
const time = (Date.now() - before) / 1000; //in seconds
const opBySecond = NB_REQ / time;
console.log('The end : ', { opBySecond, time, NB_REQ, MAX_CON });
await client.end();
process.exit(0);
}catch(e){
console.log(e);
}
})();
@mysql/xdevapi
const mysql = require('@mysql/xdevapi');
const MAX_CON = Number.parseInt(process.argv[2]) || 120;
const NB_REQ = Number.parseInt(process.argv[3]) || 500;
(async() => {
try{
const client = await mysql.getClient(
{
host : '127.0.0.1',
port : 33060,
user : 'test',
password : 'test',
schema : 'test'
},
{
pooling : {
maxSize : MAX_CON
}
}
);
const before = Date.now();
for(let i = 0; i < NB_REQ; i++){
const con = await client.getSession();
const prep = await con.sql('SELECT 1 from user');
await prep.execute();
await con.close();
}
const time = (Date.now() - before) / 1000;
const opBySecond = NB_REQ / time;
console.log('The end : ', { opBySecond, time, NB_REQ, MAX_CON });
await client.close();
process.exit(0);
}catch(e){
console.log(e);
}
})();
Boths scripts run 500 requests with a pool of 60 connections with respective commands :
node squential-mysql2.js 60 500node squential-xdevapi.js 60 500
And the results :
| Driver |
Op / sec |
time (s) |
| mysql2 |
11 111.11 |
0.045 |
| xdevapi |
3 703.70 |
0.135 |
@mysql/xdevapi is 3 to 4 times slower than mysql2 with sequential execution.
Parallel
mysql2
const mysql = require('mysql2/promise');
const MAX_CON = Number.parseInt(process.argv[2]) || 60;
const NB_REQ = Number.parseInt(process.argv[3]) || 500;
(async() => {
try{
const client = new mysql.createPool(
{
host : '127.0.0.1',
port : 3306,
user : 'test',
password : 'test',
database : 'test',
connectionLimit : MAX_CON
}
);
const before = Date.now();
const promises = [];
for(let i = 0; i < NB_REQ; i++){
promises.push(new Promise(async resolve => {
const con = await client.getConnection();
await con.query('SELECT 1 from user');
await con.release();
resolve();
}))
}
await Promise.allSettled(promises);
const time = (Date.now() - before) / 1000; //in seconds
const opBySecond = NB_REQ / time;
console.log('The end : ', { opBySecond, time, NB_REQ, MAX_CON });
await client.end();
process.exit(0);
}catch(e){
console.log(e);
}
})();
@mysql/xdevapi
const mysql = require('@mysql/xdevapi');
const MAX_CON = Number.parseInt(process.argv[2]) || 60;
const NB_REQ = Number.parseInt(process.argv[3]) || 500;
(async() => {
try{
const client = await mysql.getClient(
{
host : '127.0.0.1',
port : 33060,
user : 'test',
password : 'test',
schema : 'test'
},
{
pooling : {
maxSize : MAX_CON
}
}
);
const before = Date.now();
const promises = [];
for(let i = 0; i < NB_REQ; i++){
promises.push(new Promise(async resolve => {
const con = await client.getSession();
const prep = await con.sql('SELECT 1 from user');
await prep.execute();
await con.close();
resolve()
}));
}
await Promise.allSettled(promises);
const time = (Date.now() - before) / 1000;
const opBySecond = NB_REQ / time;
console.log('The end : ', { opBySecond, time, NB_REQ, MAX_CON });
await client.close();
process.exit(0);
}catch(e){
console.log(e);
}
})();
There things are worse.
Boths scripts run 500 requests with a pool of 60 connections with respective commands :
node parallel-mysql2.js 60 500node parallel-xdevapi.js 60 500
And the results :
| Driver |
Op / sec |
time (s) |
| mysql2 |
8 771.92 |
0.057 |
| xdevapi |
76.66 |
6.522 |
@mysql/xdevapi is 110 times slower than mysql2 with parallel execution. But it doesn't stop there.
If you try node parallel-xdevapi.js 120 500 you may get an error :
/test/node/node_modules/@mysql/xdevapi/lib/DevAPI/Connection.js:920
return state.error || new Error(errors.MESSAGES.ER_DEVAPI_CONNECTION_CLOSED);
^
Error: This session was closed. Use "mysqlx.getSession()" or "mysqlx.getClient()" to create a new one.
at Object.getError (/test/node/node_modules/@mysql/xdevapi/lib/DevAPI/Connection.js:920:35)
at Socket.<anonymous> (/test/node/node_modules/@mysql/xdevapi/lib/DevAPI/Connection.js:677:40)
at Object.onceWrapper (node:events:642:26)
at Socket.emit (node:events:527:28)
at TCP.<anonymous> (node:net:715:12)
Node.js v18.0.0
While node parallel-mysql2.js 120 500 output :
| Driver |
Op / sec |
time (s) |
| mysql2 |
7 142.86 |
0.07 |
For the error thrown, my guess is that mysql/xdevapi doesn't handle the mysql-server max clients connected at a time. On my machine it's the default 128 value, since I have several process using the DB, running the script with a pool of maxSize=120 crash the proces.
It's the reason wy I didn't get any error in dev, but some hasardous crash in prod : with two pools of maxSize=25 by process and 4 nodejs process launched in parallel, it reached a max of 200 mysql client connections. Any load of connections crashed one or several pools, and thus the process would not be able to recover from it. All subsquent calls to client.getSession() would hang indefinitly from this point.
App Testing
I refactored the whole app DB connection handling to be sure it is consistant, then I created a DB component that can handle connector plugin/plugout.
I created two plugin : one using a @mysql/xedvapi driver, and another one using mysql2. Both shown similar results than those above when I run some benchmarks with autocannon.
I also created a connection wrapper that helps me know if any connection remains unclosed. No connection where left open anywere and were always returned to the pool after each query.
Conclusion
In conclusion, I would say that it seems that something is wrong with the @mysql/xdevapi package at this time, in version 8.0.29 with mysql 8.0.29, on nodejs v18.0.0, ubuntu 20.04.
Either for it not handling the edge case when the mysql server cannot accept more connection, or for its slow perfromance, especially when queries are not sequential (which is the majority of the use cases in a webserver like nodejs application).
I solved my problem by switching from @mysql/xdevapi to mysql2 for now.
-------------- EDIT2 ----------------
For those who are or may be intrested into this discussion, follow this link to the mysql bug report.
