Question Re: Ruby API returns different result based on same SQL but prepared vs execute_direct in Technology Q&A

Ruby API returns different result based on same SQL but prepared vs execute_direct

kbachl — Thu, 09 May 2024 09:43:31 GMT

Hi,

following code:

sql = <<-END_SQL select count("ItemCode") from "TEST2024"."OITM" where "ItemCode" = ? END_SQL p item_code # this won't work, allways returns [0,0]! stmt = @@api.hanaclient_prepare @@connection, sql _, param = @@api.hanaclient_describe_bind_param(stmt, 0) param.set_value(item_code) @@api.hanaclient_bind_param(stmt, 0, param) _rc = @@api.hanaclient_execute(stmt) @@api.hanaclient_fetch_next( stmt ) puts "R1: " + @@api.hanaclient_get_column(stmt, 0).to_s @@api.hanaclient_free_stmt(stmt) #This works -> correct results returned: sql = ActiveRecord::Base.sanitize_sql([sql, item_code]) stmt = @@api.hanaclient_execute_direct(@@connection, sql) @@api.hanaclient_fetch_next( stmt ) puts "R2: " + @@api.hanaclient_get_column(stmt, 0).to_s

whatever I try I allways get a return of array [0,0] in case of my prepared statement compared to the direct executed one that returns the correct and expected data.

Result:

Im using the latest driver 20.20.20. Any idea what I made wrong in my prepared statement?

Re: Ruby API returns different result based on same SQL but prepared vs execute_direct

jeff_albion — Thu, 16 May 2024 18:25:27 GMT

Hello,

I can't seem to reproduce this behaviour with a simplified example:

require 'hanaclient' include HANACLIENT @@api = HANACLIENT::HANACLIENTInterface.new() HANACLIENT::API.hanaclient_initialize_interface(@@api) @@api.hanaclient_init() @@conn = @@api.hanaclient_new_connection() @@api.hanaclient_connect(@@conn, "servernode=myserver:30015;UID=myuser;PWD=mypwd") sql = <<-END_SQL select 42 from "SYS"."DUMMY" where 1 = ? END_SQL item_code = 1 stmt = @@api.hanaclient_prepare @@conn, sql _, param = @@api.hanaclient_describe_bind_param(stmt, 0) param.set_value(item_code) @@api.hanaclient_bind_param(stmt, 0, param) _rc = @@api.hanaclient_execute(stmt) @@api.hanaclient_fetch_next( stmt ) puts "R1: " + @@api.hanaclient_get_column(stmt, 0).to_s @@api.hanaclient_free_stmt(stmt) @@api.hanaclient_disconnect(@@conn) @@api.hanaclient_free_connection(@@conn) @@api.hanaclient_fini() HANACLIENT::API.hanaclient_finalize_interface(@@api)

Can you also run my example and see the correct value?

From your example, are you sure that the value being bound is being found correctly in the table? Have you tried adding SQLDBC Tracing

to your application to better understand what's happening inside the driver for the bind value and result? You can quickly set environment variables to trace to stdout if that's helpful:

export HDB_SQLDBC_TRACEFILE=stdout export HDB_SQLDBC_TRACEOPTS=SQL,DEBUG,FLUSH

Best regards,

Jeff

Re: Ruby API returns different result based on same SQL b...

kbachl — Fri, 17 May 2024 08:28:19 GMT

@jeff_albionThanks for trying to help.

I tried your example and it worked as long as the type was integer. As soon as I changed the SQL to use would use String it broke, see:

... sql = <<-END_SQL select 42 from "SYS"."DUMMY" where 'TestValue' = ? END_SQL item_code = 'TestValue' stmt = @@api.hanaclient_prepare @@connection, sql _, param = @@api.hanaclient_describe_bind_param(stmt, 0) param.set_value(item_code) @@api.hanaclient_bind_param(stmt, 0, param) _rc = @@api.hanaclient_execute(stmt) @@api.hanaclient_fetch_next( stmt ) puts "R1: " + @@api.hanaclient_get_column(stmt, 0).to_s @@api.hanaclient_free_stmt(stmt) ...

