IBM/node-odbc

Error calling stored procedure with many parameters. [BUG]

Opened this issue · 33 comments

Describe your system

odbc Package Version: 2.4.7
ODBC Driver: IBM i Access ODBC Driver
Database Name: DB2
Database Version: Latest version + patches
Database OS: Power i
Node.js Version: 14.17.3
Node.js OS: Windows

Hello! I'm testing out odbc with our existing code and ran into an issue calling a stored procedure. Here's the call (lots of parameters)...
call WOR3070SP(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)

This is the error...
Code: 30038, State: HY090, Message: [IBM][System i Access ODBC Driver]Invalid string or buffer length.

Our server admin says he does not see the stored procedure call on the database side, so I'm assuming there's something in the odbc module or the driver that's keeping this from working.

I've also attached an odbc trace.
cwbtrace-64-node.exe-28460.log

Let me know if there is any more information I can provide. Thanks again for your help!

Hi @snotmare ,

Could you post the snippet of code that generates the error? Just the callProcedure function call should suffice. It looks like it is failing on SQLProcedures, but there's really nothing there that should fail as all of the buffers are marked as SQL_NTS (null-terminated string).

Or, if you are using the query function instead of callProcedure, that would be helpful to know as well!

Good morning @markdirish !

This is the portion of code that makes the stored procedure call...

		try {
			let callResults = new ConnectionCallResults();
			connection = await this.getConnection();

			let parameters = worker.parameters.map(parameter => parameter.value);
			let results = await connection.callProcedure(null, null, worker.sql, parameters);

			callResults.rows = results;
			callResults.parameters = results.parameters;
			
			return callResults;
		} catch(error) {

Ok, I created a large procedure with 80 INOUT parameters, and it seemed to behave ok. So it shouldn't be the parameter count itself. Next thing lets try, lets get a unixODBC trace (this has slightly different information than the cwb trace, which is an IBM i-specific trace). Instructions on getting a unixODBC trace can be found here: https://github.com/markdirish/node-odbc#debugging

*** UPDATE ***

Please ignore the following post. It contains invalid information due to a faulty test on my part.


Hello!

I ran my stored procedure test today to build the trace you asked for and... it works now for some reason. Relatable meme

I don't have an explanation of why it's working now. I'm running the same code I did last Wednesday. I have installed some python packages on my pc for an unrelated project, but I don't see how that would impact anything.

Our system admin says nothing on our test lpar has changed, but, "it would have IPL'd on last Friday and likely cleaned up the SQLPKG as part of that IPL"

In case it helps, I've attached the unix trace you asked for plus a new odbc trace. I'll do some more testing over the next week or so and let you know if I run into this again.

As always, thanks for your help!

SQL.LOG
cwbtrace-64-node.exe-9800.log

Neither the SQL.LOG or latest cwbtrace have any relevant calls in them. It connects to the database and calls SQLGetInfo, but that's it. There's no calls to prepare, or SQLProcedures like in the original cwbtrace.

I can say that the HY090 is caused by an error when checking for wildcards in the schema / procedure names. Unfortunately, the driver doesn't trace out the parameters, but I think SQL.log should show us what was being passed.

Ugh, thank you. My prior test was invalid. I have run this again with the trace you asked for and I ran into the issue as expected. Sorry for the confusion.

SQL.LOG

Hi there,
i have an issues with calling an IBM i Stored Procedure which we used with the old Node.js DB Providers back in Node 6 and with idb-pconnector and maybe it is the same problem as above?!?

After testing many, many things I found out it it is the length of the output parameter.

What I do is:

CREATE or replace PROCEDURE SESEDI.SPTEST8 ( 
	IN TEST CHAR(10) CCSID 1208 , 
	OUT RVALUE VARCHAR(2000) CCSID 1208 ) 
	LANGUAGE SQL 
	SPECIFIC SESEDI.SPTEST8 
	NOT DETERMINISTIC 
	MODIFIES SQL DATA 
	CALLED ON NULL INPUT 
	SET OPTION  ALWBLK = *ALLREAD , 
	ALWCPYDTA = *OPTIMIZE , 
	COMMIT = *NONE , 
	DECRESULT = (31, 31, 00) , 
	DYNDFTCOL = *NO , 
	DYNUSRPRF = *USER , 
	SRTSEQ = *HEX   
	BEGIN 
SET RVALUE = 'Hallo Welt' ; 
RETURN ; 
END  ; 

This works fine when I call it this way:
const result = await connection.callProcedure('MYDSN', 'MYLIB','SPTEST8', ['12345', null]);

When I enhance the OUT Parameter to (for example) 16000 it doesn't work anymore.
In my original procedure I return 32000 as varchar. This is a "legacy" thing which is caused by the problem that the first DB driver for Node.js (back in 2014) didn't return a result set. So I solved it this way.
Can you enhance that value easily?
Otherwise I need to change a lot of stuff or find another way.

Many thanks and have a great weekend!
Markus

Good morning @markdirish !

This is the portion of code that makes the stored procedure call...

		try {
			let callResults = new ConnectionCallResults();
			connection = await this.getConnection();

			let parameters = worker.parameters.map(parameter => parameter.value);
			let results = await connection.callProcedure(null, null, worker.sql, parameters);

			callResults.rows = results;
			callResults.parameters = results.parameters;
			
			return callResults;
		} catch(error) {

Sitting here a few weeks later, and I think I know the issue...

Is worker.sql the SQL string you are trying to call? In the .log file you sent, the call to SQLProceduresW had "call WOR3070SP(?, ? ... ,?)" as the proc name. This value should just be WOR3070SP, and then the connector will actually go and execute the procedure with the proper ODBC procedure call escape sequence.

Try replacing worker.sql with just the name of the procedure, and see what happens.

Good morning!

I gave that a shot but ran into this error...

Caused By: Error: [odbc] The number of parameters the procedure expects and and the number of passed parameters is not equal

This is how I updated the code to test that out...

		try {
			let callResults = new ConnectionCallResults();
			connection = await this.getConnection();

			let parameters = worker.parameters.map(parameter => parameter.value);
			console.log(parameters);
			// let results = await connection.callProcedure(null, null, worker.sql, parameters);
			let results = await connection.callProcedure(null, null, 'WOR3070SP', parameters);

			callResults.rows = results;
			callResults.parameters = results.parameters;
			
			return callResults;
		} catch(error) {

As you can see, I also wrote the parameters to the console...

[
  'CH', 'Y', 'FFGFA', '', '',  0,   '',
  '',   '',  '',      0,  0,   '',  '',
  '',   0,   '',      0,  0,   '',  '',
  '',   '',  '',      '', '',  'N', '',
  'N',  0,   '',      '', 'N', '',  '',
  '',   0,   0,       0,  0,   '',  '',
  '',   0,   '',      0,  '',  'N', '',
  '',   '',  '',      '', '',  'N', 0,
  0,    'N', '',      '', '',  '',  '',
  '',   '',  '',      '', '',  '',  '',
  '',   '',  '',      '', ''
]

This is the call I'm expecting it to make...
call WOR3070SP('CH', 'Y', 'FFGFA', '', '', 0, '', '', '', '', 0, 0, '', '', '', 0, '', 0, 0, '', '', '', '', '', '', '', 'N', '', 'N', 0, '', '', 'N', '', '', '', 0, 0, 0, 0, '', '', '', 0, '', 0, '', 'N', '', '', '', '', '', '', 'N', 0, 0, 'N', '', '', '', '', '', '', '', '', '', '', '', '', '', '', '', '', '')

Thank you for your help!

As a side note, could the error message indicate how many parameters are expected and how many were passed in?

Ben

Ok, one more SQL.log with the new code and it should show me the number of params it expects. Delete your old log before running or else it will append to that file

No problem. Here you go!
SQL.LOG

Well, I forgot that ODBC uses SQLProcedureColumns then calls SQLFetch a ton of times... so the log was less than helpful.

How about this. Run the following query, and let me know the result:

SELECT COUNT(*) FROM SYSIBM.SQLPROCEDURECOLS WHERE PROCEDURE_NAME='WOR3070SP'

If you have more than one procedure with that name, you may have to add another part of the WHERE clause and add a check against the value of PROCEDURE_SCHEM.

Yep, I had to add the schema to the where clause. I see 75 columns.

And it looks like you are passing in 75 values. Not sure why it thinks there is a mistmatch. How about a cwb trace, maybe that will tell us a little more?

Or, if you have installed tools that can recompile the package, you can add the following line in src/odbc_connection.cpp, around line 1404 (should be right before the check and procedure parameter count error):

printf("The number of columns is %d\n", (SQLSMALLINT)data->storedRows.size());

Once you've added that line, you can run npm install --build-from-source to add that debug line for us. Then when you run, it should tell us how many rows were returned from SQLProcedureColumns

This is the trace I captured. I killed it after about 30 mins because it looked like it hung. Hopefully this contains the info you're looking for.

We don't code in c++, but it looks like there are some vscode tools I can use. I'll see if I can debug or something to get that count.
cwbtrace-64-node.exe-29732.log

node-odbc Version: 2.4.7
ODBC Driver: iSeries Access ODBC Driver
Database: IBM i V7R3
Node.js Version: 18.16.0
Node.js OS: Windows

I ran into a similar issue with .callProcedure() that may or may not be relevant for @snotmare. Even with the correct number of parameters being used to call a stored procedure, I would get the following error:
Error: [odbc] The number of parameters the procedure expects and and the number of passed parameters is not equal

After doing some digging, I found that this error was caused by having a different PROCEDURE_NAME than a SPECIFIC_NAME. When I ran SELECT * FROM SYSIBM.SQLPROCEDURES WHERE PROCEDURE_NAME = ?, I'd have:

PROCEDURE_NAME SPECIFIC_NAME
GET_TERRITORY_MANAGERS GETTERMGRS

Changing the SPECIFIC_NAME to match the PROCEDURE_NAME resolved my issue.

@myronng Thanks for the tip. In my case, the proc name and specific name already match :/.

That table does indicate the number of input, output, and inout params. In my case, input is 72, inout is 3 for the total of 75 mentioned above.

@markdirish Hello! I've poked around a bit to see if I can recompile the c++ binaries like you suggested (#326 (comment)). I'm not a c++ dev and haven't had any luck with that :/. Sorry to be a pain, but would it be possible for you to create that change in a branch? I can install from that branch and test it out again.

Hi @snotmare ,

I now have a branch called print-param-count. When you run your stored procedure, it should tell you how many parameters it thinks you passed, and how many parameters it thinks the stored procedure has.

https://github.com/markdirish/node-odbc/tree/print-param-count

Thanks for doing that @markdirish !

I pulled that branch and reran the code with a trace. I've attached both types of traces.

cwbtrace-64-node.exe-30460.log

SQL.LOG

Oh sorry for the confusion, I'm just interested in what it should spit out to the console. It should just print stuff out when you run node whatever.js

@markdirish Ah, gotcha. Here is what is coming from my console...

[
'CH', 'Y', 'FFGFA', '', '', 0, '',
'', '', '', 0, 0, '', '',
'', 0, '', 0, 0, '', '',
'', '', '', '', '', 'N', '',
'N', 0, '', '', 'N', '', '',
'', 0, 0, 0, 0, '', '',
'', 0, '', 0, '', 'N', '',
'', '', '', '', '', 'N', 0,
0, 'N', '', '', '', '', '',
'', '', '', '', '', '', '',
'', '', '', '', ''
]
2023-05-18 07:29:22.481 - info: SpData (813ms) Error
call WOR3070SP('CH', 'Y', 'FFGFA', '', '', 0, '', '', '', '', 0, 0, '', '', '', 0, '', 0, 0, '', '', '', '', '', '', '', 'N', '', 'N', 0, '', '', 'N', '', '', '', 0, 0, 0, 0, '', '', '', 0, '', 0, '', 'N', '', '', '', '', '', '', 'N', 0, 0, 'N', '', '', '', '', '', '', '', '', '', '', '', '', '', '', '', '', '')
requestId: 03a710e5-bb3a-47cc-84e4-3f41019f03e1
2023-05-18 07:29:23.235 - error: Benjamin J Ferguson (FERGB)
requestId: 797660e8-e591-4c0d-aa08-539e705d4eb5
2023-05-18 07:29:23.236 - error: DatabaseError: Error calling call WOR3070SP(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) with parameters field: readAction value: CH
field: ignoreWarning value: Y
field: workOrder value: FFGFA
field: groupWithWo value:
field: productType value:
field: customerNumber value: 0
field: OperatingUnder value:
field: workDescription value:
field: authorizedBy value:
field: department value:
field: dateInShop value: 0
field: estimatedOutDate value: 0
field: customerPo value:
field: aircraftRegIn value:
field: aircraftMake value:
field: makeHistoryId value: 0
field: aircraftModel value:
field: modelId value: 0
field: modelSeq value: 0
field: aircraftSerialNo value:
field: contactName value:
field: contactTitle value:
field: phone value:
field: contactCell value:
field: contactFax value:
field: contactEmail value:
field: hiddenDamageInspection value: N
field: rvsmStatusDesc value:
field: workOffsite value: N
field: paramQuoteId value: 0
field: paramPartNum value:
field: aircraftRegOut value:
field: preliminaryInspection value: N
field: departmentToReceiveCredit value:
field: creditReasonCode value:
field: cessnaUnitNo value:
field: departureDate value: 0
field: testFlightDate1 value: 0
field: testFlightDate2 value: 0
field: woCloseDate value: 0
field: netJetsWorkOrderNumber value:
field: lockedWorkOrder value:
field: shipInMethod value:
field: airportLocationId value: 0
field: location value:
field: cOfAValidityDate value: 0
field: workOrderType value:
field: prebuy value: N
field: aogExpediteFlag value:
field: taxStatus value:
field: wayBillNo value:
field: shipOutMethod value:
field: lockOverrideCode value:
field: discountOverideCode value:
field: miscSupplyCharges value: N
field: laborDiscountOveride value: 0
field: partsDiscountOveride value: 0
field: freightHandling value: N
field: rsshto value:
field: rsshnm value:
field: shipAddress1 value:
field: shipAddress2 value:
field: shipAddress3 value:
field: shipAddress4 value:
field: City value:
field: shipState value:
field: shipZip value:
field: custFreightAccountNbr value:
field: shippingCountryCode value:
field: restrictToDepartment value:
field: projectManagerEmployeeCode value:
field: unitMake value:
field: unitModel value:
field: creditAuthorizedBy value:
field: contractType value:

at OdbcConnection.processCall (C:\_rad\ts-server\src\connection\odbc-connection.ts:345:10)
at SpData.read (C:\_rad\ts-server\src\data\sp.data.ts:49:14)
at BenIndex.testSpDataTypes (C:\_rad\app\it-server\src\temp\ben\ben-index.ts:155:13)
at BenIndex.testConnector (C:\_rad\app\it-server\src\temp\ben\ben-index.ts:37:3)
at TestRouter.get (C:\_rad\app\it-server\src\temp\ben\ben-index.ts:171:3)
at Object.try (C:\_rad\ts-server\src\services\handlers\base-handler.ts:98:6)
at ServerUtils.handleTryAsync (C:\_rad\ts-base\src\utils\platform-utils.ts:161:12)
at ServerUtils.tryIgnoreAsync (C:\_rad\ts-base\src\utils\platform-utils.ts:131:11)

Caused By: Error: [odbc] The number of parameters the procedure expects and and the number of passed parameters is not equal

@snotmare you may need to recompile the program after you pulled down the branch:

npm run build

What I am expecting in the output is two lines that look like:

The number of columns is #
The number of parameters passed is #

You can check that they should fire (and that you have the right code) by looking in the src directory and looking for:
https://github.com/markdirish/node-odbc/blob/print-param-count/src/odbc_connection.cpp#L1396-L1397

If you try to build and it complains that you don't have the proper build tools, I can try to make you a prebuilt binary in a few hours when I get to a Windows system that has that all set up

@markdirish Man, I'm just not being very helpful, am I? Sorry about that. Here is the long-awaited info you are looking for!

The number of columns is 420
The number of parameters passed is 75

Good morning! Any luck on tracking down this issue?

Hi @snotmare ,

So I did track down what might be the issue. When SQLProcedureColumns is called, it appears our IBM i driver returns the values not based on the specific name, but on the normal procedure name. Let me illustrate with an example:

I have two procedures named MIRISH.MYPROC:

  1. The first has 2 parameters (IN, OUT), and has a specific name of MYPROC
  2. The second has 3 parameters (IN, OUT, OUT) and has a specific name of MYPRO00001

When I use this odbc library to call SQLProcedureColumns, with the values MIRISH for schema and MYPROC for procedure name, it says that there are 5 columns for that procedure.

When I call with values MIRISH and MYPRO00001, it says there are 0 columns for that procedure.

HOWEVER, I'm not even sure if this is your issue. In this reply #326 (comment), you said that it returned 75 for you. But somewhere it seems like it is finding additional columns for your WOR3070SP procedure. Could you double check that there aren't additional procedures with that name which might have additional columns?

In my case, it clearly is pulling off the procedure name, not the specific procedure name. I am going to discuss with @kadler what to do about it. I don't think I can just drop the check, as I need information about the columns to bind. In the case where it is returning more columns than it expects, there isn't a good programmatic way for me to grab the correct ones.

In the meantime, I think the only workaround is to ensure that all of your procedures have unique names.

@markdirish Based on what you found, I did some playing and found that if I specify the schema in my call, I can get this to work!

let results = await connection.callProcedure(null, 'DUNC', 'WOR3070SP', parameters);

Running this SQL...

SELECT count(*)
FROM SYSIBM.SQLPROCEDURECOLS
WHERE PROCEDURE_NAME = 'WOR3070SP'
and procedure_schem = 'DUNC'

...gives me 75 columns. Running this...

SELECT count(*)
FROM SYSIBM.SQLPROCEDURECOLS
WHERE PROCEDURE_NAME = 'WOR3070SP'

...gives me 420. This is because we have our prod version of the code running in DUNC while we have other versions of the code being tested in other schemas/libraries.

So, good news that we can get this to work. However, this will still be an issue for us because we don't want to hard code the schema in our procedure call. We would like to allow the system to find the correct procedure based on our library list. That way we can change the library list to include one of our test libraries and have our node code hit the test procedure.

Can you change the internal code to find the number of columns while accounting for the correct schema?

I'm also curious, do you have to query for sysprocedurecols every time we make a call, or is that information cached?

Hello! Thought I'd check in on this issue. Any luck resolving it?

Thanks

@snotmare I doubt your issue with a procedure being found in multiple schemas will be resolved in node-odbc. Instead I think you will have to run a query prior to calling the stored procedure to find the schema to use, that's what I decided to do in our project. You can get the routine_schema column from qsys2.sysprocs - join against qsys2.library_list_info and filter by parameter count then order by ordinal position.

@markdirish @kadler I have an idea to handle multiple procedures in the same schema - SQLProcedureColumns() also returns the ordinal position column which could be used to find the boundary between different versions of a procedure and select the right set of parameters.

@brandonp42 Hello! Has there been any progress on this issue?

Hi @snotmare, last I heard @markdirish and @kadler didn't like my proposal. Mark submitted a PR with an alternate fix a couple months ago which hasn't been merged yet. I don't know if they are still planning to work on that further or what's going on.