MySQL XDev API - Node.js Connector - client.getSession() never resolve nor throw after few hours

Question

I use the MySQL XDevAPI connector in nodejs to connect to a MySQL db on the same server. It runs successfully few hours until, at some point await pool.getSession() never resolve nor throw any error.

• MySQL is version 8.0.29-0ubuntu0.20.04.3
• NodeJS is 18.0.0
• Mysql XDevConnector for nodejs is v 8.0.29 installed with yarn

I create my client pool with :

{
    pooling : { 
        enabled: true, 
        maxSize: 25, 
        maxIdleTime : 1000, 
        queueTimeout: 2000 
    }
}

As I said, for a few hours, the server will work smoothly, and suddently, the connection pool will stop giving me new sessions. The time before it occurs vary from 10/12h to 48h (the website using it receive almost no traffic).

I tried to circumvent this problem by adding a Promise.race with a timeout, like this :

await Promise.race([
    pool.getSession(),
    new Promise((resolve, reject) => {
        setTimeout(() => reject(
            new DBConnectionError(
                'XDEV_GET_SESSION_NEVER_RETURNS',
                'Here we go again...'
            )
        ), 10000)
    })
]);

Sometimes, hiting the timeout allow the pool to work for subsequent pool.getSession for few minutes until the bug shows up again. Sometimes it takes several calls (3-4) and sometimes, I need to restart my app. It's a very strange and random behavior.

I release every connection after any transaction/request by calling await con.close(), and my race timeout is five time greater than the queueTimeout.

What am I doing wrong ?

Answer 1

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 :

1. Raw Testing* the @mysql/xdevapi module
2. Raw testing* the mysql2 module
3. Testing the @mysql/xdevapi module with my app architecture
4. 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 500
• node 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 500
• node 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.