retrieve connection from pool timeout

[outbackStack]

I'm getting the following error after installing mariadb as replacement for mysql2. The weird part is that it works during the initial npm install but when I restart the computer I get this error. I think there might be a configuration issue which is not letting it connect to the mysql database during startup.

Is there a way to get an error on why it's not getting the connection from the pool?

not connected due to error: SqlError: (conn=-1, no: 45028, SQLState: HY000) retrieve connection from pool timeout after 10001ms (pool connections: active=0 idle=0 limit=5)

      const pool = mariadb.createPool({
        host: "127.0.0.1",
        user: process.env.DB_USER,
        password: process.env.DB_PASS,
        connectionLimit: 5,
        bigIntAsNumber: true,
        trace: true
      });

      let conn;
      try {
        conn = await pool.getConnection();
        console.log("connected ! connection id is " + conn.threadId);
        await conn.release(); //release to pool
      } catch (err) {
        console.log("not connected due to error: " + err);
      }

[gfiorentini]

I have the same issue. Code very similar to the above. Any help ? GF

[rusher]

Most error must be logged like this example :

SqlError: (conn=-1, no: 45028, SQLState: HY000) retrieve connection from pool timeout after 516ms
    (pool connections: active=0 idle=0 limit=1)
    connection error: Error during pool initialization: (conn=3284, no: 1045, SQLState: 28000) Access denied for user 'root'@'localhost' (using password: YES)
    at module.exports.createError (C:\projects\mariadb-connector-nodejs\lib\misc\errors.js:64:10)
    at Pool._requestTimeoutHandler (C:\projects\mariadb-connector-nodejs\lib\pool.js:349:26)
    at listOnTimeout (node:internal/timers:573:17)
    at process.processTimers (node:internal/timers:514:7) {
  sqlMessage: 'retrieve connection from pool timeout after 516ms\n' +
    '    (pool connections: active=0 idle=0 limit=1)',
  sql: null,
  fatal: false,
  errno: 45028,
  sqlState: 'HY000',
  code: 'ER_GET_CONNECTION_TIMEOUT'
}

real error in previous example is 'Access denied for user 'root'@'localhost' (using password: YES)'

In order to be sure to have this additional error information, could you set initializationTimeout (default 30000ms) to a lower value than acquireTimeout (default to 10000ms) ? in case of network/dns timeout issues, this will permit to have those error logged

[outbackStack]

I've tried setting to a lower value and it stills show the same error.

  const mainPool = mariadb.createPool({
    ...dbConfig,
    connectionLimit: 5,
    bigIntAsNumber: true,
    trace: true,
    initializationTimeout: 9000,
    acquireTimeout: 10000
  });

[outbackStack]

I've managed to print the error object.

SqlError: (conn=-1, no: 45028, SQLState: HY000) retrieve connection from pool timeout after 10001ms
    (pool connections: active=0 idle=0 limit=5)
    at module.exports.createError (/Users/node_modules/mariadb/lib/misc/errors.js:64:10)
    at Pool._requestTimeoutHandler (/Users/node_modules/mariadb/lib/pool.js:349:26)
    at listOnTimeout (node:internal/timers:573:17)
    at process.processTimers (node:internal/timers:514:7)
 From event:
    at PoolPromise.getConnection (/Users/node_modules/mariadb/lib/pool-promise.js:86:50)
    at Object.<anonymous> (file:///Users/routes/auth.js:66:49)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5) {
  sqlMessage: 'retrieve connection from pool timeout after 10001ms\n' +
    '    (pool connections: active=0 idle=0 limit=5)',
  sql: null,
  fatal: false,
  errno: 45028,
  sqlState: 'HY000',
  code: 'ER_GET_CONNECTION_TIMEOUT'
}

[pragmatta]

I'm seeing the same error after the timeout period on a fresh install of MariaDb (11.3) and Node.js connector (3.3.0) using the sample from NPM readme. If I give a wrong password I will get an error for it. If I set debug:true in the connection parameters I get the following in the console.

<== conn:-1 Authentication.onPacketReceive (4,86)
+--------------------------------------------------+
|  0  1  2  3  4  5  6  7   8  9  a  b  c  d  e  f |
+--------------------------------------------------+------------------+
| 52 00 00 00 0A 31 31 2E  33 2E 32 2D 4D 61 72 69 | R....11.3.2-Mari |
| 61 44 42 00 32 00 00 00  4E 66 38 22 3F 56 72 5C | aDB.2...Nf8"?Vr\ |
| 00 FE F7 2D 02 00 FF 81  15 00 00 00 00 00 00 1D | ...-............ |
| 00 00 00 54 72 62 73 3C  6F 3E 26 42 5A 7E 2E 00 | ...Trbs<o>&BZ~.. |
| 6D 79 73 71 6C 5F 6E 61  74 69 76 65 5F 70 61 73 | mysql_native_pas |
| 73 77 6F 72 64 00                                | sword.           |
+--------------------------------------------------+------------------+

