OP25 OP25 No Audio output.

Status
Not open for further replies.

VA4JOE

Member
Joined
Jul 25, 2023
Messages
56
Hi there,

I have installed OP25 on my Debian Bookworm system, but it seems no matter how much I try I can't get it to output audio.
I use the following command:
./rx.py --args 'rtl' -N 'LNA:47' -S 2500000 -x 2 -f 770.19375e6 -o 17e3 -q -2 -v 5 -T trunk.tsv -O hw:1,0 -w -2 -U 2> stderr-stream0.2
I get a screen that shows 4 voice frequencies and so far about 10 unknown talk groups. The tsbks keep going up.
This is the output of part of my stderr-stream0.2 file
Using Python /usr/bin/python3
CPU Features: SSE2+ SSE4.1- AVX- FMA-
Using sse2 for xtrxdsp_iq16_sc32
Using sse2 for xtrxdsp_iq8_ic16
Using sse2 for xtrxdsp_iq16_ic16i
Using sse2 for xtrxdsp_iq8_ic8i
Using sse2 for xtrxdsp_sc32i_iq16
Using sse2 for xtrxdsp_iq8_sc32
Using sse2 for xtrxdsp_iq8_sc32i
Using sse2 for xtrxdsp_iq16_sc32i
Using sse2 for xtrxdsp_sc32_iq16
Using sse2 for xtrxdsp_ic16i_iq16
gr-osmosdr 0.2.0.0 (0.2.0) gnuradio 3.10.5.1
built-in source types: file fcd rtl rtl_tcp uhd hackrf bladerf rfspace airspy airspyhf soapy redpitaya freesrp xtrx
Using device #0 Realtek RTL2838UHIDIR SN: 00000001
Found Rafael Micro R828D tuner
[R82XX] PLL not locked!
gain: name: LNA range: start 0 stop 49 step 0
setting gain LNA to 47
supported sample rates 250000-2560000 step 24000
Exact sample rate is: 2500000.107620 Hz
[R82XX] PLL not locked!
Using two-stage decimator for speed=2500000, decim=25/4 if1=100000 if2=25000
op25_audio::eek:pen_socket(): enabled udp host(127.0.0.1), wireshark(23456), audio(23456)
p25_frame_assembler_impl: do_imbe[1], do_output[0], do_audio_output[1], do_phase2_tdma[1], do_nocrypt[0]
07/25/23 15:23:26.946546 set control channel=770.193750
metadata update not enabled
using ALSA sound system
audio device: hw:1,0
set_rate failed: -22
failed to set up pcm stream
Listening on 127.0.0.1:23456
audio closing
python version detected: 3.11.2 (main, Mar 13 2023, 12:18:29) [GCC 12.2.0]
Allocating 15 zero-copy buffers
07/25/23 15:23:28.585295 add_patch: tgid(42050) is patched to sg(42063)
07/25/23 15:24:03.398501 set tgid=1899, srcaddr=600063
07/25/23 15:24:03.398891 new tgid=1899 Unknown1 prio 3
07/25/23 15:24:03.399124 new freq=771.206250
07/25/23 15:24:03.399390 voice update: tg(1899), freq(771206250), slot(-), prio(3)
07/25/23 15:24:03.479723 set tgid=1899, srcaddr=600063
07/25/23 15:24:04.489790 voice timeout
07/25/23 15:24:05.117419 clear tgid=1899, freq=771.206250, slot=0
07/25/23 15:24:05.117736 clear tgid=1899, freq=771.206250, slot=1
07/25/23 15:24:05.352753 set tgid=1899, srcaddr=0
07/25/23 15:24:05.353095 hold active tg(1899)
07/25/23 15:24:05.353216 voice update: tg(1899), freq(771206250), slot(-), prio(3)
07/25/23 15:24:06.489623 voice timeout
07/25/23 15:24:06.652073 clear tgid=1899, freq=771.206250, slot=0
07/25/23 15:24:06.652329 clear tgid=1899, freq=771.206250, slot=1
07/25/23 15:24:09.330528 set tgid=1899, srcaddr=4929
07/25/23 15:24:09.331131 new freq=771.456250
07/25/23 15:24:09.331432 voice update: tg(1899), freq(771456250), slot(-), prio(3)
07/25/23 15:24:09.410362 set tgid=1899, srcaddr=4929
07/25/23 15:24:09.472708 set tgid=1899, srcaddr=4929
07/25/23 15:24:09.535243 set tgid=1899, srcaddr=0
07/25/23 15:24:10.567136 voice timeout
07/25/23 15:24:10.738308 clear tgid=1899, freq=771.456250, slot=0
07/25/23 15:24:10.738678 clear tgid=1899, freq=771.456250, slot=1
07/25/23 15:24:11.265321 set tgid=1899, srcaddr=0
07/25/23 15:24:11.265655 hold active tg(1899)
07/25/23 15:24:11.265790 voice update: tg(1899), freq(771456250), slot(-), prio(3)
07/25/23 15:24:12.413457 voice timeout
07/25/23 15:24:12.776090 set tgid=1899, srcaddr=600063
07/25/23 15:24:12.777340 clear tgid=1899, freq=771.456250, slot=0
07/25/23 15:24:12.777662 hold active tg(1899)
07/25/23 15:24:12.778057 voice update: tg(1899), freq(771456250), slot(-), prio(3)
07/25/23 15:24:12.835080 set tgid=1899, srcaddr=600063
07/25/23 15:24:13.867654 voice timeout
07/25/23 15:24:14.349397 set tgid=1899, srcaddr=0
07/25/23 15:24:14.351168 hold active tg(1899)
07/25/23 15:24:14.351410 voice update: tg(1899), freq(771456250), slot(-), prio(3)
07/25/23 15:24:15.446200 voice timeout
07/25/23 15:24:15.912872 clear tgid=1899, freq=771.456250, slot=0
07/25/23 15:24:15.913176 clear tgid=1899, freq=771.456250, slot=1
07/25/23 15:24:16.522445 control channel timeout
07/25/23 15:25:48.666358 set tgid=1915, srcaddr=600069
07/25/23 15:25:48.666676 new tgid=1915 prio 3
07/25/23 15:25:48.666819 new freq=771.706250
07/25/23 15:25:48.666975 voice update: tg(1915), freq(771706250), slot(-), prio(3)
07/25/23 15:25:49.757092 voice timeout
07/25/23 15:25:50.333251 clear tgid=1915, freq=771.706250, slot=0
07/25/23 15:25:50.333556 clear tgid=1915, freq=771.706250, slot=1
07/25/23 15:25:50.559322 set tgid=1915, srcaddr=0
07/25/23 15:25:50.559781 hold active tg(1915)
07/25/23 15:25:50.559974 voice update: tg(1915), freq(771706250), slot(-), prio(3)
07/25/23 15:25:51.715279 voice timeout
07/25/23 15:25:51.874745 clear tgid=1915, freq=771.706250, slot=0
07/25/23 15:25:51.875067 clear tgid=1915, freq=771.706250, slot=1
07/25/23 15:25:52.602783 set tgid=1915, srcaddr=4849
07/25/23 15:25:52.603068 voice update: tg(1915), freq(771206250), slot(-), prio(3)
07/25/23 15:25:52.661024 set tgid=1915, srcaddr=4849
07/25/23 15:25:52.756247 set tgid=1915, srcaddr=4849
07/25/23 15:25:53.756801 voice timeout
07/25/23 15:25:54.441925 clear tgid=1915, freq=771.206250, slot=0
07/25/23 15:25:54.442203 clear tgid=1915, freq=771.206250, slot=1
07/25/23 15:25:54.919006 set tgid=1915, srcaddr=0
07/25/23 15:25:54.919537 voice update: tg(1915), freq(771206250), slot(-), prio(3)
07/25/23 15:25:56.079030 voice timeout
07/25/23 15:25:56.576123 clear tgid=1915, freq=771.206250, slot=0
07/25/23 15:25:56.578122 clear tgid=1915, freq=771.206250, slot=1
07/25/23 15:25:57.015757 set tgid=1915, srcaddr=0
07/25/23 15:25:57.016093 voice update: tg(1915), freq(771206250), slot(-), prio(3)
07/25/23 15:25:58.160481 voice timeout
07/25/23 15:25:58.646642 clear tgid=1915, freq=771.206250, slot=0
07/25/23 15:25:58.646844 clear tgid=1915, freq=771.206250, slot=1
07/25/23 15:25:58.734307 set tgid=1915, srcaddr=0
07/25/23 15:25:58.734648 hold active tg(1915)
07/25/23 15:25:58.734779 voice update: tg(1915), freq(771206250), slot(-), prio(3)
07/25/23 15:25:59.894890 voice timeout
07/25/23 15:26:00.279401 clear tgid=1915, freq=771.206250, slot=0
07/25/23 15:26:00.279726 clear tgid=1915, freq=771.206250, slot=1
07/25/23 15:26:00.382787 set tgid=1915, srcaddr=0
07/25/23 15:26:00.383902 hold active tg(1915)
07/25/23 15:26:00.384095 voice update: tg(1915), freq(771206250), slot(-), prio(3)
07/25/23 15:26:01.474577 voice timeout
07/25/23 15:26:01.840931 clear tgid=1915, freq=771.206250, slot=0
07/25/23 15:26:01.841189 clear tgid=1915, freq=771.206250, slot=1
Flowgraph completed. Exiting
Not sure what the problem is but I'm crawling the walls and tearing my hair out trying to search for and find an answer.
 

wgbecks

Active Member
Joined
Jan 17, 2005
Messages
1,020
Location
NE Wisconsin
I am not familiar with the debian Bookworm OS but you might want to try directing audio to use the default Linux sound device by using
the -U command line argument for op25 instead of -O hw:1,0 to let the operating system decide if the sound device accessable under ALSA
or in its actually under control of Pulse Audio.
 

VA4JOE

Member
Joined
Jul 25, 2023
Messages
56
I am not familiar with the debian Bookworm OS but you might want to try directing audio to use the default Linux sound device by using
the -U command line argument for op25 instead of -O hw:1,0 to let the operating system decide if the sound device accessable under ALSA
or in its actually under control of Pulse Audio.
It is in the command I used near the end.
./rx.py --args 'rtl' -N 'LNA:47' -S 2500000 -x 2 -f 770.19375e6 -o 17e3 -q -2 -v 5 -T trunk.tsv -O hw:1,0 -w -2 -U 2> stderr-stream0.2
I changed it to this:
./rx.py --args 'rtl' -N 'LNA:47' -S 2400000 -x 2 -f 770.19375e6 -o 25000 -S 8000 -q -2 -v 5 -T trunk.tsv -w -2 -U 2> stderr-stream0.2
and then the stderr-stream0.2 file shows:
metadata update not enabled
using ALSA sound system
audio device: default
Listening on 127.0.0.1:23456
python version detected: 3.11.2 (main, Mar 13 2023, 12:18:29) [GCC 12.2.0]
Allocating 15 zero-copy buffers
So the error disappears but I still get no audio.
 
Last edited:

wgbecks

Active Member
Joined
Jan 17, 2005
Messages
1,020
Location
NE Wisconsin
It is in the command I used near the end.

I changed it to this:

and then the stderr-stream0.2 file shows:

So the error disappears but I still get no audio.

