[Home]

Summary:ASTERISK-03501: Looking up VM config from MySQL seems to be broken in stable Asterisk
Reporter:beonice (beonice)Labels:
Date Opened:2005-02-13 11:00:10.000-0600Date Closed:2011-06-07 14:05:30
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) sample-voicemail.conf
Description:I'm running the stable asterisk:
Asterisk CVS-v1-0-12/12/04-15:58:29, Copyright (C) 1999-2004 Digium.

When I try to point Asterisk to use MySQL for VM configuration details, it seems to do weird things. Basically, MySQL indicates that instead of passing in a valid SELECT statement, all that's going to MYSQL during find_user is "SEL"!!

I ran asterisk within GDB, and here is the interaction with gdb (you'll notice that the value of 'query' within mysql-vm-routines.h:find user is 'SEL' followed by a bunch of garbage):
----------------------------------------------------
GNU gdb Red Hat Linux (6.0post-0.20040223.20rh)
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you
are
welcome to change it and/or distribute copies of it under certain
conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for
details.
This GDB was configured as "i386-redhat-linux-gnu"...Using host
libthread_db library "/lib/tls/libthread_db.so.1".

(gdb) break app_voicemail.c:find_user
No source file named app_voicemail.c.
Make breakpoint pending on future shared library load? (y or [n]) y

Breakpoint 1 (app_voicemail.c:find_user) pending.
(gdb) break mysql-vm-routines.h:find_user
No source file named mysql-vm-routines.h.
Make breakpoint pending on future shared library load? (y or [n]) y

Breakpoint 2 (mysql-vm-routines.h:find_user) pending.
(gdb) run -cp
Starting program: /usr/sbin/asterisk -cp
[Thread debugging using libthread_db enabled]
[New Thread -1222246272 (LWP 9179)]
[New Thread -1222247504 (LWP 9182)]
[Thread -1222247504 (LWP 9182) exited]
[New Thread -1222247504 (LWP 9183)]
Asterisk CVS-v1-0-12/12/04-15:58:29, Copyright (C) 1999-2004 Digium.
Written by Mark Spencer <markster@digium.com>
========================================================================
=
[ Booting.....[New Thread -1224402000 (LWP 9184)]
.Feb 13 09:04:04 WARNING[9179]: res_musiconhold.c:564 moh_register:
Unable to open pseudo channel for timing...  Sound may be choppy.
[New Thread -1226523728 (LWP 9185)]
.Detaching after fork from child process 9186.
Junk at the beginning 49443303
Warning, flexibel rate not heavily tested!
.[New Thread -1228678224 (LWP 9188)]
.....[New Thread -1231180880 (LWP 9189)]
....[New Thread -1233450064 (LWP 9190)]
.Feb 13 09:04:04 WARNING[9179]: chan_iax2.c:7430 load_module: Unable to
open IAX timing interface: No such device
[New Thread -1236948048 (LWP 9191)]
..Feb 13 09:04:04 WARNING[9179]: chan_skinny.c:2584 reload_config:
Unable to get our IP address, Skinny disabled
[New Thread -1239159888 (LWP 9192)]
.Feb 13 09:04:04 WARNING[9179]: chan_oss.c:357 setformat: Requested 8000
Hz, got 48000 Hz -- sound may be choppy
[New Thread -1241494608 (LWP 9193)]
Feb 13 09:04:04 WARNING[9179]: chan_oss.c:239 sound_thread: Read error
on sound device: Resource temporarily unavailable
.[New Thread -1243624528 (LWP 9194)]
.Feb 13 09:04:04 WARNING[9179]: chan_zap.c:9599 setup_zap: Ignoring
switchtype
[New Thread -1246000208 (LWP 9195)]
..[New Thread -1248150608 (LWP 9196)]
.[New Thread -1250268240 (LWP 9197)]
..Breakpoint 3 at 0xb558a0da: file mysql-vm-routines.h, line 40.
Pending breakpoint "app_voicemail.c:find_user" resolved
Note: breakpoint 3 also set at pc 0xb558a0da.
Breakpoint 4 at 0xb558a0da: file mysql-vm-routines.h, line 40.
Pending breakpoint "mysql-vm-routines.h:find_user" resolved
.    -- Logging into database with user asteriskuser, password amp109,
and database asterisk_vm
.........[New Thread -1253127248 (LWP 9199)]
........................................................................
......Feb 13 09:04:06 WARNING[9179]: cdr_addon_mysql.c:330
my_load_module: MySQL database sock file not specified.  Using default
. ]
Asterisk Ready.
*CLI> [New Thread -1258980432 (LWP 9201)]
Feb 13 09:04:30 WARNING[9179]: app_voicemail.c:1335 leave_voicemail: EXT
is: 1111
[Switching to Thread -1258980432 (LWP 9201)]

Breakpoint 3, find_user (ivm=0xb4f529b0, context=0x0,
   mailbox=0xb5597feb "app_voicemail.c") at mysql-vm-routines.h:40
warning: Source file is more recent than executable.

40              char options[160] = "";
(gdb) n
34      {
(gdb) n
Feb 13 09:04:40 WARNING[9179]: chan_oss.c:269 sound_thread: Read error
on sound device: Resource temporarily unavailable
Feb 13 09:04:40 NOTICE[9179]: res_musiconhold.c:309 monmp3thread:
Request to schedule in the past?!?!
40              char options[160] = "";
(gdb) n
Feb 13 09:04:41 WARNING[9179]: chan_oss.c:269 sound_thread: Read error
on sound device: Resource temporarily unavailable
Feb 13 09:04:41 NOTICE[9179]: res_musiconhold.c:309 monmp3thread:
Request to schedule in the past?!?!
43              retval=malloc(sizeof(struct ast_vm_user));
(gdb) n
Feb 13 09:04:42 WARNING[9179]: chan_oss.c:269 sound_thread: Read error
on sound device: Resource temporarily unavailable
45              if (retval) {
(gdb) n
Feb 13 09:04:43 WARNING[9179]: chan_oss.c:269 sound_thread: Read error
on sound device: Resource temporarily unavailable
Feb 13 09:04:43 NOTICE[9179]: res_musiconhold.c:309 monmp3thread:
Request to schedule in the past?!?!
46                      memset(retval, 0, sizeof(struct ast_vm_user));
(gdb) n
Feb 13 09:04:44 WARNING[9179]: chan_oss.c:269 sound_thread: Read error
on sound device: Resource temporarily unavailable
Feb 13 09:04:44 NOTICE[9179]: res_musiconhold.c:309 monmp3thread:
Request to schedule in the past?!?!
294             if (reviewvm)
(gdb)(gdb) n
Feb 13 09:05:43 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:43 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
293             vmu->attach = -1;
(gdb) n
Feb 13 09:05:45 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:45 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
294             if (reviewvm)
(gdb) n
Feb 13 09:05:45 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:45 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
296             if (calloper)
(gdb) n
Feb 13 09:05:46 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:46 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
298             if (saycidinfo)
(gdb) n
Feb 13 09:05:47 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:47 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
300             if (svmailinfo)
(gdb) n
Feb 13 09:05:47 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:47 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
301                     vmu->svmail = 1;
(gdb) n
Feb 13 09:05:48 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:48 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
302             if (hearenv)
(gdb) n
Feb 13 09:05:49 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:49 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
303                     vmu->envelope = 1;
(gdb) n
Feb 13 09:05:50 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:50 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
304             if (callcontext)
(gdb) n
Feb 13 09:05:52 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:52 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
305                     strncpy(vmu->callback, callcontext, sizeof(vmu->callback) -1);
(gdb) n
Feb 13 09:05:54 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:54 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
306             if (dialcontext)
(gdb) n
Feb 13 09:05:56 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:56 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
307                     strncpy(vmu->dialout, dialcontext, sizeof(vmu->dialout) -1);
(gdb) n
Feb 13 09:05:58 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:58 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
308             if (exitcontext)
(gdb) n
Feb 13 09:05:58 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:05:58 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
309                     strncpy(vmu->exit, exitcontext, sizeof(vmu->exit) -1);
(gdb) n
Feb 13 09:06:00 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:00 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
48                      retval->attach=-1;
(gdb) n
Feb 13 09:06:05 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:05 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
49                      retval->alloced=1;
(gdb) n
Feb 13 09:06:07 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:07 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
48                      retval->attach=-1;
(gdb) n
Feb 13 09:06:10 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:10 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
50                      retval->next=NULL;
(gdb) n
Feb 13 09:06:11 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:11 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
51                      if (mailbox) {
(gdb) n
Feb 13 09:06:12 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:12 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
49                      retval->alloced=1;
(gdb) n
Feb 13 09:06:13 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:13 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
50                      retval->next=NULL;
(gdb) n
Feb 13 09:06:13 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:13 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
51                      if (mailbox) {
(gdb) n
Feb 13 09:06:14 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:14 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
52                              strcpy(retval->mailbox, mailbox);
(gdb) n
Feb 13 09:06:15 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:15 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
54                      if (context) {
(gdb) n
Feb 13 09:06:17 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:17 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
57                              strcpy(retval->context, "default");
(gdb) n
Feb 13 09:06:18 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:18 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
58                              context = "default";
(gdb) n
Feb 13 09:06:18 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:18 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
62                      if (*retval->context) {
(gdb) n
Feb 13 09:06:19 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:19 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
66                              return(NULL);
(gdb) n
Feb 13 09:06:20 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:20 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
68                      ast_log(LOG_WARNING, "Query so far is: %s\n", query);
(gdb) n
Feb 13 09:06:24 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:06:24 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
69
(gdb) print query
$1 = "SEL\000ÿÿÿÿ", '\0' <repeats 24 times>, "\002\000\000\000\004\000\000\000 \000\000\000 \000\000\000\000\000\000\000@\000\000\000¦@þ´ $õ´", '\0' <repeats 77 times>, "\003\002\230", '¿' <repeats 19 times>, "ÀÀÀÀÀÀÀÁÁÁÁÁÁÂÂÂÂÂÂÂÃÃÃÃÃÄÄÄÄÄÄÅÅÅÅÅÅÆÆÆÆÆÆÆÇÇÇÇÇÇÈÈÈÈÈÈÈÉÉÉÉÉÉÊÊÊÊÊÊËËËËËËÌÌ"
(gdb) n
Feb 13 09:08:08 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:08:08 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
70                      ast_mutex_lock(&mysqllock);
(gdb) n
Feb 13 09:08:13 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:08:13 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
100                             }
(gdb) n
Feb 13 09:08:14 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:08:14 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
101                     }
(gdb) n
Feb 13 09:08:18 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:08:18 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
103                     free(retval);
(gdb) n
Feb 13 09:08:19 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:08:19 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
104             }
(gdb) n
Feb 13 09:08:20 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:08:20 NOTICE[9179]: res_musiconhold.c:309 monmp3thread: Request to schedule in the past?!?!
leave_voicemail (chan=0x813e7d0, ext=0x0, silent=0, busy=0, unavail=1)
   at app_voicemail.c:1543
1543                    ast_log(LOG_WARNING, "No entry in voicemail config file for '%s'\n", ext);
(gdb) n
Feb 13 09:08:21 WARNING[9179]: chan_oss.c:269 sound_thread: Read error on sound device: Resource temporarily unavailable
Feb 13 09:08:21 WARNING[9179]: app_voicemail.c:1543 leave_voicemail: No entry in voicemail config file for '1111'
1545                    if (ast_exists_extension(chan, chan->context, chan->exten, chan->priority + 101, chan->callerid))






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

By the way, when I tried to put in extra logging/print statements into mysql-vm-routines.h, did a make clean/make/make install, then gdb says that the mysql-vm-routines.h source file is newer than the executable. I assumed that make clean would have ensured a recompile.
Comments:By: Mark Spencer (markster) 2005-02-13 11:09:37.000-0600

This line here:

warning: Source file is more recent than executable.

indicates that the debugging lines quite possibly do not correspond to the executable you are running.  Can you please update to latest stable CVS and duplicate this problem the same way you did, printing the value of the query at each point?
By: Mark Spencer (markster) 2005-02-13 11:10:17.000-0600

Also, please do a rm -rf /usr/lib/asterisk/modules and "make clean ; make install" in both asterisk and the addons.
By: beonice (beonice) 2005-02-13 11:32:28.000-0600

Will updating to latest stable CVS break my existing config? :D I've spent a lot of time getting things set up ... what directories should I be careful to back up before I update asterisk?
By: Mark Spencer (markster) 2005-02-13 12:25:59.000-0600

It will not affect your config, but you can backup everything first if you want (/etc/asterisk, /usr/lib/asterisk, /usr/sbin/asterisk, /var/lib/asterisk and of course the sources)
By: beonice (beonice) 2005-02-13 12:37:08.000-0600

Mark, THANKS a bunch for the hint to update to the latest stable asterisk. That seems to have fixed the problem. I'm very much obliged, and now am one happy camper. Now I just have to get the rest of my own application debugged!

How can I get asterisk to tell me what the current version that I am running is? I notice the auto-printed header didn't change visibly!
By: Mark Spencer (markster) 2005-02-13 12:50:49.000-0600

The bug tracker is not a place for technical support.  Please see the "support" section of asterisk.org for more information on seeking technical support.