Changeset 11187 in ntrip for trunk/BNC/src

Timestamp:

Nov 9, 2026, 5:37:55 PM (6 hours ago)

Author:

stuerze

Message:

Structured logging improved

Location:

trunk/BNC/src

Files:

• bnccore.cpp (modified) (5 diffs)
• bnccore.h (modified) (3 diffs)
• bncgetthread.cpp (modified) (1 diff)
• bnchelp.html (modified) (7 diffs)
• bnclog.cpp (modified) (4 diffs)
• bnclog.h (modified) (4 diffs)
• bncwindow.cpp (modified) (1 diff)
• pppRun.cpp (modified) (1 diff)

trunk/BNC/src/bnccore.cpp

@@ -43 +43 @@
 #include <QMessageBox>
 #include <cmath>
+#ifndef Q_OS_WIN
+#include <sys/stat.h>
+#endif
 
 #include "bnccore.h"
@@ -72 +75 @@
   _logStream   = 0;
   _logFileStructured  = 0;
+  _logStructuredInit  = false;
   _logFormatStructured = t_logRecord::json;
   _logLevelStructured  = t_logRecord::debug;
@@ -195 +199 @@
     delete _logStream; _logStream = 0;
     delete _logFile;   _logFile   = 0;
-    delete _logFileStructured; _logFileStructured = 0;
     _logFileFlag = 1;
     _fileDate = currDate;
@@ -214 +217 @@
       _logStream->setDevice(_logFile);
     }
-    QString structName = settings.value("logFileStructured").toString();
-    if ( !structName.isEmpty() ) {
-      expandEnvVar(structName);
+  }
+
+  // Structured logfile: one endless file (rotation by external tools)
+  // ---------------------------------------------------------------
+  if (!_logStructuredInit) {
+    _logStructuredInit = true;
+    bncSettings settings;
+    _logFileStructuredName = settings.value("logFileStructured").toString();
+    if (!_logFileStructuredName.isEmpty()) {
+      expandEnvVar(_logFileStructuredName);
       _logFormatStructured = t_logRecord::formatFromString(
                                settings.value("logFormatStructured").toString());
       _logLevelStructured  = t_logRecord::levelFromString(
                                settings.value("logLevelStructured").toString());
-      _logFileStructured = new QFile(structName + "_" + currDate.toString("yyMMdd"));
-      if (!_logFileStructured->open(append ? (QIODevice::WriteOnly | QIODevice::Append)
-                                           : QIODevice::WriteOnly)) {
-        delete _logFileStructured; _logFileStructured = 0;
-      }
-    }
+      openLogFileStructured();
+    }
+  }
+  else if (!_logFileStructuredName.isEmpty() && _logStructuredCheck.hasExpired(1000)) {
+    openLogFileStructured();   // reopens only if the file was moved or removed
   }
 
@@ -244 +253 @@
     _logFileStructured->write(rec.encode(_logFormatStructured, currDateTime) + "\n");
     _logFileStructured->flush();
+  }
+}
+
+// Open the structured logfile, or reopen it after an external rotation
+// (logrotate without copytruncate moves the file and the old one must be
+// released); always appending, also after copytruncate
+////////////////////////////////////////////////////////////////////////////
+void t_bncCore::openLogFileStructured() {
+  _logStructuredCheck.start();
+  if (_logFileStructured) {
+    bool same = _logFileStructured->exists();
+#ifndef Q_OS_WIN
+    if (same) {
+      struct stat stPath, stOpen;
+      same = (stat(QFile::encodeName(_logFileStructuredName).constData(), &stPath) == 0 &&
+              fstat(_logFileStructured->handle(), &stOpen) == 0 &&
+              stPath.st_dev == stOpen.st_dev && stPath.st_ino == stOpen.st_ino);
+    }
+#endif
+    if (same) {
+      return;
+    }
+    delete _logFileStructured; _logFileStructured = 0;
+  }
+  _logFileStructured = new QFile(_logFileStructuredName);
+  if (!_logFileStructured->open(QIODevice::WriteOnly | QIODevice::Append)) {
+    delete _logFileStructured; _logFileStructured = 0;
   }
 }

trunk/BNC/src/bnccore.h