Your rx.py command line is a mess! For one, you're trying to direct audio to both the "Wireshark" (UDP) port (-w ) while expecting to receive audio from the Linux sound device using the (-U) command line argument. It has to be one or the other. You'll also need to include the
(-V) option to enable the Phase-1 vocoder. Also, don't arbitrarily add the (-x2) option as this will boost decoded audio levels that may well
introduce unwanted distortion.

Stick to the basics first and get it working! Then go back and fine tune options/settings as necessary. Begin testing using the following
rx.py command line shown below.

./rx.py --args 'rtl' -N 'LNA:47' -S 1000000 -f 770.19375e6 -o 25000 -q -2 -T trunk.tsv -U -V -2 -v 5 2> stderr-stream0.2


.
 

VA4JOE

Member
Joined
Jul 25, 2023
Messages
56
Your rx.py command line is a mess! For one, you're trying to direct audio to both the "Wireshark" (UDP) port (-w ) while expecting to receive audio from the Linux sound device using the (-U) command line argument. It has to be one or the other. You'll also need to include the
(-V) option to enable the Phase-1 vocoder. Also, don't arbitrarily add the (-x2) option as this will boost decoded audio levels that may well
introduce unwanted distortion.

Stick to the basics first and get it working! Then go back and fine tune options/settings as necessary. Begin testing using the following
rx.py command line shown below.

./rx.py --args 'rtl' -N 'LNA:47' -S 1000000 -f 770.19375e6 -o 25000 -q -2 -T trunk.tsv -U -V -2 -v 5 2> stderr-stream0.2
Using the command:
./rx.py --args 'rtl' -N 'LNA:47' -S 1000000 -f 770.19375e6 -o 25000 -q -2 -T trunk.tsv -U -V -2 -v 5 2> stderr-stream0.2
I get no audio but the following in the stderr-stream0.2 file:
Using Python /usr/bin/python3
CPU Features: SSE2+ SSE4.1- AVX- FMA-
Using sse2 for xtrxdsp_iq16_sc32
Using sse2 for xtrxdsp_iq8_ic16
Using sse2 for xtrxdsp_iq16_ic16i
Using sse2 for xtrxdsp_iq8_ic8i
Using sse2 for xtrxdsp_sc32i_iq16
Using sse2 for xtrxdsp_iq8_sc32
Using sse2 for xtrxdsp_iq8_sc32i
Using sse2 for xtrxdsp_iq16_sc32i
Using sse2 for xtrxdsp_sc32_iq16
Using sse2 for xtrxdsp_ic16i_iq16
gr-osmosdr 0.2.0.0 (0.2.0) gnuradio 3.10.5.1
built-in source types: file fcd rtl rtl_tcp uhd hackrf bladerf rfspace airspy airspyhf soapy redpitaya freesrp xtrx
Using device #0 Realtek RTL2838UHIDIR SN: 00000001
Found Rafael Micro R828D tuner
[R82XX] PLL not locked!
gain: name: LNA range: start 0 stop 49 step 0
setting gain LNA to 47
supported sample rates 250000-2560000 step 24000
Exact sample rate is: 1000000.026491 Hz
[R82XX] PLL not locked!
Using two-stage decimator for speed=1000000, decim=10/4 if1=100000 if2=25000
op25_audio::eek:pen_socket(): enabled udp host(127.0.0.1), wireshark(23456), audio(23456)
p25_frame_assembler_impl: do_imbe[1], do_output[0], do_audio_output[1], do_phase2_tdma[1], do_nocrypt[0]
07/25/23 19:32:05.203451 set control channel=770.193750
metadata update not enabled
using ALSA sound system
audio device: default
Listening on 127.0.0.1:23456
python version detected: 3.11.2 (main, Mar 13 2023, 12:18:29) [GCC 12.2.0]
Allocating 15 zero-copy buffers
07/25/23 19:32:06.266308 control channel timeout
07/25/23 19:32:06.524488 add_patch: tgid(42050) is patched to sg(42063)
07/25/23 19:32:28.810738 set tgid=1899, srcaddr=600061
07/25/23 19:32:28.811049 new tgid=1899 Unknown1 prio 3
07/25/23 19:32:28.811189 new freq=771.956250
07/25/23 19:32:28.811365 voice update: tg(1899), freq(771956250), slot(-), prio(3)
07/25/23 19:32:28.867194 set tgid=1899, srcaddr=600061
07/25/23 19:32:30.242237 voice timeout
07/25/23 19:32:30.606757 clear tgid=1899, freq=771.956250, slot=0
07/25/23 19:32:30.607401 clear tgid=1899, freq=771.956250, slot=1
07/25/23 19:32:31.055792 set tgid=1899, srcaddr=5185
07/25/23 19:32:31.056138 voice update: tg(1899), freq(771956250), slot(-), prio(3)
07/25/23 19:32:31.163016 set tgid=1899, srcaddr=5185
07/25/23 19:32:31.295941 set tgid=1899, srcaddr=0
07/25/23 19:32:32.467000 voice timeout
07/25/23 19:32:32.635396 clear tgid=1899, freq=771.956250, slot=0
07/25/23 19:32:32.635674 clear tgid=1899, freq=771.956250, slot=1
07/25/23 19:32:33.280734 set tgid=1899, srcaddr=0
07/25/23 19:32:33.281210 voice update: tg(1899), freq(771956250), slot(-), prio(3)
07/25/23 19:32:33.677641 set tgid=1899, srcaddr=0
07/25/23 19:32:34.692291 voice timeout
07/25/23 19:32:35.157873 clear tgid=1899, freq=771.956250, slot=0
07/25/23 19:32:35.158081 clear tgid=1899, freq=771.956250, slot=1
07/25/23 19:32:35.363951 set tgid=1899, srcaddr=0
07/25/23 19:32:35.364290 voice update: tg(1899), freq(771956250), slot(-), prio(3)
07/25/23 19:32:35.638469 set tgid=1899, srcaddr=0
07/25/23 19:32:36.798997 voice timeout
07/25/23 19:32:37.174209 clear tgid=1899, freq=771.956250, slot=0
07/25/23 19:32:37.174426 clear tgid=1899, freq=771.956250, slot=1
07/25/23 19:32:37.331481 set tgid=1899, srcaddr=600061
07/25/23 19:32:37.331796 new freq=771.456250
07/25/23 19:32:37.331909 hold active tg(1899)
07/25/23 19:32:37.332034 voice update: tg(1899), freq(771456250), slot(-), prio(3)
07/25/23 19:32:37.592272 set tgid=1899, srcaddr=0
07/25/23 19:32:38.761462 voice timeout
07/25/23 19:32:39.231155 clear tgid=1899, freq=771.456250, slot=0
07/25/23 19:32:39.231465 clear tgid=1899, freq=771.456250, slot=1
07/25/23 19:32:39.297251 set tgid=1899, srcaddr=0
07/25/23 19:32:39.297534 hold active tg(1899)
07/25/23 19:32:39.297685 voice update: tg(1899), freq(771456250), slot(-), prio(3)
07/25/23 19:32:39.681286 set tgid=1899, srcaddr=0
07/25/23 19:32:40.728376 voice timeout
07/25/23 19:32:41.295445 clear tgid=1899, freq=771.456250, slot=0
07/25/23 19:32:41.295733 clear tgid=1899, freq=771.456250, slot=1
07/25/23 19:32:41.652825 set tgid=1899, srcaddr=0
07/25/23 19:32:41.653212 voice update: tg(1899), freq(771456250), slot(-), prio(3)
07/25/23 19:32:41.929523 set tgid=1899, srcaddr=0
07/25/23 19:32:42.960290 voice timeout
07/25/23 19:32:43.326779 clear tgid=1899, freq=771.456250, slot=0
07/25/23 19:32:43.327210 clear tgid=1899, freq=771.456250, slot=1
07/25/23 19:32:43.744585 set tgid=1899, srcaddr=0
07/25/23 19:32:43.745042 voice update: tg(1899), freq(771456250), slot(-), prio(3)
07/25/23 19:32:44.007635 set tgid=1899, srcaddr=0
07/25/23 19:32:45.055463 voice timeout
07/25/23 19:32:45.349534 clear tgid=1899, freq=771.456250, slot=0
07/25/23 19:32:45.349753 clear tgid=1899, freq=771.456250, slot=1
07/25/23 19:32:46.109914 set tgid=1899, srcaddr=0
07/25/23 19:32:46.110262 voice update: tg(1899), freq(771456250), slot(-), prio(3)
07/25/23 19:32:46.381620 set tgid=1899, srcaddr=0
Flowgraph completed. Exiting
Are control and voice channel timeouts something to be concerned about? Still no audio.
From the README file:
It is still necessary to specify the "-w" (wireshark) option if using
either the internal or external audio server.
 
Last edited:

VA4JOE

Member
Joined
Jul 25, 2023
Messages
56
The README file also states:
NOTE 1: For phase1 voice the "-V" option is not used. Instead the
"-w" option is used (see AUDIO SERVER section, below). For P25 phase 2/TDMA audio decode,
the "-2" option is required in addition to the "-w" option.
And I thought since the P25 system I am trying to decode is said to be Phase 1 I should omit "-V".
 

wgbecks

Active Member
Joined
Jan 17, 2005
Messages
1,020
Location
NE Wisconsin
You're getting some control channel decode but it doesn't appear there's any voice channel decode that explains why no audio.
In order to analyze what's wrong, the logging verbose needs to be increased to -v 10 that will write detailed information into the
logfile when executing op25. Increase logging verbose, restart op25 and allow it to run for a couple of minutes then capture and
post the new logfile.

Additionally, it will be very helpful to post your trunk.tsv file along with screen captures of the FFT, Constellation, and Mixer plots
taken while op25 is operating as a means to analyze signal quality and tuning accuracy that are equally important in achieving
reliable decodes of both the control and voice trunk channels.

Submit the following from the command line and post the output responses.

cd _~/op25
git branch <Looking for Response>
apt list gnuradio-dev <Looking for Response>
 

VA4JOE

Member
Joined
Jul 25, 2023
Messages
56
You're getting some control channel decode but it doesn't appear there's any voice channel decode that explains why no audio.
In order to analyze what's wrong, the logging verbose needs to be increased to -v 10 that will write detailed information into the
logfile when executing op25. Increase logging verbose, restart op25 and allow it to run for a couple of minutes then capture and
post the new logfile.

Additionally, it will be very helpful to post your trunk.tsv file along with screen captures of the FFT, Constellation, and Mixer plots
taken while op25 is operating as a means to analyze signal quality and tuning accuracy that are equally important in achieving
reliable decodes of both the control and voice trunk channels.

Submit the following from the command line and post the output responses.

