[Home]

Summary:ASTERISK-06788: MYSQL app crashes after reload
Reporter:Max Litnitskiy (litnimax)Labels:
Date Opened:2006-04-15 08:01:01Date Closed:2006-05-22 11:45:07
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Applications/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) bug.txt
Description:Hello folks.
I am using res_config to load configuration from MySQL database.
Everything works perfect except one issue. When I do not reload asterisk configuration (reload, extensions reload, sip reload) for some days, and issue reload, I get the following message:

extensions reload
Apr 13 08:21:25 WARNING[16693]: res_odbc.c:199 odbc_smart_direct_execute: SQL Execute error! Attempting a reconnect...
Apr 13 08:21:25 WARNING[16693]: res_odbc.c:497 odbc_obj_disconnect: res_odbc: disconnected 0 from asterisk [asterisk]
Apr 13 08:21:25 NOTICE[16693]: res_odbc.c:554 odbc_obj_connect: Connecting asterisk
Apr 13 08:21:25 NOTICE[16693]: res_odbc.c:569 odbc_obj_connect: res_odbc: Connected to asterisk [asterisk]
Apr 13 08:21:25 WARNING[16693]: res_config_odbc.c:454 config_odbc: SQL select error!
[SELECT * FROM ext_config WHERE filename='extensions.conf' and commented=0 ORDER BY filename,cat_metric desc,var_metric asc,
category,var_name,var_val,id]
Apr 13 08:21:25 WARNING[16693]: pbx.c:3740 ast_merge_contexts_and_delete: Requested contexts didn't get merged
pbx1*CLI>
pbx1*CLI> extensions reload
 == Setting global variable 'DBHOST' to '127.0.0.1'
 == Setting global variable 'DBUSER' to 'aster'
 == Setting global variable 'DBPASS' to 'aster'
 == Setting global variable 'DB' to 'pbx'
   -- Registered extension context 'dids'
   -- Added extension '_XXXXX.' priority 1 to dids
   -- Added extension '_XXXXX.' priority 2 to dids
....

So you can see that asterisk was reloaded successfully on 2-nd reload. BUT!

  -- Accepting AUTHENTICATED call from x.x.x.x:
      > requested format = alaw,
      > requested prefs = (),
      > actual format = alaw,
      > host prefs = (alaw),
      > priority = mine
   -- Executing Macro("IAX2/x.x.x.x:4569-1", "did|12128xxxx") in new stack
   -- Executing MYSQL("IAX2/x.x.x.x:4569-1", "Connect connid 127.0.0.1 asterisk aster pbx") in new stack
pbx1*CLI>
Disconnected from Asterisk server
Executing last minute cleanups
Asterisk cleanly ending (0).


IT CRASHES ON THE 1-st CALL. ALWAYS.

It is alway reproducable so apparently there is a bug somewhere.

****** ADDITIONAL INFORMATION ******

Tried versions 1.2.4, 1.2.6.
Comments:By: Joshua C. Colp (jcolp) 2006-04-15 17:45:20

Are you sure this is a bug in the MySQL stuff for res_config and not the MySQL dialplan addon? We need a backtrace to be certain, and more details. What happens if you call an extension that does not have execute the MySQL application?
By: Tilghman Lesher (tilghman) 2006-04-16 01:20:09

Backtrace needed within 3 days or issue will be closed.  Please see the bug guidelines for instructions on creating a backtrace.
By: Max Litnitskiy (litnimax) 2006-04-16 01:35:08

I will post some more traces asap
By: Serge Vecher (serge-v) 2006-05-02 13:17:16

litnimax: still need that backtrace if the problem persists. Please respond...
By: Max Litnitskiy (litnimax) 2006-05-02 15:04:54

Sorry.
Doing it.
By: Max Litnitskiy (litnimax) 2006-05-05 11:59:12

I have the following dialplan:

exten => 1,1,Answer()
exten => 1,2,Playback(demo-thanks)

Reproducing the situation:

