"Exceptionally long voice queue length" during DTMF when joining node with > 4 char number

I am just now testing ASL3 and seem to have found an issue I don’t see any discussion about. I have tried the latest PI applicance img as well as installing Debian 12 and then ASL3 from there. Using PI3b+ and 5 for testing. Everything installs fine and things seem to work well. But… I get the Exeptionally Long voice queue length error when entering more than 6 DTMF characters. I have a radio connected with a URIx and a phone connected via IAX and DVSwitch. Neither channel will receive a 7th DTMF character in time. When I send the tones with DVSwitch, six go through, then there is about a 15 second pause, then the long voice queue error, and then the 7th DTMF character is logged. So if I dial *349520 to link another node, it never works because the last character is not detected before the timeout. Here is what the log looks like via DVSwitch:

[2024-08-23 16:19:16.057] DTMF[1464] channel.c: DTMF end ‘’ received on IAX2/iaxclient-14418, duration 0 ms
[2024-08-23 16:19:16.057] DTMF[1464] channel.c: DTMF begin emulation of '
’ with duration 100 queued on IAX2/iaxclient-14418
[2024-08-23 16:19:16.157] DTMF[1464] channel.c: DTMF end emulation of ‘*’ queued on IAX2/iaxclient-14418
[2024-08-23 16:19:16.203] DTMF[1464] channel.c: DTMF end ‘3’ received on IAX2/iaxclient-14418, duration 0 ms
[2024-08-23 16:19:16.203] DTMF[1464] channel.c: DTMF begin emulation of ‘3’ with duration 100 queued on IAX2/iaxclient-14418
[2024-08-23 16:19:16.303] DTMF[1464] channel.c: DTMF end emulation of ‘3’ queued on IAX2/iaxclient-14418
[2024-08-23 16:19:16.364] DTMF[1464] channel.c: DTMF end ‘4’ received on IAX2/iaxclient-14418, duration 0 ms
[2024-08-23 16:19:16.364] DTMF[1464] channel.c: DTMF begin emulation of ‘4’ with duration 100 queued on IAX2/iaxclient-14418
[2024-08-23 16:19:16.464] DTMF[1464] channel.c: DTMF end emulation of ‘4’ queued on IAX2/iaxclient-14418
[2024-08-23 16:19:16.524] DTMF[1464] channel.c: DTMF end ‘9’ received on IAX2/iaxclient-14418, duration 0 ms
[2024-08-23 16:19:16.524] DTMF[1464] channel.c: DTMF begin emulation of ‘9’ with duration 100 queued on IAX2/iaxclient-14418
[2024-08-23 16:19:16.624] DTMF[1464] channel.c: DTMF end emulation of ‘9’ queued on IAX2/iaxclient-14418
[2024-08-23 16:19:16.684] DTMF[1464] channel.c: DTMF end ‘5’ received on IAX2/iaxclient-14418, duration 0 ms
[2024-08-23 16:19:16.684] DTMF[1464] channel.c: DTMF begin emulation of ‘5’ with duration 100 queued on IAX2/iaxclient-14418
[2024-08-23 16:19:16.784] DTMF[1464] channel.c: DTMF end emulation of ‘5’ queued on IAX2/iaxclient-14418
[2024-08-23 16:19:16.844] DTMF[1464] channel.c: DTMF end ‘2’ received on IAX2/iaxclient-14418, duration 0 ms
[2024-08-23 16:19:16.844] DTMF[1464] channel.c: DTMF begin emulation of ‘2’ with duration 100 queued on IAX2/iaxclient-14418
[2024-08-23 16:19:16.944] DTMF[1464] channel.c: DTMF end emulation of ‘2’ queued on IAX2/iaxclient-14418
[2024-08-23 16:19:32.516] WARNING[1459] channel.c: Exceptionally long voice queue length (97 voice / 98 total) queuing to IAX2/iaxclient-14418
[2024-08-23 16:19:35.345] DTMF[1464] channel.c: DTMF end ‘0’ received on IAX2/iaxclient-14418, duration 0 ms
[2024-08-23 16:19:35.345] DTMF[1464] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on IAX2/iaxclient-14418
[2024-08-23 16:19:35.445] DTMF[1464] channel.c: DTMF end emulation of ‘0’ queued on IAX2/iaxclient-14418

If I try the same DTMF via the radio, a similar problem but the queue error appears once or sometimes repeats a few times and the final DTMF character is lost:

