oracle / node-oracledb

Oracle Database driver for Node.js maintained by Oracle Corp.
http://oracle.github.io/node-oracledb/
Other
2.25k stars 1.07k forks source link

I get a lot of error from NJS-040 #1215

Closed fbsanches closed 4 years ago

fbsanches commented 4 years ago

I am getting a lot of NJS-040 error in my application. I read some topics about the error here on the forum, but it didn't help me much.

We use pm2 3.5 and node 11.14.

I'm trying to enable logstats mode, but I can't understand where I can place and enable it to view these statistics. In my code database it looks like this:

module.exports = { hrPool: { user: 'xyz', password: 'xyz', connectString: 'xyz', poolMin: 10, poolMax: 100, poolIncrement: 1, poolTimeout: 120, _enableStats : true } }

where can i add the line pool._logStats () do not boot? in the ecosystem? or the moment I request the connection again in the application?   conn = await oracledb.getConnection ();

Thank you for your help.

fbsanches commented 4 years ago

I was able to enable statistics based on this link: Leakage of pool._connectionsOut counter and consequent NJS-040 exception

fbsanches commented 4 years ago

This is the pool information when you started giving this error.::

Pool statistics: ...total up time (milliseconds): 1195784 ...total connection requests: 556 ...total requests enqueued: 201 ...total requests dequeued: 0 ...total requests failed: 0 ...total request timeouts: 118 ...max queue length: 87 ...sum of time in queue (milliseconds): 7082055 ...min time in queue (milliseconds): 0 ...max time in queue (milliseconds): 0 ...avg time in queue (milliseconds): 35234 ...pool connections in use: 4 ...pool connections open: 4 Related pool attributes: ...poolAlias: default ...queueTimeout (milliseconds): 60000 ...poolMin: 0 ...poolMax: 50 ...poolIncrement: 1 ...poolTimeout (seconds): 60 ...poolPingInterval: 60 ...sessionCallback: undefined ...stmtCacheSize: 30 Pool status: ...status: 6000 Related environment variables: ...process.env.UV_THREADPOOL_SIZE: 50 undefined

cjbj commented 4 years ago

At a guess, since you have 4 connections in use, you are not setting UV_THREADPOOL_SIZE before Node.js starts its threadpool, so Node.js is actually still using the default number of 4 threads. The doc on _logStats() notes that it will show the value of UV_THREADPOOL_SIZE , not the actual threadpool size.

Also read the doc here and here on pool sizing best practices. 100 max seems excessive . Also the max value needs to be lower than UV_THREADPOOL_SIZE. [update: I see your second test has a lower max]

fbsanches commented 4 years ago

Thank you. It worked.

fbsanches commented 4 years ago

I checked the UV_THREADPOOL_SIZE before initializing as you mentioned. It got to work for a while and even reached 8 pools being used, but it burst again and gives the error of NJS-040. What else can we do? Update pm2?

fbsanches commented 4 years ago

BEFORE: Pool statistics: ...total up time (milliseconds): 2688 ...total connection requests: 25 ...total requests enqueued: 0 ...total requests dequeued: 0 ...total requests failed: 0 ...total request timeouts: 0 ...max queue length: 0 ...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: 8 ...pool connections open: 9 Related pool attributes: ...poolAlias: default ...queueTimeout (milliseconds): 60000 ...poolMin: 5 ...poolMax: 20 ...poolIncrement: 1 ...poolTimeout (seconds): 60 ...poolPingInterval: 60 ...sessionCallback: undefined ...stmtCacheSize: 30 Pool status: ...status: 6000 Related environment variables: ...process.env.UV_THREADPOOL_SIZE: 24 undefined

AFTER:

Pool statistics: ...total up time (milliseconds): 10772436 ...total connection requests: 7189 ...total requests enqueued: 3413 ...total requests dequeued: 0 ...total requests failed: 0 ...total request timeouts: 3327 ...max queue length: 94 ...sum of time in queue (milliseconds): 199677969 ...min time in queue (milliseconds): 0 ...max time in queue (milliseconds): 0 ...avg time in queue (milliseconds): 58505 ...pool connections in use: 4 ...pool connections open: 5 Related pool attributes: ...poolAlias: default ...queueTimeout (milliseconds): 60000 ...poolMin: 1 ...poolMax: 30 ...poolIncrement: 1 ...poolTimeout (seconds): 60 ...poolPingInterval: 60 ...sessionCallback: undefined ...stmtCacheSize: 30 Pool status: ...status: 6000 Related environment variables: ...process.env.UV_THREADPOOL_SIZE: 34 undefined

fbsanches commented 4 years ago

i just changed poolmin and poolmax. If I put the same value for poolmin and poolmax, the application is in an infinite loop and gives an error. so I put different values on them.

cjbj commented 4 years ago

You still haven't set UV_THREADPOOL_SIZE correctly and/or your code flow is not releasing connections and/or you have row or table deadlocks in your SQL. Without detail from you, I can only guess.

I'd stop using pm2 for a bit and get a single Node.js process working first.

fbsanches commented 4 years ago

OK, thanks for the help. I will do a review and more tests.

cjbj commented 4 years ago

@fbsanches did you get further with your pool use investigation?

fbsanches commented 4 years ago

Yes, the connection pool has worked for several tests. I don't know yet what the real reason is to queue the connections, but now we are investigating the database. thanks for the feedback.

cjbj commented 4 years ago

@fbsanches I'll close this for now. We can reopen it if there is something else you want to ask about.