trunk-recorder
trunk-recorder copied to clipboard
robotastic
Control channel scanning across SDRs not working
When scanning control channels at start or anytime if the control channel scanning crosses between SDR receivers the control channel will never lock on. This is across both trunking types P25 & SmartNet
Thread from discussion on gitter:
Luke Berndt @robotastic Oct 29 20:44 @kb2ear Does it try to tune in the different freq in the list or is it not even trying to tune in some of the freq?
Scott Weis KB2EAR @kb2ear Oct 29 20:46 It appears to scan through the frequencies, but never gets a lock
Scott Weis KB2EAR @kb2ear Oct 29 20:54 the logs follow
Scott Weis KB2EAR @kb2ear Oct 29 21:01 The first file has the errors when the wrong frequency is on top. https://ref020.dstargateway.org/ubr_uploads/controlchannelscan1.txt
Scott Weis KB2EAR @kb2ear Oct 29 21:01 the second is when the correct control channel is on the top of the list https://ref020.dstargateway.org/ubr_uploads/controlchannelscan2.txt
Scott Weis KB2EAR @kb2ear Oct 29 21:04 Here is the config file
Scott Weis KB2EAR @kb2ear Oct 29 21:04 https://ref020.dstargateway.org/ubr_uploads/config.json.txt
Luke Berndt @robotastic Oct 29 21:05 I wonder if the problem has something to do with have the control channel move from one SDR to another. Could you try ordering it so that it tries some of the other 856 & 857MHz control channels before going to the correct one?
Scott Weis KB2EAR @kb2ear Oct 29 21:07 There are only 2 channels on 856/857
Scott Weis KB2EAR @kb2ear Oct 29 21:12 So at around 2am they moved the control channel from 769.543750 to 856.687500 and it went into the never ending scan loop until I moved the 856 up to the top. And around 7pm they moved back to the 769 frequency and I again went back into the loop. So it very well may be when crossing between SDRs
Scott Weis KB2EAR @kb2ear Oct 29 21:14 Also on an unrelated note my XG-25 radio takes forever to scan for the crontrol channel when it's in the 856 channel.
Scott Weis KB2EAR @kb2ear Nov 07 01:05 I can confirm that as soon as the control channel scan crosses between SDRs the control channel will NEVER lock on. It is true on both P25 and SmartNet systems.
Nate Carlson @natecarlson Nov 07 10:16 Interesting! I don't think I've seen a control channel change yet on my system.. sounds pretty frequent on yours?
Scott Weis KB2EAR @kb2ear Nov 07 11:05 The local harris/L3 P25 system seems to change at least once a week, and the motorola systems seem to stay put for the most part but I have see it change on 2 of the 4 systems I watch, one P25 and one smartnet. And in each case it crossed the boundry between SDR's and caused the system to stop decoding and go into and endless loop until I moved to current control channel to the top of the list.
Nate Carlson @natecarlson Nov 08 19:09 Well that's annoying!! I wonder if there's an easy way to simulate this to make it easier to fix and validate.. probably not?
Scott Weis KB2EAR @kb2ear Nov 08 19:16 easy way is to put a frequency on another SDR that is not the control channel at the begining of the list
Nate Carlson @natecarlson Nov 08 19:28 Interesting - doesn't seem to cause issues for me. I was able to start with 853787537 (RTL 2) and then it retuned to 852075000 (RTL 1) and then 852437500 (RTL 1) and started recording calls without problems. This is on a P25 system...
[2020-11-08 19:27:41.095325] (info) [scarmertst] Started with Control Channel: 853.787537 MHz
[2020-11-08 19:27:44.001586] (error) [scarmertst] Retuning to Control Channel: 852.075000 MHz
[2020-11-08 19:27:47.010803] (error) [scarmertst] Retuning to Control Channel: 852.437500 MHz
Nate Carlson @natecarlson Nov 08 19:31 This is on this branch - basically master plus some code to split each new transmission into a separate call.. https://github.com/natecarlson/trunk-recorder/tree/split_recordings_by_call_minimal_on_master
Scott Weis KB2EAR @kb2ear Nov 08 19:50 but does it ever lock on a control channel while scanning?
Scott Weis KB2EAR @kb2ear Nov 08 19:51 your snipet do not show that
Nate Carlson @natecarlson Nov 08 20:04 Sorry, yeah; more complete snippet:
[2020-11-08 19:30:45.636101]: [scarmertst] Started with Control Channel: 853.787537 MHz
[2020-11-08 19:30:48.010655]: [scarmertst] Retuning to Control Channel: 851.887500 MHz
[2020-11-08 19:30:49.183094]: [scarmertst] Control Channel Message Decode Rate: 0.666667/sec, count: 2
[2020-11-08 19:30:51.008632]: [scarmertst] Retuning to Control Channel: 852.075000 MHz
[2020-11-08 19:30:51.008967]: [scarmertst] Control Channel Message Decode Rate: 0.666667/sec, count: 2
[2020-11-08 19:30:54.005234]: [scarmertst] Retuning to Control Channel: 852.437500 MHz
[2020-11-08 19:30:54.005655]: [scarmertst] Control Channel Message Decode Rate: 1/sec, count: 3
[2020-11-08 19:30:54.753116]: [scarmertst] Decoding System ID 40F WACN: BEE07 NAC: 404
[2020-11-08 19:31:21.011976]: [scarmertst] Control Channel Message Decode Rate: 11/sec, count: 33
[2020-11-08 19:31:36.012799]: [scarmertst] Control Channel Message Decode Rate: 18.6667/sec, count: 56
[2020-11-08 19:32:00.009346]: [scarmertst] Control Channel Message Decode Rate: 22/sec, count: 66
[2020-11-08 19:32:03.009866]: [scarmertst] Control Channel Message Decode Rate: 29/sec, count: 87
[2020-11-08 19:32:09.013491]: [scarmertst] Control Channel Message Decode Rate: 21/sec, count: 63
..or with ugly logs:
[2020-11-08 19:30:45.636101]: [scarmertst] Started with Control Channel: 853.787537 MHz
[2020-11-08 19:30:45.637235]: P25 Trunking single-stage decimator - Initial decimated rate: 0 Second decimated rate: 0 Initial Decimation: 0 System Rate: 2096000
[2020-11-08 19:30:45.644911]: P25 Trunking ARB - Initial Rate: 2096000 Resampled Rate: 24091 Initial Decimation: 87 System Rate: 24000 ARB Rate: 0.996223
[2020-11-08 19:30:48.010655]: [scarmertst] Retuning to Control Channel: 851.887500 MHz
[2020-11-08 19:30:48.010922]: - System Source 0 - Min Freq: 850.952043 MHz Max Freq: 853.047957 MHz
[2020-11-08 19:30:49.183094]: [scarmertst] Control Channel Message Decode Rate: 0.666667/sec, count: 2
[2020-11-08 19:30:51.008632]: [scarmertst] Retuning to Control Channel: 852.075000 MHz
[2020-11-08 19:30:51.008882]: - System Source 0 - Min Freq: 850.952043 MHz Max Freq: 853.047957 MHz
[2020-11-08 19:30:51.008967]: [scarmertst] Control Channel Message Decode Rate: 0.666667/sec, count: 2
[2020-11-08 19:30:54.005234]: [scarmertst] Retuning to Control Channel: 852.437500 MHz
[2020-11-08 19:30:54.005558]: - System Source 0 - Min Freq: 850.952043 MHz Max Freq: 853.047957 MHz
[2020-11-08 19:30:54.005655]: [scarmertst] Control Channel Message Decode Rate: 1/sec, count: 3
[2020-11-08 19:30:54.197647]: Source Zero - 2 freq: 0talkgroup: 33211 tsbk02 Grant Update Channel ID: 19 Freq: 0 ga 33211 TDMA -1
[2020-11-08 19:30:54.197788]: Call not found yet; starting call for freq: 0.000000 MHz talkgroup: 33211 source id 0
[2020-11-08 19:30:54.197987]: [scarmertst] TG: 33211 ( ML 3) Freq: 0.000000 MHz Not Recording: no source covering Freq
[2020-11-08 19:30:54.753116]: [scarmertst] Decoding System ID 40F WACN: BEE07 NAC: 404
[2020-11-08 19:31:00.450045]: Call not found yet; starting call for freq: 855.987500 MHz talkgroup: 2264 source id 106300
[2020-11-08 19:31:00.450305]: - Starting P25 Recorder Num [16] TG: 2264 ( EMSAL ALS) Freq: 855.987500 MHz TDMA: false Slot: 0 Mod: true
[2020-11-08 19:31:00.450494]: [scarmertst] TG: 2264 ( EMSAL ALS) Freq: 855.987500 MHz Starting Recorder on Src: rtl=12340005
[2020-11-08 19:31:07.012972]: [scarmertst] TG: 2264 ( EMSAL ALS) Freq: 855.987500 MHz Ending Recorded Call - Last Update: 4s Call Elapsed: 7
[2020-11-08 19:31:07.013667]: - Stopping P25 Recorder Num [16] TG: 2264 ( EMSAL ALS) Freq: 855.987500 MHz TDMA: false Slot: 0
Scott Weis KB2EAR @kb2ear Nov 08 20:13 I'll give your brance a try and see if it works any different
Scott Weis KB2EAR @kb2ear Nov 08 20:27 current control channel is: 472.9
Scott Weis KB2EAR @kb2ear Nov 08 20:28 Bad log:
[2020-11-08 21:26:37.396777] (info) SmartNet Trunking - SysNum: 0
[2020-11-08 21:26:37.396790] (info) Control channel: 477.400000 MHz
Decim: 25 Decim2: 4
[2020-11-08 21:26:37.396977] (info) smartnet Trunking two-stage decimator - Initial decimated rate: 96000 Second decimated rate: 24000 FA: 6250 FB: 12000 System Rate: 2400000
[2020-11-08 21:26:37.406793] (info) smartnet Trunking ARB - Initial Rate: 2400000 Resampled Rate: 24000 Initial Decimation: 25 System Rate: 18000 ARB Rate: 0.75
[2020-11-08 21:26:40.006395] (info) Pll Phase: 3.84961 min Freq: -0.000001 MHz Max Freq: 0.000001 MHz
[2020-11-08 21:26:40.006565] (error) [ftnj] Retuning to Control Channel: 472.900000 MHz
[2020-11-08 21:26:40.006602] (info) - System Source 0 - Min Freq: 471.212500 MHz Max Freq: 473.512500 MHz
[2020-11-08 21:26:41.108900] (error) [ftnj] Control Channel Message Decode Rate: 0/sec, count: 0
[2020-11-08 21:26:43.004429] (info) Pll Phase: -4.72407 min Freq: -0.000001 MHz Max Freq: 0.000001 MHz
[2020-11-08 21:26:43.004639] (error) [ftnj] Retuning to Control Channel: 472.350000 MHz
[2020-11-08 21:26:43.004680] (info) - System Source 0 - Min Freq: 471.212500 MHz Max Freq: 473.512500 MHz
[2020-11-08 21:26:43.004735] (error) [ftnj] Control Channel Message Decode Rate: 0/sec, count: 0
[2020-11-08 21:26:46.005097] (info) Pll Phase: 1.23861 min Freq: -0.000001 MHz Max Freq: 0.000001 MHz
[2020-11-08 21:26:46.005205] (error) [ftnj] Retuning to Control Channel: 472.325000 MHz
[2020-11-08 21:26:46.005251] (info) - System Source 0 - Min Freq: 471.212500 MHz Max Freq: 473.512500 MHz
[2020-11-08 21:26:46.005330] (error) [ftnj] Control Channel Message Decode Rate: 0/sec, count: 0
[2020-11-08 21:26:49.005869] (info) Pll Phase: 1.05384 min Freq: -0.000001 MHz Max Freq: 0.000001 MHz
[2020-11-08 21:26:49.005971] (error) [ftnj] Retuning to Control Channel: 477.400000 MHz
[2020-11-08 21:26:49.006003] (info) - System Source 1 - Min Freq: 475.556250 MHz Max Freq: 477.856250 MHz
[2020-11-08 21:26:50.112520] (error) [ftnj] Control Channel Message Decode Rate: 0/sec, count: 0
[2020-11-08 21:26:52.008092] (info) Pll Phase: -5.14985 min Freq: -0.000001 MHz Max Freq: 0.000001 MHz
[2020-11-08 21:26:52.008348] (error) [ftnj] Retuning to Control Channel: 472.900000 MHz
[2020-11-08 21:26:52.008384] (info) - System Source 0 - Min Freq: 471.212500 MHz Max Freq: 473.512500 MHz
[2020-11-08 21:26:53.110468] (error) [ftnj] Control Channel Message Decode Rate: 0/sec, count: 0
[2020-11-08 21:26:55.008067] (info) Pll Phase: 5.03294 min Freq: -0.000001 MHz Max Freq: 0.000001 MHz
[2020-11-08 21:26:55.008250] (error) [ftnj] Retuning to Control Channel: 472.350000 MHz
[2020-11-08 21:26:55.008275] (info) - System Source 0 - Min Freq: 471.212500 MHz Max Freq: 473.512500 MHz
[2020-11-08 21:26:55.008331] (error) [ftnj] Control Channel Message Decode Rate: 0/sec, count: 0
[2020-11-08 21:26:58.008683] (info) Pll Phase: -2.92908 min Freq: -0.000001 MHz Max Freq: 0.000001 MHz
[2020-11-08 21:26:58.008772] (error) [ftnj] Retuning to Control Channel: 472.325000 MHz
[2020-11-08 21:26:58.008790] (info) - System Source 0 - Min Freq: 471.212500 MHz Max Freq: 473.512500 MHz
[2020-11-08 21:26:58.008823] (error) [ftnj] Control Channel Message Decode Rate: 0/sec, count: 0
[2020-11-08 21:27:01.010596] (info) Pll Phase: 3.01792 min Freq: -0.000001 MHz Max Freq: 0.000001 MHz
[2020-11-08 21:27:01.010714] (error) [ftnj] Retuning to Control Channel: 477.400000 MHz
[2020-11-08 21:27:01.010747] (info) - System Source 1 - Min Freq: 475.556250 MHz Max Freq: 477.856250 MHz
[2020-11-08 21:27:02.112576] (error) [ftnj] Control Channel Message Decode Rate: 0/sec, count: 0
[2020-11-08 21:27:04.008615] (info) Pll Phase: -1.00762 min Freq: -0.000001 MHz Max Freq: 0.000001 MHz
[2020-11-08 21:27:04.008822] (error) [ftnj] Retuning to Control Channel: 472.900000 MHz
Scott Weis KB2EAR @kb2ear Nov 08 20:30 Good Log:
[2020-11-08 21:30:10.127970] (info) SmartNet Trunking - SysNum: 0
[2020-11-08 21:30:10.127984] (info) Control channel: 472.900000 MHz
Decim: 25 Decim2: 4
[2020-11-08 21:30:10.128213] (info) smartnet Trunking two-stage decimator - Initial decimated rate: 96000 Second decimated rate: 24000 FA: 6250 FB: 12000 System Rate: 2400000
[2020-11-08 21:30:10.139211] (info) smartnet Trunking ARB - Initial Rate: 2400000 Resampled Rate: 24000 Initial Decimation: 25 System Rate: 18000 ARB Rate: 0.75
[2020-11-08 21:30:10.835591] (info) Source Zero - 2 freq: 4.71975e+08talkgroup: 48048
Nate Carlson @natecarlson Nov 08 20:51 That is so strange! Wonder if it's a P25 vs Smartnet thing? I don't think I have any Smartnet systems to test against in my area.
Luke Berndt @robotastic Nov 08 20:56 Ah! I have a local smartnet system I can test with. They don't switch control channels that often, but I can test by starting it on the wrong one.
Scott Weis KB2EAR @kb2ear Nov 08 20:58 Here is a P25 example: https://ref020.nj2dg.org/ubr_uploads/goodlog.txt
Scott Weis KB2EAR @kb2ear Nov 08 20:59 https://ref020.nj2dg.org/ubr_uploads/badlog.txt
Nate Carlson @natecarlson Nov 08 20:59 I see you posted a smartnet example too. So strange! Do you have multiple systems being monitored on one instance of TR here or are these separate instances? Just clutching at straws..
Nate Carlson @natecarlson Nov 08 20:59 I mean p25 example of course.
Scott Weis KB2EAR @kb2ear Nov 08 21:27 seperate instances on the same computer, but I can reproduce the issue on a smartnet system on a seperate system in another state.
Nate Carlson @natecarlson Nov 08 21:28 Very strange. Not sure if it makes any difference - but my system is on Ubuntu 20.04 with the packaged versions of rtl-sdr libraries (0.6.0), gnuradio 3.8.1.0~rc1, gr-osmosdr 0.2.0, and osmo-sdr 0.1.8.
Luke Berndt @robotastic Nov 09 21:15 Well - I just tested with my SmartNet system and had the same problem as @kb2ear - the return does not seem to work. I started with some bad channels on one RTL-SDR and then had the good channels later down the list on a different SDR and it failed. It is able to handle retunes on the same SDR. I really don't see anything obvious though that is wrong. One thing I could try is delete the old SmartNet parsing block and create a new one, each retune. I will go try this on a P25 system too, just to double check.
