Am I the only seeing 'cop 48' weirdness in ASL3?

N0NB · July 4, 2024, 5:19pm

On the repeater I’m testing ASL3 on, one of the things I set up long ago is to send a DTMF string from the node to the CAT-250 controller to disable CTCSS on the repeater during a net. The command in question is:

/usr/sbin/asterisk -rx "rpt cmd *node* cop 48 2,0,0,1,2,0"

Testing the command I noted that the controller did not respond to the command with its voice. I disabled the DTMF mute on the controller to listen to the audio from the node and heard perhaps one or two digits at odd intervals.

Just to be sure I shutdown and restarted the Pi 3B+ with the ASL2 image and the command works as expected with clean audio and all six DTMF digits clearly heard and the commands accepted by the controller.

I booted back into ASL3 and it was back to the same weirdness with only one or two digits sent. I kept sending the command and on the fourth run it sent all six digits and the controller accepted the command. I then tried the other command to assert CTCSS and it took three tries for all six digits to be sent and the controller to accept the command.

I do have audio from both the ASL2 and ASL3 runs if that helps.

So far I’ve not noticed any audio glitches on time or connect/disconnect voice announcements. I’ve not had an actual conversation to know if there are any glitches in audio to/from the network.

N0NB · July 5, 2024, 2:21am

Any tips on getting some debugging info out of the asterisk console? I see the rpt_telemetry() function calls ast_debug but setting core set verbose 9999 only popped up the following after issuing the command:

w0dod-asl*CLI> rpt cmd 519321 cop 48 2,0,0,1,2,0
    -- Hungup 'DAHDI/pseudo-972334223'

And so on.

kb4mdd · July 5, 2024, 10:39am

core set debug 7 app_rpt.so

Danny

N0NB · July 5, 2024, 10:43am

That looked promising but it didn’t show anything.

w0dod-asl*CLI> core set debug 7 app_rpt.so
Core debug was 0 and has been set to 7 for 'app_rpt'.
w0dod-asl*CLI> rpt cmd 519321 cop 48 2,0,0,1,2,0
w0dod-asl*CLI> rpt cmd 519321 cop 48 2,0,0,1,2,1
w0dod-asl*CLI>

wd6awp · July 7, 2024, 2:17pm

There is a Pi3 bug fix in the next release. Workaround is to always restart asterisk after a boot.

See for details. It’s not always a Tx lockup.

github.com/AllStarLink/ASL3

Tx gets stuck on during bootup...

opened 04:48AM - 02 Jul 24 UTC

w8cpt

bug

Pi 3 A+ and a AURSINC Allstar RF Node UHF SR-FRS Radio Programming Module for A…llstar hangs up and leaves TX on when I shut down the node properly after the install and reboot it. Here's a video and my buddies Shari Pi-hat did the same thing. He put a 30 second delay in Asterisk an entry in system d service file and it seemed to correct it...I don't know how to do that! https://youtu.be/mnH9BxGZWqQ?si=lEwRawGfE0p0Ch5a **Have you run a software update and rebooted?** - YES **Pi 3 A+

Also newer Asterisk has a setting to see DTMF or not. In logger.conf see

console => notice,warning,error,dtmf

N0NB · July 7, 2024, 4:46pm

I added debug to the console line in logger.conf, restarted Asterisk and here a sample output:

w0dod-asl*CLI> rpt cmd 519321 cop 48 2,0,0,1,2,0
[2024-07-07 11:43:50.782] DEBUG[113381]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113381 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113338 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:50.822] DEBUG[113338]: channel.c:5496 ast_write_stream: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:50.844] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:50.904] DEBUG[113381]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113381 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113338 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:50.914] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:50.982] DEBUG[113338]: channel.c:5496 ast_write_stream: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:50.983] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.022] DEBUG[113338]: channel.c:5496 ast_write_stream: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.024] DEBUG[113381]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113381 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113338 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.043] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.082] DEBUG[113338]: channel.c:5496 ast_write_stream: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.082] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.085] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.122] DEBUG[113338]: channel.c:5496 ast_write_stream: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.123] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.162] DEBUG[113338]: channel.c:5496 ast_write_stream: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.163] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.170] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.202] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.213] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.243] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.282] DEBUG[113338]: channel.c:5496 ast_write_stream: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.283] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.298] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.322] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.341] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.363] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.423] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.426] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.462] DEBUG[113338]: channel.c:5496 ast_write_stream: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.502] DEBUG[113338]: channel.c:5496 ast_write_stream: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.503] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.544] DEBUG[113381]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113381 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113338 in procedure ast_waitfor_nandfds
[2024-07-07 11:43:51.554] DEBUG[113338]: channel.c:3071 ast_waitfor_nandfds: Thread LWP 113338 is blocking 'SimpleUSB/519321', already blocked by thread LWP 113381 in procedure ast_waitfor_nandfds

It sounded like two digits were passed out of the six but I’m not sure which ones.

