DTMF Tone "#" is not submitted correctly (including log)

[[email protected]]

Hi Developers,

we have the same problem with DTMF. I can't tell you much about SIP headers or something like this, but...

...we have an Asterisk 1.4 PBX. Your "iPhone" connects to it via SIP. Everything works fine except if you try to log in to the Asterisk Voice Mail System. In my example, you have to dial *97 (what works). Asterisk now asks for the Voice Mail password. Typing the correct password "518518", followed by a "#" isn't submitted correctly, see debug below. Instead your phone submits it as "51581581851". With other Softphones it works.

Hope that helps. It would be nice if you could launch an immediate fix for this bug.


Best Regards
An Asterisk User


<------------->
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
INVITE sip:*97@srv-pbx:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-9f661c4c0f65800b-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: <sip:*97@srv-pbx:5060>
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO
Content-Type: application/sdp
Supported: replaces
User-Agent: 3CXPhone 4.0.10858.0
Content-Length: 282

v=0
o=3cxVCE 35343735 29479860 IN IP4 10.1.1.118
s=3cxVCE Audio Call
c=IN IP4 10.1.1.118
t=0 0
m=audio 40014 RTP/AVP 8 0 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

<------------->
--- (13 headers 13 lines) ---
Sending to 10.1.1.118 : 3653 (no NAT)
Using INVITE request as basis request - ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
srv-pbx*CLI>
<--- Reliably Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-9f661c4c0f65800b-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
To: <sip:*97@srv-pbx:5060>;tag=as5c6af395
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="48a38d6a"
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog 'ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.' in 32000 ms (Method: INVITE)
Found user '518'
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
ACK sip:*97@srv-pbx:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-9f661c4c0f65800b-1---d8754z-;rport
Max-Forwards: 70
To: <sip:*97@srv-pbx:5060>;tag=as5c6af395
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 1 ACK
Content-Length: 0


<------------->
--- (8 headers 0 lines) ---
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
INVITE sip:*97@srv-pbx:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-c17b7f4f57297601-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: <sip:*97@srv-pbx:5060>
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 2 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO
Content-Type: application/sdp
Proxy-Authorization: Digest username="518",realm="asterisk",nonce="48a38d6a",uri="sip:*97@srv-pbx:5060",response="8d9e5ad3750cf9812a61f8b496f9a422",algorithm=MD5
Supported: replaces
User-Agent: 3CXPhone 4.0.10858.0
Content-Length: 282

v=0
o=3cxVCE 35343735 29479860 IN IP4 10.1.1.118
s=3cxVCE Audio Call
c=IN IP4 10.1.1.118
t=0 0
m=audio 40014 RTP/AVP 8 0 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

