[asterisk-dev] Re: Urgent: DTMF does not work with rtpmap:101

Paul ast2005 at 9ux.com
Sun May 27 08:31:01 MST 2007


I think this belongs on the -users list. It looks like a configuration
question. Possibly it is more related to ser than asterisk.

JK wrote:

> Anyone please??
>
>
>
> -JK
> Message: 5
> Date: Sat, 26 May 2007 22:46:26 -0700
> From: JK <jk at bingoconsulting.com>
> Subject: [asterisk-dev] Urgent: DTMF does not work with rtpmap:101
>     telephone-event/8000
> To: asterisk-dev at lists.digium.com
> Message-ID: <46591B32.4070703 at bingoconsulting.com>
> Content-Type: text/plain; charset="iso-8859-1"
>
> Hello Developers,
> I am using Asterisk-1.2.12.1.
>
> I have been scratching my head for almost a week. We are trying to set
> a service with verizon (ip=XXX.XXX.XXX.XXX) and dtmf is not working.
> In our scenario  verizon is sending call to our ser server and ser is
> forwarding the call to asterisk. In the asterisk debug I can see the
> DTMF keys are coming but ivr does not recognice those keys at all. I
> can see this in the debug. We are using ulaw and alaw for codec.
>
> *May 24 20:14:00 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:01 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:01 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX*
>
>
> Voice part works great. I mean if I forward that call to asterisk sip
> user we can talk.
> Every thing is working great with other SP. The only difference I can
> see is the rtpmap:101 telephone-event/8000.
> With the working SP the rtpmap is rtpmap:100 telephone-event/8000.
>
> I need solution ASAP, so please give me any hint you can.
>
> Here is complete debug log for one call.
>
> May 24 20:13:47 DEBUG[26583] chan_sip.c: Allocating new SIP dialog for
> 9CB80474-
> 98311DC-86A1C9BE-38B97399 at XXX.XXX.XXX.XXX - INVITE (With RTP)
> May 24 20:13:47 DEBUG[26583] chan_sip.c: **** Received INVITE (5) -
> Command in S
> IP INVITE
> May 24 20:13:47 DEBUG[26583] res_config_mysql.c: MySQL RealTime:
> Everything is f
> ine.
> May 24 20:13:47 DEBUG[26583] res_config_mysql.c: MySQL RealTime:
> Retrieve SQL: S
> ELECT * FROM cc_sip_buddies WHERE name = '6056911122'
> May 24 20:13:47 DEBUG[26583] chan_sip.c: Setting NAT on RTP to 0
> May 24 20:13:47 DEBUG[26583] chan_sip.c: Checking SIP call limits for
> device
> May 24 20:13:47 DEBUG[26583] chan_sip.c: Updating call counter for
> incoming call
> May 24 20:13:47 DEBUG[26583] chan_sip.c: build_route: Record-Route
> hop: <sip:209.zzz.zzz.zzz;ftag=E3F05090-621;lr=on>
> May 24 20:13:47 DEBUG[26583] chan_sip.c: build_route: Record-Route
> hop: <sip:zzz.zzz.zzz.zzz;ftag=E3F05090-621;lr=on>
> May 24 20:13:47 DEBUG[26583] chan_sip.c: build_route: Record-Route
> hop: <sip:yy-proxy-ip.yy;lr>
> May 24 20:13:47 DEBUG[26574] chan_sip.c: Checking device state for
> peer XXX.XXX.XXXX.XXX
> May 24 20:13:47 DEBUG[26803] pbx.c: Launching 'NoOp'
> May 24 20:13:47 DEBUG[26574] devicestate.c: Changing state for
> SIP/XXX.XXX.XXX.XXX -
> state 2 (In use)
> May 24 20:13:47 DEBUG[26804] app_queue.c: Device 'SIP/XXX.XXX.XXX.XXX'
> changed to st
> ate '2' (In use) but we don't care because they're not a member of any
> queue.
> May 24 20:13:47 DEBUG[26803] pbx.c: Launching 'Goto'
> May 24 20:13:47 DEBUG[26803] pbx.c: Launching 'Set'
> May 24 20:13:47 DEBUG[26803] pbx.c: Launching 'Goto'
> May 24 20:13:47 DEBUG[26803] pbx.c: Launching 'Set'
> May 24 20:13:47 DEBUG[26803] pbx.c: Launching 'Set'
> May 24 20:13:47 DEBUG[26803] pbx.c: Launching 'Answer'
> May 24 20:13:47 DEBUG[26803] chan_sip.c:
> sip_answer(SIP/XXX.XXX.XXX.XXX-b7b03730)
> May 24 20:13:47 DEBUG[26574] chan_sip.c: Checking device state for
> peer XXX.XXX.XXXX.XXX
> May 24 20:13:47 DEBUG[26574] channel.c: Avoiding initial deadlock for
> 'SIP/XXX.XXX.XXXX.XXX-b7b03730'
> May 24 20:13:47 DEBUG[26803] pbx.c: Launching 'Wait'
> May 24 20:13:47 DEBUG[26574] devicestate.c: Changing state for
> SIP/XXX.XXX.XXX.XXX -
> state 2 (In use)
> May 24 20:13:47 DEBUG[26805] app_queue.c: Device 'SIP/XXX.XXX.XXX.XXX'
> changed to st
> ate '2' (In use) but we don't care because they're not a member of any
> queue.
> May 24 20:13:47 DEBUG[26583] chan_sip.c: = Found Their Call ID:
> 9CB80474-98311DC
> -86A1C9BE-38B97399 at XXX.XXX.XXX.XXX Their Tag E3F05090-621 Our tag:
> as3becafbb
> May 24 20:13:47 DEBUG[26583] chan_sip.c: **** Received ACK (6) -
> Command in SIP
> ACK
> May 24 20:13:47 DEBUG[26583] chan_sip.c: Stopping retransmission on
> '9CB80474-98
> 311DC-86A1C9BE-38B97399 at XXX.XXX.XXX.XXX' of Response 101: Match Found
> May 24 20:13:48 DEBUG[26803] pbx.c: Launching 'Set'
> May 24 20:13:48 DEBUG[26803] pbx.c: Launching 'Set'
> May 24 20:13:48 DEBUG[26803] pbx.c: Launching 'BackGround'
> May 24 20:13:48 DEBUG[26803] channel.c: Set channel
> SIP/XXX.XXX.XXX.XXX-b7b03730 to
> write format slin
> May 24 20:13:48 DEBUG[26803] rtp.c: Ooh, format changed from unknown
> to ulaw
> May 24 20:13:48 DEBUG[26803] channel.c: Scheduling timer at 160 sample
> intervals
> May 24 20:13:49 DEBUG[26803] rtp.c: Got RTCP report of 132 bytes
> May 24 20:13:52 DEBUG[26803] rtp.c: Got RTCP report of 132 bytes
> May 24 20:13:53 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:13:58 DEBUG[26803] rtp.c: Got RTCP report of 132 bytes
> May 24 20:14:00 DEBUG[26803] channel.c: Scheduling timer at 58 sample
> intervals
> May 24 20:14:00 DEBUG[26803] channel.c: Scheduling timer at 0 sample
> intervals
> May 24 20:14:00 DEBUG[26803] channel.c: Scheduling timer at 0 sample
> intervals
> May 24 20:14:00 DEBUG[26803] channel.c: Set channel
> SIP/XXX.XXX.XXX.XXX-b7b03730 to
> write format ulaw
> May 24 20:14:00 DEBUG[26803] res_config_mysql.c: MySQL RealTime:
> Everything is f
> ine.
> May 24 20:14:00 DEBUG[26803] res_config_mysql.c: MySQL RealTime:
> Retrieve SQL: S
> ELECT * FROM extensions WHERE exten = 's' AND context = 'ext-local'
> AND priority
> = '8'
> May 24 20:14:00 DEBUG[26803] res_config_mysql.c: MySQL RealTime:
> Everything is f
> ine.
> May 24 20:14:00 DEBUG[26803] res_config_mysql.c: MySQL RealTime:
> Retrieve SQL: S
> ELECT * FROM extensions WHERE exten LIKE '\\_%' AND context =
> 'ext-local' AND pr
> iority = '8' ORDER BY exten
> *May 24 20:14:00 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:01 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:01 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:01 DEBUG[26803] rtp.c: Got RTCP report of 132 bytes
> May 24 20:14:01 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:02 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:02 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:02 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:03 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:03 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:03 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:04 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:04 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX
> May 24 20:14:04 DEBUG[26803] rtp.c: Sending dtmf: 49 (1), at
> XXX.XXX.XXX.XXX*
> May 24 20:14:07 DEBUG[26803] rtp.c: Got RTCP report of 108 bytes
> May 24 20:14:09 DEBUG[26803] rtp.c: Got RTCP report of 44 bytes
> May 24 20:14:09 DEBUG[26583] chan_sip.c: = Found Their Call ID:
> 9CB80474-98311DC
> -86A1C9BE-38B97399 at XXX.XXX.XXX.XXX Their Tag E3F05090-621 Our tag:
> as3becafbb
> May 24 20:14:09 DEBUG[26583] chan_sip.c: **** Received BYE (8) -
> Command in SIP
> BYE
> May 24 20:14:09 DEBUG[26583] chan_sip.c: Received bye, issuing owner
> hangup
> .May 24 20:14:09 DEBUG[26803] pbx.c: Launching 'Hangup'
> May 24 20:14:09 DEBUG[26803] pbx.c: Spawn extension (ivr-2,h,1) exited
> non-zero
> on 'SIP/XXX.XXX.XXX.XXX-b7b03730'
> May 24 20:14:09 DEBUG[26803] cdr_addon_mysql.c: cdr_mysql: inserting a
> CDR recor
> d.
> May 24 20:14:09 DEBUG[26803] cdr_addon_mysql.c: cdr_mysql: SQL command
> as follow
> s: INSERT INTO cdr
> (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,la
> stdata,duration,billsec,disposition,amaflags,accountcode) VALUES
> ('2007-05-24 20
> :13:47','6056911122','6056911122','s','ivr-2',
> 'SIP/XXX.XXX.XXX.XXX-b7b03730','','Ha
> ngup','',22,22,'ANSWERED',3,'')
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '6056911122'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '6056911122'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is 's'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is 'ivr-2'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is
> 'SIP/XXX.XXX.XXX.XXX-b7b03730
> '
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '(null)'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is 'Hangup'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '(null)'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '2007-05-24
> 20:13:47'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '2007-05-24
> 20:13:47'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '2007-05-24
> 20:14:09'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '22'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '22'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is 'ANSWERED'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is 'DOCUMENTATION'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '(null)'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '1180062827.5'
> May 24 20:14:09 DEBUG[26803] pbx.c: Function result is '(null)'
> May 24 20:14:09 DEBUG[26803] channel.c: Hanging up channel
> 'SIP/XXX.XXX.XXX.XXX-b7b0
> 3730'
> May 24 20:14:09 DEBUG[26803] chan_sip.c: Hangup call
> SIP/XXX.XXX.XXX.XXX-b7b03730, S
> IP callid 9CB80474-98311DC-86A1C9BE-38B97399 at XXX.XXX.XXX.XXX)
> May 24 20:14:09 DEBUG[26803] chan_sip.c: update_call_counter() -
> decrement call
> limit counter
> May 24 20:14:09 DEBUG[26803] chan_sip.c: Updating call counter for
> incoming call
> May 24 20:14:09 DEBUG[26574] chan_sip.c: Checking device state for
> peer XXX.XXX.XXXX.XXX
> May 24 20:14:09 DEBUG[26574] devicestate.c: Changing state for
> SIP/XXX.XXX.XXX.XXX -
> state 1 (Not in use)
> May 24 20:14:09 DEBUG[26809] app_queue.c: Device 'SIP/XXX.XXX.XXX.XXX'
> changed to st
> ate '1' (Not in use) but we don't care because they're not a member of
> any queue
>
> -------------- next part --------------
> An HTML attachment was scrubbed...
> URL:
> http://lists.digium.com/pipermail/asterisk-dev/attachments/20070525/9ac1c3df/attachment.htm
>
>
> ------------------------------
>
> _______________________________________________
> --Bandwidth and Colocation provided by Easynews.com --
>
> asterisk-dev mailing list
> To UNSUBSCRIBE or update options visit:
>   http://lists.digium.com/mailman/listinfo/asterisk-dev




More information about the asterisk-dev mailing list