search

robotastic / trunk-recorder

Records calls from a Trunked Radio System (P25 & SmartNet)
GNU General Public License v3.0
837 stars 191 forks source link

P25 Transmissions Bleeding Together #701

Open tadscottsmith opened 2 years ago

tadscottsmith commented 2 years ago

There seems to be an issue with transmissions occasionally bleeding together within a call. From the attached call audio and JSON, you can clearly hear that there should be four distinct transmissions. All four of the transmissions are recorded correctly, but for some reason the last two seem to be combined by trunk-recorder. There are only three transmissions listed in the JSON .

2191 [SRCID 151586]: "2191." DISP [SRCID 151004]: "Go ahead." 2191 [SRCID 151586]: "Begin Oak Street Ramp." DISP [SRCID 151004]: "Copy."

[2022-06-08 17:46:36.764709] (debug)   tsbk00   Chan Grant      Channel ID:  1237       Freq: 858.737500 MHz    ga    3580      TDMA -1 sa 151586       Encrypt 0       Bandwidth: 12.5
[2022-06-08 17:46:36.764979] (trace)   tsbk00   Chan Grant      Channel ID:  1237       Freq: 858.737500 MHz    ga    3580      TDMA -1 sa 151586       Encrypt 0       Bandwidth: 12.5
[2022-06-08 17:46:36.765010] (info)   [mplscc]  1521C   TG:             UMN SEC MON (      3580)        Freq: 858.737500 MHz    Starting P25 Recorder Num [23]  TDMA: false     Slot: 0 QPSK: true
[2022-06-08 17:46:36.765074] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    Starting wavfile sink SRC ID: 151586
[2022-06-08 17:46:36.765115] (trace)   [mplscc] 1521C   TG:             UMN SEC MON (      3580)        Freq: 858.737500 MHz     New Control Channel Transmission. SA: 151586
[2022-06-08 17:46:36.902485] (debug)   tsbk00   Chan Grant      Channel ID:  1237       Freq: 858.737500 MHz    ga    3580      TDMA -1 sa 151586       Encrypt 0       Bandwidth: 12.5
[2022-06-08 17:46:36.902715] (trace)   [mplscc] 1521C   TG:             UMN SEC MON (      3580)        Freq: 858.737500 MHz     Ignoring Control Channel Grant. Likely Duplicate. SA: 151586
[2022-06-08 17:46:37.358633] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    Starting new Transmission       Src ID:  151586
[2022-06-08 17:46:39.105149] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    Spike Count: 0 pos: 12960 offset: 1086898
[2022-06-08 17:46:39.105202] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    Error Count: 0 pos: 12960 offset: 1086898
[2022-06-08 17:46:39.105241] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    TERM - record_more_transmissions = false, setting Recorder More: true - count: 12960
[2022-06-08 17:46:39.657787] (debug)   tsbk00   Chan Grant      Channel ID:  1237       Freq: 858.737500 MHz    ga    3580      TDMA -1 sa 151004       Encrypt 0       Bandwidth: 12.5
[2022-06-08 17:46:39.657962] (trace)   [mplscc] 1521C   TG:             UMN SEC MON (      3580)        Freq: 858.737500 MHz     New Control Channel Transmission. SA: 151004
[2022-06-08 17:46:39.727647] (debug)   tsbk00   Chan Grant      Channel ID:  1237       Freq: 858.737500 MHz    ga    3580      TDMA -1 sa 151004       Encrypt 0       Bandwidth: 12.5
[2022-06-08 17:46:39.728025] (trace)   [mplscc] 1521C   TG:             UMN SEC MON (      3580)        Freq: 858.737500 MHz     Ignoring Control Channel Grant. Likely Duplicate. SA: 151004
[2022-06-08 17:46:40.156423] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    Starting new Transmission       Src ID:  -1
[2022-06-08 17:46:41.112359] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    Spike Count: 0 pos: 7200 offset: 1094105
[2022-06-08 17:46:41.112514] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    Error Count: 0 pos: 7200 offset: 1094105
[2022-06-08 17:46:41.112559] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    TERM - record_more_transmissions = false, setting Recorder More: true - count: 7200
[2022-06-08 17:46:41.829025] (debug)   tsbk00   Chan Grant      Channel ID:  1237       Freq: 858.737500 MHz    ga    3580      TDMA -1 sa 151586       Encrypt 0       Bandwidth: 12.5
[2022-06-08 17:46:41.829124] (trace)   [mplscc] 1521C   TG:             UMN SEC MON (      3580)        Freq: 858.737500 MHz     New Control Channel Transmission. SA: 151586
[2022-06-08 17:46:41.947872] (debug)   tsbk00   Chan Grant      Channel ID:  1237       Freq: 858.737500 MHz    ga    3580      TDMA -1 sa 151586       Encrypt 0       Bandwidth: 12.5
[2022-06-08 17:46:41.947968] (trace)   [mplscc] 1521C   TG:             UMN SEC MON (      3580)        Freq: 858.737500 MHz     Ignoring Control Channel Grant. Likely Duplicate. SA: 151586
[2022-06-08 17:46:42.424176] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    Starting new Transmission       Src ID:  -1
[2022-06-08 17:46:44.177489] (debug)   tsbk00   Chan Grant      Channel ID:  1237       Freq: 858.737500 MHz    ga    3580      TDMA -1 sa 151004       Encrypt 0       Bandwidth: 12.5
[2022-06-08 17:46:44.177626] (trace)   [mplscc] 1521C   TG:             UMN SEC MON (      3580)        Freq: 858.737500 MHz     New Control Channel Transmission. SA: 151004
[2022-06-08 17:46:44.238667] (debug)   tsbk00   Chan Grant      Channel ID:  1237       Freq: 858.737500 MHz    ga    3580      TDMA -1 sa 151004       Encrypt 0       Bandwidth: 12.5
[2022-06-08 17:46:44.238888] (trace)   [mplscc] 1521C   TG:             UMN SEC MON (      3580)        Freq: 858.737500 MHz     Ignoring Control Channel Grant. Likely Duplicate. SA: 151004
[2022-06-08 17:46:45.829419] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    Spike Count: 3 pos: 24480 offset: 1118595
[2022-06-08 17:46:45.829459] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    Error Count: 45 pos: 24480 offset: 1118595
[2022-06-08 17:46:45.829489] (trace)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    TERM - record_more_transmissions = false, setting Recorder More: true - count: 24480
[2022-06-08 17:46:50.008547] (trace)   [mplscc] 1521C   TG:             UMN SEC MON (      3580)        Freq: 858.737500 MHz     Removing call that has been inactive for more than 3 Sec  Rec last write: 1 State: 4
[2022-06-08 17:46:50.008993] (error)   [mplscc] 1521C   TG:       3580  Freq: 858.737500 MHz    Call Grants: 4 . Recorded Transmissions: 3.
[2022-06-08 17:46:50.009031] (info)   [mplscc]  1521C   TG:       3580  Freq: 858.737500 MHz    - Transmission src: 151586 pos: 0 length: 1.62
[2022-06-08 17:46:50.009066] (info)   [mplscc]  1521C   TG:       3580  Freq: 858.737500 MHz    - Transmission src: 151004 pos: 1.62 length: 0.9
[2022-06-08 17:46:50.009099] (info)   [mplscc]  1521C   TG:       3580  Freq: 858.737500 MHz    - Transmission src: 151004 pos: 2.52 length: 3.06

