oracle / node-oracledb

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

queries even with empty result gives NJS-111 #1608

Closed magaber299 closed 4 months ago

magaber299 commented 9 months ago

I am connecting to database using thin client connection, I sometimes receive error (NJS-111: internal error: read a negative integer when expecting a positive integer), even if the query did not return any data from database.

sample error:

NJS-111: internal error: read a negative integer when expecting a positive integer at Object.throwErr (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/errors.js:591:10) at ReadPacket._readInteger (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/protocol/buffer.js:95:16) at ReadPacket.readUB4 (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/protocol/buffer.js:492:17) at ExecuteMessage.processColumnData (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/protocol/messages/withData.js:427:24) at ExecuteMessage.processRowData (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/protocol/messages/withData.js:304:22) at ExecuteMessage.processMessage (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/protocol/messages/withData.js:77:12) at ExecuteMessage.process (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/protocol/messages/base.js:197:12) at ExecuteMessage.process (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/protocol/messages/withData.js:510:11) at ExecuteMessage.decode (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/protocol/messages/base.js:188:10) at Protocol._decodeMessage (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/protocol/protocol.js:77:17) at process.processTicksAndRejections (node:internal/process/task_queues:95:5) at async Protocol._processMessage (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/protocol/protocol.js:148:9) at async ThinConnectionImpl.execute (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/connection.js:796:5) at async Connection.execute (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/connection.js:860:16) at async Connection. (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/util.js:162:14)

  1. environment details: database version =19c process.platform=linux process.version=v18.17.0 process.arch=x64 require('oracledb').versionString=6.1.0

  2. scripts SQL script:

    CREATE TABLE EXTERNAL_SESSION_TBL ( "USER_ID" VARCHAR2(50 BYTE), "RECIPIENT_ID" VARCHAR2(50 BYTE), "CHANNEL" VARCHAR2(20 BYTE), "SESSION_ID" VARCHAR2(36 BYTE), "CREATION_TIME" TIMESTAMP (3), "EXPIRY_TIME" TIMESTAMP (3), CONSTRAINT "EXTERNAL_SESSION_TBL_PKEY" PRIMARY KEY ("USER_ID", "RECIPIENT_ID", "CHANNEL", "SESSION_ID") USING INDEX )

const oracledb = require('oracledb');

async function init(){
    try{
        await oracledb.createPool({
                user          : process.env.DB_USR.toString(),
                password      : process.env.DB_PWD.toString(),
                connectString : process.env.DB_CONNECT_STR.toString(),
                poolAlias     : process.env.DB_CONN_POOL_ALIAS.toString(),
                poolIncrement : Number.parseInt(process.env.DB_CONN_POOL_INCREMENT),
                poolMax       : Number.parseInt(process.env.DB_CONN_POOL_MAX),
                poolMin       : Number.parseInt(process.env.DB_CONN_POOL_MIN),
                queueMax      : -1,
                queueTimeout  : 0 
            });
        oracledb.poolPingInterval = 0;
        oracledb.outFormat = oracledb.OUT_FORMAT_OBJECT;
        oracledb.fetchAsString = [oracledb.CLOB];
        oracledb.autoCommit = true;
        oracledb.fetchTypeHandler = function(metaData) {
            metaData.name = metaData.name.toLowerCase();
        }
    }
    catch(err){
            winstonLogger.winstonLogger("init() "+err.stack)
    }
}

async function get(userID,recipientID,channel){
    var stmt = 'SELECT SESSION_ID FROM EXTERNAL_SESSION_TBL WHERE EXPIRY_TIME >= SYSTIMESTAMP AND USER_ID = :M AND RECIPIENT_ID = :R AND CHANNEL = :C';
    var bindVars= [];
    var externalSession;
    bindVars.push(userID)
    bindVars.push(recipientID)
    bindVars.push(channel)
    result = await oraMgr.execute(stmt,bindVars);
    if(result && result.rows && result.rows.length > 0){
        externalSession = result.rows[0];
    }    
    return externalSession;    
}

