Re: [gpsd-users] Communication loss with GR-701W

[Benoît Thébaudeau]

Hi Gary,

Le 20/05/2019 à 23:06, Gary E. Miller a écrit :
> On Mon, 20 May 2019 22:43:20 +0200 (CEST)
> Benoît Thébaudeau <address@hidden> wrote:
> 
>>>> Is it safe?  
>>>
>>> Yes. The default config is in ROM, by design it is the safest thing
>>> to do.  
>>
>> I'll try this out then. I can dump the configuration beforehand just
>> in case, anyway.
> 
> Good luck with that.  Non-trivial.

A factory reset of the configuration did not help with this issue. It happened 
again after having plugged the module only twice following the configuration 
revert, and without gpsd having saved any configuration changes to NVRAM.

BTW, I've discovered u-center (https://www.u-blox.com/en/product/u-center), 
which is a great tool too.

>> FYI, once the module has passed the critical point where it sometimes
>> fails, everything seems to keep going forever. It worked fine during
>> the whole weekend. Of course, after the first steps, everything gets
>> much more quiet, so issues are less likely to occur too.
> 
> Yup, sounds like the gpsd reconfig of the GPS is failing.  After that
> gpsd does not send to the GPS.
> 
> So, try the ubxtool to reconfigure, again, after gpsd starts.
> 
> # ubxtool -e BINARY [hostname]

That worked, which confirms that the corresponding packets sent by gpsd were 
not received or interpreted by the module.

I noticed the FIXME about waiting for the ACKs in ubx_cfg_prt(), so I tried the 
following patch as a workaround, and so far it works:
8><--------------------------------
diff -Nrdupa a/driver_ubx.c b/driver_ubx.c
--- a/driver_ubx.c      2018-10-18 22:59:30.000000000 +0200
+++ b/driver_ubx.c      2019-05-21 17:22:06.110945601 +0200
@@ -1279,7 +1279,9 @@ bool ubx_write(struct gps_device_t * ses
             "=> GPS: UBX class: %02x, id: %02x, len: %zd, crc: %02x%02x\n",
             msg_class, msg_id, data_len,
             CK_A, CK_B);
+    usleep(100000);
     count = gpsd_write(session, session->msgbuf, session->msgbuflen);
+    usleep(100000);
     ok = (count == (ssize_t) session->msgbuflen);
     return (ok);
 }
8><--------------------------------

This also fixes the checksum error, which also occurred when there was no 
communication deadlock.