It seems like this Grant correctly starts a third transmission, but does not decode/respond to a TDU before the next transmission begins.

[2022-06-08 17:46:41.829025] (debug)   tsbk00   Chan Grant      Channel ID:  1237       Freq: 858.737500 MHz    ga    3580      TDMA -1 sa 151586       Encrypt 0       Bandwidth: 12.5

I'm assuming that this Grant then updates the SRCID, but does not end the previous transmission and start a new one.

[2022-06-08 17:46:44.177489] (debug)   tsbk00   Chan Grant      Channel ID:  1237       Freq: 858.737500 MHz    ga    3580      TDMA -1 sa 151004       Encrypt 0       Bandwidth: 12.5

I realize this could theoretically be a signal issue, but it is happening on multiple systems, and evenly distributed across frequencies, so it leads me to believe there may be a certain condition that is causing it. It seems this is happening on about 2% of calls.

3580-1654728397_858737500-call_1521.zip

tadscottsmith commented 2 years ago

@robotastic I've tried to track this down, and it seems it's sometimes not recognizing the terminator (TDU), and that is causing transmissions to occasionally blend. Can you double check this block at some point? I keep coming back to it, and it wondering if you are purposely only tagging "terminate" if the amt_produce<= 0. https://github.com/robotastic/trunk-recorder/blob/7c5b88491f6239859977e6e7cf46c1b00e6ebffb/lib/op25_repeater/lib/p25_frame_assembler_impl.cc#L203-L240

Dygear commented 2 years ago

I've had no issues with transmission bleeding into other recordings from one talk group into another now that I've moved over to a much more powerful AMD 5800 based system from the Raspberry Pis. I think it's very likely that given that the system is CPU starved it will continue recording on a frequency that is reused from another talk group when the terminate is late to the processed and is racing against other in flight recordings. So I think there is a data race here.

tadscottsmith commented 2 years ago

Just to clarify, this issue doesn't present itself as recordings from two different talk groups bleeding together. This is just two transmissions from the same talk group by two different radios, being recorded together is a single "transmission" within a call. You probably wouldn't even notice this happening unless you're logging and comparing the "Call Grants" and actual recorded transmissions, or you're able to watch the SUIDs like a hawk. I could be proven wrong, and it could be a race condition, or resource issue. But given that the audio, the terminations, and the next audio is all on the same voice channel (same recorder) and that it's clearly picking up the audio but missing the 20ish TDUs in between leads me to believe there's a bug to look into.

robotastic commented 2 years ago

Thanks for digging into this @tadscottsmith - it is VERY possible there is either a subtle bug in there OR some of the assumptions I made are not universal and are just local to systems I have tested on. The reason I hadn't been including TDU units where there is some audio being produced is because the audio would get dropped because the Termination Flag if true. (I have to double check this). I was always seeing lots of TDUs with amt_produced = 0 . It could be though that there is low signal sometimes and the TDUs are lost... or maybe on some systems there are no blank TDUs... or maybe when a system gets really busy the buffers back up, so the AMT produced could grow even though there is a TDU there.

