[Home]

Summary:ASTERISK-16090: Asterisk crash on ODBC /usr/lib/libodbc.so.1 and /lib/i686/cmov/libc.so.6
Reporter:Marcin Kowalczyk (kowalma)Labels:
Date Opened:2010-05-13 04:06:37Date Closed:2011-06-07 14:10:04
Priority:TrivialRegression?No
Status:Closed/CompleteComponents:Functions/func_odbc
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) crash.txt
( 1) crash-2010-05-13T12_25_40.txt
( 2) crash-2010-05-13T13_33_41+0200.txt
( 3) crash-2010-05-24-1.txt
( 4) crash-debug.txt
Description:Hi,

On quite heavy load I expirience Asterisk crash.
Asterisk 1.6.1.19 + following ODBC version

ii  libiodbc2                            3.52.6-2                   iODBC Driver Manager
ii  libmyodbc                            3.51.15r409-4              the MySQL ODBC driver
ii  libodbcinstq1c2                      2.2.11-16                  Qt-based ODBC configuration library
ii  odbcinst1debian1                     2.2.11-16                  Support library and helper program for acces
ii  unixodbc                             2.2.11-16                  ODBC tools libraries
ii  unixodbc-bin                         2.2.11-16                  Graphical tools for ODBC management and brow
ii  unixodbc-dev                         2.2.11-16                  ODBC libraries for UNIX (development files)


I'm using ODBC quite hard for dialplan (checking permissions, setting up database variables for Queues, sip realtime, etc)
Same I saw in 1.6.1.18 - I upgraded yesterday to .19 and this did not solve issue.


BT Full says:
(gdb) bt full
#0  0xb7d5f872 in free () from /lib/i686/cmov/libc.so.6
No symbol table info available.
#1  0xb769ebe1 in ?? () from /usr/lib/libodbc.so.1
No symbol table info available.
#2  0x00000001 in ?? ()
No symbol table info available.
#3  0xb76b9d2c in ?? () from /usr/lib/libodbc.so.1
No symbol table info available.
#4  0xad343658 in ?? ()
No symbol table info available.
ASTERISK-1  0xb76b9d2c in ?? () from /usr/lib/libodbc.so.1
No symbol table info available.
ASTERISK-2  0x09f22968 in ?? ()
No symbol table info available.
ASTERISK-3  0x00000003 in ?? ()
No symbol table info available.
ASTERISK-4  0xad343718 in ?? ()
No symbol table info available.
ASTERISK-5  0xb7662908 in ?? () from /usr/lib/libodbc.so.1
No symbol table info available.
ASTERISK-6 0xac202a20 in ?? ()
No symbol table info available.
ASTERISK-7 0xac202a20 in ?? ()
No symbol table info available.
ASTERISK-8 0x00007fb8 in ?? ()
No symbol table info available.
ASTERISK-9 0x080808f2 in __ao2_ref (user_data=0xac202a20, delta=-1407178208) at astobj2.c:307
       obj = (struct astobj2 *) 0xb76b9d2c
       current_value = 166865256
       ret = 3
       __PRETTY_FUNCTION__ = "__ao2_ref"
Backtrace stopped: previous frame inner to this frame (corrupt stack?)
(gdb)
Comments:By: Marcin Kowalczyk (kowalma) 2010-05-13 08:21:58

And I just had two crashes - I think these new are related to sip-realtime  (via ODBC)
By: Marcin Kowalczyk (kowalma) 2010-05-13 10:19:39

Looks that * tries to execute invalid query

cps = {sql = 0xb1cd0850 "SELECT * FROM sip_peers WHERE name = ?", extra = 0x0, ap = 0xb1cd0f24 "--\"-@!\032\b", skip = 0}

and then crashes - or am I wrong?


By: Marcin Kowalczyk (kowalma) 2010-05-13 10:22:53