==> conn:50 Handshake(0,233)
+--------------------------------------------------+
|  0  1  2  3  4  5  6  7   8  9  a  b  c  d  e  f |
+--------------------------------------------------+------------------+
| E5 00 00 01 0A A3 BE 01  00 00 00 40 E0 00 00 00 | ...........@.... |
| 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 | ................ |
| 1C 00 00 00 6E 6F 64 65  00 14 70 4C AB 86 EF 89 | ....node..pL.... |
| 33 95 64 54 11 F8 FA BE  6B A6 A9 18 9D 61 4E 6F | 3.dT....k....aNo |
| 72 74 68 77 69 6E 64 00  6D 79 73 71 6C 5F 6E 61 | rthwind.mysql_na |
| 74 69 76 65 5F 70 61 73  73 77 6F 72 64 00 FC 88 | tive_password... |
| 00 0C 5F 63 6C 69 65 6E  74 5F 6E 61 6D 65 16 4D | .._client_name.M |
| 61 72 69 61 44 42 20 63  6F 6E 6E 65 63 74 6F 72 | ariaDB connector |
| 2F 4E 6F 64 65 0F 5F 63  6C 69 65 6E 74 5F 76 65 | /Node._client_ve |
| 72 73 69 6F 6E 05 33 2E  33 2E 30 0C 5F 73 65 72 | rsion.3.3.0._ser |
| 76 65 72 5F 68 6F 73 74  09 31 32 37 2E 30 2E 30 | ver_host.127.0.0 |
| 2E 31 03 5F 6F 73 05 77  69 6E 33 32 0C 5F 63 6C | .1._os.win32._cl |
| 69 65 6E 74 5F 68 6F 73  74 0A 50 52 41 47 4D 41 | ient_host.PRAGMA |
| 54 49 53 4D 0D 5F 6E 6F  64 65 5F 76 65 72 73 69 | TISM._node_versi |
| 6F 6E 06 32 31 2E 36 2E  30                      | on.21.6.0        |
+--------------------------------------------------+------------------+

<== conn:50 Authentication.onPacketReceive (4,25)
+--------------------------------------------------+
|  0  1  2  3  4  5  6  7   8  9  a  b  c  d  e  f |
+--------------------------------------------------+------------------+
| 15 00 00 02 00 00 00 02  40 00 00 00 0C 01 0A 09 | ........@....... |
| 6E 6F 72 74 68 77 69 6E  64                      | northwind        |
+--------------------------------------------------+------------------+

In the log file HOSTNAME.err I get these lines:

2024-05-03 21:19:47 44 [Warning] Aborted connection 44 to db: 'northwind' user: 'node' host: 'localhost' (Got an error reading communication packets)

I.e. there is some communication happening but then it drops. I've tried adding a Windows firewall rule for the port but made no difference (and there exists a MariaDb executable rule) and chnaging some settings to no effect. HeidiSql-client works with same credentials. I've also tried to UTF8 on both.

PS. Note that having a wrong password will result in the same error message in Node.js, but in the debug messages you get Access denied for user.

[pragmatta]

Experiences from rolling back versions:

• 3.2.3: same
• 3.1.2: almost same 3 packets (second one is different) in an infinite loop
• 3.0.2: type error in bun (TypeError: Attempted to assign to readonly property.)
• 2.5.6: works!

Below the successfull handshake and a comparison to 3.*:

<== conn:-1 Handshake.parseHandshakeInit (0,82)
+--------------------------------------------------+
|  0  1  2  3  4  5  6  7   8  9  a  b  c  d  e  f |
+--------------------------------------------------+------------------+
| 52 00 00 00 0A 31 31 2E  33 2E 32 2D 4D 61 72 69 | R....11.3.2-Mari |
| 61 44 42 00 6E 00 00 00  58 41 7A 64 65 4D 33 57 | aDB.n...XAzdeM3W |
| 00 FE F7 2D 02 00 FF 81  15 00 00 00 00 00 00 1D | ...-............ |
| 00 00 00 3E 6F 36 5C 4C  47 60 2E 60 7A 68 76 00 | ...>o6\LG`.`zhv. |
| 6D 79 73 71 6C 5F 6E 61  74 69 76 65 5F 70 61 73 | mysql_native_pas |
| 73 77 6F 72 64 00                                | sword.           |
+--------------------------------------------------+------------------+

==> conn:110 Handshake(0,94)
+--------------------------------------------------+
|  0  1  2  3  4  5  6  7   8  9  a  b  c  d  e  f |
+--------------------------------------------------+------------------+
| 5A 00 00 01 0A A3 AE 01  00 00 00 40 E0 00 00 00 | Z..........@.... |
| 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 | ................ |
| 0C 00 00 00 6E 6F 64 65  00 14 E2 A5 3A 21 61 10 | ....node....:!a. |
| 63 F0 8C 1B ED 09 68 62  77 1D ED C9 E7 DD 4E 6F | c.....hbw.....No |
| 72 74 68 77 69 6E 64 00  6D 79 73 71 6C 5F 6E 61 | rthwind.mysql_na |
| 74 69 76 65 5F 70 61 73  73 77 6F 72 64 00       | tive_password.   |
+--------------------------------------------------+------------------+

<== conn:110 Handshake.handshakeResult (0,21)
+--------------------------------------------------+
|  0  1  2  3  4  5  6  7   8  9  a  b  c  d  e  f |
+--------------------------------------------------+------------------+
| 15 00 00 02 00 00 00 02  40 00 00 00 0C 01 0A 09 | ........@....... |
| 6E 6F 72 74 68 77 69 6E  64                      | northwind        |
+--------------------------------------------------+------------------+

PS. My guess would be the handshake is OK and there's been some change in handling of TCP-connections from 2.x to 3.x causing the final ACK to get dropped. This might be network dependent, i.e. with certain MTU or something everything works as expected.