OP25 (boatbod) multi_rx.py: op25 cannot tune voice channel; wacn/sysid not yet known

[HankFrank]

Hi all, have a weird issue with multi_rx.py. What could cause the System Info to not be gathered and populated in OP25 once you begin decoding a control channel?


Example:



This seems cosmetic until a channel grant comes along, and I get no audio. Here is the output of -v 10:

09/13/23 13:51:02.003134 [0] NAC 0x8a1 PDU:  fmt=17, op=0x3a : 37 fd 00 00 38 a5 81 3a 00 00 86 d1 01 01 41 a9 46 74 60 00 01 7e 57 d9 25 00 00 00 00 00 00 00 00 25 00 ec 8a 7a 00 00 d0 08 00 50 8b 7a 00 00
09/13/23 13:51:02.007942 [0] NAC 0x8a1 TDU3:  
09/13/23 13:51:02.011248 [0] NAC 0x8a1 TSBK: op=33 : 33 00 63 00 00 14 01 c9 c3 80 37 67
09/13/23 13:51:02.011298 [0] NAC 0x8a1 TSBK: op=33 : 33 00 73 00 00 14 01 d9 05 c0 bd 86
09/13/23 13:51:02.011306 [0] NAC 0x8a1 TSBK: op=09 : 89 90 0c 80 00 00 00 00 00 00 68 c7
09/13/23 13:51:02.013321 [0] tsbk(0x33) iden_up_tdma: id: 6 freq: 150000000 toff: 0 spac: 2500 slots/carrier: 2
09/13/23 13:51:02.013541 [0] tsbk(0x33) iden_up_tdma: id: 7 freq: 155000000 toff: 0 spac: 2500 slots/carrier: 2
09/13/23 13:51:02.013628 [0] tsbk(0x09) unhandled: 0x8a189900c800000000000000000
09/13/23 13:51:02.135558 [0] NAC 0x8a1 TSBK: op=30 : 30 00 00 04 28 2f 2d 8e 60 be a5 09
09/13/23 13:51:02.135608 [0] NAC 0x8a1 TSBK: op=33 : 33 00 93 00 00 14 01 e8 48 00 9d f6
09/13/23 13:51:02.135617 [0] NAC 0x8a1 TSBK: op=02 : 82 00 64 3c 07 53 64 3c 07 53 af 35
09/13/23 13:51:02.139446 [0] tsbk(0x33) iden_up_tdma: id: 9 freq: 160000000 toff: 0 spac: 2500 slots/carrier: 2
09/13/23 13:51:02.139784 [0] NAC 0x8a1 TDU3:  
09/13/23 13:51:02.139791 [P25 System] set tgid=1875, srcaddr=0
09/13/23 13:51:02.140523 [P25 System] VF ts ph2: tgid: 1875, freq: 151.355000, slot: 0
09/13/23 13:51:02.140782 [0] tsbk(0x02) grp_v_ch_grant_up: ch1: 151.355000 ga1: 1875 ch2: 151.355000 ga2: 1875
09/13/23 13:51:02.141408 [0] voice update:  tg(1875), rid(0), freq(151.355000), slot(0), prio(3)
09/13/23 13:51:02.141553 [0] releasing control channel
09/13/23 13:51:02.141628 [0] cannot tune voice channel; wacn/sysid not yet known
09/13/23 13:51:02.142103 [0] meta_update: queued[1] msg: {"tgid": 1875, "rid": 0, "tag": "", "json_type": "meta_update", "rtag": ""}
09/13/23 13:51:02.142856 [P25 System] needs control channel receiver
09/13/23 13:51:02.143320 [P25 System] receiver[0] not idle
09/13/23 13:51:02.143465 [P25 System] has no idle receivers for control channel monitoring
09/13/23 13:51:02.189027 icemeta::process_q_events: queue size=1
09/13/23 13:51:02.189281 icemeta::run: received message arg1=09/13/23 13:49:25.818822
09/13/23 13:51:02.189344 icemeta::run: processing message
09/13/23 13:51:02.189483 metadata update: "http://192.168.1.24:8000/admin/metadata?mount=/op25_stream_0&mode=updinfo&song=[1875]"
09/13/23 13:51:02.266211 [0] NAC 0x8a1 TSBK: op=05 : 05 90 40 80 80 00 00 00 08 00 d1 63
09/13/23 13:51:02.266277 [0] NAC 0x8a1 TSBK: op=29 : 29 00 01 01 42 1e 00 46 98 04 48 27
09/13/23 13:51:02.266291 [0] NAC 0x8a1 TSBK: op=34 : b4 00 45 00 00 14 01 c9 c3 80 34 0a
09/13/23 13:51:02.267660 [0] tsbk(0x05) unhandled: 0x8a1059040808000000008000000
09/13/23 13:51:02.268205 [0] tsbk(0x29) sccb_exp: rfid: 1 stid: 1 ch1: 421e(151.355000) ch2: 4698(154.220000)
09/13/23 13:51:02.268400 [0] tsbk(0x34) iden_up_vu: id: 4 toff: 0.000000 spac: 2.500000 freq: 150.000000 [mob Tx-]
09/13/23 13:51:02.268709 [0] NAC 0x8a1 PDU:  fmt=17, op=0x3a : 37 fd 00 00 38 a5 81 3a 00 00 86 d1 01 01 41 a9 46 74 60 00 01 7e 57 d9 55 00 00 00 00 00 00 00 a0 1b 00 ec 8a 7a 00 00 d0 08 00 50 8b 7a 00 00