[2024-08-23 16:21:06.670] DTMF[1464] channel.c: DTMF begin ‘’ received on Radio/49555
[2024-08-23 16:21:06.670] DTMF[1464] channel.c: DTMF begin passthrough '
’ on Radio/49555
[2024-08-23 16:21:06.904] DTMF[1464] channel.c: DTMF end ‘’ received on Radio/49555, duration 234 ms
[2024-08-23 16:21:06.904] DTMF[1464] channel.c: DTMF end accepted with begin '
’ on Radio/49555
[2024-08-23 16:21:06.904] DTMF[1464] channel.c: DTMF end passthrough ‘*’ on Radio/49555
[2024-08-23 16:21:07.352] DTMF[1464] channel.c: DTMF begin ‘3’ received on Radio/49555
[2024-08-23 16:21:07.352] DTMF[1464] channel.c: DTMF begin passthrough ‘3’ on Radio/49555
[2024-08-23 16:21:07.651] DTMF[1464] channel.c: DTMF end ‘3’ received on Radio/49555, duration 298 ms
[2024-08-23 16:21:07.651] DTMF[1464] channel.c: DTMF end accepted with begin ‘3’ on Radio/49555
[2024-08-23 16:21:07.651] DTMF[1464] channel.c: DTMF end passthrough ‘3’ on Radio/49555
[2024-08-23 16:21:08.247] DTMF[1464] channel.c: DTMF begin ‘4’ received on Radio/49555
[2024-08-23 16:21:08.247] DTMF[1464] channel.c: DTMF begin passthrough ‘4’ on Radio/49555
[2024-08-23 16:21:08.462] DTMF[1464] channel.c: DTMF end ‘4’ received on Radio/49555, duration 214 ms
[2024-08-23 16:21:08.462] DTMF[1464] channel.c: DTMF end accepted with begin ‘4’ on Radio/49555
[2024-08-23 16:21:08.462] DTMF[1464] channel.c: DTMF end passthrough ‘4’ on Radio/49555
[2024-08-23 16:21:08.931] DTMF[1464] channel.c: DTMF begin ‘9’ received on Radio/49555
[2024-08-23 16:21:08.931] DTMF[1464] channel.c: DTMF begin passthrough ‘9’ on Radio/49555
[2024-08-23 16:21:09.144] DTMF[1464] channel.c: DTMF end ‘9’ received on Radio/49555, duration 213 ms
[2024-08-23 16:21:09.144] DTMF[1464] channel.c: DTMF end accepted with begin ‘9’ on Radio/49555
[2024-08-23 16:21:09.144] DTMF[1464] channel.c: DTMF end passthrough ‘9’ on Radio/49555
[2024-08-23 16:21:09.571] DTMF[1464] channel.c: DTMF begin ‘5’ received on Radio/49555
[2024-08-23 16:21:09.571] DTMF[1464] channel.c: DTMF begin passthrough ‘5’ on Radio/49555
[2024-08-23 16:21:09.742] DTMF[1464] channel.c: DTMF end ‘5’ received on Radio/49555, duration 171 ms
[2024-08-23 16:21:09.742] DTMF[1464] channel.c: DTMF end accepted with begin ‘5’ on Radio/49555
[2024-08-23 16:21:09.742] DTMF[1464] channel.c: DTMF end passthrough ‘5’ on Radio/49555
[2024-08-23 16:21:09.976] DTMF[1464] channel.c: DTMF begin ‘2’ received on Radio/49555
[2024-08-23 16:21:09.976] DTMF[1464] channel.c: DTMF begin passthrough ‘2’ on Radio/49555
[2024-08-23 16:21:10.168] DTMF[1464] channel.c: DTMF end ‘2’ received on Radio/49555, duration 192 ms
[2024-08-23 16:21:10.168] DTMF[1464] channel.c: DTMF end accepted with begin ‘2’ on Radio/49555
[2024-08-23 16:21:10.168] DTMF[1464] channel.c: DTMF end passthrough ‘2’ on Radio/49555
[2024-08-23 16:21:25.541] WARNING[1453] channel.c: Exceptionally long voice queue length (97 voice / 97 total) queuing to IAX2/iaxclient-14418

I am able to connect the node using the Allmon3 interface and the linking is fine. And voice seems to work in a QSO, it’s just the DTMF that seems to create the error. I have reinstalled the OS and Allstar a couple of times on the 2 different PIs and it’s always the exact same result. If anyone has any ideas on how I could troubleshoot further I would appreciate it.

Asterisk 20.9.1+asl3-3.0.4-1.deb12

It won’t let me put the asl-node-lookup results because it thinks it’s a link. But, the node seems to be able to be looked up and results from google DNS are the same. It being this website. I enabled the beta channel and tried the asl-node-lookup with local and google DNS.

I tried entering a long string of DTMF with time announce at the beginning like this:

*722722722

The result is the node ‘hears’ all 10 chars and logs them normally, and it does announce the time once as expected. If I enter 722722722 it will hear all 12 chars (interface not showing the other 2 ""), log them in /var/log/asterisk/messages, and announce the time 3 times. It’s only node link that barfs on the 6th char. Unlink works fine longer than 6 chars.