@@ -25 +25 @@
 #ifndef BNCAPP_H
 #define BNCAPP_H
+
+#include <QElapsedTimer>
 
 #include "bnctime.h"
@@ -183 +185 @@
                        const QString& strV4);
   void  messagePrivate(const t_logRecord& rec);
+  void  openLogFileStructured();
 
   QSettings::SettingsMap _settings;
@@ -189 +192 @@
   int                    _logFileFlag;
   QFile*                 _logFileStructured;
+  QString                _logFileStructuredName;
+  bool                   _logStructuredInit;
+  QElapsedTimer          _logStructuredCheck;
   t_logRecord::e_format  _logFormatStructured;
   t_logRecord::e_level   _logLevelStructured;

trunk/BNC/src/bncgetthread.cpp

@@ -840 +840 @@
         t_logRecord rec(t_logRecord::info, "stream", "stream_content", _staID,
                         _staID + ": Received message type " + type.toLatin1() +  size.toLatin1());
+        rec.setStructuredMsg("Received message");
         rec.add("message_type", int(decoder()->_typeList[ii]._type));
         if (decoder()->_typeList[ii]._size) {

trunk/BNC/src/bnchelp.html

@@ -2787 +2787 @@
     For log processing tools (e.g. Grafana Loki, Elasticsearch, Vector, jq), BNC can write the same records in
     addition into a structured logfile: specify its path in the 'Structured logfile' field and select the format,
-    'json' for one JSON object per line (JSON Lines) or 'logfmt' for key=value pairs separated by blanks. As for the
-    logfile, the name is extended by '_YYMMDD'. The logfile itself remains unchanged, so existing scripts reading it
-    keep working. Default is an empty option field, meaning that no structured logfile is written. 'Min. level'
+    'json' for one JSON object per line (JSON Lines) or 'logfmt' for key=value pairs separated by blanks. Unlike the
+    logfile, the structured logfile is one file without date in its name, always appended (also without 'Append
+    files'), meant to be rotated by an external tool such as logrotate: if the file is moved or removed, BNC
+    continues with a new file of the same name within one second; 'copytruncate' works as well. The logfile itself
+    remains unchanged, so existing scripts reading it keep working. Default is an empty option field, meaning that no structured logfile is written. 'Min. level'
     restricts the structured logfile to records of at least the selected level: 'debug' (default) writes all records,
     'info' leaves out the debug records, 'warning' writes warnings and errors, 'error' errors only.
@@ -2798 +2800 @@
   <ul>
     <li>'time': time of the record in UTC, ISO 8601 with 'Z', e.g. '2025-11-17T13:49:40.000Z',</li>
-    <li>'gpst': the same time in GPS Time (as the time stamps of the logfile), e.g. '2025-11-17T13:49:58.000',</li>
+    <li>'epoch': GPS Time of the data epoch the record refers to, ISO 8601 without 'Z', e.g. '2025-11-17T13:49:10.000';
+        only in records of an epoch ('ppp_position', 'ppp_epoch_failed'),</li>
     <li>'level': 'debug', 'info', 'warning' or 'error'; debug records exist only in BNC versions built with the
         defines BNC_DEBUG_BCE, BNC_DEBUG_OBS or BNC_DEBUG_CMB (src/src.pri),</li>
@@ -2806 +2809 @@
         (SSR QC), or 'bnc' for general messages,</li>
     <li>'event': the kind of record, see below, or 'message' for general messages,</li>
-    <li>'stream': the stream (mountpoint) or the PPP station, if known,</li>
+    <li>'mp': the mountpoint of the stream or the PPP station, if known,</li>
     <li>the fields of the event,</li>
-    <li>'msg': the text of the record in the logfile,</li>
+    <li>'msg': the text of the record in the logfile (shortened where the fields carry the details),</li>
     <li>'v': the version of the record layout, currently 1.</li>
   </ul>
@@ -2815 +2818 @@
   </p>
   <ul>
-    <li>'ppp_position': 'epoch' (GPS Time), 'x', 'y', 'z', 'dn', 'de', 'du', 'trp0', 'trp', 'trp_stdev', 'num_sat',
+    <li>'ppp_position': 'x', 'y', 'z', 'dn', 'de', 'du', 'trp0', 'trp', 'trp_stdev', 'num_sat',
         'hdop', 'fixed' (true/false), 'fix_percent'; 'ppp_epoch_failed' (warning) if no solution was computed,</li>
     <li>'stream_format': 'decoder' (RTCM2, RTCM3, ZERO, ZERO2FILE, RTNET) and 'format' (format entry of the stream),</li>
@@ -2821 +2824 @@
     <li>'stream_content': content of the stream found by the RTCM scan (see section <a href=#miscscan>2.12.3</a>), e.g. observation
         types, antenna and receiver descriptors, antenna coordinates, GLONASS slots, CRS and Helmert parameters; for the
-        received message types with the fields 'message_type' and, if known, 'size' (bytes),</li>
+        received message types with the fields 'message_type' and, if known, 'size' (bytes) and the short 'msg'
+        'Received message' (logfile: 'Received message type 1127 (size 618)'),</li>
     <li>'stream_outage_begin' (warning), 'stream_corrupted_begin' (warning): 'since' (UTC);
         'stream_outage_end', 'stream_corrupted_end': 'ended' and 'since' (UTC),</li>
@@ -2839 +2843 @@
   </p>
   <pre><p style="font-family:Monospace">
-{"time":"2025-11-17T13:48:51.000Z","gpst":"2025-11-17T13:49:09.000","level":"info","component":"stream","event":"stream_format","stream":"BCEP00BKG0","decoder":"RTCM3","format":"RTCM_3.3","msg":"BCEP00BKG0: Get data in RTCM 3.x format","v":1}
-{"time":"2025-11-17T13:49:40.000Z","gpst":"2025-11-17T13:49:58.000","level":"info","component":"ppp","event":"ppp_position","stream":"WTZR00DEU0","epoch":"2025-11-17T13:49:10.000","x":4075580.2172,"y":931854.1555,"z":4801568.3403,"dn":0.0000,"de":0.0000,"du":0.0001,"trp0":2.1833,"trp":0.0019,"trp_stdev":0.0993,"num_sat":17,"hdop":0.59,"fixed":false,"fix_percent":0,"msg":"2025-11-17_13:49:10.000 WTZR00DEU0 X = 4075580.2172 ...","v":1}
+{"time":"2025-11-17T13:48:51.000Z","level":"info","component":"stream","event":"stream_format","mp":"BCEP00BKG0","decoder":"RTCM3","format":"RTCM_3.3","msg":"BCEP00BKG0: Get data in RTCM 3.x format","v":1}
+{"time":"2025-11-17T13:49:40.000Z","epoch":"2025-11-17T13:49:10.000","level":"info","component":"ppp","event":"ppp_position","mp":"WTZR00DEU0","x":4075580.2172,"y":931854.1555,"z":4801568.3403,"dn":0.0000,"de":0.0000,"du":0.0001,"trp0":2.1833,"trp":0.0019,"trp_stdev":0.0993,"num_sat":17,"hdop":0.59,"fixed":false,"fix_percent":0,"msg":"2025-11-17_13:49:10.000 WTZR00DEU0 X = 4075580.2172 ...","v":1}
 </pre>
   </p>
@@ -2847 +2851 @@
   </p>
   <pre><p style="font-family:Monospace">
-time=2025-11-17T13:48:51.000Z gpst=2025-11-17T13:49:09.000 level=info component=stream event=stream_format stream=BCEP00BKG0 decoder=RTCM3 format=RTCM_3.3 msg="BCEP00BKG0: Get data in RTCM 3.x format" v=1
-time=2025-11-17T13:49:40.000Z gpst=2025-11-17T13:49:58.000 level=info component=ppp event=ppp_position stream=WTZR00DEU0 epoch=2025-11-17T13:49:10.000 x=4075580.2172 y=931854.1555 z=4801568.3403 dn=0.0000 de=0.0000 du=0.0001 trp0=2.1833 trp=0.0019 trp_stdev=0.0993 num_sat=17 hdop=0.59 fixed=false fix_percent=0 msg="2025-11-17_13:49:10.000 WTZR00DEU0 X = 4075580.2172 ..." v=1
+time=2025-11-17T13:48:51.000Z level=info component=stream event=stream_format mp=BCEP00BKG0 decoder=RTCM3 format=RTCM_3.3 msg="BCEP00BKG0: Get data in RTCM 3.x format" v=1
+time=2025-11-17T13:49:40.000Z epoch=2025-11-17T13:49:10.000 level=info component=ppp event=ppp_position mp=WTZR00DEU0 x=4075580.2172 y=931854.1555 z=4801568.3403 dn=0.0000 de=0.0000 du=0.0001 trp0=2.1833 trp=0.0019 trp_stdev=0.0993 num_sat=17 hdop=0.59 fixed=false fix_percent=0 msg="2025-11-17_13:49:10.000 WTZR00DEU0 X = 4075580.2172 ..." v=1
 </pre>
   </p>

trunk/BNC/src/bnclog.cpp

@@ -21 +21 @@
 #include "bnclog.h"
 #include "bncutils.h"
+#include "bnctime.h"
 
 namespace {
@@ -211 +212 @@
 //
 ////////////////////////////////////////////////////////////////////////////
+t_logRecord& t_logRecord::setEpoch(const bncTime& epoch) {
+  if (epoch.valid()) {
+    _epoch = QByteArray((epoch.datestr() + 'T' + epoch.timestr(3)).c_str());
+  }
+  else {
+    _epoch.clear();
+  }
+  return *this;
+}
+
+//
+////////////////////////////////////////////////////////////////////////////
 const char* t_logRecord::levelString(e_level level) {
   switch (level) {
@@ -254 +267 @@
   QDateTime utc = gpst.addSecs(-gnumleap(dd.year(), dd.month(), dd.day()));
 
-  QByteArray msg = _msg;
+  QByteArray msg = _msgStructured.isEmpty() ? _msg : _msgStructured;
   while (msg.startsWith('\n')) {
     msg.remove(0, 1);
@@ -266 +279 @@
   };
   put("time",      utc.toString("yyyy-MM-ddThh:mm:ss.zzz").toLatin1() + "Z", true);
-  put("gpst",      gpst.toString("yyyy-MM-ddThh:mm:ss.zzz").toLatin1(), true);
+  if (!_epoch.isEmpty()) {
+    put("epoch",   _epoch, true);
+  }
   put("level",     levelString(_level), true);
   put("component", _component, true);
   put("event",     _event, true);
   if (!_stream.isEmpty()) {
-    put("stream", _stream, true);
+    put("mp", _stream, true);
   }
   all += _fields;

trunk/BNC/src/bnclog.h

@@ -31 +31 @@
 #include <QVector>
 
+class bncTime;
+
 // One record of the structured logfile (option logFileStructured).
 //
@@ -36 +38 @@
 // logfile gets one line per record, JSON (JSON Lines) or logfmt:
 //
-//   time gpst level component event [stream] [fields ...] msg v
+//   time [epoch] level component event [mp] [fields ...] msg v
+//
+// mp: mountpoint of the stream or PPP station (member _stream)
+//
+// time: time of the record in UTC; epoch: GPS Time of the data epoch the
+// record refers to (e.g. PPP position), only if set (setEpoch())
 //
 // Messages that are still emitted as plain text (newMessage(QByteArray,bool))
@@ -75 +82 @@
   t_logRecord& addTime(const char* key, const QDateTime& utc);   // ISO 8601, "Z"
 
-  // one line without line end; gpst: time of the record in GPS time
+  // shorter text for the structured logfile only, e.g. if the fields carry
+  // the details; the classic logfile keeps _msg
+  t_logRecord& setStructuredMsg(const QByteArray& msg) { _msgStructured = msg; return *this; }
+
+  // data epoch of the record (GPS Time, ISO 8601 without "Z"), key "epoch"
+  t_logRecord& setEpoch(const bncTime& epoch);
+
+  // one line without line end; gpst: time of the record in GPS Time,
+  // written as UTC (key "time")
   QByteArray encode(e_format format, const QDateTime& gpst) const;
 
@@ -89 +104 @@
   QByteArray _component;
   QByteArray _event;
+  QByteArray _epoch;
   QByteArray _stream;
   QByteArray _msg;
+  QByteArray _msgStructured;
 
  private:

trunk/BNC/src/bncwindow.cpp

@@ -1589 +1589 @@
   // ------------------
   _logFileLineEdit->setWhatsThis(tr("<p>Records of BNC's activities are shown in the 'Log' tab on the bottom of this window. They can be saved into a file when a valid path for that is specified in the 'Logfile (full path)' field.</p><p>The logfile name will automatically be extended by a string '_YYMMDD' carrying the current date. <i>[key: logFile]</i></p>"));
-  _logFileStructuredLineEdit->setWhatsThis(tr("<p>In addition to the logfile, BNC can write the same records as a structured logfile for log processing tools: one record per line, either JSON (JSON Lines) or logfmt (key=value pairs separated by blanks). Each record carries the time in UTC ('time', ISO 8601 with 'Z') and in GPS time ('gpst'), a level (debug, info, warning, error), the component (e.g. stream, ppp, cmb), the event (e.g. ppp_position, stream_outage_begin), the stream (mountpoint) or PPP station if known, the event's fields, the text of the classic logfile ('msg') and the record version ('v').</p><p>Messages without own event are written with event 'message' and the component of their origin; their level is error (a function does not work), warning (data or configuration problem, BNC continues) or info (status). The logfile itself remains unchanged.</p><p>The file name will automatically be extended by a string '_YYMMDD' carrying the current date. Default is an empty option field, meaning that no structured logfile is written. <i>[key: logFileStructured]</i></p>"));
+  _logFileStructuredLineEdit->setWhatsThis(tr("<p>In addition to the logfile, BNC can write the same records as a structured logfile for log processing tools: one record per line, either JSON (JSON Lines) or logfmt (key=value pairs separated by blanks). Each record carries the time in UTC ('time', ISO 8601 with 'Z'), for records of a data epoch its GPS Time ('epoch'), a level (debug, info, warning, error), the component (e.g. stream, ppp, cmb), the event (e.g. ppp_position, stream_outage_begin), the mountpoint ('mp') of the stream or the PPP station if known, the event's fields, the text of the classic logfile ('msg') and the record version ('v').</p><p>Messages without own event are written with event 'message' and the component of their origin; their level is error (a function does not work), warning (data or configuration problem, BNC continues) or info (status). The logfile itself remains unchanged.</p><p>The structured logfile is one file without date in its name, always appended, to be rotated by an external tool like logrotate (BNC continues with a new file if it is moved or removed). Default is an empty option field, meaning that no structured logfile is written. <i>[key: logFileStructured]</i></p>"));
   _logFormatStructuredComboBox->setWhatsThis(tr("<p>Select the format of the structured logfile: 'json' for one JSON object per line (JSON Lines), 'logfmt' for key=value pairs. Default is 'json'. <i>[key: logFormatStructured]</i></p>"));
   _logLevelStructuredComboBox->setWhatsThis(tr("<p>Select the minimum level of the records written into the structured logfile: 'debug' writes all records (debug records exist only in BNC versions built with the BNC_DEBUG_* defines), 'info' leaves out the debug records, 'warning' writes warnings and errors only, 'error' errors only. The logfile is not affected. Default is 'debug'. <i>[key: logLevelStructured]</i></p>"));

trunk/BNC/src/pppRun.cpp

@@ -465 +465 @@
       }
       if (output._error) {
-        emit newLogRecord(t_logRecord(t_logRecord::warning, "ppp", "ppp_epoch_failed",
-                                      staID, QByteArray(log.str().c_str())), true);
+        t_logRecord rec(t_logRecord::warning, "ppp", "ppp_epoch_failed", staID,
+                        QByteArray(log.str().c_str()));
+        rec.setEpoch(output._epoTime);
+        emit newLogRecord(rec, true);
       }
       else {
         t_logRecord rec(t_logRecord::info, "ppp", "ppp_position", staID,
                         QByteArray(log.str().c_str()));
-        rec.add("epoch", QByteArray((output._epoTime.datestr() + 'T' +
-                                     output._epoTime.timestr(3)).c_str()))
+        rec.setEpoch(output._epoTime)
            .add("x", output._xyzRover[0], 4)
            .add("y", output._xyzRover[1], 4)