Summary:ASTERISK-21039: ODBC functions time out
Reporter:Fabian Borot (fborot)Labels:
Date Opened:2013-02-05 15:05:19.000-0600Date Closed:2013-03-07 09:53:21.000-0600
Versions:11.2.0 Frequency of
Environment:Linux,Centos 5.7, Linux AW-ATL-CORE-01 2.6.18-274.7.1.el5 #1 SMP Thu Oct 20 16:21:01 EDT 2011 x86_64 x86_64 x86_64 GNU/Linux Attachments:( 0) odbc_asterisk_config_on_both_versions.txt
( 1) odbc_show_asterisk_1.8.txt
( 2) odbc_show_asterisk_11.2.txt
( 3) odbc_warnings_in_asterisk_11.2.0.txt
Description:When calling ODBC functions in the dialplan we see time outs and several warnings like the ones shown below. This started happening when we upgraded from 1.8 to 11.2.
We did not made any change to the OS nor to the freetds and odbc files that we use to connect to our SQL database. On the 1.8 asterisk this is not happening, same DNS, same network.
Also when issuing the "odbc show" command on 1.8 we see up to 165 connections out of the limit of 256, on the 11.2.0 we see only 4.

I am attaching several files:
1- "res_odbc.conf" used in both asterisk versions (1.8 and 11.2.0)
2- file showing warning that show up in the asterisk console in version 11.2.0
3- file showing output of "odbc show" in both asterisk versions
Comments:By: Rusty Newton (rnewton) 2013-02-07 18:01:03.405-0600

I don't see any attachments, did you run into an issue attaching your files?

Be sure your Asterisk log contains VERBOSE and DEBUG message types (as well as your WARNING) and that they were turned up to 5 or higher. https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information

By: Fabian Borot (fborot) 2013-02-07 18:36:42.925-0600

I uploaded 4 files, I can see them on the JIRA website for this incident (ASTERISK-21039)

By: Richard Mudgett (rmudgett) 2013-02-07 20:34:51.705-0600

You have to look under the History or Activity tabs to see them for some reason.  (Maybe because they all have spaces in the filenames.)

By: Fabian Borot (fborot) 2013-02-12 13:54:32.275-0600

Hi, Were you able to see the attached files? thank you

By: Fabian Borot (fborot) 2013-02-12 13:55:40.527-0600

Hi, Were you able to see the attached files? thank you

By: Richard Mudgett (rmudgett) 2013-02-12 15:21:51.009-0600

I was able to see the files in the expected location the next morning.

By: Matt Jordan (mjordan) 2013-02-13 21:32:40.952-0600

Which version of 1.8 were you running?

There's only one change in {{res_odbc}} between the current revision in the branches of 1.8 and 11, which involved using the {{ao2_lock}} calls to lock the ao2 objects as opposed to explicitly accessing them. I don't think that would be causing any lifetime/connection issues.

Can you also attach a DEBUG 5 log? The warnings you get typically occur when an attempt to access the database fails, at which point we tear down the connection and attempt to re-connect. I'm curious if there's a common pattern in the database accesses leading up to that point.

By: Matt Jordan (mjordan) 2013-03-07 09:53:12.956-0600

I haven't been able to reproduce this behavior, and there were no changes to {{res_odbc}} between 1.8 and 11 save for using {{ao2_lock}} to lock the mutexes. Your warnings and errors show that Asterisk wasn't able to allocate a handle to the database:

[2013-02-05 20:54:53.630] WARNING[8074][C-000002bd]: res_config_odbc.c:85 custom_prepare: SQL Alloc Handle failed!

That means that {{SQLAllocHandle}} itself is failing - which is outside of Asterisk's control. The fact that you're also getting timeouts makes me thing there is something going on here that is system dependent.

[2013-02-05 20:54:53.556] WARNING[8074][C-000002bc]: res_odbc.c:1552 odbc_obj_connect: res_odbc: Error SQLConnect=-1 errno=0 [unixODBC][FreeTDS][SQL Server]Timeout expired

Since we can't reproduce this and there are no real changes between 1.8 and 11, I'm closing this out as "Can't Reproduce". If anyone else can reproduce this problem when moving between 1.8 and 11 and provide some indication as to what might be causing the problem, we can reopen this issue.