I can take a look into it. let me know if you find clues!

tadscottsmith commented 2 years ago

[@Dewey3] If you want to give it a shot, this branch has been updated to better handle things on my P25 P1 system. However, I don't have a P25 P2 system close, so I can't test against one. https://github.com/tadscottsmith/trunk-recorder/tree/p25-tx-update

Dewey3 commented 2 years ago

[@Dewey3] If you want to give it a shot, this branch has been updated to better handle things on my P25 P1 system. However, I don't have a P25 P2 system close, so I can't test against one. https://github.com/tadscottsmith/trunk-recorder/tree/p25-tx-update

I just tried it, but unfortunately, I didn't see a difference on the P25 P2-TDMA system. Thank you for trying!

tadscottsmith commented 2 years ago

Has it ever worked on a 4.x version? I just want to double check, since you'd called out 4.3 on the other thread.

tadscottsmith commented 2 years ago

I added a couple a couple of commits. I'm kind of flying blind just digging through code, but I noticed the p25_frame_assembler_impl.cc wasn't ever trying to update the source for P25P2. If you have a minute, give it a shot and see if it makes anything better (or way way worse...).

https://github.com/tadscottsmith/trunk-recorder/tree/p25-tx-update

Dewey3 commented 2 years ago

Has it ever worked on a 4.x version? I just want to double check, since you'd called out 4.3 on the other thread.

I want to say no it has not, BUT, that is from a memory that doesn't work like it used to. With that said, I have to add that I actually came into the v4 game late because I thought there was a problem with the recordings, and it wasn't until just about 3 or 4 months ago that I realized the problem was my fault. I had my v3 gains set at something like 7 for digital and 7 for analog and the raspy sound of the over-modulation in v4 with my v3 gains did not click on what to do until earlier this year.

Dewey3 commented 2 years ago

Thanks again! It's close to nighttime retirement time for me, so I'll give this a shot when I return home from work tomorrow.

Dewey3 commented 2 years ago

I added a couple a couple of commits. I'm kind of flying blind just digging through code, but I noticed the p25_frame_assembler_impl.cc wasn't ever trying to update the source for P25P2. If you have a minute, give it a shot and see if it makes anything better (or way way worse...).

https://github.com/tadscottsmith/trunk-recorder/tree/p25-tx-update

I just gave it a shot and unfortunately, no change. Just for a matter of clarification, the way I'm doing the checking is by watching the UID live in Rdio-Scanner after TrunkRecorder sends the transmissions. The system is a very busy system, and a lot of the transmissions are back-to-back-to-back-to-back. When the rapid transmissions happen, most times the same UID will remain on the Rdio-Scanner screen, but occasionally, the UID will fail to populate at all, For the sake of comparison, when I pop my TrunkRecorder v3 card back into the RPi, everything returns to working as it should with the UID following the actual transmitting UID no matter how fast the transmissions come behind each other. I am able to verify the correctness of the live UIDs buy following the same transmissions on the SDS100, SDS200, and Unitrunker.

tadscottsmith commented 2 years ago

Bummer! Well, if anyone has a spare box around near a P25P2 system, let me know. Otherwise, without being able to print out some debugging statements to troubleshoot, I am not sure how much more I can dig into for P25P2. I know on P25P1 it seemed that either intentionally or unintentionally the Control Channel wasn't always processing grant message as fast as the voice channel, and it seems to work a little better to trust the voice channel once the recorder has started.

Dewey3 commented 2 years ago

When I get home today, I'll see if I can build a quick testbed RPi for the 2A8 system that you can ssh into and I'll leave up for the weekend.

tadscottsmith commented 2 years ago

I won't be able to do anything this weekend, but I can probably find some time next week! We can touch base after the weekend.

robotastic commented 2 years ago

I get spotty reception of the PG County system. I can try running to see if I can spot something. There is also a chance the pipeline for getting those IDs to Rdio could have been messed up too.

If I have enough SDRs I maybe able to run 3.x side by side with 4.x and look for differences.

On Jun 17, 2022, at 11:50 AM, tadscottsmith @.***> wrote:

 I won't be able to do anything this weekend, but I can probably find some time next week! We can touch base after the weekend.

— Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you were mentioned.

Dewey3 commented 2 years ago

I get spotty reception of the PG County system. I can try running to see if I can spot something. There is also a chance the pipeline for getting those IDs to Rdio could have been messed up too. If I have enough SDRs I maybe able to run 3.x side by side with 4.x and look for differences. … On Jun 17, 2022, at 11:50 AM, tadscottsmith @.***> wrote:  I won't be able to do anything this weekend, but I can probably find some time next week! We can touch base after the weekend. — Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you were mentioned.

