ASTERISK-22459: Compiling res_odbc against iODBC instead of unixodbc produces runtime errors

[Home]

Summary: ASTERISK-22459: Compiling res_odbc against iODBC instead of unixodbc produces runtime errors

Reporter: Patrick Maille (patrickm) Labels:

Date Opened: 2013-09-04 15:10:04 Date Closed: 2013-10-08 17:30:01

Priority: Major Regression?

Status: Closed/Complete Components: Resources/res_odbc

Versions: 11.5.1 Frequency of
Occurrence

Related
Issues:

Environment: Debian linux (squeeze), ODBC/MysQL Attachments: ( 0) extrafull
( 1) issueA22459_warn_when_using_iodbc.patch

Description: When I set (in res_odbc.conf):
username=>asterisk

the mysql logs show:
130904 15:51:30 57 Connect Access denied for user 'a'@'localhost' (using password: YES)

If I set (in res_odbc.conf):
username=>debian

the mysql logs show:
130904 15:52:30 63 Connect Access denied for user 'd'@'localhost' (using password: YES)

So it looks like it's only taking the first letter of the username for authentication to the database.

I confirmed that my odbc/mysql stack works:

$ echo "select 1" | isql -v asterisk-connector asterisk Test1234
+---------------------------------------+
| Connected! |
| |
| sql-statement |
| help [tablename] |
| quit |
| |
+---------------------------------------+
SQL> select 1
+---------------------+
| 1 |
+---------------------+
| 1 |
+---------------------+
SQLRowCount returns 1
1 rows fetched

Comments: By: Michael L. Young (elguero) 2013-09-04 21:15:09.471-0500

This is interesting since, I am currently using res_odbc.conf (mysql) without any issues parsing the username.

Can you post your full res_odbc.conf file (sanitized)?

A complete debug log may help triage the issue. This document will provide instructions on how to collect debugging logs from an Asterisk machine for the purpose of helping bug marshals troubleshoot an issue: https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information

Thanks

By: Patrick Maille (patrickm) 2013-09-05 08:00:38.518-0500

Here is the full res_odbc.conf:
{noformat}
[asterisk]
enabled=>yes
dsn=>asterisk-connector
password=>Test1234
username=>asterisk
pre-connect=>yes
;;pooling=>no
;sanitysql => select 1
;idlecheck => 3600
;share_connections => no
;limit => 1
;forcecommit => no
;isolation => repeatable_read
;backslash_is_escape => yes
;connect_timeout => 10
;negative_connection_cache => 300
;Threading=2
{noformat}

I also tried with polling=>no and limit=>1

By: Richard Mudgett (rmudgett) 2013-09-05 11:13:40.633-0500

I took a quick look at the res_odbc.c code last night. The code is dealing with the username as a string. I did not find any code that would truncate the username string. I did see the code passing the username string to the database connect call. It may be a problem in the database library itself.
By: Patrick Maille (patrickm) 2013-09-05 13:06:09.994-0500

Ok, I guess it's possible. I'm using the following packages:

dpkg -l | grep -i odbc
ii libiodbc2 3.52.6-4 iODBC Driver Manager
ii libiodbc2-dev 3.52.6-4 iODBC Driver Manager (development files)
ii libmyodbc 5.1.6-1 the MySQL ODBC driver
ii odbcinst 2.2.14p2-1 Helper program for accessing odbc ini files
ii odbcinst1debian2 2.2.14p2-1 Support library for accessing odbc ini files
ii unixodbc 2.2.14p2-1 ODBC tools libraries

Are you using any different packages/versions by any chance ?

Also, just for testing I actually created a user 'a'@'localhost' in mysql just to see if the connection would work .... and it doesn't .. so I assume that the same issue is happening for the password.
By: Walter Doekes (wdoekes) 2013-09-06 05:15:57.863-0500

Could someone be passing wide characters? 'a\0\0\0s\0\0\0t\0\0\0...'

What are your (sanitized) odbc.ini and odbcinst.ini ?

Try to enable tracing in odbc.ini/odbcinst.ini.
{noformat}
# To enable unixODBC tracing, add this section to odbcinst.ini.
# Include the [ODBC] section heading.
[ODBC]
Trace = yes
TraceFile = /tmp/mytrace.txt
{noformat}

By: Patrick Maille (patrickm) 2013-09-06 08:13:14.877-0500

Here is my odbcinst.ini:
{noformat}
[MySQL]
Description = ODBC for MySQL
Driver = /usr/lib64/odbc/libmyodbc.so
Setup = /usr/lib64/odbc/libodbcmyS.so
FileUsage = 1
{noformat}

Here is my odbc.ini:
{noformat}
[asterisk-connector]
Description= MySQL connection to asterisk database
Driver= MySQL
Database=asterisk
Server=localhost
UserName=asterisk
Password=Test1234
Port=3306
Socket=/var/run/mysqld/mysqld.sock
{noformat}

