[Asterisk-Dev] Core dump in __ast_dsp_silence (dsp.c:1195, version 0.7.2)

[Ryan Tucker]

Greetings...

We got the following core last night.  I'm not entirely sure what the 
endpoint suggested by the core was doing, but, well, it doesn't look like 
*that* extraordinary of a set of circumstances.

Search-and-replace has been run to mask personal information; virgin data, 
if important, is available to Qualified Asterisk Developers [tm].  :-)

(gdb) bt
#0  0x0808cfad in __ast_dsp_silence (dsp=0x0, s=0x52d005b0, len=160, 
totalsilence=0x0) at dsp.c:1195
#1  0x0808aebb in ast_dsp_process (chan=0x5044ecb8, dsp=0xb38, af=0xa0, 
needlock=0) at dsp.c:1427
#2  0x41b948db in sip_rtp_read (ast=0x11, p=0x52d005b0) at chan_sip.c:1655
#3  0x41b93259 in sip_read (ast=0x52d005b0) at chan_sip.c:1667
#4  0x08058fec in ast_read (chan=0xb38) at channel.c:1089
#5  0x41dc9a36 in wait_for_answer (in=0x5044ecb8, outgoing=0x82023c0, 
to=0x52d00db0, allowredir_in=0x52d00db4,
     allowredir_out=0x52d00db8, allowdisconnect=0x52d00dbc) at 
app_dial.c:310
#6  0x41dc8f95 in dial_exec (chan=0x5044ecb8, data=0x8629f48) at 
app_dial.c:648
#7  0x08063fda in pbx_exec (c=0x5044ecb8, app=0x80e2660, data=0x52d015a8, 
newstack=1) at pbx.c:396
#8  0x0806b5c1 in pbx_extension_helper (c=0x5044ecb8, context=0x5044ee10 
"xxxxxxxdid", exten=0x0, priority=2,
     callerid=0x4eac1458 "xxxxxxxx32", action=1104987508) at pbx.c:1171
#9  0x08065f9c in ast_pbx_run (c=0x41dcc574) at pbx.c:1655
#10 0x0806bc81 in pbx_thread (data=0x11) at pbx.c:1880
#11 0x40028332 in start_thread () from /lib/tls/libpthread.so.0

Here's __ast_dsp_silence:

static int __ast_dsp_silence(struct ast_dsp *dsp, short *s, int len, int 
*totalsilence)
{
         int accum;
         int x;
         int res = 0;

         accum = 0;
         for (x=0;x<len; x++)
                 accum += abs(s[x]);
         accum /= len;
         if (accum < dsp->threshold) {     /*  <------- THIS IS THE LINE IN 
QUESTION */
                 dsp->totalsilence += len/8;
                 if (dsp->totalnoise) {
                         /* Move and save history */
                         memmove(dsp->historicnoise + DSP_HISTORY - 
dsp->busycount, dsp->historicnoise + DSP_HISTORY - dsp-
> busycoun
t +1, dsp->busycount*sizeof(dsp->historicnoise[0]));
                         dsp->historicnoise[DSP_HISTORY - 1] = 
dsp->totalnoise;
/* we don't want to check for busydetect that frequently */
#if 0
                         dsp->busymaybe = 1;
#endif
                 }
                 dsp->totalnoise = 0;
                 res = 1;
         } else {
                 dsp->totalnoise += len/8;
                 if (dsp->totalsilence) {
                         int silence1 = dsp->historicsilence[DSP_HISTORY - 
1];
                         int silence2 = dsp->historicsilence[DSP_HISTORY - 
2];
                         /* Move and save history */
                         memmove(dsp->historicsilence + DSP_HISTORY - 
dsp->busycount, dsp->historicsilence + DSP_HISTORY -
dsp->busy
count + 1, dsp->busycount*sizeof(dsp->historicsilence[0]));
                         dsp->historicsilence[DSP_HISTORY - 1] = 
dsp->totalsilence;
                         /* check if the previous sample differs only by 
BUSY_PERCENT from the one before it */
                         if (silence1 < silence2) {
                                 if (silence1 + silence1/BUSY_PERCENT >= 
silence2)
                                         dsp->busymaybe = 1;
                                 else
                                         dsp->busymaybe = 0;
                         } else {
                                 if (silence1 - silence1/BUSY_PERCENT <= 
silence2)
                                         dsp->busymaybe = 1;
                                 else
                                         dsp->busymaybe = 0;
                         }

                 }
                 dsp->totalsilence = 0;
         }
         if (totalsilence)
                 *totalsilence = dsp->totalsilence;
         return res;
}

Last debug log chunks were:

Feb 19 22:15:41 DEBUG[1150520624]: Setting NAT on RTP to -1
Feb 19 22:15:41 DEBUG[1150520624]: Stopping retransmission on 
'0003e386-3c790035-6a60201e-1f4d9a29 at 1.168.2.245' of
Response 101: Fo
und
Feb 19 22:15:41 DEBUG[1150520624]: Setting NAT on RTP to -1
Feb 19 22:15:41 DEBUG[1150520624]: Check for res for xxxxxxx-xx32
Feb 19 22:15:41 DEBUG[1150520624]: Call from user 'xxxxxxx-xx32' is 1 out 
of 0
Feb 19 22:15:41 DEBUG[1150520624]: build_route: Contact hop: 
sip:xxxxxxx-xx32 at 1.168.2.245:5060
Feb 19 22:15:41 DEBUG[1389370672]: SIMPLE DIAL (NO URL)
Feb 19 22:15:41 DEBUG[1389370672]: Setting NAT on RTP to -1
Feb 19 22:15:41 DEBUG[1389370672]: Outgoing Call for xxxxxxx-xx31
Feb 19 22:15:41 DEBUG[1389370672]: Call from user 'xxxxxxx-xx31' is 1 out 
of 0
Feb 19 22:15:41 DEBUG[1150520624]: (Provisional) Stopping retransmission 
(but retaining packet) on
'6d49a7500c0dbfda04373d4b6a15aa2
e at xxx.xx.xx.35' Request 102: Found
Feb 19 22:15:41 DEBUG[1150520624]: (Provisional) Stopping retransmission 
(but retaining packet) on
'6d49a7500c0dbfda04373d4b6a15aa2
e at xxx.xx.xx.35' Request 102: Found
Feb 19 22:15:41 DEBUG[1389370672]: Driver for channel 
'SIP/xxxxxxx-xx32-ed93' does not support indication 3, emulating it
Feb 19 22:15:41 DEBUG[1389370672]: Prodding channel 'SIP/xxxxxxx-xx32-ed93'
Feb 19 22:15:41 DEBUG[1389370672]: RTP NAT: Using address 
xxx.xx.xx.114:19734

xxxxxxx-xx31 and xxxxxxx-xx32 are on the same IP address, different ports, 
behind a NAT:

xxxxxxx-xx32/ne  xxx.xx.xx.114   (D)  255.255.255.255  5060     Unmonitored
xxxxxxx-xx31/ne  xxx.xx.xx.114   (D)  255.255.255.255  1035     Unmonitored

-- 
Ryan Tucker
Network Engineer
ISP Direct, Inc.
1159 Pittsford-Victor Road, Suite 140
Pittsford, New York 14534
585-419-8200
www.netacc.net