bugGPSD - Bugs: bug #39888, Bad checksum messages cause gpsd...

 
 

bug #39888: Bad checksum messages cause gpsd to drop TCP/UDP devices

Submitted by:  Tom Nightingale <tnightingale>
Submitted on:  Thu 29 Aug 2013 07:32:02 AM UTC  
 
Category: NoneSeverity: 3 - Normal
Item Group: NoneStatus: Invalid
Privacy: PublicAssigned to: None
Open/Closed: Closed

Add a New Comment(Rich Markup)
   

You are not logged in

Please log in, so followups can be emailed to you.

 

Fri 30 Aug 2013 05:34:05 PM UTC, comment #2:

Here is my method for reconnecting the client after gpsd detects a message with a bad checksum and resets the device:

In my case I only have one device (tcp://data.aishub.net) and one client (python). From what I can tell, the only way a python client can detect its device has been reset is when it receives a 'DEVICE' message from gpsd containing details about the device it was supposed to be listening to.

So in the simplest case where you only have one device to listen to, it can be assumed when a 'DEVICE' message is received that no more messages are going to come in until a 'WATCH' is sent back to gpsd. Browsing the python client lib source shows that 'WATCH' messages are sent when a call is made to gps.stream().

Here's an updated version of the python example in http://gpsd.berlios.de/client-howto.html that handles this case:

session = gps(mode=WATCH_ENABLE)
try:
while True:
report = session.next()

# Check report class for 'DEVICE' messages from gpsd.
# If we're expecting messages from multiple devices we should inspect the message to determine which device
# has just become available.
# However in this simple case we only listen to our feed from AISHub so we can assume that gpsd has reset the device.
if report['class'] == 'DEVICE':
# Clean up our current connection.
session.close()
# Tell gpsd we're ready to receive messages.
session = gps(mode=WATCH_ENABLE)

else:
# Do regular stuff here.

except StopIteration:
print "GPSD has terminated"

That's the gist of how I have worked around this issue anyway.

I don't think you can easily implement the above with the simpler iterator-based example as you would need to wrap the for-loop in another loop to handle the new session object.

Tom Nightingale <tnightingale>
Fri 30 Aug 2013 05:22:16 AM UTC, comment #1:

Just following up on this:

I hadn't noticed the 'DEVICE' message which gets sent to my client after gpsd detects one of the bad messages and drops the client socket.

By detecting this message and reconnecting to gpsd, my application is now 'ignoring' the bad messages which is what I had been trying to achieve.

Now that I have had this 'ah-ha!' moment I see that this issue is not a bug in gpsd but just something easily overlooked when reading the client documentation here: http://gpsd.berlios.de/client-howto.html (specifically the python examples).

I hope this feedback is useful to someone but feel free to close the ticket as a non-issue (I don't think I have the account permission to do so myself).

In other words: sorry for the noise, thanks for the software! :-)

Tom Nightingale <tnightingale>
Thu 29 Aug 2013 07:32:02 AM UTC, original submission:

When processing a TCP feed from AISHub (eg: gpsd tcp://data.aishub.4143) occasionally gpsd encounters a message that has a bad checksum. When run with '-D6', the output looks like:

> gpsd -D6 tcp://data.aishub:4143

gpsd:SPIN: packet_get() fd 5 -> 37 (0)
gpsd:WARN: bad checksum in NMEA packet; expected 63.
gpsd:PROG: no /etc/gpsd/device-hook present, skipped running DEACTIVATE hook
gpsd:INFO: hunt on tcp://data.aishub.net:4143 failed (0.000746 sec since data)
gpsd:WARN: device read of tcp://data.aishub.net:4143 returned error or packet sniffer failed sync (flags {ERROR})
gpsd:IO: => client(0): {"class":"DEVICE","path":"tcp://data.aishub.net:4143","activated":0}\x0d\x0a
gpsd:INFO: closing GPS=tcp://data.aishub.net:4143 (5)
gpsd:SPIN: close(5) in gpsd_close(tcp://data.aishub.net:4143)
gpsd:PROG: no /etc/gpsd/device-hook present, skipped running DEACTIVATE hook
gpsd:SPIN: select() {3 4 6} -> { 6 } at 1377656595.767019 (errno 0)
gpsd:SPIN: packet_get() fd 6 -> 26 (0)
gpsd:SPIN: select() {3 4 6} -> { 6 } at 1377656595.767238 (errno 0)
gpsd:SPIN: packet_get() fd 6 -> 0 (0)
gpsd:DATA: tcp://data.aishub.net:4143 returned zero bytes
gpsd:DATA: tcp://data.aishub.net:4143 will be repolled in 0.010000 seconds

(here's a longer version of the above log output: https://gist.github.com/tnightingale/b6461ef7e1205eefe3cb)

At which point the tcp 'device' is dropped and no more messages are read or parsed.

I logged the stream of NMEA messages coming from AISHub and ran them through gpsfake until I encountered the error. Here's a trimmed version of the log:

!AIVDM,1,1,,2,839ec40j2d=><>=Md1b@e?bh7<P0,0*64
!AIVDM,1,1,,B,B6:fN?@0@220cJ3:tS5?LwS61P06,0*
48

(longer version: https://gist.github.com/tnightingale/6375039)

The first message parses fine, the second causes the 'bad checksum' error. It looks like there's an unintentional linebreak/whitespace character in the message.

Interestingly, while the default execution of gpsfake (with a pty device) reports the bad checksum error, the device isn't dropped. Gpsd continues to read and parse messages. However if you run gpsfake with the '-u' option (forcing UDP instead of pty) and '-D6' you see the following:

> gpsfake -u -D6 snippet.ais

gpsd:SPIN: select() {3 4 5 6 7} -> { 7 } at 1377758984.266909 (errno 0)
gpsd:SPIN: packet_get() fd 7 -> 46 (0)
gpsd:WARN: bad checksum in NMEA packet; expected 48.
gpsd:PROG: no /etc/gpsd/device-hook present, skipped running DEACTIVATE hook
gpsd:INFO: hunt on udp://127.0.0.1:5000 failed (0.001238 sec since data)
gpsd:WARN: device read of udp://127.0.0.1:5000 returned error or packet sniffer failed sync (flags {ERROR})
gpsd:IO: => client(0): {"class":"DEVICE","path":"udp://127.0.0.1:5000","activated":0}\x0d\x0a
gpsd:INFO: closing GPS=udp://127.0.0.1:5000 (7)
gpsd:SPIN: close(7) in gpsd_close(udp://127.0.0.1:5000)
gpsd:PROG: no /etc/gpsd/device-hook present, skipped running DEACTIVATE hook

The UDP 'device' and any listening clients are dropped and no more messages are read/parsed.

I have tested this with gpsd revision 3.9 compiled on debian wheezy and Mac OSX 10.8.4.

Tom Nightingale <tnightingale>

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach File(s):
   
   
Comment:
   

Attached Files
file #28954:  badchecksum.2.ais added by tnightingale (78B - application/octet-stream - Here's another message that gpsd reports to have a bad checksum.)
file #28950:  snippet.ais added by tnightingale (5KiB - application/octet-stream - snippet.ais contains about 100 messages, the failing one is near the end. The failing message also included individually in badchecksum.ais)
file #28951:  badchecksum.ais added by tnightingale (51B - application/octet-stream - snippet.ais contains about 100 messages, the failing one is near the end. The failing message also included individually in badchecksum.ais)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -unavailable- added by esr (Updated the item)
  • -unavailable- added by tnightingale (Submitted the item)
  • -unavailable- added by tnightingale
  •  

    Do you think this task is very important?
    If so, you can click here to add your encouragement to it.
    This task has 0 encouragements so far.

    Only logged-in users can vote.

     

    Please enter the title of George Orwell's famous dystopian book (it's a date):

     

     

    Follow 6 latest changes.

    Date Changed By Updated Field Previous Value => Replaced By
    Fri 22 Nov 2013 01:45:13 PM UTCesrOpen/ClosedOpen=>Closed
    Fri 30 Aug 2013 10:57:32 AM UTCesrStatusNone=>Invalid
    Thu 29 Aug 2013 07:19:13 PM UTCtnightingaleAttached File-=>Added badchecksum.2.ais, #28954
    Thu 29 Aug 2013 07:32:02 AM UTCtnightingaleAttached File-=>Added snippet.ais, #28950
      Attached File-=>Added badchecksum.ais, #28951
      Carbon-Copy-=>Added -unavailable-

    Back to the top


    Powered by Savane 3.1-cleanup1