Does anyone have any idea why Asterisk takes so long to process DTMF signals?
I have a program to ask for a phone number and then call the number entered. The problem is that after entering the number from the caller’s phone, the DTMF signal reaches Asterisk for a long time. Which negatively affects the service.
Can you tell us what influences how quickly the DTMF signal reaches Asterisk?
Assuming SIP, not DAHDI.
Network congestion, is what would affect the propagation delay.
I suspect we need more details, such as how DTMF is being encoded (dtmfmode), and if in band, the codecs in use. Also the context in which the DTMF is being used, e.g. completing dialed numbers, waitexten, or read. For the first two, what is the form of the dialplan pattern you are trying to match.
Hi,
Yes, I am using SIP (PJSIP exactly)
On my endpoint I have dtmfmode set to rfc4733, I use only alaw/ulaw codec
This may seem complicated, but is the result of my attempt to optimize the performance.
First, I use Read (var, audio, 1) to go to the context where I use ReadExten () to process each DTMF signal by signal. The reason for this approach was that Asterisk had an additional delay with ‘#’
[XXX]
same => n,ReadExten(CPB,wprowadznumer,disa-kod-build)
same => n,Noop(${CPB})
same => n,Goto(disa-kod-build,read,1)
[disa-kod-build]
exten => read,1,Noop(Nowe podejscie)
; ReadExten(variable[,filename[,context[,option[,timeout]]]])
same => n,Noop(${CPB})
same => n,ReadExten(WYBOR,silence/10,disa-kod-build)
same => n,Goto(${WYBOR},1)
exten => _X,1,Noop(User wprowadzil ${EXTEN})
same => n,Set(CPB=${CPB}${EXTEN})
same => n,Goto(read,1)
exten => #,1,Noop(User wprowadzil ${EXTEN})
same => n,Noop(CALY NUMER TO ${CPB})
same => n,Set(NUMER=${CPB})
same => n,Goto(disa-kod,1,check)
same => n,Goto(read,1)
You haven’t specified a timeout. Are users keying # to end the number?
Yes, the user is obliged to finish entering the number with the # key.
Where should I set the timeout? I am asking because the Read () command is supposed to respond to 1 signal, while ReadExten adjusts to its context
Timeout is the fifth parameter, see https://wiki.asterisk.org/wiki/display/AST/Asterisk+10+Application_ReadExten
On re-checking, it shouldn’t need a timeout if there are no open ended extension patterns.
When you look at the DTMF log, preferably with the logging time resolution set to milliseconds, are the underlying DTMF events delayed?
Where I can find DTMF log? How to open it, it is an Asterisk CLI command?
Wherever you enable it to be in /etc/asterisk/logger.conf
OK, I enabled it by this tutorial https://arstech.net/how-to-enable-dtmf-logging-or-debug-on-asterisk/
I entered my 9 digit phone number quickly, and began watching how quickly the DTMF reached the system. When I enter a phone number from my phone in less than 1 second, it takes 2-3 seconds, sometimes even 8 seconds, to arrive and be validated.
That suggests the problem is upstream.
The next step to confirming this would be to capture the RTP, using tcpdump, and analyze it with wireshark, to see what is actually arriving at the machine.
ohh, and the log looks like:
[Sep 28 11:52:43] DTMF[1520752][C-0000fe75]: channel.c:3957 __ast_read: DTMF begin '7' received on PJSIP/incoming-0001e166
[Sep 28 11:52:43] DTMF[1520752][C-0000fe75]: channel.c:3961 __ast_read: DTMF begin ignored '7' on PJSIP/incoming-0001e166
[Sep 28 11:52:43] DTMF[1520752][C-0000fe75]: channel.c:3843 __ast_read: DTMF end '7' received on PJSIP/incoming-0001e166, duration 140 ms
[Sep 28 11:52:43] DTMF[1520752][C-0000fe75]: channel.c:3932 __ast_read: DTMF end passthrough '7' on PJSIP/incoming-0001e166
[Sep 28 11:52:43] DTMF[1520752][C-0000fe75]: channel.c:3957 __ast_read: DTMF begin '0' received on PJSIP/incoming-0001e166
[Sep 28 11:52:43] DTMF[1520752][C-0000fe75]: channel.c:3961 __ast_read: DTMF begin ignored '0' on PJSIP/incoming-0001e166
[Sep 28 11:52:43] DTMF[1520752][C-0000fe75]: channel.c:3843 __ast_read: DTMF end '0' received on PJSIP/incoming-0001e166, duration 140 ms
[Sep 28 11:52:43] DTMF[1520752][C-0000fe75]: channel.c:3932 __ast_read: DTMF end passthrough '0' on PJSIP/incoming-0001e166
[Sep 28 11:52:43] DTMF[1520755][C-0000fe76]: channel.c:3957 __ast_read: DTMF begin '1' received on PJSIP/incoming-0001e167
[Sep 28 11:52:43] DTMF[1520755][C-0000fe76]: channel.c:3961 __ast_read: DTMF begin ignored '1' on PJSIP/incoming-0001e167
[Sep 28 11:52:44] DTMF[1520755][C-0000fe76]: channel.c:3843 __ast_read: DTMF end '1' received on PJSIP/incoming-0001e167, duration 260 ms
[Sep 28 11:52:44] DTMF[1520755][C-0000fe76]: channel.c:3932 __ast_read: DTMF end passthrough '1' on PJSIP/incoming-0001e167
[Sep 28 11:52:44] DTMF[1520752][C-0000fe75]: channel.c:3957 __ast_read: DTMF begin '1' received on PJSIP/incoming-0001e166
[Sep 28 11:52:44] DTMF[1520752][C-0000fe75]: channel.c:3961 __ast_read: DTMF begin ignored '1' on PJSIP/incoming-0001e166
[Sep 28 11:52:44] DTMF[1520752][C-0000fe75]: channel.c:3843 __ast_read: DTMF end '1' received on PJSIP/incoming-0001e166, duration 140 ms
[Sep 28 11:52:44] DTMF[1520752][C-0000fe75]: channel.c:3932 __ast_read: DTMF end passthrough '1' on PJSIP/incoming-0001e166
[Sep 28 11:52:45] DTMF[1520752][C-0000fe75]: channel.c:3957 __ast_read: DTMF begin '#' received on PJSIP/incoming-0001e166
[Sep 28 11:52:45] DTMF[1520752][C-0000fe75]: channel.c:3961 __ast_read: DTMF begin ignored '#' on PJSIP/incoming-0001e166
[Sep 28 11:52:45] DTMF[1520752][C-0000fe75]: channel.c:3843 __ast_read: DTMF end '#' received on PJSIP/incoming-0001e166, duration 140 ms
[Sep 28 11:52:45] DTMF[1520752][C-0000fe75]: channel.c:3932 __ast_read: DTMF end passthrough '#' on PJSIP/incoming-0001e166
you mean to catch a RTP stream and listen all DTMF ?
If you are using RFC 4733 properly at the source end, there will be nothing to listen to, as it will be being sent with specially binary encoded packets which show up quite well on wireshark.
I had to wait to late. I grabbed some traffic from start to end a call and in wireshark I see an rtpevents.
what I should do next? I still dont know why DTMF are so slow. Why I have to wait 3 sec or longer until whole number come to my system.
Does the wireshark output indicate they are slow in arriving, or slow in being acted upon. If the former, you need to look upstream of Asterisk.
You need to correlate the time field for the first end event on the # or last digit with other events (like all initiations, or Asterisk log events. You will need to calibrate the zero point of the times between the different data streams. You should make sure you have high resolution time stamps set in logger.conf.
I would note that the digits are being sent quite slowly, less than two a second.
Just a ‘drive-by’ observation based on my experience and not reading all the posts to this topic…
When I enter series of DTMF like an account number from my cell, even though I make the entry very quickly, my cell provider delivers the key strokes at a very measured and leisurely pace.
Exactly same here. I stroke my phone numbers like my clients, but dtmf are come slower then I provide. Can it be solved?