Changeset 11187 in ntrip for trunk/BNC/tests/tools

Timestamp:

Nov 9, 2026, 5:37:55 PM (2 days ago)

Author:

stuerze

Message:

Structured logging improved

File:

• trunk/BNC/tests/tools/logcheck.py (modified) (5 diffs)

trunk/BNC/tests/tools/logcheck.py

@@ -6 +6 @@
 Checks that every line of the JSON file is a JSON object and every line of the
 logfmt file a sequence of key=value pairs, that both carry the same records,
-that the records have the mandatory keys in the documented order, that 'time'
-(UTC) is 'gpst' minus the GPS-UTC leap seconds and that the 'msg' of the
-records equals the text of the classic logfile line by line (classic lines
-without their "yy-mm-dd hh:mm:ss " prefix; the start line is skipped, it goes
-to the file of the current date). Prints a summary of the records per level,
+that the records have the mandatory keys in the documented order (optional
+'epoch' after 'time', GPS Time without 'Z'), that the 'msg' of the records
+(for RTCM scan message types: 'mp', 'message_type', 'size') equals the text of
+the classic logfile line by line (classic lines without
+their "yy-mm-dd hh:mm:ss " prefix; the start line is skipped, it goes to the
+file of the current date) and that 'time' (UTC) is the GPS Time stamp of the
+classic line minus the GPS-UTC leap seconds. Prints a summary of the records per level,
 component and event; exit code 1 on any error.
 """
@@ -20 +22 @@
 import sys
 
-HEAD = ["time", "gpst", "level", "component", "event"]
+HEAD = ["time", "level", "component", "event"]
 LEVELS = {"info", "warning", "error"}
 LEAP_GPS_UTC = 18          # valid since 2017-01-01
@@ -68 +70 @@
 
 
+def classic_text(r):
+    """Text of the classic logfile line of a record: 'msg', except for the
+    message types of the RTCM scan, which carry the short text 'Received message'
+    and the details in their fields."""
+    if r.get("event") == "stream_content" and "message_type" in r:
+        if r["msg"] != "Received message":
+            return "unexpected msg %r" % r["msg"]
+        size = " (size %d)" % r["size"] if "size" in r else " "
+        return "%s: Received message type %d%s" % (r["mp"], r["message_type"], size)
+    return r.get("msg")
+
+
 def main():
     errors = []
-    classic = []
+    classic, stamps = [], []
     for line in open(sys.argv[1], encoding="latin-1", newline="").read().split("\r\n"):
         if not line or "========== Start BNC" in line:
             continue
-        classic.append(line[18:] if re.match(r"\d\d-\d\d-\d\d \d\d:\d\d:\d\d ", line) else line)
+        if re.match(r"\d\d-\d\d-\d\d \d\d:\d\d:\d\d ", line):
+            classic.append(line[18:])
+            stamps.append(datetime.datetime.strptime(line[:17], "%y-%m-%d %H:%M:%S"))
+        else:
+            classic.append(line)
+            stamps.append(None)
 
     recs = []
@@ -92 +111 @@
             errors.append("json %d records, logfmt %d" % (len(recs), len(lf)))
         for k, (a, b) in enumerate(zip(recs, lf), 1):
-            if list(a.keys()) != list(b.keys()) or any(a[x] != b[x] for x in a):
+            # the start line carries the wall clock time of each run
+            start = "========== Start BNC" in a.get("msg", "")
+            if list(a.keys()) != list(b.keys()) or any(a[x] != b[x] for x in a
+                                                        if not (start and x == "time")):
                 errors.append("record %d differs between json and logfmt" % k)
 
@@ -98 +120 @@
     for k, r in enumerate(recs, 1):
         keys = list(r.keys())
-        if keys[:5] != HEAD or keys[-2:] != ["msg", "v"]:
+        if keys[1:2] == ["epoch"]:
+            try:
+                datetime.datetime.strptime(r["epoch"], "%Y-%m-%dT%H:%M:%S.%f")
+            except ValueError:
+                errors.append("record %d: epoch %s" % (k, r["epoch"]))
+            keys = keys[:1] + keys[2:]
+        if keys[:4] != HEAD or keys[-2:] != ["msg", "v"]:
             errors.append("record %d: keys %s" % (k, keys))
             continue
         if r["level"] not in LEVELS:
             errors.append("record %d: level %s" % (k, r["level"]))
-        utc = datetime.datetime.strptime(r["time"], "%Y-%m-%dT%H:%M:%S.%fZ")
-        gps = datetime.datetime.strptime(r["gpst"], "%Y-%m-%dT%H:%M:%S.%f")
-        if (gps - utc).total_seconds() != LEAP_GPS_UTC:
-            errors.append("record %d: time %s gpst %s" % (k, r["time"], r["gpst"]))
         count[(r["level"], r["component"], r["event"])] += 1
 
-    msgs = [r.get("msg") for r in recs if "========== Start BNC" not in r.get("msg", "")]
+    body = [r for r in recs if "========== Start BNC" not in r.get("msg", "")]
+    msgs = [classic_text(r) for r in body]
+    for k, (r, st) in enumerate(zip(body, stamps), 1):
+        utc = datetime.datetime.strptime(r["time"], "%Y-%m-%dT%H:%M:%S.%fZ")
+        if st is not None and (st - utc.replace(microsecond=0)).total_seconds() != LEAP_GPS_UTC:
+            errors.append("record %d: time %s, classic %s" % (k, r["time"], st))
     if msgs != classic:
         for k, (a, b) in enumerate(zip(msgs, classic), 1):