I'll try and add the ODBC section and trace.
By: Patrick Maille (patrickm) 2013-09-06 08:24:38.306-0500

I added ODBC trace, but when I start asterisk, nothing shows up in the trace file.

The asterisk logs show:
{noformat}
grep -i warning /var/log/asterisk/extrafull
[Sep 6 09:19:59] WARNING[1512] res_odbc.c: res_odbc: Error SQLConnect=-1 errno=1045 ��.��
[Sep 6 09:19:59] WARNING[1512] res_odbc.c: Failed to connect to asterisk
[Sep 6 09:19:59] WARNING[1512] res_odbc.c: res_odbc: Error SQLConnect=-1 errno=1045 ��.��
[Sep 6 09:19:59] WARNING[1512] res_odbc.c: Failed to connect to asterisk
[Sep 6 09:19:59] WARNING[1512] res_odbc.c: res_odbc: Error SQLConnect=-1 errno=1045 ��.��
[Sep 6 09:19:59] WARNING[1512] res_odbc.c: Failed to connect to asterisk
[Sep 6 09:19:59] WARNING[1512] res_odbc.c: Unable to retrieve database handle for table description 'sip@asterisk'
[Sep 6 09:19:59] WARNING[1532] res_odbc.c: res_odbc: Error SQLConnect=-1 errno=1045 ��.��
[Sep 6 09:19:59] WARNING[1532] res_odbc.c: Failed to connect to asterisk
[Sep 6 09:19:59] WARNING[1532] res_odbc.c: Unable to retrieve database handle for table description 'sip@asterisk'
[Sep 6 09:19:59] WARNING[1532] res_odbc.c: res_odbc: Error SQLConnect=-1 errno=1045 ��.��
[Sep 6 09:19:59] WARNING[1532] res_odbc.c: Failed to connect to asterisk
[Sep 6 09:19:59] WARNING[1512] res_odbc.c: res_odbc: Error SQLConnect=-1 errno=1045 ��.��
[Sep 6 09:19:59] WARNING[1512] res_odbc.c: Failed to connect to asterisk
[Sep 6 09:19:59] WARNING[1512] res_odbc.c: Unable to retrieve database handle for table description 'voicemail@asterisk'
{noformat}
If I use the isql tool to test, the test query (select 1) works and I get an odbc trace file.
By: Rusty Newton (rnewton) 2013-09-10 16:25:00.809-0500

Patrick, can you verify that the Asterisk logs you posted had VERBOSE and DEBUG message types enabled in logger.conf? I felt like there should be some DEBUG type messages there as well..

A good way to check while Asterisk is running is the "logger show channels" command, as checking the logger.conf file won't tell you the current state.

It'd be helpful if you just attached the completely log file from startup of Asterisk if possible.

Please attach files to the issue in .txt format and link to them from the comment.
By: Patrick Maille (patrickm) 2013-09-11 09:00:25.911-0500

Sanitized asterisk log file. I only removed the thousands of extensions being loaded to reduce file size.

Channel Type Status Configuration
------- ---- ------ -------------
/var/log/asterisk/extrafull File Enabled - DEBUG ---EVENT--- NOTICE WARNING ERROR VERBOSE DTMF CC
/var/log/asterisk/messages File Enabled - NOTICE WARNING ERROR
Console Enabled - NOTICE WARNING ERROR

By: Patrick Maille (patrickm) 2013-09-11 10:53:35.637-0500

New log file with debug on. By default debug=0 in asterisk.conf. Changed to debug=10.
By: Walter Doekes (wdoekes) 2013-09-11 11:15:23.581-0500

Unfortunately that doesn't help much.

We see only this:

{noformat}
res_odbc.c: res_odbc: Error SQLConnect=-1 errno=1045 <B0><FB>ǫ:^?
res_odbc.c: Failed to connect to asterisk
{noformat}

