JK
2007-May-24 21:40 UTC
[asterisk-users] Urgent: DTMF does not work with rtpmap:101 telephone-event/8000
Hello asterisk-users list.
I have been scratching my head for almost a week. We are trying to set a
service with a company (ip=XXX.XXX.XXX.XXX) and dtmf is not working.
In our scenario the SP 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@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
.216.2.212;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@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@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@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@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-users/attachments/20070524/5b4d0609/attachment-0001.htm
Alex Balashov
2007-May-24 21:47 UTC
[asterisk-users] Urgent: DTMF does not work with rtpmap:101 telephone-event/8000
JK, In-band or RFC2833 DTMF signaling? Also, unless you have SER configured with a media proxy, the actual "call" is not running through SER. It's a signaling proxy only. -- Alex Balashov Evariste Systems Web : http://www.evaristesys.com/ Tel : +1-678-954-0670
Doug
2007-May-25 10:03 UTC
[asterisk-users] Urgent: DTMF does not work with rtpmap:101 telephone-event/8000
At 23:40 5/24/2007, JK wrote:>Hello asterisk-users list. >I have been scratching my head for almost a week. We are trying to >set a service with a company (ip=XXX.XXX.XXX.XXX) and dtmf is not working.Have had better luck with "SIP Info".
Olle E Johansson
2007-May-28 07:17 UTC
[asterisk-users] Urgent: DTMF does not work with rtpmap:101 telephone-event/8000
25 maj 2007 kl. 06.40 skrev JK:> Hello asterisk-users list. > I have been scratching my head for almost a week. We are trying to > set a service with a company (ip=XXX.XXX.XXX.XXX) and dtmf is not > working. > In our scenario the SP 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.Your debug did not have any SIP messages. I need to see the INVITE and the 200 OK. Thanks. /O
Possibly Parallel Threads
- Re: asterisk-users Digest, Vol 34, Issue 114
- Urgent: DTMF does not work with, rtpmap:101 telephone-event/8000
- Audiocodes MP124-FXS replying BUSY when line is not.
- Asterisk 11.23.0 on CentOS6 : how to get ICE support ?
- SDP messages relating to rtpmap Question