I tried a DTMF decoder app on my phone but it didn’t capture anything useful.

wd6awp · July 7, 2024, 8:06pm

I am not able to reproduce that error.

rpi5*CLI> rpt cmd 2506 cop 48 2,0,0,1,2,0
    -- Hungup 'DAHDI/pseudo-1217849695'
    -- Hungup 'DAHDI/pseudo-1862312413'
rpi5*CLI>

How well is your node functioning otherwise?

N0NB · July 7, 2024, 11:06pm

As near as I can tell things are normal. I have a net announcement running at the bottom of the hour generated from a text-to-speech script and it plays with my main repeater running HamVOIP as scheduled (I listen on a dual-band radio). I’m running *712 at the top of an hour without issue. Links work as expected and until I run the net tonight I haven’t had a long run on passed audio but so far I’ve not noticed any slips or anything.

AI3I · January 9, 2025, 12:42am

I too am having issues with generation of any tone sequence, be it a two-tone combination, DTMF, or anything else. The tone sequence will be cut off, garbled, over-sampled, or all sorts of variations, and is specific only to cop 48 behavior. Tones generated as CW or any sound file playback does so with general fidelity through other means; again, this is only specific to calling cop 48.

I’m using ASL3 (Asterisk 20.11.0+asl3-3.2.0-2.deb12) on a RPi 3B+, for what that’s worth. I’m trying to see if I can capture more debugging or behavior. I should also note that attempting to flush telemetry through cop 24 does not stop any tone sequence already being transmitted; whatever was in the buffer continues on indefinitely and may stop or restart at non-specific intervals.

Mike · January 9, 2025, 12:51am

I do believe that a cop,24 flush is only for audio buffer and not for generational items.

AI3I · January 9, 2025, 1:06am

root@node504381:~# asl-show-version 
********** AllStarLink [ASL] Version Info **********

OS            : Debian GNU/Linux 12 (bookworm)
OS Kernel     : 6.6.62+rpt-rpi-v8

Asterisk      : 20.11.0+asl3-3.2.0-2.deb12
ASL [app_rpt] : 3.2.0

Installed ASL packages :

  Package                         Version
  ==============================  ==============================
  allmon3                         1.4.2-1.deb12
  asl3                            3.6.0-1.deb
  asl3-asterisk                   2:20.11.0+asl3-3.2.0-2.deb12
  asl3-asterisk-config            2:20.11.0+asl3-3.2.0-2.deb12
  asl3-asterisk-modules           2:20.11.0+asl3-3.2.0-2.deb12
  asl3-menu                       1.11-1.deb12
  asl3-pi-appliance               1.9.0-5.deb12
  asl3-update-nodelist            1.5.1-1.deb12
  cockpit                         287.1-0+deb12u3
  cockpit-bridge                  287.1-0+deb12u3
  cockpit-networkmanager          287.1-0+deb12u3
  cockpit-packagekit              287.1-0+deb12u3
  cockpit-sosreport               287.1-0+deb12u3
  cockpit-storaged                287.1-0+deb12u3
  cockpit-system                  287.1-0+deb12u3
  cockpit-wifimanager             1.1.1-1.deb12
  cockpit-ws                      287.1-0+deb12u3
  dahdi                           1:3.1.0-2
  dahdi-dkms                      1:3.4.0-4+asl
  dahdi-linux                     1:3.4.0-4+asl

AI3I · January 9, 2025, 1:07am

Good to know; I assumed it would halt anything app_rpt generated, or attempt to.

N0NB · January 12, 2025, 7:46pm

Here are sound files of the truncated digits:

The first two should have sent the string 2,0,0,1,2,0 and the third 2,0,0,1,2,1. In none of the cases was the command accepted by the CAT-250 controller.

It seems to me this will require the use of git bisect to determine what change took place. I did try to make sense of the code last summer but got lost in it, I think. As I noted in my OP the digits will play correctly with ASL2 and HamVoIP.

Besides Asterisk app_rpt, the system is using Simple USB and the sound interface is a Techno By George CM108 based FOB. Telemetry and user audio suffer no such glitching that I have observed either at this node or to another.

Mike · January 20, 2025, 3:24pm

What duplex mode are you using and are you using link2link=yes ?
Is this is a wired link or RF to the cat controller ?

AI3I · February 1, 2025, 3:47am

Bug Filed: cop,48 produces choppy and broken telemetry · Issue #124 · AllStarLink/ASL3 · GitHub

N8EI · February 1, 2025, 5:35pm

Bug moved: cop,48 produces choppy and broken telemetry · Issue #481 · AllStarLink/app_rpt · GitHub

N0NB · July 1, 2025, 8:19pm

Sorry for the delay.

I just upgraded this particular node today and am happy to report that the DTMF command string now works the sale as in ASL2.

Thanks to all who hunted down and squashed this bug.

system · July 4, 2025, 8:19pm

This topic was automatically closed 3 days after the last reply. New replies are no longer allowed.