cd _~/op25
git branch <Looking for Response>
apt list gnuradio-dev <Looking for Response>
~/op25$ git branch
* gr310
master
~/op25$ apt list gnuradio-dev
Listing... Done
gnuradio-dev/stable,now 3.10.5.1-3 amd64 [installed]
gnuradio-dev/stable 3.10.5.1-3 i386
trunk.tsv
"Sysname" "Control Channel List" "Offset" "NAC" "Modulation" "TGID Tags File" "Whitelist" "Blacklist" "Center Frequency"
"P25 SYSTEM" "770.193750,770.456250,770.706250,770.956250" "0" "0x9ec" "CQPSK" "manitoba.tsv" "" "" ""
Took screenshots of some plots:Gnuplot.pngRawMixer.pngTunedMixer.pngConstellation.png
Couldn't Find an FFT Plot.
Stderr-stream0.2:partial file--->
Using Python /usr/bin/python3
CPU Features: SSE2+ SSE4.1- AVX- FMA-
Using sse2 for xtrxdsp_iq16_sc32
Using sse2 for xtrxdsp_iq8_ic16
Using sse2 for xtrxdsp_iq16_ic16i
Using sse2 for xtrxdsp_iq8_ic8i
Using sse2 for xtrxdsp_sc32i_iq16
Using sse2 for xtrxdsp_iq8_sc32
Using sse2 for xtrxdsp_iq8_sc32i
Using sse2 for xtrxdsp_iq16_sc32i
Using sse2 for xtrxdsp_sc32_iq16
Using sse2 for xtrxdsp_ic16i_iq16
gr-osmosdr 0.2.0.0 (0.2.0) gnuradio 3.10.5.1
built-in source types: file fcd rtl rtl_tcp uhd hackrf bladerf rfspace airspy airspyhf soapy redpitaya freesrp xtrx
Using device #0 Realtek RTL2838UHIDIR SN: 00000001
Found Rafael Micro R828D tuner
[R82XX] PLL not locked!
gain: name: LNA range: start 0 stop 49 step 0
setting gain LNA to 47
supported sample rates 250000-2560000 step 24000
Exact sample rate is: 1000000.026491 Hz
[R82XX] PLL not locked!
Using two-stage decimator for speed=1000000, decim=10/4 if1=100000 if2=25000
op25_audio::eek:pen_socket(): enabled udp host(127.0.0.1), wireshark(23456), audio(23456)
p25_frame_assembler_impl: do_imbe[1], do_output[0], do_audio_output[1], do_phase2_tdma[1], do_nocrypt[0]
07/25/23 23:42:34.055790 [0] p25_frame_assembler_impl::control: cmd(set_slotid), args({"tuner": 0, "cmd": "set_slotid", "slotid": 0})
07/25/23 23:42:34.059947 set control channel=770.193750
07/25/23 23:42:34.060463 [0] p25_frame_assembler_impl::control: cmd(set_nac), args({"tuner": 0, "cmd": "set_nac", "nac": 2540})
07/25/23 23:42:34.060596 [0] p25p1_fdma::set_nac: 0x9ec
07/25/23 23:42:34.117787 [0] p25_frame_assembler_impl::control: cmd(reset_timer), args({"tuner": 0, "cmd": "reset_timer"})
metadata update not enabled
using ALSA sound system
audio device: default
Listening on 127.0.0.1:23456
python version detected: 3.11.2 (main, Mar 13 2023, 12:18:29) [GCC 12.2.0]
Allocating 15 zero-copy buffers
07/25/23 23:42:35.096139 [0] p25_dibit::set_fs_index(): fs_type=4, fs=aa8a0a008800
07/25/23 23:42:35.096337 [0] p25_dibit::set_fs_index(): fs_type=4, fs=aa8a0a008800
07/25/23 23:42:35.212064 [0] p25p1_fdma::check_timeout: expired
07/25/23 23:42:35.220840 control channel timeout
07/25/23 23:42:35.221486 [0] p25_frame_assembler_impl::control: cmd(set_nac), args({"tuner": 0, "cmd": "set_nac", "nac": 2540})
07/25/23 23:42:35.221623 [0] p25p1_fdma::set_nac: 0x9ec
07/25/23 23:42:35.223787 [0] NAC 0x9ec TSBK: op=16 : 16 00 00 c0 15 c0 ff ff 00 01 90 1f
07/25/23 23:42:35.223970 [0] NAC 0x9ec TSBK: op=00 : 00 90 a4 4f a4 42 a4 42 a4 42 95 26
07/25/23 23:42:35.224017 [0] NAC 0x9ec TSBK: op=39 : b9 00 01 58 15 98 04 15 48 04 76 16
07/25/23 23:42:35.224984 [0] p25_dibit::set_fs_index(): fs_type=4, fs=aa8a0a008800
07/25/23 23:42:35.237328 [0] tsbk(0x16) sndcp_data_ch: ch1: 15c0 ch2: ffff
07/25/23 23:42:35.237793 [0] tsbk(0x00) mfid90_grg_add_cmd: sg: 42063 ga1: 42050 ga2: 42050 ga3: 42050
07/25/23 23:42:35.237902 add_patch: tgid(42050) is patched to sg(42063)
07/25/23 23:42:35.238081 [0] tsbk(0x39) sccb: rfid: 1 stid: 88 ch1: 1598(ID-0x1598) ch2: 1548(ID-0x1548)
07/25/23 23:42:35.344229 [0] p25_dibit::set_fs_index(): fs_type=4, fs=aa8a0a008800
07/25/23 23:42:35.344515 [0] NAC 0x9ec TSBK: op=3c : 3c 00 00 39 ee 01 01 15 a6 70 71 f9
07/25/23 23:42:35.344587 [0] NAC 0x9ec TSBK: op=33 : 33 00 33 a5 80 64 09 15 75 62 75 fc
07/25/23 23:42:35.344637 [0] NAC 0x9ec TSBK: op=3d : bd 00 43 22 70 64 0b 25 6e 84 51 9d
07/25/23 23:42:35.351513 [0] tsbk(0x3c) adj_sts_bcst: rfid: 1 stid: 1 ch1: 15a6(ID-0x15a6)
07/25/23 23:42:35.351885 [0] tsbk(0x33) iden_up_tdma: 3 freq: 762006250 toff: 30000000 spac: 12500 slots/carrier: 2
07/25/23 23:42:35.352090 [0] tsbk(0x3d) iden_up: id: 4 toff: -39.000000 spac: 12.500000 freq: 935.012500
07/25/23 23:42:35.352618 [0] p25_dibit::set_fs_index(): fs_type=4, fs=aa8a0a008800
07/25/23 23:42:35.352880 [0] NAC 0x9ec TSBK: op=33 : 33 00 53 30 c0 64 0b 25 6e 84 1d dd
07/25/23 23:42:35.352948 [0] NAC 0x9ec TSBK: op=30 : 30 00 00 04 6a 2e fa 25 47 80 12 a7
07/25/23 23:42:35.352994 [0] NAC 0x9ec TSBK: op=3a : ba 00 00 39 ee 01 58 15 20 70 d1 00
07/25/23 23:42:35.362615 [0] tsbk(0x33) iden_up_tdma: 5 freq: 935012500 toff: -39000000 spac: 12500 slots/carrier: 2
07/25/23 23:42:35.363163 [0] tsbk(0x3a) rfss_sts_bcst: syid: 9ee rfid: 1 stid: 88 ch1: 1520(ID-0x1520)
07/25/23 23:42:35.481495 [0] NAC 0x9ec TSBK: op=3b : 3b 00 00 be e0 09 ee 15 20 70 bc 0a
07/25/23 23:42:35.481679 [0] NAC 0x9ec TSBK: op=05 : 05 90 40 00 c0 00 00 00 08 00 10 8a
07/25/23 23:42:35.481729 [0] NAC 0x9ec TSBK: op=09 : 89 90 0f 00 00 00 00 00 00 00 0b 4b
07/25/23 23:42:35.484463 [0] p25_dibit::set_fs_index(): fs_type=4, fs=aa8a0a008800
07/25/23 23:42:35.485500 [0] tsbk(0x3b) net_sts_bcst: wacn: bee00 syid: 9ee ch1: 1520(ID-0x1520)
07/25/23 23:42:35.507807 [0] NAC 0x9ec TSBK: op=16 : 16 00 00 c0 15 c0 ff ff 00 01 90 1f
07/25/23 23:42:35.507966 [0] NAC 0x9ec TSBK: op=0b : 0b 90 00 00 00 00 00 00 15 20 30 d3
07/25/23 23:42:35.508012 [0] NAC 0x9ec TSBK: op=00 : 80 90 a4 4f a4 42 a4 42 a4 42 71 12
07/25/23 23:42:35.509385 [0] p25_dibit::set_fs_index(): fs_type=4, fs=aa8a0a008800
07/25/23 23:42:35.516945 [0] tsbk(0x16) sndcp_data_ch: ch1: 15c0 ch2: ffff
07/25/23 23:42:35.517405 [0] tsbk(0x00) mfid90_grg_add_cmd: sg: 42063 ga1: 42050 ga2: 42050 ga3: 42050
07/25/23 23:42:35.632322 [0] p25_dibit::set_fs_index(): fs_type=4, fs=aa8a0a008800
07/25/23 23:42:35.632597 [0] NAC 0x9ec TSBK: op=39 : 39 00 01 58 15 48 04 15 70 04 29 fc
07/25/23 23:42:35.632658 [0] NAC 0x9ec TSBK: op=3c : 3c 00 00 39 ee 01 0f 15 ac 70 3c 68
07/25/23 23:42:35.632720 [0] NAC 0x9ec TSBK: op=3d : bd 00 03 22 d0 32 0a 25 10 a2 87 94
07/25/23 23:42:35.633040 [0] tsbk(0x39) sccb: rfid: 1 stid: 88 ch1: 1548(ID-0x1548) ch2: 1570(ID-0x1570)
07/25/23 23:42:35.633330 [0] tsbk(0x3c) adj_sts_bcst: rfid: 1 stid: 15 ch1: 15ac(ID-0x15ac)
07/25/23 23:42:35.633528 [0] tsbk(0x3d) iden_up: id: 0 toff: -45.000000 spac: 6.250000 freq: 851.006250
07/25/23 23:42:35.654819 [0] p25_dibit::set_fs_index(): fs_type=4, fs=aa8a0a008800
07/25/23 23:42:35.655099 [0] NAC 0x9ec TSBK: op=3d : 3d 00 13 25 e0 32 09 15 75 62 1b 36
07/25/23 23:42:35.655174 [0] NAC 0x9ec TSBK: op=33 : 33 00 23 38 40 64 0a 25 15 84 48 4b
07/25/23 23:42:35.655218 [0] NAC 0x9ec TSBK: op=30 : b0 00 00 04 6a 2e fa 25 47 a8 53 f9
07/25/23 23:42:35.664639 [0] tsbk(0x3d) iden_up: id: 1 toff: 30.000000 spac: 6.250000 freq: 762.006250
07/25/23 23:42:35.664986 [0] tsbk(0x33) iden_up_tdma: 2 freq: 851012500 toff: -45000000 spac: 12500 slots/carrier: 2
07/25/23 23:42:35.743704 [0] NAC 0x9ec TSBK: op=3a : 3a 00 00 39 ee 01 58 15 20 70 35 34
07/25/23 23:42:35.744197 [0] NAC 0x9ec TSBK: op=3b : 3b 00 00 be e0 09 ee 15 20 70 bc 0a
07/25/23 23:42:35.744261 [0] NAC 0x9ec TSBK: op=05 : 85 90 40 00 c0 00 00 00 08 00 f4 be
07/25/23 23:42:35.747115 [0] p25_dibit::set_fs_index(): fs_type=4, fs=aa8a0a008800
07/25/23 23:42:35.751221 [0] tsbk(0x3a) rfss_sts_bcst: syid: 9ee rfid: 1 stid: 88 ch1: 1520(770.206250)
07/25/23 23:42:35.751699 [0] tsbk(0x3b) net_sts_bcst: wacn: bee00 syid: 9ee ch1: 1520(770.206250)
07/25/23 23:42:36.138618 [0] p25_dibit::set_fs_index(): fs_type=6, fs=001050551155
07/25/23 23:42:36.147293 [0] p25_dibit::set_fs_index(): fs_type=6, fs=001050551155
07/25/23 23:42:36.267745 [0] p25_dibit::set_fs_index(): fs_type=6, fs=001050551155
07/25/23 23:42:36.268056 [0] NAC 0x9ec TSBK: op=3d : 3d 00 03 22 d0 32 0a 25 10 a2 63 a0
07/25/23 23:42:36.268128 [0] NAC 0x9ec TSBK: op=3d : 3d 00 13 25 e0 32 09 15 75 62 1b 36
07/25/23 23:42:36.268173 [0] NAC 0x9ec TSBK: op=33 : b3 00 23 38 40 64 0a 25 15 84 ac 7f
07/25/23 23:42:36.270244 [0] tsbk(0x3d) iden_up: id: 0 toff: -45.000000 spac: 6.250000 freq: 851.006250
07/25/23 23:42:36.270601 [0] tsbk(0x3d) iden_up: id: 1 toff: 30.000000 spac: 6.250000 freq: 762.006250
07/25/23 23:42:36.270786 [0] tsbk(0x33) iden_up_tdma: 2 freq: 851012500 toff: -45000000 spac: 12500 slots/carrier: 2
07/25/23 23:42:36.402768 [0] p25_dibit::set_fs_index(): fs_type=6, fs=001050551155
07/25/23 23:42:36.403089 [0] NAC 0x9ec TSBK: op=30 : 30 00 00 04 6a 2e fa 25 48 02 b3 53
07/25/23 23:42:36.403163 [0] NAC 0x9ec TSBK: op=3a : 3a 00 00 39 ee 01 58 15 20 70 35 34
07/25/23 23:42:36.403209 [0] NAC 0x9ec TSBK: op=3b : bb 00 00 be e0 09 ee 15 20 70 58 3e
07/25/23 23:42:36.403873 [0] p25_dibit::set_fs_index(): fs_type=6, fs=001050551155
07/25/23 23:42:36.404095 [0] NAC 0x9ec TSBK: op=05 : 05 90 40 00 c0 00 00 00 08 00 10 8a
07/25/23 23:42:36.404158 [0] NAC 0x9ec TSBK: op=09 : 09 90 0f 00 00 00 00 00 00 00 ef 7f
07/25/23 23:42:36.404203 [0] NAC 0x9ec TSBK: op=16 : 96 00 00 c0 15 c0 ff ff 00 01 74 2b
07/25/23 23:42:36.413510 [0] tsbk(0x3a) rfss_sts_bcst: syid: 9ee rfid: 1 stid: 88 ch1: 1520(770.206250)
07/25/23 23:42:36.413842 [0] tsbk(0x3b) net_sts_bcst: wacn: bee00 syid: 9ee ch1: 1520(770.206250)
07/25/23 23:42:36.414218 [0] tsbk(0x16) sndcp_data_ch: ch1: 15c0 ch2: ffff
07/25/23 23:42:36.528418 [0] NAC 0x9ec TSBK: op=00 : 00 90 a4 4f a4 42 a4 42 a4 42 95 26
07/25/23 23:42:36.528611 [0] NAC 0x9ec TSBK: op=39 : 39 00 01 58 15 48 04 15 70 04 29 fc
07/25/23 23:42:36.528662 [0] NAC 0x9ec TSBK: op=3c : bc 00 00 39 ee 01 01 15 a6 70 95 cd
07/25/23 23:42:36.530697 [0] p25_dibit::set_fs_index(): fs_type=6, fs=001050551155
07/25/23 23:42:36.536347 [0] tsbk(0x00) mfid90_grg_add_cmd: sg: 42063 ga1: 42050 ga2: 42050 ga3: 42050
07/25/23 23:42:36.536827 [0] tsbk(0x39) sccb: rfid: 1 stid: 88 ch1: 1548(770.456250) ch2: 1570(770.706250)
07/25/23 23:42:36.537074 [0] tsbk(0x3c) adj_sts_bcst: rfid: 1 stid: 1 ch1: 15a6(771.043750)
07/25/23 23:42:36.537174 tsbk(0x3c) adj_sts_bcst: 762006250 6250
07/25/23 23:42:36.545116 [0] p25_dibit::set_fs_index(): fs_type=6, fs=001050551155
07/25/23 23:42:36.545376 [0] NAC 0x9ec TSBK: op=33 : 33 00 33 a5 80 64 09 15 75 62 75 fc
07/25/23 23:42:36.545451 [0] NAC 0x9ec TSBK: op=3d : 3d 00 43 22 70 64 0b 25 6e 84 b5 a9
07/25/23 23:42:36.545514 [0] NAC 0x9ec TSBK: op=33 : b3 00 53 30 c0 64 0b 25 6e 84 f9 e9
07/25/23 23:42:36.547620 [0] tsbk(0x33) iden_up_tdma: 3 freq: 762006250 toff: 30000000 spac: 12500 slots/carrier: 2
07/25/23 23:42:36.547959 [0] tsbk(0x3d) iden_up: id: 4 toff: -39.000000 spac: 12.500000 freq: 935.012500
07/25/23 23:42:36.548141 [0] tsbk(0x33) iden_up_tdma: 5 freq: 935012500 toff: -39000000 spac: 12500 slots/carrier: 2
07/25/23 23:42:36.658854 [0] NAC 0x9ec TSBK: op=30 : 30 00 00 04 6a 2e fa 25 48 2a 16 39
07/25/23 23:42:36.659049 [0] NAC 0x9ec TSBK: op=3a : 3a 00 00 39 ee 01 58 15 20 70 35 34
07/25/23 23:42:36.659097 [0] NAC 0x9ec TSBK: op=0b : 8b 90 00 00 00 00 00 00 15 20 d4 e7
07/25/23 23:42:36.659990 [0] p25_dibit::set_fs_index(): fs_type=6, fs=001050551155
07/25/23 23:42:36.660131 [0] tsbk(0x3a) rfss_sts_bcst: syid: 9ee rfid: 1 stid: 88 ch1: 1520(770.206250)
07/25/23 23:42:36.670085 [0] NAC 0x9ec TSBK: op=3b : 3b 00 00 be e0 09 ee 15 20 70 bc 0a
07/25/23 23:42:36.670301 [0] NAC 0x9ec TSBK: op=05 : 05 90 40 00 c0 00 00 00 08 00 10 8a
07/25/23 23:42:36.670363 [0] NAC 0x9ec TSBK: op=09 : 89 90 10 40 00 00 00 00 00 00 32 d1
07/25/23 23:42:36.670568 [0] p25_dibit::set_fs_index(): fs_type=6, fs=001050551155
07/25/23 23:42:36.670934 [0] tsbk(0x3b) net_sts_bcst: wacn: bee00 syid: 9ee ch1: 1520(770.206250)
07/25/23 23:42:36.793797 [0] NAC 0x9ec TSBK: op=16 : 16 00 00 c0 15 c0 ff ff 00 01 90 1f
07/25/23 23:42:36.793970 [0] NAC 0x9ec TSBK: op=00 : 00 90 a4 4f a4 42 a4 42 a4 42 95 26
07/25/23 23:42:36.794021 [0] NAC 0x9ec TSBK: op=39 : b9 00 01 58 15 70 04 15 98 04 5a 10
07/25/23 23:42:36.794342 [0] p25_dibit::set_fs_index(): fs_type=6, fs=001050551155
07/25/23 23:42:36.794686 [0] tsbk(0x16) sndcp_data_ch: ch1: 15c0 ch2: ffff
07/25/23 23:42:36.794994 [0] tsbk(0x00) mfid90_grg_add_cmd: sg: 42063 ga1: 42050 ga2: 42050 ga3: 42050
07/25/23 23:42:36.795274 [0] tsbk(0x39) sccb: rfid: 1 stid: 88 ch1: 1570(770.706250) ch2: 1598(770.956250)
07/25/23 23:42:36.916039 [0] NAC 0x9ec TSBK: op=3c : 3c 00 00 39 ee 01 0f 15 ac 70 3c 68
07/25/23 23:42:36.916207 [0] NAC 0x9ec TSBK: op=3d : 3d 00 03 22 d0 32 0a 25 10 a2 63 a0
07/25/23 23:42:36.916257 [0] NAC 0x9ec TSBK: op=3d : bd 00 13 25 e0 32 09 15 75 62 ff 02
07/25/23 23:42:36.917650 [0] p25_dibit::set_fs_index(): fs_type=6, fs=001050551155
07/25/23 23:42:36.917570 [0] tsbk(0x3c) adj_sts_bcst: rfid: 1 stid: 15 ch1: 15ac(771.081250)
07/25/23 23:42:36.920553 tsbk(0x3c) adj_sts_bcst: 762006250 6250
07/25/23 23:42:36.921608 [0] tsbk(0x3d) iden_up: id: 0 toff: -45.000000 spac: 6.250000 freq: 851.006250
07/25/23 23:42:36.921940 [0] tsbk(0x3d) iden_up: id: 1 toff: 30.000000 spac: 6.250000 freq: 762.006250
07/25/23 23:42:36.932399 [0] NAC 0x9ec TSBK: op=33 : 33 00 23 38 40 64 0a 25 15 84 48 4b
07/25/23 23:42:36.932564 [0] NAC 0x9ec TSBK: op=30 : 30 00 00 04 6a 2e fa 25 48 52 e9 a6
 

