diff --git a/README.md b/README.md index 2eb98fe..377277f 100644 --- a/README.md +++ b/README.md @@ -261,12 +261,32 @@ The CLI helps you: |----------|-------------| | `GET /api/display` | Main TRMNL endpoint - returns current image | | `POST /api/log` | Device event logging | -| `POST /api/battery` | Battery telemetry | +| `POST /api/battery` | Battery telemetry (MunichGlance extension, not part of the TRMNL protocol) | | `GET /api/health` | Health check | | `GET /settings` | Current configuration | | `GET /settings/plugins` | List registered plugins | | `GET /docs` | OpenAPI documentation | +### Device protocol notes + +The firmware identifies itself with the **`ID`** header (its MAC address) and +piggybacks telemetry — `Battery-Voltage`, `RSSI`, `FW-Version`, `Refresh-Rate` — +onto every request. Requests without `ID` are served normally but are not +registered as devices. `X-Device-MAC` and `?mac=` work as aliases for custom +clients. + +`POST /api/log` accepts the current firmware payload `{"logs": [...]}`, the older +`{"log": {"logs_array": [...]}}`, and a flat legacy form. Anything else is answered +`200 OK` and logged at WARNING with the raw body, so unknown shapes are visible +instead of silently dropped. + +Battery readings are taken from the telemetry headers and from log entries, at most +one sample per device per 15 minutes. `POST /api/battery` stays available for manual +reporting; stock firmware never calls it. + +Set `LOG_LEVEL=DEBUG` (or `server.log_level` in the config) for per-request device +detail. + ## Architecture ``` diff --git a/config/app-config.yaml b/config/app-config.yaml index e10c54d..abfc04a 100644 --- a/config/app-config.yaml +++ b/config/app-config.yaml @@ -23,6 +23,11 @@ server: # Enable debug mode for development (enables detailed error messages) debug: false + # Root log level: DEBUG, INFO, WARNING, ERROR + # DEBUG adds per-request device detail (identification, telemetry, payloads). + # The LOG_LEVEL environment variable overrides this. + log_level: "INFO" + # Timezone for displaying times (IANA timezone format) # Examples: Europe/Berlin, America/New_York, Asia/Tokyo timezone: "Europe/Berlin" diff --git a/tests/test_device_api.py b/tests/test_device_api.py new file mode 100644 index 0000000..813876f --- /dev/null +++ b/tests/test_device_api.py @@ -0,0 +1,272 @@ +"""Tests for the TRMNL device protocol handling in /api. + +These cover the two regressions that made the server silently lose all device +data: the MAC arriving in the ``ID`` header (not ``X-Device-MAC``), and the +firmware's ``{"logs": [...]}`` log payload. + +Assertions read the SQLite file directly rather than through the async session: +the app owns the event loop the async engine is bound to. +""" + +import sqlite3 + +import pytest +from fastapi import FastAPI +from fastapi.testclient import TestClient +from sqlalchemy import create_engine + +from trmnl_server import database +from trmnl_server.config import ServerConfig +from trmnl_server.database import Base +from trmnl_server.routes import api + +DEVICE_MAC = "AA:BB:CC:DD:EE:FF" +NORMALIZED_MAC = "AABBCCDDEEFF" + + +@pytest.fixture +def db_path(tmp_path, monkeypatch): + """Point the global config at a throwaway database and create the schema.""" + config = ServerConfig(project_root=tmp_path) + config.ensure_directories() + monkeypatch.setattr("trmnl_server.config._config", config, raising=False) + + # The async engine is a module-level singleton; drop it so it is rebuilt + # against this database, inside the app's own event loop. + monkeypatch.setattr(database, "_engine", None) + monkeypatch.setattr(database, "_session_factory", None) + + sync_engine = create_engine(f"sqlite:///{config.db_path}") + Base.metadata.create_all(sync_engine) + sync_engine.dispose() + + return config.db_path + + +@pytest.fixture +def client(db_path): + """A client for the /api router only (no lifespan, no scheduler, no plugins).""" + app = FastAPI() + app.include_router(api.router) + with TestClient(app) as test_client: + yield test_client + + +def rows(db_path, table: str) -> list[sqlite3.Row]: + """All rows of a table, oldest first.""" + connection = sqlite3.connect(db_path) + connection.row_factory = sqlite3.Row + try: + return list(connection.execute(f"SELECT * FROM {table} ORDER BY id")) + finally: + connection.close() + + +def test_mac_from_id_header(client, db_path): + """The stock firmware identifies itself with the ID header.""" + response = client.post( + "/api/log", + headers={"ID": DEVICE_MAC}, + json={"logs": [{"message": "boot", "level": "info"}]}, + ) + + assert response.status_code == 200 + assert [r["mac_address"] for r in rows(db_path, "devices")] == [NORMALIZED_MAC] + + +def test_x_device_mac_header_still_works(client, db_path): + """The legacy header stays supported for custom clients.""" + client.post( + "/api/log", + headers={"X-Device-MAC": DEVICE_MAC}, + json={"logs": [{"message": "boot"}]}, + ) + + assert [r["mac_address"] for r in rows(db_path, "devices")] == [NORMALIZED_MAC] + + +def test_unidentified_device_is_not_registered(client, db_path): + """No ID header must not mint a throwaway device row on every request.""" + for _ in range(3): + client.post("/api/log", json={"logs": [{"message": "hello"}]}) + + assert rows(db_path, "devices") == [] + # The log entries are still kept, under the shared UNKNOWN bucket. + device_logs = rows(db_path, "device_logs") + assert len(device_logs) == 3 + assert {r["device_mac"] for r in device_logs} == {api.UNKNOWN_DEVICE_MAC} + + +def test_terminus_log_payload_is_stored(client, db_path): + """{"logs": [...]} is the shape the current firmware posts.""" + response = client.post( + "/api/log", + headers={"ID": DEVICE_MAC}, + json={ + "logs": [ + { + "id": 1, + "message": "display refresh", + "level": "info", + "source_path": "src/display.cpp", + "source_line": 597, + "firmware_version": "1.7.8", + "battery_voltage": 4.11, + "wifi_signal": -69, + "free_heap_size": 160656, + } + ] + }, + ) + + assert response.status_code == 200 + device_logs = rows(db_path, "device_logs") + assert len(device_logs) == 1 + entry = device_logs[0] + assert entry["device_mac"] == NORMALIZED_MAC + assert entry["message"] == "display refresh" + assert entry["log_type"] == "info" + assert entry["battery_voltage"] == pytest.approx(4.11) + assert entry["wifi_rssi"] == -69 + assert entry["firmware_version"] == "1.7.8" + assert entry["free_heap"] == 160656 + + +def test_battery_reading_extracted_from_log_entry(client, db_path): + """Battery telemetry rides along with the logs - there is no battery endpoint.""" + client.post( + "/api/log", + headers={"ID": DEVICE_MAC}, + json={"logs": [{"message": "wake", "battery_voltage": 4.11, "wifi_signal": -69}]}, + ) + + readings = rows(db_path, "battery_readings") + assert len(readings) == 1 + assert readings[0]["device_mac"] == NORMALIZED_MAC + assert readings[0]["voltage"] == pytest.approx(4.11) + assert readings[0]["rssi"] == -69 + + +def test_battery_sampling_is_throttled(client, db_path): + """A device polls every couple of minutes; only the first sample is kept.""" + for _ in range(3): + client.post( + "/api/log", + headers={"ID": DEVICE_MAC}, + json={"logs": [{"message": "wake", "battery_voltage": 4.11}]}, + ) + + assert len(rows(db_path, "battery_readings")) == 1 + + +def test_legacy_logs_array_payload_still_works(client, db_path): + """Older firmware format must keep working.""" + client.post( + "/api/log", + headers={"ID": DEVICE_MAC}, + json={ + "log": { + "logs_array": [ + { + "log_message": "sleep", + "log_sourcefile": "main.cpp", + "device_status_stamp": { + "current_fw_version": "1.5.2", + "battery_voltage": 3.9, + "wifi_rssi_level": -55, + }, + } + ] + } + }, + ) + + device_logs = rows(db_path, "device_logs") + assert len(device_logs) == 1 + assert device_logs[0]["message"] == "sleep" + assert device_logs[0]["firmware_version"] == "1.5.2" + assert len(rows(db_path, "battery_readings")) == 1 + + +def test_unrecognized_payload_is_logged_not_dropped_silently(client, db_path, caplog): + """An unknown shape must be visible in the logs, with the payload.""" + with caplog.at_level("WARNING"): + response = client.post( + "/api/log", + headers={"ID": DEVICE_MAC}, + json={"something": "entirely different"}, + ) + + assert response.status_code == 200 + assert rows(db_path, "device_logs") == [] + messages = [record.getMessage() for record in caplog.records] + assert any("unrecognized payload" in message for message in messages) + assert any("entirely different" in message for message in messages) + + +def test_telemetry_headers_recorded(client, db_path): + """Battery/RSSI/firmware headers are the firmware's main telemetry channel.""" + client.post( + "/api/log", + headers={ + "ID": DEVICE_MAC, + "Battery-Voltage": "4.05", + "RSSI": "-71", + "FW-Version": "2.1.3", + "Refresh-Rate": "1800", + }, + json={"logs": [{"message": "poll"}]}, + ) + + device = rows(db_path, "devices")[0] + assert device["firmware_version"] == "2.1.3" + assert device["refresh_rate"] == 1800 + + reading = rows(db_path, "battery_readings")[0] + assert reading["voltage"] == pytest.approx(4.05) + assert reading["rssi"] == -71 + + +def test_display_records_device_and_telemetry(client, db_path, monkeypatch): + """/api/display is the highest-traffic endpoint and the main telemetry channel. + + No plugin is registered here, so the handler takes its error branch — the point + is that the device is recorded before any early return. + """ + monkeypatch.setattr(api, "get_primary_plugin_name", lambda: None) + + response = client.get( + "/api/display", + headers={"ID": DEVICE_MAC, "Battery-Voltage": "4.2", "RSSI": "-58"}, + ) + + assert response.status_code == 200 + assert [r["mac_address"] for r in rows(db_path, "devices")] == [NORMALIZED_MAC] + reading = rows(db_path, "battery_readings")[0] + assert reading["voltage"] == pytest.approx(4.2) + assert reading["rssi"] == -58 + + +def test_display_without_id_header_registers_nothing(db_path, client, monkeypatch): + """The old behaviour created one device row per anonymous poll.""" + monkeypatch.setattr(api, "get_primary_plugin_name", lambda: None) + + for _ in range(5): + client.get("/api/display") + + assert rows(db_path, "devices") == [] + + +def test_battery_endpoint_still_accepts_manual_readings(client, db_path): + """The non-standard /api/battery endpoint stays usable for custom clients.""" + response = client.post( + "/api/battery", + headers={"ID": DEVICE_MAC}, + json={"voltage": 3.8, "rssi": -60}, + ) + + assert response.status_code == 200 + readings = rows(db_path, "battery_readings") + assert len(readings) == 1 + assert readings[0]["device_mac"] == NORMALIZED_MAC + assert readings[0]["voltage"] == pytest.approx(3.8) diff --git a/trmnl_server/config.py b/trmnl_server/config.py index 5c11ad5..cb93d86 100644 --- a/trmnl_server/config.py +++ b/trmnl_server/config.py @@ -24,6 +24,7 @@ class ServerConfig: host: str = "0.0.0.0" port: int = 4567 debug: bool = False + log_level: str = "INFO" # DEBUG surfaces per-request device/telemetry detail # Paths project_root: Path = field(default_factory=_get_project_root) @@ -101,6 +102,7 @@ def from_yaml(cls, config_file: str | None = None) -> "ServerConfig": host=loader.get("server", "host", "0.0.0.0"), port=int(loader.get("server", "port", 4567)), debug=debug_val, + log_level=str(loader.get("server", "log_level", "INFO")), refresh_time=int(loader.get("device", "refresh_time", 120)), setup_api_key=loader.get("device", "api_key", ""), setup_friendly_id=loader.get("device", "friendly_id", "munich-glance"), diff --git a/trmnl_server/main.py b/trmnl_server/main.py index 61de155..2a69d18 100644 --- a/trmnl_server/main.py +++ b/trmnl_server/main.py @@ -1,6 +1,7 @@ """FastAPI application for TRMNL BYOS server.""" import logging +import os from contextlib import asynccontextmanager from fastapi import FastAPI, Request @@ -15,11 +16,29 @@ from trmnl_server.services.plugins import register_plugins, schedule_plugins from trmnl_server.services.scheduler import start_scheduler, stop_scheduler -# Configure logging -logging.basicConfig( - level=logging.INFO, - format="%(asctime)s - %(name)s - %(levelname)s - %(message)s", -) + +def _configure_logging() -> None: + """Set the root log level from LOG_LEVEL or server.log_level (default INFO). + + The device handlers log request detail at DEBUG. With the level hardcoded, the + only way to see any of it in a container was to rebuild the image. + """ + level_name = os.getenv("LOG_LEVEL") + if not level_name: + try: + level_name = get_config().log_level + except Exception: # pragma: no cover - config problems surface later + level_name = "INFO" + + level = getattr(logging, level_name.strip().upper(), logging.INFO) + logging.basicConfig( + level=level, + format="%(asctime)s - %(name)s - %(levelname)s - %(message)s", + ) + logging.getLogger().setLevel(level) + + +_configure_logging() logger = logging.getLogger(__name__) diff --git a/trmnl_server/routes/api.py b/trmnl_server/routes/api.py index 871e8b9..e56999f 100644 --- a/trmnl_server/routes/api.py +++ b/trmnl_server/routes/api.py @@ -2,11 +2,12 @@ import logging import uuid -from datetime import datetime, time, timedelta +from datetime import UTC, datetime, time, timedelta from zoneinfo import ZoneInfo from fastapi import APIRouter, Header, Query, Request from pydantic import BaseModel +from sqlalchemy import select from trmnl_server.config import get_config from trmnl_server.database import get_session @@ -22,6 +23,14 @@ logger = logging.getLogger(__name__) router = APIRouter(prefix="/api", tags=["api"]) +# Device MAC used for readings that arrive without any identification. +UNKNOWN_DEVICE_MAC = "UNKNOWN" + +# Minimum spacing between stored battery samples per device. The firmware reports +# telemetry on every poll (~2 min); without throttling battery_readings would grow by +# ~700 rows/day for data that only moves on an hourly scale. +BATTERY_SAMPLE_INTERVAL_SECONDS = 900 + class DisplayResponse(BaseModel): """Response for /api/display endpoint.""" @@ -74,13 +83,45 @@ class LogArray(BaseModel): model_config = {"extra": "allow"} +class TerminusLogEntry(BaseModel): + """Single log entry in the Terminus (current firmware) format. + + Field names follow usetrmnl/terminus doc/api.adoc — the payload the stock + firmware actually posts. Everything is optional: firmware versions differ in + which fields they populate. + """ + + id: int | None = None + message: str | None = None + level: str | None = None + source_path: str | None = None + source_line: int | None = None + created_at: int | None = None + firmware_version: str | None = None + battery_voltage: float | None = None + wifi_signal: int | None = None + wifi_status: str | None = None + free_heap_size: int | None = None + max_alloc_size: int | None = None + wake_reason: str | None = None + sleep_duration: int | None = None + refresh_rate: int | None = None + special_function: str | None = None + retry: int | None = None + + model_config = {"extra": "allow"} + + class LogRequest(BaseModel): """Request body for /api/log endpoint. - Accepts the TRMNL firmware log format: - {"log": {"logs_array": [...]}} + Accepts three shapes, newest first: + 1. Terminus / stock firmware: {"logs": [...]} + 2. Older firmware: {"log": {"logs_array": [...]}} + 3. Legacy flat: {"log_type": "...", "message": "..."} """ + logs: list[TerminusLogEntry] | None = None log: LogArray | None = None # Legacy format support @@ -124,19 +165,162 @@ class SetupResponse(BaseModel): message: str -def _get_device_mac(request: Request, header_mac: str | None = None) -> str: - """Extract device MAC address from request.""" - # Try header first - if header_mac: - return header_mac.upper().replace(":", "") +def _normalize_mac(raw: str) -> str: + """Normalize a MAC to bare uppercase hex (AA:BB:CC -> AABBCC).""" + return raw.strip().upper().replace(":", "").replace("-", "") + + +def _get_device_mac(request: Request, header_mac: str | None = None) -> str | None: + """Resolve the calling device's MAC, or None when it is unidentified. + + The stock TRMNL firmware identifies itself with the ``ID`` header (see + usetrmnl/terminus doc/api.adoc); ``X-Device-MAC`` and ``?mac=`` are kept for + custom clients. Returning None instead of a random ``UNKNOWN-xxxx`` id matters: + the old fallback minted a fresh identity on every poll, so an anonymous device + registered a new row in ``devices`` every couple of minutes. + """ + for raw in (header_mac, request.headers.get("ID"), request.query_params.get("mac")): + if raw and raw.strip(): + return _normalize_mac(raw) + return None + + +def _header_value(request: Request, *names: str) -> str | None: + """First non-empty value among the given (case-insensitive) header names.""" + for name in names: + value: str | None = request.headers.get(name) + if value and value.strip(): + return str(value.strip()) + return None + + +def _as_float(value: str | None) -> float | None: + """Parse a header value as float, tolerating junk from the firmware.""" + if value is None: + return None + try: + return float(value) + except ValueError: + return None + + +def _as_int(value: str | None) -> int | None: + """Parse a header value as int, tolerating floats ("-69.0") and junk.""" + if value is None: + return None + try: + return int(float(value)) + except ValueError: + return None + + +class DeviceTelemetry(BaseModel): + """Device state reported alongside a request. - # Try query param - mac = request.query_params.get("mac", "") - if mac: - return mac.upper().replace(":", "") + The TRMNL protocol has no battery endpoint — the firmware piggybacks battery, + signal and firmware version onto the headers of every /api/display call, and + repeats them inside /api/log entries. + """ + + voltage: float | None = None + rssi: int | None = None + firmware_version: str | None = None + refresh_rate: int | None = None - # Generate a unique ID for unknown devices - return f"UNKNOWN-{uuid.uuid4().hex[:8].upper()}" + def has_reading(self) -> bool: + """True when there is a battery sample worth storing.""" + return self.voltage is not None + + +def _telemetry_from_headers(request: Request) -> DeviceTelemetry: + """Read telemetry headers, accepting both dash and underscore spellings.""" + return DeviceTelemetry( + voltage=_as_float(_header_value(request, "Battery-Voltage", "BATTERY_VOLTAGE")), + rssi=_as_int(_header_value(request, "RSSI", "WIFI-RSSI")), + firmware_version=_header_value(request, "FW-Version", "FW_VERSION"), + refresh_rate=_as_int(_header_value(request, "Refresh-Rate", "REFRESH_RATE")), + ) + + +async def _raw_body_preview(request: Request, limit: int = 1000) -> str: + """Truncated raw request body, for diagnosing unrecognized payloads. + + Safe to call after FastAPI parsed the body — Starlette caches it on the request. + """ + try: + body = await request.body() + except Exception as e: # pragma: no cover - defensive + return f"" + text = bytes(body).decode("utf-8", errors="replace") + return text[:limit] + ("…" if len(text) > limit else "") + + +async def _should_sample_battery(session, mac: str) -> bool: + """True when the last stored reading for this device is old enough.""" + result = await session.execute( + select(BatteryReading.created_at) + .where(BatteryReading.device_mac == mac) + .order_by(BatteryReading.created_at.desc()) + .limit(1) + ) + last: datetime | None = result.scalar_one_or_none() + if last is None: + return True + if last.tzinfo is None: + last = last.replace(tzinfo=UTC) + age = (datetime.now(UTC) - last).total_seconds() + return bool(age >= BATTERY_SAMPLE_INTERVAL_SECONDS) + + +async def _record_device_contact( + mac: str | None, + telemetry: DeviceTelemetry, + plugin_name: str | None = None, +) -> None: + """Upsert the device row and store a throttled battery sample. + + Unidentified callers are deliberately not registered — see _get_device_mac. + Never raises: telemetry bookkeeping must not fail a device's display request. + """ + if not mac: + logger.debug("Unidentified request (no ID header), skipping device registration") + return + + try: + async with get_session() as session: + result = await session.execute(select(Device).where(Device.mac_address == mac)) + device = result.scalar_one_or_none() + + if device is None: + device = Device(mac_address=mac, current_plugin=plugin_name) + session.add(device) + logger.info(f"Registered new device {mac}") + + # UTC throughout: created_at/updated_at use the DB's func.now(), which is + # UTC in SQLite. Writing a local-time last_seen skewed the two by the + # server's UTC offset. + device.last_seen = datetime.now(UTC) + if plugin_name: + device.current_plugin = plugin_name + if telemetry.firmware_version: + device.firmware_version = telemetry.firmware_version + if telemetry.refresh_rate: + device.refresh_rate = telemetry.refresh_rate + + if telemetry.has_reading() and await _should_sample_battery(session, mac): + session.add( + BatteryReading( + device_mac=mac, + voltage=telemetry.voltage, + rssi=telemetry.rssi, + ) + ) + logger.info( + f"Battery sample from {mac}: {telemetry.voltage}V rssi={telemetry.rssi}" + ) + + except Exception as e: + logger.warning(f"Could not record device contact for {mac}: {e}") def _parse_time(time_str: str) -> time: @@ -240,6 +424,11 @@ async def get_display( """ config = get_config() mac = _get_device_mac(request, x_device_mac) + plugin_name = plugin or get_primary_plugin_name() + + # Record contact before any early return: a sleeping device still reports its + # battery, and that is the only channel the firmware has for telemetry. + await _record_device_contact(mac, _telemetry_from_headers(request), plugin_name=plugin_name) # Check if device should be sleeping if _is_in_sleep_window(config): @@ -271,9 +460,6 @@ async def get_display( special_function="sleep", ) - # Determine which plugin to use - plugin_name = plugin or get_primary_plugin_name() - if not plugin_name: logger.error("No plugin available") base_url = _public_base_url(request) @@ -312,28 +498,6 @@ async def get_display( image_url = f"{base_url}/generated/screen.bmp?v={output.content_hash}" filename = f"{output.content_hash}_screen.bmp" - # Update device last seen - try: - async with get_session() as session: - from sqlalchemy import select - - result = await session.execute(select(Device).where(Device.mac_address == mac)) - device = result.scalar_one_or_none() - - if device: - device.last_seen = datetime.now() - else: - # Register new device - device = Device( - mac_address=mac, - last_seen=datetime.now(), - current_plugin=plugin_name, - ) - session.add(device) - - except Exception as e: - logger.warning(f"Could not update device record: {e}") - logger.debug(f"Display response for {mac}: {image_url}") # Get dynamic refresh rate from plugin if available @@ -361,20 +525,48 @@ async def post_log( Called by TRMNL firmware on various events like display update, sleep, wake, etc. - Accepts two formats: - 1. TRMNL firmware format: {"log": {"logs_array": [...]}} - 2. Legacy format: {"log_type": "...", "message": "..."} + Accepts three formats: + 1. Terminus / stock firmware: {"logs": [...]} + 2. Older firmware format: {"log": {"logs_array": [...]}} + 3. Legacy format: {"log_type": "...", "message": "..."} """ mac = _get_device_mac(request, x_device_mac) + telemetry = _telemetry_from_headers(request) try: async with get_session() as session: - # Handle TRMNL firmware format - if log_data.log and log_data.log.logs_array: + # Handle Terminus format (current firmware) + if log_data.logs: + for terminus_entry in log_data.logs: + session.add( + DeviceLog( + device_mac=mac or UNKNOWN_DEVICE_MAC, + log_type=terminus_entry.level + or terminus_entry.source_path + or "firmware", + message=terminus_entry.message, + firmware_version=terminus_entry.firmware_version, + wifi_rssi=terminus_entry.wifi_signal, + battery_voltage=terminus_entry.battery_voltage, + free_heap=terminus_entry.free_heap_size, + ) + ) + # Headers win when present; otherwise fall back to the newest entry + # that carried a voltage. + if not telemetry.has_reading(): + for terminus_entry in reversed(log_data.logs): + if terminus_entry.battery_voltage is not None: + telemetry.voltage = terminus_entry.battery_voltage + telemetry.rssi = terminus_entry.wifi_signal + telemetry.firmware_version = terminus_entry.firmware_version + break + logger.info(f"Log from {mac}: {len(log_data.logs)} entries (terminus format)") + # Handle older TRMNL firmware format + elif log_data.log and log_data.log.logs_array: for entry in log_data.log.logs_array: status = entry.device_status_stamp log_entry = DeviceLog( - device_mac=mac, + device_mac=mac or UNKNOWN_DEVICE_MAC, log_type=entry.log_sourcefile or "firmware", message=entry.log_message, firmware_version=status.current_fw_version if status else None, @@ -383,11 +575,19 @@ async def post_log( free_heap=status.free_heap_size if status else None, ) session.add(log_entry) - logger.debug(f"Log from {mac}: {len(log_data.log.logs_array)} entries") + if ( + not telemetry.has_reading() + and status + and status.battery_voltage is not None + ): + telemetry.voltage = status.battery_voltage + telemetry.rssi = status.wifi_rssi_level + telemetry.firmware_version = status.current_fw_version + logger.info(f"Log from {mac}: {len(log_data.log.logs_array)} entries") # Handle legacy format elif log_data.log_type: log_entry = DeviceLog( - device_mac=mac, + device_mac=mac or UNKNOWN_DEVICE_MAC, log_type=log_data.log_type, message=log_data.message, firmware_version=log_data.firmware_version, @@ -396,15 +596,26 @@ async def post_log( free_heap=log_data.free_heap, ) session.add(log_entry) - logger.debug(f"Log from {mac}: {log_data.log_type}") + if not telemetry.has_reading() and log_data.battery_voltage is not None: + telemetry.voltage = log_data.battery_voltage + telemetry.rssi = log_data.wifi_rssi + telemetry.firmware_version = log_data.firmware_version + logger.info(f"Log from {mac}: {log_data.log_type}") else: - # Accept but don't store unknown formats - logger.debug(f"Log from {mac}: unknown format, accepted") + # Accept but don't store — and say so loudly with the payload, since + # a silent drop here is exactly how this endpoint stored nothing for + # weeks while answering 200 OK. + logger.warning( + f"Log from {mac}: unrecognized payload, nothing stored: " + f"{await _raw_body_preview(request)}" + ) except Exception as e: logger.error(f"Failed to save log: {e}") return LogResponse(status=1, message=str(e)) + await _record_device_contact(mac, telemetry) + return LogResponse(status=0, message="ok") @@ -416,9 +627,12 @@ async def post_battery( ) -> BatteryResponse: """Record battery and RSSI readings. - Called periodically by TRMNL firmware to report battery status. + Note: this endpoint is a MunichGlance extension, not part of the TRMNL protocol — + stock firmware never calls it. Real devices report battery in the headers of + /api/display and inside /api/log entries, which is where the readings come from. + Kept for manual reporting and custom clients; writes are not throttled here. """ - mac = _get_device_mac(request, x_device_mac) + mac = _get_device_mac(request, x_device_mac) or UNKNOWN_DEVICE_MAC try: async with get_session() as session: @@ -429,7 +643,7 @@ async def post_battery( ) session.add(reading) - logger.debug(f"Battery from {mac}: {battery_data.voltage}V") + logger.info(f"Battery from {mac}: {battery_data.voltage}V") except Exception as e: logger.error(f"Failed to save battery reading: {e}") @@ -453,7 +667,8 @@ async def get_setup( # Generate or retrieve API key for device api_key = config.setup_api_key or f"mg_{uuid.uuid4().hex[:16]}" - logger.info(f"Setup request from {mac}") + await _record_device_contact(mac, _telemetry_from_headers(request)) + logger.info(f"Setup request from {mac or 'unidentified device'}") return SetupResponse( status=0,