mariadb-corporation / mariadb-connector-nodejs

MariaDB Connector/Node.js is used to connect applications developed on Node.js to MariaDB and MySQL databases. MariaDB Connector/Node.js is LGPL licensed.
GNU Lesser General Public License v2.1
366 stars 91 forks source link

retrieve connection from pool timeout after 10000ms using pool.query #203

Closed mathias22osterhagen22 closed 2 years ago

mathias22osterhagen22 commented 2 years ago

Hello, I'm hosting a socket.io server that has "routes" (like a basic express server) in which it query the database. I have around 34 users simultaneous.

I'm using pool.query to perform all of my database queries to be sure to release the connection. Example of one of the road:

const sqlquery = require('../config/sql-query');
const utils = require('../config/utils');
const pool = require('../config/mariadb');

module.exports = {
    params: ['user', 'token'],
    requireValidToken: true,
    requireAdmin: false,
    listener: async function (road, data, client, server, userid) {
        let res = await pool.query(sqlquery.getstatsdesklist); //<-- here the query
        console.log(`${utils.getTime()}(${utils.formatId(client.id)})   -->   [${road}]: ${res.length} desk list`);
        utils.success(client, road, { desklist: res });
    }
}; 

I'm getting a retrieve connection from pool timeout after 10000ms error in console after few days/weeks of uptimes on some roads like:

1|server | [02/06 15:12:55](RUPwEX) [queue]: Searching for:
1|server | [02/06 15:12:55] road: queue SqlError: retrieve connection from pool timeout after 10000ms
1|server | at Object.module.exports.createError (/opt/app-root/src/server/node_modules/mariadb/lib/misc/errors.js:61:10)
1|server | at timeoutTask (/opt/app-root/src/server/node_modules/mariadb/lib/pool-base.js:303:16)
1|server | at Timeout.rejectAndResetTimeout [as _onTimeout] (/opt/app-root/src/server/node_modules/mariadb/lib/pool-base.js:326:5)
1|server | at listOnTimeout (internal/timers.js:556:17)
1|server | at processTimers (internal/timers.js:497:7) {| |1\|server \| text: 'retrieve connection from pool timeout after 10000ms',| |1\|server \| sql: null,| |1\|server \| fatal: false,| |1\|server \| errno: 45028,| |1\|server \| sqlState: 'HY000',| |1\|server \| code: 'ER_GET_CONNECTION_TIMEOUT'| |1\|server \| }
1|server | stack: Error: retrieve connection from pool timeout after 10000ms
1|server | at Object.module.exports.createError (/opt/app-root/src/server/node_modules/mariadb/lib/misc/errors.js:61:10)
1|server | at timeoutTask (/opt/app-root/src/server/node_modules/mariadb/lib/pool-base.js:303:16)
1|server | at Timeout.rejectAndResetTimeout [as _onTimeout] (/opt/app-root/src/server/node_modules/mariadb/lib/pool-base.js:326:5)
1|server | at listOnTimeout (internal/timers.js:556:17)
1|server | at processTimers (internal/timers.js:497:7)

I'm not sure to understand the root cause as sometimes its working and sometimes not (like a call from another client after the error on the same road is working well).

Here is the way I'm setting up the pool (connectionLimit is at 50):

const mariadb = require('mariadb');
const cfg = require('./cfg');
const pool = mariadb.createPool({
    host: cfg.database.host,
    user: cfg.database.user,
    password: cfg.database.password,
    connectionLimit: cfg.database.connectionLimit,  // = 50
    database: cfg.database.dbname
});
module.exports = pool;

What could explain this behavior ? Thank you very much.

mathias22osterhagen22 commented 2 years ago

After careful investigation, I figured out that the database they deployed was running on low gas (setup to use max to 1core). So here is what was happening:

  1. the road above is a "big" request taking around 200ms to execute.
  2. when the road get spammed, the database start to get spammed and the pool.query starts to take more and more time to execute, so I found myself with 50 parallel queries executed in simultaneous slowing down each other because of the "charge". Each query going from 200ms to 250ms to 300ms to 350 and keep slowing....
  3. the execution time of each pool.query finally reach 10000ms and timeout on the pool.getConnection

So to avoid this to happened and find a way around, I added a Semaphore around the pool.query forcing max 2 simultaneous pool.query around this road.

So now my clients, after calling this road, are placed in a queue waiting their turn, this solve the accumulating query execution + timeout.

So basically, I slowed down my server to make it faster. 🚂

const Semaphore = require('async-mutex').Semaphore;

const semaphore = new Semaphore(2); //set 2 as max parallel execution

module.exports = {
    params: ['user', 'token', ['limit', 'number'], ['page', 'number']],
    requireValidToken: true,
    requireAdmin: false,
    listener: async function (road, data, client, server, userid) {
        //[...] code
        let [value, release] = await semaphore.acquire(); //wait to +1 if free then +1
        if (!client.connected) { release(); return; } //do not process if client is not connected anymore
        await pool.query(query, parameters); //execute query
        release(); //release, doing -1
        //[...] code
    }
}
rusher commented 2 years ago

This is always depending on application. If all connection are used, pool is queuing other queries demand, so if queue is long, it can lead to the timeout error you face. server will 50 connections used simultaneously with 1 core will have a lot of thread context switching ...

There is no straight answer as to what value you should set for your application connection pool, however, there are some fundamentals you should know before you start fiddling with it. The main idea is you should have enough connections in order to use all the available resources, but not more than that.

Usually the best solution is around (2 to 4) x the core number. With server using one core only, maybe 4 connections would be the solution, without any additional locking.