Why is my node-oracledb execute Promise steadily increasing in the amount of time it takes to resolve?

Question

I'm writing an ETL tool that interacts with an Oracle database which also uses node-oracledb 1.10 and RxJS to handle all of the various asynchronous data streams that I'm tossing around. I'm running into an issue where the longer my application runs, the longer a call to node-oracledb's .execute() takes, and it seems to increase in running time linearly. Hopefully you can spot the mistake in the code below and correct it.

First let me show how I'm running Oracle queries. I created my own .execute() function that acts as a wrapper around node-oracledb's .execute().

import oracledb from 'oracledb';
var oraConnPool;

export function execute(sql, bind, opts) {
  if (!oraConnPool) {
    createOraPool();
  }
  return oraConnPool
    .then(pool => pool.getConnection())
    .then(conn => conn.execute(sql, bind, opts));
}

function createOraPool() {
  let oraPool = oracledb.createPool(config.database.oracle);
  oraConnPool = oraPool;
  return oraPool;
}

And my config.database.oracle (without the credentials):

{
  "poolTimeout": 60,
  "poolMin": 10,
  "poolMax": 25,
  "queueRequests": true,
  "queueTimeout": 600000,
  "_enableStats": true
}

Below is an example of me invoking my .execute() function. As you can see, there's a lot happening here, so let me try to annotate it a bit for clarity. rnd is used to create a unique id for console.time(), so I can keep track of the time it takes for the .execute() Promise to resolve. Let me know if there's a flaw in this time measuring technique. The bind input variable passed to the SELECT statement is a csv string of ssid identifiers, and a list of matches will be returned. This allows me to batch process records instead of creating a single query for each individual row, hopefully saving some execution time. The first .then() makes every key in the resulting array of objects lowercase. The second .then(), obviously, ends the console.time() tracking.

const rnd = Math.random() * 100;
console.time(rnd);
return execute(`
  SELECT
    ssid_input.ssid AS ssid,
    students.id AS student_id,
    students.student_number AS student_number
  FROM (
         SELECT REGEXP_SUBSTR(
                    :ssids,
                    '[^,]+', 1, level) AS ssid
         FROM dual
         CONNECT BY REGEXP_SUBSTR(
                        :ssids,
                        '[^,]+', 1, level) IS NOT NULL
  ) ssid_input
  LEFT JOIN students ON students.state_studentnumber = ssid_input.ssid`, {
    ssids: {
      val: ssids.join(','),
      dir: orawrap.BIND_IN,
      type: orawrap.STRING
    }
  }, {
    outFormat: orawrap.OBJECT,
    maxRows: ssids.length
  })
  .then(results => {
    return results.rows.map(result => {
      let newObj = {};
      Object.keys(result).forEach(key => {
        newObj[key.toLowerCase()] = result[key];
      });
      return newObj;
    });
  })
  .then(result => {
    console.timeEnd(rnd);
    return result;
  });

Below is the console.time() output, which increases steadily until it hits the 60000 ms queueTimeout limit.

97.24179652744425: 12226.930ms
38.14057213652584: 14583.518ms
46.19793585774834: 16024.785ms
16.12600313565251: 17820.694ms
87.73720584788988: 20809.461ms
54.711100085462604: 22652.638ms
42.474404414891744: 24037.868ms
49.09845121453702: 26521.596ms
87.70258724764568: 29461.480ms
1.0731996619882223: 31210.875ms
90.33430329792829: 32259.944ms
37.4829457960367: 34076.824ms
9.731832830291932: 35292.281ms
/home/nathanjones/Projects/test-forge/node_modules/@reactivex/rxjs/dist/cjs/util/subscribeToResult.js:41
            root_1.root.setTimeout(function () { throw err; });
                                                 ^

Error: NJS-040: connection request timeout

I've tried to include most of the relevant code, please let me know if you need more context.

EDIT:

I added a console.log(pool._logStats()) statement every time the .execute() function is called. I've included the output of the last time it was printed before the NJS-040 error:

Pool statistics:
...total up time (milliseconds): 62823
...total connection requests: 1794
...total requests enqueued: 1769
...total requests dequeued: 0
...total requests failed: 0
...total request timeouts: 0
...max queue length: 1769
...sum of time in queue (milliseconds): 0
...min time in queue (milliseconds): 0
...max time in queue (milliseconds): 0
...avg time in queue (milliseconds): 0
...pool connections in use: 25
...pool connections open: 25
Related pool attributes:
...queueRequests: true
...queueTimeout (milliseconds): 60000
...poolMin: 10
...poolMax: 25
...poolIncrement: 1
...poolTimeout (seconds): 60
...stmtCacheSize: 30
Related environment variables:
...process.env.UV_THREADPOOL_SIZE: undefined
undefined

Answer 1

(This is a duplicate of node-oracledb Issue 474).

You need to make sure you close connections.

You probably need to increase UV_THREADPOOL_SIZE, see the node-oracledb documentation on Connections and Number of Threads.