[asterisk-users] Suggestions on how to debug strange DTMF problems

[James FitzGibbon]

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