Fetching diagnostic records with iodbc and HFSQL

[bbigras]

Using the weird HFSQL database with iodbc.

The query seems to work when I'm using HFSQL's UI thing.

backtrace

#0  0x00007ffff7dc6bc7 in __pthread_kill_implementation () from /nix/store/fz54faknl123dimzz6jsppw193lx2mip-glibc-2.35-163/lib/libc.so.6
No symbol table info available.
#1  0x00007ffff7d79b46 in raise () from /nix/store/fz54faknl123dimzz6jsppw193lx2mip-glibc-2.35-163/lib/libc.so.6
No symbol table info available.
#2  0x00007ffff7d644b5 in abort () from /nix/store/fz54faknl123dimzz6jsppw193lx2mip-glibc-2.35-163/lib/libc.so.6
No symbol table info available.
#3  0x00007ffff7dbaa60 in __libc_message () from /nix/store/fz54faknl123dimzz6jsppw193lx2mip-glibc-2.35-163/lib/libc.so.6
No symbol table info available.
#4  0x00007ffff7dd0b9a in malloc_printerr () from /nix/store/fz54faknl123dimzz6jsppw193lx2mip-glibc-2.35-163/lib/libc.so.6
No symbol table info available.
#5  0x00007ffff7dd26ec in _int_free () from /nix/store/fz54faknl123dimzz6jsppw193lx2mip-glibc-2.35-163/lib/libc.so.6
No symbol table info available.
#6  0x00007ffff7dd5273 in free () from /nix/store/fz54faknl123dimzz6jsppw193lx2mip-glibc-2.35-163/lib/libc.so.6
No symbol table info available.
#7  0x00007ffff7f7f55a in SQLGetDiagRec_Internal () from /nix/store/1larqcdmwr5lyk38l7fvrakqa3lz14gr-libiodbc-3.52.15/lib/libiodbc.so.2
No symbol table info available.
#8  0x00007ffff7f7ff1e in SQLGetDiagRec () from /nix/store/1larqcdmwr5lyk38l7fvrakqa3lz14gr-libiodbc-3.52.15/lib/libiodbc.so.2
No symbol table info available.
#9  0x0000555555586e63 in odbc_api::handles::diagnostics::{impl#1}::diagnostic_record<odbc_api::handles::statement::StatementRef> (self=0x7fffffff3448, rec_number=1, message_text=&mut [u8](size=0))
    at src/handles/diagnostics.rs:186
        native_error = 0
        state = [0, 0, 0, 0, 0, 0]
        text_length = 1376
#10 0x0000555555586cdb in odbc_api::handles::diagnostics::Diagnostics::diagnostic_record_vec<odbc_api::handles::statement::StatementRef> (self=0x7fffffff3448, rec_number=1, message_text=0x7fffffff3280)
    at src/handles/diagnostics.rs:138
        cap = 0
#11 0x00005555555857bc in odbc_api::handles::diagnostics::Record::fill_from<odbc_api::handles::statement::StatementRef> (self=0x7fffffff3280, handle=0x7fffffff3448, record_number=1)
    at src/handles/diagnostics.rs:235
No locals.
#12 0x00005555555883d7 in odbc_api::handles::sql_result::SqlResult<bool>::into_result_with_trunaction_check<bool, odbc_api::handles::statement::StatementRef> (self=..., handle=0x7fffffff3448, 
    error_for_truncation=false) at src/error.rs:201
        record = odbc_api::handles::diagnostics::Record {state: odbc_api::handles::diagnostics::State ([0, 0, 0, 0, 0]), native_error: 0, message: Vec(size=0)}
        function = "SQLExecDirect"
#13 0x0000555555574a0d in odbc_api::handles::sql_result::SqlResult<bool>::into_result<bool, odbc_api::handles::statement::StatementRef> (self=..., handle=0x7fffffff3448)
    at /home/bbigras/.cargo/registry/src/github.com-1ecc6299db9ec823/odbc-api-0.49.0/src/error.rs:172
        error_for_truncation = false
#14 0x000055555556bd2b in odbc_api::execute::execute<odbc_api::handles::statement::StatementImpl> (statement=..., query=...)
    at /home/bbigras/.cargo/registry/src/github.com-1ecc6299db9ec823/odbc-api-0.49.0/src/execute.rs:97
        sql = 0x7fffffff3e20
        stmt = odbc_api::handles::statement::StatementRef {parent: core::marker::PhantomData<&*mut odbc_sys::Dbc>, handle: 0x5555556201e0}