async function execute(stmt, bindVars, options, retry = 0) {
    let result = null;    
    let connection;
    let e;
    if(!options) options = {};
    try {
        connection = await oracledb.getConnection(process.env.DB_CONN_POOL_ALIAS.toString());
        result = await connection.execute(stmt,bindVars,options);
    } catch (err) {
        winstonLogger.winstonLogger("execute() " + err.stack + " "+ stmt + +" "+JSON.stringify(bindVars));
        e=err;              
    } finally {
        if (connection) {
            try {
                await connection.close(); // Put the connection back in the pool
            } catch (err) {
                winstonLogger.winstonLogger("conn close() "+err.stack)
            }
        }
    }  

}
magaber299 commented 9 months ago

Any clue about this issue?

sudarshan12s commented 9 months ago

Thanks for informing. I could not reproduce with similar program on 6.1.0.

Can you share few more details..

I see this stack frame, at ExecuteMessage.processColumnData (/root/orchestrator/alinma-orchestrator/node_modules/oracledb/lib/thin/protocol/messages/withData.js:427:24)

The line number 427 doesn't point to calling readUB4 (buffer.js:492:17). In 6.1.0 line 427 corresponds to buf.readUInt8. Its not clear on how this could happen.

If this issue is reproduced in test environment (no sensitive data to dump ) .., Can you also share the packet traces enabled with NODE_ORACLEDB_DEBUG_PACKETS env (export NODE_ORACLEDB_DEBUG_PACKETS=1)

magaber299 commented 9 months ago

Dear Sudarshan, thanks for your efforts. please note that the line 427 in file withData.js points to "const numBytes = buf.readUInt8()", while this seems that the integer itself is signed which causes the exception.I attached the file here.

withData.txt

sudarshan12s commented 9 months ago

Dear Sudarshan, thanks for your efforts. please note that the line 427 in file withData.js points to "const numBytes = buf.readUInt8()", while this seems that the integer itself is signed which causes the exception.I attached the file here.

withData.txt

Yes I see withData.js:427 calls buffer.js:492 which is not readUint8 but its readUB4. So i am little confused. Can you also share the console prints by setting the env , NODE_ORACLEDB_DEBUG_PACKETS=1 which dumps the raw packet exchange between client and server.

magaber299 commented 9 months ago

Dear Sudarshan, I enabled the oracledb debugging using the environment variable since Sunday, the packets are output to console, however the issue is not reproduced yet, I will feedback the soonest.

rotkiw commented 8 months ago

We have the same error with a procedure call with multiple parameters. 6.1.0 and 6.2.0 affected. Switching back to 5.5.0 solved the problem.

anthony-tuininga commented 8 months ago

Can you share the procedure in a standalone test case? Or the packet output as suggested by Sudarshan?

Note as well that you should be able to enable thick mode in versions 6.1.0 and 6.2.0 and that should address the issue just as effectively as switching back to 5.5.0. The default in 6.1.0 and 6.2.0 is thin mode.

magaber299 commented 8 months ago

Hello guys,

Thanks alot for your feedback.

currently I am using oracledb 6.2 with thin mode. previously this issue occurs mainly overnight, however after I enabled debugging packets output and for two weeks now, the issue is not reproduced, so I am trying to reproduce it.

sudarshan12s commented 8 months ago

Hello guys,

Thanks alot for your feedback.

currently I am using oracledb 6.2 with thin mode. previously this issue occurs mainly overnight, however after I enabled debugging packets output and for two weeks now, the issue is not reproduced, so I am trying to reproduce it.

Thanks for your time. I think the sample reproducing the issue is same as mentioned in the description which i am checking more details ..

sharadraju commented 5 months ago

@magaber299 Are you able to reproduce this issue with node-oracledb 6.3

magaber299 commented 5 months ago

@magaber299 Are you able to reproduce this issue with node-oracledb 6.3

Dear Sharad, The issue is not reproducing since 6.2 from my side and error is not appearing.

sharadraju commented 4 months ago

Thanks @magaber299 I am closing this issue as it is no longer reproducible. Please feel free to re-open this issue, when you see it again.