The time command:
[2024-08-24 15:11:47.169] DTMF[1464] channel.c: DTMF end ‘’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:47.169] DTMF[1464] channel.c: DTMF begin emulation of '
’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:47.269] DTMF[1464] channel.c: DTMF end emulation of ‘’ queued on IAX2/iaxclient-9176
[2024-08-24 15:11:47.330] DTMF[1464] channel.c: DTMF end ‘7’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:47.330] DTMF[1464] channel.c: DTMF begin emulation of ‘7’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:47.430] DTMF[1464] channel.c: DTMF end emulation of ‘7’ queued on IAX2/iaxclient-9176
[2024-08-24 15:11:47.490] DTMF[1464] channel.c: DTMF end ‘2’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:47.490] DTMF[1464] channel.c: DTMF begin emulation of ‘2’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:47.590] DTMF[1464] channel.c: DTMF end emulation of ‘2’ queued on IAX2/iaxclient-9176
[2024-08-24 15:11:47.651] DTMF[1464] channel.c: DTMF end ‘2’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:47.651] DTMF[1464] channel.c: DTMF begin emulation of ‘2’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:47.753] DTMF[1464] channel.c: DTMF end emulation of ‘2’ queued on IAX2/iaxclient-9176
[2024-08-24 15:11:47.813] DTMF[1464] channel.c: DTMF end '
’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:47.813] DTMF[1464] channel.c: DTMF begin emulation of ‘’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:47.913] DTMF[1464] channel.c: DTMF end emulation of '
’ queued on IAX2/iaxclient-9176
[2024-08-24 15:11:47.973] DTMF[1464] channel.c: DTMF end ‘7’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:47.973] DTMF[1464] channel.c: DTMF begin emulation of ‘7’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.074] DTMF[1464] channel.c: DTMF end emulation of ‘7’ queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.134] DTMF[1464] channel.c: DTMF end ‘2’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:48.134] DTMF[1464] channel.c: DTMF begin emulation of ‘2’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.234] DTMF[1464] channel.c: DTMF end emulation of ‘2’ queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.294] DTMF[1464] channel.c: DTMF end ‘2’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:48.294] DTMF[1464] channel.c: DTMF begin emulation of ‘2’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.395] DTMF[1464] channel.c: DTMF end emulation of ‘2’ queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.455] DTMF[1464] channel.c: DTMF end ‘’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:48.455] DTMF[1464] channel.c: DTMF begin emulation of '
’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.555] DTMF[1464] channel.c: DTMF end emulation of ‘*’ queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.616] DTMF[1464] channel.c: DTMF end ‘7’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:48.616] DTMF[1464] channel.c: DTMF begin emulation of ‘7’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.716] DTMF[1464] channel.c: DTMF end emulation of ‘7’ queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.777] DTMF[1464] channel.c: DTMF end ‘2’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:48.777] DTMF[1464] channel.c: DTMF begin emulation of ‘2’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.877] DTMF[1464] channel.c: DTMF end emulation of ‘2’ queued on IAX2/iaxclient-9176
[2024-08-24 15:11:48.937] DTMF[1464] channel.c: DTMF end ‘2’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:11:48.938] DTMF[1464] channel.c: DTMF begin emulation of ‘2’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:11:49.038] DTMF[1464] channel.c: DTMF end emulation of ‘2’ queued on IAX2/iaxclient-9176

The unlink:

[2024-08-24 15:12:52.029] DTMF[1464] channel.c: DTMF end ‘’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:12:52.029] DTMF[1464] channel.c: DTMF begin emulation of '
’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.129] DTMF[1464] channel.c: DTMF end emulation of ‘*’ queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.189] DTMF[1464] channel.c: DTMF end ‘1’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:12:52.189] DTMF[1464] channel.c: DTMF begin emulation of ‘1’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.290] DTMF[1464] channel.c: DTMF end emulation of ‘1’ queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.351] DTMF[1464] channel.c: DTMF end ‘4’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:12:52.351] DTMF[1464] channel.c: DTMF begin emulation of ‘4’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.451] DTMF[1464] channel.c: DTMF end emulation of ‘4’ queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.511] DTMF[1464] channel.c: DTMF end ‘9’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:12:52.511] DTMF[1464] channel.c: DTMF begin emulation of ‘9’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.611] DTMF[1464] channel.c: DTMF end emulation of ‘9’ queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.672] DTMF[1464] channel.c: DTMF end ‘5’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:12:52.672] DTMF[1464] channel.c: DTMF begin emulation of ‘5’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.772] DTMF[1464] channel.c: DTMF end emulation of ‘5’ queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.832] DTMF[1464] channel.c: DTMF end ‘2’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:12:52.832] DTMF[1464] channel.c: DTMF begin emulation of ‘2’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.932] DTMF[1464] channel.c: DTMF end emulation of ‘2’ queued on IAX2/iaxclient-9176
[2024-08-24 15:12:52.993] DTMF[1464] channel.c: DTMF end ‘0’ received on IAX2/iaxclient-9176, duration 0 ms
[2024-08-24 15:12:52.993] DTMF[1464] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on IAX2/iaxclient-9176
[2024-08-24 15:12:53.093] DTMF[1464] channel.c: DTMF end emulation of ‘0’ queued on IAX2/iaxclient-9176

Please open a bug here: Sign in to GitHub · GitHub

Done! dahdi/usbradio channels hang with "Exceptionally long queue length" message when trying to join nodes with more than 4 digits in the node number · Issue #390 · AllStarLink/app_rpt · GitHub … Alright it worked that time! It’s really hard to work issues when you just joined the community. The spam protection has removed my posts and told me I can’t post until tomorrow. I understand spam protection is important, but it does seem a bit aggressive IMHO.

Please see DTMF Linking + DNS Lookup Timeouts - Known Issue.