#15 0x000055555556baa7 in odbc_api::execute::execute_with_parameters<odbc_api::handles::statement::StatementImpl, odbc_api::connection::{impl#1}::execute::{closure_env#0}<()>, ()> (lazy_statement=..., query=..., 
    params=()) at /home/bbigras/.cargo/registry/src/github.com-1ecc6299db9ec823/odbc-api-0.49.0/src/execute.rs:31
        statement = odbc_api::handles::statement::StatementImpl {parent: core::marker::PhantomData<&*mut odbc_sys::Dbc>, handle: 0x5555556201e0}
#16 0x0000555555567f4e in odbc_api::connection::Connection::execute<()> (self=0x7fffffff4788, query="SELECT 1;", params=())
    at /home/bbigras/.cargo/registry/src/github.com-1ecc6299db9ec823/odbc-api-0.49.0/src/connection.rs:115
        lazy_statement = odbc_api::connection::{impl#1}::execute::{closure_env#0}<()> {self: 0x7fffffff4788}
        query = odbc_api::handles::sql_char::SqlText {text: "SELECT 1;"}

odbc-api = { version = "0.49.0", features = [ "iodbc" ] }

Note that will the old odbc crate I get:

thread 'tokio-runtime-worker' panicked at 'called `Result::unwrap()` on an `Err` value: FromBytesWithNulError { kind: InteriorNul(4) }', /home/bbigras/.cargo/registry/src/github.com-1ecc6299db9ec823/odbc-0.16.1/src/diagnostics.rs:55:60

[pacman82]

It seems to get an error executing the statement and getting an invalid free than trying to fetch the error message.

I actually would be suprised if iodbc would be thread safe. The pthread in the stack worries me a bit. If you use odbc-api directly you'll find that you have to write unsafe code in order to make Connections Send. That means you have to use connections on the same thread you create them.

I know from the other thread that you use a connection pool library which hides that unsafe code behind a safe function call, but it doesn't actually do anything to make it safe (nor can it, if the underlying C-Lirbrary is not thread safe).

As you might be able to imagine I would have a hard time reproducing your error. Best I can do is provide a couple of guesses.

First thing I would try is to have a really simple program outside of any server implementation just executing this one query. No multithreading, no fancy connection pooling and see if that works.

Best, Markus

[bbigras]

Oh for this case I didn't use r2d2.

My code is this:

[dependencies]
anyhow = "1.0.65"
dotenv = "0.15.0"
odbc-api = { version = "0.49.0", features = [ "iodbc" ] }

use anyhow::{Context, Error};
use dotenv::dotenv;
use odbc_api::{buffers::TextRowSet, Cursor, Environment, ResultSetMetadata};
use std::{
    env,
    ffi::CStr,
    io::{stdout, Write},
    path::PathBuf,
};

const BATCH_SIZE: usize = 5000;

fn main() -> Result<(), Error> {
    dotenv().ok();

    let conn_str = env::var("SQL_STR").unwrap();

    let environment = Environment::new()?;
    let mut connection = environment.connect_with_connection_string(&conn_str)?;

    match connection.execute("SELECT 1;", ())? {
        Some(mut cursor) => {
            println!("ok!");
        }
        None => {
            eprintln!("Query came back empty. No output has been created.");
        }
    }

    Ok(())
}

I also tested other queries:

• SELECT CURRENT_DATE FROM DUAL; OK
• SELECT TO_CHAR(12,'RN') free(): invalid pointer

@genusistimelord suggested that it "it must not like selects without From".

[pacman82]

Okay interessting. Yeah, there might be something it doesn't like about these SELECTs. The issue from my point of view is not that these fail, but that you get an error when diagnostics are fetched.

[pacman82]

To clarify, in case an error occurrs odbc-api goes on and uses ODBC C-API to get an error message from the datasource. E.g. a message explaining a syntax error, or similar stuff. This seems to be the call causing the invalid free.

Stuff that is currently beyond my understanding:

• Why do we get an invalid free? The ODBC function SQLGetDiagRec (get diagnostic record) should just fill a buffer. Not delete anything. The implementation may do whatever it wants to (obviously).
• How does pthread sneak into the call stack, if it is supposed to be a stupid single threaded program?

I feel the first point may hold more relevance though.

[genusistimelord]

yeah in this case connection is only on a single thread to begin with so multi threading should not cause any issues here. I wounder if the error from hfsql is different from those in other SQL so it doesn't know how to parse it. which it fails and then tries to call Free on memory that doesn't exist due to the failure.

[bbigras]

Could this happen if my database's charset is latin1?

If I run SELECT 1; with the old odbc-rs, I get a FromBytesWithNulError but with gdb I can see this error message:
"Erreur dans le code SQL de la requ"

Which means that there's an error in the SQL query. The next character should be "ê" so maybe there's an encoding problem there.

I wonder if it could be similar with odbc-api.

[genusistimelord]

ahh yeah it might be having a hard time since the string doesn't have a nul terminator?

[bbigras]

ahh yeah it might be having a hard time since the string doesn't have a nul terminator?

not sure.

but with odbc-api, I just found something.

If I add message_text.resize(1024, 0); at the start of diagnostic_record_vec(), I don't get the free error anymore, I get:

EDIT: with the full error.

Error: ODBC emitted an error calling 'SQLExecDirect':
State: 0100, Native error: 0, Message: Erreur dans le code SQL de la requ?te <Requete_HyperFile612242256>. Initialisation de la requ?te impossible.
Fichier ###DUAL0### inconnu
Erreur d?tect?e :
FROM >>>>"###DUAL0###"<<<< 

Informations de d?bogage :
IEWD230SQL=1.12
Module=<WD230SQL>
Version=<23.0.18.0>


Code SQL de la requ?te :
SELECT  2 AS Expr1 
FROM "###DUAL0###"

I tried this because I was wondering if it could be related to null_mut. maybe my driver doesn't like it.

odbc-api/odbc-api/src/handles/buffer.rs

Lines 13 to 19 in c37869f

	pub fn mut_buf_ptr<T>(buffer: &mut [T]) -> *mut T {
	if buffer.is_empty() {
	null_mut()
	} else {
	buffer.as_mut_ptr()
	}
	}

[pacman82]

Hello together,

sorry for the delayed response. I am a bit swamped this week, and I did not have internet on my train rides recently.

@bbigras Thanks for taking a closer look at it. It might be helpful to know, that at least for the first diagnostic message associated with an error, odbc-api tends to call the underlying SQLGetDiagRec twice. The first time it is with an empty buffer, just to retrieve the minimal buffer length, which might be able to hold the entire text message. On the second call it would try to receive the same message with an adequatly sized buffer. This leads me to hypothesize that the ODBC driver in question may remove that message after the first fetch, and in the second fetch might try to remove it again (retrieving diagnostic messages actually should not change state, so this is likely a bug). To verify, what would happen if you only call it with a buffer of size 10 instead of 1024?

@genusistimelord You are not wrong either. You identified the reason why the replacement character shows instead of the é in requests. Usually odbc-api does avoid this kind of problems by specifying to using wide characters by default. According to the standard these must always be UTF-16 encoded. The narrow encoding is according the spec decided by the system locale, yet many impelementation just always return UTF-8. So the idea is to enable the narrow feature only on modern platforms there the character encoding is set as UTF-8. However, either the iodbc driver manager seems to be unable to handle the wide encoding (it allocates the state buffer of the wrong size among other things). So the iodbc feature implies using narrow encoding. I would advice switching the system locale to an UTF-8 character encoding, to solve this part of the problem.

I won't be able to do much this week, please do not mistake my inactivity for me being unsympathetic to your problem.

Cheers, Markus

[bbigras]

With size 10, I get:

Error: ODBC emitted an error calling 'SQLExecDirect':
State: 0, Native error: 0, Message: E

I won't be able to do much this week, please do not mistake my inactivity for me being unsympathetic to your problem.

Thanks, I appreciate your replies, but no hurries at all. This issue doesn't block me at all.

Btw, we probably can rename this issue as SELECT 1 seems to just be not supported with HFSQL, and the issue seems rather to be related to SQLGetDiagRec.

[pacman82]

odbc-api 0.50.0 is released. Then first fetching diagnostics it uses a buffer of size 512. It seems that fetching with a buffer of size 0 is what causes the HFSQL driver to remove the message (guessing here). So this may workaround the issue. However any true fix must be happening within HFSQL.

The other issue that came up, is the confusion of encodings. Any encoding other than UTF-8 or UTF-16 is not supported by the higher level of abstractions of this crate. If you care about decoding the diagonstics correctly and can not change the system locale you must fall back the functionality provided by the handles submodule.

Best, Markus

[genusistimelord]

thank you Markus.

[pacman82]

You are welcome