Here it still should work as 'TestValue' = 'TestValue' would be true, yet it gets not result back:

10:13:01 web.1 | [SQLDBC] SQL COMMAND : select 42 from "SYS"."DUMMY" where 'TestValue' = ? 10:13:01 web.1 | 10:13:01 web.1 | [SQLDBC] ENCODING : UTF8 10:13:01 web.1 | [SQLDBC] >Connection::getClientInfo (2024-05-17 10:13:01.192786) 10:13:01 web.1 | [SQLDBC] <=0x00007e6270061cb8 10:13:01 web.1 | [SQLDBC] >PreparedStatement::resetParametersProcessed (2024-05-17 10:13:01.192788) 10:13:01 web.1 | [SQLDBC] < 10:13:01 web.1 | [SQLDBC] >ParseInfo::selectPhysicalConnection (2024-05-17 10:13:01.192791) 10:13:01 web.1 | [SQLDBC] >Connection::selectPhysicalConnection (2024-05-17 10:13:01.192795) 10:13:01 web.1 | [SQLDBC] locationIndex=4294967295 10:13:01 web.1 | [SQLDBC] isUpdateCommand=0 10:13:01 web.1 | [SQLDBC] >Connection::getPrimaryConnection (2024-05-17 10:13:01.192798) 10:13:01 web.1 | [SQLDBC] <=1 10:13:01 web.1 | [SQLDBC] <=1 10:13:01 web.1 | [SQLDBC] <=1 10:13:01 web.1 | [SQLDBC] >PreparedStatement::resetResults (2024-05-17 10:13:01.192803) 10:13:01 web.1 | [SQLDBC] >Statement::resetResults (2024-05-17 10:13:01.192804) 10:13:01 web.1 | [SQLDBC] clearResultSet=1 10:13:01 web.1 | [SQLDBC] >Connection::getWorkloadReplayContext (2024-05-17 10:13:01.192807) 10:13:01 web.1 | [SQLDBC] m_workloadReplayContext= 10:13:01 web.1 | [SQLDBC] < 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] STATEMENTID : STATEMENT[C22CE9B2325B0500(1507648191671490):1] 10:13:01 web.1 | [SQLDBC] INPUT PARAMETERS 10:13:01 web.1 | [SQLDBC] APPLICATION 10:13:01 web.1 | [SQLDBC] INDEX TYPE AT LENGTH INDICATOR DATA 10:13:01 web.1 | [SQLDBC] >PreparedStatement::checkInitParameters (2024-05-17 10:13:01.192815) 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] >Connection::getRequestPacket (2024-05-17 10:13:01.192818) 10:13:01 web.1 | [SQLDBC] packetsize=0 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] >RequestPacket::addSegment (2024-05-17 10:13:01.192821) 10:13:01 web.1 | [SQLDBC] < 10:13:01 web.1 | [SQLDBC] >RoutingInfo::addRoutingInfoPart (2024-05-17 10:13:01.192829) 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] >PreparedStatement::executeFillDirectData (2024-05-17 10:13:01.192833) 10:13:01 web.1 | [SQLDBC] haslobs=0 10:13:01 web.1 | [SQLDBC] startindex=1 10:13:01 web.1 | [SQLDBC] >Translator::translateInput (2024-05-17 10:13:01.192836) 10:13:01 web.1 | [SQLDBC] arrayoffset=0 10:13:01 web.1 | [SQLDBC] rowsize=0 10:13:01 web.1 | [SQLDBC] >StringTranslator::translateUTF8Input (2024-05-17 10:13:01.192845) 10:13:01 web.1 | [SQLDBC] data= 10:13:01 web.1 | [SQLDBC] >GenericTranslator::addCharacterData (2024-05-17 10:13:01.192855) 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] 1 UTF8 0 0 '' 10:13:01 web.1 | [SQLDBC] 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] >Connection::sqlaexecute_clientconnection (2024-05-17 10:13:01.192873) 10:13:01 web.1 | [SQLDBC] >Connection::updateStatementContextInRequest (2024-05-17 10:13:01.192875) 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] PHYSICAL CONNECTION - [0x00007e62700654c0] [CONNECTED - COORDINATOR] 10:13:01 web.1 | [SQLDBC] CONNECTED AT : 2024-05-17 10:13:01.009213 10:13:01 web.1 | [SQLDBC] LOCATION : 192.168.*.*:30015 [192.168.*.*] 10:13:01 web.1 | [SQLDBC] SERVER CONNECTION ID: 351026 10:13:01 web.1 | [SQLDBC] CLIENT CONNECTION ID: 1 10:13:01 web.1 | [SQLDBC] VOLUME ID : 3 10:13:01 web.1 | [SQLDBC] SESSION ID : 1647312013039303 10:13:01 web.1 | [SQLDBC] LAST SEND TIME : 2024-05-17 10:13:01.141457 10:13:01 web.1 | [SQLDBC] LAST RECEIVE TIME : 2024-05-17 10:13:01.192421 10:13:01 web.1 | [SQLDBC] CONNECTION OBJECT : [0x00007e6270061950] 10:13:01 web.1 | [SQLDBC] >SimpleClientSocket::doPollBeforeSendToDetectSocketDead (2024-05-17 10:13:01.192891) 10:13:01 web.1 | [SQLDBC] < 10:13:01 web.1 | [SQLDBC] SEND TIME: 151 USEC, MESSAGE: EXECUTE 10:13:01 web.1 | [SQLDBC] >SocketCommunication::receive (2024-05-17 10:13:01.193060) 10:13:01 web.1 | [SQLDBC] < 10:13:01 web.1 | [SQLDBC] RECV TIME: 48413 USEC 10:13:01 web.1 | [SQLDBC] >Connection::doProcessReply (2024-05-17 10:13:01.241524) 10:13:01 web.1 | [SQLDBC] >ReplySegment::getSQLDiag (2024-05-17 10:13:01.241528) 10:13:01 web.1 | [SQLDBC] <=false 10:13:01 web.1 | [SQLDBC] >Connection::updateTopology (2024-05-17 10:13:01.241532) 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] >Connection::updateSessionVariableCache (2024-05-17 10:13:01.241535) 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] >Connection::processImplicitXASession (2024-05-17 10:13:01.241540) 10:13:01 web.1 | [SQLDBC] requestMessageType=EXECUTE 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] >Connection::updateTransactionStatus (2024-05-17 10:13:01.241544) 10:13:01 web.1 | [SQLDBC] connectionId=1 10:13:01 web.1 | [SQLDBC] action=TA_READTRANS 10:13:01 web.1 | [SQLDBC] TRANSACTION ACTION TA_READTRANS 10:13:01 web.1 | [SQLDBC] TRANSACTION: 10:13:01 web.1 | [SQLDBC] STATE: READ TRANSACTION 10:13:01 web.1 | [SQLDBC] PRIMARY: 1 10:13:01 web.1 | [SQLDBC] TRANSACTION MEMBERS (READ): [1] 10:13:01 web.1 | [SQLDBC] TRANSACTION MEMBERS (WRITE): [] 10:13:01 web.1 | [SQLDBC] TRANSACTION MEMBERS (WRITE CANDIDATE): [] 10:13:01 web.1 | [SQLDBC] TRANSACTION MEMBERS (WRITE TXN AS OF LAST REPLY) : [] 10:13:01 web.1 | [SQLDBC] HINT ROUTED CONNECTIONS: [] 10:13:01 web.1 | [SQLDBC] TRANSACTION UPDATED: 10:13:01 web.1 | [SQLDBC] TRANSACTION: 10:13:01 web.1 | [SQLDBC] STATE: READ TRANSACTION 10:13:01 web.1 | [SQLDBC] PRIMARY: 1 10:13:01 web.1 | [SQLDBC] TRANSACTION MEMBERS (READ): [1] 10:13:01 web.1 | [SQLDBC] TRANSACTION MEMBERS (WRITE): [] 10:13:01 web.1 | [SQLDBC] TRANSACTION MEMBERS (WRITE CANDIDATE): [] 10:13:01 web.1 | [SQLDBC] TRANSACTION MEMBERS (WRITE TXN AS OF LAST REPLY) : [] 10:13:01 web.1 | [SQLDBC] HINT ROUTED CONNECTIONS: [] 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] >Connection::updateStatementContextFromReply (2024-05-17 10:13:01.241559) 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] SERVER STATISTICS UPDATE OF [0x00007e627006a3a0] 10:13:01 web.1 | [SQLDBC] PROCESSING TIME INCREASED TO 170 BY 170 USEC 10:13:01 web.1 | [SQLDBC] CPU TIME INCREASED TO 99 BY 99 USEC 10:13:01 web.1 | [SQLDBC] PEAK MEMORY USAGE INCREASED TO 0 BY 0 BYTES 10:13:01 web.1 | [SQLDBC] >Statement::parseResult (2024-05-17 10:13:01.241573) 10:13:01 web.1 | [SQLDBC] >Connection::getWorkloadReplayContext (2024-05-17 10:13:01.241575) 10:13:01 web.1 | [SQLDBC] m_workloadReplayContext= 10:13:01 web.1 | [SQLDBC] < 10:13:01 web.1 | [SQLDBC] RESULTSET ID:RESULT[C22CE9B2325B0500:1] 10:13:01 web.1 | [SQLDBC] parseResult parsing ResultSet 10:13:01 web.1 | [SQLDBC] *** ROW NOT FOUND ***