wgbecks

Active Member
Joined
Jan 17, 2005
Messages
1,020
Location
NE Wisconsin
OK, looking like you're getting pretty good control channel decoding but not enough log capture to indicate what happens when
a talk group goes active. The FFT plot was the first of the three plots posted. Signal levels are quite strong but I am seeing what
looks like interference or signal artifacts on the high side of the mixer plot that needs to be investigated.

I recommend reducing LNA gain downward to approximately 35 to determine if this will reduce or eliminate the potential signal artifacts
that appear in the mixer plot. The offset isn't normally a requirement except to move the spike that commonly occurs with RTL devices
that can interfere with weaker signals. Offset can also be used to some extent to help fine tune the SDR to frequency but does require
cut and try methodology. Reduce the LNA to 35 and make the Offset 2500 instead of 25000 per the following.

./rx.py --args 'rtl' -N 'LNA:35' -S 1000000 -o 2500 -q -2 -T trunk.tsv -U -V -2 -v 10 2> stderr-stream0.2

Now, with these few changes, restart op25. Open another terminal session to view the logfile (tail -f stderr-stream0.2) as it's being
written. Let op25 to continue to run until there is sign of active talk group activity, then capture and post that data if there is still no
audio. The logfile text would look something like the following when decoding an FDMA (Phase-1) talk group,


