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

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.

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.

core set debug 7 app_rpt.so

Danny

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> 

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.

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

console => notice,warning,error,dtmf

1 Like

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.

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?

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.