search

oracle / node-oracledb

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

NJS-111: internal error: read a negative integer when expecting a positive integer at position 4475 of packet 80463 #1684

Open joseviniciusnunes opened 3 months ago

joseviniciusnunes commented 3 months ago

Hey guys,

Unfortunately we have the same problem again in production:

"NJS-111: internal error: read a negative integer when expecting a positive integer at position 4475 of packet 80463"

The problem is so intermittent to the point that I can't reproduce it locally.

I updated the driver to version 6.5.1 but had the same results.

Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

sudarshan12s commented 3 months ago

@joseviniciusnunes , do you have the backtrace along with above error message. Does it happen again with a select sql where the response is huge (at network layer response gets fragmented at default sdu size 8k ) . Any more information on type of sql would help.

typically we print backtrace along with the error message:

example:

Error recovery failed: NJS-103: unexpected message type 254 received at position 11 of packet 361
Original error: Cannot read properties of undefined (reading '_oraTypeNum')
      at ExecuteMessage._adjustFetchType (/Users/sudarshansoma/work/nodejs/node-oracledb/lib/thin/protocol/messages/withData.js:135:36)
joseviniciusnunes commented 3 months ago

I'll try to get the log and send it here tomorrow

joseviniciusnunes commented 2 months ago

@sudarshan12s it's help you?

driverError: Error: NJS-111: internal error: read a negative integer when expecting a positive integer at position 4411 of packet 19862 at Object.throwErr (/app/node_modules/oracledb/lib/errors.js:647:10) at ReadPacket._readInteger (/app/node_modules/oracledb/lib/impl/datahandlers/buffer.js:95:16) at ReadPacket.readUB4 (/app/node_modules/oracledb/lib/impl/datahandlers/buffer.js:508:17) at ExecuteMessage.processColumnData (/app/node_modules/oracledb/lib/thin/protocol/messages/withData.js:502:26) at ExecuteMessage.processRowData (/app/node_modules/oracledb/lib/thin/protocol/messages/withData.js:378:22) at ExecuteMessage.processMessage (/app/node_modules/oracledb/lib/thin/protocol/messages/withData.js:79:12) at ExecuteMessage.process (/app/node_modules/oracledb/lib/thin/protocol/messages/base.js:190:12) at ExecuteMessage.decode (/app/node_modules/oracledb/lib/thin/protocol/messages/base.js:181:10) at Protocol._decodeMessage (/app/node_modules/oracledb/lib/thin/protocol/protocol.js:78:17) at process.processTicksAndRejections (node:internal/process/task_queues:95:5) { code: 'NJS-111' }, code: 'NJS-111' }

sudarshan12s commented 2 months ago

The backtrace shows the assertion happened when CLOB/BLOB column is fetched as CLOB/BLOB.
Can you confirm if there is a possibility that these tables are dropped and created during runtime before next insert/select operations are issued ?

joseviniciusnunes commented 2 months ago

@sudarshan12s I don't know exactly what you meant by I understood dropped and created

joseviniciusnunes commented 2 months ago

@sudarshan12s I got the NODE_ORACLEDB_DEBUG_PACKETS log of the query, what is your email so I can send it?

sudarshan12s commented 2 months ago

@sudarshan12s I don't know exactly what you meant by I understood dropped and created

I mean some what like these:

  1. create table,
  2. insert records,
  3. select LOB columns // works
  4. drop table ,
  5. create table with same column types or with different column types,
  6. select LOB columns sometimes fail at this stage??
sudarshan12s commented 2 months ago

@sudarshan12s I got the NODE_ORACLEDB_DEBUG_PACKETS log of the query, what is your email so I can send it?

Please send to sudarshan.ss.s@oracle.com

joseviniciusnunes commented 2 months ago

@sudarshan12s I don't know exactly what you meant by I understood dropped and created

I mean some what like these:

  1. create table,
  2. insert records,
  3. select LOB columns // works
  4. drop table ,
  5. create table with same column types or with different column types,
  6. select LOB columns sometimes fail at this stage??

no, they are permanent data tables.

I sent the log to your email

sudarshan12s commented 2 months ago

@sudarshan12s I don't know exactly what you meant by I understood dropped and created

I mean some what like these:

  1. create table,
  2. insert records,
  3. select LOB columns // works
  4. drop table ,
  5. create table with same column types or with different column types,
  6. select LOB columns sometimes fail at this stage??

no, they are permanent data tables.

I sent the log to your email

I have not received the log file , mostly got filtered out due to zip format, ... Can you send it to my gmail id sudarshan12s@gmail.com or to Anthony (anthony.tuininga@oracle.com)

joseviniciusnunes commented 2 months ago

@sudarshan12s I don't know exactly what you meant by I understood dropped and created

I mean some what like these:

  1. create table,
  2. insert records,
  3. select LOB columns // works
  4. drop table ,
  5. create table with same column types or with different column types,
  6. select LOB columns sometimes fail at this stage??

no, they are permanent data tables. I sent the log to your email

I have not received the log file , mostly got filtered out due to zip format, ... Can you send it to my gmail id sudarshan12s@gmail.com or to Anthony (anthony.tuininga@oracle.com)

I sent

sudarshan12s commented 2 months ago

Thanks @joseviniciusnunes for the logs. I think i am able to reproduce similar issue. Is it possible to verify with this patch if it reproduces at your end..

For 6.5.1, the patch looks like this:


diff --git a/lib/thin/protocol/messages/withData.js b/lib/thin/protocol/messages/withData.js
index 10a63b75a..ff83dc657 100644
--- a/lib/thin/protocol/messages/withData.js
+++ b/lib/thin/protocol/messages/withData.js
@@ -67,7 +67,6 @@ class MessageWithData extends Message {
     if (messageType === constants.TNS_MSG_TYPE_DESCRIBE_INFO) {
       buf.skipBytesChunked();
       const prevQueryVars = this.statement.queryVars;
-      this.statement.queryVars = [];
       this.statement.numQueryVars = 0;
       this.statement.bufferRowCount = 0;
       this.statement.bufferRowIndex = 0;
joseviniciusnunes commented 2 months ago

Thanks @joseviniciusnunes for the logs. I think i am able to reproduce similar issue. Is it possible to verify with this patch if it reproduces at your end..

For 6.5.1, the patch looks like this:


diff --git a/lib/thin/protocol/messages/withData.js b/lib/thin/protocol/messages/withData.js
index 10a63b75a..ff83dc657 100644
--- a/lib/thin/protocol/messages/withData.js
+++ b/lib/thin/protocol/messages/withData.js
@@ -67,7 +67,6 @@ class MessageWithData extends Message {
     if (messageType === constants.TNS_MSG_TYPE_DESCRIBE_INFO) {
       buf.skipBytesChunked();
       const prevQueryVars = this.statement.queryVars;
-      this.statement.queryVars = [];
       this.statement.numQueryVars = 0;
       this.statement.bufferRowCount = 0;
       this.statement.bufferRowIndex = 0;

thanks @sudarshan12s , I'm going to do a battery of tests in STAGE before applying it to production, when I have results I'll post them here

joseviniciusnunes commented 2 months ago

I implemented the change in production on the 25th and since then we have not had the driver error anymore.