So we end up in a SegFault if I try to access a non existing Row that should be here:

10:13:01 web.1 | [SQLDBC] ::FETCH NEXT SQLCURS_1 RESULT[C22CE9B2325B0500:1] [0x00007e627006bbb0] 2024-05-17 10:13:01.241744 10:13:01 web.1 | [SQLDBC] >ResultSet::assertNotClosed (2024-05-17 10:13:01.241745) 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] >ResultSet::executeFetchNext (2024-05-17 10:13:01.241747) 10:13:01 web.1 | [SQLDBC] >ResultSet::assertValid (2024-05-17 10:13:01.241748) 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] <=SQLDBC_NO_DATA_FOUND 10:13:01 web.1 | [SQLDBC] <=SQLDBC_NO_DATA_FOUND 10:13:01 web.1 | [SQLDBC] >ResultSet::getResultCount (2024-05-17 10:13:01.241751) 10:13:01 web.1 | [SQLDBC] 10:13:01 web.1 | [SQLDBC] ::GET RESULT COUNT SQLCURS_1 RESULT[C22CE9B2325B0500:1] [0x00007e627006bbb0] 10:13:01 web.1 | [SQLDBC] COUNT:0 10:13:01 web.1 | [SQLDBC] >ResultSet::assertValid (2024-05-17 10:13:01.241753) 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] <=0 10:13:01 web.1 | [SQLDBC] >ConnectionItem::applicationCheckWarnings (2024-05-17 10:13:01.241756) 10:13:01 web.1 | [SQLDBC] ::APPLICATION CHECKING WARNINGS ON CONNECTIONITEM [0x00007e627006bbb0] 10:13:01 web.1 | [SQLDBC] m_diag.warns= 10:13:01 web.1 | [SQLDBC] < 10:13:01 web.1 | [SQLDBC] >ConnectionItem::applicationCheckError (2024-05-17 10:13:01.241761) 10:13:01 web.1 | [SQLDBC] ::APPLICATION CHECKING ERROR ON CONNECTIONITEM [0x00007e627006bbb0] 10:13:01 web.1 | [SQLDBC] m_diag.errs= 10:13:01 web.1 | [SQLDBC] < 10:13:01 web.1 | /...REDACTED.../hana/hana_query.rb:100: [BUG] Segmentation fault at 0x0000000000000010 10:13:01 web.1 | ruby 3.3.1 (2024-04-23 revision c56cd86388) [x86_64-linux]