07/26/23 09:22:24.412308 [0] tsbk(0x02) mfid90_grg_ch_grant: f: 852.387500 sg: 4035 sa: 9720041
07/26/23 09:22:24.412620 [0] tsbk(0x3b) net_sts_bcst: wacn: 92493 syid: 796 ch1: 1cd(853.887500)
07/26/23 09:22:24.412936 set tgid=4035, srcaddr=0
07/26/23 09:22:24.413089 [0] tsbk(0x03) mfid90_grg_ch_grant_updt: f1: 852.387500 sg1: 4035 f2: 852.387500 sg2: 4035
07/26/23 09:22:24.413347 [0] tsbk(0x16) sndcp_data_ch: ch1: 8d ch2: ffff
07/26/23 09:22:24.534196 [0] NAC 0x794 TSBK: op=33 : 33 00 33 a5 80 64 09 15 75 62 75 fc
07/26/23 09:22:24.534319 [0] NAC 0x794 TSBK: op=09 : 09 90 14 00 00 00 00 00 00 00 04 64
07/26/23 09:22:24.534356 [0] NAC 0x794 TSBK: op=39 : b9 00 04 21 01 6b 04 01 6b 04 90 b2
07/26/23 09:22:24.534912 [0] tsbk(0x33) iden_up_tdma: 3 freq: 762006250 toff: 30000000 spac: 12500 slots/carrier: 2
07/26/23 09:22:24.535496 [0] tsbk(0x39) sccb: rfid: 4 stid: 33 ch1: 16b(853.275000) ch2: 16b(853.275000)
07/26/23 09:22:24.660249 [0] NAC 0x794 TSBK: op=3c : 3c 00 00 37 96 04 08 01 cb 70 39 5a
07/26/23 09:22:24.660396 [0] NAC 0x794 TSBK: op=30 : 30 00 00 04 6a 14 89 3d 18 88 f4 05
07/26/23 09:22:24.660438 [0] NAC 0x794 TSBK: op=3d : bd 00 03 22 d0 32 0a 25 10 a2 87 94
07/26/23 09:22:24.667920 [0] tsbk(0x3c) adj_sts_bcst: rfid: 4 stid: 8 ch1: 1cb(853.875000)
07/26/23 09:22:24.668162 tsbk(0x3c) adj_sts_bcst: 851006250 6250
07/26/23 09:22:24.671849 [0] tsbk(0x3d) iden_up: id: 0 toff: -45.000000 spac: 6.250000 freq: 851.006250
07/26/23 09:22:24.925615 [0] NAC 0x794 LDU2: ESS: algid=80, keyid=0, mi=00 00 00 00 00 00 00 00 00, rs_errs=0
07/26/23 09:22:24.925828 [0] IMBE 04 0c fd 7b fb 7d f2 7b 3d 9e 44 errs 0
07/26/23 09:22:24.926523 [0] IMBE 04 0c fd 7b fb 7d f2 7b 3d 9e 44 errs 0
07/26/23 09:22:24.926909 [0] IMBE 04 0c fd 7b fb 7d f2 7b 3d 9e 44 errs 0
07/26/23 09:22:24.927220 [0] IMBE 04 0c fd 7b fb 7d f2 7b 3d 9e 44 errs 0
07/26/23 09:22:24.927482 [0] IMBE 04 0c fd 7b fb 7d f2 7b 3d 9e 44 errs 0
07/26/23 09:22:24.927733 [0] IMBE 04 0c fd 7b fb 7d f2 7b 3d 9e 44 errs 0
07/26/23 09:22:24.927965 [0] IMBE 04 0c fd 7b fb 7d f2 7b 3d 9e 44 errs 0
07/26/23 09:22:24.928192 [0] IMBE 04 0c fd 7b fb 7d f2 7b 3d 9e 44 errs 0
07/26/23 09:22:24.928426 [0] IMBE 04 0c fd 7b fb 7d f2 7b 3d 9e 44 errs 0
07/26/23 09:22:25.058406 [0] NAC 0x794 LDU1: LCW: ec=0, pb=0, sf=0, lco=0 : 00 90 00 00 0f c3 94 50 e9
07/26/23 09:22:25.058553 [0] IMBE 18 3e 92 32 1e 40 00 24 0b 00 52 errs 0
07/26/23 09:22:25.060159 [0] IMBE b0 5c 40 31 dc db 00 00 04 55 61 errs 0
07/26/23 09:22:25.061421 [0] IMBE 18 63 a8 18 7e a4 03 15 46 4c 9a errs 0
07/26/23 09:22:25.062813 [0] IMBE 18 72 0b 0f 3f 0c 00 6d 8b 72 cb errs 0
07/26/23 09:22:25.064005 [0] IMBE 18 67 21 c1 3c a4 01 27 c7 27 3a errs 0
07/26/23 09:22:25.063956 [0] lcw(0x00) grp_v_ch_usr: ga: 4035 s: 0 sa: 9720041
07/26/23 09:22:25.065099 [0] IMBE 18 62 aa 5a a9 d6 01 85 e6 70 bb errs 0
07/26/23 09:22:25.066051 [0] IMBE 18 53 49 8d fc e0 00 3c 4a c2 ea errs 0
07/26/23 09:22:25.067029 [0] IMBE 18 66 a2 72 8c 26 01 32 83 e4 b3 errs 0
07/26/23 09:22:25.067962 [0] IMBE 18 3b 19 91 3e 90 01 70 d2 98 22 errs 0
07/26/23 09:22:25.190896 [0] NAC 0x794 LDU2: ESS: algid=80, keyid=0, mi=00 00 00 00 00 00 00 00 00, rs_errs=0
07/26/23 09:22:25.191028 [0] IMBE 18 67 a0 74 ce 83 00 36 29 00 73 errs 0
07/26/23 09:22:25.191969 [0] IMBE 18 63 29 61 d5 a9 01 40 3c ac 8a errs 0
07/26/23 09:22:25.192864 [0] IMBE 18 63 29 99 a5 0f 00 17 9b b7 a3 errs 0
07/26/23 09:22:25.194035 [0] IMBE 18 63 29 6d 58 88 00 bf de 7a 3a errs 0
07/26/23 09:22:25.195028 [0] IMBE 18 72 8a 1a ad d2 01 56 51 81 c3 errs 0
07/26/23 09:22:25.195950 [0] IMBE 18 62 aa 1a 6d 5e 01 31 25 89 5a errs 0
07/26/23 09:22:25.196993 [0] IMBE 18 73 09 3d cc b6 01 51 95 a3 9b errs 0
07/26/23 09:22:25.197938 [0] IMBE 18 63 29 59 e4 a7 01 23 76 db 0a errs 0
07/26/23 09:22:25.198923 [0] IMBE 18 62 2b 0b f8 5d 01 bb c7 00 3b errs 0
07/26/23 09:22:25.447320 [0] NAC 0x794 LDU1: LCW: ec=0, pb=0, sf=0, lco=0 : 00 90 00 00 0f c3 94 50 e9
07/26/23 09:22:25.447481 [0] IMBE 18 63 a8 58 fd 8c 01 24 02 24 3a errs 0
07/26/23 09:22:25.449275 [0] IMBE 18 63 29 4d fd 28 01 69 d4 bb 2b errs 0
07/26/23 09:22:25.452496 [0] IMBE 18 72 0b 1f b9 64 00 a0 5f 13 6a errs 0
07/26/23 09:22:25.453123 [0] lcw(0x00) grp_v_ch_usr: ga: 4035 s: 0 sa: 9720041



Make a new set of plots and post that include FFT (1), Constellation (2), Datascope (4), and Raw Mixer (5) and include a screen capture
of the op25 terminal window while running that will indicate the frequency the SDR is tuned to and its approximate frequency error.
 
Last edited:

wgbecks

Active Member
Joined
Jan 17, 2005
Messages
1,020
Location
NE Wisconsin
As a follow up. I would concentrate efforts on correcting the frequency error that's visible in the "Raw Mixer" plot that
indicates the center of the tuned IF spectrum is sitting low in frequency.

Earlier, I suggested lowering the offset to -o 2500 but I think to begin with you should remove it completely and then incrementally
adjust the PPM (-q -2) as needed to center the IF spectrum on the zero-center line of the raw mixer plot display per the example
shown below.
Raw Mixer.png
 

VA4JOE

