[asterisk-users] Asterisk ZAP/DAHDI reads phantom digit on overlap PRI

Vieri rentorbuy at yahoo.com
Mon Dec 14 18:12:55 CST 2009


--- On Mon, 12/14/09, Vieri <rentorbuy at yahoo.com> wrote:

> From: Vieri <rentorbuy at yahoo.com>
> Subject: Re: [asterisk-users] Asterisk ZAP/DAHDI reads phantom digit on overlap PRI
> To: asterisk-users at lists.digium.com
> Date: Monday, December 14, 2009, 3:26 PM
> 
> --- On Mon, 12/14/09, Tzafrir Cohen <tzafrir.cohen at xorcom.com>
> wrote:
> 
> > On Mon, Dec 14, 2009 at 05:32:21AM
> > -0800, Vieri wrote:
> > > Hi,
> > > 
> > > I've noticed that a small but meaningful quota
> of
> > calls from my Alcatel PBX to Asterisk are failing.
> > > 
> > > This does not always happen and it is not easily
> > reproducible but on high traffic I do get a large
> number of
> > cases.
> > > 
> > > Example: Alcatel PBX extension 7085 calls
> Asterisk PBX
> > extension 6145 over a PRI E1 link.
> > > 
> > > I see this in the Asterisk log:
> > > 
> > > Dec 14 14:10:31 VERBOSE[11378] logger.c: 
> >    -- Accepting overlap call from '7085' to
> > '6145' on channel 1/31, span 1
> > > Dec 14 14:10:31 VERBOSE[5558] logger.c: 
> >    -- Starting simple switch on 'Zap/31-1'
> > > Dec 14 14:10:32 DEBUG[5558] chan_zap.c: DTMF
> digit: 5
> > on Zap/31-1
> > > Dec 14 14:10:40 DEBUG[5558] chan_zap.c: No such
> > possible extension '61455' in context 'from-alcatel'
> > > 
> > > Obviously, it's failing because Asterisk is
> trying to
> > match destination+extra DTMF digit (ie. 6145+5). 
> > > 
> > > However, noone ever dialed that extra digit! So
> how
> > did it get there?
> > > 
> > > I guess I could disable "overlap" in Asterisk but
> that
> > isn't the right way to go.
> > > 
> > > What else can I do (where else can I look) to
> solve
> > this issue?
> > 
> > Please provide trace from 'pri debug' .
> 
> OK, I just grabbed a log for an Alcatel PBX extension 6166
> calling an Asterisk PBX extension 6158 over a PRI E1 link:
> (not omitting any lines, just in case useful info is
> inadvertantly removed)
> 
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < Protocol
> Discriminator: Q.931 (8)  len=39
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < Call Ref:
> len= 2 (reference 28696/0x7018) (Originator)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < Message type:
> SETUP (5)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < [04 03 80 90
> a3]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < Bearer
> Capability (len= 5) [ Ext: 1  Q.931 Std: 0  Info
> transfer capability: Speech (0)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: <   
>                
>           Ext: 1  Trans
> mode/rate: 64kbps, circuit-mode (16)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: <   
>                
>             User information
> layer 1: A-Law (35)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < [18 03 a9 83
> 8e]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < Channel ID
> (len= 5) [ Ext: 1  IntID: Implicit, PRI Spare: 0,
> Exclusive Dchan: 0
> Dec 14 20:15:53 VERBOSE[11378] logger.c: <   
>                
>     ChanSel: As indicated in following octets
> Dec 14 20:15:53 VERBOSE[11378] logger.c: <   
>                
>    Ext: 1  Coding:
> 0   Number Specified   Channel
> Type: 3
> Dec 14 20:15:53 VERBOSE[11378] logger.c: <   
>                
>    Ext: 1  Channel: 14 ]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < [1e 02 80
> 83]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < Progress
> Indicator (len= 4) [ Ext: 1  Coding: CCITT (ITU)
> standard (0) 0: 0   Location: User (0)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: <   
>                
>            Ext: 1 
> Progress Description: Calling equipment is non-ISDN. (3) ]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < [6c 06 00 81
> 36 31 36 36]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < Calling
> Number (len= 8) [ Ext: 0  TON: Unknown Number Type
> (0)  NPI: Unknown Number Plan (0)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: <   
>                
>        Presentation: Presentation
> permitted, user number passed network screening (1) '6166'
> ]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < [70 05 80 36
> 31 35 38]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < Called Number
> (len= 7) [ Ext: 1  TON: Unknown Number Type (0) 
> NPI: Unknown Number Plan (0) '6158' ]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < [7d 02 91
> 81]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < IE:
> High-layer Compatibility (len = 4)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < [a1]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: < Sending
> Complete (len= 1)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: -- Making new call
> for cr 28696
> Dec 14 20:15:53 VERBOSE[11378] logger.c: -- Processing
> Q.931 Call Setup
> Dec 14 20:15:53 VERBOSE[11378] logger.c: -- Processing IE 4
> (cs0, Bearer Capability)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: -- Processing IE
> 24 (cs0, Channel Identification)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: -- Processing IE
> 30 (cs0, Progress Indicator)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: -- Processing IE
> 108 (cs0, Calling Party Number)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: -- Processing IE
> 112 (cs0, Called Party Number)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: -- Processing IE
> 125 (cs0, High-layer Compatibility)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: -- Processing IE
> 161 (cs0, Sending Complete)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: > Protocol
> Discriminator: Q.931 (8)  len=11
> Dec 14 20:15:53 VERBOSE[11378] logger.c: > Call Ref:
> len= 2 (reference 28696/0x7018) (Terminator)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: > Message type:
> CALL PROCEEDING (2)
> Dec 14 20:15:53 VERBOSE[11378] logger.c: > [18 04 e9 81
> 83 8e]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: > Channel ID
> (len= 6) [ Ext: 1  IntID: Explicit, PRI Spare: 0,
> Exclusive Dchan: 0
> Dec 14 20:15:53 VERBOSE[11378] logger.c: >   
>                
>     ChanSel: As indicated in following octets
> Dec 14 20:15:53 VERBOSE[11378] logger.c: >   
>                
>    Ext: 1  DS1 Identifier: 1  
> Dec 14 20:15:53 VERBOSE[11378] logger.c: >   
>                
>    Ext: 1  Coding:
> 0   Number Specified   Channel
> Type: 3
> Dec 14 20:15:53 VERBOSE[11378] logger.c: >   
>                
>    Ext: 1  Channel: 14 ]
> Dec 14 20:15:53 VERBOSE[11378] logger.c: 
>    -- Accepting overlap call from '6166' to
> '6158' on channel 1/14, span 1
> Dec 14 20:15:53 VERBOSE[15709] logger.c: 
>    -- Starting simple switch on 'Zap/14-1'
> Dec 14 20:15:53 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:53 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:53 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:53 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:53 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '26d6021811f743aa74b1483b4ac462c0 at 10.215.147.111' of Request
> 102: Match Found
> Dec 14 20:15:54 DEBUG[15709] chan_zap.c: DTMF digit: 8 on
> Zap/14-1
> Dec 14 20:15:54 DEBUG[11374] chan_sip.c: Auto destroying
> call '499086686-54077-1 at 192.168.250.7'
> Dec 14 20:15:54 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:54 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:54 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:54 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:54 DEBUG[15728] manager.c: Manager received
> command 'login'
> Dec 14 20:15:54 VERBOSE[15728]
> logger.c:   == Parsing
> '/etc/asterisk/manager.conf': Dec 14 20:15:54 VERBOSE[15728]
> logger.c:   == Parsing
> '/etc/asterisk/manager.conf': Found
> Dec 14 20:15:54 DEBUG[15728] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0
> appended to acl for peer
> Dec 14 20:15:54 DEBUG[15728] acl.c:
> 127.0.0.1/255.255.255.255/255.255.255.255 appended to acl
> for peer
> Dec 14 20:15:54 DEBUG[15728] acl.c:
> 10.215.147.111/255.255.255.255/255.255.255.255 appended to
> acl for peer
> Dec 14 20:15:54 DEBUG[15728] acl.c:
> 10.215.147.112/255.255.255.255/255.255.255.255 appended to
> acl for peer
> Dec 14 20:15:54 DEBUG[15728] acl.c:
> 192.168.250.111/255.255.255.255/255.255.255.255 appended to
> acl for peer
> Dec 14 20:15:54 DEBUG[15728] acl.c:
> 192.168.250.112/255.255.255.255/255.255.255.255 appended to
> acl for peer
> Dec 14 20:15:54 DEBUG[15728] acl.c: ##### Testing
> 10.215.147.111 with 0.0.0.0
> Dec 14 20:15:54 DEBUG[15728] acl.c: ##### Testing
> 10.215.147.111 with 127.0.0.1
> Dec 14 20:15:54 DEBUG[15728] acl.c: ##### Testing
> 10.215.147.111 with 10.215.147.111
> Dec 14 20:15:54 DEBUG[15728] acl.c: ##### Testing
> 10.215.147.111 with 10.215.147.112
> Dec 14 20:15:54 DEBUG[15728] acl.c: ##### Testing
> 10.215.147.111 with 192.168.250.111
> Dec 14 20:15:54 DEBUG[15728] acl.c: ##### Testing
> 10.215.147.111 with 192.168.250.112
> Dec 14 20:15:54 VERBOSE[15728]
> logger.c:   == Manager 'inftester' logged on
> from 10.215.147.111
> Dec 14 20:15:54 DEBUG[15728] manager.c: Manager received
> command 'Logoff'
> Dec 14 20:15:54 VERBOSE[15728]
> logger.c:   == Manager 'inftester' logged off
> from 10.215.147.111
> Dec 14 20:15:54 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 0.0.0.0
> Dec 14 20:15:54 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 127.0.0.1
> Dec 14 20:15:54 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 0.0.0.0
> Dec 14 20:15:54 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 127.0.0.1
> Dec 14 20:15:55 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:55 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:55 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:55 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:55 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 0.0.0.0
> Dec 14 20:15:55 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 127.0.0.1
> Dec 14 20:15:55 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 0.0.0.0
> Dec 14 20:15:55 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 127.0.0.1
> Dec 14 20:15:55 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 0.0.0.0
> Dec 14 20:15:55 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 127.0.0.1
> Dec 14 20:15:55 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 0.0.0.0
> Dec 14 20:15:55 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 127.0.0.1
> Dec 14 20:15:56 DEBUG[11374] chan_sip.c: Auto destroying
> call '899767513-34417-1 at 192.168.250.32'
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.30 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:56 DEBUG[11374] acl.c: ##### Testing
> 192.168.250.8 with 0.0.0.0
> Dec 14 20:15:57 DEBUG[11374] chan_sip.c: Auto destroying
> call '1171794545-29013-1 at 192.168.250.32'
> Dec 14 20:15:57 DEBUG[11374] chan_sip.c: Auto destroying
> call '268115595-23470-1 at 192.168.250.32'
> Dec 14 20:15:57 DEBUG[11374] chan_sip.c: Auto destroying
> call '57108573-13315-1 at 192.168.250.32'
> Dec 14 20:15:57 DEBUG[11374] chan_sip.c: Auto destroying
> call '2067961949-32610-1 at 192.168.250.32'
> Dec 14 20:15:57 DEBUG[11374] chan_sip.c: Auto destroying
> call '1026640341-56087-1 at 192.168.250.32'
> Dec 14 20:15:57 DEBUG[11374] chan_sip.c: Auto destroying
> call '1029587739-27554-1 at 192.168.250.32'
> Dec 14 20:15:57 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '055d25fe7a7fd6d268c05966457b0e35 at 10.215.147.111' of Request
> 102: Match Found
> Dec 14 20:15:58 DEBUG[11374] acl.c: ##### Testing
> 10.215.146.202 with 0.0.0.0
> Dec 14 20:15:58 DEBUG[11374] acl.c: ##### Testing
> 10.215.146.202 with 0.0.0.0
> Dec 14 20:15:58 DEBUG[11374] acl.c: ##### Testing
> 10.215.146.202 with 0.0.0.0
> Dec 14 20:15:58 DEBUG[11374] acl.c: ##### Testing
> 10.215.146.202 with 0.0.0.0
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '6fc6b5bb25efcb074cc5cd205ebd10ca at 192.168.250.111' of
> Request 102: Match Found
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '563978d273d799f40b17699a5a15fa5f at 192.168.250.111' of
> Request 102: Match Found
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '1209c14465a7e9983ae008002b35de90 at 10.215.147.111' of Request
> 102: Match Found
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '4750cd34753b75746ed4dbbb1044fe2e at 192.168.250.111' of
> Request 102: Match Found
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '2bbe75ff5234b8340baa00b6638ed508 at 10.215.147.111' of Request
> 102: Match Found
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '0627b0ab6ee80a12346318472096d0ff at 10.215.147.111' of Request
> 102: Match Found
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '099a35c745ac60ce6175164f513bcc0a at 10.215.147.111' of Request
> 102: Match Found
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Auto destroying
> call '655820725-43243-1 at 192.168.250.33'
> Dec 14 20:15:58 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 0.0.0.0
> Dec 14 20:15:58 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 127.0.0.1
> Dec 14 20:15:58 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 0.0.0.0
> Dec 14 20:15:58 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 127.0.0.1
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Auto destroying
> call '1300218108-26745-1 at 192.168.250.33'
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Auto destroying
> call '1451777419-40210-1 at 192.168.250.33'
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Auto destroying
> call '130829179-35800-1 at 192.168.250.33'
> Dec 14 20:15:58 DEBUG[11374] chan_sip.c: Auto destroying
> call '302046145-5060-1 at 192.168.250.30'
> Dec 14 20:15:59 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 0.0.0.0
> Dec 14 20:15:59 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 127.0.0.1
> Dec 14 20:15:59 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 0.0.0.0
> Dec 14 20:15:59 DEBUG[11375] acl.c: ##### Testing 127.0.0.1
> with 127.0.0.1
> Dec 14 20:15:59 DEBUG[11374] chan_sip.c: Auto destroying
> call '1003985022-58132-1 at 192.168.250.33'
> Dec 14 20:15:59 DEBUG[11374] chan_sip.c: Auto destroying
> call '2120692116-34217-1 at 192.168.250.33'
> Dec 14 20:15:59 DEBUG[11374] chan_sip.c: Auto destroying
> call '136564176-5062-1 at 192.168.250.30'
> Dec 14 20:15:59 DEBUG[11374] chan_sip.c: Auto destroying
> call 'DA87E117-A8EF-4A1B-B03E-8F91A5C26E22 at 10.215.144.47'
> Dec 14 20:15:59 DEBUG[15293] channel.c: Got DTMF on channel
> (mISDN/4-1)
> Dec 14 20:15:59 DEBUG[15293] channel.c: Bridge stops
> bridging channels mISDN/4-1 and Zap/3-1
> Dec 14 20:15:59 DEBUG[15293] res_features.c: Feature
> interpret: chan=mISDN/4-1, peer=Zap/3-1, sense=1,
> features=18
> Dec 14 20:16:00 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '796c12ae04837c495e9976a8235da32e at 192.168.250.111' of
> Request 102: Match Found
> Dec 14 20:16:00 DEBUG[15293] chan_zap.c: Exception on 31,
> channel 3
> Dec 14 20:16:00 DEBUG[15293] chan_zap.c: Got event Dial
> Complete(9) on channel 3 (index 0)
> Dec 14 20:16:00 DEBUG[15293] chan_zap.c: Echo cancellation
> already on
> Dec 14 20:16:00 DEBUG[11374] chan_sip.c: Auto destroying
> call '189453912-26133-1 at 192.168.250.33'
> Dec 14 20:16:00 DEBUG[11374] chan_sip.c: Auto destroying
> call '958801415-5064-1 at 192.168.250.30'
> Dec 14 20:16:00 DEBUG[11374] chan_sip.c: Auto destroying
> call 'd7a054a090a9d1a9 at 10.215.146.196'
> Dec 14 20:16:01 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '34a4e9b75f811d3a4c4ac61b5ee1b043 at 192.168.250.111' of
> Request 102: Match Found
> Dec 14 20:16:01 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '7d4a598770048e657b7c853f34e336ce at 10.215.147.111' of Request
> 102: Match Found
> Dec 14 20:16:01 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '51bc609a061eeeaf701aa9e540ffab22 at 192.168.250.111' of
> Request 102: Match Found
> Dec 14 20:16:01 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '7691917d5d96e11e0fea7c1764a0c3f9 at 192.168.250.111' of
> Request 102: Match Found
> Dec 14 20:16:01 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '566729374d92c0491184247b34329977 at 192.168.250.111' of
> Request 102: Match Found
> Dec 14 20:16:02 DEBUG[11374] chan_sip.c: Stopping
> retransmission on
> '6abe29ef642a3c9e68adb8e747472f8f at 192.168.250.111' of
> Request 102: Match Found
> Dec 14 20:16:02 DEBUG[15709] chan_zap.c: No such possible
> extension '61588' in context 'from-alcatel'
> 
> Not sure, but I don't see libpri passing the "extra"
> digit... chan_zap seems to detect it out of the blue. Could
> it be echo?

I don't think it's echo because 1) it's a PRI link between 2 PBXs, 2) there's an echo canceller.
On voip-info I read:
"Duplicate DTMF 
Change the setting relaxdtmf= and see if that helps 
If you appear to be receiving doubled DTMF signals then you are likely to get both inband and RFC2833 or SIP INFO signalling on your Asterisk box; you will want to make the sening party use only one of these two methods. 
Another possible cause would be that your telephony card has hardware-based DMTF detection turned on, coupled with the fact that Asterisk also detects the DTMF signal(s)."
I think I can discard the last 2 options (by the way, I don't think that my Digium TE120P has "hardware DTMF detection").
So I'm left with "relaxdtmf", I guess.

Vieri



      



More information about the asterisk-users mailing list