I'm thinking if it's related to https://issues.asterisk.org/view.php?id=17245
By: Tilghman Lesher (tilghman) 2010-05-13 10:24:31

Per the Asterisk maintenance timeline page at http://www.asterisk.org/asterisk-versions maintenance (bug) support for the 1.6.0 and 1.6.1 branches has ended. For continued maintenance support please move to the 1.6.2 branch.

More information on this change can be found in the release announcement: http://www.asterisk.org/node/49924

By: Marcin Kowalczyk (kowalma) 2010-05-13 11:37:23

Like suggested - I've upgraded to 1.6.2.7 and applied patch from ASTERISK-16014
I'm waiting for crash :-)


By: Marcin Kowalczyk (kowalma) 2010-05-19 05:35:53

Just expirienced * crash.
1.6.2.7 with patch from ASTERISK-1700245 - bt uploaded
By: Marcin Kowalczyk (kowalma) 2010-05-24 07:38:10

Looks for me it's general ODBC issue - I expirience crases on func_odbc and sip realtime as well
By: Marcin Kowalczyk (kowalma) 2010-05-25 11:51:29

Today I managed to crash * on ODBC after executing "module reload"
By: Paul Belanger (pabelanger) 2010-06-25 09:14:15

Are you able to rebuild UnixODBC with debug symbols? Any additional info is helpful.
By: Marcin Kowalczyk (kowalma) 2010-06-25 14:45:33

I don't see any debug compilation options in ODBC configure. Or this should be configured on * level?
I've recently upgraded to most recent version on libs:
mysql-connector-odbc-5.1.6-linux-glibc2.3-x86-32bit
unixODBC-2.3.0

but sill I expirience crash every 2-3 days.
By: Tilghman Lesher (tilghman) 2010-06-25 15:03:32

./configure CFLAGS="-O0 -g3" CXXFLAGS="-O0 -g3"
By: Marcin Kowalczyk (kowalma) 2010-06-25 16:29:38

I've recompiled ODBC and upgraded * to 1.6.2.9. See what will happen. Recent crashes I had on extremly low traffic - 1 active call.


By: Marcin Kowalczyk (kowalma) 2010-07-02 05:05:07

Please find attached most recent crash with ODBC debug symbols.
By: Marcin Kowalczyk (kowalma) 2010-07-04 03:12:54

I had MySQL connection idle (looks closed due to inactivity) and then call came.

[Jul  4 10:08:02] WARNING[30385]: res_odbc.c:1300 ast_odbc_request_obj2: SetConnectAttr (Txn isolation) returned an error: HY000: [MySQL][ODBC 5.1 Driver]MySQL server has gone away
[Jul  4 10:08:02] WARNING[30385]: res_odbc.c:1300 ast_odbc_request_obj2: SetConnectAttr (Txn isolation) returned an error: HY000: [MySQL][ODBC 5.1 Driver]MySQL server has gone away
[Jul  4 10:08:02] WARNING[30386]: func_odbc.c:183 generic_execute: SQL Execute returned an error -1: 08S01: [MySQL][ODBC 5.1 Driver][mysqld-5.0.51a-24+lenny1-log]MySQL server has gone away (80)
[Jul  4 10:08:02] WARNING[30386]: func_odbc.c:183 generic_execute: SQL Execute returned an error -1: 08S01: [MySQL][ODBC 5.1 Driver][mysqld-5.0.51a-24+lenny1-log]MySQL server has gone away (80)
[Jul  4 10:08:02] WARNING[30385]: func_odbc.c:183 generic_execute: SQL Execute returned an error -1: 08S01: [MySQL][ODBC 5.1 Driver][mysqld-5.0.51a-24+lenny1-log]MySQL server has gone away (80)
[Jul  4 10:08:02] WARNING[30385]: func_odbc.c:183 generic_execute: SQL Execute returned an error -1: 08S01: [MySQL][ODBC 5.1 Driver][mysqld-5.0.51a-24+lenny1-log]MySQL server has gone away (80)
[Jul  4 10:08:02] WARNING[30386]: func_odbc.c:191 generic_execute: SQL Exec Direct failed (-1)![select id from Now where host = "CC9373" limit 0,1]
[Jul  4 10:08:02] WARNING[30386]: func_odbc.c:191 generic_execute: SQL Exec Direct failed (-1)![select id from Now where host = "CC9373" limit 0,1]
[Jul  4 10:08:02] WARNING[30385]: func_odbc.c:191 generic_execute: SQL Exec Direct failed (-1)![select id from Now where host = "CC9374" limit 0,1]
[Jul  4 10:08:02] WARNING[30385]: func_odbc.c:191 generic_execute: SQL Exec Direct failed (-1)![select id from Now where host = "CC9374" limit 0,1]
[Jul  4 10:08:02] WARNING[30385]: res_odbc.c:583 ast_odbc_direct_execute: SQL Exec Direct failed.  Attempting a reconnect...
[Jul  4 10:08:02] WARNING[30385]: res_odbc.c:583 ast_odbc_direct_execute: SQL Exec Direct failed.  Attempting a reconnect...
Asterisk-node0*CLI>
By: Tilghman Lesher (tilghman) 2011-03-10 00:51:25.000-0600