<------------->
--- (14 headers 13 lines) ---
Sending to 10.1.1.118 : 3653 (NAT)
Using INVITE request as basis request - ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
Found user '518'
Found RTP audio format 8
Found RTP audio format 0
Found RTP audio format 3
Found RTP audio format 101
Found audio description format PCMA for ID 8
Found audio description format PCMU for ID 0
Found audio description format GSM for ID 3
Found audio description format telephone-event for ID 101
Capabilities: us - 0xc (ulaw|alaw), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing), combined - 0xc (ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 10.1.1.118:40014
Looking for *97 in from-internal (domain srv-pbx)
list_route: hop: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
srv-pbx*CLI>
<--- Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-c17b7f4f57297601-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
To: <sip:*97@srv-pbx:5060>
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 2 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Contact: <sip:*[email protected]>
Content-Length: 0


<------------>
-- Executing [*97@from-internal:1] Answer("SIP/518-00000050", "") in new stack
Audio is at 10.1.1.19 port 17582
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
srv-pbx*CLI>
<--- Reliably Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-c17b7f4f57297601-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 2 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Contact: <sip:*[email protected]>
Content-Type: application/sdp
Content-Length: 266

v=0
o=root 15297 15297 IN IP4 10.1.1.19
s=session
c=IN IP4 10.1.1.19
t=0 0
m=audio 17582 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSuppff - - - -
a=ptime:20
a=sendrecv

<------------>
-- Executing [*97@from-internal:2] Wait("SIP/518-00000050", "1") in new stack
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
ACK sip:*[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-fb796b3de4571346-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 2 ACK
Proxy-Authorization: Digest username="518",realm="asterisk",nonce="48a38d6a",uri="sip:*97@srv-pbx:5060",response="8d9e5ad3750cf9812a61f8b496f9a422",algorithm=MD5
User-Agent: 3CXPhone 4.0.10858.0
Content-Length: 0


<------------->
--- (11 headers 0 lines) ---
-- Executing [*97@from-internal:3] Macro("SIP/518-00000050", "user-callerid|") in new stack
-- Executing [s@macro-user-callerid:1] Set("SIP/518-00000050", "AMPUSER=518") in new stack
-- Executing [s@macro-user-callerid:2] GotoIf("SIP/518-00000050", "0?report") in new stack
-- Executing [s@macro-user-callerid:3] ExecIf("SIP/518-00000050", "1|Set|REALCALLERIDNUM=518") in new stack
-- Executing [s@macro-user-callerid:4] Set("SIP/518-00000050", "AMPUSER=518") in new stack
-- Executing [s@macro-user-callerid:5] Set("SIP/518-00000050", "AMPUSERCIDNAME=myuser") in new stack
-- Executing [s@macro-user-callerid:6] GotoIf("SIP/518-00000050", "0?report") in new stack
-- Executing [s@macro-user-callerid:7] Set("SIP/518-00000050", "AMPUSERCID=518") in new stack
-- Executing [s@macro-user-callerid:8] Set("SIP/518-00000050", "CALLERID(all)="myuser" <518>") in new stack
-- Executing [s@macro-user-callerid:9] GotoIf("SIP/518-00000050", "0?continue") in new stack
-- Executing [s@macro-user-callerid:10] Set("SIP/518-00000050", "__TTL=64") in new stack
-- Executing [s@macro-user-callerid:11] GotoIf("SIP/518-00000050", "1?continue") in new stack
-- Goto (macro-user-callerid,s,18)
-- Executing [s@macro-user-callerid:18] NoOp("SIP/518-00000050", "Using CallerID "myuser" <518>") in new stack
-- Executing [*97@from-internal:4] Macro("SIP/518-00000050", "get-vmcontext|518") in new stack
-- Executing [s@macro-get-vmcontext:1] Set("SIP/518-00000050", "VMCONTEXT=default") in new stack
-- Executing [s@macro-get-vmcontext:2] GotoIf("SIP/518-00000050", "0?200:300") in new stack
-- Goto (macro-get-vmcontext,s,300)
-- Executing [s@macro-get-vmcontext:300] NoOp("SIP/518-00000050", "") in new stack
-- Executing [*97@from-internal:5] MailboxExists("SIP/518-00000050", "518@default") in new stack
-- Executing [*97@from-internal:6] GotoIf("SIP/518-00000050", "1?mbexist") in new stack
-- Goto (from-internal,*97,106)
-- Executing [*97@from-internal:106] VoiceMailMain("SIP/518-00000050", "518@default") in new stack
-- <SIP/518-00000050> Playing 'vm-password' (language 'de')
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
SUBSCRIBE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-873f0021b720085f-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: "myuser"<sip:518@srv-pbx:5060>;tag=as59262a93
From: "myuser"<sip:518@srv-pbx:5060>;tag=421e4238
Call-ID: NTZkNDM2NDZmYjJkNDE4ODU3ZjVhNWQxNzhlMTMyNDE.
CSeq: 26 SUBSCRIBE
Expires: 120
User-Agent: 3CXPhone 4.0.10858.0
Authorization: Digest username="518",realm="asterisk",nonce="2e3652e0",uri="sip:[email protected]",response="8840dd87c2c8dd419426f14fcc387de0",algorithm=MD5
Event: message-summary
Content-Length: 0


<------------->
--- (13 headers 0 lines) ---
Found peer '518'
srv-pbx*CLI>
<--- Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-873f0021b720085f-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=421e4238
To: "myuser"<sip:518@srv-pbx:5060>;tag=as59262a93
Call-ID: NTZkNDM2NDZmYjJkNDE4ODU3ZjVhNWQxNzhlMTMyNDE.
CSeq: 26 SUBSCRIBE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="26d2f58d", stale=true
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog 'NTZkNDM2NDZmYjJkNDE4ODU3ZjVhNWQxNzhlMTMyNDE.' in 6464 ms (Method: SUBSCRIBE)
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
SUBSCRIBE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-1570cc06487bd14a-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: "myuser"<sip:518@srv-pbx:5060>;tag=as59262a93
From: "myuser"<sip:518@srv-pbx:5060>;tag=421e4238
Call-ID: NTZkNDM2NDZmYjJkNDE4ODU3ZjVhNWQxNzhlMTMyNDE.
CSeq: 27 SUBSCRIBE
Expires: 120
User-Agent: 3CXPhone 4.0.10858.0
Authorization: Digest username="518",realm="asterisk",nonce="26d2f58d",uri="sip:[email protected]",response="bd17512416677363b31070468f1ae0ed",algorithm=MD5
Event: message-summary
Content-Length: 0


<------------->
--- (13 headers 0 lines) ---
Found peer '518'
Scheduling destruction of SIP dialog 'NTZkNDM2NDZmYjJkNDE4ODU3ZjVhNWQxNzhlMTMyNDE.' in 130000 ms (Method: SUBSCRIBE)

<--- Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-1570cc06487bd14a-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=421e4238
To: "myuser"<sip:518@srv-pbx:5060>;tag=as59262a93
Call-ID: NTZkNDM2NDZmYjJkNDE4ODU3ZjVhNWQxNzhlMTMyNDE.
CSeq: 27 SUBSCRIBE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Expires: 120
Contact: <sip:[email protected]>;expires=120
Content-Length: 0


<------------>
Reliably Transmitting (NAT) to 10.1.1.118:3653:
NOTIFY sip:[email protected]:3653;rinstance=b823cd74871da9f9 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.19:5060;branch=z9hG4bK06426370;rport
Route: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
From: "Unknown" <sip:[email protected]>;tag=as59262a93
To: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>;tag=421e4238
Contact: <sip:[email protected]>
Call-ID: NTZkNDM2NDZmYjJkNDE4ODU3ZjVhNWQxNzhlMTMyNDE.
CSeq: 114 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 89

Messages-Waiting: yes
Message-Account: sip:*[email protected]
Voice-Message: 2/1 (0/0)

---
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.19:5060;branch=z9hG4bK06426370;rport=5060
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>;tag=421e4238
From: "Unknown"<sip:[email protected]>;tag=as59262a93
Call-ID: NTZkNDM2NDZmYjJkNDE4ODU3ZjVhNWQxNzhlMTMyNDE.
CSeq: 114 NOTIFY
User-Agent: 3CXPhone 4.0.10858.0
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '[email protected]' in 32000 ms (Method: REGISTER)
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
INFO sip:*[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-bb72eb06d422554c-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 3 INFO
Content-Type: application/dtmf-relay
Proxy-Authorization: Digest username="518",realm="asterisk",nonce="48a38d6a",uri="sip:*[email protected]",response="6de16d49b92c4fd2484990a88ce22b22",algorithm=MD5
User-Agent: 3CXPhone 4.0.10858.0
Content-Length: 24

Signal=5
Duration=250

<------------->
--- (12 headers 2 lines) ---
Receiving INFO!
* DTMF-relay event received: 5

<--- Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-bb72eb06d422554c-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 3 INFO
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0


<------------>
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
INFO sip:*[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-837a6a72516baa78-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 4 INFO
Content-Type: application/dtmf-relay
Proxy-Authorization: Digest username="518",realm="asterisk",nonce="48a38d6a",uri="sip:*[email protected]",response="6de16d49b92c4fd2484990a88ce22b22",algorithm=MD5
User-Agent: 3CXPhone 4.0.10858.0
Content-Length: 24

Signal=1
Duration=250

<------------->
--- (12 headers 2 lines) ---
Receiving INFO!
* DTMF-relay event received: 1

<--- Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-837a6a72516baa78-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 4 INFO
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0


<------------>
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
INFO sip:*[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-df62a40fcb50f631-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 5 INFO
Content-Type: application/dtmf-relay
Proxy-Authorization: Digest username="518",realm="asterisk",nonce="48a38d6a",uri="sip:*[email protected]",response="6de16d49b92c4fd2484990a88ce22b22",algorithm=MD5
User-Agent: 3CXPhone 4.0.10858.0
Content-Length: 24

Signal=8
Duration=250

<------------->
--- (12 headers 2 lines) ---
Receiving INFO!
* DTMF-relay event received: 8
srv-pbx*CLI>
<--- Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-df62a40fcb50f631-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 5 INFO
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0


<------------>
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
INFO sip:*[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-56619761021a251c-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 6 INFO
Content-Type: application/dtmf-relay
Proxy-Authorization: Digest username="518",realm="asterisk",nonce="48a38d6a",uri="sip:*[email protected]",response="6de16d49b92c4fd2484990a88ce22b22",algorithm=MD5
User-Agent: 3CXPhone 4.0.10858.0
Content-Length: 24

Signal=5
Duration=250

<------------->
--- (12 headers 2 lines) ---
Receiving INFO!
* DTMF-relay event received: 5

<--- Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-56619761021a251c-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 6 INFO
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0


<------------>
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
INFO sip:*[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-03466312ea1c655b-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 7 INFO
Content-Type: application/dtmf-relay
Proxy-Authorization: Digest username="518",realm="asterisk",nonce="48a38d6a",uri="sip:*[email protected]",response="6de16d49b92c4fd2484990a88ce22b22",algorithm=MD5
User-Agent: 3CXPhone 4.0.10858.0
Content-Length: 24

Signal=1
Duration=250

<------------->
--- (12 headers 2 lines) ---
Receiving INFO!
* DTMF-relay event received: 1
srv-pbx*CLI>
<--- Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-03466312ea1c655b-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 7 INFO
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0


<------------>
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
INFO sip:*[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-160ccf6d2c53a862-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 8 INFO
Content-Type: application/dtmf-relay
Proxy-Authorization: Digest username="518",realm="asterisk",nonce="48a38d6a",uri="sip:*[email protected]",response="6de16d49b92c4fd2484990a88ce22b22",algorithm=MD5
User-Agent: 3CXPhone 4.0.10858.0
Content-Length: 24

Signal=8
Duration=250

<------------->
--- (12 headers 2 lines) ---
Receiving INFO!
* DTMF-relay event received: 8

<--- Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-160ccf6d2c53a862-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 8 INFO
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0


<------------->
--- (12 headers 2 lines) ---
Receiving INFO!
* DTMF-relay event received: #
srv-pbx*CLI>
<--- Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-523ac46ba33e2652-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 9 INFO
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0


<------------>
-- Incorrect password '51581581851' for user '518' (context = default)
-- <SIP/518-00000050> Playing 'vm-incorrect' (language 'de')
-- <SIP/518-00000050> Playing 'vm-password' (language 'de')
srv-pbx*CLI>
<--- SIP read from 10.1.1.118:3653 --->
BYE sip:*[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-8d13d04ae01dd865-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:[email protected]:3653;rinstance=b823cd74871da9f9>
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 10 BYE
Proxy-Authorization: Digest username="518",realm="asterisk",nonce="48a38d6a",uri="sip:*[email protected]",response="b977526ae2a9dd5d224d239716fcee25",algorithm=MD5
User-Agent: 3CXPhone 4.0.10858.0
Content-Length: 0


<------------->
--- (11 headers 0 lines) ---
Sending to 10.1.1.118 : 3653 (NAT)
srv-pbx*CLI>
<--- Transmitting (NAT) to 10.1.1.118:3653 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.118:3653;branch=z9hG4bK-d8754z-8d13d04ae01dd865-1---d8754z-;received=10.1.1.118;rport=3653
From: "myuser"<sip:518@srv-pbx:5060>;tag=bc49613b
To: <sip:*97@srv-pbx:5060>;tag=as20977d54
Call-ID: ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.
CSeq: 10 BYE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0


<------------>
-- Executing [h@from-internal:1] Macro("SIP/518-00000050", "hangupcall") in new stack
-- Executing [s@macro-hangupcall:1] GotoIf("SIP/518-00000050", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,4)
-- Executing [s@macro-hangupcall:4] GotoIf("SIP/518-00000050", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,7)
-- Executing [s@macro-hangupcall:7] GotoIf("SIP/518-00000050", "1?theend") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing [s@macro-hangupcall:9] Hangup("SIP/518-00000050", "") in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/518-00000050' in macro 'hangupcall'
== Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/518-00000050'
Really destroying SIP dialog 'ZTkwMzhjZTc2ZjVhNzkwYTBkY2ZmNTJiODQ3ZWQ3NGQ.' Method: BYE



<------------->
--- (10 headers 0 lines) ---
Really destroying SIP dialog '[email protected]' Method: OPTIONS
Reliably Transmitting (NAT) to 10.1.1.125:30186:
OPTIONS sip:[email protected]:30186;rinstance=b2b7960e29bc6df6 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.19:5060;branch=z9hG4bK23a424a9;rport
From: "Unknown" <sip:[email protected]>;tag=as1937582a
To: <sip:[email protected]:30186;rinstance=b2b7960e29bc6df6>
Contact: <sip:[email protected]>
Call-ID: [email protected]
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Thu, 11 Feb 2010 13:04:11 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0


---
srv-pbx*CLI>
<--- SIP read from 10.1.1.125:30186 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.19:5060;branch=z9hG4bK23a424a9;rport=5060
Contact: <sip:10.1.1.125:30186>
To: <sip:[email protected]:30186;rinstance=b2b7960e29bc6df6>;tag=6625c35c
From: "Unknown"<sip:[email protected]>;tag=as1937582a
Call-ID: [email protected]
CSeq: 102 OPTIONS
Accept: application/sdp
Accept-Language: en
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
User-Agent: X-Lite release 1104o stamp 56125
Content-Length: 0


<------------->
--- (12 headers 0 lines) ---
Really destroying SIP dialog '[email protected]' Method: OPTIONS
srv-pbx*CLI>
<--- SIP read from 10.1.1.125:30186 --->

 

[SY]

Hi Asterisk User

I don't know what is the reason of this post, but...

You can reread your log ( provided by Asterisk? ) and see following:
1. Log says about 7 SIP INFO packets confirmed by asterisk.
2. The sequence of SIP INFO packets delivers exact 518518# as you expected

Do you have any idea where from asterisk got "51581581851"?

Thanks
P.S. By the way, I don't see any correlation between subject and information provided in log. There is explicit confirmation that asterisk has received #

 

[EricStyles]

I'm seeing something exactly like the original author is seeing but I'm pretty sure it's not with " # " DTMF tone, but it's DTMF related, from what I can see from one of my users, that uses 3cx, and my testing of the client on multiple computers.

What happens is, when the user is prompted for input (PIN number) for a conference bridge (meetme) user enters 4 digit pin, system rejects PIN. From my Asterisk logs I see the PIN number being captured but it's adding/repeating more digits. i.e.

user enters PIN 0037

Asterisk captures the input as = 00003377

Server = PBX is Asterisk 1.6

Client = 3cx softphone (latest stable)

Note this happens with any DTMF tone sent, VM, IVR prompts, etc ... What I think is happing is 3cx is sending the DTMF tones way too quickly. I have not run wireshark yet, nor have done any other testing to verify my diagnoses, as the fix is easy (use a different client). All other softphone clients I have tested with including Linux clients can't reproduce the above behavior, and is only indicative to 3cx.

Just an observation (2 cents) but going through the rest of the 3cx forums it's seems obvious 3cx and DTMF tones don't play along very nicely?

I hope this helps,

Cheers,
Eric

 

[SY]

I'm seeing something exactly like the original author is seeing but I'm pretty sure it's not with " # " DTMF tone, but it's DTMF related, from what I can see from one of my users, that uses 3cx, and my testing of the client on multiple computers.

What happens is, when the user is prompted for input (PIN number) for a conference bridge (meetme) user enters 4 digit pin, system rejects PIN. From my Asterisk logs I see the PIN number being captured but it's adding/repeating more digits. i.e.

user enters PIN 0037

Asterisk captures the input as = 00003377

Server = PBX is Asterisk 1.6

Client = 3cx softphone (latest stable)

Note this happens with any DTMF tone sent, VM, IVR prompts, etc ... What I think is happing is 3cx is sending the DTMF tones way too quickly. I have not run wireshark yet, nor have done any other testing to verify my diagnoses, as the fix is easy (use a different client). All other softphone clients I have tested with including Linux clients can't reproduce the above behavior, and is only indicative to 3cx.

Just an observation (2 cents) but going through the rest of the 3cx forums it's seems obvious 3cx and DTMF tones don't play along very nicely?

I hope this helps,

Cheers,
Eric

Eric,

The problem has been described and commented in previous posts. There is only one log and it is provided by Asterisk.

Could you please run wireshark to verify your diagnoses and then update your information?
How much time you need to make it?

Thanks

 

[EricStyles]

I'm a pretty busy guy at the moment, (one man IT shop) and my Asterisk logs reflect the same as the original author. Also I notices a debug on 3cx but it's not outputting anything, which is why I was going to go down analyzing packets path with wireshark. So at the moment, my user is working with a different client, if my user and myself have the time I'll try to get a packet capture and post here. Time frame wise, I'm just not sure at the moment.

Cheers,
Eric

 

[Vali_3CX]

Hi Eric
Eric, which DTMF mode is your 3CXPhone configured to use?
Regards
vali

 

[SY]

I'm a pretty busy guy at the moment, (one man IT shop) and my Asterisk logs reflect the same as the original author. Also I notices a debug on 3cx but it's not outputting anything, which is why I was going to go down analyzing packets path with wireshark. So at the moment, my user is working with a different client, if my user and myself have the time I'll try to get a packet capture and post here. Time frame wise, I'm just not sure at the moment.

Cheers,
Eric

3CX Phone supports three different styles of DTMF delivery. (see Connection/Advanced configuration dialog)
It is recommended to choose only one which will provide best interoperability with your PBX.
It is not recommended to combine styles, because some PBXes and/or software/hardware may be confused in case if each DTMF signal will be delivered simultaneously through "in-band", "RTP payload" and "SIP INFO" channels

 

[EricStyles]

Asterisk will use rfc2833 for DTMF relay by default but will switch to inband DTMF tones if the remote side does not indicate support of rfc2833 in SDP. So either or, Asterisk tries to play nice with both. I wish I had the time to help you guys out, I'm involved in a couple of other open source VoIP projects, maybe if you guys setup just a standard vanilla Asterisk Server to test with. PBX In A Flash has ISO's that will you get you up and running in no time at all.

 

[SY]

Asterisk will use rfc2833 for DTMF relay by default but will switch to inband DTMF tones if the remote side does not indicate support of rfc2833 in SDP. So either or, Asterisk tries to play nice with both. I wish I had the time to help you guys out, I'm involved in a couple of other open source VoIP projects, maybe if you guys setup just a standard vanilla Asterisk Server to test with. PBX In A Flash has ISO's that will you get you up and running in no time at all.

Technical descriptions of how does Asterisk handle DTMFs is really interesting but not in this case.
Asterisk collects DTMFs from SIP INFO as well (see log provided in initial post).
Wireshark capture is not required .
Asterisk logs can provide you information how DTMF signals were collected and where from Asterisk has collected "dublicates" of each digit.
For information about how 3CX Phone delivers DTMF signals and how to configure this process, see my previous comment.

Regards

 

[leejor]

I've had problems in the past with devices detecting in-band as well as the SIP messages resulting in double digits being detected. This usually requires some trial and error to discover which single method works best for you in all cases.