multiple pool.getConnection - takes more time to release connection

[SJ-SivaSubrahmaniam]

We are able to get results with in milliseconds If we trigger single pool.getconnection. However, with multiple pool.getConnection at the same time its taking time(10s,20s) to release the connection

Note : When using oracledb.getConnection without pool, everything is fine, even triggering multiple call at same time works fine.

Consider table has 5 rows.

Below is my code.

var config = {
    user: 'user',
    password: 'pass',
    connectString: 'localhost',
    poolMax: 10,
    poolMin: 1,
    poolIncrement: 2,
    poolTimeout: 10
}

  //create pool
  oracledb.createPool(config, function(err, pool) {
   if (err) throw err;
   oracledb.getPool = pool; //attach pool to oracledb
   server.start(function (error) {
    if (error) {
      console.log('Failed to start server', error);
    }
  });
 });

//connect with pool  - Triggering the below code with multiple calls at the same time takes time to release connection
oracledb.getPool.getConnection(function (err, connection) {
       connection.execute("select * from table", {}, {
            outFormat: oracledb.OBJECT // Return the result as Object
        }, function (err, result) { 
            //release 
            connection.release(
                function (err) {    
                   **//takes 20s to come into this function**
                    if (err) {
                        console.error(err.message);
                    } 
                });
        });
    });

[cjbj]

Dig a little deeper

• Are you sure it's not the creation of the initial connections that is taking time? Have you 'warmed up' the pool before starting timings?]
• How did you determine you needed a low 10s pool timeout?
• Are you printing/logging timestamps for each step of the app?
• Check the pool queue stats
• How are you invoking the getConnection() method? Check whether you have thread contention: do you need to increase UV_THREADPOOL_SIZE https://github.com/oracle/node-oracledb/blob/master/doc/api.md#connpoolmonitor
• Are you using DRCP? The initial session creation profile can differ from non DRCP, so the cost occurs later.

[dmcghan]

@sivacreatives Please provide a reproducible test case. You're pretty close, but the code you supplied only invokes getConnection once and thus doesn't reproduce the issue your describing.

My guess is you're running into the same issue described here:
#395

[SJ-SivaSubrahmaniam]

1). Changed poolmin to 10 and pooltimeout 0

var config = {
    user: 'user',
    password: 'pass',
    connectString: 'localhost',
    poolMax: 20,
    poolMin: 10,
    poolIncrement: 5,
    poolTimeout: 0
}

Increasing the poolMin value greater than 2 or setting poolTimeout to 0 fixes this issue. max response time 200ms

2). Changed poolmin : 1 and pooltimeout: 10 - release time and get conn time increases for subsequent request.

var config = {
    user: 'user',
    password: 'pass',
    connectString: 'localhost',
    poolMax: 10,
    poolMin: 1,
    poolIncrement: 2,
    poolTimeout: 10
}

However, From my above configuration poolmin : 1, if I try to open 2 connections parallely, From poolIncrement value 2 it has to open two new connections and thus it becomes 3 open connections now.

so, when releasing one connection, it closes opened 2 incremented connection ? or only that particular incremented connection ?

The above setting takes 18s to release the connection not for the first time but for subsequent request. For the first time response comes with in milli seconds.

3).Changed pooltimeout : 1 - Release time and get coon max takes 2s. for subsequent request - average performance

var config = {
    user: 'user',
    password: 'pass',
    connectString: 'localhost',
    poolMax: 10,
    poolMin: 1,
    poolIncrement: 2,
    poolTimeout: 1
}

The above settings(changed pooltimeout to 1) takes 2s to release the connection not for the first time but for subsequent request. For the first time response comes with in milli seconds.

Final Question : Pooltimeout terminates only the Incremented idle connection or all open connection including the minimum opened connection ?

[cjbj]

Having looked a a few cases, the devil is in the details. In particular see my previous question about what you are measuring.

[SJ-SivaSubrahmaniam]

@cjbj

1). Are you sure it's not the creation of the initial connections that is taking time? Have you 'warmed up' the pool before starting timings?] -
We have poolmin : 1 and thus by default only one connection is open. So, when we trigger two connection at a time, from poolincrement value which is 2 it opens two new connection everytime and releases. Is this fine ? or Do you want me to increase poolmin size ?

2). How did you determine you needed a low 10s pool timeout? -
If we are giving it 0, the opened connections in pool are not closed and response is fast. If we are giving it 1, the opened connections are terminated with in 1 sec and response time takes 2s. If we are giving 10, subsequent request response time takes 18s

3). Check the pool queue stats -
I cannot check this, bcoz am exporting the pool to another file and logstats() is not working in another file . However its working with in the createpool function

4).How are you invoking the getConnection() method? Check whether you have thread contention: do you need to increase UV_THREADPOOL_SIZE-