pbx1*CLI> extensions reload
May  5 11:44:12 WARNING[8618]: res_odbc.c:199 odbc_smart_direct_execute: SQL Execute error! Attempting a reconnect...
May  5 11:44:12 WARNING[8618]: res_odbc.c:495 odbc_obj_disconnect: res_odbc: disconnected 0 from asterisk [asterisk]
May  5 11:44:12 NOTICE[8618]: res_odbc.c:552 odbc_obj_connect: Connecting asterisk
May  5 11:44:12 NOTICE[8618]: res_odbc.c:567 odbc_obj_connect: res_odbc: Connected to asterisk [asterisk]
May  5 11:44:12 WARNING[8618]: res_config_odbc.c:454 config_odbc: SQL select error!
[SELECT * FROM ext_config WHERE filename='extensions.conf' and commented=0 ORDER BY filename,cat_metric desc,var_metric asc,category,var_name,var_val,id]

May  5 11:44:12 WARNING[8618]: pbx.c:3740 ast_merge_contexts_and_delete: Requested contexts didn't get merged
pbx1*CLI>

And calling Playback always works! That means it is app_MySQL issue:

   -- Executing Macro("IAX2/5072233067-5", "check-limits")
   -- Executing MYSQL("IAX2/5072233067-5", "Connect connid 127.0.0.1 asterisk asterpass pbx_manager_new") in new stack
pbx1*CLI>
Disconnected from Asterisk server
Executing last minute cleanups
Asterisk cleanly ending (0).

Seems it is app_MySQL bug! And it apparently related to timeouts!
I am using 5.0.18, and I found:
>>>>>>>>>>>>>>>>>>>>>>>
Prior to MySQL 5.0.19, even if the reconnect flag in the MYSQL structure is equal to 1, MySQL does not automatically reconnect and re-issue the query as it doesn't know if the server did get the original query or not.

The solution to this is to either do a mysql_ping on the connection if there has been a long time since the last query (this is what MyODBC does) or set wait_timeout on the mysqld server so high that it in practice never times out.
<<<<<<<<<<<<<<<<<<<<<<<<<

Hm, but app_mysql is not connected all the time! So it must not be affected by timeout.


It is always reproducable. Just restart MySql server, do extensions reload and:

   -- Executing Playback("IAX2/5072233067-3", "demo-thanks") in new stack
   -- Playing 'demo-thanks' (language 'en')
pbx1*CLI>
   -- Executing MYSQL("IAX2/5072233067-3", "Connect connid 127.0.0.1 asterisk asterpass pbx_manager_new") in new stack
pbx1*CLI>
Disconnected from Asterisk server
Executing last minute cleanups
Asterisk cleanly ending (0).

HOW CAN APP_MYSQL INTERFERE WITH RES_CONFIG?
By: Joshua C. Colp (jcolp) 2006-05-05 12:06:51

It's probably not but we need a backtrace to be sure. Without that we don't know where the issue is exactly.
By: Max Litnitskiy (litnimax) 2006-05-05 12:47:09

Shall I follow this howto below??
--------------------------
An Important Note on Submitting Backtraces

When getting a backtrace to have developers help you debug a problem, it is VERY important that you build asterisk with "make clean; make valgrind; make install". This will turn off optimizations so that we can get a readable backtrace.

Thank you!

Backtracing a core dump file in /tmp

  1. start Asterisk with safe_asterisk
  2. enter "gdb asterisk core.xxxx"
  3. enter "bt" while in gdb (or do a "bt full")

Naturally you'll need to have gdb installed on your system
By: Joshua C. Colp (jcolp) 2006-05-05 12:49:19

Yes.
By: Max Litnitskiy (litnimax) 2006-05-07 05:20:27

This is traceback:

(gdb) bt
#0  0xf6dfd8d2 in my_strcasecmp_8bit () from /usr/lib/libmyodbc3.so
#1  0xf6df5e41 in get_charset_number () from /usr/lib/libmyodbc3.so
#2  0xf6df6133 in get_charset_by_csname () from /usr/lib/libmyodbc3.so
#3  0xf6e0f9c7 in mysql_real_connect () from /usr/lib/libmyodbc3.so
#4  0xf64ca329 in ?? () from /home/asterisk/usr/lib/asterisk/modules/app_addon_sql_mysql.so
ASTERISK-1  0x09cdba60 in ?? ()
ASTERISK-2  0xf6078e6f in ?? ()
ASTERISK-3  0xf6078e79 in ?? ()
ASTERISK-4  0xf6078e82 in ?? ()
ASTERISK-5  0xf6078e8c in ?? ()
ASTERISK-6 0x00000cea in ?? ()
ASTERISK-7 0x00000000 in ?? ()