Member
Joined
Jul 25, 2023
Messages
56
I'm not getting anything like what you posted about it decoding in the stderr-stream0.2 file.
07/26/23 12:06:56.915121 hold active tg(42063)
07/26/23 12:06:56.915225 voice update: tg(42063), freq(771706250), slot(-), prio(3)
07/26/23 12:06:56.987402 [0] p25_frame_assembler_impl::control: cmd(reset_timer), args({"tuner": 0, "cmd": "reset_timer"})
07/26/23 12:06:57.011615 [0] NAC 0x9ec TSBK: op=02 : 02 90 40 16 10 a4 4f 01 74 14 0f 3b
07/26/23 12:06:57.011804 [0] NAC 0x9ec TSBK: op=3b : 3b 00 00 be e0 09 ee 15 20 70 bc 0a
07/26/23 12:06:57.011854 [0] NAC 0x9ec TSBK: op=16 : 96 00 00 40 ff ff ff ff 00 01 bb ff
07/26/23 12:06:57.018431 set tgid=42063, srcaddr=95252
07/26/23 12:06:57.018704 set tgid=42050, srcaddr=95252
07/26/23 12:06:57.018781 update_talkgroups: sg(42063) patched tgid(42050)
07/26/23 12:06:57.018884 [0] tsbk(0x02) mfid90_grg_ch_grant: f: 771.706250 sg: 42063 sa: 95252
07/26/23 12:06:57.019131 [0] tsbk(0x3b) net_sts_bcst: wacn: bee00 syid: 9ee ch1: 1520(770.206250)
07/26/23 12:06:57.019330 [0] tsbk(0x16) sndcp_data_ch: ch1: ffff ch2: ffff
07/26/23 12:06:57.177248 [0] NAC 0x9ec TSBK: op=3d : 3d 00 03 22 d0 32 0a 25 10 a2 63 a0
07/26/23 12:06:57.177434 [0] NAC 0x9ec TSBK: op=00 : 00 90 a4 4f a4 42 a4 42 a4 42 95 26
07/26/23 12:06:57.177483 [0] NAC 0x9ec TSBK: op=3d : bd 00 13 25 e0 32 09 15 75 62 ff 02
07/26/23 12:06:57.188443 [0] tsbk(0x3d) iden_up: id: 0 toff: -45.000000 spac: 6.250000 freq: 851.006250
07/26/23 12:06:57.188796 [0] tsbk(0x00) mfid90_grg_add_cmd: sg: 42063 ga1: 42050 ga2: 42050 ga3: 42050
07/26/23 12:06:57.188973 [0] tsbk(0x3d) iden_up: id: 1 toff: 30.000000 spac: 6.250000 freq: 762.006250
07/26/23 12:06:57.284077 [0] NAC 0x9ec TSBK: op=33 : 33 00 23 38 40 64 0a 25 15 84 48 4b
07/26/23 12:06:57.284271 [0] NAC 0x9ec TSBK: op=30 : 30 00 00 04 6a 2e fa 88 d2 e8 e7 da
07/26/23 12:06:57.284321 [0] NAC 0x9ec TSBK: op=3a : ba 00 00 39 ee 01 58 15 20 70 d1 00
07/26/23 12:06:57.317829 [0] tsbk(0x33) iden_up_tdma: 2 freq: 851012500 toff: -45000000 spac: 12500 slots/carrier: 2
07/26/23 12:06:57.318290 [0] tsbk(0x3a) rfss_sts_bcst: syid: 9ee rfid: 1 stid: 88 ch1: 1520(770.206250)
07/26/23 12:06:58.320714 [0] p25p1_fdma::check_timeout: expired
07/26/23 12:06:58.330335 voice timeout
07/26/23 12:06:58.414892 [0] p25_frame_assembler_impl::control: cmd(reset_timer), args({"tuner": 0, "cmd": "reset_timer"})
07/26/23 12:06:58.643600 clear tgid=42063, freq=771.706250, slot=0
07/26/23 12:06:58.643847 clear tgid=42063, freq=771.706250, slot=1
07/26/23 12:06:58.865734 [0] NAC 0x9ec TSBK: op=16 : 16 00 00 c0 15 e8 ff ff 00 01 9a 86
07/26/23 12:06:58.865912 [0] NAC 0x9ec TSBK: op=30 : 30 00 00 04 6a 2e fa 88 d3 ba ae 5c
07/26/23 12:06:58.865960 [0] NAC 0x9ec TSBK: op=3a : ba 00 00 39 ee 01 58 15 20 70 d1 00
07/26/23 12:06:58.894981 [0] tsbk(0x16) sndcp_data_ch: ch1: 15e8 ch2: ffff
07/26/23 12:06:58.895436 [0] tsbk(0x3a) rfss_sts_bcst: syid: 9ee rfid: 1 stid: 88 ch1: 1520(770.206250)
07/26/23 12:06:58.898917 [0] NAC 0x9ec TSBK: op=3b : 3b 00 00 be e0 09 ee 15 20 70 bc 0a
07/26/23 12:06:58.899084 [0] NAC 0x9ec TSBK: op=03 : 03 90 16 10 a4 4f 16 10 a4 4f ac ac
07/26/23 12:06:58.899133 [0] NAC 0x9ec TSBK: op=05 : 85 90 40 00 c0 00 00 00 08 00 f4 be
07/26/23 12:06:58.912541 [0] tsbk(0x3b) net_sts_bcst: wacn: bee00 syid: 9ee ch1: 1520(770.206250)
07/26/23 12:06:58.912926 set tgid=42063, srcaddr=0
07/26/23 12:06:58.913029 set tgid=42050, srcaddr=0
07/26/23 12:06:58.913116 update_talkgroups: sg(42063) patched tgid(42050)
07/26/23 12:06:58.913215 [0] tsbk(0x03) mfid90_grg_ch_grant_updt: f1: 771.706250 sg1: 42063 f2: 771.706250 sg2: 42063
07/26/23 12:06:58.914319 hold active tg(42063)
07/26/23 12:06:58.914512 voice update: tg(42063), freq(771706250), slot(-), prio(3)
07/26/23 12:06:58.977566 [0] p25_frame_assembler_impl::control: cmd(reset_timer), args({"tuner": 0, "cmd": "reset_timer"})
07/26/23 12:06:58.994350 [0] NAC 0x9ec TSBK: op=09 : 09 90 10 40 00 00 00 00 00 00 d6 e5
07/26/23 12:06:58.994526 [0] NAC 0x9ec TSBK: op=39 : 39 00 01 58 15 48 04 15 70 04 29 fc
07/26/23 12:06:58.994633 [0] NAC 0x9ec TSBK: op=3c : bc 00 00 39 ee 01 01 15 a6 70 95 cd
07/26/23 12:06:58.998877 [0] tsbk(0x39) sccb: rfid: 1 stid: 88 ch1: 1548(770.456250) ch2: 1570(770.706250)
07/26/23 12:06:58.999405 [0] tsbk(0x3c) adj_sts_bcst: rfid: 1 stid: 1 ch1: 15a6(771.043750)
07/26/23 12:06:58.999537 tsbk(0x3c) adj_sts_bcst: 762006250 6250
07/26/23 12:06:59.117928 [0] NAC 0x9ec TSBK: op=33 : 33 00 33 a5 80 64 09 15 75 62 75 fc
07/26/23 12:06:59.118111 [0] NAC 0x9ec TSBK: op=00 : 00 90 a4 4f a4 42 a4 42 a4 42 95 26
07/26/23 12:06:59.118196 [0] NAC 0x9ec TSBK: op=3d : bd 00 43 22 70 64 0b 25 6e 84 51 9d
07/26/23 12:06:59.134590 [0] tsbk(0x33) iden_up_tdma: 3 freq: 762006250 toff: 30000000 spac: 12500 slots/carrier: 2
07/26/23 12:06:59.134947 [0] tsbk(0x00) mfid90_grg_add_cmd: sg: 42063 ga1: 42050 ga2: 42050 ga3: 42050
07/26/23 12:06:59.135127 [0] tsbk(0x3d) iden_up: id: 4 toff: -39.000000 spac: 12.500000 freq: 935.012500
07/26/23 12:06:59.141232 [0] NAC 0x9ec TSBK: op=33 : 33 00 53 30 c0 64 0b 25 6e 84 1d dd
07/26/23 12:06:59.141389 [0] NAC 0x9ec TSBK: op=0b : 0b 90 00 00 00 00 00 00 15 20 30 d3
07/26/23 12:06:59.141454 [0] NAC 0x9ec TSBK: op=16 : 96 00 00 c0 15 e8 ff ff 00 01 7e b2
07/26/23 12:06:59.150000 [0] tsbk(0x33) iden_up_tdma: 5 freq: 935012500 toff: -39000000 spac: 12500 slots/carrier: 2
07/26/23 12:06:59.150452 [0] tsbk(0x16) sndcp_data_ch: ch1: 15e8 ch2: ffff
07/26/23 12:06:59.245696 [0] NAC 0x9ec TSBK: op=30 : 30 00 00 04 6a 2e fa 88 d3 ec 94 6f
07/26/23 12:06:59.245890 [0] NAC 0x9ec TSBK: op=3a : 3a 00 00 39 ee 01 58 15 20 70 35 34
07/26/23 12:06:59.245955 [0] NAC 0x9ec TSBK: op=3b : bb 00 00 be e0 09 ee 15 20 70 58 3e
07/26/23 12:06:59.250690 [0] tsbk(0x3a) rfss_sts_bcst: syid: 9ee rfid: 1 stid: 88 ch1: 1520(770.206250)
07/26/23 12:06:59.251048 [0] tsbk(0x3b) net_sts_bcst: wacn: bee00 syid: 9ee ch1: 1520(770.206250)
07/26/23 12:06:59.258380 [0] NAC 0x9ec TSBK: op=03 : 03 90 16 10 a4 4f 16 10 a4 4f ac ac
07/26/23 12:06:59.258558 [0] NAC 0x9ec TSBK: op=05 : 05 90 40 00 c0 00 00 00 08 00 10 8a
07/26/23 12:06:59.258606 [0] NAC 0x9ec TSBK: op=09 : 89 90 11 80 00 00 00 00 00 00 03 17
07/26/23 12:06:59.264226 set tgid=42063, srcaddr=0
07/26/23 12:06:59.264468 set tgid=42050, srcaddr=0
07/26/23 12:06:59.264545 update_talkgroups: sg(42063) patched tgid(42050)
07/26/23 12:06:59.264629 [0] tsbk(0x03) mfid90_grg_ch_grant_updt: f1: 771.706250 sg1: 42063 f2: 771.706250 sg2: 42063
07/26/23 12:07:00.285701 [0] p25p1_fdma::check_timeout: expired
07/26/23 12:07:00.295255 voice timeout
07/26/23 12:07:00.350438 [0] p25_frame_assembler_impl::control: cmd(reset_timer), args({"tuner": 0, "cmd": "reset_timer"})
07/26/23 12:07:00.775435 clear tgid=42063, freq=771.706250, slot=0
07/26/23 12:07:00.775696 clear tgid=42063, freq=771.706250, slot=1
07/26/23 12:07:00.989480 [0] NAC 0x9ec TSBK: op=02 : 02 00 16 38 06 af 16 38 06 af 2a cf
07/26/23 12:07:00.989690 [0] NAC 0x9ec TSBK: op=00 : 00 90 a4 4f a4 42 a4 42 a4 42 95 26
07/26/23 12:07:00.989740 [0] NAC 0x9ec TSBK: op=3d : bd 00 13 25 e0 32 09 15 75 62 ff 02
07/26/23 12:07:00.995355 set tgid=1711, srcaddr=0
07/26/23 12:07:00.995629 [0] tsbk(0x02) grp_v_ch_grant_updt: ch1: 771.956250 ga1: 1711 ch2: 771.956250 ga2: 1711
07/26/23 12:07:00.995795 voice update: tg(1711), freq(771956250), slot(-), prio(3)
07/26/23 12:07:01.054297 [0] p25_frame_assembler_impl::control: cmd(reset_timer), args({"tuner": 0, "cmd": "reset_timer"})
07/26/23 12:07:01.088191 [0] NAC 0x9ec TSBK: op=33 : 33 00 23 38 40 64 0a 25 15 84 48 4b
07/26/23 12:07:01.088378 [0] NAC 0x9ec TSBK: op=16 : 16 00 00 c0 15 e8 ff ff 00 01 9a 86
07/26/23 12:07:01.088430 [0] NAC 0x9ec TSBK: op=30 : b0 00 00 04 6a 2e fa 88 d4 e6 48 86
07/26/23 12:07:01.095314 [0] tsbk(0x33) iden_up_tdma: 2 freq: 851012500 toff: -45000000 spac: 12500 slots/carrier: 2
07/26/23 12:07:01.095674 [0] tsbk(0x16) sndcp_data_ch: ch1: 15e8 ch2: ffff
07/26/23 12:07:01.225023 [0] NAC 0x9ec TSBK: op=05 : 05 90 40 00 c0 00 00 00 08 00 10 8a
07/26/23 12:07:01.225283 [0] NAC 0x9ec TSBK: op=09 : 09 90 12 c0 00 00 00 00 00 00 f2 ba
It won't let me post the whole filee cause it's too long it says.
 

wgbecks

Active Member
Joined
Jan 17, 2005
Messages
1,020
Location
NE Wisconsin
Still a little off frequency but not enough that you should not be getting audio on active talk groups. I am willing to look at your logfile
if you want to PM me to exchange contact (email) info. Let op25 run at logging verbose -v 10 for at least an hour then grab that file and
email it to me after we exchange email addresses.

Bill
 

VA4JOE

Member
Joined
Jul 25, 2023
Messages
56
Still a little off frequency but not enough that you should not be getting audio on active talk groups. I am willing to look at your logfile
if you want to PM me to exchange contact (email) info. Let op25 run at logging verbose -v 10 for at least an hour then grab that file and
email it to me after we exchange email addresses.

Bill
A little off topic but I was messing around with GQRX and DSD and for the second voice frequency I was able to get some data. It seems like there is a mix of C4FM and GFSK traffic on that channel
Sync: +P25p1 mod: GFSK inlvl: 53% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 35% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 26% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 20% nac: 9EC src: 0 tg: 0 PDU
Sync: +P25p1 mod: C4FM inlvl: 19% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 PDU
Sync: +P25p1 mod: C4FM inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 15% nac: 9EC src: 0 tg: 0 PDU
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 14% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 15% nac: 9EC src: 0 tg: 0 PDU
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 PDU
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 14% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 PDU
Sync: +P25p1 mod: GFSK inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 15% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: GFSK inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 16% nac: 9EC src: 0 tg: 0 TDULC
Sync: +P25p1 mod: C4FM inlvl: 17% nac: 9EC src: 0 tg: 0 TDULC
Output to output.wav file.
I was able to get about a second of garbled audio in the wav file.
 
Last edited:

boatbod

Member
Joined
Mar 3, 2007
Messages
3,409
Location
Talbot Co, MD
To the OP: Is this a phase 1 only (FDMA) system or does it carry phase 2 (TDMA) traffic too? I don't see any p25p2 log message or slotid in your log fragment so I'm thinking it might be a c4fm phase 1 system. In that case you'd probably want to add "-D fsk4" to the rx.py command line to force the demodulation which should correct the voice channel timeouts. Try it and see if it helps; if it's no better back the change out and post a longer log fragment at "-v 11" detail level containing some "voice update:" messages.
 