Over here, that looks like this:
{noformat}
res_odbc.c: res_odbc: Error SQLConnect=-1 errno=1045 [unixODBC][MySQL][ODBC 5.1 Driver]Access denied for user 'baduser'@'localhost' (using passwor
res_odbc.c: Failed to connect to asterisk
{noformat}

The {{msg}} is filled with 100 bytes of error description by {{SQLGetDiagRec(SQL_HANDLE_DBC, con, 1, state, &err, msg, 100, &mlen);}}, in your case it's uninitialized. Which is strange by itself.

What does that {{libiodbc2}} lib do? Do you need it?

I've got this:
{noformat}
$ dpkg -l | grep odbc | awk '{print $2 " " $3}'
libmyodbc 5.1.6-1
odbcinst 2.2.14p2-1
odbcinst1debian2 2.2.14p2-1
{noformat}
(.. and a locally compiled unixodbc-2.2.14p2)
By: Walter Doekes (wdoekes) 2013-09-11 11:19:16.455-0500

How about if you replace:
{noformat}
UserName=asterisk
{noformat}
with:
{noformat}
User=asterisk
{noformat}

(.. and remove the {{username=>}} from res_odbc.conf)
(although putting the username there works for me too)
By: Walter Doekes (wdoekes) 2013-09-11 11:25:44.038-0500

P.S. Port= and Socket= don't make sense together. Use either Server= and Port= or just Socket=. Try if changing them helps.
By: Patrick Maille (patrickm) 2013-09-11 11:30:42.245-0500

libiodbc2 is a required library for me. I uninstalled it and got:
[Sep 11 12:24:43] WARNING[9299] loader.c: Error loading module 'res_odbc.so': libiodbc.so.2: cannot open shared object file: No such file or directory

I reinstalled it , but I get the same error:
[Sep 11 12:27:10] WARNING[9472] res_odbc.c: res_odbc: Error SQLConnect=-1 errno=1045 <B0>;<F5><D6>@^?

I also did the replace for the username, but same thing.

It looks like the res_odbc module isn't "talking" right to the system odbc library or something, because it's not even generating a trace file. So it might be an interop issue with that particular version of odbc maybe ?
By: Walter Doekes (wdoekes) 2013-09-11 11:43:09.255-0500

Try recompiling (re-run configure) after removing libiodbc.
By: Patrick Maille (patrickm) 2013-09-11 11:53:31.408-0500

If if remove libiodbc2 then I can't select anything related to odbc when I do the "make menuselect"
By: Walter Doekes (wdoekes) 2013-09-18 02:09:30.230-0500

{quote}
ii unixodbc 2.2.14p2-1 ODBC tools libraries
{quote}

Where is the {{unixodbc-dev}} package...?

I think you've managed to compile against {{iODBC}} while {{isql(1)}} tests {{unixodbc}} connectivity. So that's comparing apples with oranges.
By: Patrick Maille (patrickm) 2013-09-18 08:15:10.776-0500

I don't have unixodbc-dev, I only have libiodbc2-dev.
I'll try and remove libiodbc2-dev and install unixodbc-dev instead, and recompile.
By: Patrick Maille (patrickm) 2013-09-18 09:05:09.659-0500

That did it.
So it looks like libiodbc2-dev provides a satisfactory dependency to "configure" for odbc support ..and it does build and run .. just not as expected.
Removing libiodbc2-dev and recompiling against unixodbc-dev did the trick. Thanks.
By: Walter Doekes (wdoekes) 2013-09-18 10:43:04.827-0500

Indeed.

If I run {{/usr/share/doc/libiodbc2-dev/examples/iodbctest.c.gz}}, I get this:

{noformat}
$ gcc test.c -liodbc
$ ./a.out 'DSN=mydb;UID=myuser;PWD=mypass' >/dev/null
1: SQLDriverConnect = �� (0) SQLSTATE=
{noformat}
{noformat}
$ gcc -DUNICODE test.c -liodbc
$ ./a.out 'DSN=mydb;UID=myuser;PWD=mypass' >/dev/null
1: SQLDriverConnectW = �� (0) SQLSTATE=��0
{noformat}

Something is fishy with that iodbc lib.

It does write stuff to my trace log, but it's not promising. And SQLGetDiagRec returns utter garbage.

I could see how a warning to not try iodbc would be appropriate.

----

{noformat}
--- test.c.orig 2013-09-18 16:53:29.000000000 +0200
+++ test.c 2013-09-18 16:56:24.000000000 +0200
@@ -146,7 +146,7 @@

length = strlen (sourStr);
if (length > 0)
- OPL_A2W (sourStr, destStr, length);
+ OPL_A2W (sourStr, (wchar_t *) destStr, length);
destStr[length] = L'\0';

return destStr;
@@ -1089,7 +1089,7 @@
*/
ODBC_Disconnect ();

- printf ("\nHave a nice day.");
+ printf ("\nHave a nice day.\n");

return 0;
}
{noformat}
By: Matt Jordan (mjordan) 2013-09-18 10:45:03.556-0500

Walter: where do you think the warning would be appropriate?
By: Walter Doekes (wdoekes) 2013-09-24 02:23:18.298-0500

Something along the lines of {{issueA22459_warn_when_using_iodbc.patch}} perhaps.

Note that on my Ubuntu 13.04, {{iodbc2}} has some crazy package dependency rules that won't even allow me to install libmyodbc (or unixodbc) and libiodbc2 together anymore. So the potential problem will at least be gone there (for as long as that lasts).

{noformat}
$ apt-cache show libmyodbc | grep libiodbc2
Recommends: libodbc1 | libiodbc2
Breaks: libiodbc2, odbcinst1debian2 (<< 2.2.14p2-3), unixodbc (<< 2.2.14p2-3)
{noformat}

:P
By: Matt Jordan (mjordan) 2013-09-26 14:49:26.312-0500

I'm good with that.