Thanks Luke. You gave me another idea for one thing I didn't think about before. With v4, I am sending the recordings to Rdio on another RPi via plugin. Since the plugin did not exist in v3, I run both on the receiving Rpi ingesting the call into the local copy of Rdio via DIrwatch, then sending downstream to the main Rpi. I need to throw Rdio on the local Rpi when running v4, then ingest the calls locally as I do with v3 to see if there is a difference. Thanks again... I'll probably give that a try this evening since I will not be in a rush to build the testbed RPi.

tadscottsmith commented 2 years ago

@robotastic I've got a lot of extra logging turned on, but here's an example on P25 P1 where the master branch wouldn't correctly update the SRCID.

The second transmission (below) either doesn't receive or fails to process any TDUs.

[2022-06-17 11:34:24.370340] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    Starting New Transmission       Src ID:  320643

This means that the second and third transmissions (320643 and 312993) would be recorded together and would only have one SRCID (320643). What seems to be working pretty well is to end the transmission and let it start a new transmission any time that the voice channel and current call have different sources. I think you had most of the code already stubbed out and commented. I'm wondering if something similar is occurring in P25P2. 

[2022-06-17 11:34:19.687548] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Starting P25 Recorder Num [0]   TDMA: false     Slot: 0 QPSK: true
[2022-06-17 11:34:19.783264] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    TERM - CHANNEL Record More Transmissions: true
[2022-06-17 11:34:19.790885] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Chan Grant      SA: 312993
[2022-06-17 11:34:19.849784] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:19.947267] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:20.112490] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    Starting New Transmission       Voice Src ID:  312993   Call Src ID: 312993
[2022-06-17 11:34:20.112568] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    Starting New Transmission       Src ID:  312993
[2022-06-17 11:34:20.224172] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:20.607187] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:20.879678] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:21.211245] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:21.491654] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:21.810562] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:22.082737] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:22.186830] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    TERM - record_more_transmissions = false, setting Recorder More: true - count: 15840
[2022-06-17 11:34:22.187336] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    Ending Current Transmission     Src ID:  312993
[2022-06-17 11:34:22.463333] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:22.800504] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:23.389278] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    TERM - CHANNEL Record More Transmissions: true
[2022-06-17 11:34:23.493535] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    TERM - CHANNEL Record More Transmissions: true
[2022-06-17 11:34:23.604291] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    TERM - CHANNEL Record More Transmissions: true
[2022-06-17 11:34:23.773936] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Chan Grant      SA: 320643
[2022-06-17 11:34:23.832160] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Chan Grant      SA: 320643
[2022-06-17 11:34:23.889922] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:24.108429] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:24.370244] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    Starting New Transmission       Voice Src ID:  -1       Call Src ID: 320643
[2022-06-17 11:34:24.370340] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    Starting New Transmission       Src ID:  320643
[2022-06-17 11:34:24.439671] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:24.809846] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:25.092216] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:25.308516] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Chan Grant      SA: 312993
[2022-06-17 11:34:25.423763] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Chan Grant      SA: 312993
[2022-06-17 11:34:25.480384] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:25.573762] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:25.857400] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:26.240303] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:26.449163] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    Mismatched Voice Channel Source ID: 312993 Current Source ID: 320643 Since Update: 0
[2022-06-17 11:34:26.449471] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    Ending Current Transmission     Src ID:  320643
[2022-06-17 11:34:26.449725] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    Starting New Transmission       Voice Src ID:  312993   Call Src ID: 312993
[2022-06-17 11:34:26.449786] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    Starting New Transmission       Src ID:  312993
[2022-06-17 11:34:26.622934] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:26.831335] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:27.008367] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:27.265864] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:27.606536] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:27.872394] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:28.197931] (error)   [ramsey] 363C    TG:               SPPD CH 5 (     11532)        Freq: 853.212500 MHz    Grant Update    SA: -1
[2022-06-17 11:34:28.409382] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    TERM - record_more_transmissions = false, setting Recorder More: true - count: 14976
[2022-06-17 11:34:28.409641] (error)   [ramsey] 363C    TG:      11532  Freq: 853.212500 MHz    Ending Current Transmission     Src ID:  312993
tadscottsmith commented 2 years ago

I'm also curious about this line not having an equivalent for p2tdma? I tried to build it out blind in my branch above, but it may not have worked.

https://github.com/robotastic/trunk-recorder/blob/fc16d6e85d5a0ea04f11da23bd0d7d07bea5ccd5/lib/op25_repeater/lib/p25_frame_assembler_impl.cc#L204

Dewey3 commented 2 years ago

I just completed the trial of v4 into a local copy of Rdio via Rdio's Dirwatch, and I'm still missing a lot of the UIDs when the transmissions are right behind each other.

Dygear commented 2 years ago

What is the JSON configuration needed for that level of logging? @tadscottsmith?

tadscottsmith commented 2 years ago

What is the JSON configuration needed for that level of logging? @tadscottsmith?

It's just a custom branch I've been using for debugging with a bunch of extra log statements. Nothing that can be changed in the config file as of yet, but I could certainly put in a PR with some additional call logging.

robotastic commented 2 years ago

@tadscottsmith that is a really interesting catch, where the source changes but there is no TDU message. How is your reception? is it possible that those "packets" were just dropped for some reason?

