James FitzGibbon
2007-Aug-17 15:20 UTC
[asterisk-users] Suggestions on how to debug strange DTMF problems
I'm hoping people can suggest some ideas for debugging a problem that I'm having with DTMF. Unlike most of the DTMF problems reported here, it has nothing to do with Asterisk interpreting DTMF. My problem is with the synthesis of DTMF tones on outbound calls on a PRI connected to a TE412P card. I'm running * 1.4.10.1 with Zaptel 1.4.4. It is important to note that these problems never occurred when we were using 1.2. They started immediately after upgrading to 1.4 (1.4.4 and 1.4.2.1 at the time IIRC) The original problem people would report is that they have problems using IVRs that they call over the PSTN. Duplicated digits, missed digits, etc. I've tried to replicate the problem using various user agents (Polycom 430, Grandstream GXP2000, Linksys SPA942, eyeBeam, etc.) and have observed the problem. It's not consistent, but that's probably due to the inconsistency of user input. If you concentrate very carefully and hit the keys for a consistent period of time with consistent spacing, the problem doesn't seem to happen. I also found that when the user agent was directed into DISA() and then dialed the IVR from within that application, they didn't have problems with their DTMF being recognized. In an attempt to quantify the problem, I set up the following test harness, sending calls out of Asterisk into an ITSP system. The final termination of the call is a different Asterisk box from the one that generated the call, though running the same version. DTMF from the ITSP to the second Asterisk system is SIP INFO. Asterisk -> PRI (TE412P) -> PSTN -> ITSP -> Asterisk I generated calls that executed SendDTMF(). On the other Asterisk system, I used Read() to capture the DTMF and stick it in a database. I did 1250 calls (250 to each of the 4 PRIs connected to the TE412P and 250 without regard to the PRI used). Across all of those calls, I didn't see one missed or doubled-up digit. I then did some manual tests where I placed calls from the Polycom 430 to the same application (basically putting myself in place of SendDTMF). Immediately I saw doubled up an missed digits. I turned on DTMF debugging on the second Asterisk box, and doubled-up digits always seem to take this form: [Aug 17 10:50:05] DTMF[25160] channel.c: DTMF begin emulation of '4' with duration 90 queued on SIP/5060-08da0d70 [Aug 17 10:50:05] DTMF[25160] channel.c: DTMF end emulation of '4' queued on SIP/5060-08da0d70 [Aug 17 10:50:05] DTMF[25160] channel.c: DTMF end '4' received on SIP/5060-08da0d70, duration 70 ms [Aug 17 10:50:05] DTMF[25160] channel.c: DTMF begin emulation of '4' with duration 80 queued on SIP/5060-08da0d70 [Aug 17 10:50:05] DTMF[25160] channel.c: DTMF end emulation of '4' queued on SIP/5060-08da0d70 [Aug 17 10:50:05] DTMF[25160] channel.c: DTMF end '4' received on SIP/5060-08da0d70, duration 50 ms [Aug 17 10:50:05] DTMF[25160] channel.c: DTMF begin emulation of '4' with duration 80 queued on SIP/5060-08da0d70 [Aug 17 10:50:05] DTMF[25160] channel.c: DTMF end emulation of '4' queued on SIP/5060-08da0d70 That's a single keypress. As I understand it, synthesized DTMF tones should consistently have a duration of 100 ms, and indeed most of what shows up in the DTMF log does have that duration (or something close to it): [Aug 17 10:49:55] DTMF[25160] channel.c: DTMF end '1' received on SIP/5060-08da0d70, duration 100 ms [Aug 17 10:49:55] DTMF[25160] channel.c: DTMF begin emulation of '1' with duration 100 queued on SIP/5060-08da0d70 [Aug 17 10:49:55] DTMF[25160] channel.c: DTMF end emulation of '1' queued on SIP/5060-08da0d70 [Aug 17 10:49:57] DTMF[25160] channel.c: DTMF end '2' received on SIP/5060-08da0d70, duration 100 ms [Aug 17 10:49:57] DTMF[25160] channel.c: DTMF begin emulation of '2' with duration 100 queued on SIP/5060-08da0d70 [Aug 17 10:49:57] DTMF[25160] channel.c: DTMF end emulation of '2' queued on SIP/5060-08da0d70 [Aug 17 10:49:58] DTMF[25160] channel.c: DTMF end '3' received on SIP/5060-08da0d70, duration 110 ms [Aug 17 10:49:58] DTMF[25160] channel.c: DTMF begin emulation of '3' with duration 110 queued on SIP/5060-08da0d70 [Aug 17 10:49:58] DTMF[25160] channel.c: DTMF end emulation of '3' queued on SIP/5060-08da0d70 [Aug 17 10:50:00] DTMF[25160] channel.c: DTMF end '4' received on SIP/5060-08da0d70, duration 100 ms [Aug 17 10:50:00] DTMF[25160] channel.c: DTMF begin emulation of '4' with duration 100 queued on SIP/5060-08da0d70 [Aug 17 10:50:01] DTMF[25160] channel.c: DTMF end emulation of '4' queued on SIP/5060-08da0d70 [Aug 17 10:50:02] DTMF[25160] channel.c: DTMF end '4' received on SIP/5060-08da0d70, duration 100 ms Yet from time to time, the ITSP "hears" that supposed 100ms tone as two tones of 70 and 50ms, or 90 and 40, or some combination that makes it appear to be a doubled-up digit. I'd be tempted to say that the problem is whatever part of the ITSP that is interpreting the DTMF coming in from the PSTN, but the IVRs that my users complain about are operated by tons of different companies. I have trouble dialing extensions on a 10 year old Meridian system; someone else can't use Audible's account management IVR; another user can't get WestJet to work, etc. What evidence I've collected seems to suggest two things: - there is a difference between DTMF that is generated inside of Asterisk (such as is the case for SendDTMF and digits picked up inside of DISA and then regenerated on another call leg) and DTMF received from a connected user agent (SIP INFO or RFC2833) - the audio of tones that the TE412P (or Asterisk; not sure exactly where the tone generation is happening or if this is PRI specific) are not consistent enough for many other systems to interpret correctly. Can anyone suggest what I should do next? Changes to testing methodology, data collection, etc. I'm pretty much open to anything that doesn't require me to take the system with the TE412P down or restart it (or rather; I can do that only overnight, so several such changes and testing have to play out over several days) Much appreciated. -- j. -------------- next part -------------- An HTML attachment was scrubbed... URL: http://lists.digium.com/pipermail/asterisk-users/attachments/20070817/4d29a581/attachment.htm