I can reproduce this with different receivers (both an rtl and an ettus b200 mini) on this particular system. I can also reproduce it on multiple computers/platforms running OP25.

This particular system is a Moto VHF Phase II system. It does not seem to happen on 700/800 systems (both Harris and Moto) but the sample size is not very large.

I have also tested this exact system with rx.py, and I don't get this behavior. Everything seems to work fine with rx.py.

VHF Systems always have funky trunking tables, so could it be an issue regarding that?

My multi_rx.py config is attached. (It is really just a slightly edited version of the p25_sample in the apps directory.)

Thanks!

 

[wgbecks]

This seems odd. I have a statewide VHF P25 Phase-1 site here, but AFAIK, all of the system info displays normally.

Add the line: "raw_output": "P25_System.bin", to your json file as shown below. Restart multi_rx.py the let it run for a couple of minutes,
stop, and save the P25_System.bin file. PM for my email address or upload the file to a publicly accessible file share site.


{
"channels": [
{
"name": "Voice_ch1",
"device": "sdr0",
"trunking_sysname": "P25 System",
"meta_stream_name": "stream_0",
"demod_type": "cqpsk",
"cqpsk_tracking": true,
"tracking_threshold": 120,
"tracking_feedback": 0.75,
"destination": "udp://127.0.0.1:23456",
"excess_bw": 0.2,
"raw_output": "P25_System.bin",
"filter_type": "rc",
"if_rate": 24000,
"plot": "",
"symbol_rate": 4800,
"enable_analog": "off",
"blacklist": "",
"whitelist": "stream0.wlist",
"crypt_keys": "example_keys.json"
}

 

[boatbod]

It's a bug that is now fixed if you run a "git pull"
For the idly curious, the problem was improper decode of MBT (multi-block trunking) messages in tk_p25 due to miscounting of an offset. I'm actually surprised the problem hasn't been noticed before, but I can only guess the 700/800 Motorola systems don't use MBT for sys ident.

 

[HankFrank]

Thanks boatbod!

CC decoding is definitely improved. Channel grants are processed now and it switches over to the proper freq and time slot. However it looks like the SYSID is still not being picked up (WACN is though.)




Also, there are now lot of AMBE decode errors on this system. I tested again with rx.py (on same system and hardware) and rx.py still works fine... multi_rx has the issues. Same config as before.

I sent another .bin file to Bill that should demonstrate the AMBE decode issues. Let me know if I can do anything else to help!

Cheers

 

[boatbod]

Thanks boatbod!

CC decoding is definitely improved. Channel grants are processed now and it switches over to the proper freq and time slot. However it looks like the SYSID is still not being picked up (WACN is though.)


View attachment 148280

Also, there are now lot of AMBE decode errors on this system. I tested again with rx.py (on same system and hardware) and rx.py still works fine... multi_rx has the issues. Same config as before.

I sent another .bin file to Bill that should demonstrate the AMBE decode issues. Let me know if I can do anything else to help!

Cheers

Run a "git pull" and try again please.
The issue I addressed last night was bigger than I anticipated, but the fix was ultimately easier. AMBE decode relies on a scrambling scheme that utilizes WACN and SYSID, so if one of those is incorrect the AMBE decode will fail too.

 

[HankFrank]

Thanks for sharing what the fixes involved. multi_rx seems to be working very well now. Only had a few minutes to check this evening, but both VHF systems here look good so far!

 

[boatbod]

Thanks for sharing what the fixes involved. multi_rx seems to be working very well now. Only had a few minutes to check this evening, but both VHF systems here look good so far!

The most curious part of your experience is that I personally run three instances of multi_rx 24x7 and have never encountered this problem. I can only assume my local /\/\oto 700 system sends it's net_sts_bcst and iden_up messages in abbreviated format TSBKs rather than extended format MBTs.

 

[lwvmobile]

The most curious part of your experience is that I personally run three instances of multi_rx 24x7 and have never encountered this problem. I can only assume my local /\/\oto 700 system sends it's net_sts_bcst and iden_up messages in abbreviated format TSBKs rather than extended format MBTs.

I think I've only seen one system (maybe two?) ever put out MBT/MBF trunking blocks, and it also operates only as a Phase 1 system and puts out Iden Up and Grant Update TSBK single blocks, so even if it had missed the NET_STS_BCST out of the iden up, or not processed any MBT blocks at all, it could have still tuned to some extent and wouldn't need to descramble Phase 2 frames with the WACN/SYSID/CC

08:44:34 Sync: +P25p1  inlvl: 44% nac: [ 14E] src: [       0] tg: [    0]  MBF
 P25 MBF FMT: 17 SAP: 3D Blocks: 01 MFID: 00 ALT MBT - OP: 00
  Group Voice Channel Grant Update - Extended
  SVC [44] CHAN-T [35B9] CHAN-R [3A93] Group [31052][794C]
  Frequency [163.800000] MHz
  Frequency [170.010000] MHz
08:44:34 Sync: +P25p1  inlvl: 44% nac: [ 14E] src: [       0] tg: [    0]  TSBK
 Group Voice Channel Grant Update - Implicit
  Channel 1 [35F8] Group 1 [32205][7DCD]
  Frequency [164.115000] MHz
  Channel 2 [2499] Group 2 [30231][7617]
  Frequency [141.885000] MHz
08:44:34 Sync: +P25p1  inlvl: 45% nac: [ 14E] src: [       0] tg: [    0]  MBF
 P25 MBF FMT: 17 SAP: 3D Blocks: 01 MFID: 00 ALT MBT - OP: 3C
 Adjacent Status Broadcast - Extended
  LRA [00] CFVA [3] RFSS[002] SYSID [14F] SITE [024]
  CHAN-T [35E9] CHAN-R [3A15] SSC [70] WACN [BEE00]
   Up to Date (Correct) Valid RFSS Connection Active
  Frequency [164.040000] MHz
  Frequency [169.380000] MHz
08:44:34 Sync: +P25p1  inlvl: 46% nac: [ 14E] src: [       0] tg: [    0]  TSBK
 Group Voice Channel Grant Update - Implicit
  Channel 1 [35B9] Group 1 [31052][794C]
  Frequency [163.800000] MHz
  Channel 2 [3694] Group 2 [30596][7784]
  Frequency [164.895000] MHz
08:44:34 Sync: +P25p1  inlvl: 44% nac: [ 14E] src: [       0] tg: [    0]  TSBK
 Synchronization Broadcast
  Date: 2023.03.23 Time: 19:46:18 UTC
  Local Time Offset: 0.0 Hours; Invalid System Time 
08:44:34 Sync: +P25p1  inlvl: 46% nac: [ 14E] src: [       0] tg: [    0]  MBF
 P25 MBF FMT: 17 SAP: 3D Blocks: 01 MFID: 00 ALT MBT - OP: 00
  Encrypted Group Voice Channel Grant Update - Extended
  SVC [44] CHAN-T [2499] CHAN-R [2A74] Group [30231][7617]
  Frequency [141.885000] MHz
  Frequency [149.380000] MHz
08:44:34 Sync: +P25p1  inlvl: 45% nac: [ 14E] src: [       0] tg: [    0]  MBF
 P25 MBF FMT: 17 SAP: 3D Blocks: 01 MFID: 00 ALT MBT - OP: 00
08:44:34 Sync: +P25p1  inlvl: 47% nac: [ 14E] src: [       0] tg: [    0]  TSBK
 Group Voice Channel Grant Update - Implicit
  Channel 1 [2499] Group 1 [30231][7617]
  Frequency [141.885000] MHz
  Channel 2 [2499] Group 2 [30231][7617]
  Frequency [141.885000] MHz
 Identifier Update UHF/VHF
  Channel Identifier [3] BW [5] Transmit Offset [20B4]
  Channel Spacing [028] Base Frequency [01DD8618] [156475000]
 Identifier Update for TDMA - Abbreviated
  Channel Identifier [4] Channel Type [3] Transmit Offset [0E10]
  Channel Spacing [064] Base Frequency [0A251584] [851012500]
08:44:35 Sync: +P25p1  inlvl: 47% nac: [ 14E] src: [       0] tg: [    0]  MBF
 P25 MBF FMT: 17 SAP: 3D Blocks: 01 MFID: 00 ALT MBT - OP: 3B
 Network Status Broadcast MBT - Extended
  LRA [00] WACN [BEE00] SYSID [14F] NAC [14E]
  CHAN-T [25C5] CHAN-R [29AB]
  Frequency [143.385000] MHz
  Frequency [148.375000] MHz
08:44:35 Sync: +P25p1  inlvl: 46% nac: [ 14E] src: [       0] tg: [    0]  TSBK
 Group Voice Channel Grant Update - Implicit
  Channel 1 [2499] Group 1 [30231][7617]
  Frequency [141.885000] MHz
  Channel 2 [2499] Group 2 [30231][7617]
  Frequency [141.885000] MHz
 Group Voice Channel Grant Update - Implicit
  Channel 1 [35B9] Group 1 [31052][794C]
  Frequency [163.800000] MHz
  Channel 2 [3694] Group 2 [30596][7784]
  Frequency [164.895000] MHz

 

[HankFrank]

The most curious part of your experience is that I personally run three instances of multi_rx 24x7 and have never encountered this problem. I can only assume my local /\/\oto 700 system sends it's net_sts_bcst and iden_up messages in abbreviated format TSBKs rather than extended format MBTs.

Thanks for the update! Yes this was curious to me too, I just went down the rabbit hole on reading about extended format MBTs.

There are two VHF systems within earshot, the one I captured the data on is 100% Phase II. The other one is Phase II capable, but is still operates almost nearly Phase 1.

The second one (the one I didn't send captures on) exhibited similar behavior to the the other before you made your last change, however the voice channel grant tracking still worked and audio was decoded. What didn't work was that the SysID was still missing and the Adjacent Site decodes did not work correctly.

Here is what the adjacent sites looked like before your last change (sorry, forgot to post this earlier):


The frequencies are correct but the SubSystem IDs and Site IDs were obviously all borked.

Anyway I'm sure you know this but I wanted to make a quick post thanking you...

Cheers