Well, Without increasing the thread and by making the poolmin size 20, response time its fast. I dont see any changes when I try to increase thread size when am having the poolmin:1

5).Are you using DRCP? The initial session creation profile can differ from non DRCP, so the cost occurs later.

We are not using DRCP

[cjbj]

@sivacreatives the more high level description given, the more confusing it is to work out exactly what you are running, and how you are measuring results. Sounds like you need to simplify what you are experimenting with and take it back to a basic, single file test.

[SJ-SivaSubrahmaniam]

Thanks for your reply @cjbj

poolmin : 1 - getting single connection and releasing it has no problem. However, triggering two conn at a time fails.

poolmin : 20 : no problem

[cjbj]

@sivacreatives let us know when you have simplified the test case and have posted it.

[SJ-SivaSubrahmaniam]

var config = {
    user: 'user',
    password: 'pass',
    connectString: 'localhost',
    poolMax: 3,
    poolMin: 1,
    poolIncrement: 2,
    poolTimeout: 60
}

  //create pool
  oracledb.createPool(config, function(err, pool) {
   if (err) throw err;
   oracledb.getPool = pool; //attach pool to oracledb
   server.start(function (error) {
    if (error) {
      console.log('Failed to start server', error);
    }
  });
 });

internals.getOne = function (request, reply) {
oracledb.getPool.getConnection(function (err, connection) {
       connection.execute("select * from table", {}, {
            outFormat: oracledb.OBJECT // Return the result as Object
        }, function (err, result) { 
            //release 
            connection.release(
                function (err) {    
                    if (err) {
                        console.error(err.message);
                    } 
                });
                return reply(result);
        });
    });
}

internals.getTwo = function (request, reply) {
oracledb.getPool.getConnection(function (err, connection) {
       connection.execute("select * from table", {}, {
            outFormat: oracledb.OBJECT // Return the result as Object
        }, function (err, result) { 
            //release 
            connection.release(
                function (err) {    
                    if (err) {
                        console.error(err.message);
                    } 
                });
            return reply(result);
        });
    });
}

From angular :
$http.get('/getOne').then(successCallback, errorCallback);
$http.get('/getTwo').then(successCallback, errorCallback);

@cjbj The above code takes more time to return values for subsequent request.

[cjbj]

• that code doesn't have any instrumentation to measure what is taking time. Originally you mentioned the release was taking time, but now you seem to be focussed on end-to-end time.
• since something subtle is going on, you need to include a complete testcase, not just the db access code.

[SJ-SivaSubrahmaniam]

Hi,

Thanks for your reply @cjbj

Updating oracle client from 11g to 12c fixes this issue. However, We do not know the reason.

Here is the unit test case :
oracleClient_unitTest.zip

unit test case will create three get conn and will release the conn, after pooltimeout time, it will trigger 2 new connections to check the release conn time delay

Oracle 11.2.0.2.0 – After POOL_TIME_OUT Releasing the connection took more time and for subsequent get connection waits for the previous releasing time. (Unit test case will fail here)

Oracle 12.1.0.2.0 – We did not face any problem with connection pool. (Unit test case will pass)

Test case output files are attached for both oracle clients(11.2,12.1).
oracle12_output.txt
oracle11_output.txt

Following are the versions and configuration settings:

Python : 2.7.5
Node : 4.2.6
Database Version : 11g

Dbconfig:

     user            :user,
     password        :pass,
     connectString   :IP/xe,
     poolMin         : 1,
     poolMax         : 20,
     poolIncrement   : 2,
     poolTimeout     : 20

[SJ-SivaSubrahmaniam]

Hi, @cjbj have you had a chance to look into this issue

[cjbj]

From a brief look I think you are seeing the effect of the pool being a shared resource so creating a new connection will block releasing another one. This is likely to be very configuration-specific. My results were different to yours. With the few connections created in your testcase I saw a slow release before the 21s sleep, not after. You should size the pool carefully so the session creation costs can be amortized over a number of getConnection calls. Do you really need so small a poolMin? Do you really need to expire sessions so quickly? Also don't forget we have connection pool queueing now, so a smaller pool will be able to cope better with connection spikes. Have you seen https://github.com/oracle/node-oracledb/blob/master/doc/api.md#connpoolmonitor ?

[cjbj]

@sivacreatives if this is answered, I will close it.

[SJ-SivaSubrahmaniam]

hi @cjbj .. did u use same versions of dependent softwares and oracle client(Instant client) version which I had mentioned above ? using which oracle client version did you face the issue ? bcoz I did not face any issue before timeout threshold.

[cjbj]

I tried various versions on a couple of machines. Results varied.

How did you go with adjusting the pool parameters?

[cjbj]

Closing due to lack of activity.