Bug report: "SOME data is TOO OLD" is spamming the debug log before the GPS has locked on satellites

[runestone74]

It would be nicer to just have this message once, or at least only once per second.

Meshtastic-device/src/gps/NMEAGPS.cpp
Row 119: DEBUG_MSG("SOME data is TOO OLD\n");

Not sure about how to solve this though... :)

[mc-hamster]

Do you have a log where this comes up?

Thanks!

[runestone74]

done
??:??:?? 4 Updating eink... done
??:??:?? 11 Starting meshradio init...
??:??:?? 11 (bw=31, sf=9, cr=4/8) packet symLen=16 ms, payloadSize=16, time 1363 ms
??:??:?? 11 Set radio: name=LongFast, config=2, ch=5, power=0
??:??:?? 11 Radio myRegion->freq: 865.200012
??:??:?? 11 Radio myRegion->spacing: 0.300000
??:??:?? 11 Radio myRegion->numChannels: 10
??:??:?? 11 Radio channel_num: 5
??:??:?? 11 Radio frequency: 866.700012
??:??:?? 11 Short packet time: 1363 msec
??:??:?? 11 Set radio: final power level=22
??:??:?? 12 SX126x init result 0
??:??:?? 12 Current limit set to 140.000000
??:??:?? 12 Current limit set result 0
??:??:?? 12 SX1262 Radio init succeeded, using SX1262 radio
??:??:?? 12 (bw=31, sf=9, cr=4/8) packet symLen=16 ms, payloadSize=237, time 9637 ms
??:??:?? 12 myNodeInfo.bitrate = 24.592716 bytes / sec
??:??:?? 12 PowerFSM init, USB power=1
??:??:?? 12 Enter state: BOOT
??:??:?? 12 [Power] Battery: usbPower=1, isCharging=1, batMv=4766, batPct=100
??:??:?? 12 [Screen] Done with boot screen...
??:??:?? 12 [Screen] Screen: Started...
??:??:?? 12 [Screen] showing standard frames
??:??:?? 12 [Screen] Showing 0 plugin frames
??:??:?? 13 [Screen] Total frame count: 35
??:??:?? 13 [Screen] Added plugins. numframes: 0
??:??:?? 13 [Screen] Finished building frames. numframes: 2
??:??:?? 13 [Screen] Setting fast framerate
??:??:?? 13 [Screen] Setting idle framerate
??:??:?? 15 [Screen] Updating eink... done
??:??:?? 23 [GPS] publishing pos@0:2, hasVal=0, GPSlock=0
??:??:?? 23 [GPS] No GPS lock
??:??:?? 23 [GPS] onGPSChanged() pos@0:4, time=0, lat=0, bat=100
??:??:?? 23 [GPS] updatePosition LOCAL pos@0:5, time=0, latI=0, lonI=0
??:??:?? 23 [GPS] Node status update: 3 online, 3 total
??:??:?? 23 [GPS] showing standard frames
??:??:?? 23 [GPS] Showing 0 plugin frames
??:??:?? 23 [GPS] Total frame count: 35
??:??:?? 23 [GPS] Added plugins. numframes: 0
??:??:?? 23 [GPS] Finished building frames. numframes: 4
??:??:?? 23 [GPS] Setting fast framerate
??:??:?? 23 [PowerFSM] Enter state: POWER
??:??:?? 23 [PowerFSM] Initialise the Bluefruit nRF52 module
??:??:?? 23 [PowerFSM] Configuring the Device Information Service
??:??:?? 24 [PowerFSM] Configuring the Battery Service
??:??:?? 24 [PowerFSM] Configuring the Mesh bluetooth service
??:??:?? 24 [PowerFSM] Setting up the advertising payload(s)
??:??:?? 24 [PowerFSM] Advertising
??:??:?? 24 [Screen] Screen: Powered...
??:??:?? 24 [Screen] Setting idle framerate
??:??:?? 27 [Screen] Updating eink... done
??:??:?? 34 [Power] Battery: usbPower=1, isCharging=1, batMv=4768, batPct=100
??:??:?? 34 [NodeInfoPlugin] Sending our nodeinfo to mesh (wantReplies=1)
??:??:?? 35 [NodeInfoPlugin] sending owner !9bbfc773/Rune/Run
??:??:?? 35 [NodeInfoPlugin] Update DB node 0x9bbfc773, rx_time=0
??:??:?? 35 [NodeInfoPlugin] handleReceived(LOCAL) (id=0x5851f430 Fr0x73 To0xff, WantAck0, HopLim3 Ch0x0 Portnum=4 WANTRESP priority=10)
??:??:?? 35 [NodeInfoPlugin] No plugins interested in portnum=4, src=LOCAL
??:??:?? 35 [NodeInfoPlugin] Add packet record (id=0x5851f430 Fr0x73 To0xff, WantAck0, HopLim3 Ch0x0 Portnum=4 WANTRESP priority=10)
??:??:?? 35 [NodeInfoPlugin] Expanding short PSK #1
??:??:?? 35 [NodeInfoPlugin] Installing AES128 key!
??:??:?? 35 [NodeInfoPlugin] enqueuing for send (id=0x5851f430 Fr0x73 To0xff, WantAck0, HopLim3 Ch0xb6 encrypted priority=10)
??:??:?? 35 [NodeInfoPlugin] (bw=31, sf=9, cr=4/8) packet symLen=16 ms, payloadSize=54, time 2789 ms
??:??:?? 35 [NodeInfoPlugin] txGood=0,rxGood=0,rxBad=0
??:??:?? 35 [NodeInfoPlugin] AirTime - Packet transmitted : 2789ms
??:??:?? 36 [RadioIf] Starting low level send (id=0x5851f430 Fr0x73 To0xff, WantAck0, HopLim3 Ch0xb6 encrypted priority=10)
??:??:?? 39 [RadioIf] Completed sending (id=0x5851f430 Fr0x73 To0xff, WantAck0, HopLim3 Ch0xb6 encrypted priority=10)
??:??:?? 54 [Power] Battery: usbPower=1, isCharging=1, batMv=4757, batPct=100
??:??:?? 60 [PositionPlugin] Sending pos@0:6 to mesh (wantReplies=1)
??:??:?? 60 [PositionPlugin] Stripping time 0 from position send
??:??:?? 60 [PositionPlugin] Update DB node 0x9bbfc773, rx_time=0
??:??:?? 60 [PositionPlugin] handleReceived(LOCAL) (id=0x5851f431 Fr0x73 To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 WANTRESP priority=10)
??:??:?? 60 [PositionPlugin] No plugins interested in portnum=3, src=LOCAL
??:??:?? 60 [PositionPlugin] Add packet record (id=0x5851f431 Fr0x73 To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 WANTRESP priority=10)
??:??:?? 60 [PositionPlugin] Expanding short PSK #1
??:??:?? 60 [PositionPlugin] Installing AES128 key!
??:??:?? 60 [PositionPlugin] enqueuing for send (id=0x5851f431 Fr0x73 To0xff, WantAck0, HopLim3 Ch0xb6 encrypted priority=10)
??:??:?? 60 [PositionPlugin] (bw=31, sf=9, cr=4/8) packet symLen=16 ms, payloadSize=24, time 1675 ms
??:??:?? 60 [PositionPlugin] txGood=1,rxGood=0,rxBad=0
??:??:?? 60 [PositionPlugin] AirTime - Packet transmitted : 1675ms
??:??:?? 61 [RadioIf] Starting low level send (id=0x5851f431 Fr0x73 To0xff, WantAck0, HopLim3 Ch0xb6 encrypted priority=10)
??:??:?? 63 [RadioIf] Completed sending (id=0x5851f431 Fr0x73 To0xff, WantAck0, HopLim3 Ch0xb6 encrypted priority=10)
??:??:?? 75 [Power] Battery: usbPower=1, isCharging=1, batMv=4754, batPct=100
??:??:?? 80 [Button] Enter state: POWER
??:??:?? 80 [Screen] Screen: Unpowered...
??:??:?? 80 [Screen] Setting LastScreenTransition
??:??:?? 80 [Screen] Setting fast framerate
??:??:?? 80 [Screen] Screen: Powered...
??:??:?? 80 [Screen] Setting idle framerate
??:??:?? 83 [Screen] Updating eink... done
??:??:?? 95 [Power] Battery: usbPower=1, isCharging=1, batMv=4750, batPct=100
??:??:?? 98 [Button] Enter state: POWER
??:??:?? 98 [Screen] Screen: Unpowered...
??:??:?? 98 [Screen] Setting LastScreenTransition
??:??:?? 98 [Screen] Setting fast framerate
??:??:?? 98 [Screen] Screen: Powered...
??:??:?? 98 [Screen] Setting idle framerate
??:??:?? 101 [Screen] Updating eink... done
??:??:?? 115 [Power] Battery: usbPower=1, isCharging=1, batMv=4732, batPct=100
??:??:?? 116 [GPS] SOME data is TOO OLD
??:??:?? 116 [GPS] SOME data is TOO OLD
??:??:?? 116 [GPS] SOME data is TOO OLD
??:??:?? 116 [GPS] SOME data is TOO OLD
??:??:?? 116 [GPS] SOME data is TOO OLD
??:??:?? 116 [GPS] SOME data is TOO OLD
??:??:?? 116 [GPS] SOME data is TOO OLD
??:??:?? 117 [GPS] SOME data is TOO OLD
??:??:?? 117 [GPS] SOME data is TOO OLD
??:??:?? 117 [GPS] SOME data is TOO OLD
??:??:?? 117 [GPS] SOME data is TOO OLD
??:??:?? 117 [GPS] SOME data is TOO OLD