I was thinking of having the transmissions switch if the source does... I just wasn't sure if that would create new problems if I have some weird errors with the src decoding. It might be worth trying to re-enable that.

If I am remembering things right, Phase 2 audio still gets put through the Phase 1 decoder first, and that is where the SRC ID is captured.... I should go check though

Dewey3 commented 2 years ago

I'm not seeing a way to PM on Github so I don't know how to send the credentials. I do have a duplicate Prince George's Co, MD 2A8 system up and running on a spare RPi that is ready for either of you to take a look at via SSH and/or Rdio-Scanner and fiddle with if needed.

tadscottsmith commented 2 years ago

@robotastic I added some additional logging, and it appears the TDUs are being received, although this issue seems to happen when there are just a short number of TDUs before the next HDU/LDU. Here's the full log of a transmission from two different sources, 117020 and 116007.

[2022-06-22 17:30:40.373361] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        Starting New Transmission       Voice Src ID:  117020   Call Src ID: 117020
[2022-06-22 17:30:40.464770] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 576      SAMPLE COUNT: 864
[2022-06-22 17:30:40.649723] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU2    Last Source 0
[2022-06-22 17:30:40.651104] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 1440
[2022-06-22 17:30:40.744241] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 0
[2022-06-22 17:30:40.746517] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 2304
[2022-06-22 17:30:40.843743] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 3168
[2022-06-22 17:30:40.933515] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU2    Last Source 0
[2022-06-22 17:30:40.935140] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 4032
[2022-06-22 17:30:41.027413] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 4896
[2022-06-22 17:30:41.214697] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 0
[2022-06-22 17:30:41.214736] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - GRP_V_CH_USR    New Source 117020
[2022-06-22 17:30:41.216523] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 5760
[2022-06-22 17:30:41.305251] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU2    Last Source 117020
[2022-06-22 17:30:41.308623] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 6624
[2022-06-22 17:30:41.400048] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 7488
[2022-06-22 17:30:41.498878] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 117020
[2022-06-22 17:30:41.498921] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - GRP_V_CH_USR    New Source 117020
[2022-06-22 17:30:41.501865] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 8352
[2022-06-22 17:30:41.588484] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU2    Last Source 117020
[2022-06-22 17:30:41.591811] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 9216
[2022-06-22 17:30:41.772996] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 10080
[2022-06-22 17:30:41.867600] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 117020
[2022-06-22 17:30:41.871960] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 10944
[2022-06-22 17:30:41.962019] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 11808
[2022-06-22 17:30:42.055375] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU2    Last Source 117020
[2022-06-22 17:30:42.056961] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 12672
[2022-06-22 17:30:42.154517] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 117020
[2022-06-22 17:30:42.155714] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 13536
[2022-06-22 17:30:42.244629] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 14400
[2022-06-22 17:30:42.428257] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU2    Last Source 117020
[2022-06-22 17:30:42.430114] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 15264
[2022-06-22 17:30:42.456573] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        Chan Grant      SA: 116007
[2022-06-22 17:30:42.528215] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        Chan Grant      SA: 116007
[2022-06-22 17:30:42.531649] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 16128
[2022-06-22 17:30:42.617743] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 117020
[2022-06-22 17:30:42.619740] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDU     Last Source 117020
[2022-06-22 17:30:42.619789] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 117020
[2022-06-22 17:30:42.619843] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:42.619859] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - IGNORING ADDING TERMINATE TAG         AMT_PRODUCE: 864
[2022-06-22 17:30:42.619964] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 16992
[2022-06-22 17:30:42.714042] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 117020
[2022-06-22 17:30:42.714074] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 17:30:42.714124] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 0
[2022-06-22 17:30:42.714171] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDU     Last Source 0
[2022-06-22 17:30:42.714215] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:42.714232] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - IGNORING ADDING TERMINATE TAG         AMT_PRODUCE: 864
[2022-06-22 17:30:42.714281] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 17856
[2022-06-22 17:30:42.811498] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - HDU     Last Source 0
[2022-06-22 17:30:42.900121] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 0
[2022-06-22 17:30:42.901284] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 18720
[2022-06-22 17:30:43.084762] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 576      SAMPLE COUNT: 19584
[2022-06-22 17:30:43.178968] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU2    Last Source 0
[2022-06-22 17:30:43.184102] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 20160
[2022-06-22 17:30:43.273696] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 576      SAMPLE COUNT: 21024
[2022-06-22 17:30:43.368657] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 0
[2022-06-22 17:30:43.368685] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 17:30:43.371292] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 21600
[2022-06-22 17:30:43.467200] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU2    Last Source 0
[2022-06-22 17:30:43.471042] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 22464
[2022-06-22 17:30:43.645862] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 23328
[2022-06-22 17:30:43.739880] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 0
[2022-06-22 17:30:43.739911] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - GRP_V_CH_USR    New Source 116007
[2022-06-22 17:30:43.745277] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        Mismatched Voice Channel Source ID: 116007 Current Source ID: 117020 Samples: 24192
[2022-06-22 17:30:43.745305] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 24192
[2022-06-22 17:30:43.844658] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 25056
[2022-06-22 17:30:43.929255] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU2    Last Source 116007
[2022-06-22 17:30:43.933203] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 25920
[2022-06-22 17:30:44.023232] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 116007
[2022-06-22 17:30:44.027927] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 26784
[2022-06-22 17:30:44.206758] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 27648
[2022-06-22 17:30:44.301314] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU2    Last Source 116007
[2022-06-22 17:30:44.302706] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 28512
[2022-06-22 17:30:44.395613] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 116007
[2022-06-22 17:30:44.396700] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDU     Last Source 116007
[2022-06-22 17:30:44.396718] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:44.396733] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - IGNORING ADDING TERMINATE TAG         AMT_PRODUCE: 864
[2022-06-22 17:30:44.396881] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 29376
[2022-06-22 17:30:44.490792] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 116007
[2022-06-22 17:30:44.490871] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 116007
[2022-06-22 17:30:44.490930] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:44.490951] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - IGNORING ADDING TERMINATE TAG         AMT_PRODUCE: 864
[2022-06-22 17:30:44.491167] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 30240
[2022-06-22 17:30:44.585033] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 116007
[2022-06-22 17:30:44.585114] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 116007
[2022-06-22 17:30:44.585181] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:44.585201] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - IGNORING ADDING TERMINATE TAG         AMT_PRODUCE: 576
[2022-06-22 17:30:44.585269] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 576      SAMPLE COUNT: 31104
[2022-06-22 17:30:44.771612] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 116007
[2022-06-22 17:30:44.771650] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 17:30:44.771712] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 0
[2022-06-22 17:30:44.771784] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 0
[2022-06-22 17:30:44.771846] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:44.771866] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - ADDING TERMINATE TAG  AMT_PRODUCE: 0
[2022-06-22 17:30:44.772207] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - TERMINATE TAG RECEIVED       Sample count 31680 Pos: 31680 Offset: 53326
[2022-06-22 17:30:44.772235] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 1        SAMPLE COUNT: 31680
[2022-06-22 17:30:44.772397] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TERM - record_more_transmissions = false, setting Recorder More: true - count: 31680
[2022-06-22 17:30:44.772522] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        Ending Current Transmission     Src ID:  116007