Based upon the latest crash report, this may be resolved with the commit for ASTERISK-16946.  If not, we will need Valgrind output to figure this one out.
By: Marcin Kowalczyk (kowalma) 2011-03-10 03:44:43.000-0600

I will apply patch against 1.8.2.4 and I will give feedback in next couple of days
By: Marcin Kowalczyk (kowalma) 2011-03-22 17:49:56

Today I managed to put patch on. From patch worklog I can see it has sth to do with 64bit, but I'm running 32bit OS

In addition - I just found one interesting thing:

asterisk-01*CLI> core show uptime
System uptime: 1 day, 14 hours, 21 minutes, 48 seconds

core file: core.asterisk-01-2011-03-21T09:22:36+0100

asterisk-02*CLI> core show uptime
System uptime: 1 day, 14 hours, 21 minutes, 56 seconds

core file core.asterisk-02-2011-03-21T09:22:39+0100

seems that my two * crashed same time (!). Seems that database behaviour triggers crash
By: Marcin Kowalczyk (kowalma) 2011-03-28 13:56:33

No change... Today again crash and again two boxes same time:
core.asterisk-02-2011-03-28T16:36:03+0200
core.asterisk-01-2011-03-28T16:36:37+0200

It's hard to do valgrind as they were running fine for 6 days
By: Tilghman Lesher (tilghman) 2011-03-28 17:05:16

What happens when you add:  wait_timeout=999999 in the [mysqld] context to /etc/mysql/my.cnf (or wherever your distribution puts my.cnf) and restart the MySQL server?
By: Marcin Kowalczyk (kowalma) 2011-03-29 03:15:38

I've just added it. Let's wait couple of next days to check how it looks like,
By: Leif Madsen (lmadsen) 2011-04-14 13:03:13

Any feedback?
By: Tilghman Lesher (tilghman) 2011-05-03 19:16:12

kowalma: based upon the lack of response, is it safe to assume that upping the timeout fixed the problem?
By: Marcin Kowalczyk (kowalma) 2011-05-04 02:53:01

sorry - I was on my looong hollidays.
Seems this solves problem, so I would say odbc module has problem detecting when connection is closed and needs reconnect
By: Leif Madsen (lmadsen) 2011-05-10 16:27:23

As I've seen this mentioned here, and on the mailing lists now, I think we should add documentation somewhere. What, and where, could we add this?
By: Leif Madsen (lmadsen) 2011-05-10 16:33:38

I'm going to close this as it isn't an issue with Asterisk. It would be ideal for someone to follow up with the MySQL people. Thanks!