[Home]

Summary:ASTERISK-02622: [isdn4linux] echotest / voicemail crash when receiving DTMF from the PSTN[
Reporter:Edwin Groothuis (mavetju)Labels:
Date Opened:2004-10-17 23:35:58Date Closed:2008-01-15 15:11:35.000-0600
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) patch-channels::chan_modem.c
Description:I use i4l to receive incoming calls (and use &L to route between asterisk and the mgetty).

I call in via the PSTN network into the echotest and/or voicemail of Asterisk. When pressing an DTMF button, asterisk segfaults:

#0  ast_queue_frame (chan=0x812d530, fin=0x80f53a4) at channel.c:384
#1  0x0809cb70 in ast_dsp_process (chan=0x812d530, dsp=0x8135c80, af=0x80f53a4) at dsp.c:1570
#2  0x40020449 in i4l_read (p=0x80f5298) at chan_modem_i4l.c:451
#3  0x4001c036 in modem_read (ast=0x8139db0) at chan_modem.c:485
#4  0x0805a9a3 in ast_read (chan=0x8139db0) at channel.c:1311
ASTERISK-1  0x08062948 in ast_waitstream (c=0x8139db0, breakon=0x44d3a0ee "") at file.c:942
ASTERISK-2  0x44d39df1 in playback_exec (chan=0x8139db0, data=0x4539683c) at app_playback.c:81
ASTERISK-3  0x080701fb in pbx_exec (c=0x8139db0, app=0x8111380, data=0x4539683c, newstack=1) at pbx.c:478
ASTERISK-4  0x08072028 in pbx_extension_helper (c=0x8139db0, con=0x0, context=0x8139f14 "unauthenticated",
   exten=0x813a008 "600", priority=1, label=0x0, callerid=0x813b5c8 "Àß\022BXe\023\b\020", action=1) at pbx.c:1308
ASTERISK-5  0x08072d81 in ast_pbx_run (c=0x8139db0) at pbx.c:1806
ASTERISK-6 0x0807a15f in pbx_thread (data=0x8139db0) at pbx.c:2046
ASTERISK-7 0x4002efef in pthread_start_thread () from /lib/i686/libpthread.so.0

