Problem with DTMF

[marzo]

I have Vicibox 5.0.3 with:
1) Version of VICIDIAL: VERSION: 2.8-413a BUILD: 130928-1130
2) loadavg: load average: 0.11, 0.05, 0.06
3) Server Specs: Intel(R) Xeon(R) CPU E3-1220 V2 @ 3.10GHz with fout cores. 12 GBytes of RAM. 2 TBytes hard disk.
4) Codecs used: alaw
5) VOIP or PSTN : VOIP
6) OS: Linux cc1 3.7.10-1.16-pae #1 SMP Fri May 31 20:21:23 UTC 2013 (97c14ba) i686 i686 i386 GNU/Linux

The Vicibox has a SIP trunk to a PBX-IP which has the PSTN connection.

This is the trunk to the PBX-IP:
Carrier ID: ccpbx

Account Entry:
[ccpbx]
username=ccpbx
type=friend
secret=r2c4rd
qualify=yes
host=192.168.11.11
context=trunkinbound
disallow=all
allow=alaw
dtmfmode=rfc2833

Protocol:SIP

Globals String: TSCCPBX = SIP/ccpbx

Dialplan Entry:
; Llamadas Locales en Medellin
exten => _NXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _NXXXXXX,2,Dial(${TSCCPBX}/${EXTEN},55,To)
exten => _NXXXXXX,3,Hangup

From a softphone of Vicibox I can make call to the PSTN and use DTMF without any problem. This is the output from the CLI:
[Nov 11 10:53:17] == Using SIP RTP CoS mark 5
[Nov 11 10:53:17] -- Executing [3452389@default:1] AGI("SIP/cc101-0000001f", "agi://127.0.0.1:4577/call_log") in new stack
[Nov 11 10:53:17] -- <SIP/cc101-0000001f>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Nov 11 10:53:17] -- Executing [3452389@default:2] Dial("SIP/cc101-0000001f", "SIP/ccpbx/3452389,55,To") in new stack
[Nov 11 10:53:17] == Using SIP RTP CoS mark 5
[Nov 11 10:53:17] -- Called SIP/ccpbx/3452389
[Nov 11 10:53:18] -- SIP/ccpbx-00000020 is making progress passing it to SIP/cc101-0000001f
[Nov 11 10:53:18] -- SIP/ccpbx-00000020 answered SIP/cc101-0000001f
[Nov 11 10:53:27] DTMF[4557]: channel.c:4151 __ast_read: DTMF begin '1' received on SIP/cc101-0000001f
[Nov 11 10:53:27] DTMF[4557]: channel.c:4161 __ast_read: DTMF begin passthrough '1' on SIP/cc101-0000001f
[Nov 11 10:53:27] DTMF[4557]: channel.c:4066 __ast_read: DTMF end '1' received on SIP/cc101-0000001f, duration 100 ms
[Nov 11 10:53:27] DTMF[4557]: channel.c:4106 __ast_read: DTMF end accepted with begin '1' on SIP/cc101-0000001f
[Nov 11 10:53:27] DTMF[4557]: channel.c:4135 __ast_read: DTMF end passthrough '1' on SIP/cc101-0000001f


