Some incoming calls no dtmf signals go through

Hello, we are having a problem that when some calls come into our system the dtmf tones are not heard. The person will call in and they get to the ivr menu. They hear the recording and press the appropriate number, but nothing happens. The system does not pick up the tone. They do not even register in the dtmf logs. We are running FreePBX 5.211 with Asterisk 11. Our incoming sip trunk is configured as:
type=friend
dtmfmode=auto
relaxdtmf=yes
username=username
secret=password
context=from-trunk ;
insecure=port,invite
canreinvite=no
host=vitelity.net

This configuration is suggested right from our provider. I have changed the dtmf mode to rfc2833, but that did not help either.

I am very new to this and would appreciate any help that anyone could provide. Please feel free to let me know if you need any additional information or have any ideas that I could try.

What codecs do you allow?

We have nothing defined in the trunk configuration, but on the Asterisk sip settings page we allow ulaw, alaw and gsm.

I have never had a problem with Vitelity using G711u and rfc2833, inbound, but consider adding DTMF to your logged events and debug that way.

I did have my logger set to log DTMF signals. The logger worked and it logged DTMF signals, however, at the times when the suspect calls came through, there was nothing in the dtmf logs. It is like the system did not hear anything at all.

That would depend on how you are handling DTMF decoding, if you are using rfc2833 it should be apparent in the sip debug messages, if you are using inband, then make sure you have signal ringing enabled on your inbound routes.going to the ivr.

Sorry for the delay, I did not get the notice that you replied. Dtmf decoding is set to auto in the trunk configuration. I have the signal ringing unchecked in the inbound route. The incoming calls are being routed directly to an ivr, could this be the issue? Is it recommended to set the dtmf decoding in the sip trunk to rfc2833?

I was able to turn on sip debug logging in the asterisk console, but how do I get that log into a file?

Also, is it recommended to define the audio codecs in the sip trunk configuration? The suggested configuration from Vitelity is what is shown above and what I put in place. Thank you for any help that you can provide.

I suggest you check the various scenarios one scenario at a time start with g711 and rfc=2833 and “signal ringing= yes”

If you turn on sip debugging it should be in your /var/log/asterisk/full log

Okay. I will make those changes this afternoon and let you know when I find something that could help more.

Thank you.

Okay, with those changes made I have had another incoming call where the dtmf tones were not heard. This time I was able to get a log capture with sip debugging on. I am having a hard time testing this since every test I run is successful. I only hear about the problem from clients who call and cant get through.

Thank you.