VA4JOE

Member
Joined
Jul 25, 2023
Messages
56
To the OP: Is this a phase 1 only (FDMA) system or does it carry phase 2 (TDMA) traffic too? I don't see any p25p2 log message or slotid in your log fragment so I'm thinking it might be a c4fm phase 1 system. In that case you'd probably want to add "-D fsk4" to the rx.py command line to force the demodulation which should correct the voice channel timeouts. Try it and see if it helps; if it's no better back the change out and post a longer log fragment at "-v 11" detail level containing some "voice update:" messages.
According to radioreference.com it is a P25 Phase 1 system with no phase 2 capabilities yet.
Issued command:
./rx.py --args 'rtl' -N 'LNA:35' -S 1000000 -D fsk4 -q 1 -T trunk.tsv -U -V -2 -v 11 2> stderr-stream0.2
07/27/23 08:35:45.383321 new tgid=1899 Unknown1 prio 3
07/27/23 08:35:45.383450 new freq=771.206250
07/27/23 08:35:45.383541 [0] tsbk(0x00) grp_v_ch_grant: f: 771.206250 ga: 1899 sa: 600062
07/27/23 08:35:45.383682 voice update: tg(1899), freq(771206250), slot(-), prio(3)
07/27/23 08:35:45.383779 do_metadata state=0: [1899] Unknown1
07/27/23 08:35:45.383868 set_frequency(771206250)
07/27/23 08:35:45.438369 [0] p25_frame_assembler_impl::control: cmd(reset_timer), args({"tuner": 0, "cmd": "reset_timer"})
07/27/23 08:35:45.438862 type 7 with ts 07/27/23 08:35:45.377621 ignored due to frequency change
07/27/23 08:35:45.522570 [0] NAC 0x9ec TSBK: op=05 : 05 90 40 00 c0 00 00 00 08 00 10 8a
07/27/23 08:35:45.522724 [0] NAC 0x9ec TSBK: op=00 : 00 00 44 15 c0 07 6b 09 27 fe d9 86
07/27/23 08:35:45.522775 [0] NAC 0x9ec TSBK: op=3c : bc 00 00 39 ee 01 0f 15 ac 70 d8 5c
07/27/23 08:35:45.532663 nac 9ec type 7 state 2 len 10
07/27/23 08:35:45.532989 nac 9ec type 7 state 2 len 10
07/27/23 08:35:45.533118 set tgid=1899, srcaddr=600062
07/27/23 08:35:45.533220 [0] tsbk(0x00) grp_v_ch_grant: f: 771.206250 ga: 1899 sa: 600062
07/27/23 08:35:45.533427 nac 9ec type 7 state 2 len 10
07/27/23 08:35:45.533547 [0] tsbk(0x3c) adj_sts_bcst: rfid: 1 stid: 15 ch1: 15ac(771.081250)
07/27/23 08:35:45.533626 tsbk(0x3c) adj_sts_bcst: 762006250 6250
07/27/23 08:35:45.641187 [0] NAC 0x9ec TSBK: op=16 : 16 00 00 40 ff ff ff ff 00 01 5f cb
07/27/23 08:35:45.641363 [0] NAC 0x9ec TSBK: op=02 : 02 00 15 c0 07 6b 15 c0 07 6b da 47
07/27/23 08:35:45.641413 [0] NAC 0x9ec TSBK: op=39 : b9 00 01 58 15 48 04 15 98 04 54 d3
07/27/23 08:35:45.645814 nac 9ec type 7 state 2 len 10
07/27/23 08:35:45.646907 [0] tsbk(0x16) sndcp_data_ch: ch1: ffff ch2: ffff
07/27/23 08:35:45.648957 nac 9ec type 7 state 2 len 10
07/27/23 08:35:45.649615 set tgid=1899, srcaddr=0
07/27/23 08:35:45.649821 [0] tsbk(0x02) grp_v_ch_grant_updt: ch1: 771.206250 ga1: 1899 ch2: 771.206250 ga2: 1899
07/27/23 08:35:45.650201 nac 9ec type 7 state 2 len 10
07/27/23 08:35:45.650457 [0] tsbk(0x39) sccb: rfid: 1 stid: 88 ch1: 1548(770.456250) ch2: 1598(770.956250)
07/27/23 08:35:45.765994 [0] NAC 0x9ec TSBK: op=09 : 09 90 15 40 00 00 00 00 00 00 9e 5b
07/27/23 08:35:45.766254 [0] NAC 0x9ec TSBK: op=0b : 0b 90 00 00 00 00 00 00 15 20 30 d3
07/27/23 08:35:45.766335 [0] NAC 0x9ec TSBK: op=3d : bd 00 03 22 d0 32 0a 25 10 a2 87 94
07/27/23 08:35:45.766534 nac 9ec type 7 state 2 len 10
07/27/23 08:35:45.771545 nac 9ec type 7 state 2 len 10
07/27/23 08:35:45.772017 nac 9ec type 7 state 2 len 10
07/27/23 08:35:45.772777 [0] tsbk(0x3d) iden_up: id: 0 toff: -45.000000 spac: 6.250000 freq: 851.006250
07/27/23 08:35:46.810762 [0] p25p1_fdma::check_timeout: expired
07/27/23 08:35:46.823220 process_data_unit timeout
07/27/23 08:35:46.823497 voice timeout
07/27/23 08:35:46.823601 set_frequency(770193750)
07/27/23 08:35:46.880562 [0] p25_frame_assembler_impl::control: cmd(reset_timer), args({"tuner": 0, "cmd": "reset_timer"})
07/27/23 08:35:46.888633 clear tgid=1899, freq=771.206250, slot=0
07/27/23 08:35:46.888917 clear tgid=1899, freq=771.206250, slot=1
07/27/23 08:35:47.363955 [0] NAC 0x9ec TSBK: op=00 : 00 90 a4 4f a4 42 a4 42 a4 42 95 26
07/27/23 08:35:47.364164 [0] NAC 0x9ec TSBK: op=05 : 05 90 40 00 c0 00 00 00 08 00 10 8a
07/27/23 08:35:47.365030 [0] NAC 0x9ec TSBK: op=3c : bc 00 00 39 ee 01 12 15 a8 70 36 b9
07/27/23 08:35:47.368336 nac 9ec type 7 state 1 len 10
07/27/23 08:35:47.368605 [0] tsbk(0x00) mfid90_grg_add_cmd: sg: 42063 ga1: 42050 ga2: 42050 ga3: 42050
07/27/23 08:35:47.368775 nac 9ec type 7 state 1 len 10
07/27/23 08:35:47.368922 nac 9ec type 7 state 1 len 10
07/27/23 08:35:47.369240 [0] tsbk(0x3c) adj_sts_bcst: rfid: 1 stid: 18 ch1: 15a8(771.056250)
07/27/23 08:35:47.369355 tsbk(0x3c) adj_sts_bcst: 762006250 6250
07/27/23 08:35:47.470443 [0] NAC 0x9ec TSBK: op=16 : 16 00 00 40 ff ff ff ff 00 01 5f cb
07/27/23 08:35:47.470622 [0] NAC 0x9ec TSBK: op=02 : 02 00 15 c0 07 6b 15 c0 07 6b da 47
07/27/23 08:35:47.470695 [0] NAC 0x9ec TSBK: op=39 : b9 00 01 58 15 70 04 15 48 04 4f 37
07/27/23 08:35:47.476235 nac 9ec type 7 state 1 len 10
07/27/23 08:35:47.476500 [0] tsbk(0x16) sndcp_data_ch: ch1: ffff ch2: ffff
07/27/23 08:35:47.476599 do_metadata state=1: [None] None
07/27/23 08:35:47.476751 nac 9ec type 7 state 1 len 10
07/27/23 08:35:47.476895 set tgid=1899, srcaddr=0
07/27/23 08:35:47.477010 [0] tsbk(0x02) grp_v_ch_grant_updt: ch1: 771.206250 ga1: 1899 ch2: 771.206250 ga2: 1899
07/27/23 08:35:47.477189 voice update: tg(1899), freq(771206250), slot(-), prio(3)
07/27/23 08:35:47.477293 do_metadata state=0: [1899] Unknown1
07/27/23 08:35:47.477396 set_frequency(771206250)
07/27/23 08:35:47.482597 [0] NAC 0x9ec TSBK: op=09 : 09 90 10 40 00 00 00 00 00 00 d6 e5
07/27/23 08:35:47.482768 [0] NAC 0x9ec TSBK: op=33 : 33 00 33 a5 80 64 09 15 75 62 75 fc
07/27/23 08:35:47.482832 [0] NAC 0x9ec TSBK: op=3d : bd 00 43 22 70 64 0b 25 6e 84 51 9d
07/27/23 08:35:47.532656 [0] p25_frame_assembler_impl::control: cmd(reset_timer), args({"tuner": 0, "cmd": "reset_timer"})
07/27/23 08:35:47.533146 type 7 with ts 07/27/23 08:35:47.470692 ignored due to frequency change
07/27/23 08:35:47.533424 nac 9ec type 7 state 2 len 10
07/27/23 08:35:47.533616 nac 9ec type 7 state 2 len 10
07/27/23 08:35:47.533822 [0] tsbk(0x33) iden_up_tdma: 3 freq: 762006250 toff: 30000000 spac: 12500 slots/carrier: 2
07/27/23 08:35:47.533968 nac 9ec type 7 state 2 len 10
07/27/23 08:35:47.534062 [0] tsbk(0x3d) iden_up: id: 4 toff: -39.000000 spac: 12.500000 freq: 935.012500
07/27/23 08:35:47.620074 [0] NAC 0x9ec TSBK: op=3a : 3a 00 00 39 ee 01 58 15 20 70 35 34
07/27/23 08:35:47.620348 [0] NAC 0x9ec TSBK: op=3b : 3b 00 00 be e0 09 ee 15 20 70 bc 0a
07/27/23 08:35:47.620458 [0] NAC 0x9ec TSBK: op=00 : 80 90 a4 4f a4 42 a4 42 a4 42 71 12
07/27/23 08:35:47.627223 nac 9ec type 7 state 2 len 10
07/27/23 08:35:47.627602 [0] tsbk(0x3a) rfss_sts_bcst: syid: 9ee rfid: 1 stid: 88 ch1: 1520(770.206250)
07/27/23 08:35:47.627785 nac 9ec type 7 state 2 len 10
07/27/23 08:35:47.627885 [0] tsbk(0x3b) net_sts_bcst: wacn: bee00 syid: 9ee ch1: 1520(770.206250)
07/27/23 08:35:47.628020 nac 9ec type 7 state 2 len 10
07/27/23 08:35:47.628104 [0] tsbk(0x00) mfid90_grg_add_cmd: sg: 42063 ga1: 42050 ga2: 42050 ga3: 42050
07/27/23 08:35:47.745866 [0] NAC 0x9ec TSBK: op=05 : 05 90 40 00 c0 00 00 00 08 00 10 8a
07/27/23 08:35:47.746051 [0] NAC 0x9ec TSBK: op=3c : 3c 00 00 39 ee 01 33 15 18 70 8d 7a
07/27/23 08:35:47.746100 [0] NAC 0x9ec TSBK: op=16 : 96 00 00 40 ff ff ff ff 00 01 bb ff
07/27/23 08:35:47.752037 nac 9ec type 7 state 2 len 10
07/27/23 08:35:47.752350 nac 9ec type 7 state 2 len 10
07/27/23 08:35:47.752473 [0] tsbk(0x3c) adj_sts_bcst: rfid: 1 stid: 51 ch1: 1518(770.156250)
07/27/23 08:35:47.752551 tsbk(0x3c) adj_sts_bcst: 762006250 6250
07/27/23 08:35:47.752683 nac 9ec type 7 state 2 len 10
07/27/23 08:35:47.752769 [0] tsbk(0x16) sndcp_data_ch: ch1: ffff ch2: ffff
07/27/23 08:35:47.860130 [0] NAC 0x9ec TSBK: op=02 : 02 00 15 c0 07 6b 15 c0 07 6b da 47
07/27/23 08:35:47.860311 [0] NAC 0x9ec TSBK: op=39 : 39 00 01 58 15 48 04 15 98 04 b0 e7
07/27/23 08:35:47.860359 [0] NAC 0x9ec TSBK: op=09 : 89 90 11 80 00 00 00 00 00 00 03 17
07/27/23 08:35:47.866098 nac 9ec type 7 state 2 len 10
07/27/23 08:35:47.866581 set tgid=1899, srcaddr=0
07/27/23 08:35:47.866779 [0] tsbk(0x02) grp_v_ch_grant_updt: ch1: 771.206250 ga1: 1899 ch2: 771.206250 ga2: 1899
07/27/23 08:35:47.868520 nac 9ec type 7 state 2 len 10
07/27/23 08:35:47.879272 [0] tsbk(0x39) sccb: rfid: 1 stid: 88 ch1: 1548(770.456250) ch2: 1598(770.956250)
07/27/23 08:35:47.883066 nac 9ec type 7 state 2 len 10
07/27/23 08:35:48.913160 [0] p25p1_fdma::check_timeout: expired
07/27/23 08:35:48.923424 process_data_unit timeout
07/27/23 08:35:48.923677 voice timeout
07/27/23 08:35:48.923778 set_frequency(770193750)
07/27/23 08:35:48.996940 [0] p25_frame_assembler_impl::control: cmd(reset_timer), args({"tuner": 0, "cmd": "reset_timer"})
07/27/23 08:35:49.442732 [0] NAC 0x9ec TSBK: op=0b : 0b 90 00 00 00 00 00 00 15 20 30 d3
07/27/23 08:35:49.442914 [0] NAC 0x9ec TSBK: op=00 : 00 90 a4 4f a4 42 a4 42 a4 42 95 26
07/27/23 08:35:49.442963 [0] NAC 0x9ec TSBK: op=05 : 85 90 40 00 c0 00 00 00 08 00 f4 be
07/27/23 08:35:49.445736 nac 9ec type 7 state 1 len 10
07/27/23 08:35:49.446074 nac 9ec type 7 state 1 len 10
07/27/23 08:35:49.446630 [0] tsbk(0x00) mfid90_grg_add_cmd: sg: 42063 ga1: 42050 ga2: 42050 ga3: 42050
07/27/23 08:35:49.446866 nac 9ec type 7 state 1 len 10
07/27/23 08:35:49.516738 clear tgid=1899, freq=771.206250, slot=0
07/27/23 08:35:49.517000 clear tgid=1899, freq=771.206250, slot=1
07/27/23 08:35:49.566887 [0] NAC 0x9ec TSBK: op=02 : 02 00 15 c0 07 6b 15 c0 07 6b da 47
07/27/23 08:35:49.567074 [0] NAC 0x9ec TSBK: op=3c : 3c 00 00 39 ee 01 01 15 a6 70 71 f9
07/27/23 08:35:49.567124 [0] NAC 0x9ec TSBK: op=16 : 96 00 00 40 ff ff ff ff 00 01 bb ff
07/27/23 08:35:49.568784 nac 9ec type 7 state 1 len 10
07/27/23 08:35:49.569338 set tgid=1899, srcaddr=0
07/27/23 08:35:49.569441 [0] tsbk(0x02) grp_v_ch_grant_updt: ch1: 771.206250 ga1: 1899 ch2: 771.206250 ga2: 1899
07/27/23 08:35:49.569592 voice update: tg(1899), freq(771206250), slot(-), prio(3)
07/27/23 08:35:49.569675 do_metadata state=0: [1899] Unknown1
07/27/23 08:35:49.569767 set_frequency(771206250)
07/27/23 08:35:49.575651 [0] NAC 0x9ec TSBK: op=39 : 39 00 01 58 15 70 04 15 48 04 ab 03
07/27/23 08:35:49.575809 [0] NAC 0x9ec TSBK: op=09 : 09 90 11 80 00 00 00 00 00 00 e7 23
07/27/23 08:35:49.575855 [0] NAC 0x9ec TSBK: op=33 : b3 00 33 a5 80 64 09 15 75 62 91 c8
07/27/23 08:35:49.625388 [0] p25_frame_assembler_impl::control: cmd(reset_timer), args({"tuner": 0, "cmd": "reset_timer"})
07/27/23 08:35:49.625861 type 7 with ts 07/27/23 08:35:49.567070 ignored due to frequency change
07/27/23 08:35:49.626065 type 7 with ts 07/27/23 08:35:49.567121 ignored due to frequency change
07/27/23 08:35:49.626279 nac 9ec type 7 state 2 len 10
07/27/23 08:35:49.626446 [0] tsbk(0x39) sccb: rfid: 1 stid: 88 ch1: 1570(770.706250) ch2: 1548(770.456250)
07/27/23 08:35:49.626605 nac 9ec type 7 state 2 len 10
07/27/23 08:35:49.626744 nac 9ec type 7 state 2 len 10
07/27/23 08:35:49.626833 [0] tsbk(0x33) iden_up_tdma: 3 freq: 762006250 toff: 30000000 spac: 12500 slots/carrier: 2
07/27/23 08:35:49.709681 [0] NAC 0x9ec TSBK: op=3a : 3a 00 00 39 ee 01 58 15 20 70 35 34
07/27/23 08:35:49.709877 [0] NAC 0x9ec TSBK: op=3b : 3b 00 00 be e0 09 ee 15 20 70 bc 0a
07/27/23 08:35:49.709926 [0] NAC 0x9ec TSBK: op=00 : 80 90 a4 4f a4 42 a4 42 a4 42 71 12
07/27/23 08:35:49.718508 nac 9ec type 7 state 2 len 10
07/27/23 08:35:49.718818 [0] tsbk(0x3a) rfss_sts_bcst: syid: 9ee rfid: 1 stid: 88 ch1: 1520(770.206250)
07/27/23 08:35:49.719018 nac 9ec type 7 state 2 len 10
07/27/23 08:35:49.719133 [0] tsbk(0x3b) net_sts_bcst: wacn: bee00 syid: 9ee ch1: 1520(770.206250)
07/27/23 08:35:49.719291 nac 9ec type 7 state 2 len 10
07/27/23 08:35:49.719392 [0] tsbk(0x00) mfid90_grg_add_cmd: sg: 42063 ga1: 42050 ga2: 42050 ga3: 42050
07/27/23 08:35:49.836753 [0] NAC 0x9ec TSBK: op=05 : 05 90 40 00 c0 00 00 00 08 00 10 8a
07/27/23 08:35:49.836923 [0] NAC 0x9ec TSBK: op=02 : 02 00 15 c0 07 6b 15 c0 07 6b da 47
07/27/23 08:35:49.836971 [0] NAC 0x9ec TSBK: op=3c : bc 00 00 39 ee 01 0f 15 ac 70 d8 5c
07/27/23 08:35:49.842585 nac 9ec type 7 state 2 len 10
07/27/23 08:35:49.842907 nac 9ec type 7 state 2 len 10
07/27/23 08:35:49.843041 set tgid=1899, srcaddr=0
07/27/23 08:35:49.843164 [0] tsbk(0x02) grp_v_ch_grant_updt: ch1: 771.206250 ga1: 1899 ch2: 771.206250 ga2: 1899
07/27/23 08:35:49.843384 nac 9ec type 7 state 2 len 10
07/27/23 08:35:49.843517 [0] tsbk(0x3c) adj_sts_bcst: rfid: 1 stid: 15 ch1: 15ac(771.081250)
07/27/23 08:35:49.843608 tsbk(0x3c) adj_sts_bcst: 762006250 6250
07/27/23 08:35:49.956793 [0] NAC 0x9ec TSBK: op=16 : 16 00 00 40 ff ff ff ff 00 01 5f cb
07/27/23 08:35:49.956991 [0] NAC 0x9ec TSBK: op=39 : 39 00 01 58 15 48 04 15 98 04 b0 e7
07/27/23 08:35:49.957042 [0] NAC 0x9ec TSBK: op=09 : 89 90 10 40 00 00 00 00 00 00 32 d1
07/27/23 08:35:49.965783 nac 9ec type 7 state 2 len 10
07/27/23 08:35:49.966060 [0] tsbk(0x16) sndcp_data_ch: ch1: ffff ch2: ffff
07/27/23 08:35:49.967033 nac 9ec type 7 state 2 len 10
07/27/23 08:35:49.967275 [0] tsbk(0x39) sccb: rfid: 1 stid: 88 ch1: 1548(770.456250) ch2: 1598(770.956250)
07/27/23 08:35:49.967498 nac 9ec type 7 state 2 len 10
07/27/23 08:35:51.009965 [0] p25p1_fdma::check_timeout: expired
07/27/23 08:35:51.016635 process_data_unit timeout
07/27/23 08:35:51.016930 voice timeout
 

