OP25 OP25 Hold Problem

[n5pwp]

I've been playing with the Osmocom version of OP25 and I've noticed that if I leave a TG on hold for a while when I release it and go back to scanning it doesn't. The TSBKs don't count up either. That leads me to stopping it and restarting the program. Anybody had this issue before?
Here's the last lines of the stderr.2 log. I have the whole log if needed:

using ALSA sound system
audio device: default
Listening on 127.0.0.1:23456
python version detected: 2.7.16 (default, Oct 10 2019, 22:02:15)
[GCC 8.3.0]
Allocating 15 zero-copy buffers
1642620111.827208 p25p1_fdma::rx_sym() timeout, channel 0
1642620111.830929 process_data_unit timeout, channel 0
1642620111.833696 control channel timeout, current CC 774431250
Traceback (most recent call last):
File "/home/pi/op25/op25/gr-op25_repeater/apps/sql_dbi.py", line 78, in insert_row
self.cursor.execute(d['command'], d['row'])
OperationalError: no such table: data_store
sql_dbi: db logging stopped due to error (or db not initialized)
1642620113.191461 p25p1_fdma::rx_sym() timeout, channel 0
1642620113.198981 process_data_unit timeout, channel 0
1642620113.199691 control channel timeout, current CC 774431250
1642620114.835707 error tracking: {"tuning_error": -38, "band": 0, "name": "rx.py", "time": 1642620114.835451, "device": "rtl", "freq_correction": -38, "json_type": "freq_error_tracking", "error_band": 0, "freq_error": -258}
1642620117.981714 voice update: tg(2766), freq(773218750), slot(1), prio(5)
1642620119.529557 p25p1_fdma::rx_sym() timeout, channel 0
1642620119.530216 process_data_unit timeout, channel 0
1642620121.168789 error tracking: {"tuning_error": -67, "band": 0, "name": "rx.py", "time": 1642620121.168562, "device": "rtl", "freq_correction": -67, "json_type": "freq_error_tracking", "error_band": 0, "freq_error": -197}
1642620123.409781 duid15, tg(2766)
1642620124.478476 hold active tg(2766)
1642620124.489342 hold active tg(2766)
1642620124.531039 hold active tg(2766)
1642620124.531734 voice update: tg(2766), freq(773218750), slot(1), prio(5)
1642620128.020323 error tracking: {"tuning_error": -90, "band": 0, "name": "rx.py", "time": 1642620128.020045, "device": "rtl", "freq_correction": -90, "json_type": "freq_error_tracking", "error_band": 0, "freq_error": -159}
main: exception occurred
main: exception:
Traceback (most recent call last):
File "./rx.py", line 797, in run
time.sleep(1)
KeyboardInterrupt

I see messages about tuning errors. I have played with the ppm and have gotten it down as far as I can. Plus, I've seen errors larger than this and the auto-tune was able to yank it back when scanning. Is there a requirement to hold the tuning better than this while on Hold?
This is running on a RPi 3B+

Thanks
Mike

 

[KA1RBI]

I've been playing with the Osmocom version of OP25 and I've noticed that if I leave a TG on hold for a while when I release it and go back to scanning it doesn't. The TSBKs don't count up either.

At exactly what point in time do the TSBKs stop counting? It's normal in rx.py for the TSBK count to pause during active voice reception. Otherwise the count should increase.

I see messages about tuning errors.

The tuning error in the messages you posted are a printout of the internal state variables of the error tracking loop. From what you posted it looks like the error is well under control.

It might be good to have you increase the log level via "-v" to, say 11, and reproduce the problem - then send me a copy of the stderr log.

Max

 

[n5pwp]

At exactly what point in time do the TSBKs stop counting? It's normal in rx.py for the TSBK count to pause during active voice reception. Otherwise the count should increase.

I didn't watch the display during the time that this was going on. I was listening to a stakeout on the TG and it sounded interesting so I did the Hold. After a while I noticed there was no more activity and I looked over at the display and noticed the TSBKs had stopped counting. I just tried it again on another TG and the TSBKs keep counting without activity on the TG. I'm not sure when they stopped counting. I'm watching it now and it has been on Hold for 6 minutes and it is still counting.

It might be good to have you increase the log level via "-v" to, say 11, and reproduce the problem - then send me a copy of the stderr log.

I will send you a stderr with -v at 11. I currently have one captured from the original incident with the log level at 3. If that would provide any info I can send that to you. Otherwise I'll watch to see when the TSBKs stop counting and then get that one to you.
Thanks, Max
Mike

 

[n5pwp]