<------------->
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: — (14 headers 16 lines) —
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: Sending to 66.241.96.164:5060 (NAT)
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Sending to 66.241.96.164:5060 (NAT)
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Using INVITE request as basis request - [email protected]
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Found peer ‘vitel-inbound’ for ‘7406954742’ from 66.241.96.164:5060
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] netsock2.c: == Using SIP RTP TOS bits 184
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] netsock2.c: == Using SIP RTP CoS mark 5
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Found RTP audio format 0
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Found RTP audio format 8
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Found RTP audio format 3
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Found RTP audio format 18
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Found RTP audio format 101
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Found audio description format PCMU for ID 0
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Found audio description format PCMA for ID 8
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Found audio description format GSM for ID 3
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Found audio description format G729 for ID 18
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Found audio description format telephone-event for ID 101
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Capabilities: us - (ulaw), peer - audio=(gsm|ulaw|alaw|g729)/video=(nothing)/text=(nothing), combined - (ulaw)
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Peer audio RTP is at port 66.241.96.164:10144
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: Looking for 7174311244 in from-trunk (domain 66.109.247.70)
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c: list_route: hop: sip:[email protected]
[2014-09-15 12:43:27] VERBOSE[1884][C-00000219] chan_sip.c:
<— Transmitting (NAT) to 66.241.96.164:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 66.241.96.164:5060;branch=z9hG4bK20b2ac71;received=66.241.96.164;rport=5060
From: “7406954742” sip:[email protected];tag=as56b2a0ce
To: sip:[email protected]:43398
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.11.0(11.8.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [7174311244@from-trunk:1] Set(“SIP/vitel-inbound-00000385”, “__FROM_DID=7174311244”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [7174311244@from-trunk:2] Gosub(“SIP/vitel-inbound-00000385”, “app-blacklist-check,s,1()”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/vitel-inbound-00000385”, “0?blacklisted”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/vitel-inbound-00000385”, “CALLED_BLACKLIST=1”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/vitel-inbound-00000385”, “”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [7174311244@from-trunk:3] Set(“SIP/vitel-inbound-00000385”, “CDR(did)=7174311244”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [7174311244@from-trunk:4] ExecIf(“SIP/vitel-inbound-00000385”, “0 ?Set(CALLERID(name)=7406954742)”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [7174311244@from-trunk:5] Set(“SIP/vitel-inbound-00000385”, “CHANNEL(musicclass)=default”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [7174311244@from-trunk:6] Set(“SIP/vitel-inbound-00000385”, “__MOHCLASS=default”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [7174311244@from-trunk:7] Ringing(“SIP/vitel-inbound-00000385”, “”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] chan_sip.c:
<— Transmitting (NAT) to 66.241.96.164:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 66.241.96.164:5060;branch=z9hG4bK20b2ac71;received=66.241.96.164;rport=5060
From: “7406954742” sip:[email protected];tag=as56b2a0ce
To: sip:[email protected]:43398;tag=as44c738f2
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.11.0(11.8.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [7174311244@from-trunk:8] Set(“SIP/vitel-inbound-00000385”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [7174311244@from-trunk:9] Set(“SIP/vitel-inbound-00000385”, “CALLERPRES()=allowed_not_screened”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [7174311244@from-trunk:10] Goto(“SIP/vitel-inbound-00000385”, “ivr-1,s,1”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Goto (ivr-1,s,1)
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:1] Set(“SIP/vitel-inbound-00000385”, “TIMEOUT_LOOPCOUNT=0”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:2] Set(“SIP/vitel-inbound-00000385”, “INVALID_LOOPCOUNT=0”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:3] Set(“SIP/vitel-inbound-00000385”, “_IVR_CONTEXT_ivr-1=”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:4] Set(“SIP/vitel-inbound-00000385”, “_IVR_CONTEXT=ivr-1”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:5] Set(“SIP/vitel-inbound-00000385”, “__IVR_RETVM=”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:6] GotoIf(“SIP/vitel-inbound-00000385”, “0?skip”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:7] Answer(“SIP/vitel-inbound-00000385”, “”) in new stack
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] chan_sip.c: Audio is at 12114
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] chan_sip.c: Adding codec 100003 (ulaw) to SDP
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2014-09-15 12:43:27] VERBOSE[21039][C-00000219] chan_sip.c:
<— Reliably Transmitting (NAT) to 66.241.96.164:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 66.241.96.164:5060;branch=z9hG4bK20b2ac71;received=66.241.96.164;rport=5060
From: “7406954742” sip:[email protected];tag=as56b2a0ce
To: sip:[email protected]:43398;tag=as44c738f2
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.11.0(11.8.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:[email protected]:5060
Content-Type: application/sdp
Content-Length: 237

v=0
o=root 1192689672 1192689672 IN IP4 66.109.247.70
s=Asterisk PBX 11.8.1
c=IN IP4 66.109.247.70
t=0 0
m=audio 12114 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<------------>
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c:
<— SIP read from UDP:66.241.96.164:5060 —>
ACK sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 66.241.96.164:5060;branch=z9hG4bK540d33db;rport
From: “7406954742” sip:[email protected];tag=as56b2a0ce
To: sip:[email protected]:43398;tag=as44c738f2
Contact: sip:[email protected]
Call-ID: [email protected]
CSeq: 102 ACK
User-Agent: packetrino
Max-Forwards: 70
Content-Length: 0

<------------->
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: — (10 headers 0 lines) —
[2014-09-15 12:43:27] NOTICE[1884] chan_sip.c: – Re-registration for [email protected]
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: REGISTER 11 headers, 0 lines
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: Reliably Transmitting (NAT) to 66.241.96.164:5060:
REGISTER sip:inbound24.vitelity.net SIP/2.0
Via: SIP/2.0/UDP 66.109.247.70:5060;branch=z9hG4bK2c87943b;rport
Max-Forwards: 70
From: sip:[email protected];tag=as696e4d8c
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 11008 REGISTER
User-Agent: FPBX-2.11.0(11.8.1)
Authorization: Digest username=“john_lanc”, realm=“asterisk”, algorithm=MD5, uri=“sip:inbound24.vitelity.net”, nonce=“6863c4f2”, response="b12c637986c57c7ab8236fd824230da5"
Expires: 120
Contact: sip:[email protected]:5060
Content-Length: 0


[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c:
<— SIP read from UDP:66.241.96.164:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 66.109.247.70:5060;branch=z9hG4bK2c87943b;received=66.109.247.70;rport=43398
From: sip:[email protected];tag=as696e4d8c
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 11008 REGISTER
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0

<------------->
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: — (10 headers 0 lines) —
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c:
<— SIP read from UDP:66.241.96.164:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 66.109.247.70:5060;branch=z9hG4bK2c87943b;received=66.109.247.70;rport=43398
From: sip:[email protected];tag=as696e4d8c
To: sip:[email protected];tag=as784e9408
Call-ID: [email protected]
CSeq: 11008 REGISTER
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="4f0134d6"
Content-Length: 0

<------------->
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: — (11 headers 0 lines) —
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: Responding to challenge, registration to domain/host name inbound24.vitelity.net
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: REGISTER 11 headers, 0 lines
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: Reliably Transmitting (NAT) to 66.241.96.164:5060:
REGISTER sip:inbound24.vitelity.net SIP/2.0
Via: SIP/2.0/UDP 66.109.247.70:5060;branch=z9hG4bK0b1aca43;rport
Max-Forwards: 70
From: sip:[email protected];tag=as696e4d8c
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 11009 REGISTER
User-Agent: FPBX-2.11.0(11.8.1)
Authorization: Digest username=“john_lanc”, realm=“asterisk”, algorithm=MD5, uri=“sip:inbound24.vitelity.net”, nonce=“4f0134d6”, response="1597ce9d40fc0662502d561e586d2077"
Expires: 120
Contact: sip:[email protected]:5060
Content-Length: 0


[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c:
<— SIP read from UDP:66.241.96.164:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 66.109.247.70:5060;branch=z9hG4bK0b1aca43;received=66.109.247.70;rport=43398
From: sip:[email protected];tag=as696e4d8c
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 11009 REGISTER
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0

<------------->
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: — (10 headers 0 lines) —
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c:
<— SIP read from UDP:66.241.96.164:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 66.109.247.70:5060;branch=z9hG4bK0b1aca43;received=66.109.247.70;rport=43398
From: sip:[email protected];tag=as696e4d8c
To: sip:[email protected];tag=as784e9408
Call-ID: [email protected]
CSeq: 11009 REGISTER
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Expires: 60
Contact: sip:[email protected]:5060;expires=60
Date: Mon, 15 Sep 2014 16:43:27 GMT
Content-Length: 0

<------------->
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: — (13 headers 0 lines) —
[2014-09-15 12:43:27] NOTICE[1884] chan_sip.c: Outbound Registration: Expiry for inbound24.vitelity.net is 60 sec (Scheduling reregistration in 45 s)
[2014-09-15 12:43:27] VERBOSE[1884] chan_sip.c: Really destroying SIP dialog ‘[email protected]’ Method: REGISTER
[2014-09-15 12:43:28] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:8] Wait(“SIP/vitel-inbound-00000385”, “1”) in new stack
[2014-09-15 12:43:29] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:9] Set(“SIP/vitel-inbound-00000385”, “IVR_MSG=custom/Lancaster_Greeting2”) in new stack
[2014-09-15 12:43:29] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:10] Set(“SIP/vitel-inbound-00000385”, “TIMEOUT(digit)=3”) in new stack
[2014-09-15 12:43:29] VERBOSE[21039][C-00000219] func_timeout.c: – Digit timeout set to 3.000
[2014-09-15 12:43:29] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:11] ExecIf(“SIP/vitel-inbound-00000385”, “1?Background(custom/Lancaster_Greeting2)”) in new stack
[2014-09-15 12:43:29] VERBOSE[21039][C-00000219] file.c: – <SIP/vitel-inbound-00000385> Playing ‘custom/Lancaster_Greeting2.slin’ (language ‘en’)
[2014-09-15 12:43:32] VERBOSE[1884] chan_sip.c: Reliably Transmitting (NAT) to 10.10.58.115:5060:
OPTIONS sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.10.58.2:5060;branch=z9hG4bK08a72873;rport
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as02074c9e
To: sip:[email protected]
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-2.11.0(11.8.1)
Date: Mon, 15 Sep 2014 16:43:32 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


[2014-09-15 12:43:32] VERBOSE[1884] chan_sip.c:
<— SIP read from UDP:10.10.58.115:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.58.2:5060;branch=z9hG4bK08a72873;rport
From: “Unknown” sip:[email protected];tag=as02074c9e
To: sip:[email protected];tag=82FBDBF4-8C6C885D
CSeq: 102 OPTIONS
Call-ID: [email protected]:5060
Contact: sip:[email protected]
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_501-UA/3.1.8.0070
Accept-Language: en
Accept: application/sdp,text/plain,message/sipfrag,application/dialog-info+xml
Accept-Encoding: identity
Supported: 100rel,timer,replaces
Content-Length: 0

<------------->
[2014-09-15 12:43:32] VERBOSE[1884] chan_sip.c: — (14 headers 0 lines) —
[2014-09-15 12:43:32] VERBOSE[1884] chan_sip.c: Really destroying SIP dialog ‘[email protected]:5060’ Method: OPTIONS
[2014-09-15 12:43:34] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:12] WaitExten(“SIP/vitel-inbound-00000385”, “10,”) in new stack
[2014-09-15 12:43:36] VERBOSE[1884] chan_sip.c: Reliably Transmitting (NAT) to 10.10.58.103:5060:
OPTIONS sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.10.58.2:5060;branch=z9hG4bK619d8072;rport
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as604b06e9
To: sip:[email protected]
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-2.11.0(11.8.1)
Date: Mon, 15 Sep 2014 16:43:36 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


[2014-09-15 12:43:36] VERBOSE[1884] chan_sip.c:
<— SIP read from UDP:10.10.58.103:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.58.2:5060;branch=z9hG4bK619d8072;rport
From: “Unknown” sip:[email protected];tag=as604b06e9
To: sip:[email protected];tag=D0EE2049-8E949874
CSeq: 102 OPTIONS
Call-ID: [email protected]:5060
Contact: sip:[email protected]
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_501-UA/3.1.8.0070
Accept-Language: en
Accept: application/sdp,text/plain,message/sipfrag,application/dialog-info+xml
Accept-Encoding: identity
Supported: 100rel,timer,replaces
Content-Length: 0

<------------->
[2014-09-15 12:43:36] VERBOSE[1884] chan_sip.c: — (14 headers 0 lines) —
[2014-09-15 12:43:36] VERBOSE[1884] chan_sip.c: Really destroying SIP dialog ‘[email protected]:5060’ Method: OPTIONS
[2014-09-15 12:43:37] VERBOSE[1884] chan_sip.c: Reliably Transmitting (NAT) to 10.10.58.114:5060:
OPTIONS sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.10.58.2:5060;branch=z9hG4bK4e6b0a0c;rport
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as6ae29618
To: sip:[email protected]
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-2.11.0(11.8.1)
Date: Mon, 15 Sep 2014 16:43:37 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


[2014-09-15 12:43:37] VERBOSE[1884] chan_sip.c:
<— SIP read from UDP:10.10.58.114:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.58.2:5060;branch=z9hG4bK4e6b0a0c;rport
From: “Unknown” sip:[email protected];tag=as6ae29618
To: sip:[email protected];tag=901C2DE3-F7601454
CSeq: 102 OPTIONS
Call-ID: [email protected]:5060
Contact: sip:[email protected]
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_501-UA/3.1.8.0070
Accept-Language: en
Accept: application/sdp,text/plain,message/sipfrag,application/dialog-info+xml
Accept-Encoding: identity
Supported: 100rel,timer,replaces
Content-Length: 0

<------------->
[2014-09-15 12:43:37] VERBOSE[1884] chan_sip.c: — (14 headers 0 lines) —
[2014-09-15 12:43:37] VERBOSE[1884] chan_sip.c: Really destroying SIP dialog ‘[email protected]:5060’ Method: OPTIONS
[2014-09-15 12:43:39] VERBOSE[1884] chan_sip.c: Reliably Transmitting (NAT) to 10.10.58.102:5060:
OPTIONS sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.10.58.2:5060;branch=z9hG4bK16f18cfd;rport
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as0a4cae49
To: sip:[email protected]
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-2.11.0(11.8.1)
Date: Mon, 15 Sep 2014 16:43:39 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


[2014-09-15 12:43:39] VERBOSE[1884] chan_sip.c:
<— SIP read from UDP:10.10.58.102:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.58.2:5060;branch=z9hG4bK16f18cfd;rport
From: “Unknown” sip:[email protected];tag=as0a4cae49
To: sip:[email protected];tag=55AD663-70377268
CSeq: 102 OPTIONS
Call-ID: [email protected]:5060
Contact: sip:[email protected]
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_501-UA/3.1.8.0070
Accept-Language: en
Accept: application/sdp,text/plain,message/sipfrag,application/dialog-info+xml
Accept-Encoding: identity
Supported: 100rel,timer,replaces
Content-Length: 0

<------------->
[2014-09-15 12:43:39] VERBOSE[1884] chan_sip.c: — (14 headers 0 lines) —
[2014-09-15 12:43:39] VERBOSE[1884] chan_sip.c: Really destroying SIP dialog ‘[email protected]:5060’ Method: OPTIONS
[2014-09-15 12:43:41] VERBOSE[1884] chan_sip.c: Reliably Transmitting (NAT) to 10.10.58.101:5060:
OPTIONS sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.10.58.2:5060;branch=z9hG4bK7a38aeb7;rport
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as65272843
To: sip:[email protected]
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-2.11.0(11.8.1)
Date: Mon, 15 Sep 2014 16:43:41 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


[2014-09-15 12:43:42] VERBOSE[1884] chan_sip.c:
<— SIP read from UDP:10.10.58.101:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.58.2:5060;branch=z9hG4bK7a38aeb7;rport
From: “Unknown” sip:[email protected];tag=as65272843
To: sip:[email protected];tag=97E553CA-495EBC69
CSeq: 102 OPTIONS
Call-ID: [email protected]:5060
Contact: sip:[email protected]
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_501-UA/3.1.8.0070
Accept-Language: en
Accept: application/sdp,text/plain,message/sipfrag,application/dialog-info+xml
Accept-Encoding: identity
Supported: 100rel,timer,replaces
Content-Length: 0

<------------->
[2014-09-15 12:43:42] VERBOSE[1884] chan_sip.c: — (14 headers 0 lines) —
[2014-09-15 12:43:42] VERBOSE[1884] chan_sip.c: Really destroying SIP dialog ‘[email protected]:5060’ Method: OPTIONS
[2014-09-15 12:43:44] VERBOSE[21039][C-00000219] pbx.c: – Timeout on SIP/vitel-inbound-00000385, going to ‘t’
[2014-09-15 12:43:44] VERBOSE[21039][C-00000219] pbx.c: – Executing [t@ivr-1:1] Set(“SIP/vitel-inbound-00000385”, “TIMEOUT_LOOPCOUNT=1”) in new stack
[2014-09-15 12:43:44] VERBOSE[21039][C-00000219] pbx.c: – Executing [t@ivr-1:2] GotoIf(“SIP/vitel-inbound-00000385”, “0?final”) in new stack
[2014-09-15 12:43:44] VERBOSE[21039][C-00000219] pbx.c: – Executing [t@ivr-1:3] Set(“SIP/vitel-inbound-00000385”, “IVR_MSG=no-valid-responce-pls-try-again”) in new stack
[2014-09-15 12:43:44] VERBOSE[21039][C-00000219] pbx.c: – Executing [t@ivr-1:4] Goto(“SIP/vitel-inbound-00000385”, “s,start”) in new stack
[2014-09-15 12:43:44] VERBOSE[21039][C-00000219] pbx.c: – Goto (ivr-1,s,10)
[2014-09-15 12:43:44] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:10] Set(“SIP/vitel-inbound-00000385”, “TIMEOUT(digit)=3”) in new stack
[2014-09-15 12:43:44] VERBOSE[21039][C-00000219] func_timeout.c: – Digit timeout set to 3.000
[2014-09-15 12:43:44] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:11] ExecIf(“SIP/vitel-inbound-00000385”, “1?Background(no-valid-responce-pls-try-again)”) in new stack
[2014-09-15 12:43:44] VERBOSE[21039][C-00000219] file.c: – <SIP/vitel-inbound-00000385> Playing ‘no-valid-responce-pls-try-again.slin’ (language ‘en’)
[2014-09-15 12:43:48] VERBOSE[21039][C-00000219] pbx.c: – Executing [s@ivr-1:12] WaitExten(“SIP/vitel-inbound-00000385”, “10,”) in new stack
[2014-09-15 12:43:53] VERBOSE[1884] chan_sip.c: Reliably Transmitting (NAT) to 10.10.58.109:5060:
OPTIONS sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.10.58.2:5060;branch=z9hG4bK40614997;rport
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as3728846a
To: sip:[email protected]
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-2.11.0(11.8.1)
Date: Mon, 15 Sep 2014 16:43:53 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

Hmmm no dtmf here coming in (you have dtmf logging on, right? ) . . . You might try adding:-

rfc2833compensate=yes

otherwise send that log to Vitelity

Yes, dtmf logging is on. I had sent that log to Vitelity. Their response was “We are unable to reproduce any issues on our end. If the same people continually have issues, it is likely an issue with their terminating carrier. I see that 7406954742 is a Comcast number. It is very likely there is an issue on their end causing DTMF issues. If you can provide a pcap of a problem call, that may help us narrow down the issue.”

I just found the rfc2833compensate=yes and applied that to the trunk this afternoon. I am going to try to contact that person and ask them to try to get a hold of me again. I will update you on what happens. Thank you for your help.

Ah!! Comcast! a well known standards compliant carrier :wink:

In Comcast we trust.

Maybe a custom inbound route for that Caller (and others like it) invoking

SIPdtmfmode(inband)

Hey Dicko. So it looks like that setting the dtmfmode to inband only superficially fixed the issue. The system is recording 3 incoming dtmf signals when the person presses a button. Since we had direct dial enabled the three numbers were fix to an extension (in this case 111 or 222) and routed there. In the past 2 days that extension was changed and we realized that the routing of the calls was wrong.

Here is the trunk config, can you let me know if anything jumps out at you that is wrong? Again, we are running the freepbx distro 5.211 with Asterisk 11. Signal ringing is enabled on all of the incoming routes. I have also added an excerpt of the log with the multiple dtmf tones. Is there somewhere I can check what freepbx is expecting for the tone duration of the dtmf signal?

type=friend
dtmfmode=inband
rfc2833compensate=yes
relaxdtmf=yes
username=username
secret=secret
context=from-trunk ; (this could be ext-did or from-pstn as well)
insecure=port,invite
canreinvite=no
host=inbound24.vitelity.net
disallow=all
allow=ulaw

[2014-10-02 09:53:30] DTMF[8623][C-000006af] channel.c: DTMF end ‘2’ received on SIP/vitel-inbound-0000112e, duration 0 ms
[2014-10-02 09:53:30] DTMF[8623][C-000006af] channel.c: DTMF end accepted without begin ‘2’ on SIP/vitel-inbound-0000112e
[2014-10-02 09:53:30] DTMF[8623][C-000006af] channel.c: DTMF end passthrough ‘2’ on SIP/vitel-inbound-0000112e
[2014-10-02 09:53:30] DTMF[8623][C-000006af] channel.c: DTMF end ‘2’ received on SIP/vitel-inbound-0000112e, duration 0 ms
[2014-10-02 09:53:30] DTMF[8623][C-000006af] channel.c: DTMF end accepted without begin ‘2’ on SIP/vitel-inbound-0000112e
[2014-10-02 09:53:30] DTMF[8623][C-000006af] channel.c: DTMF end passthrough ‘2’ on SIP/vitel-inbound-0000112e
[2014-10-02 09:53:31] DTMF[8623][C-000006af] channel.c: DTMF end ‘2’ received on SIP/vitel-inbound-0000112e, duration 0 ms
[2014-10-02 09:53:31] DTMF[8623][C-000006af] channel.c: DTMF end accepted without begin ‘2’ on SIP/vitel-inbound-0000112e
[2014-10-02 09:53:31] DTMF[8623][C-000006af] channel.c: DTMF end passthrough ‘2’ on SIP/vitel-inbound-0000112e

I would not have relaxdtmf=yes, it only increases the likelehood of talk-off

Alright, I removed the relaxed dtmf line from the trunk config and I am going to watch the logs and see what happens.

Looks like it is still pulling multiple dtmf tones when a person only presses the button once. Any ideas?

Not really, take it to Vitelity.