meshtastic
[Bug]: GPS Buffer full
Category
Hardware Compatibility, Other
Hardware
Seeed Card Tracker T1000-E
Firmware Version
2.5.18
Description
WARN | 10:26:13 342 [GPS] GPS Buffer full with 1023 bytes waiting. Flush to avoid corruption
Relevant log output
WARN | 10:26:13 342 [GPS] GPS Buffer full with 1023 bytes waiting. Flush to avoid corruption
DEBUG | 10:29:59 568 [Router] Module 'routing' considered
INFO | 10:29:59 568 [GPS] GPS power state move from IDLE to ACTIVE
WARN | 10:29:59 568 [Position] Ch. util >25%. Skip send
DEBUG | 10:29:59 568 [RadioIf] Lora RX (id=0x49311782 fr=0xda63587c to=0xffffffff, WantAck=0, HopLim=3 Ch=0x1e encrypted len=49 rxSNR=10 rxRSSI=-34 via MQTT hopStart=7)
DEBUG | 10:29:59 568 [RadioIf] Packet RX: 600ms
DEBUG | 10:29:59 568 [RadioIf] rx_snr found. hop_limit:5 rx_snr:9.750000
DEBUG | 10:29:59 568 [RadioIf] rx_snr found in packet. Setting tx delay:5467
DEBUG | 10:29:59 568 [Router] Add packet record (id=0x49311782 fr=0xda63587c to=0xffffffff, WantAck=0, HopLim=3 Ch=0x1e encrypted len=49 rxSNR=10 rxRSSI=-34 via MQTT hopStart=7)
DEBUG | 10:29:59 568 [Router] Use channel 1 (hash 0x1e)
DEBUG | 10:29:59 568 [Router] Use AES128 key!
DEBUG | 10:29:59 568 [Router] decoded message (id=0x49311782 fr=0xda63587c to=0xffffffff, WantAck=0, HopLim=3 Ch=0x1 Portnum=3 rxtime=1736155799 rxSNR=10 rxRSSI=-34 via MQTT hopStart=7)
DEBUG | 10:29:59 568 [Router] handleReceived(REMOTE) (id=0x49311782 fr=0xda63587c to=0xffffffff, WantAck=0, HopLim=3 Ch=0x1 Portnum=3 rxtime=1736155799 rxSNR=10 rxRSSI=-34 via MQTT hopStar
DEBUG | 10:29:59 568 [Router] Module 'position' wantsPacket=1
INFO | 10:29:59 568 [Router] Received position from=0xda63587c, id=0x49311782, portnum=3, payloadlen=27
DEBUG | 10:29:59 568 [Router] POSITION node=da63587c l=27 lat=482770944 lon=115572736 msl=0 hae=0 geo=0 pdop=0 hdop=0 vdop=0 siv=0 fxq=0 fxt=0 pts=0 time=1736155782
INFO | 10:30:00 568 [Router] updatePosition REMOTE node=0xda63587c time=1736155782 lat=482770944 lon=115572736
DEBUG | 10:30:00 568 [Router] Node status update: 49 online, 76 total
DEBUG | 10:30:00 568 [Router] Module 'position' considered
DEBUG | 10:30:00 568 [Router] Module 'routing' wantsPacket=1
INFO | 10:30:00 568 [Router] Received routing from=0xda63587c, id=0x49311782, portnum=3, payloadlen=27
DEBUG | 10:30:00 568 [Router] Routing sniffing (id=0x49311782 fr=0xda63587c to=0xffffffff, WantAck=0, HopLim=3 Ch=0x1 Portnum=3 rxtime=1736155799 rxSNR=10 rxRSSI=-34 via MQTT hopStart=7)
INFO | 10:30:00 569 [Router] Rebroadcast received floodmsg
DEBUG | 10:30:00 569 [Router] Use AES128 key!
DEBUG | 10:30:00 569 [Router] enqueue for send (id=0x49311782 fr=0xda63587c to=0xffffffff, WantAck=0, HopLim=2 Ch=0x1e encrypted len=49 rxtime=1736155799 rxSNR=10 rxRSSI=-34 via MQTT hopSt
DEBUG | 10:30:00 569 [Router] txGood=24,txRelay=20,rxGood=38,rxBad=0
DEBUG | 10:30:00 569 [Router] rx_snr found. hop_limit:5 rx_snr:9.750000
DEBUG | 10:30:00 569 [Router] rx_snr found in packet. Setting tx delay:1694
DEBUG | 10:30:00 569 [Router] Delivering rx packet (id=0x49311782 fr=0xda63587c to=0xffffffff, WantAck=0, HopLim=3 Ch=0x1 Portnum=3 rxtime=1736155799 rxSNR=10 rxRSSI=-34 via MQTT hopStart=
DEBUG | 10:30:00 569 [Router] Update DB node 0xda63587c, rx_time=1736155799
DEBUG | 10:30:00 569 [Router] Forwarding to phone (id=0x49311782 fr=0xda63587c to=0xffffffff, WantAck=0, HopLim=3 Ch=0x1 Portnum=3 rxtime=1736155799 rxSNR=10 rxRSSI=-34 via MQTT hopStart=7
DEBUG | 10:30:00 569 [Router] Module 'routing' considered
INFO | 10:30:00 569 Tell client we have new packets 42
INFO | 10:30:00 569 BLE notify fromNum
DEBUG | 10:30:00 569 FromRadio=STATE_SEND_PACKETS
DEBUG | 10:30:00 569 phone downloaded packet (id=0x49311782 fr=0xda63587c to=0xffffffff, WantAck=0, HopLim=3 Ch=0x1 Portnum=3 rxtime=1736155799 rxSNR=10 rxRSSI=-34 via MQTT hopSta
DEBUG | 10:30:16 585 [Power] Battery: usbPower=1, isCharging=1, batMv=4192, batPct=100
WARN | 10:30:16 585 [GPS] GPS Buffer full with 1023 bytes waiting. Flush to avoid corruption
INFO | 10:30:16 585 [EnvironmentTelemetry] Send: barometric_pressure=0.000000, current=0.000000, gas_resistance=0.000000, relative_humidity=0.000000, temperature=26.416958
INFO | 10:30:16 585 [EnvironmentTelemetry] Send: voltage=0.000000, IAQ=0, distance=0.000000, lux=0.000000
INFO | 10:30:16 585 [EnvironmentTelemetry] Send: wind speed=0.000000m/s, direction=0 degrees, weight=0.000000kg
INFO | 10:30:16 585 [EnvironmentTelemetry] Send: radiation=0.000000##R/h
DEBUG | 10:30:16 585 [EnvironmentTelemetry] Partially randomized packet id 2028851658
INFO | 10:30:16 585 [EnvironmentTelemetry] Send packet to phone
WARN | 10:30:16 585 [RadioIf] Can not send yet, busyRx
DEBUG | 10:30:16 585 [RadioIf] rx_snr found. hop_limit:5 rx_snr:9.750000
DEBUG | 10:30:16 585 [RadioIf] rx_snr found in packet. Setting tx delay:5159
INFO | 10:30:16 585 Tell client we have new packets 43
INFO | 10:30:16 585 BLE notify fromNum
Thanks @cracky22 . Do you have the ability to build your own firmware? If so logs from one with #define GPS_DEBUG 1 in variant.h . Otherwise let me know and I'll make one for you.
DEBUG | 09:57:18 50 Radio wait to sleep, txEmpty=0
DEBUG | 09:57:18 50 Radio wait to sleep, txEmpty=0
DEBUG | 09:57:18 50 Radio wait to sleep, txEmpty=0
DEBUG | 09:57:18 50 Radio wait to sleep, txEmpty=0
DEBUG | 09:57:18 50 Radio wait to sleep, txEmpty=0
DEBUG | 09:57:18 50 Radio wait to sleep, txEmpty=0
DEBUG | 09:57:19 50 Radio wait to sleep, txEmpty=0
DEBUG | 09:57:19 50 Radio wait to sleep, txEmpty=0
DEBUG | 09:57:19 51 Radio wait to sleep, txEmpty=0
DEBUG | 09:57:19 51 Radio wait to sleep, txEmpty=0
ERROR | 09:57:40 72 NOTE! Record critical error 2 at src/sleep.cpp:176
ERROR | 09:57:40 72 assert failed src/sleep.cpp: 177, vo
OK, interesting. I wonder if our GPS configuration is being lost while asleep. Then it starts back up with every NMEA sequence enabled. Something like #5088
wait i have some logs for you:
WARN | 10:35:20 2123 [GPS] GPS Buffer full with 1023 bytes waiting. Flush to avoid corruption
meshtastic-log-2025-01-11T09-57-08.007Z.log
Thanks for the logs @cracky22 .
So, the NMEA sequences are correct: GGA and RMC
Though, there are a few lines in there like the GPS just started up again (when it starts it announces its version info), like this:
DEBUG | 10:26:33 1597 [GPS] ..F1: 0000 0000..V0: 0000 0000 [0001]..00: 0000 0000..U0: 0000 0001 [0000]..T0: 0000 00B7..Leaving the BROM........8....~.....$PAIR001,002,1*38..$PAIR001,021,
DEBUG | 10:26:33 1597 [GPS] AGE: LOC=86851 FIX=0 DATE=86851 TIME=86851
DEBUG | 10:26:33 1597 [GPS] $PAIR011,001*27..$PAIR010,1,-1*16..$PAIR010,2,-1*15..$PAIR001,002,0*39..$PAIR001,021,0*38..$PAIR021,AG3335M_V2.6.0.AG3335_20221230,S,I,cfced9e,2212300120,,,,,
DEBUG | 10:26:34 1598 [GPS] $GNGGA,092634.784,,,,,0,0,,,M,,M,,*57..$GNRMC,092634.784,V,,,,,,,110125,,,N,V*2E..
DEBUG | 10:26:35 1598 [RadioIf] Started Tx (id=0x54894424 fr=0x1d698c30 to=0xffffffff, WantAck=0, HopLim=0 Ch=0x8 encrypted len=50 rxtime=1736586913 rxSNR=10.5 rxRSSI=-45 hopStart=3 priority
DEBUG | 10:26:35 1598 [RadioIf] Packet TX: 608ms
DEBUG | 10:26:35 1599 [GPS] $GNGGA,092635.784,,,,,0,0,,,M,,M,,*56..$GNRMC,092635.784,V,,,,,,,110125,,,N,V*2F..
DEBUG | 10:26:35 1599 [RadioIf] Completed sending (id=0x54894424 fr=0x1d698c30 to=0xffffffff, WantAck=0, HopLim=0 Ch=0x8 encrypted len=50 rxtime=1736586913 rxSNR=10.5 rxRSSI=-45 hopStart=3 p
DEBUG | 10:26:35 1599 [RadioIf] rx_snr found. hop_limit:6 rx_snr:11.000000
DEBUG | 10:26:35 1599 [RadioIf] rx_snr found in packet. Setting tx delay:1309
DEBUG | 10:26:36 1600 [GPS] $GNGGA,092636.752,,,,,0,0,,,M,,M,,*5E..$GNRMC,092636.752,V,,,,,,,110125,,,N,V*27..
DEBUG | 10:26:37 1600 [RadioIf] Started Tx (id=0xc12a0b5f fr=0xda547a28 to=0xffffffff, WantAck=0, HopLim=6 Ch=0x8 encrypted len=91 rxtime=1736586930 rxSNR=11 rxRSSI=-38 hopStart=7 priority=6
DEBUG | 10:26:37 1600 [RadioIf] Packet TX: 911ms
DEBUG | 10:26:37 1601 [GPS] $PAIR001,021,0*38..$PAIR021,AG3335M_V2.6.0.AG3335_20221230,S,I,cfced9e,2212300120,a2b7,0,,,735e4e5a,2212300107,e951622,2212300116,,,,,-15.48,-15.48,-14.02,-15
DEBUG | 10:26:37 1601 [RadioIf] Completed sending (id=0xc12a0b5f fr=0xda547a28 to=0xffffffff, WantAck=0, HopLim=6 Ch=0x8 encrypted len=91 rxtime=1736586930 rxSNR=11 rxRSSI=-38 hopStart=7 pri
DEBUG | 10:26:37 1601 [RadioIf] rx_snr found. hop_limit:5 rx_snr:8.750000
DEBUG | 10:26:37 1601 [RadioIf] rx_snr found in packet. Setting tx delay:5467
WARN | 10:26:38 1601 [Position] Ch. util >25%. Skip send
DEBUG | 10:26:38 1602 [GPS] $PAIR010,0,0,2348,552415*34..
DEBUG | 10:26:38 1602 [GPS] $GNGGA,092638.758,4810.1629,N,01149.1463,E,1,8,1.11,518.3,M,47.4,M,,*43..$GNRMC,092638.758,A,4810.1629,N,01149.1463,E,0.44,0.00,110125,,,A,V*0C..
INFO | 10:27:10 1634 [GPS] toRadioWriteCb data 0x20014b9a, len 2
OK,so I read the logs from 10:00 to 10:10 and it all looks good. Then out of the blue, we get our buffer error. There aren't too many messages going on, so it looks like the buffer is not getting cleared properly. We probably need to clear it before sleep or something like that.
Next step: reading the code.
Hi Tom, can you please build me something that will automatically restart my node every 12 hours? Something that I can put into the firmware myself.. thanks
_meshtastic-log-2025-01-16T18-06-53.495Z.log
WARN | 19:06:17 61 [GPS] GPS Buffer full with 1023 bytes waiting. Flush to avoid corruption
edit: i used the re-reupload of 2.5.19
It seems like the board now doesn't have lfs issues anymore but the GPS buffer problems are still existing...
Should I built the firmware in my own again with #define GPS_DEBUG 1 and submit you some logfiles? @fifieldt
Since firmware 2.7.3, my T1000-E has been restarting less frequently, and in the two instances where I had the logger active, there were no more buffer full messages.
I think I figured this out.
We set the buffer size to about a byte:
arch/esp32/esp32.ini: -DSERIAL_BUFFER_SIZE=4096
arch/esp32/esp32c6.ini: -DSERIAL_BUFFER_SIZE=4096
arch/nrf52/nrf52.ini: -DSERIAL_BUFFER_SIZE=1024
This was based on 9600 baud being about 1 byte per millisecond.
However, 115200 baud, like the T1000e uses is about 12 times that - almost 15 bytes per millisecond. 15 bytes * 200 millisecond = 3000 bytes, which is longer than our buffer on the nrf52 platform.
[fifieldt] is correct, I literally made just that change (buffer to 4K) and my T1000-e has been getting location indoor solid for hours. Used to crap out pretty quickly.
