[LinuxPPS] Occasionally ntpd stops receiving NMEA data

[Philip M. White]

I do not claim correlation, but once I upgraded my LinuxPPS to version
2.1.0, ntpd began behaving poorly: after several minutes of running
correctly, it stops receiving the GPS data.

Here's a log of `dmesg':

vers/pps/pps.c: New message from PID 21711 (flags 0)
drivers/pps/pps.c: PPS_FETCH: source 0
drivers/pps/kapi.c: capture assert seq #132 for source 0
drivers/serial/8250.c: serial8250: PPS assert event at 36061905
drivers/pps/kapi.c: capture clear seq #131 for source 0
drivers/serial/8250.c: serial8250: PPS clear event at 36062005
drivers/pps/kapi.c: capture assert seq #133 for source 0
drivers/serial/8250.c: serial8250: PPS assert event at 36062905
drivers/pps/kapi.c: capture clear seq #132 for source 0
drivers/serial/8250.c: serial8250: PPS clear event at 36063005
drivers/pps/pps.c: New message from PID 21711 (flags 0)
drivers/pps/pps.c: PPS_FETCH: source 0
drivers/pps/kapi.c: capture assert seq #134 for source 0
drivers/serial/8250.c: serial8250: PPS assert event at 36063905
drivers/pps/kapi.c: capture clear seq #133 for source 0
drivers/serial/8250.c: serial8250: PPS clear event at 36064005
drivers/pps/kapi.c: capture assert seq #135 for source 0
drivers/serial/8250.c: serial8250: PPS assert event at 36064905
drivers/pps/kapi.c: capture clear seq #134 for source 0
drivers/serial/8250.c: serial8250: PPS clear event at 36065006
drivers/pps/pps.c: New message from PID 21711 (flags 0)
drivers/pps/pps.c: PPS_FETCH: source 0
[it stops here]

And here's a log of ntpd:

nmea: gpsread 72 $GPRMC,051330,A,3300.6600,N,09643.3346,W,000.0,016.2,050606,004.8,E,A*0B
nmea: timecode 72 $GPRMC,051330,A,3300.6600,N,09643.3346,W,000.0,016.2,050606,004.8,E,A*0B
nmea: gpsread 68 $GPGGA,051330,3300.6600,N,09643.3346,W,1,06,1.7,191.7,M,-24.9,M,,*72
nmea: gpsread 49 $GPGSA,A,3,08,11,17,19,,,27,28,,,,,2.7,1.7,1.0*39
nmea: gpsread 68 $GPGSV,3,1,11,08,84,350,43,11,44,092,49,17,43,231,42,19,15,043,39*7E
nmea: gpsread 68 $GPGSV,3,2,11,24,10,176,00,26,16,314,00,27,66,143,49,28,55,324,39*71
nmea: gpsread 55 $GPGSV,3,3,11,29,20,306,00,48,36,234,37,51,50,199,00*4D
nmea: gpsread 27 $PGRME,3.2,M,4.7,M,5.7,M*2E
nmea: gpsread 45 $GPGLL,3300.6600,N,09643.3346,W,051330,A,A*5B
nmea: gpsread 22 $PGRMV,0.0,0.0,-0.0*71
nmea: gpsread 75 $PGRMF,354,105224,050606,051330,14,3300.6600,N,09643.3346,W,A,2,0,16,3,1*31
nmea: gpsread 19 $PGRMB,,,,,,K,,,*2D
nmea: gpsread 16 $PGRMM,WGS 84*06
nmea: gpsread 72 $GPRMC,051332,A,3300.6599,N,09643.3344,W,000.0,016.2,050606,004.8,E,A*08
nmea: timecode 72 $GPRMC,051332,A,3300.6599,N,09643.3344,W,000.0,016.2,050606,004.8,E,A*08
nmea: gpsread 68 $GPGGA,051332,3300.6599,N,09643.3344,W,1,06,1.7,192.0,M,-24.9,M,,*75
nmea: gpsread 49 $GPGSA,A,3,08,11,17,19,,,27,28,,,,,2.7,1.7,1.0*39
nmea: gpsread 68 $GPGSV,3,1,11,08,84,350,43,11,44,092,49,17,43,231,41,19,15,043,38*7C
auth_agekeys: at 120 keys 1 expired 0
refclock_transmit: at 121 127.127.20.0
transmit: at 130 192.168.1.31->209.223.236.234 mode 3
receive: at 130 192.168.1.31<-209.223.236.234 mode 4 code 1
clock_filter: n 3 off -0.003078 del 0.010688 dsp 1.938220 jit 0.002107, age 127
transmit: at 131 192.168.1.31->64.5.1.130 mode 3
receive: at 131 192.168.1.31<-64.5.1.130 mode 4 code 1
clock_filter: n 2 off 0.000248 del 0.071222 dsp 3.937742 jit 0.002194, age 64
transmit: at 133 192.168.1.31->192.83.249.31 mode 3
receive: at 133 192.168.1.31<-192.83.249.31 mode 4 code 1
clock_filter: n 2 off 0.000392 del 0.055600 dsp 3.938355 jit 0.000738, age 133
transmit: at 136 192.168.1.31->64.112.189.11 mode 3
receive: at 136 192.168.1.31<-64.112.189.11 mode 4 code 1
clock_filter: n 2 off -0.003331 del 0.060046 dsp 3.937987 jit 0.000857, age 136
refclock_transmit: at 139 127.127.20.0
refclock_transmit: at 155 127.127.20.0
clock GPS_NMEA(0) event 'clk_noreply' (0x01)
transmit: at 166 192.168.1.31->192.168.1.254 mode 3
receive: at 166 192.168.1.31<-192.168.1.254 mode 4 code 1
clock_filter: n 4 off 0.000873 del 0.001795 dsp 0.938172 jit 0.000035, age 64
refclock_transmit: at 172 127.127.20.0
clock_filter: n 7 off -0.001090 del 0.000000 dsp 0.107930 jit 1.632992, age 84
clock GPS_NMEA(0) event 'clk_noreply' (0x01)
auth_agekeys: at 180 keys 1 expired 0
refclock_transmit: at 190 127.127.20.0
clock_filter: n 6 off -0.001090 del 0.000000 dsp 0.188981 jit 0.000001, age 102
report_event: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_uhf_clock, 2 events, event_restart' (0xc421)
addto_syslog: synchronized to GPS_NMEA(0), stratum 0
clock_update: at 190 assoc 6
local_clock: assocID 6612 offset -0.001090167 freq -161.604 state 1
local_clock: time 88 clock 0.000000 offset -0.001090 freq -161.604 state 4
addto_syslog: kernel time sync disabled 0041
local_clock: mu 88 jitr 0.001 freq -161.812 stab 6.652 poll 6 count 6
report_event: system event 'event_sync_chg' (0x03) status 'leap_none, sync_uhf_clock, 3 events, event_peer/strat_chg' (0x434)
report_event: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_uhf_clock, 4 events, event_sync_chg' (0x443)
clock GPS_NMEA(0) event 'clk_noreply' (0x01)

It's clear from the log that the GPS saw six satellites at the time of
the incident, so the PPS signal did not stop.

When I Ctrl-C the ntpd process (which is running in the foreground with
the -d switch), it takes a while for the process to die, like it's stuck
waiting for something.

Once I restart ntpd, for a little while everything's fine again -- it
can see NMEA data.

Any ideas?

-- 
Philip
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 191 bytes
Desc: not available
Url : http://ml.enneenne.com/pipermail/linuxpps/attachments/20060605/537fecb5/attachment-0001.pgp