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

Question

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

joseviniciusnunes opened this issue 6 months ago · 14 comments

joseviniciusnunes commented 6 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

Answer 1 · 2024-07-17T14:24:13.000Z

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

Answer 2 · 2024-07-18T00:14:02.000Z

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

Answer 3 · 2024-07-22T16:03:04.000Z

@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'
}

Answer 4 · 2024-07-22T16:39:07.000Z

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 ?

Answer 5 · 2024-07-23T11:32:09.000Z

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

Answer 6 · 2024-07-23T11:34:47.000Z

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

Answer 7 · 2024-07-23T13:19:52.000Z

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

I mean some what like these:

create table,
insert records,
select LOB columns // works
drop table ,
create table with same column types or with different column types,
select LOB columns sometimes fail at this stage??

Answer 8 · 2024-07-23T13:20:48.000Z

@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

Answer 9 · 2024-07-23T14:49:15.000Z

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

I mean some what like these:

create table,

insert records,

select LOB columns // works

drop table ,

create table with same column types or with different column types,

select LOB columns sometimes fail at this stage??

no, they are permanent data tables.

I sent the log to your email

Answer 10 · 2024-07-23T15:10:51.000Z

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

I mean some what like these:

create table,

insert records,

select LOB columns // works

drop table ,

create table with same column types or with different column types,

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)

Answer 11 · 2024-07-23T15:21:28.000Z

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

I mean some what like these:

create table,

insert records,

select LOB columns // works

drop table ,

create table with same column types or with different column types,

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

Answer 12 · 2024-07-24T15:58:30.000Z

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;

Answer 13 · 2024-07-24T17:30:38.000Z

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

Answer 14 · 2024-07-29T13:50:22.000Z

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