Max, here's the stderr.2 file you asked for. I tried earlier today to get one but the lockup didn't occur even after 2 hrs on Hold. I tried again and it locked up with 15 minutes. I looked down through the file and did see tuning error of +1200. I don't know what causes it to get thrown off that much when it runs 24 x 7 and I don't have the problem. It appears to only happen after I've held a TG. Anyway, I hope you can find something. That is, something other than the tuning error. ;-)
Oops, I just checked the log file and it is over 64MB. I'll provide you with a link so you can pull it without plugging up the RR forum.

Long Hold stderr file

Mike

 

[KA1RBI]

ok thanks Mike. I have the log file. It is very interesting - the tuning errors do seem to suggest a trouble.

For some reason the phase error detector stops tracking frequency adjustments, almost as if the adjustments stop getting applied in the first place. I'll have to try to correlate this with the hold function. The tracking failure has also occurred in other times and places and some mitigations have been applied - it may be that multi_rx.py (in p25 trunking mode) might be more robust in this situation but that would have to be tested.

Due to the large number of variables in play it would be helpful if you could paste a copy of your rx.py startup command line and of your trunking TSV (-T) file. Probably no need to paste the whitelist / blacklist and/or tgmap or unit map files.

Another thing noticed in the log file

decode_mbt_data(): received unsupported mbt opcode 31

The opcode 31 (AUTH DEMAND) is now supported in OP25 which suggests you're running an older OP25 build. Depending on how old it may be worth upgrading to the latest version...

Max

 

[n5pwp]

Due to the large number of variables in play it would be helpful if you could paste a copy of your rx.py startup command line and of your trunking TSV (-T) file. Probably no need to paste the whitelist / blacklist and/or tgmap or unit map files.

Here ya go:
./rx.py --args 'rtl' -N 'LNA:46' -S 960000 -l http:0.0.0.0:1234 -T 1-14_trunk.tsv -q -2 -X -U -2 -w -v 11 --nocrypt 2> stderr.2

The opcode 31 (AUTH DEMAND) is now supported in OP25 which suggests you're running an older OP25 build. Depending on how old it may be worth upgrading to the latest version...

Hmm, not sure how to tell what version I've got. When I go to the About buttton it says "UI Updated: 29-Aug-2021. Is that an old one? I'll go ahead and do a git clone and see if it updates.
Thanks, Max
Mike

 

[KA1RBI]

So the C++ code has probably changed - a full rebuild (install.sh) should be done to be on the safe side...

 

[n5pwp]

Max, I renamed the old OP25 directory and did a git clone to what I assume is the latest release of OP25. I did the ./install.sh. Everything seemed to go well. After the install I checked the About window and it still says UI Updated 29-Aug-2021. How do I tell if I have the latest version installed?

 

[Outerdog]

Max, I renamed the old OP25 directory and did a git clone to what I assume is the latest release of OP25. I did the ./install.sh. Everything seemed to go well. After the install I checked the About window and it still says UI Updated 29-Aug-2021. How do I tell if I have the latest version installed?

The "UI Updated" date should show 09-Jan-2022.

Sounds like a browser cache is holding an old version of the javascript file main.js - that date is generated in ../../www-static/main.js.

The C++ is largely separate from the web UI.

You should also run make uninstall from the old version before installing the new. Navigate to ../op25/build and run sudo make uninstall

 

[n5pwp]

I just checked the stderr.2 logs and both the old install and the new one show the same info:
gr-osmosdr 0.1.4 (0.1.4) gnuradio 3.7.13.4
That would indicate to me that I have the latest version.
Mike
[edit] Oops, I posted before I realized you had updated. Sorry, I will follow your directions. So we can't keep and old version in case an update goes wrong and we can fall back?

 

[n5pwp]

Well, it appears that since I didn't do the sudo make uninstall from the beginning I must have something whacked. I have 'make uninstall'ed in both the old directory and the new OP25 directory and done a complete git clone and ./install.sh. I finally did a 'make uninstall' in both directories. Then I archived my old OP25 directory tree (in case I need to pull a file I neglected to backup). I then completely deleted the new OP25 directory tree and started all over. No matter what I do the About button and the header of stderror.2 stays the same as the original install. Something is not getting updated. I don't know what that is. I guess I could just wipe the SD card and reinstall the image and just install OP25 again without ever having the old install. Before I do that is there anything I can check before going nuclear?
Thanks.
Mike

 

[Outerdog]

Before I do that is there anything I can check before going nuclear?

Clear the cache of the browser you are using to view the web UI.

 

[n5pwp]

Thanks, Outerdog. Max DID say that above and I totally missed it. READ CAREFULLY.
That brought me up to UI Updated 09-Jan-2022. Since the stderr.2 file still has the same version numbers in it I guess that didn't change from last year to this?
Still living up to my Newbie rank.
Mike