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

[joseviniciusnunes]

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]

@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]

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

[joseviniciusnunes]

@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]

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]

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

[joseviniciusnunes]

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

[sudarshan12s]

@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]

@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]

@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]

@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]

@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]

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]

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]

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