You can see here that there are only 5 TDUs in a very brief period of time, and the p25_frame_assembler_impl::general_work() ignores them, because it apparently is never able to get to a state of AMT_PRODUCE == 0 while terminate_call == true.

[2022-06-22 17:30:42.456573] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        Chan Grant      SA: 116007
[2022-06-22 17:30:42.528215] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        Chan Grant      SA: 116007
[2022-06-22 17:30:42.531649] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 16128
[2022-06-22 17:30:42.617743] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 117020
[2022-06-22 17:30:42.619740] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDU     Last Source 117020
[2022-06-22 17:30:42.619789] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 117020
[2022-06-22 17:30:42.619843] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:42.619859] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - IGNORING ADDING TERMINATE TAG         AMT_PRODUCE: 864
[2022-06-22 17:30:42.619964] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 16992
[2022-06-22 17:30:42.714042] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 117020
[2022-06-22 17:30:42.714074] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 17:30:42.714124] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 0
[2022-06-22 17:30:42.714171] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDU     Last Source 0
[2022-06-22 17:30:42.714215] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:42.714232] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - IGNORING ADDING TERMINATE TAG         AMT_PRODUCE: 864
[2022-06-22 17:30:42.714281] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 17856
[2022-06-22 17:30:42.811498] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - HDU     Last Source 0
[2022-06-22 17:30:42.900121] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 0
[2022-06-22 17:30:42.901284] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 18720
[2022-06-22 17:30:43.084762] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 576      SAMPLE COUNT: 19584

And here you can see at the end of the second "transmission", there were 8 TDUs over a longer period of time and p25_frame_assembler_impl::general_work() appears to be able to process all they way through amt_produced and the terminate tag is correctly applied and sent to the transmission_sink.

[2022-06-22 17:30:44.396700] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDU     Last Source 116007
[2022-06-22 17:30:44.396718] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:44.396733] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - IGNORING ADDING TERMINATE TAG         AMT_PRODUCE: 864
[2022-06-22 17:30:44.396881] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 29376
[2022-06-22 17:30:44.490792] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 116007
[2022-06-22 17:30:44.490871] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 116007
[2022-06-22 17:30:44.490930] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:44.490951] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - IGNORING ADDING TERMINATE TAG         AMT_PRODUCE: 864
[2022-06-22 17:30:44.491167] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 30240
[2022-06-22 17:30:44.585033] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 116007
[2022-06-22 17:30:44.585114] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 116007
[2022-06-22 17:30:44.585181] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:44.585201] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - IGNORING ADDING TERMINATE TAG         AMT_PRODUCE: 576
[2022-06-22 17:30:44.585269] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 576      SAMPLE COUNT: 31104
[2022-06-22 17:30:44.771612] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 116007
[2022-06-22 17:30:44.771650] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 17:30:44.771712] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 0
[2022-06-22 17:30:44.771784] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDULC   Last Source 0
[2022-06-22 17:30:44.771846] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - P1FDMA TERMINATE_CALL : TRUE
[2022-06-22 17:30:44.771866] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        FRAME ASSEMBLER - ADDING TERMINATE TAG  AMT_PRODUCE: 0
[2022-06-22 17:30:44.772207] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - TERMINATE TAG RECEIVED       Sample count 31680 Pos: 31680 Offset: 53326
[2022-06-22 17:30:44.772235] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 1        SAMPLE COUNT: 31680
[2022-06-22 17:30:44.772397] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TERM - record_more_transmissions = false, setting Recorder More: true - count: 31680
[2022-06-22 17:30:44.772522] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        Ending Current Transmission     Src ID:  116007