And its libSQLDBCHDB 2.20.20.1712178305 version exactly.

Re: Ruby API returns different result based on same SQL but prepared vs execute_direct

kbachl — Fri, 17 May 2024 08:29:11 GMT

I made an "Answer" below - seems I cant directly reply to you

Re: Ruby API returns different result based on same SQL but prepared vs execute_direct

jeff_albion — Fri, 17 May 2024 20:29:07 GMT

Hi @kbachl, thanks for trying the updated instructions. I can see from your trace that the string value isn't bound properly from the ruby level:

10:13:01 web.1 | [SQLDBC] >StringTranslator::translateUTF8Input (2024-05-17 10:13:01.192845) 10:13:01 web.1 | [SQLDBC] data= 10:13:01 web.1 | [SQLDBC] >GenericTranslator::addCharacterData (2024-05-17 10:13:01.192855) 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] <=SQLDBC_OK 10:13:01 web.1 | [SQLDBC] 1 UTF8 0 0 ''

I had been originally trying Ruby 2.7, but couldn't reproduce the problem:

[SQLDBC] >GenericTranslator::addCharacterData (2024-05-17 16:21:08.715159) [SQLDBC] <=SQLDBC_OK [SQLDBC] <=SQLDBC_OK [SQLDBC] <=SQLDBC_OK [SQLDBC] 1 UTF8 9 9 'TestValue'