[mc-hamster]

This looks like a TEcho?

[thebentern]

I've seen this in the logs of my rak4631_19003 with the RAK-12500 GNSS module as well.

[ernax78]

This is because the T-ECHO GPS does not send Date too often.

The timeout of all data is 300ms for position, date and time

T-ECHO sends Date every X seconds, which means position and time are sent, but date is "too old" triggering this.

I wrote some rant about this on discord some week ago when I had done some testing.

A possible work around would be to increase the allowed age of the date-data to 5000ms or even more, depending on what testing will show.

[ernax78]

ernax78 — 01/22/2022
I have found some kind of snafu here with the GPS on T-Echo
7:44:23 1017 [GPS] AGE: LOC=3275 FIX=0 DATE=4780 TIME=3275
LOC and TIME is sent by the message GPS_SENTENCE_GPGGA and GPS_SENTENCE_GPRMC
but DATE is only sent (together with time and loc) in GPS_SENTENCE_GPRMC
The maximum allowed age for DATE, TIME and LOC is 300ms.
These rarely match up so all three are less than 300
increasing allowed age for DATE to 5000ms makes the device much less unhappy.
ref: TinyGPS++.cpp line 227 and further
Still does not explain why we are fed crap
ernax78 — 01/22/2022
Basically it only accepts a GPS_SENTENCE_GPRMC as position/date/time and then - only if it's newer than 300ms
or it is rejected
08:05:26 2280 [GPS] AGE: LOC=13020 FIX=0 DATE=16604 TIME=13020
08:05:26 2280 [GPS] date data is TOO OLD
08:05:27 2280 [GPS] AGE: LOC=248 FIX=0 DATE=16851 TIME=249
08:05:27 2280 [GPS] WANT GPS=0
08:05:27 2280 [GPS] publishing pos@61ebbac7:2, hasVal=1, GPSlock=1
08:05:27 2280 [GPS] GPSStatus.match() new pos@61ebbac7 to old pos@61ebb932

[runestone74]

Seems like 5000 ms is used in the T-Echo sample code https://github.com/Xinyuan-LilyGO/LilyGO-T-Echo/blob/main/examples/GPS/GPS.ino

[caveman99]

I increased the time to 5000msec and added a bit more verbose logging in case that still happens. I have a feature branch on my TinyGPS Fork that updates date and time regardless of lock status (it's always populated if valid, SoftRF does the same thing in their lib) and merge that back in as soon as the underlying problems with jumping coordinates are identified and fixed.