The full log (now working) looks like this:
8><--------------------------------
gpsd:INFO: launching (Version 3.18.1)
gpsd:IO: opening IPv4 socket
gpsd:IO: opening IPv6 socket
gpsd:INFO: listening on port 2947
gpsd:PROG: NTP: shmat(0,0,0) succeeded, segment 0
gpsd:PROG: NTP: shmat(32769,0,0) succeeded, segment 1
gpsd:PROG: shmget(0x47505344, 14024, 0666) for SHM export succeeded
gpsd:PROG: shmat() for SHM export succeeded, segment 6094850
gpsd:INFO: stashing device /dev/ttyUSB0 at slot 0
gpsd:PROG: no /etc/gpsd/device-hook present, skipped running ACTIVATE hook
gpsd:INFO: SER: opening GPS data source type 3 at '/dev/ttyUSB0'
gpsd:INFO: SER: speed 9600, 8N1
gpsd:PROG: no probe matched...
gpsd:INFO: gpsd_activate(2): activated GPS (fd 5)
gpsd:PROG: PPS:/dev/ttyUSB0 chrony socket /var/run/chrony.ttyUSB0.sock doesn't 
exist
gpsd:PROG: KPPS:/dev/ttyUSB0 checking /sys/devices/virtual/pps/pps0/path, 
/dev/ttyUSB0
gpsd:INFO: KPPS:/dev/ttyUSB0 RFC2783 path:/dev/pps0, fd is 6
gpsd:INFO: KPPS:/dev/ttyUSB0 pps_caps 0x1133
gpsd:INFO: KPPS:/dev/ttyUSB0 have PPS_CANWAIT
gpsd:INFO: KPPS:/dev/ttyUSB0 kernel PPS will be used
gpsd:PROG: PPS:/dev/ttyUSB0 thread launched
gpsd:INFO: PPS:/dev/ttyUSB0 ntpshm_link_activate: 1
gpsd:INFO: device /dev/ttyUSB0 activated
gpsd:INFO: KPPS:/dev/ttyUSB0 kernel PPS timeout Interrupted system call
gpsd:INFO: KPPS:/dev/ttyUSB0 kernel PPS timeout Interrupted system call
gpsd:INFO: running with effective group ID 0
gpsd:INFO: running with effective user ID 0
gpsd:INFO: startup at 2019-05-21T15:38:22.000Z (1558453102)
gpsd:PROG: switching to match packet type 1: 
$GPTXT,01,01,02,ANTSTATUS=OK*3B\x0d\x0a
gpsd:PROG: switch_driver(NMEA0183) called...
gpsd:PROG: selecting NMEA0183 driver...
gpsd:INFO: /dev/ttyUSB0 identified as type NMEA0183, 0 sec @ 9600bps
gpsd:PROG: => Probing for Garmin NMEA
gpsd:IO: SER: => GPS: $PGRMCE*0E\x0d\x0a
gpsd:IO: <= GPS: $GPTXT,01,01,02,ANTSTATUS=OK*3B
gpsd:WARN: TXT: Notice: ANTSTATUS=OK
gpsd:IO: <= GPS: $GPTXT,01,01,01,PGRM inv format*34
gpsd:WARN: TXT: Warning: PGRM inv format
gpsd:PROG: => Probing for FV-18
gpsd:IO: SER: => GPS: $PFEC,GPint*58\x0d\x0a
gpsd:IO: <= GPS: $GPRMC,153823.00,V,,,,,,,210519,,,N*7D
gpsd:PROG: => Probing for Trimble Copernicus
gpsd:IO: SER: => GPS: $PTNLSNM,0139,01*5C\x0d\x0a
gpsd:IO: <= GPS: $GPVTG,,,,,,,,,N*30
gpsd:WARN: unknown sentence: "$GPVTG,,,,,,,,,N*30\x0d\x0a"
gpsd:IO: <= GPS: $GPGGA,153823.00,,,,,0,00,99.99,,,,,,*68
gpsd:IO: <= GPS: $GPGSA,A,1,,,,,,,,,,,,,99.99,99.99,99.99*30
gpsd:PROG: xxGSA sets mode 1
gpsd:IO: <= GPS: $GPGSV,3,1,11,07,17,313,,08,28,285,,10,35,139,,15,01,056,*7C
gpsd:PROG: Partial satellite data (1 of 3).
gpsd:PROG: => Probing for UBX
gpsd:PROG: => GPS: UBX class: 06, id: 00, len: 0, crc: 0618
gpsd:IO: SER: => GPS: b562060000000618
gpsd:IO: <= GPS: $GPGSV,3,2,11,16,76,197,,18,05,232,,20,46,105,,21,43,057,*7C
gpsd:PROG: Partial satellite data (2 of 3).
gpsd:IO: <= GPS: $GPGSV,3,3,11,26,47,165,,27,63,301,,30,01,338,*44
gpsd:INFO: Sats used (0):
gpsd:IO: <= GPS: $GPGLL,,,,,153823.00,V,N*44
gpsd:WARN: can't use GLL time until after ZDA or RMC has supplied a year.
gpsd:PROG: GPGLL sentence timestamped 153823.00.
gpsd:PROG: GPGLL starts a reporting cycle.
gpsd:IO: <= GPS: $GPTXT,01,01,01,PFEC inv format*2C
gpsd:WARN: TXT: Warning: PFEC inv format
gpsd:IO: <= GPS: $GPTXT,01,01,01,PTNL inv format*3A
gpsd:WARN: TXT: Warning: PTNL inv format
gpsd:IO: UBX: len 28
gpsd:PROG: switching to match packet type 11: 
b5620600140001000000c008000080250000070003000000000092b5
gpsd:PROG: switch_driver(u-blox) called...
gpsd:PROG: selecting u-blox driver...
gpsd:INFO: /dev/ttyUSB0 identified as type u-blox, 1 sec @ 9600bps
gpsd:PROG: => GPS: UBX class: 0a, id: 04, len: 0, crc: 0e34
gpsd:IO: SER: => GPS: b5620a0400000e34
gpsd:PROG: => GPS: UBX class: 06, id: 16, len: 8, crc: 31e5
gpsd:IO: SER: => GPS: b56206160800030703000000000031e5
gpsd:PROG: => GPS: UBX class: 06, id: 00, len: 20, crc: a0a9
gpsd:IO: SER: => GPS: b5620600140001000000d0080000802500000700010000000000a0a9
gpsd:PROG: => GPS: UBX class: 0a, id: 04, len: 0, crc: 0e34
gpsd:IO: SER: => GPS: b5620a0400000e34
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 104b
gpsd:IO: SER: => GPS: b56206010300010401104b
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 124f
gpsd:IO: SER: => GPS: b56206010300010601124f
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 2c83
gpsd:IO: SER: => GPS: b562060103000120012c83
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 45ac
gpsd:IO: SER: => GPS: b5620601030001300a45ac
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 47b0
gpsd:IO: SER: => GPS: b5620601030001320a47b0
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 0d45
gpsd:IO: SER: => GPS: b562060103000101010d45
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 1d65
gpsd:IO: SER: => GPS: b562060103000111011d65
gpsd:IO: UBX: len 10
gpsd:IO: UBX: len 108
gpsd:INFO: UBX_MON_VER: SW 1.00 (59842),HW 00070000,PROTVER 
14.00,GPS;SBAS;GLO;QZSS
gpsd:IO: UBX: len 10
gpsd:IO: UBX: len 10
gpsd:IO: UBX: len 108
gpsd:INFO: UBX_MON_VER: SW 1.00 (59842),HW 00070000,PROTVER 
14.00,GPS;SBAS;GLO;QZSS
gpsd:IO: UBX: len 10
gpsd:IO: UBX: len 10
gpsd:IO: UBX: len 10
gpsd:IO: UBX: len 60
gpsd:PROG: UBX_NAV_SOL
gpsd:IO: UBX: len 26
gpsd:PROG: UBX_NAV_DOP
gpsd:IO: UBX: len 24
gpsd:PROG: UBX_NAV_TIMEGPS
gpsd:IO: UBX: len 10
gpsd:IO: UBX: len 10
gpsd:IO: UBX: len 10
gpsd:IO: UBX: len 10
gpsd:INFO: KPPS:/dev/ttyUSB0 kernel PPS timeout Connection timed out
gpsd:IO: UBX: len 60
gpsd:PROG: UBX_NAV_SOL
gpsd:IO: UBX: len 292
gpsd:PROG: UBX_NAV_SVINFO
gpsd:INFO: Sats used (0):
gpsd:IO: UBX: len 28
gpsd:IO: UBX: len 26
gpsd:PROG: UBX_NAV_DOP
gpsd:IO: UBX: len 28
gpsd:IO: UBX: len 24
gpsd:PROG: UBX_NAV_TIMEGPS
8><--------------------------------