ruby 2.7.6p219 (2022-04-12 revision c9c2245c0a) [x86_64-linux]

After I upgraded to the latest Ruby 3.3, I could then reproduce the problem as you described:

ruby 3.3.1 (2024-04-23 revision c56cd86388) [x86_64-linux]

[SQLDBC] >GenericTranslator::addCharacterData (2024-05-17 16:13:54.026311) [SQLDBC] <=SQLDBC_OK [SQLDBC] <=SQLDBC_OK [SQLDBC] <=SQLDBC_OK [SQLDBC] 1 UTF8 0 0 ''

I am also noticing these ruby messages in Ruby 3.3:

simple.rb:7: warning: undefining the allocator of T_DATA class DBCAPI::a_hanaclient_connection simple.rb:14: warning: undefining the allocator of T_DATA class DBCAPI::a_hanaclient_stmt simple.rb:15: warning: undefining the allocator of T_DATA class DBCAPI::a_hanaclient_bind_data

So it seems like there's a bug with newer Ruby versions here - I have opened an internal bug report to investigate further.

Can you try an older version of Ruby for now?

Note that the official Supported Platforms page only lists up to Ruby 2.7 currently: https://me.sap.com/notes/3447024

Best regards,

Jeff

Re: Ruby API returns different result based on same SQL b...

kbachl — Fri, 17 May 2024 21:00:42 GMT

@jeff_albionThanks for the update!

I hardly can go on to ruby 2.7 as I'm doing a current new rails project and ruby 3.1.0 is the new baseline for upcoming rails 7.2, me using ruby 3.3.1.
Beside ruby 2.7 is EOL since 2023-03-31. Since I only need this on some rare occasions (when the SAP B1 ServiceLayer is too slow or can't deliver the complexity of a query well enough) I can go forward with using this with the direct SQL way of using ActiveRecord's base

 sql = ActiveRecord::Base.sanitize_sql([sql, item_code])

for the time. Yet, it would also be nice if you could do a bug report that an access to a non existing row or column dont lead to a SegFault like in my last post as this is quite annoying in development 🙂