ibm_db crashes node with OUTPUT parameter of type BINARY and Data of type non-Buffer

[asselin]

System: Linux x86_64 (Bullseye), node v18.16.1

We have a simple stored procedure call to DB2, where one of the parameters is a BINARY output parameter. We have tried both leaving the Data as the default string type and setting it to a Buffer; in both cases, node crashes due to a double memory free. This bug report is for the case of using a String type, although I believe it will fail in the same way with any non-Buffer type. I opened #942 for Buffer types, since it's a different bug.

This bug was introduced in version 3.0 of ibm_db. I confirmed this by testing different levels of ibm_db (all with version 11.5.8 of the ODBC driver). Version 2.8.1 and 2.8.2 ran under load for 24 hours each with no crashes. Versions 3.0 and 3.2.1 crashed approx every 30 minutes under load with various messages:

malloc_consolidate(): invalid chunk size

free(): invalid pointer

node[1]: ../src/cleanup_queue-inl.h:32:void node::CleanupQueue::Add(node::CleanupQueue::Callback, void*): Assertion `(insertion_info.second) == (true)' failed.

double free or corruption (!prev)

This is the DB2 query:

const query = `call DB2PROD.XQHASH(?, ?, ?, ?, ?, ?, ?)`;

The parameters are:

    const oHashedValue = {
      ParamType: AppConstants.HASH_PARAM_TYPE,
      DataType: HashDataType.BINARY,
      Data: '',
      Length: 32,
    };
    const oErrorCode = {
      ParamType: AppConstants.HASH_PARAM_TYPE,
      DataType: HashDataType.INTEGER,
      Data: '',
    };
    const oReasonCode = {
      ParamType: AppConstants.HASH_PARAM_TYPE,
      DataType: HashDataType.INTEGER,
      Data: '',
    };

    const params = [
      1,
      _.padEnd(hashType, 10),
      value.length,
      _.padEnd(value, 100),
      oHashedValue,
      oErrorCode,
      oReasonCode,
    ];

The call to ibm_db looks like:

db.query(query, params)

The issue is that in this case, Nan::NewBuffer() will be used in GetOutputParameter() to return the data, but isBuffer will not be set to true, and FREE_PARAMS() will free the memory.

If the input parameter is NOT a Buffer (as in this case, where it's a string), then e.g. GetStringParam() will be called from GetParametersFromArray(), and isBuffer will remain false.

Later, in GetOutputParameter(), after the query completes, is this code:

      if(sqlTypeBinary || prm.c_type == SQL_C_BINARY) {
          //str = Nan::NewOneByteString((uint8_t *) prm.buffer, prm.length).ToLocalChecked();
          //prm.buffer will be freed by Garbage collector, no need to free here.
          return scope.Escape(Nan::NewBuffer((char *)prm.buffer, prm.length).ToLocalChecked());
      }

The issue is that prm.c_type is SQL_C_BINARY, so this code will be executed, however, prm.isBuffer is false, so the test in the FREE_PARAMS() macro will not fire, and it will free the memory:

        if (prm = params[i], prm.buffer != NULL && !prm.isBuffer) {  \
            // <either a delete or free here>
        }                                                            \

I confirmed this by adding a logging statement inside that if() statement in GetOutputParameter():

      if(sqlTypeBinary || prm.c_type == SQL_C_BINARY) {
          DEBUG_PRINTF("ODBC::GetOutputParameter -- using NewBuffer.  isBuffer=%d\n", prm.isBuffer);
          // str = Nan::NewOneByteString((uint8_t *) prm.buffer, prm.length).ToLocalChecked();
          return scope.Escape(Nan::NewBuffer((char *)prm.buffer, prm.length).ToLocalChecked());
      }

And you can see it show up in the log:

2023-09-07T14:22:33.015Z [6] : [http] >> POST /contacts/person-ids/hash [correlationId:LOCAL:2c56b690-45ac-4732-a35f-d6673624c052] 
2023-09-07T14:22:33.020Z [6] : [PersonIdService] creating hash of type TAX_ID for value: 123456789 [correlationId:LOCAL:2c56b690-45ac-4732-a35f-d6673624c052] 
2023-09-07T14:22:33.022Z [6] : [ContactPersonDb2Repository] getting stored procedure result using: DB2PROD.XQHASH [correlationId:LOCAL:2c56b690-45ac-4732-a35f-d6673624c052] 
ODBCConnection::Query - Entry
ODBC::GetParametersFromArray
ODBC::GetParametersFromArray - param[0].length = -1
ODBC::GetInt32Param: param1 : paramtype=1, c_type=-25, type=-5, size=0, decimals=0, buffer=1, buffer_length=0, length=8
ODBC::GetParametersFromArray - param[1].length = -1
ODBC::GetStringParam: param2 : paramtype=1, c_type=1, type=12, size=11, decimals=0, buffer=TAX_ID    , buffer_length=11, length=10
ODBC::GetParametersFromArray - param[2].length = -1
ODBC::GetInt32Param: param3 : paramtype=1, c_type=-25, type=-5, size=0, decimals=0, buffer=9, buffer_length=0, length=8
ODBC::GetParametersFromArray - param[3].length = -1
ODBC::GetStringParam: param4 : paramtype=1, c_type=1, type=12, size=101, decimals=0, buffer=123456789                                                                                           , buffer_length=101, length=100
ODBC::GetParametersFromArray - param[4].length = -1
ODBC::GetStringParam: param5 : paramtype=4, c_type=-2, type=-2, size=33, decimals=0, buffer=abc, buffer_length=33, length=3
ODBC::GetParametersFromArray - param[5].length = -1
ODBC::GetStringParam: param6 : paramtype=4, c_type=1, type=12, size=4, decimals=0, buffer=abc, buffer_length=4, length=3
ODBC::GetParametersFromArray - param[6].length = -1
ODBC::GetStringParam: param7 : paramtype=4, c_type=1, type=12, size=4, decimals=0, buffer=abc, buffer_length=4, length=3
ODBCConnection::Query: sqlLen=40, sqlSize=41,sql=call DB2PROD.XQHASH(?, ?, ?, ?, ?, ?, ?), hDBC=1
ODBCConnection::UV_Query - Entry: hDBC=1
ODBC::BindParameters - param[0]: c_type=-25 type=-5 buffer_length=0 size=0 length=8 length=8
ODBC::BindParameters - param[1]: c_type=1 type=12 buffer_length=11 size=11 length=10 length=10
ODBC::BindParameters - param[2]: c_type=-25 type=-5 buffer_length=0 size=0 length=8 length=8
ODBC::BindParameters - param[3]: c_type=1 type=12 buffer_length=101 size=101 length=100 length=100
ODBC::BindParameters - param[4]: c_type=-2 type=-2 buffer_length=33 size=33 length=3 length=3
ODBC::BindParameters - param[5]: c_type=1 type=12 buffer_length=4 size=4 length=3 length=3
ODBC::BindParameters - param[6]: c_type=1 type=12 buffer_length=4 size=4 length=3 length=3
ODBCConnection::Query - Exit for hDBC=1
ODBCConnection::UV_Query - Exit: hDBC=1
ODBCConnection::UV_AfterQuery - Entry
ODBCConnection::UV_AfterQuery : data->result=0, data->noResultObject=0, stmt=10001
SQL Type of parameter: -2
BINARY DATA SELECTED
ODBC::GetOutputParameter - String: paramtype=4 c_type=-2 type=-2 buf_len=33 len=32 val=0x7f572450dd20
**ODBC::GetOutputParameter -- using NewBuffer.  isBuffer=0**
SQL Type of parameter: 12
ODBC::GetOutputParameter - String: paramtype=4 c_type=1 type=12 buf_len=4 len=1 val=0x7f5726e9d980
SQL Type of parameter: 12
ODBC::GetOutputParameter - String: paramtype=4 c_type=1 type=12 buf_len=4 len=1 val=0x7f5726d8b510
ODBCConnection::UV_AfterQuery : outParamCount=3
ODBCResult::New
ODBCResult::New m_hENV=1 m_hDBC=1 m_hSTMT=10001 canFreeHandle=1
ODBCResult::FetchAll - Entry
ODBCResult::FetchAll - Exit
ODBCConnection::UV_AfterQuery - Exit
ODBCResult::UV_FetchAll - Entry
ODBCResult::UV_FetchAll - Exit, return code = -1 for stmt 10001
ODBCResult::UV_AfterFetchAll - Entry
ODBC::GetSQLError : handleType=3, handle=10001
ODBC::GetSQLError : calling SQLGetDiagRec; i=0
ODBC::GetSQLError : after SQLGetDiagRec; i=0, ret=0
ODBC::GetSQLError : errorMessage=[IBM][CLI Driver] CLI0115E  Invalid cursor state. SQLSTATE=24000, errorSQLState=24000
ODBC::GetSQLError : calling SQLGetDiagRec; i=1
ODBC::GetSQLError : after SQLGetDiagRec; i=1, ret=100
ODBC::GetColumns - Entry
ODBC::GetColumns - Exit
ODBCResult::UV_AfterFetchAll, colcount = 0, columns = 654125472, stmt = 10001
ODBCResult::UV_AfterFetchAll Done for stmt 10001
ODBCResult::MoreResultsSync
ODBCResult::CloseSync - Entry
ODBCResult::CloseSync closeOption=1 m_canFreeHandle=1, hSTMT=10001
ODBCResult::Free SQLFreeHandle called for m_hSTMT=10001
ODBCResult::CloseSync - Exit
2023-09-07T14:22:33.236Z [6] : [ContactPersonDb2Repository] stored procedure call successful [correlationId:LOCAL:2c56b690-45ac-4732-a35f-d6673624c052] 
2023-09-07T14:22:33.236Z [6] : [ContactPersonDb2Repository] hash object 32 ' E�&W��ecauseOfAlwaysOp' [correlationId:LOCAL:2c56b690-45ac-4732-a35f-d6673624c052] 
2023-09-07T14:22:33.236Z [6] : [PersonIdService] successfully created hash [correlationId:LOCAL:2c56b690-45ac-4732-a35f-d6673624c052] 
2023-09-07T14:22:33.237Z [6] : [http] << POST /contacts/person-ids/hash 200 OK [correlationId:LOCAL:2c56b690-45ac-4732-a35f-d6673624c052, ms=222] 
ODBC::FreeColumns - Entry
ODBC::FreeColumns - Exit
ODBCResult::UV_AfterFetchAll - Exit
ODBCResult::~ODBCResult m_hSTMT=0 m_canFreeHandle=0
ODBCResult::~ODBCResult m_hSTMT=0 m_canFreeHandle=0
ODBCResult::~ODBCResult m_hSTMT=0 m_canFreeHandle=0
malloc_consolidate(): invalid chunk size

I've also noticed that the output string is also random every time you execute the query; that is also a manifestation of the same bug, using memory that technically is freed and being used by something else.

I created PR #945 to fix this.