wgbecks

Active Member
Joined
Jan 17, 2005
Messages
1,020
Location
NE Wisconsin
Gents,

I spun up a Debian Bookworm (v12) VM this afternoon and was able to build and run op25 successfully with no audio decode or
voice timeout issues. The only thing that gave me fits was that the apt repository installs Liquidsoap v2.1.3 that has changed the
scripting needed to make use of the output.icecast operator.

Bill
 

boatbod

Member
Joined
Mar 3, 2007
Messages
3,409
Location
Talbot Co, MD
The most recent logs show the channel grants/updates being processed and a tuning command issues but no subsequent acquisition of framing on the voice channel.
07/27/23 08:35:49.569592 voice update: tg(1899), freq(771206250), slot(-), prio(3)
07/27/23 08:35:49.569675 do_metadata state=0: [1899] Unknown1
07/27/23 08:35:49.569767 set_frequency(771206250)
...snip...
07/27/23 08:35:51.009965 [0] p25p1_fdma::check_timeout: expired
07/27/23 08:35:51.016635 process_data_unit timeout
07/27/23 08:35:51.016930 voice timeout
[/code]

It'd be interesting to observe the fft, mixer and datascope plots as tuning takes place to see if there really is a voice signal appearing at the expected location. With the current implementation of my demodulator, even if the ppm and/or tuning is off by 1-2khz it usually locks in eventually.
 

VA4JOE

Member
Joined
Jul 25, 2023
Messages
56
Ok so I made the mistake of running the install script as root because my user was not set up for sudo.

I have reinstalled op25. Now I get all zeros in the frequency part of the screen and can't seem to get a proper -q value to change that.op25new.png
The frequency at the bottom is all wrong too.
 
Status
Not open for further replies.
Top