venus/dbus-anchor-alarm/debug_logger.py

"""
Optional SQLite debug logger — default OFF.

Controlled at runtime via /Settings/DebugLogging D-Bus path.
When enabled, logs raw_points and estimation_log at the tracker rate (1/15s)
with buffered commits (flush every FLUSH_INTERVAL_SEC).

Schema is identical to the original TrackLogger so analysis scripts still work.
"""

import logging
import os
import sqlite3
import time

from config import DATA_DIR

logger = logging.getLogger('dbus-anchor-alarm.debug_logger')

DB_FILE = 'track.db'
FLUSH_INTERVAL_SEC = 30.0
ESTIMATION_LOG_MAX_AGE_SEC = 7 * 86400

_SCHEMA = """
CREATE TABLE IF NOT EXISTS raw_points (
    ts    REAL PRIMARY KEY,
    lat   REAL,
    lon   REAL,
    hdg   REAL,
    cog   REAL,
    spd   REAL,
    ws    REAL,
    wd    REAL,
    dist  REAL,
    depth REAL
);

CREATE TABLE IF NOT EXISTS estimation_log (
    ts              REAL PRIMARY KEY,
    marked_lat      REAL,
    marked_lon      REAL,
    est_lat         REAL,
    est_lon         REAL,
    uncertainty_ft  REAL,
    drift_ft        REAL,
    hdg_est_lat     REAL,
    hdg_est_lon     REAL,
    arc_center_lat  REAL,
    arc_center_lon  REAL,
    arc_radius_ft   REAL,
    arc_residual    REAL,
    arc_coverage    REAL,
    arc_valid       INTEGER,
    arc_point_count INTEGER,
    weight_arc      REAL,
    weight_heading  REAL,
    cat_dist_ft     REAL,
    vessel_lat      REAL,
    vessel_lon      REAL
);
"""


class DebugLogger:
    """SQLite debug logger, only active when explicitly enabled."""

    def __init__(self, data_dir=DATA_DIR):
        self._data_dir = data_dir
        self._conn = None
        self._last_flush = 0.0
        self._pending = 0

    @property
    def active(self):
        return self._conn is not None

    def enable(self):
        """Open SQLite connection and create tables."""
        if self._conn is not None:
            return
        os.makedirs(self._data_dir, exist_ok=True)
        db_path = os.path.join(self._data_dir, DB_FILE)
        self._conn = sqlite3.connect(db_path, check_same_thread=False)
        self._conn.execute('PRAGMA journal_mode=WAL')
        self._conn.execute('PRAGMA synchronous=NORMAL')
        self._conn.executescript(_SCHEMA)
        self._conn.commit()
        self._last_flush = time.time()
        self._pending = 0
        logger.info('Debug logging enabled -> %s', db_path)

    def disable(self):
        """Flush and close the SQLite connection."""
        if self._conn is None:
            return
        try:
            self._conn.commit()
            self._conn.close()
        except sqlite3.Error:
            logger.exception('Error closing debug logger')
        self._conn = None
        self._pending = 0
        logger.info('Debug logging disabled')

    def log(self, snapshot, tracker):
        """Log both raw point and estimation state in a single call."""
        if self._conn is None:
            return

        ts = snapshot.timestamp or time.time()

        try:
            if snapshot.latitude is not None and snapshot.longitude is not None:
                self._conn.execute(
                    'INSERT OR REPLACE INTO raw_points '
                    '(ts, lat, lon, hdg, cog, spd, ws, wd, dist, depth) '
                    'VALUES (?,?,?,?,?,?,?,?,?,?)',
                    (ts, snapshot.latitude, snapshot.longitude,
                     snapshot.heading, snapshot.course, snapshot.speed,
                     snapshot.wind_speed, snapshot.wind_direction,
                     tracker.estimated_distance_ft, snapshot.depth),
                )
                self._pending += 1

            if tracker.anchor_set:
                self._conn.execute(
                    'INSERT OR REPLACE INTO estimation_log '
                    '(ts, marked_lat, marked_lon, est_lat, est_lon, '
                    'uncertainty_ft, drift_ft, hdg_est_lat, hdg_est_lon, '
                    'arc_center_lat, arc_center_lon, arc_radius_ft, '
                    'arc_residual, arc_coverage, arc_valid, arc_point_count, '
                    'weight_arc, weight_heading, cat_dist_ft, '
                    'vessel_lat, vessel_lon) '
                    'VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)',
                    (ts,
                     tracker.marked_lat, tracker.marked_lon,
                     tracker.estimated_lat, tracker.estimated_lon,
                     tracker.uncertainty_radius_ft, tracker.drift_ft,
                     tracker.last_heading_est_lat, tracker.last_heading_est_lon,
                     tracker.last_arc_center_lat, tracker.last_arc_center_lon,
                     tracker.last_arc_radius_ft, tracker.last_arc_residual,
                     tracker.last_arc_coverage,
                     int(tracker.last_arc_valid),
                     tracker.last_arc_point_count,
                     tracker.last_weight_arc, tracker.last_weight_heading,
                     tracker.estimated_distance_ft,
                     snapshot.latitude, snapshot.longitude),
                )
                self._pending += 1
        except sqlite3.Error:
            logger.exception('Debug log write failed')

        now = time.time()
        if now - self._last_flush >= FLUSH_INTERVAL_SEC and self._pending > 0:
            self._flush(now)

    def _flush(self, now):
        try:
            self._conn.commit()
            cutoff = now - ESTIMATION_LOG_MAX_AGE_SEC
            self._conn.execute('DELETE FROM estimation_log WHERE ts < ?', (cutoff,))
            self._conn.commit()
        except sqlite3.Error:
            logger.exception('Debug logger flush failed')
        self._pending = 0
        self._last_flush = now