However from the agent interface the DTMF does not work.
This is the output from the CLI:
[Nov 11 10:56:07] > Channel SIP/cc101-00000021 was answered.
[Nov 11 10:56:07] -- Executing [8600051@default:1] MeetMe("SIP/cc101-00000021", "8600051,F") in new stack
[Nov 11 10:56:07] == Parsing '/etc/asterisk/meetme.conf': [Nov 11 10:56:07] == Found
[Nov 11 10:56:07] == Parsing '/etc/asterisk/meetme-vicidial.conf': [Nov 11 10:56:07] == Found
[Nov 11 10:56:07] -- Created MeetMe conference 1023 for conference '8600051'
[Nov 11 10:56:07] -- <SIP/cc101-00000021> Playing 'conf-onlyperson.gsm' (language 'en')
[Nov 11 10:56:08] == Manager 'sendcron' logged off from 127.0.0.1
[Nov 11 10:56:25] == Manager 'sendcron' logged on from 127.0.0.1
[Nov 11 10:56:25] -- Executing [8600051@default:1] MeetMe("Local/8600051@default-00000035;2", "8600051,F") in new stack
[Nov 11 10:56:25] > Channel Local/8600051@default-00000035;1 was answered.
[Nov 11 10:56:25] -- Executing 3452389@default:1] AGI("Local/8600051@default-00000035;1", "agi://127.0.0.1:4577/call_log") in new stack
[Nov 11 10:56:25] -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=SAC))
[Nov 11 10:56:25] -- <Local/8600051@default-00000035;1>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Nov 11 10:56:25] -- Executing 3452389@default:2] Dial("Local/8600051@default-00000035;1", "SIP/ccpbx/3452389,55,To") in new stack
[Nov 11 10:56:25] == Using SIP RTP CoS mark 5
[Nov 11 10:56:25] -- Called SIP/ccpbx/3452389
[Nov 11 10:56:26] == Manager 'sendcron' logged on from 127.0.0.1
[Nov 11 10:56:26] -- Executing [58600051@default:1] MeetMe("Local/58600051@default-00000036;2", "8600051,Fmq") in new stack
[Nov 11 10:56:26] > Channel Local/58600051@default-00000036;1 was answered.
[Nov 11 10:56:26] -- Executing [8309@default:1] Answer("Local/58600051@default-00000036;1", "") in new stack
[Nov 11 10:56:26] -- Executing [8309@default:2] Monitor("Local/58600051@default-00000036;1", "wav,20131111-105625_3452389") in new stack
[Nov 11 10:56:26] -- Executing [8309@default:3] Wait("Local/58600051@default-00000036;1", "3600") in new stack
[Nov 11 10:56:26] -- SIP/ccpbx-00000022 is making progress passing it to Local/8600051@default-00000035;1
[Nov 11 10:56:26] -- SIP/ccpbx-00000022 answered Local/8600051@default-00000035;1
[Nov 11 10:56:26] == Manager 'sendcron' logged off from 127.0.0.1
[Nov 11 10:56:27] == Manager 'sendcron' logged off from 127.0.0.1
[Nov 11 10:56:33] == Manager 'sendcron' logged on from 127.0.0.1
[Nov 11 10:56:33] -- Executing [8500998@default:1] Answer("Local/8500998@default-00000037;2", "") in new stack
[Nov 11 10:56:33] > Channel Local/8500998@default-00000037;1 was answered.
[Nov 11 10:56:33] -- Executing [78600051@default:1] MeetMe("Local/8500998@default-00000037;1", "8600051,Fq") in new stack
[Nov 11 10:56:33] -- Executing [8500998@default:2] Playback("Local/8500998@default-00000037;2", "silence") in new stack
[Nov 11 10:56:33] -- <Local/8500998@default-00000037;2> Playing 'silence.slin' (language 'en')
[Nov 11 10:56:34] -- Executing [8500998@default:3] AGI("Local/8500998@default-00000037;2", "agi-dtmf.agi") in new stack
[Nov 11 10:56:34] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-dtmf.agi
[Nov 11 10:56:34] == Manager 'sendcron' logged off from 127.0.0.1
[Nov 11 10:56:34] -- Playing 'silence' (escape_digits=) (sample_offset 0)
[Nov 11 10:56:34] -- Playing '1' (escape_digits=) (sample_offset 0)
[Nov 11 10:56:34] -- Playing 'silence' (escape_digits=) (sample_offset 0)
[Nov 11 10:56:34] -- Playing 'silence' (escape_digits=) (sample_offset 0)
[Nov 11 10:56:35] -- Playing 'silence' (escape_digits=) (sample_offset 0)
[Nov 11 10:56:35] -- Playing 'silence' (escape_digits=) (sample_offset 0)
[Nov 11 10:56:35] -- Playing 'silence' (escape_digits=) (sample_offset 0)
[Nov 11 10:56:35] -- Playing 'silence' (escape_digits=) (sample_offset 0)
[Nov 11 10:56:36] -- Playing 'silence' (escape_digits=) (sample_offset 0)
[Nov 11 10:56:36] -- Playing 'silence' (escape_digits=) (sample_offset 0)
[Nov 11 10:56:36] -- Playing 'silence' (escape_digits=) (sample_offset 0)
[Nov 11 10:56:37] -- <Local/8500998@default-00000037;2>AGI Script agi-dtmf.agi completed, returning 0
[Nov 11 10:56:37] -- Executing [8500998@default:4] Hangup("Local/8500998@default-00000037;2", "") in new stack
[Nov 11 10:56:37] == Spawn extension (default, 8500998, 4) exited non-zero on 'Local/8500998@default-00000037;2'
[Nov 11 10:56:37] -- Executing [h@default:1] AGI("Local/8500998@default-00000037;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[Nov 11 10:56:37] -- <Local/8500998@default-00000037;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
[Nov 11 10:56:37] == Spawn extension (default, 78600051, 1) exited non-zero on 'Local/8500998@default-00000037;1'
[Nov 11 10:56:37] -- Executing [h@default:1] AGI("Local/8500998@default-00000037;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[Nov 11 10:56:37] -- <Local/8500998@default-00000037;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0

Any help will be appreciated.

[williamconley]

You have control of both sides of a VOIP connection and have shown the "dtmfmode=rfc2833" for ONE side of the connection. What about the other side?

Also, you said 'from the agent interface' but did not explain precisely. Are you saying the agent is putting the dtmf information in the dtmf field on their agent web page and pushing send, or they are logged in and pushing dtmf buttons on their soft phone or ...? Did you try both? Did you also try ALL available dtmf modes?

also (while we're here ...), you did not mention your asterisk version. Now, I'm familiar with 5.0.3 and know it installs asterisk 1.8, but you should always list it (especially when asking detailed asterisk questions such as this) and that brings me to the next point ... what is listed in admin->servers for this server under asterisk version? (I've heard rumors that the entire string is necessary as just 1.8 is apparently not always sufficient ... but I've not valildated that in any way). If you do change this value, test again and test with the full string or just 1.8.

[marzo]

Hello,

Yes, I have control of the other side of the VOIP connection, it has dtmfmode=rfc2833 too.
According with the Vicidial Troubleshooting (http://wiki.vicidial.org/index.php/VICI:Troubleshooting), DTMF not working, I have changed to inband, info an auto but this does not solved the problem.
Yes, I am saying the agent is putting the dtmf information in the dtmf field on their agent web page and pushing send.
The Vicibox 5.0.3 has asterisk 1.8.23.0-vici.
The PBX-IP has Asterisk 1.8.13.0 and FreePBX 2.8.0.4.

This is the SIP trunk in the in the PBX-IP side:
username=ccpbx
type=friend
secret=r2c4rd
qualify=yes
host=192.168.11.12
context=CallCenter
disallow=all
allow=alaw
dtmfmode=rfc2833

Additionally when I make a call from a softphone of Vicibox, this is the output from the CLI of the PBX-IP:
[Nov 11 11:28:42] DTMF[8767] channel.c: DTMF begin '1' received on SIP/ccpbx-0005ff39
[Nov 11 11:28:42] DTMF[8767] channel.c: DTMF begin passthrough '1' on SIP/ccpbx-0005ff39
[Nov 11 11:28:42] DTMF[8767] channel.c: DTMF end '1' received on SIP/ccpbx-0005ff39, duration 140 ms
[Nov 11 11:28:42] DTMF[8767] channel.c: DTMF end accepted with begin '1' on SIP/ccpbx-0005ff39
[Nov 11 11:28:42] DTMF[8767] channel.c: DTMF end passthrough '1' on SIP/ccpbx-0005ff39

When I make a call from the agent interface, there is not any kind of activity related with DTMF in the CLI of the PBX-IP.

Thanks

[marzo]

The solution to this problem is the following post:

viewtopic.php?f=4&t=22626&p=81247&hilit=dtmf#p81247