(gdb) list
379                     ast_log(LOG_WARNING, "Unable to duplicate frame\n");
380                     return -1;
381             }
382             ast_mutex_lock(&chan->lock);
383             prev = NULL;
384             cur = chan->pvt->readq;
385             while(cur) {
386                     if ((cur->frametype == AST_FRAME_CONTROL) && (cur->subclass == AST_CONTROL_HANGUP)) {
387                             /* Don't bother actually queueing anything after a hangup */
388                             ast_frfree(f);

(gdb) p chan
$4 = (struct ast_channel *) 0x812d530
(gdb) p chan->pvt
$5 = (struct ast_channel_pvt *) 0x0

More information can be available on request.
Comments:By: Olle Johansson (oej) 2004-10-19 14:15:20

* Linux kernel version?
* Any other Asterisk modules, outside of the standard distribution?
* Please explain "&L" - what is that?
* What ISDN card, which Linux kernel driver?
By: Edwin Groothuis (mavetju) 2004-10-19 16:48:52

Linux versions:

Kernel version: Linux mercury.barnet.com.au 2.4.18-3 ASTERISK-14 SMP Tue Dec 3 23:09:03 EST 2002 i686 unknown

[root@mercury root]# cat /etc/redhat-release
Red Hat Linux release 7.3 (Valhalla)

No asterisk modules outside the default one (I'm just starting)

ISDN card: 00:0e.0 Network controller: Eicon Technology Corporation DIVA Server BRI-8M (rev 01). It uses the default 2.4.18-3 i4l drivers.

&L is to specify for the selected tty to listen to a certain incoming phone number. So &L123 on ttyI0 forwards all calls to number 123 to ttyI0 and the rest goes to ttyI1 and following.
By: Mark Spencer (markster) 2004-10-19 23:36:54

Did you already try "make clean ; make install"?
By: Edwin Groothuis (mavetju) 2004-10-19 23:59:44

I just did it and it still fails.
By: Mark Spencer (markster) 2004-10-20 08:39:52

Please install valgrind and run under valgrind so we can find the true source of the problem.  Please find someone on IRC (e.g. kram, bkw_) to assist you with the debug.
By: Edwin Groothuis (mavetju) 2004-10-20 20:10:13

<pre>
[root@mercury asterisk]# valgrind --tool=memcheck asterisk -f -g -c -vv
[...]
Oct 21 11:03:44 DEBUG[15]: chan_modem_i4l.c:413 i4l_read: Value of escape is 8 (56)...
Oct 21 11:03:44 DEBUG[15]: chan_modem_i4l.c:299 i4l_handle_escape: Detected outband DTMF digit: '8' (56)
==7386==
==7386== Thread 15:
==7386== Invalid read of size 4
==7386==    at 0x8059198: ast_queue_frame (channel.c:384)
==7386==    by 0x809CC9F: ast_dsp_process (dsp.c:1570)
==7386==    by 0x3C3C8448: ??? (chan_modem_i4l.c:451)
==7386==    by 0x3C02BF75: ??? (chan_modem.c:485)
==7386==  Address 0x3D2DEC2C is 944 bytes inside a block of size 6164 free'd
==7386==    at 0x3C01C862: free (vg_replace_malloc.c:127)
==7386==    by 0x8059737: ast_channel_free (channel.c:654)
==7386==    by 0x8059A15: ast_hangup (channel.c:759)
==7386==    by 0x80734E8: ast_pbx_run (pbx.c:2042)
==7386==
==7386== Thread 15:
==7386== Invalid read of size 4
==7386==    at 0x80591A1: ast_queue_frame (channel.c:384)
==7386==    by 0x809CC9F: ast_dsp_process (dsp.c:1570)
==7386==    by 0x3C3C8448: ??? (chan_modem_i4l.c:451)
==7386==    by 0x3C02BF75: ??? (chan_modem.c:485)
==7386==  Address 0x4 is not stack'd, malloc'd or free'd
==7386==
==7386== Process terminating with default action of signal 11 (SIGSEGV): dumping core
==7386==  Access not within mapped region at address 0x4
==7386==    at 0x80591A1: ast_queue_frame (channel.c:384)
==7386==    by 0x809CC9F: ast_dsp_process (dsp.c:1570)
==7386==    by 0x3C3C8448: ??? (chan_modem_i4l.c:451)
==7386==    by 0x3C02BF75: ??? (chan_modem.c:485)
==7386==
</pre>

do you have an email address for bwk_ or kram so I can contact them for a realtime-session? (I'm on the irc-channel already as 'mavvie')
By: Edwin Groothuis (mavetju) 2004-10-23 00:43:34

From debugging, this is what I found:

First, I added a field "char valid;" to all structures involved (struct ast_channel, struct ast_channel_pvt). This field will be set to 1 when the structure is allocated, and set to 0 just before it is freed.

This is an overview of function calls and the variables we're interested in. The number before the . is the PID, the number before the / is the value of the valid field and the number after the / is the memory location.

Asterisk gets started:
22187. mkif: tmp: 1/0x80f7330
22187. mkif: tmp: 1/0x80f7c90
22187. mkif: tmp: 1/0x80f85f0

Incoming call on ttyI0:
22191. i4l_read: p: 1/0x80f7330
22191. i4l_read: p: 1/0x80f7330
22191. i4l_read: p: 1/0x80f7330
22191. ast_channel_alloc: chan: 1/0x813fde0
22191. ast_channel_alloc: chan->pvt: 1/0x80f66f8
22191. name: Modem[i4l]/ttyI0, modem: 0x80f7330, owner: 0x813fde0
22203. ast_channel_alloc: chan: 1/0x8141600
22203. ast_channel_alloc: chan->pvt: 1/0x80f6408
22203. ast_channel_alloc: chan: 1/0x8142e20
22203. ast_channel_alloc: chan->pvt: 1/0x80f64d8
22204. ast_queue_frame: chan: 1/0x8141600, fin: 0x4536f50c
22204. ast_channel_alloc: chan: 1/0x8145708
22204. ast_channel_alloc: chan->pvt: 1/0x80f9e70
22204. ast_queue_frame: chan: 1/0x8141600, fin: 0x8147204
22204. ast_queue_frame: chan: 1/0x8141600, fin: 0x8147204
22204. ast_queue_frame: chan: 1/0x8141600, fin: 0x8147204
22204. ast_queue_frame: chan: 1/0x8141600, fin: 0x8147204
22204. ast_queue_frame: chan: 1/0x8141600, fin: 0x8147204
22204. ast_queue_frame: chan: 1/0x8141600, fin: 0x8147204
22203. i4l_read: p: 1/0x80f7330
22204. ast_queue_frame: chan: 1/0x8141600, fin: 0x8147204
22203. i4l_read: p: 1/0x80f7330
22203. i4l_read: p: 1/0x80f7330
22204. ast_queue_frame: chan: 1/0x8141600, fin: 0x8147204
22203. i4l_read: p: 1/0x80f7330
22203. i4l_read: (before dsp) p: 1/0x80f7330
22203. i4l_read: (before dsp) p->owner: 1/0x813fde0
22203. ast_dsp_process: chan: 1/0x813fde0, af: 0x80f7440
22203. ast_queue_frame: chan: 1/0x8142e20, fin: 0x80f7440
22203. ast_queue_frame: chan: 1/0x8142e20, fin: 0x4516f90c
22203. ast_queue_frame: chan: 1/0x813fde0, fin: 0x4516f90c
22203. i4l_read: p: 1/0x80f7330

Call is answered, now some juggling is happening:
22204. ast_do_masquerade: original: 1/0x8142e20, clone: 1/0x813fde0
22204. ast_do_masquerade: original->pvt: 1/0x80f64d8, clone->pvt: 1/0x80f66f8
2Oct 23 15:16:50 WARNING[15375]: channel.c:2393 ast_do_masquerade: Driver 'Modem' does not have a fixup routine (for Modem[i4l]/ttyI0)!  Bad things may happen.
2204. ast_queue_frame: chan: 1/0x8141600, fin: 0x4536eeec
22204. ast_do_masquerade: after: original: 1/0x8142e20
22204. ast_do_masquerade: after: original->pvt: 1/0x80f66f8
22204. ast_do_masquerade: after: clone: 1/0x813fde0
22204. ast_do_masquerade: after: clone->pvt: 1/0x80f64d8
22203. ast_channel_free: chan: 1/0x8141600, chan->pvt: 1/0x80f6408
22203. ast_channel_free: chan: 1/0x813fde0, chan->pvt: 1/0x80f64d8
the channel at 0x813fde0 is free()d

but...
22204. i4l_read: p: 1/0x80f7330
22204. i4l_read: p: 1/0x80f7330
22204. i4l_read: (before dsp) p: 1/0x80f7330
22204. i4l_read: (before dsp) p->owner: 40/0x813fde0
22204. ast_dsp_process: chan: 40/0x813fde0, af: 0x80f7440
p->owner is still pointing to it!

Not all the juggling in ast_do_masquerade() was successful.

Further debugging shows that after the ast_do_masquerade(), (struct ast_modem_pvt *)original->pvt->pvt->owner is pointing to 0x813fde0 instead of to 0x8142e20.

I suspect it has to do with the absence of a fixup routine. More later.
By: Edwin Groothuis (mavetju) 2004-10-23 04:38:44

It was indeed the absense of a fixup for channels/chan_modem.c which caused the problem. Attached patch which creates modem_fixup() resolves it for me.
By: Mark Spencer (markster) 2004-10-23 07:46:24

Fixed in CVS
By: Russell Bryant (russell) 2004-10-24 17:11:59

fixed in 1.0
By: Digium Subversion (svnbot) 2008-01-15 15:11:11.000-0600

Repository: asterisk
Revision: 4057

U   trunk/channels/chan_modem.c

------------------------------------------------------------------------
r4057 | markster | 2008-01-15 15:11:10 -0600 (Tue, 15 Jan 2008) | 2 lines

Add missing fixup (bug ASTERISK-2622)

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=4057
By: Digium Subversion (svnbot) 2008-01-15 15:11:35.000-0600

Repository: asterisk
Revision: 4088

U   branches/v1-0/channels/chan_modem.c

------------------------------------------------------------------------
r4088 | russell | 2008-01-15 15:11:35 -0600 (Tue, 15 Jan 2008) | 2 lines

Add missing fixup (bug ASTERISK-2622)

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=4088