diff options
| -rw-r--r-- | gps.h | 3 | ||||
| -rw-r--r-- | gps/fake.py | 2 | ||||
| -rwxr-xr-x | gps/gps.py | 5 | ||||
| -rw-r--r-- | gps_json.h | 3 | ||||
| -rw-r--r-- | gpsd.c | 19 | ||||
| -rw-r--r-- | gpsd.h-tail | 9 | ||||
| -rw-r--r-- | gpsd_json.c | 15 | ||||
| -rwxr-xr-x | gpsprof | 202 | ||||
| -rw-r--r-- | gpsprof.xml | 67 | ||||
| -rw-r--r-- | gpsutils.c | 9 | ||||
| -rw-r--r-- | libgpsd_core.c | 16 | ||||
| -rw-r--r-- | www/hacking.html | 51 |
12 files changed, 53 insertions, 348 deletions
@@ -1751,6 +1751,9 @@ extern /*@observer@*/const char *gps_maskdump(gps_mask_t); extern double safe_atof(const char *); extern time_t mkgmtime(register struct tm *); extern timestamp_t timestamp(void); +#ifdef TIMING_ENABLE +extern timestamp_t realtimestamp(void); +#endif /* TIMING_ENABLE */ extern timestamp_t iso8601_to_unix(char *); extern /*@observer@*/char *unix_to_iso8601(timestamp_t t, /*@ out @*/char[], size_t len); extern double earth_distance(double, double, double, double); diff --git a/gps/fake.py b/gps/fake.py index 182529a5..7843fed6 100644 --- a/gps/fake.py +++ b/gps/fake.py @@ -495,8 +495,6 @@ class TestSession: self.progress("gpsfake: gather(%d)\n" % seconds) #mark = time.time() time.sleep(seconds) - #if self.timings.c_recv_time <= mark: - # TestSessionError("no sentences received\n") def cleanup(self): "We're done, kill the daemon." self.progress("gpsfake: cleanup()\n") @@ -125,7 +125,6 @@ class gpsdata: self.devices = [] self.version = None - self.timings = None def __repr__(self): st = "Time: %s (%s)\n" % (self.utc, self.fix.time) @@ -293,10 +292,6 @@ class gps(gpsdata, gpsjson): if sat.used: self.satellites_used += 1 self.valid = ONLINE_SET | SATELLITE_SET - elif self.data.get("class") == "TIMING": - self.data["c_recv"] = self.received - self.data["c_decode"] = time.time() - self.timings = self.data def read(self): "Read and interpret data from the daemon." @@ -16,7 +16,8 @@ extern "C" { void json_data_report(gps_mask_t, struct gps_data_t *, struct policy_t *, /*@out@*/char *, size_t); char *json_stringify(/*@out@*/char *, size_t, /*@in@*/const char *); -void json_tpv_dump(const struct gps_data_t *, /*@out@*/char *, size_t); +void json_tpv_dump(const struct gps_data_t *, + const struct policy_t *, /*@out@*/char *, size_t); void json_noise_dump(const struct gps_data_t *, /*@out@*/char *, size_t); void json_sky_dump(const struct gps_data_t *, /*@out@*/char *, size_t); void json_att_dump(const struct gps_data_t *, /*@out@*/char *, size_t); @@ -1226,7 +1226,7 @@ static void handle_request(struct subscriber_t *sub, for (devp = devices; devp < devices + MAXDEVICES; devp++) { if (allocated_device(devp) && subscribed(sub, devp)) { if ((devp->observed & GPS_TYPEMASK) != 0) { - json_tpv_dump(&devp->gpsdata, + json_tpv_dump(&devp->gpsdata, &sub->policy, reply + strlen(reply), replylen - strlen(reply)); rstrip(reply); @@ -1633,23 +1633,6 @@ static void consume_packets(struct gps_device_t *device) if (buf[0] != '\0') (void)throttled_write(sub, buf, strlen(buf)); -#ifdef TIMING_ENABLE - if (buf[0] != '\0' && sub->policy.timing) { - (void)snprintf(buf, sizeof(buf), - "{\"class\":\"TIMING\"," - "\"tag\":\"%s\",\"len\":%d," - "\"xmit\":%lf,\"recv\":%lf," - "\"decode\":%lf," - "\"emit\":%lf}\r\n", - device->gpsdata.tag, - (int)device->packet.outbuflen, - device->d_xmit_time, - device->d_recv_time, - device->d_decode_time, - timestamp()); - (void)throttled_write(sub, buf, strlen(buf)); - } -#endif /* TIMING_ENABLE */ } } } diff --git a/gpsd.h-tail b/gpsd.h-tail index 0979d86b..6297a77b 100644 --- a/gpsd.h-tail +++ b/gpsd.h-tail @@ -569,15 +569,6 @@ struct gps_device_t { struct aivdm_context_t aivdm[AIVDM_CHANNELS]; #endif /* AIVDM_ENABLE */ -#ifdef TIMING_ENABLE - /* profiling data for last sentence */ - char tag[MAXTAGLEN+1]; /* tag of last sentence processed */ - timestamp_t d_xmit_time; /* beginning of sentence transmission */ - timestamp_t d_recv_time; /* daemon receipt time (-> E1+T1) */ - timestamp_t d_decode_time; /* daemon end-of-decode time (-> D1) */ - timestamp_t emit_time; /* emission time (-> E2) */ -#endif /* TIMING_ENABLE */ - /* * State of an NTRIP connection. We don't want to zero this on every * activation, otherwise the connection state will get lost. Information diff --git a/gpsd_json.c b/gpsd_json.c index bcaa0e3c..bb5a6201 100644 --- a/gpsd_json.c +++ b/gpsd_json.c @@ -113,10 +113,14 @@ void json_version_dump( /*@out@*/ char *reply, size_t replylen) GPSD_PROTO_MAJOR_VERSION, GPSD_PROTO_MINOR_VERSION); } -void json_tpv_dump(const struct gps_data_t *gpsdata, +void json_tpv_dump(const struct gps_data_t *gpsdata, + const struct policy_t *policy, /*@out@*/ char *reply, size_t replylen) { char tbuf[JSON_DATE_MAX+1]; +#ifdef TIMING_ENABLE + timestamp_t xmit_time = realtimestamp(); +#endif /* TIMING_ENABLE */ assert(replylen > 2); (void)strlcpy(reply, "{\"class\":\"TPV\",", replylen); @@ -199,6 +203,13 @@ void json_tpv_dump(const struct gps_data_t *gpsdata, (void)snprintf(reply + strlen(reply), replylen - strlen(reply), "\"epc\":%.2f,", gpsdata->fix.epc); +#ifdef TIMING_ENABLE + if (policy->timing) + (void)snprintf(reply + strlen(reply), + replylen - strlen(reply), + "\"xmit_time\":%f,", + xmit_time); +#endif /* TIMING_ENABLE */ } if (reply[strlen(reply) - 1] == ',') reply[strlen(reply) - 1] = '\0'; /* trim trailing comma */ @@ -2922,7 +2933,7 @@ void json_data_report(gps_mask_t changed, buf[0] = '\0'; if ((changed & REPORT_IS) != 0) { - json_tpv_dump(datap, buf+strlen(buf), buflen-strlen(buf)); + json_tpv_dump(datap, policy, buf+strlen(buf), buflen-strlen(buf)); } if ((changed & GST_SET) != 0) { @@ -42,7 +42,7 @@ class Baton: return class spaceplot: - "Total times without instrumentation." + "Spatial scattergram of fixes." name = "space" def __init__(self): self.fixes = [] @@ -184,205 +184,7 @@ plot "-" using 0:1 title "Total time" with impulses res += self.header(session) return res + self.data(session) -class rawplot: - "All measurement, no deductions." - name = "raw" - def __init__(self): - self.stats = [] - def gather(self, session): - self.stats.append(copy.copy(session.timings)) - return True - def header(self, session): - res = "# Raw latency data, %s, %s, %dN%d, cycle %ds\n" % \ - (title, - session.gps_id, session.baudrate, - session.stopbits, session.cycle) - res += "# tag len xmit " - for hn in ("T1", "D1", "E2", "T2", "D2"): - res += "%-13s" % hn - res += "\n#------- ----- --------------------" - res += (" " + ("-" * 11)) * 5 - return res + "\n" - def data(self, unused): - res = "" - for timings in self.stats: - res += "% 8s %4d %2.9f %2.9f %2.9f %2.9f %2.9f %2.9f\n" \ - % (timings.tag, - timings.len, - timings.xmit, - timings.recv - timings.xmit, - timings.decode - timings.recv, - timings.emit - timings.decode, - timings.c_recv - timings.emit, - timings.c_decode - timings.c_recv) - return res - def plot(self, unused, session): - fmt = ''' -set autoscale -set key below -set key title "Raw latency data, %s, %s, %dN%d, cycle %ds" -plot \ - "-" using 0:8 title "D2 = Client decode time" with impulses, \ - "-" using 0:7 title "T2 = TCP/IP latency" with impulses, \ - "-" using 0:6 title "E2 = Daemon encode time" with impulses, \ - "-" using 0:5 title "D1 = Daemon decode time" with impulses, \ - "-" using 0:4 title "T1 = RS232 time" with impulses -''' - res = fmt % (title, - session.gps_id, session.baudrate, - session.stopbits, session.cycle) - res += self.header(session) - res += (self.data(session) + "e\n") * 5 - return res - -class splitplot: - "Discard base time, use color to indicate different tags." - name = "split" - sentences = [] - def __init__(self): - self.stats = [] - def gather(self, session): - self.stats.append(copy.copy(session.timings)) - if session.timings.tag not in self.sentences: - self.sentences.append(session.timings.tag) - return True - def header(self, session): - res = "# Split latency data, %s, %s, %dN%d, cycle %ds\n#" % \ - (title, - session.gps_id, session.baudrate, - session.stopbits, session.cycle) - for s in splitplot.sentences: - res += "%8s\t" % s - for hn in ("T1", "D1", "E2", "T2", "D2", "length"): - res += "%8s\t" % hn - res += "tag\n# " - for s in tuple(splitplot.sentences) + ("T1", "D1", "E2", "T2", "D2", "length"): - res += "---------\t" - return res + "--------\n" - def data(self, unused): - res = "" - for timings in self.stats: - for s in splitplot.sentences: - if s == timings.tag: - res += "%2.6f\t" % timings.xmit - else: - res += "- \t" - res += "%2.6f\t%2.6f\t%2.6f\t%2.6f\t%2.6f\t%8d\t# %s\n" \ - % (timings.recv - timings.xmit, - timings.decode - timings.recv, - timings.emit - timings.decode, - timings.c_recv - timings.emit, - timings.c_decode - timings.c_recv, - timings.len, - timings.tag) - return res - def plot(self, title, session): - fixed = ''' -set autoscale -set key below -set key title "Filtered latency data, %s, %s, %dN%d, cycle %ds" -plot \ - "-" using 0:%d title "D2 = Client decode time" with impulses, \ - "-" using 0:%d title "T2 = TCP/IP latency" with impulses, \ - "-" using 0:%d title "E2 = Daemon encode time" with impulses, \ - "-" using 0:%d title "D1 = Daemon decode time" with impulses, \ - "-" using 0:%d title "T1 = RS232 time" with impulses, \ -''' - sc = len(splitplot.sentences) - fmt = fixed % (title, - session.gps_id, session.baudrate, - session.stopbits, session.cycle, - sc+5, - sc+4, - sc+3, - sc+2, - sc+1) - for i in range(sc): - fmt += ' "-" using 0:%d title "%s" with impulses,' % \ - (i+1, self.sentences[i]) - res = fmt[:-1] + "\n" - res += self.header(session) - res += (self.data(session) + "e\n") * (sc + 5) - return res - -class cycle: - "Send-cycle analysis." - name = "cycle" - def __init__(self): - self.stats = [] - def gather(self, session): - self.stats.append(copy.copy(session.timings)) - return True - def plot(self, title, session): - msg = "" - def roundoff(n): - # Round a time to hundredths of a second - return round(n*100) / 100.0 - intervals = {} - last_seen = {} - last_command = "" - for timing in self.stats: - # Throw out everything but the leader in each GSV group - if timing.tag[-3:] == "GSV" and last_command[-3:] == "GSV": - continue - last_command = timing.tag - # Record timings - received = timing.d_received() - if not timing.tag in intervals: - intervals[timing.tag] = [] - if timing.tag in last_seen: - intervals[timing.tag].append(roundoff(received - last_seen[timing.tag])) - last_seen[timing.tag] = received - - # Step three: get command frequencies and the basic send cycle time - frequencies = {} - for (key, interval_list) in intervals.items(): - frequencies[key] = {} - for interval in interval_list: - frequencies[key][interval] = frequencies[key].get(interval, 0) + 1 - # filter out noise - for key in frequencies: - distribution = frequencies[key] - for interval in distribution.keys(): - if distribution[interval] < 2: - del distribution[interval] - cycles = {} - for key in frequencies: - distribution = frequencies[key] - if len(frequencies[key].values()) == 1: - # The value is uniqe after filtering - cycles[key] = distribution.keys()[0] - else: - # Compute the mode - maxfreq = 0 - for (interval, frequency) in distribution.items(): - if distribution[interval] > maxfreq: - cycles[key] = interval - maxfreq = distribution[interval] - msg += "Cycle report %s, %s, %dN%d, cycle %ds" % \ - (title, - session.gps_id, session.baudrate, - session.stopbits, session.cycle) - msg += "The sentence set emitted by this GPS is: %s\n" % " ".join(intervals.keys()) - for key in cycles: - if len(frequencies[key].values()) == 1: - if cycles[key] == 1: - msg += "%s: is emitted once a second.\n" % key - else: - msg += "%s: is emitted once every %d seconds.\n" % (key, cycles[key]) - else: - if cycles[key] == 1: - msg += "%s: is probably emitted once a second.\n" % key - else: - msg += "%s: is probably emitted once every %d seconds.\n" % (key, cycles[key]) - sendcycle = min(*cycles.values()) - if sendcycle == 1: - msg += "Send cycle is once per second.\n" - else: - msg += "Send cycle is once per %d seconds.\n" % sendcycle - return msg - -formatters = (spaceplot, uninstrumented, rawplot, splitplot, cycle) +formatters = (spaceplot, uninstrumented) def plotframe(await, fname, speed, threshold, title): "Return a string containing a GNUplot script " diff --git a/gpsprof.xml b/gpsprof.xml index a46a9b53..0daa841e 100644 --- a/gpsprof.xml +++ b/gpsprof.xml @@ -34,12 +34,12 @@ BSD terms apply: see the file COPYING in the distribution root for details. <refsect1 id='description'><title>DESCRIPTION</title> -<para><application>gpsprof</application> measures the various -latencies between a GPS and its client. It emits to standard output a -GNUPLOT program that draws an illustrative graph. It can also be told -to emit the raw profile data. The information it provides can be -useful for establishing an upper bound on latency, and thus on -position accuracy of a GPS in motion.</para> +<para><application>gpsprof</application> performs accuracy and latency +profiling onm a GPS. It emits to standard output a GNUPLOT program +that draws an illustrative graph. It can also be told to emit the raw +profile data. The information it provides can be useful for +establishing an upper bound on latency, and thus on position accuracy +of a GPS in motion.</para> <para><application>gpsprof</application> uses instrumentation built into <application>gpsd</application>.</para> @@ -77,60 +77,9 @@ This is the default.</para> <listitem> <para>Plot total latency without instrumentation. Useful mainly as a check that the instrumentation is not producing significant -distortion. It only plots times for sentences that contain fixes; +distortion. It only plots times for reports that contain fixes; staircase-like artifacts in the plot are created when elapsed time -from sentences without fixes is lumped in.</para> -</listitem> -</varlistentry> -<varlistentry> -<term>raw</term> -<listitem> -<para>Plot raw data.</para> -</listitem> -</varlistentry> -<varlistentry> -<term>split</term> -<listitem> -<para>Each sentence has its RS232 latency time colored differently.</para> -</listitem> -</varlistentry> -<varlistentry> -<term>cycle</term> -<listitem> -<para>Report on the set of sentences or packets emitted by the GPS, -their send intervals, and the basic cycle time. (This report is -plain text rather than a gnuplot script.)</para> -</listitem> -</varlistentry> -</variablelist> - -<para>The instrumented time plot conveys the following information:</para> - -<variablelist> -<varlistentry> -<term>RS232 time</term> -<listitem> -<para>Time required to send the sentence from the GPS to -<application>gpsd</application>. This measured from the time of -the last zero-length read before the packet to when the packet sniffer -recognizes a complete sentence, so there is a small amount of -computational overhead mixed in.</para> -</listitem> -</varlistentry> -<varlistentry> -<term>Decode time</term> -<listitem> -<para>Elapsed time between sentence reception and the moment that -<application>gpsd</application> ships the resulting update to -the profiling client.</para> -</listitem> -</varlistentry> -<varlistentry> -<term>TCP/IP latency</term> -<listitem> -<para>Elapsed time between the moment that -<application>gpsd</application> ships the update to -the profiling client and the moment it is decoded and timestamped.</para> +from reports without fixes is lumped in.</para> </listitem> </varlistentry> </variablelist> @@ -294,6 +294,15 @@ timestamp_t timestamp(void) return (timestamp_t)(tv.tv_sec + tv.tv_usec * 1e-6); } +#ifdef TIMING_ENABLE +timestamp_t realtimestamp(void) +{ + struct timespec ts; + (void)clock_gettime(CLOCK_REALTIME, &ts); + return (timestamp_t)(ts.tv_sec + ts.tv_nsec * 1e-9); +} +#endif /* TIMING_ENABLE */ + time_t mkgmtime(register struct tm * t) /* struct tm to seconds since Unix epoch */ { diff --git a/libgpsd_core.c b/libgpsd_core.c index ff364f2e..0f60100e 100644 --- a/libgpsd_core.c +++ b/libgpsd_core.c @@ -810,10 +810,10 @@ gps_mask_t gpsd_poll(struct gps_device_t *session) gps_clear_fix(&session->newdata); -#ifdef TIMING_ENABLE - if (session->packet.outbuflen == 0) - session->d_xmit_time = timestamp(); -#endif /* TIMING_ENABLE */ + /* + * If we ever want a start-of-packet timestamp again, take it here + * with a test that session->packet.outbuflen is zero. + */ if (session->packet.type >= COMMENT_PACKET) { /*@-shiftnegative@*/ @@ -890,10 +890,6 @@ gps_mask_t gpsd_poll(struct gps_device_t *session) gpsd_report(LOG_RAW + 3, "Accepted packet on %s.\n", session->gpsdata.dev.path); -#ifdef TIMING_ENABLE - session->d_recv_time = timestamp(); -#endif /* TIMING_ENABLE */ - /* track the packet count since achieving sync on the device */ if (first_sync) { speed_t speed = gpsd_get_speed(&session->ttyset); @@ -997,10 +993,6 @@ gps_mask_t gpsd_poll(struct gps_device_t *session) session->fixcnt++; } -#ifdef TIMING_ENABLE - session->d_decode_time = timestamp(); -#endif /* TIMING_ENABLE */ - /* * Sanity check. This catches a surprising number of port and * driver errors, including 32-vs.-64-bit problems. diff --git a/www/hacking.html b/www/hacking.html index 9179470d..ae602ac8 100644 --- a/www/hacking.html +++ b/www/hacking.html @@ -491,51 +491,22 @@ only, suspicion should focus here.</p> <h2 id="profiling">Profiling</h2> <p>There is a barely-documented timing policy flag in the WATCH -command that will cause it to emit a TIMING object on every sentence. -The TIMING response contains the following attributed:</p> +command that will cause it to that will cause it to emit timing +information on every TPV. Presently there is exactly one +such member:</p> <ol> -<li>tag: An identifying sentence tag.</li> - -<li>len: The character length of the sentence containing the timestamp - data.</li> - -<li>timebase: The timestamp associated with the sentence, in seconds since - the Unix epoch (this time <em>is</em> leap-second corrected, like UTC). - This timestamp may be zero. If nonzero, it is the base time for - the packet.</li> - -<li>xmit: An offset from the timestamp telling when gpsd believes the - transmission of the current packet started (this is actually - recorded just before the first read of the new packet). If - the sentence timestamp was zero, this offset is a full timestamp - and the base time of the packet.</li> - -<li>recv: An offset from the base time telling when <code>gpsd</code> - received the last bytes of the packet.</li> - -<li>decode: An offset from the base time telling when gpsd decoded the - data.</li> - -<li>poll: An offset from the base time taken just before encoding the - response — effectively, when gpsd was polled to transmit the - data.</li> - -<li>elapsed: An offset from the base time to the time of the TIMING emission.</li> +<li><p>xmit_time: the time at which the daemon created the TPV for +transmission.</p></li> </ol> -<p>The TIMING figures measure components of the latency between the GPS's +<p>Thes attributes measure components of the latency between the GPS's time measurement and when the sentence data became available to the -client. For them to be meaningful, the GPS has to ship timestamps with -sub-second precision. SiRF-II and Evermore chipsets ship times with -millisecond resolution. Your machine's time reference must also be -accurate to subsecond precision; I recommend using <code>ntpd</code>, -which will normally give you about 15 microseconds precision (two -orders of magnitude better than GPSes report).</p> - -<p>Note, some inaccuracy is introduced into the start- and end-of-packet -timestamps by the fact that the last read of a packet may grab a few -bytes of the next one.</p> +client. They are collected using get_realtime(3), so they are not +subject to corrections from ntpd. For the latencty timing to be +meaningful, the GPS has to ship timestamps with sub-second +precision. SiRF-II and Evermore chipsets ship times with millisecond +resolution.</p> <p>The distribution includes a Python script, <code>gpsprof</code>, that uses the timing support to collect profiling information from a |