(gdb) bt full
#0  0xf6dfd8d2 in my_strcasecmp_8bit () from /usr/lib/libmyodbc3.so
No symbol table info available.
#1  0xf6df5e41 in get_charset_number () from /usr/lib/libmyodbc3.so
No symbol table info available.
#2  0xf6df6133 in get_charset_by_csname () from /usr/lib/libmyodbc3.so
No symbol table info available.
#3  0xf6e0f9c7 in mysql_real_connect () from /usr/lib/libmyodbc3.so
No symbol table info available.
#4  0xf64ca329 in ?? () from /home/asterisk/usr/lib/asterisk/modules/app_addon_sql_mysql.so
No symbol table info available.
ASTERISK-1  0x09cdba60 in ?? ()
No symbol table info available.
ASTERISK-2  0xf6078e6f in ?? ()
No symbol table info available.
ASTERISK-3  0xf6078e79 in ?? ()
No symbol table info available.
ASTERISK-4  0xf6078e82 in ?? ()
No symbol table info available.
ASTERISK-5  0xf6078e8c in ?? ()
No symbol table info available.
ASTERISK-6 0x00000cea in ?? ()
No symbol table info available.
ASTERISK-7 0x00000000 in ?? ()
No symbol table info available.
(gdb)


Is it enough?
By: Tilghman Lesher (tilghman) 2006-05-07 08:50:16

I need you to go into your asterisk-addons directory and edit the Makefile so that the line which currently reads:

CFLAGS+=-fPIC

to read:

CFLAGS+=-fPIC -g

then you need to type:

make clean install

Additionally, please go into your asterisk source directory and type:

make clean dont-optimize

Then obtain the backtrace, as before, and upload the resulting output AS A FILE, NOT AS A BUGNOTE onto this bug.
By: Max Litnitskiy (litnimax) 2006-05-09 02:08:34

Just uploaded bug.txt with backtrace.
Pls see it and tell if it's ok or advise what else info shall I provide.
Thx.
By: Tilghman Lesher (tilghman) 2006-05-09 11:59:12

The problem is that you have a module which links against libmyodbc, where it should be linking against libmysqlclient.  The problem is that both of these libraries have the same exported symbols, and there can be only one.

There isn't really an easy fix, here, other than to stop using either the MYSQL app or the MySQL backend driver (through ODBC) for Realtime.  They are incompatible with each other.  One possible replacement for the MYSQL app is to use func_odbc.  See http://svncommunity.com/view/func_odbc/1.2/
By: Max Litnitskiy (litnimax) 2006-05-09 18:39:41

Hold on, but how can it work perfectly for days ?
How can it even start? But it works fine, the only issue is asterisk crash when database timeout expires.
By: Tilghman Lesher (tilghman) 2006-05-09 23:12:47

Hang on... before, you said it was a reload that caused it to crash.  Now you're saying that it's a database timeout?  Are you disconnecting the connId on every call after you're done with the database handle?
By: Max Litnitskiy (litnimax) 2006-05-10 04:56:21

Everything works perfect on start up.
I can do extensions reload as many time as I want and all is ok.
But when database connection timeouts or database is reload, so res_config connection becomes broken, I try to extensions relaod I get:

[SELECT * FROM ext_config WHERE filename='extensions.conf' and commented=0 ORDER BY filename,cat_metric desc,var_metric asc,category,var_name,var_val,id]

May 5 11:44:12 WARNING[8618]: pbx.c:3740 ast_merge_contexts_and_delete: Requested contexts didn't get merged
pbx1*CLI>

And after that app_MySQL crashes asterisk. So the problems is somewhere in the code of res_config that is handling reconnections. For example, why it fails to read dialplan from database after connection timeout?
Look again:

May 5 11:44:12 WARNING[8618]: res_odbc.c:199 odbc_smart_direct_execute: SQL Execute error! Attempting a reconnect...
May 5 11:44:12 WARNING[8618]: res_odbc.c:495 odbc_obj_disconnect: res_odbc: disconnected 0 from asterisk [asterisk]
May 5 11:44:12 NOTICE[8618]: res_odbc.c:552 odbc_obj_connect: Connecting asterisk
May 5 11:44:12 NOTICE[8618]: res_odbc.c:567 odbc_obj_connect: res_odbc: Connected to asterisk [asterisk]
May 5 11:44:12 WARNING[8618]: res_config_odbc.c:454 config_odbc: SQL select error!
[SELECT * FROM ext_config WHERE filename='extensions.conf' and commented=0 ORDER BY filename,cat_metric desc,var_metric asc,category,var_name,var_val,id]

It seems to reconnect but fails to read data!
If I issue again extensions reload it works smooth, dialplan is read, all works ok. Except that app_mysql crashes asterisk.

You can easily model the situation by /etc/init.d/mysql restart, no need to wait till timeout.
By: Joshua C. Colp (jcolp) 2006-05-19 09:19:57

Are these connected to the same database server?
By: Max Litnitskiy (litnimax) 2006-05-19 10:08:03

Yes, all is on localhost.
By: Joshua C. Colp (jcolp) 2006-05-19 10:23:54

So maybe the ODBC stuff can deal with a server disappearing better then the direct MySQL client library... which is certainly what it looks like. I've dealt with this same issue in programming other software, so it's not isolated to Asterisk and I don't know what we can do for you.
By: Max Litnitskiy (litnimax) 2006-05-19 11:04:23

1. I am trying to use ODBC for realtime/static configuration and app_mysql from dialplan. I will report what I get.
2. can anyone explain where exactly is a bug? In res_config? In app_mysql? How they can interfere?
By: Joshua C. Colp (jcolp) 2006-05-19 11:09:46

I don't believe they are interfering, and I don't know why you keep going back to that. If you don't get your extensions.conf from the database at all does the same thing happen with the MySQL application? If so, then it's just the MySQL application that is having the issue - and based on the backtrace you provided before it's the actual library that it links against that is crashing.
By: Max Litnitskiy (litnimax) 2006-05-19 11:12:16

Ok, all is the same.
Now I have:
pbx1*CLI> show config mappings
pbx1*CLI>


Config Engine: odbc
===> musiconhold.conf (db=asterisk, table=moh_config)
===> extensions.conf (db=asterisk, table=ext_config)
===> voicemail (db=asterisk, table=voicemail)
===> extensions (db=asterisk, table=dialplan)
===> sippeers (db=asterisk, table=peer)
===> sipusers (db=asterisk, table=peer)
===> iaxpeers (db=asterisk, table=peer)
===> iaxusers (db=asterisk, table=peer)

Config Engine: mysql

Guys, this is 100% always reproducable bug, can anyone figure it out for sure?
By: Max Litnitskiy (litnimax) 2006-05-19 11:13:35

Is there a way to use MySQL in res_config directly? I would like to test both MySQL realtime and static, but seems static works only for ODBC. Correct?
By: Joshua C. Colp (jcolp) 2006-05-19 11:19:09

Go back to what Corydon asked... are you doing MYSQL(Disconnect <connid>) after you are finished with it?
By: Max Litnitskiy (litnimax) 2006-05-19 13:19:45

This is my dialplan:
's' =>            1. MySQL(Connect connid ${DBHOST} ${DBUSER} ${DBPASS} ${DB}) [pbx_config]
                   2. Set(QUERY=call p_asterisk_did2user(${ARG1})) [pbx_config]
                   3. MYSQL(Query resultid ${connid} ${QUERY})   [pbx_config]
                   4. MYSQL(Fetch fetchid ${resultid} user)      [pbx_config]
                   5. MYSQL(Clear ${resultid})                   [pbx_config]
                   6. MYSQL(Disconnect ${connid})                [pbx_config]

I  always use Disconnect!!
By: Joshua C. Colp (jcolp) 2006-05-22 11:45:06

After talking with others I've made the decision to close the bug as your problem is stemming from the library that app_addon_sql_mysql is linked against. It is what is causing your Asterisk to segfault. Sorry, but I don't think there's anything we can do for you.