PyGPSClient VMS usage rises over time #262
Replies: 22 comments
|
Hi @pat-2010 Thanks for this information. For extended logging (> 2 hours or so) I would strongly recommend using an unattended (e.g. CLI) tool like GNSSStreamer rather than an attended (GUI) tool like PyGPSClient (especially if you're running 'headless' anyway), but this certainly warrants investigation. May for example be a memory leak issue in an underlying tkinter package? Couple of quick questions:
|
|
Good morning. I had started looking at GNSStreamer for my final setup. For now I'm learning the system and having the information on the GUI helps. Especially since I can get all three receivers up on my main computer using VNC.
By the way I started a run at 9 last night. LC29DA on a Pi 4. This morning the console was refreshing every 30 seconds or longer. I also think that the log that looked like the sample below was an operator error. I likely turned on NMEA and those are the binary RTCM messages. |
|
Hi,
Absolutely - PyGPSClient can be a very useful learning tool, but for extended data logging there are probably better options - it's not as though you're going to be eyeballing the data for hours on end?
Thanks for that - I'll take a look. Be aware that some memory stat tools and techniques can themselves impose something of a performance and memory overhead.
Not necessarily an issue, but the u-blox default setting is normally 38400 and I'd recommend that as a bare minimum.
In the console, e.g. 
Thanks again for taking the time to conduct these tests - they are helpful. There are a number of known potential memory leak issues with tkinter in particular - I thought I'd caught the worst of them, but there may be some still lurking. |
|
That python attachment appears to have got garbled in the upload - could I trouble you to provide the script again as embedded text in the comment i.e. something like this: print("this is an example")Thanks |
|
Here is the python script. It was adapted from one of the examples at the psutil readthedocs site import psutil #https://psutil.readthedocs.io/stable/
import time
import datetime
#loop through processes to find the pid for PYGPSclient
for proc in psutil.process_iter(['pid', 'name', 'memory_info']):
try:
if proc.info['name']=="pygpsclient":
print(f"PID: {proc.info['pid']}, Name: {proc.info['name']}, Memory Usage: {proc.info['memory_info'].vms} bytes")
thispid=proc.info['pid']
except (psutil.NoSuchProcess, psutil.AccessDenied):
pass
print("Time, vms memory usage kB, delta memory usage kB, cpu percent") #header line
oldvms=0
process = psutil.Process(thispid)
while True:
memory_info = process.memory_info()
thisvms=int (memory_info.vms/1024) #convert to KB
if thisvms!=oldvms:
print("%27s %10d %8d %5.2f " % (datetime.datetime.now(),thisvms,thisvms-oldvms,process.cpu_percent(interval=None)))
oldvms=thisvms
time.sleep(1) |
|
I looked through the datalog for the case that has the dropout plot above. There were no GNTXT messages. I assume those would come through on the datalog since they are NMEA. Is that correct? I don't remember seeing any fly by in the console but I will keep an eye out. Well, I take that back. Found one: Might be a pilot error. just before the NMEA string was: So I may have been doing something that caused it. Later on in the datalog it looks like I turned on NMEA. I will do a more systematic check as soon as I figure out how to fix my Pi5 which is periodically shutting down. Sigh. I have looked through the logs for 6 cases and found no GNTXT messages. |
No you can ignore that one. Shortly after a connection is first started, PyGPSClient attempts to establish the receiver's hardware model and firmware version by sending out a series of poll messages using different manufacturers' protocols (u-blox UBX
Again, this is the UBX response to the |
|
The 'µb' is a UBX packet |
|
Seeing similar results, but interestingly only when the app is left unattended for an extended period. This was overnight on an RPi5 running stock Trixie with a ZED-X20P outputting standard NMEA cohort at 230400 baud. Will investigate further as and when time permits... 
|
|
I'll stop looking at memory usage and work on using the CLI tools. I want to run a 24 hour test to see the position variability. I'm in a town so multi path may be a problem. Thanks for recommending the CLI tools. I'm just spoiled from the ease of use and system performance visibility that I get from PyGPSClient. I did run two tests recently. Pi 400 running from a SD card and LC29N. 1 Hz sample rate. Datalog in binary. 115200 Baud. In one case I ran with the default window setup. In the second case I dropped the map and the two satellite related windows. The plot is below. I scaled it to match your plot. Your slope is much steeper (for what that is worth). 
Let me know if there is anything I can do to help to collect data about the other 2 problems (dropped messages and lags in refreshing windows or responding to mouse clicks). I haven't yet checked the two Pi 400 tests for data drop outs. I'll do that today. |
|
Looked at 2 runs where the only difference was one case with the default window set and a second case where the map window and the satellite window and the signals window were closed (lower load case). Found that in at least some (if not all) cases a block of dropped messages appears to be preceded by two copies of the same message. The analysis was to look through the log file for GNMRC or GNGAA messages. In the low load case I always found both messages with the same time tag as expected. With a run of 43937 seconds I found no cases where there were missing GNRMC or GNGGA messages. The default window test datalog showed dropped messages. With a run of 40949 seconds I only found 19233 time tags. It was not always both GNRMC and GNGGA. A plot of the time difference between successive time tags is: 
When I was looking through the raw log files to crosscheck I noticed that the gaps appear to be preceded by duplicate messages. In the excerpt below the second and third messages are duplicates. Both have time tags of 9:18:18, while the 4th message with a time tag of 9:18:23 is the first one after a 5 second data gap. $GNGGA,091818.000,3851.42464825,N,12116.91451424,W,1,08,43.53,41.686,M,-22.320,M,,4E I scanned a handful of data gaps and the duplicate message was in all of the ones I checked. I don't plan on checking the other 20000 or so gaps ;-). I did spot check at the beginning of the run when the dropout rate was low and at the end of the run when the rate was high. |
|
Well... not always duplicate messages. I had a case with ZED-F9P running on a pi 400. Baud rate was 115000 and I had up the default windows. Messages were being dropped. But with a scan of 10 or so I did NOT find any duplicate messages. Here's an example when the NMEA sentence from 14:35:04 was truncated and the stream restarted with the GNRMC at 14:35:37. $GNRMC,143504.00,V,,,,,,,160726,,,N,V1A There were no partial messages or checksum errors in the datalog. I also checked a case on the Pi 400 that was the same as above but the baud rate was 9600. I saw data dropouts at the end of NMEA sentences but no duplicate messages. For reference here is a full NMEA sentence for that test: $GNRMC,101851.00,A,3851.4266413,N,12116.7996908,W,1.087,,150726,,,A,V09 |
Well the pasted examples look wrong/inconsistent, and repeatedly missing the '*' delimiter for the NMEA checksum in many of them. Perhaps it's the mark-down formatting, as also seeing random lines in italics. Suggest pasting within triple '`' code blocks. Large blocks missing, conveniently at sentence boundaries is highly suggestive of parsing / syncing anomalies, where something that persists in messages causes issues. Ideally data can be piped directly to a log file, that can subsequently replayed through the parser as test cases. On UART side bit/byte level sync/framing can become an issue. I've seen this stress some MCU, or home-brew UART IP implementations. The data is very dense and continuous, perhaps more so than other implementations as uBlox DMA's data out of the UART, so there's next to no inter-symbol spacing, Each output epoch does provide an natural break in the data. Perhaps try enabling Two Stop Bits? A Start-Bit is a LOW, and a Stop-Bit is a HIGH, often used to resync the UART timing / bit-centering when oversampling at x8 or x16 |
|
Appreciate the input but I would hold off on further testing for now. There's clearly a reproducible issue here affecting long term stability in unattended PyGPSClient instances which manifests itself in various ways. I suspect this may be a tkinter implementation issue on my part, but it may be a week or so before I can spare any serious time on investigation and remediation - I have a few potential strategies in mind. So please bear with me until then. Again, appreciate the information you've provided to date. In the meantime, I did conduct an extended test of the CLI gnssstreamer tool (on a 'headless' RPi5 8MB running stock Trixie desktop) and can confirm that this is rock solid for extended data logging. PyGPSClient and gnssstreamer share the same I/O and parsing 'engine', so I'm reasonably confident this is not a UART or parsing issue per se (though, as @cturvey mentions above, such issues can arise in other circumstances) (I've routinely run >24 hour RAW UBX logs for PPK purposes on an RPi using gnssstreamer without issue, but I thought I'd double check anyway). I acquired a log of the standard NMEA output from a ZED-X20P over a roughly 14 hour period using the following command - 1,954,941 NMEA messages were captured in total: gnssstreamer -P /dev/ttyACM0 --baudrate 115200 --timeout 3 --format 2 --clioutput 1 --output x20p_datalog.bin --verbosity 2The ZED-X20P was in factory configuration other than the UART1 and UART2 baudrates, which I increased to 115200. I checked the reported VMS memory footprint over time (as per your script) and the continuity of the logged GNRMC messages. VMS was static at 115,536 kB for the entire duration of the test: The interval between successive GMRMC.time values was exactly 1 second for all 52,000 GNRMC messages captured - no dropouts whatsoever. 
|
|
Sorry about the poor paste. I'm new to this and just learning markdown. I pasted in below the set of messages from the case that had duplicate messages. The checksum delimiter is back. What besides that and the italics was wrong/inconsistent with the messages? Buried in the data above was the note that for the same GPS receiver settings I could cause the dropouts by enabling windows in PyGPSSreamer and eliminate the dropouts by reducing the number of windows. I also still saw dropouts on the ZED-F9P when it was running at 9600 baud. My setup is a Waveshare LC29HDA or a u-blox ZED-F9P connected to a raspberry pi or Windows laptop for both power and data through the USB cord. I have seen missing messages on both LC29HDA and the ZED-FP9 so it doesn't look like it is only a uBlox DMA issue. I'm running vanilla PyGPSClient without any modifications. Enabling 2 stop bits? Frankly I wouldn't have an idea on how to do that. And my goal is to put together off the shelf hardware and software without needing to understand that level of detail. My next step is to learn GNSSStreamer cli to get the data directly from the serial port and dump it to a file. |
|
Thanks for including the gnssstreamer command to dump to a file. That saved me from some time on the web trying to figure out what commands I need. From here on I'm happy to rely on the cli tools for longer term data collection and will use PyGPSClient as is for short term tasks where the visibility is useful, like checking out new setups. I'll avoid any more testing, but I'm a retired aerospace engineer with too much time on my hands so I can't guarantee that I will stop. |
|
Repetitive output from a uBlox receiver would by highly atypical, beyond NMEA Talker duplication, time would continue advancing internally and the solution would flag as invalid. Some receiver firmwares stall time, and repeat, but uBlox is not one of those. |
In my professional consultancy guise I've long cited aeronautics as the exemplar for proper engineering test practice so - please - knock yourself out :-) |
|
I believe I have a resolution for the extended data logging / dropped message issues in RC 1.7.1. I've run a series of overnight tests on MacOS, Windows and various flavours of Linux and I'm not seeing any data loss or latency. I need to do more testing but, all being well, this should mean that PyGPSClient can be relied on for data logging over extended periods (though I would still recommend using the CLI tools for logs of more than a few hours). The UI still becomes a little sluggish when left unattended for hours, but it remains responsive. The most serious 'memory leak' issue has also been resolved, though there still seems to be some residual VMS creep on RPi Linux - I'm not sure if this is simply an artefact of the platform or psutils implementation. The app itself appears to work fine. It's still a work in progress but if you're interested in testing the provisional release candidate branch, be my guest. Instructions on how to install it are given below. I've also added an 'easter egg' diagnostic feature which can be enabled by setting environment variable PYGPSCLIENT_PSSTATS as follows: If 1 or 3 - the current VMS stats will appear in the banner panel: 
If 2 or 3 and The following instructions install PyGPSClient v1.7.1 into a virtual environment named 'pygpsclient_1.7.1': python3 -m venv pygpsclient_1.7.1
source pygpsclient_1.7.1/bin/activate
python3 -m pip install --upgrade psutil
python3 -m pip install --force-reinstall git+https://github.com/semuconsulting/pygpsclient.git@RC-1.7.1
python3 -m pip install --force-reinstall git+https://github.com/semuconsulting/pygnssutils.git@RC-1.2.6
export PYGPSCLIENT_PSSTATS=3
python3 -m pygpsclient --verbosity 2 |
|
I'm trying out the new version. I did confirm that I'm running 1.7.1 by checking the version number under "About". FYI, I'm not seeing the memory usage banner. I used the instructions for installing v1.7.1 above. No problem on my side, I can run the python script here if I want to. I've noticed that some of the times PyGPSClient seems not to respond are because the mouse clicks are registering in the window behind PyGPSClient. If I select that other window then go back to PyGPSClient the mouse works as expected. So this is using VNC on a Mac to remotely access the Pi. Oh so many places that could cause what I am seeing. That was just FYI. If I can make it reproduce (without VNC involved) I'll pass on the details. Or maybe my system is cursed. |
You need to set the environment variable PYGPSCLIENT_PSSTATS=1 to see the VMS stats... export PYGPSCLIENT_PSSTATS=1
This is a VNC thing. VNC will only register clicks against 'non-transient' windows - it's a bit complicated but, in broad terms, if you have multiple windows open, some of which overlay others, VNC will only respond to the 'top level' window in the display hierarchy (which isn't necessarily the windows which appears to be on top). Bear in mind a remote VNC session will be sluggish at the best of times - it's not an ideal testing platform when looking at GUI performance. One alternative option you could try is spinning up a virtual Linux machine on your standard laptop using, say, VirtualBox. There is a reference to this in the README here. FYI this provisional release candidate version will probably be subject to additional updates before finalisation, so check for further commits since you last installed it. |
|
I've moved this to the Discussion for now, but will continue to monitor the issues raised. I'm confident changes in PyGPSClient v1.7.2 resolve the practical long term data logging and message drop issues - I've done a series of extended tests (> 12 hours) on various platforms including RPi and I'm not seeing any data loss in the logs. The most egregious 'memory leak' issue has also been resolved, as confirmed by tracemalloc monitoring results. This related to a message queue used by the socket server function which was being filled up even when the socket server was inactive. However, there does appear to be a residual issue which causes reported VMS to grow and the UI to become progressively more sluggish when left unattended for several hours. I'm finding that the UI remains responsive and the sluggishness goes away within a few seconds of new user interaction (e.g. resizing the window or opening / closing a dialog box). I'll continue to investigate this, and I'd welcome any further testing you may care to conduct yourself. |
Uh oh!
There was an error while loading. Please reload this page.
In the process of chasing down dropped NMEA messages I noticed that the PyGPSClient VMS memory usage grows. A few times it will take a step down, but the trend is upward. I wrote a python script to check the process ID for PyGPSClient every second and report any changes in VMS usage. Here is a sample:
Time, vms memory usage kB, delta memory usage kB
22:36:57 88232 88232 Initial startup
22:37:14 88368 136
22:37:29 88968 600
22:37:37 89100 132
22:37:49 162908 73808 Started rover
22:37:50 163316 408
22:37:52 163456 140
22:37:57 163596 140.
22:38:02 163732 136
22:38:08 163876 144
22:38:13 164008 132
22:38:19 164148 140
22:38:24 164280 132
22:38:30 164424 144
22:38:36 164568 144
22:38:41 164704 136
22:38:45 164840 136
22:38:47 165152 312
22:38:48 165308 156
22:40:04 165444 136
22:40:09 165576 132
22:40:15 165716 140
22:40:20 165848 132
22:40:26 165984 136
22:40:32 166132 148
22:40:38 166272 140
22:40:43 166416 144
22:40:49 166552 136
22:40:54 166684 132
22:40:59 166824 140
22:41:05 166960 136
22:41:11 167100 140
22:41:16 167232 132
22:41:22 167376 144
22:41:26 168400 1024
22:41:27 168536 136
22:41:33 168676 140
22:41:39 168820 144
22:41:44 168956 136
... to the next morning
10:56:52 313276 148
11:00:05 313412 136
11:03:28 313552 140
11:07:40 314576 1024
11:15:56 315600 1024
11:24:52 316624 1024
Here's a plot for the entire run:
I've had similar but not identical results using a Pi400, Pi4 and a Pi5 with a u-blox ZED-F9P and with Quectel LC29HDA and LC29HBS.
For the Pi400 and Pi4 I ran tests where I tried to eliminate other possible interference sources. I used a fresh install of the OS Trixie on the SD card followed by an install of PyGPSClient using the instructions at https://github.com/semuconsulting/pyubx2. I started PyGPSClient, then started the python script that tracked VM usage. I closed the map and satellite views and turned on the datalog using binary. After setting the data rate (9600 for ZED-F9P and 115200 for LC29) I connected to the GPS receiver. No other defaults were changed. The downlink rate was 1 Hz. I've checked and the CPU does not seem to be loaded at all (although I wouldn't likely see short bursts). Most of the time I run headless, but for the Pi400 case with fresh install I did not use VNC.
The memory usage was one consistent characteristic I could easily record. I've also seen:
Dropped NMEA messages that get worse over time. I had a run that lasted 46288 seconds. I scanned for time tags in GNRMC or GNGGA (either one or both) and found 19852 time tags. A plot showing the time between time tags for one case is:
In another case I had the scatter plots set with a 100 point average. In a 12 hour run I'd expect over 400 points, but only 33 were recorded. But in looking at log files I have never seen a message dropout rate that high so I think something else is going on.
Slow display updates (console display would update every 2 seconds or longer) and slow response to the mouse. I closed the map view and the console refresh rate went to normal. Reopened the map view and the console refresh rate stayed normal. Another time undocking the settings also made the console refresh rate go to normal. Looking at a run going now, the console is refreshing every 7 seconds. I opened the server config window. When I click on the close icon nothing happens until just before the console display refreshes.
Very infrequent warnings "Error parsing data stream Serial stream terminated unexpectedly. Line requested, xx bytes returned". Sometimes the error is on the checksum. I "think" this happens mostly or possibly only when the baud rate is 115200.
Also very infrequently the log looks like:
$GBGSV,2,1,07,13,59,159,22,27,39,311,19,28,79,249,09,33,75,031,19,17F
$GBGSV,2,2,07,38,33,151,21,41,50,236,13,42,19,047,23,145
$GQGSV,1,1,00,064
$GNGST,192253.00,57,27,13,98,5.3,11,1541
µb
1$��+))+)'()(+))-,+++,----3/12U5G95;225C85848?9@DABCGEHJLNRRXZ_fjnsx}ÅÇÑÑäñíçççåäãããåàâââàâÜáåÖÜÜÖÑÑÑÑÜàçëííäåååçåççéåçéããççèúîëèèèëèééèéçãäââäâàâàààäâââáâââçñåàáàáàäâääââäãåããäââàáÖÖÅ�~ywvtpmic
]WVÄOD@=;<:897865344431622/303----,1.+,+*+++*)*)***(()()()( °� °�Ç≥a^-+,,/,.-.-00/0114436899>;;<?>ADGFEFHMKLNQOQRSTYWY\[]dlltjklqvÖ�yx{~~ÉâÖÖÑÖÜâåççñåääåíèéåçéèî§úîíëíîìòòîîîññòúõõõõúõû†õõòóòòùúîìííëìïìììììïïôóîóïñïóôóîîîììôóíëìêéèåçãäâáÜÖÜÇÄ}z|{~ê®é}vusuxqoijfdcb_[ZXVUVSNLIFFEDBA>===;;7764533132//0.//--.,.9,,-++,,,+,+),** °� °�j⁄ÙH'%ä$GNRMC,192254.00,A,3851.4242490,N,12116.8037205,W,0.227,,130726,,,A,V05$GNGGA,192254.00,3851.4242490,N,12116.8037205,W,1,08,1.40,72.129,M,-26.730,M,,4A
$GNGSA,A,3,10,24,27,18,23,,,,,,,,3.01,1.40,2.66,10E
$GNGSA,A,3,81,,,,,,,,,,,,3.01,1.40,2.66,20E
$GNGSA,A,3,,,,,,,,,,,,,3.01,1.40,2.66,306
$
Desktop (please complete the following information):
Raspberry Pi Trixie OS, Bookworm on some of the earlier runs.
Raspberry Pi 400, Pi 4 and Pi 5. The Pi 400 and Pi 4 were running from SD card. The Pi5 has a NVMe installed in a hat.
Python 3.13.5
USB connection
u-blox ZED-F9P, Quectel LC29HDAN and LC29HBS
I don't have the firmware versions or protocols but I will work on getting them if it would help.
The challenge is that the problem is not consistent. Some times there are no (or very few) messages dropped. I'm working on compiling a set of tests that systematically tests:
1-GPS receiver (probably won't use the base station)
2-receiver baud rate
3-computer
4-PyGPSClient setup (minimal vs maximum windows open, no log, binary log, parsed log)
5- headless vs hard wired display.
I'm happy to run any test cases if that would help. The challenge is that it takes several hours for some of the characteristics to show up. I can log the memory usage and use the data log to detect dropped messages. But I haven't been able to figure out how to detect the refresh slowdown without looking at it. Or even if it is a useful symptom to measure.
I added just about everything that I saw. I hope that some of it will be useful. I expect that some of the symptoms are red herrings, I just don't know which.
All reactions