I'm still learning this flow, so I figured I'd log what I have so far, and maybe something will stand out to you.

robotastic commented 2 years ago

Nice detective work - I am going to have to dig into your fork so I can better match up the log messages with what is happening.

One interesting thing I saw:

[2022-06-22 17:30:42.428257] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU2    Last Source 117020
[2022-06-22 17:30:42.430114] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 15264
[2022-06-22 17:30:42.456573] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        Chan Grant      SA: 116007
[2022-06-22 17:30:42.528215] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        Chan Grant      SA: 116007
[2022-06-22 17:30:42.531649] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 856.938e+08        TRANSMISSION SINK - DOWORK       NOUTPUT_ITEMS: 864      SAMPLE COUNT: 16128
[2022-06-22 17:30:42.617743] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - LDU1    Last Source 117020
[2022-06-22 17:30:42.619740] (error)   [mplscc] 34C     TG:            MPLS PD 3 DI (      2958)        Freq: 8.56938e+08        P25P1 - TDU     Last Source 117020

If I am reading this right, it looks like the Control Channel, channel grant message comes in before the TDU... which sort of shows the difference in processing time between the two.

I will dig in more

robotastic commented 2 years ago

PS - I did try to put together a flow chart on call handling... not sure it makes things clearer: https://github.com/robotastic/trunk-recorder/blob/master/docs/notes/CALL-HANDLING.md

tadscottsmith commented 2 years ago

This branch is very similar to your master, except that it has a ton of extra logging: https://github.com/tadscottsmith/trunk-recorder/tree/p25-logging It segfaults occasionally, which I assume has something to do with my hasty work to pass the call info all over, but it generally runs long enough to see a few mismatches.

To further complicate things, it appears there is a "hang time", or "teardown time" (approximately 2 seconds) in which there is never a grant on the control channel and the source is only updated via the voice channel. I'm trying to find actual documentation on it, but here's an example (no Grant for 154241)...

[2022-06-22 20:26:35.213467] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 856.262500 MHz    Chan Grant      SA: 169895
[2022-06-22 20:26:35.264950] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 856.262500 MHz    Chan Grant      SA: 169895
[2022-06-22 20:26:35.816026] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:36.566575] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 169895
[2022-06-22 20:26:36.849852] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 169895
[2022-06-22 20:26:37.694223] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:37.877389] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:37.958355] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 856.262500 MHz    Chan Grant      SA: 154241
[2022-06-22 20:26:38.066893] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:38.067037] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:38.067131] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:38.086145] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 856.262500 MHz    Chan Grant      SA: 154241
[2022-06-22 20:26:39.188686] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 154241
[2022-06-22 20:26:39.560565] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 154241
[2022-06-22 20:26:39.940334] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:40.121914] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:40.316568] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:40.405384] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:40.683649] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:40.707643] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 856.262500 MHz    Chan Grant      SA: 169895
[2022-06-22 20:26:40.767539] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 856.262500 MHz    Chan Grant      SA: 169895
[2022-06-22 20:26:40.872408] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:40.872664] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:41.061740] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:42.089530] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 169895
[2022-06-22 20:26:42.372853] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 169895
[2022-06-22 20:26:44.151175] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 169895
[2022-06-22 20:26:45.181031] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:45.274233] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:45.462676] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:45.646334] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:45.837110] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:45.930337] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:46.023214] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:47.050760] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 154241
[2022-06-22 20:26:47.424643] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 154241
[2022-06-22 20:26:48.833810] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 154241
[2022-06-22 20:26:49.113036] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:49.297586] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:49.493903] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:49.581115] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:49.772459] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:50.046860] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
[2022-06-22 20:26:50.143036] (error)   [mplscc] 195C    TG:            MTC PD DISPW (      2532)        Freq: 8.56262e+08        P25P1 - GRP_V_CH_USR    New Source 0
robotastic commented 2 years ago

SO! It looks like the voice data that is sent along with the TDU, may actually be silence. This means it should be safe to terminate if we see any TDU come in... I think. I am going to look at the specs some more. There is also a good chance that there are differences in implementations.

Screen Shot 2022-06-22 at 9 55 07 PM

robotastic commented 2 years ago

That is super weird that there was no Channel Grant for the new Source. I wonder if it came in as a Channel Update message vs a Channel Grant? The update messages do not have a Src ID in them. Still - I thought all new units transmitting got a channel grant.

Dewey3 commented 2 years ago

Luke, you're w - a - a - a - y - y beyond my education and pay scale now; however, is there something you can do to compare the last few versions of v3 to the latest versions? I still run v3 and do not see any problems between the transmissions.

