About a month ago we started to get people complaining that they were trying to enter a meetme conference and the pin was entered properly but the system reported the pin as being entered improperly. So I took a look at the logs and sure enough it looked like it was entered wrong, but they insisted the digits were entered properly.
Since we were on one of the first versions of 1.8 I decided to upgrade to 1.8.22.0 as I saw many DTMF issues addressed and thought this would be a good fit. We are still having issues where I can see they are entering the wrong pin but they insist the pin is entered properly, an example below (user entered 2157 not 21157).
I’ve also tried turning on relaxdtmf=yes in the chan_dahdi.conf (dahdi show channel pasted below).
I’ve turned on PRI debugging and unfortunately I have not been able to catch the invalidpin issue but also have determined that I have no clue what to do with the PRI debugging information.
Any clue what else I can try?
---- dahdi show channel 8 ----
Channel: 8
File Descriptor: 18
Span: 1
Extension:
Dialing: no
Context: from-pstn
Caller ID:
Calling TON: 33
Caller ID subaddress:
Caller ID name:
Mailbox: none
Destroy: 0
InAlarm: 0
Signalling Type: ISDN PRI
Radio: 0
Owner:
Real:
Callwait:
Threeway:
Confno: -1
Propagated Conference: -1
Real in conference: 0
DSP: no
Busy Detection: no
TDD: no
Relax DTMF: yes
Dialing/CallwaitCAS: 0/0
Default law: ulaw
Fax Handled: no
Pulse phone: no
Gains (RX/TX): 0.00/0.00
Dynamic Range Compression (RX/TX): 0.00/0.00
DND: no
Echo Cancellation:
128 taps
(unless TDM bridged) currently OFF
Wait for dialtone: 0ms
PRI Flags:
PRI Logical Span: Implicit
Hookstate (FXS only): Onhook
---- dtmf -----
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF begin ‘2’ received on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF begin ignored ‘2’ on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF end ‘2’ received on DAHDI/i1/xxxxxxxxxx-10ce, duration 80 ms
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF end passthrough ‘2’ on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF begin ‘1’ received on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF begin ignored ‘1’ on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF end ‘1’ received on DAHDI/i1/xxxxxxxxxx-10ce, duration 80 ms
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF end passthrough ‘1’ on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF begin ‘1’ received on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF begin ignored ‘1’ on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF end ‘1’ received on DAHDI/i1/xxxxxxxxxx-10ce, duration 80 ms
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF end passthrough ‘1’ on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF begin ‘5’ received on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF begin ignored ‘5’ on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF end ‘5’ received on DAHDI/i1/xxxxxxxxxx-10ce, duration 80 ms
[Oct 2 11:01:31] DTMF[20558] channel.c: DTMF end passthrough ‘5’ on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:32] DTMF[20558] channel.c: DTMF begin ‘7’ received on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:32] DTMF[20558] channel.c: DTMF begin ignored ‘7’ on DAHDI/i1/xxxxxxxxxx-10ce
[Oct 2 11:01:32] DTMF[20558] channel.c: DTMF end ‘7’ received on DAHDI/i1/xxxxxxxxxx-10ce, duration 80 ms
[Oct 2 11:01:32] DTMF[20558] channel.c: DTMF end passthrough ‘7’ on DAHDI/i1/xxxxxxxxxx-10ce
You need to enable millisecond logging in logger.conf, to see the detailed timing. As it is reporting all the digits as 80ms,I suspect the problem is upstream…
I’m note a dahdi user, but there may also be lower level debugging avaliable in the code that actually does the tone detection, or reads the detected tones from the hardware.
It may also be relevant whether the call originated on a landline phone, a mobile phone, or an IP phone
theguy_: I see you’re using DAHDI with a PRI. If you’re using a card based on the wct4xxp driver with a hardware echo canceler and a DAHDI version between 2.4.0 and 2.5.0.1 it’s possible you’re hitting a bug fixed by commit wct4xxp: Fix condition where hardware echo canceler erroneously mutes DTMF..
If you think this applies to your case, I recommend updating to DAHDI-Linux 2.6.2. If not feel free to disregard.
Actually, looking back over your report, you’re seeing double digits, so this is probably not related. The case I mentioned would manifest as missing digits.
Ok, I’ve enabled millisecond logging and will post results later today or monday morning.
We are using DAHDI 2.4.1 and libpri 1.4.11.5. I will try to upgrade DAHDI this weekend, I’ve done this successfully on test boxes but not production yet.
Has anyone had success troubleshooting DTMF with AT&T? I tried to call and talk to a tech about the issue, this particular tech went on and on about how this was a local site issue with our PBX and would not listen to anything I had to say regarding the issue. I was planning on calling back to put another ticket.
Finally happened this morning, repeating 1 below with milliseconds. Any ideas?
[2013-10-08 10:12:36.759] VERBOSE[28362] pbx.c: – Executing [7380@from-pstn:1] Goto(“DAHDI/i1/xxxxxxxxxx-17fa”, “ivr-meetme,s,1”) in new stack
[2013-10-08 10:12:36.759] VERBOSE[28362] pbx.c: – Goto (ivr-meetme,s,1)
[2013-10-08 10:12:36.759] VERBOSE[28362] pbx.c: – Executing [s@ivr-meetme:1] Verbose(“DAHDI/i1/xxxxxxxxxx-17fa”, “Welcome to Conference”) in new stack
[2013-10-08 10:12:36.759] VERBOSE[28362] app_verbose.c: Welcome to Conference
[2013-10-08 10:12:36.759] VERBOSE[28362] pbx.c: – Executing [s@ivr-meetme:2] Answer(“DAHDI/i1/xxxxxxxxxx-17fa”, “”) in new stack
[2013-10-08 10:12:36.759] VERBOSE[28362] pbx.c: – Executing [s@ivr-meetme:3] Playback(“DAHDI/i1/xxxxxxxxxx-17fa”, “silence/1”) in new stack
[2013-10-08 10:12:36.760] VERBOSE[28362] file.c: – <DAHDI/i1/xxxxxxxxxx-17fa> Playing ‘silence/1.ulaw’ (language ‘en’)
[2013-10-08 10:12:37.759] VERBOSE[28362] pbx.c: – Executing [s@ivr-meetme:4] BackGround(“DAHDI/i1/xxxxxxxxxx-17fa”, “enter-conf-call-number”) in new stack
[2013-10-08 10:12:37.760] VERBOSE[28362] file.c: – <DAHDI/i1/xxxxxxxxxx-17fa> Playing ‘enter-conf-call-number.ulaw’ (language ‘en’)
[2013-10-08 10:12:41.559] VERBOSE[28362] pbx.c: – Executing [s@ivr-meetme:5] WaitExten(“DAHDI/i1/xxxxxxxxxx-17fa”, “20”) in new stack
[2013-10-08 10:12:47.073] DTMF[28362] channel.c: DTMF begin ‘8’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:47.073] DTMF[28362] channel.c: DTMF begin ignored ‘8’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:47.169] DTMF[28362] channel.c: DTMF end ‘8’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:12:47.169] DTMF[28362] channel.c: DTMF end passthrough ‘8’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:47.425] DTMF[28362] channel.c: DTMF begin ‘8’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:47.425] DTMF[28362] channel.c: DTMF begin ignored ‘8’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:47.521] DTMF[28362] channel.c: DTMF end ‘8’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:12:47.521] DTMF[28362] channel.c: DTMF end passthrough ‘8’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:47.777] DTMF[28362] channel.c: DTMF begin ‘4’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:47.777] DTMF[28362] channel.c: DTMF begin ignored ‘4’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:47.873] DTMF[28362] channel.c: DTMF end ‘4’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:12:47.873] DTMF[28362] channel.c: DTMF end passthrough ‘4’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:48.161] DTMF[28362] channel.c: DTMF begin ‘6’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:48.161] DTMF[28362] channel.c: DTMF begin ignored ‘6’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:48.225] DTMF[28362] channel.c: DTMF end ‘6’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:12:48.225] DTMF[28362] channel.c: DTMF end passthrough ‘6’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:48.225] VERBOSE[28362] pbx.c: == CDR updated on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:48.225] VERBOSE[28362] pbx.c: – Executing [8846@ivr-meetme:1] MeetMe(“DAHDI/i1/xxxxxxxxxx-17fa”, “8846,cMpT”) in new stack
[2013-10-08 10:12:48.225] VERBOSE[28362] file.c: – <DAHDI/i1/xxxxxxxxxx-17fa> Playing ‘conf-getpin.ulaw’ (language ‘en’)
[2013-10-08 10:12:50.049] DTMF[28362] channel.c: DTMF begin ‘9’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:50.049] DTMF[28362] channel.c: DTMF begin ignored ‘9’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:50.145] DTMF[28362] channel.c: DTMF end ‘9’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:12:50.145] DTMF[28362] channel.c: DTMF end passthrough ‘9’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:50.497] DTMF[28362] channel.c: DTMF begin ‘8’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:50.497] DTMF[28362] channel.c: DTMF begin ignored ‘8’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:50.593] DTMF[28362] channel.c: DTMF end ‘8’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:12:50.593] DTMF[28362] channel.c: DTMF end passthrough ‘8’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:50.881] DTMF[28362] channel.c: DTMF begin ‘1’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:50.881] DTMF[28362] channel.c: DTMF begin ignored ‘1’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:50.913] DTMF[28362] channel.c: DTMF end ‘1’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:12:50.913] DTMF[28362] channel.c: DTMF end passthrough ‘1’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:50.977] DTMF[28362] channel.c: DTMF begin ‘1’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:50.977] DTMF[28362] channel.c: DTMF begin ignored ‘1’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:51.009] DTMF[28362] channel.c: DTMF end ‘1’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:12:51.009] DTMF[28362] channel.c: DTMF end passthrough ‘1’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:51.265] DTMF[28362] channel.c: DTMF begin ‘1’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:51.265] DTMF[28362] channel.c: DTMF begin ignored ‘1’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:51.361] DTMF[28362] channel.c: DTMF end ‘1’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:12:51.361] DTMF[28362] channel.c: DTMF end passthrough ‘1’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:12:56.362] VERBOSE[28362] file.c: – <DAHDI/i1/xxxxxxxxxx-17fa> Playing ‘conf-invalidpin.ulaw’ (language ‘en’)
[2013-10-08 10:12:59.584] VERBOSE[28362] file.c: – <DAHDI/i1/xxxxxxxxxx-17fa> Playing ‘conf-getpin.ulaw’ (language ‘en’)
[2013-10-08 10:13:11.809] DTMF[28362] channel.c: DTMF begin ‘9’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:11.809] DTMF[28362] channel.c: DTMF begin ignored ‘9’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:11.905] DTMF[28362] channel.c: DTMF end ‘9’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:13:11.905] DTMF[28362] channel.c: DTMF end passthrough ‘9’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:12.193] DTMF[28362] channel.c: DTMF begin ‘8’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:12.193] DTMF[28362] channel.c: DTMF begin ignored ‘8’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:12.289] DTMF[28362] channel.c: DTMF end ‘8’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:13:12.289] DTMF[28362] channel.c: DTMF end passthrough ‘8’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:12.577] DTMF[28362] channel.c: DTMF begin ‘1’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:12.577] DTMF[28362] channel.c: DTMF begin ignored ‘1’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:12.673] DTMF[28362] channel.c: DTMF end ‘1’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:13:12.673] DTMF[28362] channel.c: DTMF end passthrough ‘1’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:12.961] DTMF[28362] channel.c: DTMF begin ‘1’ received on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:12.961] DTMF[28362] channel.c: DTMF begin ignored ‘1’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:13.057] DTMF[28362] channel.c: DTMF end ‘1’ received on DAHDI/i1/xxxxxxxxxx-17fa, duration 80 ms
[2013-10-08 10:13:13.057] DTMF[28362] channel.c: DTMF end passthrough ‘1’ on DAHDI/i1/xxxxxxxxxx-17fa
[2013-10-08 10:13:18.058] VERBOSE[28362] file.c: – <DAHDI/i1/xxxxxxxxxx-17fa> Playing ‘conf-onlyone.ulaw’ (language ‘en’)
I’m not sure where the 80ms is coming from, but it seems to have detected rather short 1 digits, so it presumably thought t he digit had stopped and restarted. That does look like a DSP problem.
I think you also need to capture the raw audio, and look at it with something like Aduacity, to see if there are obvious problems upstream.
In regards to the DSP issue, I’ve found some articles that relate DMTF issues to AT&T, they recommend inserting this into DSP.conf:
dtmf_normal_twist=6.31
dtmf_reverse_twist=2.51
relax_dtmf_normal_twist=6.31
relax_dtmf_reverse_twist=3.98
dtmf_hits_to_begin=1
dtmf_misses_to_end=1
I’ve tried this and it did not seem to help so I reverted, do you think these values are too low? I guess a recording would be the way to figure out for sure. It’s hard to record since its so random.
When I do a dahdi show channel I see a line that says “DSP: no” does this mean DSP is not enabled?
theguy_: since you’re in 2.4.1 and you have a hardware echocan, I would still strong suggest upgrading your version of DAHDI to just eliminate any potential issues from the hardware DSP.