whereas the full log in the previously working (but with checksum errors) case 
looked like this:
8><--------------------------------
gpsd:INFO: launching (Version 3.18.1)
gpsd:IO: opening IPv4 socket
gpsd:IO: opening IPv6 socket
gpsd:INFO: listening on port 2947
gpsd:PROG: NTP: shmat(0,0,0) succeeded, segment 0
gpsd:PROG: NTP: shmat(32769,0,0) succeeded, segment 1
gpsd:PROG: shmget(0x47505344, 14024, 0666) for SHM export succeeded
gpsd:PROG: shmat() for SHM export succeeded, segment 294914
gpsd:INFO: stashing device /dev/ttyUSB0 at slot 0
gpsd:PROG: no /etc/gpsd/device-hook present, skipped running ACTIVATE hook
gpsd:INFO: SER: opening GPS data source type 3 at '/dev/ttyUSB0'
gpsd:INFO: SER: speed 9600, 8N1
gpsd:PROG: no probe matched...
gpsd:INFO: gpsd_activate(2): activated GPS (fd 5)
gpsd:PROG: PPS:/dev/ttyUSB0 chrony socket /var/run/chrony.ttyUSB0.sock doesn't 
exist
gpsd:PROG: KPPS:/dev/ttyUSB0 checking /sys/devices/virtual/pps/pps0/path, 
/dev/ttyUSB0
gpsd:INFO: KPPS:/dev/ttyUSB0 RFC2783 path:/dev/pps0, fd is 6
gpsd:INFO: KPPS:/dev/ttyUSB0 pps_caps 0x1133
gpsd:INFO: KPPS:/dev/ttyUSB0 have PPS_CANWAIT
gpsd:INFO: KPPS:/dev/ttyUSB0 kernel PPS will be used
gpsd:PROG: PPS:/dev/ttyUSB0 thread launched
gpsd:INFO: PPS:/dev/ttyUSB0 ntpshm_link_activate: 1
gpsd:INFO: device /dev/ttyUSB0 activated
gpsd:INFO: running with effective group ID 0
gpsd:INFO: running with effective user ID 0
gpsd:INFO: startup at 2019-05-20T16:19:13.000Z (1558369153)
gpsd:INFO: KPPS:/dev/ttyUSB0 kernel PPS timeout Interrupted system call
gpsd:PROG: switching to match packet type 1: 
$GPRMC,161914.00,A,4708.40771,N,00141.94240,W,0.055,,200519,,,A*66\x0d\x0a
gpsd:PROG: switch_driver(NMEA0183) called...
gpsd:PROG: selecting NMEA0183 driver...
gpsd:INFO: /dev/ttyUSB0 identified as type NMEA0183, 1 sec @ 9600bps
gpsd:PROG: => Probing for Garmin NMEA
gpsd:IO: SER: => GPS: $PGRMCE*0E\x0d\x0a
gpsd:IO: <= GPS: 
$GPRMC,161914.00,A,4708.40771,N,00141.94240,W,0.055,,200519,,,A*66
gpsd:PROG: GPRMC sentence timestamped 161914.00.
gpsd:PROG: GPRMC starts a reporting cycle.
gpsd:PROG: NTP: ntpshm_put(/dev/ttyUSB0,-20)  1558369154.000000000 @  
1558369154.140840884
gpsd:IO: <= GPS: $GPVTG,,T,,M,0.055,N,0.101,K,A*23
gpsd:WARN: unknown sentence: "$GPVTG,,T,,M,0.055,N,0.101,K,A*23\x0d\x0a"
gpsd:PROG: => Probing for FV-18
gpsd:IO: SER: => GPS: $PFEC,GPint*58\x0d\x0a
gpsd:IO: <= GPS: 
$GPGGA,161914.00,4708.40771,N,00141.94240,W,1,07,1.20,2.8,M,48.2,M,,*45
gpsd:PROG: GPGGA sentence timestamped 161914.00.
gpsd:PROG: => Probing for Trimble Copernicus
gpsd:IO: SER: => GPS: $PTNLSNM,0139,01*5C\x0d\x0a
gpsd:IO: <= GPS: $GPGSA,A,3,27,16,10,20,08,26,21,,,,,,2.68,1.20,2.40*05
gpsd:PROG: xxGSA sets mode 3
gpsd:IO: <= GPS: 
$GPGSV,4,1,13,07,18,298,,08,42,295,28,10,48,123,38,11,06,259,*77
gpsd:PROG: Partial satellite data (1 of 4).
gpsd:IO: <= GPS: $GPGSV,4,2,13,13,00,012,,15,04,042,,16,58,179,35,18,19,240,*7E
gpsd:PROG: Partial satellite data (2 of 4).
gpsd:IO: <= GPS: 
$GPGSV,4,3,13,20,47,081,33,21,28,060,36,26,29,166,30,27,77,331,38*7C
gpsd:PROG: Partial satellite data (3 of 4).
gpsd:PROG: => Probing for UBX
gpsd:PROG: => GPS: UBX class: 06, id: 00, len: 0, crc: 0618
gpsd:IO: SER: => GPS: b562060000000618
gpsd:IO: <= GPS: $GPGSV,4,4,13,30,08,327,*46
gpsd:INFO: PRN=  8 az=295 el=42 (-0.673518, 0.314067, 0.669131)
gpsd:INFO: PRN= 10 az=123 el=48 (0.561180, -0.364435, 0.743145)
gpsd:INFO: PRN= 16 az=179 el=58 (0.009248, -0.529839, 0.848048)
gpsd:INFO: PRN= 20 az= 81 el=47 (0.673602, 0.106688, 0.731354)
gpsd:INFO: PRN= 21 az= 60 el=28 (0.764655, 0.441474, 0.469472)
gpsd:INFO: PRN= 26 az=166 el=29 (0.211590, -0.848640, 0.484810)
gpsd:INFO: PRN= 27 az=331 el=77 (-0.109058, 0.196747, 0.974370)
gpsd:INFO: Sats used (7):
gpsd:IO: <= GPS: $GPGLL,4708.40771,N,00141.94240,W,161914.00,A,A*70
gpsd:PROG: GPGLL sentence timestamped 161914.00.
gpsd:IO: <= GPS: $GPTXT,01,01,01,PGRM inv format*34
gpsd:WARN: TXT: Warning: PGRM inv format
gpsd:IO: <= GPS: $GPTXT,01,01,01,PFEC inv format*2C
gpsd:WARN: TXT: Warning: PFEC inv format
gpsd:IO: <= GPS: $GPTXT,01,01,01,PTNL inv format*3A
gpsd:WARN: TXT: Warning: PTNL inv format
gpsd:IO: UBX: len 28
gpsd:PROG: switching to match packet type 11: 
b5620600140001000000c008000080250000070003000000000092b5
gpsd:PROG: switch_driver(u-blox) called...
gpsd:PROG: selecting u-blox driver...
gpsd:INFO: /dev/ttyUSB0 identified as type u-blox, 1 sec @ 9600bps
gpsd:PROG: => GPS: UBX class: 0a, id: 04, len: 0, crc: 0e34
gpsd:IO: SER: => GPS: b5620a0400000e34
gpsd:PROG: => GPS: UBX class: 06, id: 16, len: 8, crc: 31e5
gpsd:IO: SER: => GPS: b56206160800030703000000000031e5
gpsd:PROG: => GPS: UBX class: 06, id: 00, len: 20, crc: a0a9
gpsd:IO: SER: => GPS: b5620600140001000000d0080000802500000700010000000000a0a9
gpsd:PROG: => GPS: UBX class: 0a, id: 04, len: 0, crc: 0e34
gpsd:IO: SER: => GPS: b5620a0400000e34
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 104b
gpsd:IO: SER: => GPS: b56206010300010401104b
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 124f
gpsd:IO: SER: => GPS: b56206010300010601124f
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 2c83
gpsd:IO: SER: => GPS: b562060103000120012c83
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 45ac
gpsd:IO: SER: => GPS: b5620601030001300a45ac
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 47b0
gpsd:IO: SER: => GPS: b5620601030001320a47b0
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 0d45
gpsd:IO: SER: => GPS: b562060103000101010d45
gpsd:PROG: => GPS: UBX class: 06, id: 01, len: 3, crc: 1d65
gpsd:IO: SER: => GPS: b562060103000111011d65
gpsd:IO: UBX: len 10
gpsd:IO: UBX: len 108
gpsd:IO: UBX checksum 0xc7de over length 108, expecting 0x6205 (type 0x0a04)
gpsd:IO: UBX: len 60
gpsd:PROG: UBX_NAV_SOL
gpsd:IO: UBX: len 304
gpsd:PROG: UBX_NAV_SVINFO
gpsd:PROG: => GPS: UBX class: 0a, id: 04, len: 0, crc: 0e34
gpsd:IO: SER: => GPS: b5620a0400000e34
gpsd:INFO: PRN=  8 az=295 el=42 (-0.673518, 0.314067, 0.669131)
gpsd:INFO: PRN= 10 az=123 el=48 (0.561180, -0.364435, 0.743145)
gpsd:INFO: PRN= 16 az=179 el=58 (0.009248, -0.529839, 0.848048)
gpsd:INFO: PRN= 20 az= 81 el=47 (0.673602, 0.106688, 0.731354)
gpsd:INFO: PRN= 21 az= 60 el=28 (0.764655, 0.441474, 0.469472)
gpsd:INFO: PRN= 26 az=166 el=29 (0.211590, -0.848640, 0.484810)
gpsd:INFO: PRN= 27 az=331 el=77 (-0.109058, 0.196747, 0.974370)
gpsd:INFO: Sats used (7):
gpsd:IO: UBX: len 28
gpsd:IO: UBX: len 28
gpsd:IO: UBX: len 24
gpsd:PROG: UBX_NAV_TIMEGPS
gpsd:PROG: NTP: ntpshm_put(/dev/ttyUSB0,-20)  1558369154.999592304 @  
1558369155.529363862
gpsd:IO: UBX: len 20
gpsd:IO: UBX: len 108
gpsd:INFO: UBX_MON_VER: SW 1.00 (59842),HW 00070000,PROTVER 
14.00,GPS;SBAS;GLO;QZSS
gpsd:PROG: KPPS:/dev/ttyUSB0 assert  0.000000000, sequence: 0, clear   
1558369155.999711283, sequence: 1 - using: clear
gpsd:PROG: KPPS:/dev/ttyUSB0 Clear cycle: 1558369155999711, duration: 
1558369155999711 @  1558369155.999711283
gpsd:PROG: PPS:/dev/ttyUSB0 Clear cycle: 1558369155999711, duration: 
1558369155999711 @  1558369155.999711283
gpsd:PROG: KPPS:/dev/ttyUSB0 assert  1558369156.099754208, sequence: 1, clear   
1558369155.999711283, sequence: 1 - using: assert
gpsd:PROG: KPPS:/dev/ttyUSB0 Assert cycle: 1558369156099754, duration:  100042 
@  1558369156.099754208
gpsd:PROG: PPS:/dev/ttyUSB0 Assert cycle: 1558369156099754, duration:  100042 @ 
 1558369156.099754208
gpsd:PROG: PPS:/dev/ttyUSB0 Assert ignored Too long for 0.5Hz
gpsd:IO: UBX: len 60
gpsd:PROG: UBX_NAV_SOL
gpsd:PROG: NTP: ntpshm_put(/dev/ttyUSB0,-20)  1558369156.000000000 @  
1558369156.130215887
gpsd:IO: UBX: len 28
gpsd:IO: UBX: len 28
gpsd:IO: UBX: len 24
gpsd:PROG: UBX_NAV_TIMEGPS
8><--------------------------------

Unfortunately, I do not have time to investigate this issue more deeply.

FYI, the ntp fudge time1 value that I got for the GR-701W using the 
peerstats-based procedure is 0.181638.

Thanks for gpsd!

Best regards,
Benoît