tadscottsmith commented 2 years ago

I'm not seeing a way to PM on Github so I don't know how to send the credentials. I do have a duplicate Prince George's Co, MD 2A8 system up and running on a spare RPi that is ready for either of you to take a look at via SSH and/or Rdio-Scanner and fiddle with if needed.

@Dewey3 Are you in the Discord? If you message me, I can take a look and see if I see anything obvious.

tadscottsmith commented 2 years ago

If I'm reading this correctly, it seems like if the system is setup in message trunking mode and using the direct call continuation method, that there could be multiple sources (tranmissions) on the traffic channel without additional explicit grants on the control channel. As long as the response was within the hang time, it would just continue sending grant updates.

Pages 74-76 explain (diagram is for control channel method and there is no diagram for direct method). https://www.taitradioacademy.com/wp-content/uploads/2016/02/TRG-00001-01-M_Intro_to_P25.pdf

robotastic commented 2 years ago

Interesting!! that is a great find @tadscottsmith. It could be something like that. I wonder why the old system was working though? It was only getting the Src IDs from the control channel, and those only come on the Grant messages, not the Updates.

Are the transmission really short? Like there wouldn't be time for the Src ID to come over the Voice Channel?

robotastic commented 2 years ago

Still - There should be TDUs on the voice channel... but maybe in this mode there are less of them or they always have silent voice samples attached. I will go remove the check on the TDUs and just have them all be equal.

Dewey3 commented 2 years ago

Interesting!! that is a great find @tadscottsmith. It could be something like that. I wonder why the old system was working though? It was only getting the Src IDs from the control channel, and those only come on the Grant messages, not the Updates.

Are the transmission really short? Like there wouldn't be time for the Src ID to come over the Voice Channel?

Thanks much @robotastic and @tadscottsmith for all that you do! As I mentioned, I don't know about the inner workings of trunking or TrunkRecorder, so I unfortunately can't comment there. However, I can say like TrunkRecorder v3, I don't think Unitrunker misses the data for any changes and transmissions on the same PG Co, MD P25P2-TDMA system, and I'm pretty sure that it gets its information from only the control channel.

robotastic commented 2 years ago

To be fair - the inner workings of Trunk Recorder are a bit of a mess! Thanks for putting up with it!

That was a great clue - it looks like I had actually changed the code so Src IDs were not being sent in from the Voice Channel. I just fixed that in the latest build.

robotastic commented 2 years ago

@tadscottsmith I also changed it so that the TDU flag will end a transmission even if there were audio samples that came in with it.

tadscottsmith commented 2 years ago

Sounds great. Thanks for the updates! I'm out for a few days but will do some testing later this week or next. Enjoy the holiday! Perhaps @Dewey3 can pull the latest version and see if it's able to keep up on his busy system.

tadscottsmith commented 2 years ago

@robotastic I took a look and can’t see any reason that the changes would impact the TGID. What indications were you seeing that the TGID was messed up? I can certainly dig deeper and find out.

robotastic commented 2 years ago

@tadscottsmith yea... I didn't see anything either, it was super weird! It could have been some weird compilation thing and it was building against an old library version or something.

I did find a fix, I think. The PTT packet gets sent every time someone keys their radio. It can be used to separate the transmissions... and it also has the SRC ID for the next transmission!! I was testing on the same system as @Dewey3 and I think it is working. Give the Master branch a try.

I am curious though on where you got those extra message types from, that you added in on your branch?

tadscottsmith commented 2 years ago

They were in older versions of OP25. I went back to your v3.3.7 and it seems like OP25 used to update the SRC on many more message types, although mostly they are just idle messages or group voice channel user update messages. You should probably be safe just using the SRC from the voice frames, but I have noticed in my logging that occasionally it seems there's a few frames of voice with a SRC of 0 before the voice channel starts sending the real source.

robotastic commented 2 years ago

oh! That is genius! I didn't catch that it had changed on the OP25 side. Let me see if I can re-create what was happening, but use a test branch!:)

Dewey3 commented 2 years ago

Thanks @robotastic - I built this version, but was only able to run it for 5 or 10 minutes today. Looking at a couple of the json files that contain multiple transmissions, that 5 or 10 minutes looks promising, so I can't wait until tomorrow to give it the full test. Just a side note... when I complete a build, I like to create an image file of the fresh build, so I will do a full clean up of the OS with autoremove --purge, autoclean, and clean. When I did that today, some packages got removed but I don't think that they're affecting the build. I'll find that out tomorrow also. Here's a screenshot of the removals:

image

Dewey3 commented 2 years ago

There is still an occasional miss, but they are far and few... this version is working miles better at catching the SRCID, in fact, I sometimes see the new ID popup on Rdio a second or two before the transmission actually starts (could be the timing for the call grant). Concerning the packages that got removed with this version, it looks like that killed the "compressWav" function. While I have compressWav set to true, I have never seen anything other than a wav file. That's certainly NOT a problem since I can always rebuild electing to not remove those packages, or let Rdio do the compression for me, the latter is what I am doing for now.