[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [gpsd-dev] Major progress!
From: |
Eric S. Raymond |
Subject: |
Re: [gpsd-dev] Major progress! |
Date: |
Mon, 9 Feb 2015 13:16:25 -0500 |
User-agent: |
Mutt/1.5.23 (2014-03-12) |
Greg Troxel <address@hidden>:
> bisect fingers
>
> commit 156c381715e13466682af32d284ee1c684b0de96
> Author: Eric S. Raymond <address@hidden>
> Date: Mon Feb 9 06:13:31 2015 -0500
>
> which doesn't make a lot of sense.
Actually, that's a pretty good clue to what's going on. There used to be
two ways a test could terminate:
(1) gpsd recognizes a final "# EOF\n" comment packet injected by gpsfake.
It shuts down the device pty.
(2) gpsd waits on select. The test code notices it has run out of data. After
a timeout of CLOSE_DELAY it removes the device. This is the code path that
produced flaky errors.
You've fingered the commit where method 2 was removed.
> Your commit message said "all regression tests pass", but of course that
> isn't true :-) What platforms did you actually test on (and it would
> be good to note that in the commit message)?
My main development machine of course, under Linux. If I check out
that commit and run
gpsfake -D 10 -p -1 test/daemon/bu303-stillfix.log
here's what the tail of the log looks like (wuth comments interspersed, led
with ;;):
gpsd:UNK: 00004848: character '.' [b3], SIRF_TRAILER_1 -> SIRF_RECOGNIZED
gpsd:UNK: Packet type 4 accepted 99 =
a0a2005b2900000000012e17ba3d050000000000000000000000001bb710440482b37c00021f5200020c8c00000000000000000000000000010a000001e500000000000000000000000000000000000000000000000000000000000000004f0693b0b3
;; Lexer went to strate SIRF_RECOGNIZED, meaning it sees a complete SiRF
;; binary packet. That is accepted and placed in the lexer's output buffer
gpsd:UNK: Packet discard of 99, chars remaining is 6 = # EOF\x0a
gpsd:RAW: /dev/pts/9 is known to be SiRF
gpsd:RAW: window average of received byte count is 70.250000
gpsd:UNK: /dev/pts/9 sent 99 new characters
gpsd:RAW: packet sniff on /dev/pts/9 finds type 4
gpsd:RAW: raw packet of type 4,
99:a0a2005b2900000000012e17ba3d050000000000000000000000001bb710440482b37c00021f5200020c8c00000000000000000000000000010a000001e500000000000000000000000000000000000000000000000000000000000000004f0693b0b3
gpsd:RAW: SiRF: Raw packet type 0x29
gpsd:PROG: SiRF: unused GND 0x29
gpsd:DATA: packet type 4 from /dev/pts/9 with {ONLINE|PACKET}
gpsd:UNK: Read 0 chars to buffer offset 6 (total 6): # EOF\x0a
;; The SiRF packet is a GND and is ignored. "# EOF\n" remains in the input
;; buffer - that is the stop packet injected by gpsfake.
gpsd:SPIN: packet_get() fd 10 -> 0 (0)
gpsd:UNK: 00004848: character '#' [23] pushed back, state set to GROUND_STATE
gpsd:UNK: 00004848: character '#' [23], GROUND_STATE -> COMMENT_BODY
gpsd:UNK: 00004849: character ' ' [20], COMMENT_BODY -> COMMENT_BODY
gpsd:UNK: 00004850: character 'E' [45], COMMENT_BODY -> COMMENT_BODY
gpsd:UNK: 00004851: character 'O' [4f], COMMENT_BODY -> COMMENT_BODY
gpsd:UNK: 00004852: character 'F' [46], COMMENT_BODY -> COMMENT_BODY
gpsd:UNK: 00004853: character '.' [0a], COMMENT_BODY -> COMMENT_RECOGNIZED
gpsd:UNK: Packet type 0 accepted 6 = # EOF\x0a
;; The lexer sees # in state SIRF_RECOGNIZED, pushes it back, and drops to
;; GROUND_STATE. This is where it is ready to recognize any kind of packet
;; start.
gpsd:UNK: Packet discard of 6, chars remaining is 0 = # EOF\x0a
gpsd:RAW: /dev/pts/9 is known to be SiRF
gpsd:RAW: window average of received byte count is 6.000000
gpsd:UNK: /dev/pts/9 sent 6 new characters
gpsd:RAW: packet sniff on /dev/pts/9 finds type 0
gpsd:PROG: synthetic EOF
gpsd:WARN: device signed off /dev/pts/9
;; gpsd recognizes a synthetic EOF
gpsd:CLIENT: => client(0):
{"class":"DEVICE","path":"/dev/pts/9","activated":0}\x0d\x0a
gpsd:INFO: closing GPS=/dev/pts/9 (10)
{"class":"DEVICE","path":"/dev/pts/9","activated":0}
gpsd:SPIN: close(10) in gpsd_close(/dev/pts/9)
;; It ships a device-close notification to all watchers, then closes
;; the device.
gpsd:PROG: no /etc/gpsd/device-hook present, skipped running DEACTIVATE hook
gpsd:UNK: select waits
gpsd:SPIN: select() {6 7 8 9} -> { 6 } at 1423504701.449384 (errno 0)
gpsd:INFO: control socket connect on fd 10
gpsd:CLIENT: <= control(10): -/dev/pts/9\x0d\x0a
gpsd:INFO: <= control(10): removing /dev/pts/9
gpsd:CLIENT: => client(0):
{"class":"DEVICE","path":"/dev/pts/9","activated":0}\x0d\x0a
gpsd:SPIN: close(10) of control socket
gpsd:UNK: select waits
{"class":"DEVICE","path":"/dev/pts/9","activated":0}
;; gpsfake receives the device-closed notification...
gpsd:WARN: received terminating signal 15.
;; ...because no active devices remain, it signals the slave gpsd,
gpsd:WARN: exiting.
gpsd:SPIN: close(9) in detach_client()
gpsd:INFO: detaching 127.0.0.1 (sub 0, fd 9) in detach_client
;; Which then exits.
What we need to figure out is where in this shutdown sequence things are
going awry. You should run
gpsfake -D 10 -p -1 test/daemon/bu303-stillfix.log
and compare the tail of the log with this.
--
<a href="http://www.catb.org/~esr/">Eric S. Raymond</a>
signature.asc
Description: Digital signature
Re: [gpsd-dev] Major progress!, Hal Murray, 2015/02/09
- Re: [gpsd-dev] Major progress!, Eric S. Raymond, 2015/02/09
- Re: [gpsd-dev] Major progress!, Gary E. Miller, 2015/02/09
- Re: [gpsd-dev] Major progress!, Eric S. Raymond, 2015/02/09
- Re: [gpsd-dev] Major progress!, Gary E. Miller, 2015/02/09
- Re: [gpsd-dev] Major progress!, Eric S. Raymond, 2015/02/09
- Re: [gpsd-dev] Major progress!, Hal Murray, 2015/02/10
- Re: [gpsd-dev] Major progress!, Eric S. Raymond, 2015/02/10
Re: [gpsd-dev] Major progress!, Hal Murray, 2015/02/09