diff --git a/data/web/app.js b/data/web/app.js index 7f556266..1997d9cf 100644 --- a/data/web/app.js +++ b/data/web/app.js @@ -12,7 +12,7 @@ function switchTab(tabName) { // Update bottom tab bar active state. // Tabs under "More" (wifi, mqtt, system, about) keep "more" highlighted. - const moreTabs = ['wifi', 'mqtt', 'system', 'about']; + const moreTabs = ['logs', 'wifi', 'mqtt', 'system', 'about']; const barTab = moreTabs.includes(tabName) ? 'more' : tabName; document.querySelectorAll('.tab-bar-item').forEach(item => { item.classList.toggle('active', item.dataset.tab === barTab); @@ -262,10 +262,10 @@ function updateAuthUI() { const sensorsTabBtn = document.querySelector('.tab-bar-item[data-tab="sensors"]'); if (sensorsTabBtn) sensorsTabBtn.style.display = isAuthenticated ? '' : 'none'; - // More menu: hide admin items (wifi, mqtt, system) + // More menu: hide admin items (wifi, mqtt, system, logs) for (const item of document.querySelectorAll('.more-sheet-item')) { const text = item.textContent.trim().toLowerCase(); - if (text === 'wifi' || text === 'mqtt' || text.startsWith('system') || text.startsWith('🔒')) { + if (text === 'wifi' || text === 'mqtt' || text.startsWith('system') || text.startsWith('🔒') || text.includes('logs')) { item.style.display = isAuthenticated ? '' : 'none'; } } @@ -294,12 +294,12 @@ function updateAuthUI() { } } - // System / WiFi / MQTT / Sensors tabs: fully hide when not authenticated. Never + // System / WiFi / MQTT / Logs / Sensors tabs: fully hide when not authenticated. Never // force-show here — that previously used `''` (empty string), which falls back // to the CSS default `display:block`, making the tab visible again on every 2s // poll regardless of which tab switchTab() had actually activated (the reported // "always jumps back to WiFi Settings" bug). - for (const id of ['tab-system', 'tab-wifi', 'tab-mqtt']) { + for (const id of ['tab-system', 'tab-wifi', 'tab-mqtt', 'tab-logs']) { const el = document.getElementById(id); if (el && !isAuthenticated) el.style.display = 'none'; } @@ -1001,9 +1001,122 @@ async function saveSensorMapping() { } } +// ── Log Console ── + +var lastLogSeq = 0; +var lastLogBoot = 0; +var logLevelFilter = 'info'; +// Generation token: bumped on every request, filter change and clear. +// Responses carrying an older token are discarded, so a slow in-flight +// poll cannot append stale/duplicate entries or overwrite lastLogSeq +// after a newer poll, filter switch or clear has happened. +var logReqToken = 0; +// Serializes polls: fetch() responses taking longer than the 2s tick must not +// start a second concurrent poll (whose response would bump the token and +// discard the first one — leaving the console stuck until the next clear). +var logPollInFlight = false; + +function escapeHtml(s) { + return String(s).replace(/&/g,'&').replace(//g,'>').replace(/"/g,'"'); +} + +function loadLogs() { + // Only poll while the Logs tab is actually visible: the unconditional 2s + // timer used to keep appending DOM nodes (and fetching) in hidden tabs, + // growing the document by tens of thousands of nodes per day. + if (document.visibilityState !== 'visible') return; + var logTab = document.getElementById('tab-logs'); + if (!logTab || logTab.style.display === 'none') return; + + // Never overlap polls: a slow response would otherwise be superseded by the + // next tick's request (token bump) and discarded, stalling the console until + // a clear or filter change. The next tick resumes after this one settles. + if (logPollInFlight) return; + + var wasAtBottom, consoleEl = document.getElementById('logConsole'); + if (!consoleEl) return; + wasAtBottom = consoleEl.scrollTop + consoleEl.clientHeight >= consoleEl.scrollHeight - 40; + var token = ++logReqToken; + logPollInFlight = true; + // boot = epoch of the cursor: after a reboot the server forces a full dump + // (entries 1..N) even when the new seq is already past our stored cursor. + fetch('/api/logs?since=' + lastLogSeq + '&boot=' + lastLogBoot + '&count=200&level=' + logLevelFilter) + .then(function(res) { return res.json(); }) + .then(function(data) { + if (token !== logReqToken) return; // superseded by a newer poll/filter/clear + var empty = document.getElementById('logConsoleEmpty'); + // Boot change: the server re-sent the whole new-boot ring, so the old + // pre-reboot lines are stale — drop them instead of appending on top. + if (data.boot !== lastLogBoot) { + consoleEl.textContent = ''; + } + if (!data.entries || data.entries.length === 0) { + if (!consoleEl.hasChildNodes()) empty.style.display = 'block'; + return; + } + empty.style.display = 'none'; + data.entries.forEach(function(entry) { + var line = document.createElement('div'); + line.className = 'log-entry log-' + entry.level; + line.textContent = entry.msg; + consoleEl.appendChild(line); + }); + // Evict oldest entries beyond the client-side cap so an always-open + // dashboard cannot grow the log DOM without bound. + while (consoleEl.childNodes.length > 500) { + consoleEl.removeChild(consoleEl.firstChild); + } + lastLogSeq = data.next; + lastLogBoot = data.boot; + if (wasAtBottom && data.entries.length > 0) { + consoleEl.scrollTop = consoleEl.scrollHeight; + } + }) + .catch(function() { /* silent */ }) + .finally(function() { + logPollInFlight = false; + }); +} + +function clearLogs() { + logReqToken++; // invalidate any in-flight poll — it must not repopulate the console + fetch('/api/logs/clear', { method: 'POST' }).then(function() { + var c = document.getElementById('logConsole'); + if (c) c.textContent = ''; + var e = document.getElementById('logConsoleEmpty'); + if (e) e.style.display = 'block'; + lastLogSeq = 0; + }); +} + +document.addEventListener('DOMContentLoaded', function() { + document.querySelectorAll('.log-chip').forEach(function(chip) { + chip.addEventListener('click', function() { + logReqToken++; // discard in-flight responses from the previous filter + document.querySelectorAll('.log-chip').forEach(function(c) { c.classList.remove('active'); }); + this.classList.add('active'); + logLevelFilter = this.dataset.level; + lastLogSeq = 0; + var c = document.getElementById('logConsole'); + if (c) c.textContent = ''; + var e = document.getElementById('logConsoleEmpty'); + if (e) e.style.display = 'none'; + loadLogs(); + }); + }); +}); + +var _origUpdateAuthUI = (typeof updateAuthUI === 'function') ? updateAuthUI : function(){}; +updateAuthUI = function() { + _origUpdateAuthUI(); + var clearBtn = document.getElementById('btnClearLogs'); + if (clearBtn) clearBtn.style.display = isAuthenticated ? 'inline-block' : 'none'; +}; + // ── Init ── setInterval(loadTelemetry, 2000); +setInterval(loadLogs, 2000); window.onload = function() { loadTelemetry(); diff --git a/data/web/index.html b/data/web/index.html index 1583c2fe..09cccd07 100644 --- a/data/web/index.html +++ b/data/web/index.html @@ -68,6 +68,9 @@

+
+ 📜 Logs +
📶 WiFi
@@ -510,6 +513,18 @@

ℹ️ About

+ + + diff --git a/data/web/style.css b/data/web/style.css index fcd2b2a1..62700e84 100644 --- a/data/web/style.css +++ b/data/web/style.css @@ -481,3 +481,45 @@ input:focus, select:focus { input, select { font-size: 0.9rem; padding: 0.6rem 0.75rem; } .input-hint { font-size: 0.65rem; } } + +/* ── Log Console ── */ +#tab-logs { + padding-bottom: 70px; /* leaves room for the fixed bottom nav bar */ +} +#logConsole { + background: rgba(0,0,0,0.3); + border: 1px solid var(--panel-border); + border-radius: 10px; + padding: 0.75rem; + height: calc(100dvh - 180px); + overflow-y: auto; + font-family: 'SF Mono', 'Cascadia Code', 'Fira Code', monospace; + font-size: 0.78rem; + line-height: 1.55; + word-break: break-all; +} +.log-entry { + padding: 0.15rem 0; + border-bottom: 1px solid rgba(255,255,255,0.03); +} +.log-debug { color: #6b7b8d; } +.log-info { color: var(--text-muted); } +.log-warning { color: #f59e0b; } +.log-error { color: #ef4444; } +.log-critical { color: #ef4444; font-weight: 600; } +.log-chip { + background: rgba(0,0,0,0.2); + border: 1px solid var(--panel-border); + border-radius: 20px; + padding: 0.3rem 0.8rem; + font-size: 0.75rem; + color: var(--text-muted); + cursor: pointer; + transition: all 0.2s; +} +.log-chip.active { + background: rgba(0, 229, 255, 0.15); + border-color: var(--accent-blue); + color: var(--accent-blue); +} +#btnClearLogs { outline: none; } diff --git a/docs/contactor-guide.de.md b/docs/contactor-guide.de.md index 5cc1b7a3..3298f6ee 100644 --- a/docs/contactor-guide.de.md +++ b/docs/contactor-guide.de.md @@ -144,7 +144,7 @@ GND ───────────────────────── ``` **Freilaufdioden 1N4007** parallel zu jeder Schützspule: -- Kathode (Strichseite) an **A1 (+)** +- Kathode (Strichseite) an **A1 (+)** - Anode an **A2 (GND)** Die Dioden löschen den Spannungsrückschlag (Back-EMF) der Schützspule beim diff --git a/docs/home-assistant/_index.de.md b/docs/home-assistant/_index.de.md index dc506e81..19061cbd 100644 --- a/docs/home-assistant/_index.de.md +++ b/docs/home-assistant/_index.de.md @@ -2,7 +2,7 @@ title: Home Assistant Integration summary: Pool Controller Home Assistant Integration — automatische MQTT Discovery Entitäten, Sensor/Switch/Number/Select/Time-Domänen, Lovelace Dashboard YAML, Migration von alten Konfigurationen date: "2026-06-06" -lastmod: "2026-06-06" +lastmod: "2026-07-31" draft: false toc: true type: docs @@ -60,6 +60,7 @@ ergibt `sensor._pool_temperature`). Ersetze `` durch deinen Ger | `text` | `ntp_server` | config | NTP-Server-Adresse | | `update` | `firmware` | config | Firmware-Update-Entität | | `climate` | `pool_thermostat` | config | Pool-Thermostat (HVAC-Modus + Zieltemp.) | +| `event` | `logs` | diagnostic | Log-Ereignis-Stream (MQTT-Event-Entität, siehe [Log-Ereignisse](#log-ereignisse)) | > **Entity-IDs** in HA werden aus dem `name`-Feld der MQTT Discovery generiert. Die entity_id ist > `sensor._pool_temperature` usw. — wobei `` in der Regel @@ -67,6 +68,52 @@ ergibt `sensor._pool_temperature`). Ersetze `` durch deinen Ger > "pool" um deine IDs zu finden. Ersetze `pool_controller` im Dashboard-YAML durch deinen > Geräte-Prefix falls er abweicht. +### Log-Ereignisse + +Der Controller stellt eine [MQTT-Event-Entität](https://www.home-assistant.io/integrations/event.mqtt/) +(`event.pool_controller_logs` — Object ID `logs`) bereit, die ihren State bei jedem +protokollwürdigen Ereignis aktualisiert: Betriebsartwechsel, Pumpe ein/aus, WiFi-/MQTT-Verbindung +sowie Warning-/Error-Logeinträge. Die vollständige Topic- und Payload-Referenz findest du unter +[MQTT-Konfiguration → Events (Log-Stream)](../mqtt-configuration.de.md#events-log-stream). + +Die Event-Entität hält den letzten Ereignistyp im Attribut `event_type` und übernimmt jedes +zusätzliche Payload-Feld als Attribut (z. B. `message`). + +#### Logbuch-Automation + +Alle Ereignisse ins HA-Logbuch schreiben: + +```yaml +automation: + - alias: "Pool Controller — Ereignisse ins Logbuch" + triggers: + - trigger: event.received + target: + entity_id: event.pool_controller_logs + options: + event_type: + - MODE_CHANGED + - PUMP_ON + - PUMP_OFF + - WIFI_CONNECTED + - WIFI_DISCONNECTED + - MQTT_CONNECTED + - MQTT_DISCONNECTED + - LOG_WARN + - LOG_ERROR + actions: + - action: logbook.log + data: + name: "Pool Controller" + message: "{{ state_attr('event.pool_controller_logs', 'event_type') }}" + entity_id: event.pool_controller_logs +``` + +Der `event.received`-Trigger (Home Assistant 2026.7+) feuert, wenn die Entität einen passenden +Ereignistyp empfängt; siehe [event.received-Trigger-Dokumentation](https://www.home-assistant.io/triggers/event.received/). +Kürze die `event_type`-Liste auf die gewünschten Ereignisse und passe die Entity-ID an deinen +Geräte-Prefix an, falls er abweicht (Entwickler-Tools → Entitäten, Filter "pool"). + ## Lovelace Dashboard Eine vorgefertigte Lovelace-Dashboard-Konfiguration liegt in diff --git a/docs/home-assistant/_index.md b/docs/home-assistant/_index.md index 559e541d..679dd7f2 100644 --- a/docs/home-assistant/_index.md +++ b/docs/home-assistant/_index.md @@ -2,7 +2,7 @@ title: Home Assistant Integration summary: Pool Controller Home Assistant integration — automatic MQTT Discovery entities, sensor/switch/number/select/time domains, Lovelace dashboard YAML, migration from legacy configs date: "2026-06-06" -lastmod: "2026-06-06" +lastmod: "2026-07-31" draft: false toc: true type: docs @@ -59,6 +59,7 @@ produces `sensor._pool_temperature`). Replace `` with your devic | `text` | `ntp_server` | config | NTP server address | | `update` | `firmware` | config | Firmware update entity | | `climate` | `pool_thermostat` | config | Pool thermostat (HVAC mode + target temp) | +| `event` | `logs` | diagnostic | Log event stream (MQTT event entity, see [Log Events](#log-events)) | > **Entity IDs** in HA are generated from the MQTT discovery `name` field. The entity_id will be > `sensor._pool_temperature` etc. — where `` is typically @@ -66,6 +67,52 @@ produces `sensor._pool_temperature`). Replace `` with your devic > "pool" to find your actual IDs. Replace `pool_controller` in the dashboard YAML with your > device prefix if it differs. +### Log Events + +The controller exposes an [MQTT event entity](https://www.home-assistant.io/integrations/event.mqtt/) +(`event.pool_controller_logs` — object ID `logs`) that updates its state whenever a log-worthy +event occurs: mode changes, pump on/off, WiFi/MQTT connectivity, and warning/error log entries. +See [MQTT Configuration → Events (Log stream)](../mqtt-configuration.md#events-log-stream) for the +full topic and payload reference. + +The event entity keeps the last event type in its `event_type` attribute and merges every +additional payload field as an attribute (e.g. `message`). + +#### Logbook Automation + +Write every event to the HA logbook: + +```yaml +automation: + - alias: "Pool Controller — log events to logbook" + triggers: + - trigger: event.received + target: + entity_id: event.pool_controller_logs + options: + event_type: + - MODE_CHANGED + - PUMP_ON + - PUMP_OFF + - WIFI_CONNECTED + - WIFI_DISCONNECTED + - MQTT_CONNECTED + - MQTT_DISCONNECTED + - LOG_WARN + - LOG_ERROR + actions: + - action: logbook.log + data: + name: "Pool Controller" + message: "{{ state_attr('event.pool_controller_logs', 'event_type') }}" + entity_id: event.pool_controller_logs +``` + +The `event.received` trigger (Home Assistant 2026.7+) fires when the entity receives a matching +event type; see the [event received trigger documentation](https://www.home-assistant.io/triggers/event.received/). +Trim the `event_type` list to the events you care about, and adjust the entity ID to your device +prefix if it differs (Developer Tools → Entities, filter by "pool"). + ## Lovelace Dashboard A pre-built Lovelace dashboard configuration is provided in [`dashboard.yaml`](dashboard.yaml). diff --git a/docs/mqtt-configuration.de.md b/docs/mqtt-configuration.de.md index 19c660b1..ffcd9a0d 100644 --- a/docs/mqtt-configuration.de.md +++ b/docs/mqtt-configuration.de.md @@ -2,7 +2,7 @@ title: MQTT-Konfiguration summary: Home Assistant MQTT Discovery Konfiguration, Entity-Referenztabelle und Migration von Homie für den ESP32 Pool Controller date: "2026-06-11" -lastmod: "2026-06-11" +lastmod: "2026-07-31" draft: false toc: true type: docs @@ -108,6 +108,29 @@ Der Controller veröffentlicht die folgenden Entitäten über MQTT Discovery, gr | Firmware | `update/firmware-update` | `config` | `homeassistant/update/pool-controller/firmware-update/set` | | Pool-Thermostat | `climate/thermostat` | `config` | (Modus + Temperatur via Climate-Topics) | +### Events (Log-Stream) + +Der Controller veröffentlicht **kuratierte Log-Ereignisse** als HA-`event`-Entität +(für Automatisierungen und Benachrichtigungen) sowie einen **Roh-Log-Stream** +für externe Tools: + +| Funktion | HA-Komponente/Objekt-ID | Entity Category | Topic | +| ------------------ | ----------------------- | --------------- | ---------------------------------------------------------------------- | +| Kuratierte Log-Events | `event/logs` | `diagnostic` | `homeassistant/event/pool-controller/logs/state` (Discovery `.../config`) | + +- **Discovery-Topic**: `homeassistant/event/pool-controller/logs/config` + (`"platform": "event"`) mit `event_types`: + `LOG_WARN`, `LOG_ERROR`, `MODE_CHANGED`, `PUMP_ON`, `PUMP_OFF`, + `WIFI_CONNECTED`, `WIFI_DISCONNECTED`, `MQTT_CONNECTED`, `MQTT_DISCONNECTED` +- **State-Payload** (nur bei Änderung veröffentlicht, per Log-Sequenz dedupliziert): + ```json + {"event_type": "MODE_CHANGED", "message": "Mode switched to auto"} + ``` +- **Roh-Stream** `pool-controller/log` (JSON Lines, nur WARN/ERROR): + ```json + {"seq": 42, "t": 123456, "level": "warning", "msg": "..."} + ``` + ### Entity-Category-Referenz | Kategorie | Beschreibung | diff --git a/docs/mqtt-configuration.md b/docs/mqtt-configuration.md index beedf75c..59ed0a18 100644 --- a/docs/mqtt-configuration.md +++ b/docs/mqtt-configuration.md @@ -2,7 +2,7 @@ title: MQTT Configuration summary: Home Assistant MQTT Discovery configuration, entity reference table, and migration from Homie for the ESP32 Pool Controller date: "2026-06-07" -lastmod: "2026-06-07" +lastmod: "2026-07-31" draft: false toc: true type: docs @@ -108,6 +108,28 @@ The controller publishes the following entities via MQTT Discovery, grouped by t | Firmware | `update/firmware-update` | `config` | `homeassistant/update/pool-controller/firmware-update/set` | | Pool Thermostat | `climate/thermostat` | `config` | (mode + temperature via climate topics) | +### Events (Log stream) + +The controller publishes **curated log events** as an HA `event` entity (for +automations and notifications) plus a **raw log stream** for external tools: + +| Function | HA component/object-id | Entity Category | Topic | +| ------------------ | ---------------------- | --------------- | ---------------------------------------------------------------------- | +| Curated log events | `event/logs` | `diagnostic` | `homeassistant/event/pool-controller/logs/state` (discovery `.../config`) | + +- **Discovery topic**: `homeassistant/event/pool-controller/logs/config` + (`"platform": "event"`) with `event_types`: + `LOG_WARN`, `LOG_ERROR`, `MODE_CHANGED`, `PUMP_ON`, `PUMP_OFF`, + `WIFI_CONNECTED`, `WIFI_DISCONNECTED`, `MQTT_CONNECTED`, `MQTT_DISCONNECTED` +- **State payload** (published on change only, deduplicated by log sequence): + ```json + {"event_type": "MODE_CHANGED", "message": "Mode switched to auto"} + ``` +- **Raw stream** `pool-controller/log` (JSON Lines, WARN/ERROR only): + ```json + {"seq": 42, "t": 123456, "level": "warning", "msg": "..."} + ``` + ### Entity Category Reference | Category | Description | diff --git a/docs/software-guide.de.md b/docs/software-guide.de.md index f14ca08c..19d4db60 100644 --- a/docs/software-guide.de.md +++ b/docs/software-guide.de.md @@ -2,7 +2,7 @@ title: Software-Entwicklung summary: Software-Entwicklungsleitfaden für den Pool Controller — PlatformIO Build-Umgebung, Library-Abhängigkeiten, REST-API-Referenz, Weboberfläche und Code-Architektur date: "2020-05-28" -lastmod: "2026-06-11" +lastmod: "2026-07-31" draft: false toc: true type: docs @@ -71,6 +71,8 @@ vollständiges Verwaltungs-Dashboard bereitstellt. Er läuft in zwei Modi: | `GET /api/restart` | Ja | ESP32 neu starten | | `GET /api/factory_reset` | Ja | Konfigurationsdatei löschen, Neustart im AP-Modus | | `POST /api/update` | Ja | OTA-Firmware-Update (signiertes .bin hochladen) | +| `GET /api/logs` | ❌ Nein | Log-Einträge aus dem Ringpuffer (`since`/`count`/`level`-Filter) | +| `POST /api/logs/clear` | Ja | Log-Ringpuffer leeren | ### REST-API direkt nutzen @@ -93,6 +95,36 @@ curl -b "session=$SESSION" -X POST \ http:///api/config ``` +#### Log-Ansicht-API + +Der Controller hält einen Ringpuffer der letzten Log-Einträge und stellt sie über REST bereit: + +```bash +# Log-Einträge abrufen (keine Authentifizierung nötig) +curl "http:///api/logs?since=0&count=200&level=info" +``` + +| Parameter | Standard | Beschreibung | +| --------- | -------- | ----------------------------------------------------- | +| `since` | `0` | Nur Einträge mit `seq` größer als dieser Wert | +| `count` | `200` | Maximale Anzahl Einträge (1–500) | +| `level` | `info` | Mindest-Loglevel: `debug`, `info`, `warning`, `error`, `critical` | + +Antwort: + +```json +{ + "next": 43, + "entries": [ + {"seq": 42, "t": 123456, "level": "warning", "msg": "SAFE MODE — ignoring relay ON request"} + ] +} +``` + +- `next` ist die nächste Sequenznummer, die als `since` für inkrementelles Polling übergeben wird +- `t` ist die Betriebszeit des Eintrags in Millisekunden +- `POST /api/logs/clear` (authentifiziert) leert den Puffer und liefert `{"ok": true}` + ### Authentifizierung - Im **AP-Modus** ist die Weboberfläche ungeschützt (absichtlich für die Einrichtung) diff --git a/docs/software-guide.md b/docs/software-guide.md index 942334c8..10485c67 100644 --- a/docs/software-guide.md +++ b/docs/software-guide.md @@ -2,7 +2,7 @@ title: Software Guide summary: Software development guide for the Pool Controller — PlatformIO build environment, library dependencies, REST API reference, web interface, and code architecture overview date: "2020-05-28" -lastmod: "2020-06-02" +lastmod: "2026-07-31" draft: false toc: true type: docs @@ -71,6 +71,8 @@ management dashboard. It runs in two modes: | `GET /api/restart` | Yes | Reboot the ESP32 | | `GET /api/factory_reset` | Yes | Wipe config file, reboot into AP setup mode | | `POST /api/update` | Yes | OTA firmware update (signed .bin upload) | +| `GET /api/logs` | ❌ No | Ring-buffered log entries (`since`/`count`/`level` filters) | +| `POST /api/logs/clear` | Yes | Clear the log ring buffer | ### Using the REST API Directly @@ -93,6 +95,36 @@ curl -b "session=$SESSION" -X POST \ http:///api/config ``` +#### Log View API + +The controller keeps a ring buffer of recent log entries and exposes them over REST: + +```bash +# Read log entries (no authentication needed) +curl "http:///api/logs?since=0&count=200&level=info" +``` + +| Parameter | Default | Description | +| --------- | ------- | -------------------------------------------------- | +| `since` | `0` | Only entries with `seq` greater than this value | +| `count` | `200` | Maximum number of entries (1–500) | +| `level` | `info` | Minimum log level: `debug`, `info`, `warning`, `error`, `critical` | + +Response: + +```json +{ + "next": 43, + "entries": [ + {"seq": 42, "t": 123456, "level": "warning", "msg": "SAFE MODE — ignoring relay ON request"} + ] +} +``` + +- `next` is the next sequence number to pass as `since` for incremental polling +- `t` is the entry uptime in milliseconds +- `POST /api/logs/clear` (authenticated) empties the buffer and returns `{"ok": true}` + ### Authentication - In **AP mode** the web interface is unprotected (intentional for initial setup) diff --git a/docs/superpowers/plans/2026-07-31-logging-view.md b/docs/superpowers/plans/2026-07-31-logging-view.md new file mode 100644 index 00000000..4f9653d0 --- /dev/null +++ b/docs/superpowers/plans/2026-07-31-logging-view.md @@ -0,0 +1,391 @@ +# Implementierungsplan: Logging View (Web-Log-Konsole) + +Datum: 2026-07-31 +Basis: `docs/superpowers/specs/2026-07-31-logging-view-design.md` (approved, Ansatz A) +Branch: `fix/relay-r4-solar-pump` +Commit-Historie: `db3a970` (Spec-Update) → `2e40262` (research-backed MQTT event entity) → `0783fd8` (Spec-Initial) + +--- + +## Goal + +Dem Pool-Controller eine zentrale Log-Capture-Architektur geben: + +1. **`LogCapture`** — RAM-Ringbuffer, ersetzt die 253 direkten `Serial.*`-Aufrufe in 21 Dateien. +2. **REST** — unauthentifiziertes `GET /api/logs` (mit `since`-Polling), authentifiziertes `POST /api/logs/clear`. +3. **MQTT** — HA-„event"-Entity-Discovery (research-backed, `event_types`) + Export von WARN/ERROR + kuratierten Events. +4. **UI** — „📜 Logs"-Button auf dem Dashboard (unauthentifizierter Zugriffspfad) + Eintrag im More-Menü; Konsole mit 2s-Polling, Level-Filtern, Pause-on-Scroll, Auth-Gated-Clear. +5. **Docs** — `mqtt-configuration.md`, `software-guide.md`, Home-Assistant-Sektion (Logbook-Automation-Blueprint). + +**Explizite Vorgaben (User-Entscheidungen, in Spec committed):** +- **LittleFS only** — kein PROGMEM-Fallback für die neue View (`WebPortal.cpp:58`: „PROGMEM fallbacks removed"). +- **Platzierung**: Dashboard-Button **und** More-Menü-Eintrag — Grund: Tab-Bar + More-Menü sind ohne Login unsichtbar (`app.js:262-263` `tabBar.style.display = isAuthenticated ? '' : 'none'`); der Dashboard-Button ist der einzige unauthentifizierte Einstieg. +- **Kein @librarian-Einsatz** — HA-Recherche ist abgeschlossen und committed (2e40262). Ergebnis: HA-**event**-Component (`platform: event`, `event_types`), kein Sensor/Device-Tracker. + +--- + +## Architektur + +``` +Serial.*-Calls (21 Dateien, 253 Stellen) + │ migriert zu + ▼ +LogCapture::log(level, fmt, ...) ──► RAM-Ringbuffer (static, kein Heap) + │ (mit LogToSerial-Flag: Mirror auf Serial, Byte-identisch) + ├──► WebPortal::apiGetLogs() GET /api/logs?since=&count=&level= (unauthentifiziert) + │ apiClearLogs() POST /api/logs/clear (handleAuthentication) + └──► MqttPublisher homeassistant/event/.../config (Discovery, platform: event) + homeassistant/event/.../state ({"event_type": ..., "message": ...}) + pool-controller/log (Raw, WARN/ERROR) +``` + +**Design-Entscheidungen:** +- `LogCapture` ist eine static-Klasse (Codebase-Konvention, vgl. `StateManager`, `DegradationManager`, `SystemMonitor`). +- Ringbuffer: statisches `std::array`-artiges C-Array, **kein Heap** (IoT-Qualitätsgate, `cpp-memory-opt`-Skill: keine String-Klassen, keine Allokation in Hot-Paths). +- Thread-Safety: `portMUX_TYPE`-Guard, nur unter `#ifdef ARDUINO` aktiv — in Native-Tests (kein portMUX-Mock) kompiliert er zu no-op. Aufrufer sind Loop-Task + WebServer-Handler (Loop) + MQTT-Callbacks (WiFi-Task) → Guard notwendig. +- Serial-Mirror bleibt **standardmäßig an** (`Flags::LogToSerial`-Semantik aus Logger-Stub): bestehendes Serial-Debugging (pio monitor) funktioniert unverändert weiter; Verifikations-Invariante „Serial-Ausgabe byte-identisch" wird so erfüllbar. +- `LogLevel`-Enum bleibt namensgleich zum Logger-Stub (`Debug=0, Info, Warning, Critical, Error`) — kein Consumer außer `Logger.cpp` selbst (verifiziert: kein Include von `Logger.hpp` in `src/` oder `test/native/`), Stub wird gelöscht. + +--- + +## Tech Stack + +- C++17, PlatformIO/ESP32 (Arduino-Framework), ArduinoJson, WebServer (async-frei, Loop-gepollt). +- Native Tests: CMake (`test/native`), `./build/test_runner` mit ASAN, `test/native/relay_safety` (separater Build). +- CI: `.github/workflows/native-tests.yml` (cmake build → test_runner → relay_safety → lcov → PR-Kommentar). +- Frontend: vanilla HTML/CSS/JS auf LittleFS (`data/web/`), 2s-Polling-Muster analog `loadTelemetry` (`app.js:1005`). + +--- + +## Global Constraints + +1. **Kein Heap in LogCapture** — statischer Ringbuffer, feste Entry-Größe, `vsnprintf` in Entry-Buffer. +2. **Serial-Ausgabe bleibt byte-identisch** — `LogCapture::log` formatiert exakt das übergebene Format (inkl. `\n`) und spiegelt es 1:1 auf Serial. +3. **Keine String-Klasse** in LogCapture — `char[]` + `vsnprintf` (Clean-Code/Heap-Regeln). +4. **Unauthentifizierte Endpoints nur lesend** — `GET /api/logs` (Limit/Cap), Schreibzugriff (`clear`) ausschließlich hinter `handleAuthentication()`. +5. **XSS-Sicherheit in der UI** — Log-Messages sind Fremdtext; im Frontend per `textContent`/Escaping rendern, nie per `innerHTML`. +6. **Native Tests müssen grün bleiben** — `test_runner` **und** `relay_safety` (separater Build), ASAN-Optionen wie CI. +7. **Dokumentation EN+DE** — alle Docs-Dateien existieren als `.md` + `.de.md`. +8. **LittleFS-only** — keine PROGMEM-Spiegel für neue Assets. +9. Jeder Task endet mit Build + Test + Commit (Conventional Commits, Scope `logging`). + +--- + +## Tasks + +### Task 1 — LogCapture-Kern (Ringbuffer + API) + +**Dateien:** `src/LogCapture.hpp` (neu), `src/LogCapture.cpp` (neu), `src/Nodes/Logger.{hpp,cpp}` (löschen) + +**Schritte:** +1. `src/LogCapture.hpp` anlegen: + +```cpp +// Copyright (c) 2018-2026 Smart Swimming Pool, Stephan Strittmatter +// SPDX-License-Identifier: MIT + +#pragma once + +#include +#include +#include + +namespace PoolController { + +enum class LogLevel : std::uint8_t { Debug = 0, Info, Warning, Critical, Error }; + +struct LogEntry { + std::uint32_t seq; // monoton steigend, für since-Polling + std::uint32_t uptimeMs; // millis() zum Zeitpunkt des Eintrags + LogLevel level; + char message[LOG_MSG_SIZE]; +}; + +class LogCapture final { +public: + static constexpr std::size_t LOG_BUFFER_ENTRIES = LOG_BUFFER_SIZE / LOG_MSG_SIZE; + static void begin(); + static void log(LogLevel level, const char *fmt, ...); + static void logEvent(const char *eventType, const char *fmt, ...); + static std::size_t getEntries(std::uint32_t sinceSeq, std::size_t maxCount, + LogLevel minLevel, LogEntry *out, std::size_t outCapacity); + static std::uint32_t lastSeq(); + static void clear(); + static const char *levelName(LogLevel level); + static LogLevel parseLevel(const char *name); // "info"|"warning"|"error" → Level, sonst Info + static bool isLogToSerial(); + static void setLogToSerial(bool enabled); +}; + +} // namespace PoolController + +#define LOG_DEBUG(...) PoolController::LogCapture::log(PoolController::LogLevel::Debug, __VA_ARGS__) +#define LOG_INFO(...) PoolController::LogCapture::log(PoolController::LogLevel::Info, __VA_ARGS__) +#define LOG_WARN(...) PoolController::LogCapture::log(PoolController::LogLevel::Warning, __VA_ARGS__) +#define LOG_ERROR(...) PoolController::LogCapture::log(PoolController::LogLevel::Error, __VA_ARGS__) +``` + +2. `src/LogCapture.cpp`: + - Defaults: `LOG_BUFFER_SIZE` = 8192, `LOG_MSG_SIZE` = 96 (platformio.ini `build_flags`: `-DLOG_BUFFER_SIZE=...` überschreibbar — bestehende `build_flags`-Blöcke `platformio.ini:33,56` ergänzen, Default in Header). + - Statischer Ring: `static LogEntry s_buffer[LOG_BUFFER_ENTRIES];`, `static std::size_t s_head;` (nächster freier Slot), `static std::uint32_t s_seq;` + - `log()`: `va_list` → `vsnprintf(message, sizeof, fmt, args)` → in Ring schreiben → falls `s_logToSerial`: `Serial.print(entry.message)`. + - `logEvent(eventType, ...)`: Entry mit `level=Info` und `message` = `"[eventType] "` — Marker für den MQTT-Export (Task 4), Serial-Mirror identisch. + - `getEntries`: vom ältesten Eintrag ≥ `sinceSeq` (Ring durchlaufen, seq-Vergleich) bis `maxCount`, filter `>= minLevel`, Kopie nach `out`. + - `lastSeq()`: aktueller `s_seq`-Stand (für `next` im REST-Payload). + - `clear()`: Ring leeren, `s_seq` NICHT zurücksetzen (sonst brechen Polling-Clients), s_head=0. + - Guard: `portMUX_TYPE s_mux;` nur `#ifdef ARDUINO` (`portMUX_INITIALIZER_UNLOCKED`), in `log/getEntries/clear` `portENTER_CRITICAL(&s_mux)` … `portEXIT_CRITICAL(&s_mux)`. Native Build (kein portMUX) → no-op ohne `#ifdef`-Zweig. + - `begin()`: `s_head=0; s_seq=0; s_logToSerial=true;` (init Mux). + +3. `src/Nodes/Logger.hpp` + `Logger.cpp` löschen (`git rm`). Kein anderer Referenzpunkt existiert (verifiziert). + +**Test (TDD — Test zuerst schreiben):** +- `test/native/tests/test_logcapture.cpp` (neu), Funktion `run_logcapture_tests()`: + - Ring-Wraparound: `LOG_BUFFER_ENTRIES + 5` Einträge loggen → `getEntries(0, 4096, Debug, ...)` liefert letzte `LOG_BUFFER_ENTRIES`, älteste seq > 0. + - seq-Monotonie: nach N Logs ist `lastSeq() == N`; Einträge haben strikt steigende seq. + - since-Filter: `getEntries(sinceSeq=N, ...)` liefert nur seq > N. + - Level-Filter: nur `>= Warning` bei `minLevel=Warning`. + - `clear()`: danach `getEntries(0, ...) == 0`, `lastSeq()` unverändert. + - Truncation: Message > `LOG_MSG_SIZE` wird gekappt, kein Overflow (ASAN-frei). + - Kein Heap: statische Buffer (kein dynamisches Verhalten testbar; ASAN/leak-check im CI). + - `logEvent`: Message beginnt mit `[` und enthält eventType. +- `test/native/CMakeLists.txt`: `${PROJ_ROOT}/src/LogCapture.cpp` zu `SERVICE_SOURCES` (Zeile 52-59), `tests/test_logcapture.cpp` zu `TEST_SOURCES` (Zeile 69). +- `test/native/tests/test_main.cpp`: `extern int run_logcapture_tests();` (Zeile ~102) + `total += run_logcapture_tests();` (Zeile ~116). + +**Verify:** +```bash +cmake -B build -S . && cmake --build build && ASAN_OPTIONS=detect_leaks=1:halt_on_error=1 ./build/test_runner +cmake -B relay_safety/build -S relay_safety && cmake --build relay_safety/build && ./relay_safety/build/test_relay_safety +pio run # Firmware kompiliert (LogCapture wird in setup() noch nicht benutzt — siehe Task 2) +``` + +**Commit:** `feat(logging): add LogCapture ring buffer core with native tests` + +--- + +### Task 2 — Integration in PoolController-Setup + +**Dateien:** `src/PoolController.cpp` (setup: ~Zeile 268), `platformio.ini` (build_flags 33, 56) + +**Schritte:** +1. `#include "LogCapture.hpp"` ergänzen. +2. In `setup()` unmittelbar nach `Serial.begin(...)` (vor `StateManager::begin()` Zeile 268): `LogCapture::begin();` — Ring muss vor allen Logging-Seiten stehen. +3. `platformio.ini`: `-DLOG_BUFFER_SIZE=8192` zu den `build_flags`-Blöcken (Zeile 33, 56) hinzufügen (Default steht im Header; explizit machen für OTA-Konsistenz beider Envs). + +**Verify:** `pio run` grün; `test_runner` + `relay_safety` grün (keine LogCapture-Nutzung außer begin → keine Verhaltensänderung). + +**Commit:** `feat(logging): initialize LogCapture during boot` + +--- + +### Task 3 — Serial-Migration (21 Dateien, 253 Stellen) + +**Level-Inferenz-Regeln (mechanisch):** + +| Marker im String | Level | +|---|---| +| `✖`, `ERROR`, `FAIL`, `CRITICAL` | `LOG_ERROR` | +| `⚠`, `WARN`, `WARNING` | `LOG_WARN` | +| `✔`, `✓`, sonst nichts | `LOG_INFO` | +| rein technische Poll-Diagnostik | `LOG_DEBUG` (nur wenn erkennbar Debug-Charakter, z. B. Rohwerte-Dumps in Schleifen) | + +**Mechanik:** +- `Serial.printf("...", args)` → `LOG_INFO("...", args)` (bzw. Level nach Tabelle) — Format inkl. `\n` unverändert (Serial-Mirror ist byte-identisch). +- `Serial.println("...")` → `LOG_INFO("...\n")` (println hängt `\n` an; Mirror muss identisch sein). +- `Serial.print("...")` (ohne `\n`) → `LOG_INFO("...")`. +- Mehrteilige Chains (`Serial.print(a); Serial.print(b); Serial.println(c);`) → zu **einer** `LOG_*`-Zeile mit kombiniertem Format mergen (gleiche Bytefolge: `"ab" + c + "\n"`), wo trivial; sonst je Fragment eine Zeile beibehalten. +- `Serial.println()` ohne Argument (Leerzeile) → `LOG_INFO("")`. +- `Update.printError(Serial)` in OtaUpdater → `Serial.print(Update.errorString())`-Ersatz via `LOG_ERROR("%s", Update.errorString())` NUR wo die Updater-API es erlaubt (printError ist library-intern auf Serial verdrahtet — **unverändert lassen**, kommentieren). + +**Reihenfolge** (klein → groß, jeder Datei-Task einzeln committen; Call-Zahlen verifiziert): +1. `src/Timer.cpp` (1) · 2. `src/RuleTimer.cpp` (1) · 3. `src/RuleManu.cpp` (1) · 4. `src/TimeClientHelper.cpp` (2) · 5. `src/ESP32TemperatureNode.cpp` (2) · + 6. `src/StatusLed.cpp` (5) · 7. `src/RelayModuleNode.cpp` (5) · 8. `src/NorviButtonHandler.cpp` (7) · 9. `src/NorviOledDisplay.cpp` (8) · + 10. `src/WpsProvisioner.cpp` (10) · 11. `src/ConfigManager.cpp` (11) · 12. `src/RuleBoost.cpp` (12) · 13. `src/WebPortal.cpp` (13) · + 14. `src/NetworkManager.cpp` (15) · 15. `src/DegradationManager.cpp` (15) · 16. `src/RuleAuto.cpp` (16) · 17. `src/DallasTemperatureNode.cpp` (20) · + 18. `src/OperationModeNode.cpp` (23) · 19. `src/PoolController.cpp` (26) · 20. `src/MqttPublisher.cpp` (27) · 21. `src/OtaUpdater.cpp` (33) + +**Sonderfälle:** +- `NorviOledDisplay`/`NorviButtonHandler`: Serial nur als Debug-Pfad — Flags/Guard-Bedingungen (z. B. `if (DEBUG)`) beibehalten, nur die Ausgabe ersetzen. +- `DallasTemperatureNode`: Poll-Schleifen-Logging → `LOG_DEBUG` (würde sonst Ringbuffer in Sekunden fluten). +- `OperationModeNode`: `✖ UNDEFINED Mode` → `LOG_ERROR`, `⚠ NTP time sync failed` → `LOG_WARN`. +- `MqttPublisher`/`NetworkManager`/`OtaUpdater`/`WebPortal`: kuratierte Events (siehe Task 4, Schritt 3) hier gleichzeitig als `logEvent` statt `log` setzen, wo Mode-/Pump-/Wifi-/MQTT-/OTA-Übergänge geloggt werden (kein zweiter Durchlauf). + +**Per-Task Verify:** +```bash +pio run && cmake -B build -S . && cmake --build build && ASAN_OPTIONS=detect_leaks=1:halt_on_error=1 ./build/test_runner && cmake -B relay_safety/build -S relay_safety && cmake --build relay_safety/build && ./relay_safety/build/test_relay_safety +``` +Invarianz-Check je Datei: `git diff` auf reine Call-Substitution prüfen (keine Logikänderung). + +**Commit je Datei:** `refactor(logging): migrate Serial calls in to LogCapture` (bis zu 21 Commits; kleine Gruppen á 3-4 Dateien erlaubt, wenn diff klar bleibt). + +--- + +### Task 4 — REST-Endpoint `/api/logs` + +**Dateien:** `src/WebPortal.cpp` (setupRoutes:180, apiGetStatus:436 als Muster), `src/WebPortal.hpp` + +**Schritte:** +1. `WebPortal.hpp`: `static void apiGetLogs();` + `static void apiClearLogs();` (private, wie apiGetStatus). +2. `setupRoutes()` ergänzen (Muster Zeile 193 / 199-208): +```cpp +// Log view — GET unauthenticated (read-only), clear requires login +server_.on("/api/logs", HTTP_GET, apiGetLogs); +server_.on("/api/logs/clear", HTTP_POST, []() { + if (!handleAuthentication()) + return; + apiClearLogs(); +}); +``` +3. `apiGetLogs()`: + - Query: `since` (seq, default 0), `count` (default 200, Cap 500), `level` (`parseLevel`, default `Info` — damit Debug nicht im Web landet; `level=debug` explizit möglich). + - JSON: `{"ok":true, "next":, "entries":[{"seq":…,"t":,"level":"info|warning|error","msg":"…"}, …]}` + - `JsonDocument doc;` + `serializeJson` → `server_.send(200, "application/json", payload)` — exakt wie `apiGetStatus` (Zeile 436ff, Payload-Buffer-Muster). +4. `apiClearLogs()`: `LogCapture::clear();` → `{"ok":true}`. +5. Keine PROGMEM-Anteile (LittleFS-only-Vorgabe). + +**Test (TDD):** +- Neues Muster anlehnen an `test_webportal_json.cpp` (WebServer-Mock fängt `send()` via `wsCapture`). Da `apiGetStatus` private ist und der bestehende Test + inline-JSON baut, wird für `apiGetLogs` derselbe Weg genutzt: **Test-Hook** — `LogCapture` selbst unit-testen (Task 1) + JSON-Serialisierung über einen + **public static Test-Hook** testen, z. B. `WebPortal::buildLogsJson(uint32_t since, size_t count, LogLevel minLevel, char *buf, size_t bufSize) -> size_t` + (public for testing, Muster: „Rate limiting helpers (public for testing)" existiert bereits in `WebPortal.hpp`). `apiGetLogs` ruft den Hook auf und sendet. +- Testfälle: since-Filter wirkt, count-Cap, Level-Filter, `next` = lastSeq+1, leeres Ergebnis → `entries: []`. +- Registrierung: `test_webportal_json.cpp` erweitern oder neue Testdatei + `test_main.cpp`-Eintrag. + +**Verify:** test_runner + relay_safety grün; `pio run` grün. + +**Commit:** `feat(logging): add unauthenticated /api/logs endpoint and authenticated clear` + +--- + +### Task 5 — MQTT-Event-Export + +**Dateien:** `src/MqttPublisher.cpp`/`.hpp`, `src/LogCapture.hpp` (falls Event-Zugriff nötig) + +**Schritte:** +1. `publishEventDiscovery()` — Muster `publishTextDiscovery` (Zeile 212) / `publishNumberDiscovery` (Zeile ~200), TopicBuilder (`homeassistant//pool-controller//config`, `cfgTopic.build("event", objectId, "/config")`): +```cpp +void MqttPublisher::publishEventDiscovery(const char *objectId, const char *name, const char *icon) { + TopicBuilder cfgTopic, stateTopic; + JsonDocument doc; + doc["name"] = name; + doc["unique_id"] = deviceId_ + "_" + objectId; + doc["state_topic"] = stateTopic.build("event", objectId, "/state"); + doc["availability_topic"] = "homeassistant/sensor/pool-controller/availability"; + doc["platform"] = "event"; // research-backed: HA event component + JsonArray eventTypes = doc["event_types"].to(); + eventTypes.add("LOG_WARN"); eventTypes.add("LOG_ERROR"); + eventTypes.add("MODE_CHANGED"); eventTypes.add("PUMP_ON"); eventTypes.add("PUMP_OFF"); + eventTypes.add("WIFI_CONNECTED"); eventTypes.add("WIFI_DISCONNECTED"); + eventTypes.add("MQTT_CONNECTED"); eventTypes.add("MQTT_DISCONNECTED"); + if (icon) doc["icon"] = icon; + addDeviceInfo(doc); + char payloadBuf[1024]; + serializeJson(doc, payloadBuf, sizeof(payloadBuf)); + NetworkManager::publish(cfgTopic.build("event", objectId, "/config"), payloadBuf, true); +} +``` +2. In `publishDiscovery()` (Zeile ~430, nach `isMqttConnected()`-Guard): `publishEventDiscovery("logs", "Pool Controller Logs", "mdi:clipboard-text-outline");` +3. **Export-Pumpe** — in `publishStates()` (wird im Loop 2× aufgerufen): neue Einträge seit `s_lastExportedSeq`: + - `LogCapture::logEvent`-Marker `[EVENT]` bzw. die Event-Marker (Mode/Pump/Wifi/MQTT/OTA — in Task 3 als `logEvent` gesetzt) → `{"event_type": "", "message": ""}` auf `stateTopic` (`event`-Component) — **nur** bei Änderung (dedup: gleiche seq nicht erneut). + - WARN/ERROR-Einträge ohne Event-Marker → `{"event_type": "LOG_WARN"|"LOG_ERROR", "message": "..."}` auf denselben `stateTopic`. + - **Raw-Topic** `pool-controller/log` (via `getBaseTopic()`): WARN/ERROR als JSON-Lines `{"seq":…,"t":…,"level":…,"msg":…}` für externe Tools — mit `s_lastExportedSeq` dedupliziert. + - `s_lastExportedSeq = LogCapture::lastSeq();` am Ende (Volumen-Kontrolle: keine Info/Debug über MQTT). +4. **Kuratierte Event-Trigger** (setzen als `logEvent` beim Übergang, Referenz aus Task 3): + - Mode-Wechsel: `OperationModeNode`/`PoolController` (mode set) → `logEvent("MODE_CHANGED", ...)` + - Pumpe: `PoolController::togglePoolPump/toggleSolarPump` → `PUMP_ON`/`PUMP_OFF` + - WLAN: `NetworkManager` connect/disconnect (Zeile ~256/268) → `WIFI_CONNECTED`/`WIFI_DISCONNECTED` + - MQTT: `MqttPublisher::onMqttConnect/onMqttDisconnect` → `MQTT_CONNECTED`/`MQTT_DISCONNECTED` + +**Test (TDD):** +- `test_mqttpublisher.cpp` erweitern (Muster `mqttCapture.published`): + - Nach `begin()`: Discovery-Payload für `homeassistant/event/pool-controller/logs/config` enthält `"platform":"event"` und `event_types` mit `LOG_WARN`. + - Export-Pumpe: WARN-Entry in LogCapture → nach `publishStates()` ist `{"event_type":"LOG_WARN",...}` auf dem event-state-Topic publiziert; Info-Entry wird NICHT publiziert. + - Dedup: zweiter `publishStates()`-Aufruf ohne neue Einträge publiziert nichts Neues. + - `logEvent("MODE_CHANGED", ...)` → `event_type` = `MODE_CHANGED`. +- MqttPublisher ist WRAPPER_SOURCE (wrapper generiert `wrappers/MqttPublisher.cpp` mit `mqttCapture`) — neue Publikationen laufen über `NetworkManager::publish` (Mock, `_mqttConnected=true`). + +**Verify:** test_runner + relay_safety grün; `pio run` grün. + +**Commit:** `feat(logging): export log events via MQTT event entity with HA discovery` + +--- + +### Task 6 — Web-UI: Dashboard-Button, More-Eintrag, Log-Konsole + +**Dateien:** `data/web/index.html`, `data/web/app.js`, `data/web/style.css` (LittleFS-Deployment via `uploadfs`) + +**Schritte:** +1. `index.html`: + - Dashboard-Header (bei Login-Banner-Zeile ~146): `` — sichtbar **immer** (unauthentifizierter Einstieg). + - More-Menü (`moreMenu`, Zeile ~67-83): `📜 Logs` vor `wifi`. + - Neuer `
` (Muster `tab-wifi` etc.): + - Kopf: Filter-Chips `Alle` / `Warnungen` / `Fehler` + `Logs löschen`-Button (`hidden` ohne Login). + - `
` (Scroll-Container) + `
`. +2. `app.js`: + - `moreTabs = ['logs', 'wifi', 'mqtt', 'system', 'about']` (Zeile 15) — `logs` wird über das More-Menü erreicht, `barTab`-Mapping greift. + - `switchTab('logs')` zeigt `#tab-logs` (bestehende Mechanik reicht). + - `loadLogs()`: `fetch('/api/logs?since=' + lastSeq + '&count=200&level=' + levelFilter)` → Einträge an `#logConsole` anhängen (`textContent`-basiert, keine innerHTML mit Fremdtext!), `lastSeq = data.next`; Auto-Scroll ans Ende **nur wenn** User nicht hochgescrollt hat (`scrollTop + clientHeight >= scrollHeight - 40`); relative Zeit (Uptime-ms → `h:mm:ss`). + - `setInterval(loadLogs, 2000)` (parallel zu `loadTelemetry`, Zeile ~1005); beim Tab-Wechsel zu `logs` sofort einmal laden. + - Filter-Chips: Klick setzt `levelFilter` (`info|warning|error`), leert Konsole, `lastSeq=0`, sofort `loadLogs()`. + - Clear-Button: nur sichtbar wenn `isAuthenticated` (`updateAuthUI()`-Erweiterung, Zeile ~225); Klick → `fetch('/api/logs/clear', {method:'POST'})` → Konsole leeren, `lastSeq=0`. + - Escape-Hilfe: `function escapeHtml(s)` (ersetze `<`, `>`, `&`, `"`) — verwenden für `msg`. +3. `style.css`: `#logConsole` (monospace, `overflow-y: auto`, max-height), Level-Farben (`.log-debug` grau, `.log-info` default, `.log-warn` amber, `.log-error` rot), Chips, Empty-State. + +**Hinweis:** UI-Arbeit wird beim Ausführen an `@designer` gegeben (Layout/Feel) — Copy danach vom Orchestrator geprüft. Design-Absicht (Polling, Pause-on-Scroll, Filter, Auth-Gating) bleibt fix. + +**Verify:** `pio run` + `uploadfs`-Deployment auf Gerät (oder lokale Inspektion); manuell: Button ohne Login erreichbar, Konsole füllt sich, Scroll-Pause, Filter, Clear nur mit Login, XSS-Check (Sonderzeichen in Logs rendern sicher). + +**Commit:** `feat(logging): add web log console with polling, filters and auth-gated clear` + +--- + +### Task 7 — Dokumentation (EN + DE) + +**Dateien:** `docs/mqtt-configuration.md` + `.de.md`, `docs/software-guide.md` + `.de.md`, `docs/home-assistant/_index.md` + `.de.md` + +**Inhalt:** +1. `mqtt-configuration.*`: neues Topic `homeassistant/event/pool-controller/logs/config` (Discovery, `platform: event`, `event_types`-Liste), State-Topic, Raw-Topic `pool-controller/log` (JSON-Lines, WARN/ERROR), Beispiel-Payload. +2. `software-guide.*`: REST-API `GET /api/logs` (Parameter `since`/`count`/`level`, Beispiel-Response), `POST /api/logs/clear` (Auth), Web-Log-Konsole (Platzierung: Dashboard-Button + More-Menü, Filter, Auto-Polling). +3. `home-assistant/_index.*`: **Logbook-Automation-Blueprint** (dokumentiert, nicht im Firmware) — YAML-Snippet, das `event`-Entity-Events in das HA-Logbook schreibt (Trigger `event`, Bedingung event_type in Liste, `logbook.log`-Action). + +**Verify:** Markdown-Validierung (Dateien existieren EN+DE, Links konsistent), kein Build-Einfluss. + +**Commit:** `docs(logging): document log view API, MQTT event entity and HA logbook blueprint` + +--- + +### Task 8 — Gesamt-Verifikation & Review + +**Schritte:** +1. Vollständiger CI-Lauf lokal: `pio run` + `test_runner` (ASAN) + `relay_safety`. +2. Serial-Invarianz-Stichprobe: vor/nach Diff der formatierten Strings (kein Zeichenverlust, `\n`-Semantik println→`\n`). +3. Review durch @oracle (Risiko: Ringbuffer-Corner-Cases, Thread-Safety, XSS, MQTT-Volumen) — optional, wenn Task 1-6 ohne Auffälligkeiten. +4. Finale Commit-Historie prüfen (Conventional Commits, Scope `logging`). +5. Deployment-Vorbereitung: `pio run`-Binary für `uploadfs` + OTA (Deploy-Skill folgt separat, nicht Teil dieses Plans). + +**Commit:** ggf. `fix(logging): ...` für Review-Fundstücke. + +--- + +## Selbst-Review gegen Spec + +| Spec-Anforderung | Plan-Abdeckung | +|---|---| +| Ansatz A: zentrale Capture + Migration | Task 1 + 3 (253 Calls / 21 Dateien, verifizierte Zahlen) | +| RAM-Ringbuffer, kein Heap | Task 1 (statisch, vsnprintf, IoT-Gates) | +| Unauthentifiziertes `/api/logs` (Polling `since`) | Task 4 (since/count/level, Cap 500) | +| Clear nur mit Login | Task 4 (`handleAuthentication`) | +| MQTT-Export WARN/ERROR + kuratierte Events | Task 5 (event-Entity + Raw-Topic, dedup via lastExportedSeq) | +| HA-Discovery research-backed (event-Typ) | Task 5 (committed Ergebnis 2e40262, `platform: event`) | +| UI: Konsole, 2s-Polling, Filter, Pause-on-Scroll | Task 6 (Polling-Muster wie loadTelemetry) | +| Platzierung: Dashboard-Button + More-Menü | Task 6 (Dashboard = unauthentifizierter Einstieg, More für eingeloggte) | +| LittleFS-only, kein PROGMEM | Task 4/6 (keine PROGMEM-Anteile) | +| Docs EN+DE | Task 7 (alle 3 Docs-Paare) | +| Native Tests + relay_safety grün | jeder Task (Verify-Block) | +| Ohne @librarian | eingehalten — Recherche committed, keine externe Recherche nötig | + +## Risiken / Offene Punkte + +1. **Ringbuffer-Volumen**: Poll-Schleifen-Logging (DallasTemperature) muss auf `LOG_DEBUG` — sonst ist der 8KB-Ring in Sekunden überschrieben und die Web-Konsole zeigt nur Hot-Path-Logs. Task 3 Sonderfälle deckt das ab; Review-Schritt 8.3 validiert. +2. **`Update.printError(Serial)`** bleibt serial-gebunden (library-intern) — Web/MQTT sehen OTA-Fehler nur über den kuratierten `OTA_FAILED`-Event (Task 3, Sonderfälle). +3. **Event-Dedup über Reconnect**: `s_lastExportedSeq` ist RAM-only — nach Reboot werden ältere seqs nicht re-exportiert (gewollt; MQTT-retained nur Discovery, nicht Events). +4. **XSS**: Log-Console rendert nur via `textContent`/`escapeHtml` — Fremdtexte (Mode-Namen, WLAN-SSIDs) sind potenzielle Payloads. diff --git a/docs/superpowers/specs/2026-07-31-logging-view-design.md b/docs/superpowers/specs/2026-07-31-logging-view-design.md new file mode 100644 index 00000000..b2d6a240 --- /dev/null +++ b/docs/superpowers/specs/2026-07-31-logging-view-design.md @@ -0,0 +1,166 @@ +# Design: Logging View for Pool Controller + +**Date:** 2026-07-31 +**Status:** Approved (brainstorming) +**Scope:** New "Logs" view in the web UI with RAM ring buffer log capture, REST endpoint, MQTT export, and UI console. + +## Motivation + +The pool controller currently logs exclusively to the serial interface (253 +`Serial.printf/print/println` calls across 21 files). There is no way to inspect +logs from the web UI, which makes remote debugging difficult on a 24/7 device. + +This feature adds a web-based logging view: the device captures log lines into a +RAM ring buffer, serves them via an unauthenticated read-only REST endpoint, and +optionally exports warnings/errors to MQTT (Home Assistant). The UI shows the log +as a console with level filters, auto-refresh, and auto-scroll. + +## Requirements (from brainstorming) + +1. **Content:** Full system log + filtered event view (level/category filters). +2. **Persistence:** RAM ring buffer only (no flash wear). Optional MQTT export for + warnings/errors + curated events so logs survive reboot in Home Assistant. +3. **Placement:** "📜 Logs" button on the dashboard plus an entry in the More + bottom-sheet menu (not a bottom tab). The dashboard button is the unauthenticated + access path — the tab bar and More menu are hidden entirely without login. +4. **Access:** Read-only without login (like dashboard telemetry); clear operation + requires login. +5. **Updates:** Auto-polling every 2 s while the tab is visible (same pattern as + dashboard telemetry). + +## Approach (chosen: A — central capture + migration) + +Full migration of all `Serial.printf/print/println` calls to a central logging API +that continues to write to Serial (behavior unchanged) and additionally appends to +the ring buffer. + +## Architecture + +### 1. LogCapture module (`src/LogCapture.{hpp,cpp}`) + +Replaces the current stub `src/Nodes/Logger.{hpp,cpp}`. + +- **Static ring buffer**: fixed size (default 8 KB, configurable via build flag + `-DLOG_BUFFER_SIZE=`). No heap allocation per log line → no fragmentation. + Estimated ~80–100 bytes/entry → ~80–100 lines in the buffer. +- **Entry format**: `{seq, level, uptime_ms, msg}`. + - `seq`: monotonically increasing sequence number (uint32) for incremental polling. + - `level`: enum `Debug, Info, Warning, Critical, Error` (reuse existing + `Logger::LogLevel` enum names). + - `uptime_ms`: milliseconds since boot (survives in the entry; absolute time is + derived in the UI when NTP is synced). + - `msg`: null-terminated formatted string. +- **API**: + - `LogCapture::log(Level level, const char *fmt, ...)` — variadic snprintf into a + static buffer, write to Serial AND append to ring buffer. + - `LogCapture::begin()` — initialize (called from `setup()`). + - `LogCapture::getEntries(uint32_t since, size_t maxCount, Level minLevel, ...)` + — returns entries after `since`, capped, filtered by level (for REST handler). + - `LogCapture::clear()` — reset ring buffer. +- **Thread safety**: short critical section (portMUX or mutex) — writes come from + both the WebServer task and the main loop task. +- **Level filtering at capture time**: configurable; DEBUG included by default at + build, standard capture from INFO up (configurable via build flag if needed). +- Remove the stub `Nodes/Logger` (or fold its enum/flags into `LogCapture`). + +### 2. Log capture: migration of 276 Serial calls + +- New macros `LOG_DEBUG/LOG_INFO/LOG_WARN/LOG_ERROR(...)` that expand to + `LogCapture::log(Level::..., __VA_ARGS__)`. +- **Mechanical migration** via ast-grep: + - `Serial.printf("...", ...)` → `LOG_INFO("...", ...)` (level inferred from + message content: "WARNING"/"ERROR"/"CRITICAL" prefixes → respective level, + else INFO). + - Multi-part `Serial.print` chains: combine into a single `LOG_*` call where + mechanical; remaining special cases (e.g. `Update.printError(Serial)`, + library-internal prints) handled manually. +- **Invariant:** serial output stays byte-identical after migration. Verify by + comparing serial output before/after on representative paths. + +### 3. REST API (`WebPortal.cpp`) + +- `GET /api/logs?level=INFO&count=200&since=` — **no auth** (read-only). + - Response: `{"entries": [{"seq": 42, "level": "INFO", "uptime": 3610, "msg": "..."}], "next_seq": 43}` + - `level` ∈ {DEBUG, INFO, WARN, ERROR} (server-side filter; WARN includes + Warning+Critical+Error, ERROR includes Error). + - `count` default 200, max 500. +- `POST /api/logs/clear` — **auth required** (clears ring buffer; for debugging). + +### 4. MQTT export (`MqttPublisher`) + +Follow existing HA Discovery patterns (`publishTextDiscovery`, `getBaseTopic`). +Research-backed format (official `event.mqtt` docs + HA Core sources): the HA +**MQTT event entity** is the idiomatic representation for discrete device +events; a text/sensor entity would only show a "last line" without history. + +- **Raw topic** `pool/log` (JSON lines, QoS 0, non-retained) — for external + tools. Payload: `{"level":"WARN","uptime":3610,"msg":"..."}`. +- **HA event entity "Pool Controller Event"** via MQTT Discovery + (`platform: event`) on topic `pool/event`: + - Discovery topic `homeassistant/event//pool_controller_event/config` + (retained), payload `{"platform":"event","name":"Pool Controller Event", + "unique_id":"pool_controller_event","state_topic":"pool/event", + "event_types":["mode_changed","pump_on","pump_off","wifi_connected", + "wifi_disconnected","mqtt_connected","mqtt_disconnected","ota_started", + "ota_success","ota_failed","factory_reset","warning","error"], + "entity_category":"diagnostic","device":{...same block as sensors...}}`. + - State payload (JSON, **must** contain `event_type` ∈ `event_types`): + `{"event_type":"pump_on","message":"Pump turned on","level":"INFO","uptime":3610}` + — extra keys (`message`, `level`, `uptime`) become entity attributes. + Events are stateless; replayed retained messages are discarded by HA. + - Separate `pool/event` topic (instead of reusing `pool/log`) keeps the + event_type always present without a fragile `value_template` on the raw log + stream. The `value_template` is intentionally omitted. +- **Volume control:** only WARN/ERROR + curated events (mode changes, pump + toggles, WiFi/MQTT connect/disconnect, OTA, factory reset) are published to + MQTT — not every INFO line. +- **Logbook (documented, not firmware):** event entities do *not* create + message-bearing logbook entries (`event_type: LOGBOOK_ENTRY` is a known + misconception). Users who want pool events in the HA logbook get a documented + automation blueprint: MQTT trigger on `pool/event` → `logbook.log` service + with `name`, `message: "{{ trigger.payload_json.event_type }}: {{ ... }}"` + and `entity_id`. This stays in docs, never in firmware. +- **ESPHome precedent (documented):** ESPHome forwards device logs into the HA + core log (default level WARNING, no MQTT equivalent of log_stream); our event + entity is the MQTT-only analog. + +### 5. Web UI (`data/web/index.html`, `data/web/app.js`, `data/web/style.css`) + +- **More menu**: new entry `📜 Logs` → `switchTab('logs')`. +- **Tab** `#tab-logs`: + - Console view: monospace, level colors (Info blue, Warn yellow, Error red), + auto-scroll, pause on manual scroll-up. + - Filter chips: All / Info / Warn / Error (frontend filter on loaded entries). + - Auto-polling every 2 s via `/api/logs` with `since` while tab visible; stop + when hidden (same pattern as `loadTelemetry`). + - Timestamps: relative (`+1h 02m 33s` since boot); absolute time when NTP synced + (compare with `/api/status` `local_time`). + - "Clear" button — only visible when authenticated. +- **LittleFS only**: web assets are served from LittleFS exclusively — + `WebPortal.cpp:58` documents "PROGMEM fallbacks removed". No PROGMEM mirror + for the new view (previous plan draft's fallback is obsolete by decision). + +## Error handling + +- Ring buffer overflow: oldest entries overwritten (ring semantics); API always + returns entries + `next_seq` so the client can resume. +- Reboot: logs lost (RAM-only by design); MQTT export compensates partially. +- WebServer task vs loop task: single critical section guards append. +- JSON serialization: use existing `JsonDocument` pattern; cap response size. + +## Testing + +- Unit tests for ring buffer: wrap-around, `since` pagination, level filter + (existing test setup, native build). +- Migration verification: firmware builds; serial output on representative paths + (boot, mode change, MQTT connect) is byte-identical before/after. +- Manual: `pio run --target uploadfs` + browser; verify tab in LittleFS mode + (the only mode — no PROGMEM fallback exists). +- MQTT: mosquitto subscribe `pool/log`, HA sensor appears via discovery. + +## Out of scope + +- Persistent flash logging (rejected: flash wear on 24/7 device). +- Real-time streaming (SSE/WebSocket) — 2 s polling is sufficient. +- Log download/export to file in UI. +- Per-module log level configuration at runtime. diff --git a/platformio.ini b/platformio.ini index 6242481a..861dce9a 100644 --- a/platformio.ini +++ b/platformio.ini @@ -36,6 +36,7 @@ build_flags = '-D GITHUB_REPO="smart-swimmingpool/pool-controller"' -D SERIAL_SPEED=${common.serial_speed} -D NORVI_AE01_R + -D LOG_BUFFER_SIZE=8192 -std=c++17 -Wno-deprecated-declarations build_unflags = -Werror=reorder @@ -58,6 +59,7 @@ build_flags = '-D FW_VERSION="4.2.1"' # x-release-please-version '-D GITHUB_REPO="smart-swimmingpool/pool-controller"' -D SERIAL_SPEED=${common.serial_speed} + -D LOG_BUFFER_SIZE=8192 -std=c++17 -Wno-deprecated-declarations ; Suppress deprecation warnings from libraries build_unflags = -Werror=reorder diff --git a/src/ConfigManager.cpp b/src/ConfigManager.cpp index c5896aaa..63c90930 100644 --- a/src/ConfigManager.cpp +++ b/src/ConfigManager.cpp @@ -9,6 +9,7 @@ #include "ConfigManager.hpp" #include "Version.h" +#include "LogCapture.hpp" #include #include @@ -71,14 +72,14 @@ static constexpr const char *kCfgConfigured = "cfg_configured"; // ── Lifecycle ── bool ConfigManager::begin() { - Serial.println("✓ NVS config namespace opened"); + LOG_INFO("✓ NVS config namespace opened\n"); return load(); } bool ConfigManager::load() { Preferences prefs; if (!prefs.begin(kNvsNamespace, true)) { // read-only mode - Serial.println("✖ Failed to open NVS config namespace"); + LOG_ERROR("✖ Failed to open NVS config namespace\n"); reset(); return false; } @@ -111,14 +112,14 @@ bool ConfigManager::load() { prefs.end(); - Serial.println("✓ Configuration loaded from NVS"); + LOG_INFO("✓ Configuration loaded from NVS\n"); return true; } bool ConfigManager::save() { Preferences prefs; if (!prefs.begin(kNvsNamespace, false)) { // read-write mode - Serial.println("✖ Failed to open NVS config namespace for writing"); + LOG_ERROR("✖ Failed to open NVS config namespace for writing\n"); return false; } @@ -150,7 +151,7 @@ bool ConfigManager::save() { prefs.end(); - Serial.println("✓ Configuration saved to NVS"); + LOG_INFO("✓ Configuration saved to NVS\n"); return true; } @@ -169,7 +170,7 @@ void ConfigManager::reset() { adminPasswordHash_ = kDefaultPasswordHash; // Reset to default "admin" password configured_ = false; - Serial.println("✓ Configuration reset to factory defaults"); + LOG_INFO("✓ Configuration reset to factory defaults\n"); } // ── Boot Version Tracking ── @@ -183,16 +184,16 @@ void ConfigManager::logOtaTransition() { if (previousVersion.isEmpty()) { // First boot ever — nothing to compare - Serial.printf("ℹ First boot — firmware version %s\n", runningVersion.c_str()); + LOG_INFO("ℹ First boot — firmware version %s\n", runningVersion.c_str()); } else if (previousVersion != runningVersion) { // Version changed — OTA update just happened - Serial.printf("◉ OTA UPDATE DETECTED: %s → %s\n", previousVersion.c_str(), runningVersion.c_str()); + LOG_INFO("◉ OTA UPDATE DETECTED: %s → %s\n", previousVersion.c_str(), runningVersion.c_str()); // Update stored version to match running version prefs.putString("fw_version", runningVersion); } else { // Normal boot — same version - Serial.printf("ℹ Normal boot — firmware %s (no OTA change)\n", runningVersion.c_str()); + LOG_INFO("ℹ Normal boot — firmware %s (no OTA change)\n", runningVersion.c_str()); } prefs.end(); @@ -220,10 +221,10 @@ void ConfigManager::saveSensorMapping(const uint8_t solarAddr[8], const uint8_t char buf[17]; snprintf(buf, sizeof(buf), "%02X%02X%02X%02X%02X%02X%02X%02X", solarAddr[0], solarAddr[1], solarAddr[2], solarAddr[3], solarAddr[4], solarAddr[5], solarAddr[6], solarAddr[7]); - Serial.printf("✓ Sensor mapping saved: Solar [%s]", buf); + LOG_INFO("✓ Sensor mapping saved: Solar [%s]", buf); snprintf(buf, sizeof(buf), "%02X%02X%02X%02X%02X%02X%02X%02X", poolAddr[0], poolAddr[1], poolAddr[2], poolAddr[3], poolAddr[4], poolAddr[5], poolAddr[6], poolAddr[7]); - Serial.printf(", Pool [%s]\n", buf); + LOG_INFO(", Pool [%s]\n", buf); } bool ConfigManager::loadSensorMapping(uint8_t solarAddr[8], uint8_t poolAddr[8]) { diff --git a/src/DallasTemperatureNode.cpp b/src/DallasTemperatureNode.cpp index 06a675c3..14f88eb9 100644 --- a/src/DallasTemperatureNode.cpp +++ b/src/DallasTemperatureNode.cpp @@ -13,6 +13,7 @@ #include "SystemMonitor.hpp" #include "DegradationManager.hpp" #include "Utils.hpp" +#include "LogCapture.hpp" // ── Dedicated bus constructor ────────────────────────────────────────────── @@ -88,14 +89,14 @@ bool DallasTemperatureNode::resolveFilter() { _sensorFound = true; char adr[18]; address2String(addr, adr, sizeof(adr)); - Serial.printf(" ◦ %s: filter resolved → device %d [%s] ✓\n", _id, i, adr); + LOG_INFO(" ◦ %s: filter resolved → device %d [%s] ✓\n", _id, i, adr); return true; } } } // Filter address not found on bus — fall back to deviceIndex_ - Serial.printf(" ✖ %s: filter address not found on bus! " - "Falling back to device index %d\n", + LOG_ERROR(" ✖ %s: filter address not found on bus! " + "Falling back to device index %d\n", _id, deviceIndex_); if (activeSensor->getAddress(deviceAddress_, deviceIndex_)) { _sensorFound = true; @@ -111,11 +112,11 @@ bool DallasTemperatureNode::resolveFilter() { _sensorFound = true; char adr[18]; address2String(deviceAddress_, adr, sizeof(adr)); - Serial.printf(" ◦ %s: no filter → device %d [%s]", _id, deviceIndex_, adr); if (sharedSensor_) { - Serial.print(" (shared bus)"); + LOG_INFO(" ◦ %s: no filter → device %d [%s] (shared bus)\n", _id, deviceIndex_, adr); + } else { + LOG_INFO(" ◦ %s: no filter → device %d [%s]\n", _id, deviceIndex_, adr); } - Serial.println(); return true; } } @@ -160,11 +161,11 @@ void DallasTemperatureNode::begin() { // Shared mode: sensor->begin() was already called externally — just scan numberOfDevices = activeSensor->getDeviceCount(); - Serial.printf("• DallasTemperature: Parasite power is: %d\n", activeSensor->isParasitePowerMode()); + LOG_INFO("• DallasTemperature: Parasite power is: %d\n", activeSensor->isParasitePowerMode()); if (numberOfDevices > 0) { uint8_t displayPin = sharedSensor_ ? PoolController::PIN_DS_SOLAR : _pin; - Serial.printf(" ◦ %d devices found on PIN %d\n", numberOfDevices, displayPin); + LOG_INFO(" ◦ %d devices found on PIN %d\n", numberOfDevices, displayPin); // ── Print all detected devices ────────────────────────────────────── for (uint8_t i = 0; i < numberOfDevices; i++) { @@ -172,7 +173,7 @@ void DallasTemperatureNode::begin() { if (activeSensor->getAddress(addr, i)) { char adr[18]; address2String(addr, adr, sizeof(adr)); - Serial.printf(" ◦ PIN %d: Device %d address: %s\n", displayPin, i, adr); + LOG_INFO(" ◦ PIN %d: Device %d address: %s\n", displayPin, i, adr); } } @@ -188,7 +189,7 @@ void DallasTemperatureNode::begin() { } } else { uint8_t displayPin = sharedSensor_ ? PoolController::PIN_DS_SOLAR : _pin; - Serial.printf("✖ No Dallas sensors found on pin %d\n", displayPin); + LOG_ERROR("✖ No Dallas sensors found on pin %d\n", displayPin); _sensorFound = false; PoolController::DegradationManager::reportSensorStatus(_id, false); } @@ -205,7 +206,7 @@ void DallasTemperatureNode::loop() { // ── Shared bus mode ──────────────────────────────────────────────── // The master (deviceIndex 0) drives the conversion for all sensors. if (isBusMaster_) { - Serial.printf("〽 Reading Dallas sensors (shared bus)\n"); + LOG_DEBUG("〽 Reading Dallas sensors (shared bus)\n"); PoolController::SystemMonitor::feedWatchdog(); activeSensor->requestTemperatures(); @@ -214,7 +215,7 @@ void DallasTemperatureNode::loop() { // Master reads its own sensor float newTemp = activeSensor->getTempC(deviceAddress_); if (newTemp == DEVICE_DISCONNECTED_C) { - Serial.println(" ✖ Solar sensor disconnected - setting to NaN"); + LOG_ERROR(" ✖ Solar sensor disconnected - setting to NaN\n"); _temperature = NAN; _sensorFound = false; PoolController::DegradationManager::reportSensorStatus(_id, false); @@ -222,13 +223,13 @@ void DallasTemperatureNode::loop() { _temperature = newTemp; _sensorFound = true; PoolController::DegradationManager::reportSensorStatus(_id, true); - Serial.printf(" ◦ Solar Temp = %.1f°C\n", _temperature); + LOG_DEBUG(" ◦ Solar Temp = %.1f°C\n", _temperature); } } else { // Slave: read from the conversion the master already triggered float newTemp = activeSensor->getTempC(deviceAddress_); if (newTemp == DEVICE_DISCONNECTED_C) { - Serial.println(" ✖ Pool sensor disconnected - setting to NaN"); + LOG_ERROR(" ✖ Pool sensor disconnected - setting to NaN\n"); _temperature = NAN; _sensorFound = false; PoolController::DegradationManager::reportSensorStatus(_id, false); @@ -236,12 +237,12 @@ void DallasTemperatureNode::loop() { _temperature = newTemp; _sensorFound = true; PoolController::DegradationManager::reportSensorStatus(_id, true); - Serial.printf(" ◦ Pool Temp = %.1f°C\n", _temperature); + LOG_DEBUG(" ◦ Pool Temp = %.1f°C\n", _temperature); } } } else if (numberOfDevices > 0) { // ── Dedicated bus mode (standard) ────────────────────────────────── - Serial.printf("〽 Reading Dallas sensor: %s\n", _id); + LOG_DEBUG("〽 Reading Dallas sensor: %s\n", _id); PoolController::SystemMonitor::feedWatchdog(); activeSensor->requestTemperatures(); @@ -252,7 +253,7 @@ void DallasTemperatureNode::loop() { if (activeSensor->getAddress(tempDeviceAddress, i)) { float newTemp = activeSensor->getTempC(tempDeviceAddress); if (newTemp == DEVICE_DISCONNECTED_C) { - Serial.println(" ✖ Sensor disconnected - setting to NaN"); + LOG_ERROR(" ✖ Sensor disconnected - setting to NaN\n"); _temperature = NAN; _sensorFound = false; PoolController::DegradationManager::reportSensorStatus(_id, false); @@ -260,13 +261,13 @@ void DallasTemperatureNode::loop() { _temperature = newTemp; _sensorFound = true; PoolController::DegradationManager::reportSensorStatus(_id, true); - Serial.printf(" ◦ Temp = %.1f°C\n", _temperature); + LOG_DEBUG(" ◦ Temp = %.1f°C\n", _temperature); } } } } else { // ── No sensor found — rescan ────────────────────────────────────── - Serial.println("No Sensor found on bus! Rescanning..."); + LOG_INFO("No Sensor found on bus! Rescanning...\n"); PoolController::DegradationManager::reportSensorStatus(_id, false); if (sharedSensor_) { @@ -277,13 +278,13 @@ void DallasTemperatureNode::loop() { activeSensor->getAddress(deviceAddress_, deviceIndex_); _sensorFound = true; PoolController::DegradationManager::reportSensorStatus(_id, true); - Serial.printf(" ◦ %d device(s) found after rescan\n", numberOfDevices); + LOG_INFO(" ◦ %d device(s) found after rescan\n", numberOfDevices); } } else { activeSensor->begin(); numberOfDevices = activeSensor->getDeviceCount(); if (numberOfDevices > 0) { - Serial.printf(" ◦ %d device(s) found after rescan\n", numberOfDevices); + LOG_INFO(" ◦ %d device(s) found after rescan\n", numberOfDevices); _sensorFound = true; } } diff --git a/src/DegradationManager.cpp b/src/DegradationManager.cpp index bd8c8d02..9d02df64 100644 --- a/src/DegradationManager.cpp +++ b/src/DegradationManager.cpp @@ -9,6 +9,7 @@ */ #include "DegradationManager.hpp" +#include "LogCapture.hpp" #include "NetworkManager.hpp" #include "Nodes.hpp" #include "SystemMonitor.hpp" @@ -43,7 +44,7 @@ void DegradationManager::begin() { forcedSafeMode_ = false; lastEvaluationMs_ = 0; - Serial.println(F("✓ DegradationManager initialized")); + LOG_INFO("✓ DegradationManager initialized\n"); } void DegradationManager::evaluate() { @@ -133,35 +134,32 @@ void DegradationManager::unforceSafeMode() { void DegradationManager::onTransition() { // Log the transition - Serial.print(F("⚙ Degradation: ")); - Serial.print(levelToString(previousLevel_)); - Serial.print(F(" → ")); - Serial.println(levelToString(currentLevel_)); + LOG_INFO("⚙ Degradation: %s → %s\n", levelToString(previousLevel_), levelToString(currentLevel_)); // Additional per-level actions switch (currentLevel_) { case DegradationLevel::NORMAL: - Serial.println(F("✓ All systems nominal")); + LOG_INFO("✓ All systems nominal\n"); break; case DegradationLevel::NO_WIFI: - Serial.println(F("⚠ WiFi/MQTT disconnected — operating offline")); - Serial.println(F(" All control rules still active")); + LOG_WARN("⚠ WiFi/MQTT disconnected — operating offline\n"); + LOG_WARN(" All control rules still active\n"); break; case DegradationLevel::NO_TIME: - Serial.println(F("⚠ NTP time sync lost — timer scheduling degraded")); - Serial.println(F(" Timer mode falls back to auto mode")); + LOG_WARN("⚠ NTP time sync lost — timer scheduling degraded\n"); + LOG_WARN(" Timer mode falls back to auto mode\n"); break; case DegradationLevel::NO_SENSOR: - Serial.println(F("⚠ Temperature sensor fault — using cautious defaults")); - Serial.println(F(" Auto mode may not function correctly")); + LOG_WARN("⚠ Temperature sensor fault — using cautious defaults\n"); + LOG_WARN(" Auto mode may not function correctly\n"); break; case DegradationLevel::CRITICAL: - Serial.println(F("✖ CRITICAL: Multiple system failures detected!")); - Serial.println(F(" Entering safe mode — all relays off")); + LOG_ERROR("✖ CRITICAL: Multiple system failures detected!\n"); + LOG_ERROR(" Entering safe mode — all relays off\n"); // De-energize both relays immediately (P1 review fix) poolPumpNode.setSwitch(false); solarPumpNode.setSwitch(false); @@ -171,7 +169,7 @@ void DegradationManager::onTransition() { // MQTT notification — best-effort, no retry. // Full publish is handled by MqttPublisher on its next publish cycle. if (NetworkManager::isMqttConnected()) { - Serial.println(F(" Degradation state will be published via MQTT")); + LOG_INFO(" Degradation state will be published via MQTT\n"); } } diff --git a/src/ESP32TemperatureNode.cpp b/src/ESP32TemperatureNode.cpp index fc9fb9ab..a9ebb66a 100644 --- a/src/ESP32TemperatureNode.cpp +++ b/src/ESP32TemperatureNode.cpp @@ -9,6 +9,7 @@ #include "ESP32TemperatureNode.hpp" #include "Utils.hpp" +#include "LogCapture.hpp" ESP32TemperatureNode::ESP32TemperatureNode(const char *id, const char *name, const int measurementInterval) { _id = id; @@ -19,7 +20,7 @@ ESP32TemperatureNode::ESP32TemperatureNode(const char *id, const char *name, con } void ESP32TemperatureNode::begin() { - Serial.printf("• ESP32 Internal Temp sensor '%s' initialized.\n", _id); + LOG_INFO("• ESP32 Internal Temp sensor '%s' initialized.\n", _id); } void ESP32TemperatureNode::loop() { @@ -34,6 +35,6 @@ void ESP32TemperatureNode::loop() { // standard conversion is: C = (F - 32) / 1.8 _temperature = (temp_farenheit - 32.0f) / 1.8f; - Serial.printf("〽 ESP32 internal temp: %f °C\n", _temperature); + LOG_DEBUG("〽 ESP32 internal temp: %f °C\n", _temperature); } } diff --git a/src/LogCapture.cpp b/src/LogCapture.cpp new file mode 100644 index 00000000..e074e719 --- /dev/null +++ b/src/LogCapture.cpp @@ -0,0 +1,233 @@ +// Copyright (c) 2018-2026 Smart Swimming Pool, Stephan Strittmatter +// +// SPDX-License-Identifier: MIT + +/** + * @file LogCapture.cpp + * @brief Central ring-buffer logger implementation. + * + * Static RAM ring buffer (no heap), optionally mirrored to Serial. + * On ESP32 the ring is guarded by a portMUX critical section so it is safe + * from loop, WebServer handlers, and WiFi/MQTT callbacks. Native tests + * (no ESP32 macros) compile the guard to a no-op. + */ + +#include "LogCapture.hpp" + +#include +#include +#include +#include + +// The mock Arduino.h defines ARDUINO but no ESP32 macro, so the guard keys +// off the ESP32 macros like the rest of the codebase (OtaUpdater.cpp:537). +#if defined(ESP32) || defined(ARDUINO_ARCH_ESP32) +#include +#include +#include // esp_random() for the per-boot epoch +static portMUX_TYPE s_logMux = portMUX_INITIALIZER_UNLOCKED; +#define LOG_CRITICAL_ENTER() portENTER_CRITICAL(&s_logMux) +#define LOG_CRITICAL_EXIT() portEXIT_CRITICAL(&s_logMux) +#else +#define LOG_CRITICAL_ENTER() ((void)0) +#define LOG_CRITICAL_EXIT() ((void)0) +#endif + +namespace PoolController { + +// Static storage — fixed size, no heap. +LogEntry LogCapture::s_buffer[LogCapture::LOG_BUFFER_ENTRIES]; +std::size_t LogCapture::s_head = 0; +std::uint32_t LogCapture::s_seq = 0; +std::uint32_t LogCapture::s_clearedSeq = 0; +std::uint32_t LogCapture::s_epoch = 0; +bool LogCapture::s_logToSerial = true; + +void LogCapture::begin() { + LOG_CRITICAL_ENTER(); + s_head = 0; + s_seq = 0; + s_clearedSeq = 0; +#if defined(ESP32) || defined(ARDUINO_ARCH_ESP32) + // A static RAM counter would restart at the same value after a real reboot + // (reinitialized to 0, then incremented to 1 — the same as the previous + // boot), so it cannot distinguish physical boots. Randomize instead: + // a reboot virtually never reuses the previous epoch, so persisted client + // cursors are reliably detected as stale even while the sequence catches up. + s_epoch = esp_random(); +#else + ++s_epoch; // native tests: deterministic monotonic increment per begin() +#endif + s_logToSerial = true; + LOG_CRITICAL_EXIT(); +} + +void LogCapture::log(LogLevel level, const char *fmt, ...) { + if (fmt == nullptr) { + return; + } + // Format into the full-size buffer so the Serial mirror (in store()) + // receives the complete message; only the ring copy is truncated. + char message[LOG_FORMAT_SIZE]; + va_list args; + va_start(args, fmt); + vsnprintf(message, sizeof(message), fmt, args); + va_end(args); + message[LOG_FORMAT_SIZE - 1] = '\0'; + store(level, message); +} + +void LogCapture::logEvent(const char *eventType, const char *fmt, ...) { + if (eventType == nullptr || fmt == nullptr) { + return; + } + char body[LOG_FORMAT_SIZE]; + va_list args; + va_start(args, fmt); + vsnprintf(body, sizeof(body), fmt, args); + va_end(args); + body[LOG_FORMAT_SIZE - 1] = '\0'; + + char message[LOG_FORMAT_SIZE + 64]; // room for the "[TYPE] " prefix + snprintf(message, sizeof(message), "[%s] %s", eventType, body); + store(LogLevel::Info, message); +} + +void LogCapture::store(LogLevel level, const char *message) { + const bool mirror = s_logToSerial; + + LOG_CRITICAL_ENTER(); + ++s_seq; + LogEntry &entry = s_buffer[s_head]; + entry.seq = s_seq; + entry.uptimeMs = millis(); + entry.level = level; + strncpy(entry.message, message, LOG_MSG_SIZE - 1); + entry.message[LOG_MSG_SIZE - 1] = '\0'; + s_head = (s_head + 1) % LOG_BUFFER_ENTRIES; + LOG_CRITICAL_EXIT(); + + // Mirror after leaving the critical section — Serial.print can block. + if (mirror) { + Serial.print(message); + } +} + +std::size_t LogCapture::getEntries( + std::uint32_t sinceSeq, std::uint32_t epoch, std::size_t maxCount, LogLevel minLevel, LogEntry *out, std::size_t outCapacity) { + const std::size_t cap = (maxCount < outCapacity) ? maxCount : outCapacity; + if (out == nullptr || cap == 0) { + return 0; + } + + std::size_t written = 0; + LOG_CRITICAL_ENTER(); + // A cursor is only trusted when it belongs to the current boot. Two cases + // make it stale and force a full re-read (effectiveSince = 0): + // 1. epoch mismatch: the client's cursor was persisted across a reboot + // (begin() restarted s_seq at 0 AND incremented s_epoch). A seq-only + // clamp misses this when the new boot has already produced more entries + // than the old cursor (sinceSeq <= s_seq but the entries 1..sinceSeq of + // the new boot would be skipped). + // 2. sinceSeq > s_seq within the same boot (ring wraparound past the + // cursor, or a cursor from before this feature existed with epoch 0). + const std::uint32_t effectiveSince = (epoch != s_epoch || sinceSeq > s_seq) ? 0 : sinceSeq; + // Entries written since the last clear (watermark hides pre-clear entries). + const std::uint32_t postClear = s_seq - s_clearedSeq; + const std::size_t visible = (postClear < LOG_BUFFER_ENTRIES) ? static_cast(postClear) : LOG_BUFFER_ENTRIES; + // After clear() the ring restarts at slot 0; once wrapped, s_head is oldest. + const std::size_t oldest = (postClear < LOG_BUFFER_ENTRIES) ? 0 : s_head; + + for (std::size_t i = 0; i < visible && written < cap; ++i) { + const LogEntry &entry = s_buffer[(oldest + i) % LOG_BUFFER_ENTRIES]; + if (entry.seq <= effectiveSince) { + continue; + } + if (entry.level < minLevel) { + continue; + } + out[written++] = entry; + } + LOG_CRITICAL_EXIT(); + return written; +} + +std::uint32_t LogCapture::lastSeq() { + LOG_CRITICAL_ENTER(); + const std::uint32_t seq = s_seq; + LOG_CRITICAL_EXIT(); + return seq; +} + +std::uint32_t LogCapture::epoch() { + LOG_CRITICAL_ENTER(); + const std::uint32_t epoch = s_epoch; + LOG_CRITICAL_EXIT(); + return epoch; +} + +void LogCapture::clear() { + LOG_CRITICAL_ENTER(); + // Hide everything written so far. s_seq is NOT reset so polling clients + // (which track seq) keep working; new entries continue above the watermark. + s_clearedSeq = s_seq; + s_head = 0; + LOG_CRITICAL_EXIT(); +} + +const char *LogCapture::levelName(LogLevel level) { + switch (level) { + case LogLevel::Debug: + return "debug"; + case LogLevel::Info: + return "info"; + case LogLevel::Warning: + return "warning"; + case LogLevel::Critical: + return "critical"; + case LogLevel::Error: + return "error"; + } + return "info"; +} + +LogLevel LogCapture::parseLevel(const char *name) { + if (name == nullptr) { + return LogLevel::Info; + } + // Case-insensitive compare without relying on platform string.h. + auto iequals = [](const char *a, const char *b) { + while (*a != '\0' && *b != '\0') { + if (std::tolower(static_cast(*a)) != std::tolower(static_cast(*b))) { + return false; + } + ++a; + ++b; + } + return *a == *b; + }; + + if (iequals(name, "debug")) { + return LogLevel::Debug; + } + if (iequals(name, "warning")) { + return LogLevel::Warning; + } + if (iequals(name, "error")) { + return LogLevel::Error; + } + if (iequals(name, "critical")) { + return LogLevel::Critical; + } + return LogLevel::Info; +} + +bool LogCapture::isLogToSerial() { + return s_logToSerial; +} + +void LogCapture::setLogToSerial(bool enabled) { + s_logToSerial = enabled; +} + +} // namespace PoolController diff --git a/src/LogCapture.hpp b/src/LogCapture.hpp new file mode 100644 index 00000000..584496f7 --- /dev/null +++ b/src/LogCapture.hpp @@ -0,0 +1,118 @@ +// Copyright (c) 2018-2026 Smart Swimming Pool, Stephan Strittmatter +// +// SPDX-License-Identifier: MIT + +/** + * @file LogCapture.hpp + * @brief Central ring-buffer logger — replaces direct Serial.* calls. + * + * All firmware logging flows through LogCapture: entries are stored in a + * fixed-size RAM ring buffer (no heap) and optionally mirrored to Serial + * (byte-identical, preserving existing serial debugging). REST and MQTT + * consumers read from the same buffer. + * + * Thread safety: on ESP32 the buffer is guarded by a portMUX critical + * section (callable from loop, WebServer handlers, and WiFi/MQTT callbacks). + * Native tests (no ESP32 macros) compile the guard to a no-op. + */ + +#pragma once + +#include +#include +#include + +// Configurable via PlatformIO build_flags (-DLOG_BUFFER_SIZE=...). +#ifndef LOG_BUFFER_SIZE +#define LOG_BUFFER_SIZE 8192 +#endif + +#ifndef LOG_MSG_SIZE +#define LOG_MSG_SIZE 96 +#endif + +// Formatting buffer for a single log call. Larger than LOG_MSG_SIZE so the +// Serial mirror keeps the complete formatted message (e.g. a full OTA URL) +// while only the ring copy is truncated to LOG_MSG_SIZE-1 in store(). +#ifndef LOG_FORMAT_SIZE +#define LOG_FORMAT_SIZE 512 +#endif + +namespace PoolController { + +/** + * Log levels, ordered by severity (higher = more important). + */ +enum class LogLevel : std::uint8_t { Debug = 0, Info, Warning, Critical, Error }; + +/** + * A single captured log entry. Fixed size — no heap. + */ +struct LogEntry { + std::uint32_t seq; //!< monotonically increasing, used for since-polling + std::uint32_t uptimeMs; //!< millis() at capture time + LogLevel level; //!< severity + char message[LOG_MSG_SIZE]; //!< formatted message (null-terminated) +}; + +/** + * Central logging service with a static RAM ring buffer. + */ +class LogCapture final { +public: + static constexpr std::size_t LOG_BUFFER_ENTRIES = LOG_BUFFER_SIZE / LOG_MSG_SIZE; + + /** Resets the ring and state. Called once at boot after Serial.begin(). */ + static void begin(); + /** Formats and stores an entry; mirrors to Serial when enabled. */ + static void log(LogLevel level, const char *fmt, ...); + /** Logs a curated event (Info level) with a "[TYPE] message" marker for MQTT export. */ + static void logEvent(const char *eventType, const char *fmt, ...); + /** + * Copies up to min(maxCount, outCapacity) entries newer than sinceSeq with + * level >= minLevel into out. Returns the number of entries written. + * + * The cursor (sinceSeq, epoch) is only trusted when it belongs to the + * current boot: a stale cursor — epoch != epoch() (it was persisted across a + * reboot, where begin() restarted the sequence at 0) or sinceSeq > lastSeq() + * — is treated as 0, so the whole currently-visible ring is returned + * instead of nothing or a partial new-boot log. + */ + static std::size_t getEntries( + std::uint32_t sinceSeq, std::uint32_t epoch, std::size_t maxCount, LogLevel minLevel, LogEntry *out, std::size_t outCapacity); + /** Sequence number of the last assigned entry (0 if none yet). */ + static std::uint32_t lastSeq(); + /** + * Boot epoch identifying the current boot. On ESP32 begin() assigns a fresh + * random value per boot (a RAM counter would restart at the same value after + * a real reboot and could not distinguish physical boots); native test builds + * use a deterministic monotonic increment. Clients echo it back so a reboot + * is detected even when the new sequence is still below their stored cursor. + */ + static std::uint32_t epoch(); + /** Empties the ring. s_seq is NOT reset so polling clients keep working. */ + static void clear(); + static const char *levelName(LogLevel level); + /** Parses "debug"|"info"|"warning"|"error" (case-insensitive) — unknown → Info. */ + static LogLevel parseLevel(const char *name); + static bool isLogToSerial(); + static void setLogToSerial(bool enabled); + +private: + /** Writes an already-formatted message into the ring (guarded) and mirrors to Serial. */ + static void store(LogLevel level, const char *message); + + static LogEntry s_buffer[LOG_BUFFER_ENTRIES]; + static std::size_t s_head; //!< next free slot + static std::uint32_t s_seq; //!< last assigned sequence number + static std::uint32_t s_clearedSeq; //!< watermark: entries <= this are hidden after clear() + static std::uint32_t s_epoch; //!< boot epoch, incremented by begin() + static bool s_logToSerial; +}; + +} // namespace PoolController + +#define LOG_DEBUG(...) PoolController::LogCapture::log(PoolController::LogLevel::Debug, __VA_ARGS__) +#define LOG_INFO(...) PoolController::LogCapture::log(PoolController::LogLevel::Info, __VA_ARGS__) +#define LOG_WARN(...) PoolController::LogCapture::log(PoolController::LogLevel::Warning, __VA_ARGS__) +#define LOG_ERROR(...) PoolController::LogCapture::log(PoolController::LogLevel::Error, __VA_ARGS__) diff --git a/src/MqttPublisher.cpp b/src/MqttPublisher.cpp index 4504d354..999f28c0 100644 --- a/src/MqttPublisher.cpp +++ b/src/MqttPublisher.cpp @@ -24,10 +24,27 @@ #include "RelayModuleNode.hpp" #include "TimeClientHelper.hpp" #include "Version.h" +#include "LogCapture.hpp" namespace PoolController { String MqttPublisher::deviceId_ = ""; +std::uint32_t MqttPublisher::s_lastExportedSeq = 0; + +// Reentrancy guard for the log-event export (see exportLogEvents). AsyncMqttClient +// callbacks (handleMqttMessage → publishStates) run on the AsyncTCP task, which can +// preempt the loop task mid-export; both paths share the static snapshot buffer and +// s_lastExportedSeq. Native tests (no ESP32 macros) compile the guard to a no-op. +#if defined(ESP32) || defined(ARDUINO_ARCH_ESP32) +#include +#include +static portMUX_TYPE s_exportMux = portMUX_INITIALIZER_UNLOCKED; +#define EXPORT_CRITICAL_ENTER() portENTER_CRITICAL(&s_exportMux) +#define EXPORT_CRITICAL_EXIT() portEXIT_CRITICAL(&s_exportMux) +#else +#define EXPORT_CRITICAL_ENTER() ((void)0) +#define EXPORT_CRITICAL_EXIT() ((void)0) +#endif void MqttPublisher::begin() { // Generate unique MAC-based device identifier @@ -37,7 +54,15 @@ void MqttPublisher::begin() { snprintf(macStr, sizeof(macStr), "pool_controller_%02x%02x%02x", mac[3], mac[4], mac[5]); deviceId_ = String(macStr); - Serial.printf("✓ HA Discovery Device ID set to: %s\n", deviceId_.c_str()); + // Start the log-event export watermark at the beginning of the current boot + // (seq 0). exportLogEvents() already filters Info/Debug chatter, so starting + // here does not flood the bus — but it DOES preserve WARN/ERROR and curated + // events emitted before this point (boot-loop detection, ConfigManager, + // NetworkManager/WPS/SSID warnings), which a lastSeq() watermark would + // permanently drop. + s_lastExportedSeq = 0; + + LOG_INFO("✓ HA Discovery Device ID set to: %s\n", deviceId_.c_str()); // Register callback in NetworkManager NetworkManager::setMqttCallback(handleMqttMessage); @@ -68,6 +93,17 @@ struct TopicBuilder { return buf; } }; + +// Curated event whitelist — MUST match the event_types in publishEventDiscovery(). +bool isKnownEventType(const char *type) { + static const char *const kEventTypes[] = {"LOG_WARN", "LOG_ERROR", "MODE_CHANGED", "PUMP_ON", "PUMP_OFF", "WIFI_CONNECTED", + "WIFI_DISCONNECTED", "MQTT_CONNECTED", "MQTT_DISCONNECTED"}; + for (const char *known : kEventTypes) { + if (strcmp(known, type) == 0) + return true; + } + return false; +} } // namespace void MqttPublisher::publishSensorDiscovery(const char *objectId, const char *name, const char *deviceClass, const char *unit, @@ -231,6 +267,36 @@ void MqttPublisher::publishTextDiscovery(const char *objectId, const char *name, NetworkManager::publish(cfgTopic.build("text", objectId, "/config"), payloadBuf, true); } +void MqttPublisher::publishEventDiscovery(const char *objectId, const char *name, const char *icon) { + TopicBuilder cfgTopic, stateTopic; + JsonDocument doc; + doc["name"] = name; + doc["unique_id"] = deviceId_ + "_" + objectId; + doc["state_topic"] = stateTopic.build("event", objectId, "/state"); + doc["availability_topic"] = "homeassistant/sensor/pool-controller/availability"; + doc["platform"] = "event"; + + // Whitelist MUST match the curated event types parsed by exportLogEvents(). + JsonArray eventTypes = doc["event_types"].to(); + eventTypes.add("LOG_WARN"); + eventTypes.add("LOG_ERROR"); + eventTypes.add("MODE_CHANGED"); + eventTypes.add("PUMP_ON"); + eventTypes.add("PUMP_OFF"); + eventTypes.add("WIFI_CONNECTED"); + eventTypes.add("WIFI_DISCONNECTED"); + eventTypes.add("MQTT_CONNECTED"); + eventTypes.add("MQTT_DISCONNECTED"); + + if (icon) + doc["icon"] = icon; + addDeviceInfo(doc); + + char payloadBuf[1024]; + serializeJson(doc, payloadBuf, sizeof(payloadBuf)); + NetworkManager::publish(cfgTopic.build("event", objectId, "/config"), payloadBuf, true); +} + void MqttPublisher::publishTimeDiscovery(const char *objectId, const char *name, const char *icon, const char *entityCategory) { TopicBuilder cfgTopic, stateTopic, cmdTopic; @@ -431,7 +497,10 @@ void MqttPublisher::publishDiscovery() { if (!NetworkManager::isMqttConnected()) return; - Serial.println("Publishing HA Discovery Payloads..."); + LOG_INFO("Publishing HA Discovery Payloads...\n"); + + // ── Log event entity (HA "event" component) ── + publishEventDiscovery("logs", "Pool Controller Logs", "mdi:clipboard-text-outline"); // ── Primary Sensors (no entity_category — shown on device front page) ── publishSensorDiscovery("pool-temp", "Pool Temperature", "temperature", "°C", "mdi:pool", nullptr, "measurement"); @@ -548,7 +617,7 @@ void MqttPublisher::publishDiscovery() { NetworkManager::publish(topic, "", true); // empty retained → HA removes entity } - Serial.println("✓ HA Discovery Payloads & Subscriptions complete"); + LOG_INFO("✓ HA Discovery Payloads & Subscriptions complete\n"); } void MqttPublisher::publishStates() { @@ -735,9 +804,136 @@ void MqttPublisher::publishStates() { getBaseTopic(topic, sizeof(topic), "binary_sensor", "mqtt-status"); strlcat(topic, "/state", sizeof(topic)); NetworkManager::publish(topic, NetworkManager::isMqttConnected() ? "ON" : "OFF", true); + + // Export new log entries as MQTT events (WARN/ERROR + curated logEvent markers) + exportLogEvents(); } } +// ═══════════════════════════════════════════════════════════════════════ +// Log-event export pump (WARN/ERROR + curated logEvent markers) +// ═══════════════════════════════════════════════════════════════════════ + +void MqttPublisher::exportLogEvents() { + // Only one export may run at a time: AsyncMqttClient callbacks (handleMqttMessage + // → publishStates) run on the AsyncTCP task and can preempt the loop task's + // periodic export. Both share the static snapshot buffer and the watermark, so a + // concurrent entry would clobber the snapshot or regress s_lastExportedSeq and + // duplicate MQTT events. The losing export defers to the next pass — it returns + // before touching the watermark, so its pending entries are not lost. + static bool s_exportRunning = false; + EXPORT_CRITICAL_ENTER(); + if (s_exportRunning) { + EXPORT_CRITICAL_EXIT(); + return; + } + s_exportRunning = true; + EXPORT_CRITICAL_EXIT(); + + // Batch snapshot of the ring (static: keeps ~9 KB off the loop stack). + static LogEntry entries[LogCapture::LOG_BUFFER_ENTRIES]; + const size_t count = LogCapture::getEntries(s_lastExportedSeq, LogCapture::epoch(), LogCapture::LOG_BUFFER_ENTRIES, + LogLevel::Info, entries, LogCapture::LOG_BUFFER_ENTRIES); + if (count == 0) { + EXPORT_CRITICAL_ENTER(); + s_exportRunning = false; + EXPORT_CRITICAL_EXIT(); + return; + } + + TopicBuilder stateTopic; + // Watermark only advances through entries whose required publishes were + // successfully queued. When MQTT disconnects mid-burst or the client + // refuses to enqueue (NetworkManager::publish() == false), the watermark + // stays before the failed entry so it is retried on the next export pass + // instead of being dropped. + uint32_t lastOkSeq = s_lastExportedSeq; + for (size_t i = 0; i < count; ++i) { + const LogEntry &entry = entries[i]; + const char *body = entry.message; + const char *eventType = nullptr; + char typeBuf[32]; + + // Parse the "[TYPE] message" marker written by LogCapture::logEvent(). + if (body[0] == '[') { + const char *close = strchr(body, ']'); + if (close != nullptr && close > body + 1) { + const size_t len = static_cast(close - body - 1); + if (len < sizeof(typeBuf)) { + memcpy(typeBuf, body + 1, len); + typeBuf[len] = '\0'; + if (isKnownEventType(typeBuf)) { + eventType = typeBuf; + body = close + 1; + while (*body == ' ') + ++body; + } + } + } + } + + // WARN/ERROR entries without a curated marker → LOG_WARN/LOG_ERROR. + // Info/Debug chatter is skipped (volume control — nothing on MQTT). + if (eventType == nullptr) { + switch (entry.level) { + case LogLevel::Warning: + eventType = "LOG_WARN"; + break; + case LogLevel::Error: + eventType = "LOG_ERROR"; + break; + default: + // Skipped by design — no publish required, so the watermark may + // advance past it. + lastOkSeq = entry.seq; + continue; + } + } + + // HA event-entity state: {"event_type": "...", "message": "..."} + JsonDocument doc; + doc["event_type"] = eventType; + doc["message"] = body; + char payload[256]; + serializeJson(doc, payload, sizeof(payload)); + bool ok = NetworkManager::publish(stateTopic.build("event", "logs", "/state"), payload, false); + + // Raw JSON-line for external tools (WARN/ERROR only — not Info-level events). + if (entry.level == LogLevel::Warning || entry.level == LogLevel::Error) { + JsonDocument rawDoc; + rawDoc["seq"] = entry.seq; + rawDoc["t"] = entry.uptimeMs; + rawDoc["level"] = LogCapture::levelName(entry.level); + rawDoc["msg"] = entry.message; + char rawBuf[256]; + serializeJson(rawDoc, rawBuf, sizeof(rawBuf)); + ok = NetworkManager::publish("pool-controller/log", rawBuf, false) && ok; + } + + // A required publish failed (e.g. AsyncMqttClient refused to enqueue + // during the discovery/state burst right after reconnect): keep the + // watermark before this entry so the whole tail is retried next pass. + // Do not drop the event by marking it exported without a successful queue. + if (!ok) + break; + + // This entry's required publishes were all successfully queued. + lastOkSeq = entry.seq; + } + + // Advance the watermark only through entries whose required publishes were + // successfully queued. Using LogCapture::lastSeq() here would mark entries + // appended concurrently by async WiFi/MQTT callbacks as exported even though + // they were never processed — their HA events would be permanently lost. + // Entries after a failed publish (or appended during the snapshot) are + // picked up by the next export pass instead. + s_lastExportedSeq = lastOkSeq; + + EXPORT_CRITICAL_ENTER(); + s_exportRunning = false; + EXPORT_CRITICAL_EXIT(); +} + // ═══════════════════════════════════════════════════════════════════════ // Sensor mapping select-entity discovery (published after bus scan) // ═══════════════════════════════════════════════════════════════════════ @@ -793,7 +989,7 @@ void MqttPublisher::publishSensorMappingDiscovery() { NetworkManager::subscribe("homeassistant/select/pool-controller/solar-sensor/set"); NetworkManager::subscribe("homeassistant/select/pool-controller/pool-sensor/set"); - Serial.printf("• HA: Sensor mapping select entities published (%u options)\n", solarOptCount); + LOG_INFO("• HA: Sensor mapping select entities published (%u options)\n", solarOptCount); } // Helper function to check if MQTT authentication is configured @@ -836,19 +1032,19 @@ void MqttPublisher::handleMqttMessage( if (top.endsWith("/firmware-update/set")) { // MQTT authentication is optional, but if configured, we check it if (shouldEnforceMqttAuth() && !isMqttAuthenticated()) { - Serial.println("MQTT: Firmware update command rejected - MQTT authentication required"); + LOG_WARN("MQTT: Firmware update command rejected - MQTT authentication required\n"); return; } // Always validate command value for security static const char *validFirmwareCommands[] = {"INSTALL"}; if (!MqttPublisher::isValidCommand(value, validFirmwareCommands, 1)) { - Serial.printf("MQTT: Invalid firmware command: %s\n", value.c_str()); + LOG_WARN("MQTT: Invalid firmware command: %s\n", value.c_str()); return; } if (value == "INSTALL") { - Serial.println("MQTT: Firmware update triggered from Home Assistant"); + LOG_INFO("MQTT: Firmware update triggered from Home Assistant\n"); OtaUpdater::startUpdate(); } return; @@ -866,11 +1062,11 @@ void MqttPublisher::handleMqttMessage( else if (value == "boost") poolMode = "boost"; else { - Serial.printf("MQTT: Unknown preset \"%s\" — ignoring\n", value.c_str()); + LOG_WARN("MQTT: Unknown preset \"%s\" — ignoring\n", value.c_str()); publishStates(); return; } - Serial.printf("MQTT: Climate preset → pool mode \"%s\"\n", poolMode.c_str()); + LOG_INFO("MQTT: Climate preset → pool mode \"%s\"\n", poolMode.c_str()); operationModeNode.setMode(poolMode.c_str()); ConfigManager::getSettings().opMode = poolMode; ConfigManager::save(); @@ -887,11 +1083,11 @@ void MqttPublisher::handleMqttMessage( else if (value == "heat") poolMode = "boost"; else { - Serial.printf("MQTT: Unknown climate mode \"%s\" — ignoring\n", value.c_str()); + LOG_WARN("MQTT: Unknown climate mode \"%s\" — ignoring\n", value.c_str()); publishStates(); return; } - Serial.printf("MQTT: Climate mode → pool mode \"%s\"\n", poolMode.c_str()); + LOG_INFO("MQTT: Climate mode → pool mode \"%s\"\n", poolMode.c_str()); operationModeNode.setMode(poolMode.c_str()); ConfigManager::getSettings().opMode = poolMode; ConfigManager::save(); @@ -901,7 +1097,7 @@ void MqttPublisher::handleMqttMessage( if (top.endsWith("/thermostat/temperature/set")) { float val = value.toFloat(); - Serial.printf("MQTT: Climate target temperature → %.1f\n", val); + LOG_INFO("MQTT: Climate target temperature → %.1f\n", val); operationModeNode.setPoolMaxTemperature(val); ConfigManager::getSettings().tempMaxPool = val; ConfigManager::save(); @@ -912,7 +1108,7 @@ void MqttPublisher::handleMqttMessage( if (top.endsWith("/pool-pump/set") || top.endsWith("/solar-pump/set")) { // MQTT authentication is optional, but if configured, we check it if (shouldEnforceMqttAuth() && !isMqttAuthenticated()) { - Serial.println("MQTT: Pump command rejected - MQTT authentication required"); + LOG_WARN("MQTT: Pump command rejected - MQTT authentication required\n"); publishStates(); return; } @@ -920,14 +1116,14 @@ void MqttPublisher::handleMqttMessage( // Always validate payload for security static const char *validPumpCommands[] = {"ON", "OFF"}; if (!MqttPublisher::isValidCommand(value, validPumpCommands, 2)) { - Serial.printf("MQTT: Invalid pump command: %s\n", value.c_str()); + LOG_WARN("MQTT: Invalid pump command: %s\n", value.c_str()); publishStates(); return; } // Only allow pump control from HA in manual mode if (operationModeNode.getMode() != "manu") { - Serial.printf("MQTT: Ignoring pump command — not in manual mode (current: %s)\n", operationModeNode.getMode().c_str()); + LOG_WARN("MQTT: Ignoring pump command — not in manual mode (current: %s)\n", operationModeNode.getMode().c_str()); publishStates(); return; } @@ -939,7 +1135,7 @@ void MqttPublisher::handleMqttMessage( } else if (top.endsWith("/mode/set")) { // MQTT authentication is optional, but if configured, we check it if (shouldEnforceMqttAuth() && !isMqttAuthenticated()) { - Serial.println("MQTT: Mode command rejected - MQTT authentication required"); + LOG_WARN("MQTT: Mode command rejected - MQTT authentication required\n"); publishStates(); return; } @@ -947,7 +1143,7 @@ void MqttPublisher::handleMqttMessage( // Always validate mode value for security static const char *validModes[] = {"auto", "manu", "boost", "timer"}; if (!MqttPublisher::isValidCommand(value, validModes, 4)) { - Serial.printf("MQTT: Invalid mode command: %s\n", value.c_str()); + LOG_WARN("MQTT: Invalid mode command: %s\n", value.c_str()); publishStates(); return; } @@ -958,7 +1154,7 @@ void MqttPublisher::handleMqttMessage( } else if (top.endsWith("/pool-max-temp/set")) { // MQTT authentication is optional, but if configured, we check it if (shouldEnforceMqttAuth() && !isMqttAuthenticated()) { - Serial.println("MQTT: Config command rejected - MQTT authentication required"); + LOG_WARN("MQTT: Config command rejected - MQTT authentication required\n"); publishStates(); return; } @@ -966,7 +1162,7 @@ void MqttPublisher::handleMqttMessage( float val = value.toFloat(); // Always validate range for security if (val < 0.0f || val > 40.0f) { - Serial.printf("MQTT: Invalid pool-max-temp value: %.1f\n", val); + LOG_WARN("MQTT: Invalid pool-max-temp value: %.1f\n", val); publishStates(); return; } @@ -976,7 +1172,7 @@ void MqttPublisher::handleMqttMessage( } else if (top.endsWith("/solar-min-temp/set")) { // MQTT authentication is optional, but if configured, we check it if (shouldEnforceMqttAuth() && !isMqttAuthenticated()) { - Serial.println("MQTT: Config command rejected - MQTT authentication required"); + LOG_WARN("MQTT: Config command rejected - MQTT authentication required\n"); publishStates(); return; } @@ -984,7 +1180,7 @@ void MqttPublisher::handleMqttMessage( float val = value.toFloat(); // Always validate range for security if (val < 0.0f || val > 100.0f) { - Serial.printf("MQTT: Invalid solar-min-temp value: %.1f\n", val); + LOG_WARN("MQTT: Invalid solar-min-temp value: %.1f\n", val); publishStates(); return; } @@ -994,7 +1190,7 @@ void MqttPublisher::handleMqttMessage( } else if (top.endsWith("/hysteresis/set")) { // MQTT authentication is optional, but if configured, we check it if (shouldEnforceMqttAuth() && !isMqttAuthenticated()) { - Serial.println("MQTT: Config command rejected - MQTT authentication required"); + LOG_WARN("MQTT: Config command rejected - MQTT authentication required\n"); publishStates(); return; } @@ -1002,7 +1198,7 @@ void MqttPublisher::handleMqttMessage( float val = value.toFloat(); // Always validate range for security if (val < 0.0f || val > 10.0f) { - Serial.printf("MQTT: Invalid hysteresis value: %.1f\n", val); + LOG_WARN("MQTT: Invalid hysteresis value: %.1f\n", val); publishStates(); return; } @@ -1049,7 +1245,7 @@ void MqttPublisher::handleMqttMessage( } else if (top.endsWith("/timezone/set")) { int idx = getTimezoneIndexFromLabel(value); if (idx < 0) { - Serial.printf("MQTT: Unknown timezone label \"%s\" — ignoring\n", value.c_str()); + LOG_WARN("MQTT: Unknown timezone label \"%s\" — ignoring\n", value.c_str()); publishStates(); return; } @@ -1076,7 +1272,7 @@ void MqttPublisher::handleMqttMessage( char *end = nullptr; unsigned long val = strtoul(byteStr, &end, 16); if (end != byteStr + 2) { - Serial.printf("MQTT: Invalid hex in sensor selection — ignoring\n"); + LOG_WARN("MQTT: Invalid hex in sensor selection — ignoring\n"); publishStates(); return; } @@ -1094,14 +1290,14 @@ void MqttPublisher::handleMqttMessage( solarTemperatureNode.setAddressFilter(addr); else solarTemperatureNode.clearAddressFilter(); - Serial.printf("MQTT: Solar sensor %s via HA\n", hasAddr ? "assigned" : "cleared"); + LOG_INFO("MQTT: Solar sensor %s via HA\n", hasAddr ? "assigned" : "cleared"); } else { prefs.putBytes("pool_adr", addr, 8); if (hasAddr) poolTemperatureNode.setAddressFilter(addr); else poolTemperatureNode.clearAddressFilter(); - Serial.printf("MQTT: Pool sensor %s via HA\n", hasAddr ? "assigned" : "cleared"); + LOG_INFO("MQTT: Pool sensor %s via HA\n", hasAddr ? "assigned" : "cleared"); } prefs.end(); } diff --git a/src/MqttPublisher.hpp b/src/MqttPublisher.hpp index 41a16ae7..4dbc4b33 100644 --- a/src/MqttPublisher.hpp +++ b/src/MqttPublisher.hpp @@ -69,6 +69,20 @@ class MqttPublisher { static void publishClimateDiscovery(); /** @brief Publish select-entity discovery for sensor-to-role mapping (detected addresses as options). */ static void publishSensorMappingDiscovery(); + /** + * @brief Publish HA MQTT "event" component discovery for curated log events. + * @param objectId Entity object id (e.g. "logs"). + * @param name Display name. + * @param icon Optional MDI icon. + */ + static void publishEventDiscovery(const char *objectId, const char *name, const char *icon = nullptr); + /** + * @brief Export new LogCapture entries as MQTT events (WARN/ERROR + curated + * logEvent markers). Called from publishStates(); deduplicated via + * s_lastExportedSeq and guarded against reentrancy from the AsyncTCP + * callback task (handleMqttMessage → publishStates). + */ + static void exportLogEvents(); static void getBaseTopic(char *buf, size_t bufSize, const char *component, const char *objectId); static void addDeviceInfo(JsonDocument &doc); @@ -76,6 +90,8 @@ class MqttPublisher { static void publishClimateState(); static String deviceId_; + /** @brief Sequence watermark for the MQTT log-event export pump (LogCapture::seq). */ + static std::uint32_t s_lastExportedSeq; }; } // namespace PoolController diff --git a/src/NetworkManager.cpp b/src/NetworkManager.cpp index 3ae9dd98..7512756f 100644 --- a/src/NetworkManager.cpp +++ b/src/NetworkManager.cpp @@ -15,6 +15,7 @@ #include "ConfigManager.hpp" #include "WpsProvisioner.hpp" +#include "LogCapture.hpp" namespace PoolController { @@ -41,15 +42,18 @@ bool NetworkManager::begin() { // Set up MQTT event handlers (one-time, async) mqttClient_.onConnect([](bool sessionPresent) { - Serial.println("✓ MQTT connected!"); + LOG_INFO("✓ MQTT connected!\n"); + LogCapture::logEvent("MQTT_CONNECTED", "MQTT broker connected"); // Publish online to LWT topic immediately (async, non-blocking) mqttClient_.publish("homeassistant/sensor/pool-controller/availability", 1, true, "online"); }); - mqttClient_.onDisconnect( - [](AsyncMqttClientDisconnectReason reason) { Serial.printf("✖ MQTT disconnected, reason=%d\n", static_cast(reason)); }); + mqttClient_.onDisconnect([](AsyncMqttClientDisconnectReason reason) { + LOG_ERROR("✖ MQTT disconnected, reason=%d\n", static_cast(reason)); + LogCapture::logEvent("MQTT_DISCONNECTED", "MQTT disconnected, reason %d", static_cast(reason)); + }); if (ConfigManager::getWiFi().ssid.length() == 0) { - Serial.println("⚠ No WiFi SSID configured! Starting AP mode."); + LOG_WARN("⚠ No WiFi SSID configured! Starting AP mode.\n"); startAPMode(); return true; } @@ -66,13 +70,13 @@ void NetworkManager::loop() { uint32_t now = millis(); if (now - lastWiFiRetryTime_ >= kWiFiRetryIntervalMs) { lastWiFiRetryTime_ = now; - Serial.println("🔄 AP mode: retrying WiFi connection with saved credentials..."); + LOG_INFO("🔄 AP mode: retrying WiFi connection with saved credentials...\n"); WiFi.mode(WIFI_MODE_APSTA); connectWiFi(); } if (WiFi.status() == WL_CONNECTED) { - Serial.println("✓ AP mode: WiFi reconnected! Switching back to normal mode."); + LOG_INFO("✓ AP mode: WiFi reconnected! Switching back to normal mode.\n"); WiFi.mode(WIFI_MODE_STA); apModeActive_ = false; connectionStartTime_ = 0; @@ -92,7 +96,7 @@ void NetworkManager::loop() { uint32_t now = millis(); if (now - connectionStartTime_ >= 20000) { - Serial.println("⚠ WiFi connection timeout (20s). Falling back to AP Setup Mode!"); + LOG_WARN("⚠ WiFi connection timeout (20s). Falling back to AP Setup Mode!\n"); startAPMode(); return; } @@ -124,7 +128,7 @@ void NetworkManager::loop() { statusStr = "UNKNOWN"; break; } - Serial.printf("🔄 WiFi retry... status=%s (%d), elapsed=%ums\n", statusStr, status, now - connectionStartTime_); + LOG_INFO("🔄 WiFi retry... status=%s (%d), elapsed=%ums\n", statusStr, status, now - connectionStartTime_); connectWiFi(); } return; @@ -138,7 +142,7 @@ void NetworkManager::loop() { uint32_t now = millis(); if (now - lastMqttRetryTime_ >= kMqttRetryIntervalMs) { lastMqttRetryTime_ = now; - Serial.println("🔄 MQTT disconnected, retrying..."); + LOG_INFO("🔄 MQTT disconnected, retrying...\n"); connectMqtt(); } } @@ -164,13 +168,12 @@ void NetworkManager::startAPMode() { // Setup standard open AP named 'Pool-Controller-Setup' WiFi.softAP("Pool-Controller-Setup"); - Serial.print("🚀 AP Mode active. SSID: 'Pool-Controller-Setup'. IP: "); - Serial.println(WiFi.softAPIP()); + LOG_INFO("🚀 AP Mode active. SSID: 'Pool-Controller-Setup'. IP: %s\n", WiFi.softAPIP().toString().c_str()); } void NetworkManager::connectWiFi() { const String &ssid = ConfigManager::getWiFi().ssid; - Serial.printf("📡 Connecting to WiFi: %s ...\n", ssid.c_str()); + LOG_INFO("📡 Connecting to WiFi: %s ...\n", ssid.c_str()); WiFi.begin(ssid.c_str(), ConfigManager::getWiFi().password.c_str()); } @@ -253,19 +256,21 @@ void NetworkManager::restart() { void NetworkManager::handleWiFiEvent(WiFiEvent_t event) { switch (event) { case ARDUINO_EVENT_WIFI_STA_GOT_IP: - Serial.printf("✓ WiFi connected! SSID: \"%s\", IP: %s, RSSI: %d dBm, Channel: %d\n", WiFi.SSID().c_str(), + LOG_INFO("✓ WiFi connected! SSID: \"%s\", IP: %s, RSSI: %d dBm, Channel: %d\n", WiFi.SSID().c_str(), WiFi.localIP().toString().c_str(), WiFi.RSSI(), WiFi.channel()); + LogCapture::logEvent("WIFI_CONNECTED", "WiFi connected to %s", WiFi.SSID().c_str()); apModeActive_ = false; // Start mDNS responder so the device is reachable as pool-controller.local if (MDNS.begin("pool-controller")) { MDNS.addService("http", "tcp", 80); - Serial.println("✓ mDNS: pool-controller.local"); + LOG_INFO("✓ mDNS: pool-controller.local\n"); } else { - Serial.println("✖ mDNS responder setup failed"); + LOG_ERROR("✖ mDNS responder setup failed\n"); } break; case ARDUINO_EVENT_WIFI_STA_DISCONNECTED: - Serial.printf("✖ WiFi disconnected. Status: %d (SSID: \"%s\")\n", WiFi.status(), WiFi.SSID().c_str()); + LOG_ERROR("✖ WiFi disconnected. Status: %d (SSID: \"%s\")\n", WiFi.status(), WiFi.SSID().c_str()); + LogCapture::logEvent("WIFI_DISCONNECTED", "WiFi disconnected, status %d", WiFi.status()); break; default: break; diff --git a/src/Nodes/Logger.cpp b/src/Nodes/Logger.cpp deleted file mode 100644 index c3243b10..00000000 --- a/src/Nodes/Logger.cpp +++ /dev/null @@ -1,20 +0,0 @@ -// Copyright (c) 2018-2026 Smart Swimming Pool, Stephan Strittmatter -// -// SPDX-License-Identifier: MIT - -/** - * @file Logger.cpp - * @brief Logger implementation — currently a stub; Logger is a plain struct. - */ - -#include "Logger.hpp" - -namespace PoolController { -namespace Nodes { - -// Logger is now a plain struct — the former Node-based constructor -// was removed as part of the migration to standalone MQTT via -// MqttPublisher + NetworkManager. - -} // namespace Nodes -} // namespace PoolController diff --git a/src/Nodes/Logger.hpp b/src/Nodes/Logger.hpp deleted file mode 100644 index eb66c7f9..00000000 --- a/src/Nodes/Logger.hpp +++ /dev/null @@ -1,53 +0,0 @@ -// Copyright (c) 2018-2026 Smart Swimming Pool, Stephan Strittmatter -// -// SPDX-License-Identifier: MIT - -/** - * @file Logger.hpp - * @brief Lightweight serial logger — log levels, flag-based output control. - */ - -#pragma once - -#include -#include -#include - -namespace PoolController { -namespace Nodes { - -/** - * Lightweight serial logger — replaces the former Node-based Logger. - * All output goes to Serial. The struct is kept for API compatibility with - * sites that previously used Logger::LogLevel / Logger::Flags. - */ -struct Logger final { - Logger() = default; - - enum struct LogLevel : std::size_t { Debug = 0, Info, Warning, Critical, Error }; - - struct Flags final { - using Bits = std::uint8_t; - enum $ : Bits { None = 0, LogToSerial = 1 << 0, LogToJson = 1 << 1, FlushLog = 1 << 2 }; - }; - - LogLevel CurrentLogLevel{LogLevel::Info}; - Flags::Bits CurrentFlags{Flags::LogToSerial}; - - [[nodiscard]] auto operator[](LogLevel logLevel) const noexcept -> const char * { - return *(LOG_LEVEL_NAMES + static_cast(logLevel)); - } - [[nodiscard]] auto operator*() const noexcept -> Flags::Bits { return this->CurrentFlags; } - [[nodiscard]] auto operator*() noexcept -> Flags::Bits & { return this->CurrentFlags; } - [[nodiscard]] explicit operator bool() const noexcept { return (**this & Flags::LogToSerial) != 0; } - inline auto AddFlags(const Flags::Bits x) noexcept -> Flags::Bits { return **this |= x; } - inline auto RemoveFlags(const Flags::Bits x) noexcept -> Flags::Bits { return **this &= ~x; } - inline auto ToggleFlags(const Flags::Bits x) noexcept -> Flags::Bits { return **this ^= x; } - inline auto ClearFlags() noexcept -> Flags::Bits { return **this ^= **this; } - -private: - static constexpr const char *LOG_LEVEL_NAMES[]{"Debug", "Info", "Warning", "Critical", "Error"}; -}; - -} // namespace Nodes -} // namespace PoolController diff --git a/src/NorviButtonHandler.cpp b/src/NorviButtonHandler.cpp index 34f93271..78c7e177 100644 --- a/src/NorviButtonHandler.cpp +++ b/src/NorviButtonHandler.cpp @@ -19,6 +19,7 @@ #include #include "Config.hpp" +#include "LogCapture.hpp" namespace PoolController { @@ -43,7 +44,7 @@ uint32_t NorviButtonHandler::pressStartMs_ = 0; // ═══════════════════════════════════════════════════════════════════════════ void NorviButtonHandler::begin() { - Serial.printf("• NorviButtonHandler initializing on ADC GPIO%d...\n", PIN_BUTTON_ADC); + LOG_INFO("• NorviButtonHandler initializing on ADC GPIO%d...\n", PIN_BUTTON_ADC); pinMode(PIN_BUTTON_ADC, INPUT); @@ -52,11 +53,11 @@ void NorviButtonHandler::begin() { delay(10); lastRaw_ = analogRead(PIN_BUTTON_ADC); - Serial.printf(" ◦ ADC initial value: %u\n", lastRaw_); - Serial.printf(" ◦ Button 1 ADC range: %u–%u\n", THRESH_BTN1_MIN, THRESH_BTN1_MAX); - Serial.printf(" ◦ Button 2 ADC range: %u–%u\n", THRESH_BTN2_MIN, THRESH_BTN2_MAX); - Serial.printf(" ◦ Button 3 ADC range: %u–%u\n", THRESH_BTN3_MIN, THRESH_BTN3_MAX); - Serial.println("✓ NorviButtonHandler initialized"); + LOG_INFO(" ◦ ADC initial value: %u\n", lastRaw_); + LOG_INFO(" ◦ Button 1 ADC range: %u–%u\n", THRESH_BTN1_MIN, THRESH_BTN1_MAX); + LOG_INFO(" ◦ Button 2 ADC range: %u–%u\n", THRESH_BTN2_MIN, THRESH_BTN2_MAX); + LOG_INFO(" ◦ Button 3 ADC range: %u–%u\n", THRESH_BTN3_MIN, THRESH_BTN3_MAX); + LOG_INFO("✓ NorviButtonHandler initialized\n"); } // ═══════════════════════════════════════════════════════════════════════════ @@ -77,7 +78,7 @@ void NorviButtonHandler::loop() { // Add debug logging for ADC changes static uint16_t lastDebugAdc_ = 0xFFFF; if (abs(static_cast(lastRaw_) - static_cast(lastDebugAdc_)) > 50) { - Serial.printf("ADC: %u → %d\n", lastDebugAdc_, static_cast(detected)); + LOG_DEBUG("ADC: %u → %d\n", lastDebugAdc_, static_cast(detected)); lastDebugAdc_ = lastRaw_; } diff --git a/src/NorviOledDisplay.cpp b/src/NorviOledDisplay.cpp index 34d6d74a..b96a0a7d 100644 --- a/src/NorviOledDisplay.cpp +++ b/src/NorviOledDisplay.cpp @@ -28,6 +28,7 @@ #include "Utils.hpp" #include "NetworkManager.hpp" #include "Nodes.hpp" +#include "LogCapture.hpp" #include "SystemMonitor.hpp" #include "TimeClientHelper.hpp" #include "ConfigManager.hpp" @@ -261,16 +262,16 @@ static void drawScrollingText(int16_t x, int16_t y, const __FlashStringHelper *t // ═══════════════════════════════════════════════════════════════════════════ void NorviOledDisplay::begin() { - Serial.println("• NorviOledDisplay initializing on I2C GPIO16(SDA)/GPIO17(SCL)..."); + LOG_INFO("• NorviOledDisplay initializing on I2C GPIO16(SDA)/GPIO17(SCL)...\n"); Wire.begin(PIN_OLED_SDA, PIN_OLED_SCL); if (!display.begin(SSD1306_SWITCHCAPVCC, 0x3C)) { - Serial.println("✖ NorviOledDisplay: SSD1306 allocation failed — display disabled"); + LOG_ERROR("✖ NorviOledDisplay: SSD1306 allocation failed — display disabled\n"); return; } - Serial.println("✓ NorviOledDisplay initialized (128×64, address 0x3C)"); + LOG_INFO("✓ NorviOledDisplay initialized (128×64, address 0x3C)\n"); // ── Splash screen ────────────────────────────────────────────────────── display.clearDisplay(); @@ -287,10 +288,10 @@ void NorviOledDisplay::begin() { // ── Determine starting page based on first-boot state ────────────────── if (needsWiFiSetup()) { currentPage_ = Page::WIFI_SETUP; - Serial.println("→ First boot: no WiFi configured — showing WIFI_SETUP page"); + LOG_INFO("→ First boot: no WiFi configured — showing WIFI_SETUP page\n"); } else if (needsSensorMapping()) { currentPage_ = Page::SENSOR_SETUP; - Serial.println("→ First boot: sensors not mapped — showing SENSOR_SETUP page"); + LOG_INFO("→ First boot: sensors not mapped — showing SENSOR_SETUP page\n"); } else { currentPage_ = Page::MAIN; firstBootDone_ = true; @@ -414,7 +415,7 @@ void NorviOledDisplay::confirmAction() { setupStep_ = SetupStep::IDLE; // Check if both done if (setupSolarDone_ && setupPoolDone_) { - Serial.println("→ Both sensors assigned — save mapping via long-press S3"); + LOG_INFO("→ Both sensors assigned — save mapping via long-press S3\n"); } forceRedraw_ = true; } @@ -1313,7 +1314,7 @@ bool NorviOledDisplay::setupApplyAssignment() { } memcpy(setupSolarAddr_, addr, 8); setupSolarDone_ = true; - Serial.println("→ Sensor assigned as Solar"); + LOG_INFO("→ Sensor assigned as Solar\n"); } else { // If this address is already assigned as Solar, clear that if (setupSolarDone_ && memcmp(addr, setupSolarAddr_, 8) == 0) { @@ -1322,7 +1323,7 @@ bool NorviOledDisplay::setupApplyAssignment() { } memcpy(setupPoolAddr_, addr, 8); setupPoolDone_ = true; - Serial.println("→ Sensor assigned as Pool"); + LOG_INFO("→ Sensor assigned as Pool\n"); } forceRedraw_ = true; diff --git a/src/OperationModeNode.cpp b/src/OperationModeNode.cpp index aa063f20..18b7e2d4 100644 --- a/src/OperationModeNode.cpp +++ b/src/OperationModeNode.cpp @@ -13,6 +13,7 @@ #include "RuleBoost.hpp" #include "Utils.hpp" #include "StateManager.hpp" +#include "LogCapture.hpp" // Static member definition bool OperationModeNode::_suppressPersist = false; @@ -85,11 +86,11 @@ void OperationModeNode::addRule(Rule *rule) { } Rule *OperationModeNode::getRule() { - Serial.printf("getRule: mode = %s\n", _mode.c_str()); + LOG_DEBUG("getRule: mode = %s\n", _mode.c_str()); for (size_t i = 0; i < _ruleVec.size(); i++) { if (_mode.equals(_ruleVec[i]->getMode())) { - Serial.printf("getRule: Active Rule: %s\n", _ruleVec[i]->getMode()); + LOG_DEBUG("getRule: Active Rule: %s\n", _ruleVec[i]->getMode()); // Update ruleset properties _ruleVec[i]->setPoolMaxTemperature(getPoolMaxTemperature()); @@ -117,34 +118,38 @@ bool OperationModeNode::setMode(String mode) { for (auto &rule : _ruleVec) { rule->resetTemperatureExtension(); } + // Curated log event for MQTT event entity — only on actual mode change + if (!_mode.equals(mode)) { + PoolController::LogCapture::logEvent("MODE_CHANGED", "Mode switched to %s", mode.c_str()); + } _mode = mode; - Serial.printf("set mode: %s\n", _mode.c_str()); + LOG_DEBUG("set mode: %s\n", _mode.c_str()); if (!_suppressPersist) saveState(); return true; } else { - Serial.printf("✖ UNDEFINED Mode: %s. Current unchanged mode: %s\n", mode.c_str(), _mode.c_str()); + LOG_ERROR("✖ UNDEFINED Mode: %s. Current unchanged mode: %s\n", mode.c_str(), _mode.c_str()); return false; } } void OperationModeNode::begin() { - Serial.printf("• OperationMode Node '%s' initialized.\n", _id); + LOG_INFO("• OperationMode Node '%s' initialized.\n", _id); } void OperationModeNode::loop() { if (Utils::shouldMeasure(_lastMeasurement, _measurementInterval)) { _lastMeasurement = millis(); - Serial.println("〽 OperationalMode update rule"); + LOG_DEBUG("〽 OperationalMode update rule\n"); // Check time synchronization status static bool lastTimeSyncState = isTimeSyncValid(); bool currentTimeSyncState = isTimeSyncValid(); if (!currentTimeSyncState && lastTimeSyncState) { - Serial.println(" ⚠ WARNING: NTP time sync failed! Using cached estimate."); + LOG_WARN(" ⚠ WARNING: NTP time sync failed! Using cached estimate.\n"); } else if (currentTimeSyncState && !lastTimeSyncState) { - Serial.println(" ✓ NTP time sync recovered."); + LOG_INFO(" ✓ NTP time sync recovered.\n"); } lastTimeSyncState = currentTimeSyncState; @@ -153,7 +158,7 @@ void OperationModeNode::loop() { if (rule != nullptr) { rule->loop(); } else { - Serial.printf(" ✖ no rule defined for mode: %s. Falling back to manual.\n", _mode.c_str()); + LOG_ERROR(" ✖ no rule defined for mode: %s. Falling back to manual.\n", _mode.c_str()); _mode = STATUS_MANU; saveState(); } @@ -161,7 +166,7 @@ void OperationModeNode::loop() { } bool OperationModeNode::handleHomeAssistantCommand(const char *property, const char *value) { - Serial.printf(" ◦ HA command -> property '%s' value = %s\n", property, value); + LOG_DEBUG(" ◦ HA command -> property '%s' value = %s\n", property, value); bool retval = applyProperty(String(property), String(value)); _lastMeasurement = 0; // Trigger instant loop evaluation return retval; @@ -171,10 +176,10 @@ bool OperationModeNode::applyProperty(const String &property, const String &valu bool retval = false; if (property.equalsIgnoreCase("mode")) { - Serial.printf(" ✔ set operational mode: %s\n", value.c_str()); + LOG_INFO(" ✔ set operational mode: %s\n", value.c_str()); retval = this->setMode(value); } else if (property.equalsIgnoreCase("hysteresis")) { - Serial.printf(" ✔ hysteresis: %s\n", value.c_str()); + LOG_INFO(" ✔ hysteresis: %s\n", value.c_str()); float newValue; if (parseFloat(value, newValue, 0.0f, 10.0f)) { if (newValue != _hysteresis) { @@ -183,10 +188,10 @@ bool OperationModeNode::applyProperty(const String &property, const String &valu } retval = true; } else { - Serial.printf(" ✖ Invalid hysteresis value (must be 0-10): %s\n", value.c_str()); + LOG_ERROR(" ✖ Invalid hysteresis value (must be 0-10): %s\n", value.c_str()); } } else if (property.equalsIgnoreCase("solar-min-temp")) { - Serial.printf(" ✔ solar min temp: %s\n", value.c_str()); + LOG_INFO(" ✔ solar min temp: %s\n", value.c_str()); float newValue; if (parseFloat(value, newValue, 0.0f, 60.0f)) { if (newValue != _solarMinTemp) { @@ -195,10 +200,10 @@ bool OperationModeNode::applyProperty(const String &property, const String &valu } retval = true; } else { - Serial.printf(" ✖ Invalid solar min temp (must be 0-60°C): %s\n", value.c_str()); + LOG_ERROR(" ✖ Invalid solar min temp (must be 0-60°C): %s\n", value.c_str()); } } else if (property.equalsIgnoreCase("pool-max-temp")) { - Serial.printf(" ✔ pool max temp: %s\n", value.c_str()); + LOG_INFO(" ✔ pool max temp: %s\n", value.c_str()); float newValue; if (parseFloat(value, newValue, 0.0f, 40.0f)) { if (newValue != _poolMaxTemp) { @@ -207,7 +212,7 @@ bool OperationModeNode::applyProperty(const String &property, const String &valu } retval = true; } else { - Serial.printf(" ✖ Invalid pool max temp (must be 0-60°C): %s\n", value.c_str()); + LOG_ERROR(" ✖ Invalid pool max temp (must be 0-60°C): %s\n", value.c_str()); } } else if (property.equalsIgnoreCase("timer-start-h")) { TimerSetting timerSetting = getTimerSetting(); @@ -219,7 +224,7 @@ bool OperationModeNode::applyProperty(const String &property, const String &valu } retval = true; } else { - Serial.printf(" ✖ Invalid start hour (must be 0-23): %s\n", value.c_str()); + LOG_ERROR(" ✖ Invalid start hour (must be 0-23): %s\n", value.c_str()); } } else if (property.equalsIgnoreCase("timer-start-min")) { TimerSetting timerSetting = getTimerSetting(); @@ -231,7 +236,7 @@ bool OperationModeNode::applyProperty(const String &property, const String &valu } retval = true; } else { - Serial.printf(" ✖ Invalid start minutes (must be 0-59): %s\n", value.c_str()); + LOG_ERROR(" ✖ Invalid start minutes (must be 0-59): %s\n", value.c_str()); } } else if (property.equalsIgnoreCase("timer-end-h")) { TimerSetting timerSetting = getTimerSetting(); @@ -243,7 +248,7 @@ bool OperationModeNode::applyProperty(const String &property, const String &valu } retval = true; } else { - Serial.printf(" ✖ Invalid end hour (must be 0-23): %s\n", value.c_str()); + LOG_ERROR(" ✖ Invalid end hour (must be 0-23): %s\n", value.c_str()); } } else if (property.equalsIgnoreCase("timer-end-min")) { TimerSetting timerSetting = getTimerSetting(); @@ -255,7 +260,7 @@ bool OperationModeNode::applyProperty(const String &property, const String &valu } retval = true; } else { - Serial.printf(" ✖ Invalid end minutes (must be 0-59): %s\n", value.c_str()); + LOG_ERROR(" ✖ Invalid end minutes (must be 0-59): %s\n", value.c_str()); } } else if (property.equalsIgnoreCase("timezone")) { int tzIndex = value.toInt(); @@ -263,7 +268,7 @@ bool OperationModeNode::applyProperty(const String &property, const String &valu setTimezoneIndex(tzIndex); retval = true; } else { - Serial.printf(" ✖ Invalid timezone index: %d\n", tzIndex); + LOG_ERROR(" ✖ Invalid timezone index: %d\n", tzIndex); } } @@ -287,7 +292,7 @@ void OperationModeNode::loadState() { _timerSetting.timerEndHour = StateManager::loadInt("timerEndH", 17); _timerSetting.timerEndMinutes = StateManager::loadInt("timerEndM", 30); - Serial.println("✓ Operational mode state loaded from persistent storage."); + LOG_INFO("✓ Operational mode state loaded from persistent storage.\n"); } void OperationModeNode::saveState() { diff --git a/src/OtaUpdater.cpp b/src/OtaUpdater.cpp index 8bdf55e5..76594480 100644 --- a/src/OtaUpdater.cpp +++ b/src/OtaUpdater.cpp @@ -20,6 +20,7 @@ #include "NetworkManager.hpp" #include "SystemMonitor.hpp" #include "TimeClientHelper.hpp" +#include "LogCapture.hpp" namespace PoolController { @@ -72,7 +73,7 @@ uint8_t OtaUpdater::clockSyncFailCount_ = 0; // ── Public API ── void OtaUpdater::begin() { - Serial.printf("✓ OTA Updater initialized (current: %s)\n", currentVersion_.c_str()); + LOG_INFO("✓ OTA Updater initialized (current: %s)\n", currentVersion_.c_str()); statusMessage_ = "Idle"; } @@ -168,11 +169,11 @@ bool OtaUpdater::checkForUpdate() { return false; statusMessage_ = "Checking for updates..."; - Serial.println("OTA: Checking for firmware update..."); + LOG_INFO("OTA: Checking for firmware update...\n"); if (!fetchLatestRelease()) { statusMessage_ = "Check failed"; - Serial.println("OTA: Update check failed"); + LOG_ERROR("OTA: Update check failed\n"); return false; } @@ -180,13 +181,13 @@ bool OtaUpdater::checkForUpdate() { if (isNewerVersion(currentVersion_, latestVersion_)) { updateAvailable_ = true; statusMessage_ = "Update available: v" + getLatestVersion(); - Serial.printf("OTA: New version available: %s (current: %s)\n", latestVersion_.c_str(), currentVersion_.c_str()); + LOG_INFO("OTA: New version available: %s (current: %s)\n", latestVersion_.c_str(), currentVersion_.c_str()); return true; } updateAvailable_ = false; statusMessage_ = "Up to date (v" + currentVersion_ + ")"; - Serial.println("OTA: Firmware is up to date"); + LOG_INFO("OTA: Firmware is up to date\n"); return false; } @@ -194,12 +195,12 @@ bool OtaUpdater::checkForUpdate() { bool OtaUpdater::startUpdate() { if (updateInProgress_) { - Serial.println("OTA: Update already in progress"); + LOG_WARN("OTA: Update already in progress\n"); return false; } if (!updateAvailable_ || downloadUrl_.length() == 0) { statusMessage_ = "No update available"; - Serial.println("OTA: No update package available"); + LOG_WARN("OTA: No update package available\n"); return false; } if (!NetworkManager::isWiFiConnected()) { @@ -219,7 +220,7 @@ bool OtaUpdater::startUpdate() { const size_t estimatedFirmwareSize = 600 * 1024; // 600KB estimate if (!hasSufficientSpace(estimatedFirmwareSize)) { - Serial.println("OTA: Cannot start update: insufficient flash space"); + LOG_ERROR("OTA: Cannot start update: insufficient flash space\n"); return false; } @@ -229,13 +230,13 @@ bool OtaUpdater::startUpdate() { progress_ = 0; statusMessage_ = "Downloading... 0%"; - Serial.printf("OTA: Starting download from %s\n", downloadUrl_.c_str()); + LOG_INFO("OTA: Starting download from %s\n", downloadUrl_.c_str()); bool ok = downloadAndApply(downloadUrl_); if (!ok) { updateInProgress_ = false; statusMessage_ = "Update failed!"; - Serial.println("OTA: Update failed!"); + LOG_ERROR("OTA: Update failed!\n"); // updateAvailable_ stays true so the user can retry } else { // On success, clear the flag before reboot @@ -258,7 +259,7 @@ bool OtaUpdater::fetchLatestRelease() { // Only sync if time is not already set (time(0) > 100000 means year 2000+) time_t now = time(nullptr); if (now < 100000) { // Time not set yet - Serial.println("OTA: Syncing time before GitHub TLS verification..."); + LOG_INFO("OTA: Syncing time before GitHub TLS verification...\n"); // Ensure NTP client is set up timeClientSetup(ConfigManager::getNtp().server.c_str()); // Sync system clock from NTP (sets settimeofday for mbedTLS) @@ -267,11 +268,11 @@ bool OtaUpdater::fetchLatestRelease() { delay(2000); now = time(nullptr); if (now < 100000) { - Serial.println("OTA: Time sync failed, TLS verification may fail"); + LOG_WARN("OTA: Time sync failed, TLS verification may fail\n"); // Continue anyway - the TLS verification might still work // if the device has a valid time from a previous sync } else { - Serial.printf("OTA: Time synced: %ld\n", now); + LOG_INFO("OTA: Time synced: %ld\n", now); } } @@ -289,7 +290,7 @@ bool OtaUpdater::fetchLatestRelease() { // Build API URL String url = String("https://api.github.com/repos/") + GITHUB_REPO + "/releases/latest"; - Serial.printf("OTA: Fetching %s\n", url.c_str()); + LOG_DEBUG("OTA: Fetching %s\n", url.c_str()); HTTPClient http; http.begin(client, url); @@ -298,7 +299,7 @@ bool OtaUpdater::fetchLatestRelease() { int httpCode = http.GET(); if (httpCode != 200) { - Serial.printf("OTA: GitHub API returned HTTP %d\n", httpCode); + LOG_ERROR("OTA: GitHub API returned HTTP %d\n", httpCode); http.end(); return false; } @@ -309,14 +310,14 @@ bool OtaUpdater::fetchLatestRelease() { http.end(); if (err) { - Serial.printf("OTA: JSON parse error: %s\n", err.c_str()); + LOG_ERROR("OTA: JSON parse error: %s\n", err.c_str()); return false; } // Extract tag name (e.g. "v3.2.0") const char *tag = doc["tag_name"]; if (!tag || strlen(tag) == 0) { - Serial.println("OTA: No tag_name in response"); + LOG_ERROR("OTA: No tag_name in response\n"); return false; } latestVersion_ = String(tag); @@ -361,7 +362,7 @@ bool OtaUpdater::fetchLatestRelease() { const char *url = asset["browser_download_url"]; if (url) { downloadUrl_ = String(url); - Serial.println("OTA: Board-specific asset not found, using generic firmware.bin"); + LOG_WARN("OTA: Board-specific asset not found, using generic firmware.bin\n"); break; } } @@ -369,11 +370,11 @@ bool OtaUpdater::fetchLatestRelease() { } if (downloadUrl_.length() == 0) { - Serial.println("OTA: No firmware binary found in release assets"); + LOG_ERROR("OTA: No firmware binary found in release assets\n"); return false; } - Serial.printf("OTA: Found %s → %s\n", latestVersion_.c_str(), downloadUrl_.c_str()); + LOG_INFO("OTA: Found %s → %s\n", latestVersion_.c_str(), downloadUrl_.c_str()); return true; } @@ -431,14 +432,14 @@ bool OtaUpdater::downloadAndApply(const String &url) { int httpCode = http.GET(); if (httpCode != 200) { - Serial.printf("OTA: Download returned HTTP %d\n", httpCode); + LOG_ERROR("OTA: Download returned HTTP %d\n", httpCode); http.end(); return false; } int totalSize = http.getSize(); if (totalSize <= 0) { - Serial.println("OTA: Invalid content size"); + LOG_ERROR("OTA: Invalid content size\n"); http.end(); return false; } @@ -449,14 +450,14 @@ bool OtaUpdater::downloadAndApply(const String &url) { const size_t kMinFirmwareSize = 50 * 1024; // 50KB minimum if (static_cast(totalSize) > kMaxFirmwareSize) { - Serial.printf("OTA: Firmware too large: %d bytes (max %u)\n", totalSize, kMaxFirmwareSize); + LOG_ERROR("OTA: Firmware too large: %d bytes (max %u)\n", totalSize, kMaxFirmwareSize); statusMessage_ = "Error: Firmware too large"; http.end(); return false; } if (static_cast(totalSize) < kMinFirmwareSize) { - Serial.printf("OTA: Firmware too small: %d bytes (min %u)\n", totalSize, kMinFirmwareSize); + LOG_ERROR("OTA: Firmware too small: %d bytes (min %u)\n", totalSize, kMinFirmwareSize); statusMessage_ = "Error: Firmware too small"; http.end(); return false; @@ -464,15 +465,15 @@ bool OtaUpdater::downloadAndApply(const String &url) { // Verify we have sufficient space for this specific firmware size if (!hasSufficientSpace(static_cast(totalSize))) { - Serial.println("OTA: Insufficient space for this firmware"); + LOG_ERROR("OTA: Insufficient space for this firmware\n"); http.end(); return false; } - Serial.printf("OTA: Download size: %d bytes\n", totalSize); + LOG_DEBUG("OTA: Download size: %d bytes\n", totalSize); if (!Update.begin(totalSize)) { - Serial.printf("OTA: Update.begin() failed: %s\n", Update.errorString()); + LOG_ERROR("OTA: Update.begin() failed: %s\n", Update.errorString()); http.end(); return false; } @@ -500,7 +501,7 @@ bool OtaUpdater::downloadAndApply(const String &url) { size_t written = Update.write(buffer, read); if (written != read) { - Serial.printf("OTA: Write error at byte %d: %s\n", totalRead, Update.errorString()); + LOG_ERROR("OTA: Write error at byte %d: %s\n", totalRead, Update.errorString()); Update.end(false); http.end(); return false; @@ -514,17 +515,17 @@ bool OtaUpdater::downloadAndApply(const String &url) { http.end(); if (totalRead != totalSize) { - Serial.printf("OTA: Incomplete download (%d / %d)\n", totalRead, totalSize); + LOG_ERROR("OTA: Incomplete download (%d / %d)\n", totalRead, totalSize); Update.end(false); return false; } if (!Update.end(true)) { - Serial.printf("OTA: Update.end() failed: %s\n", Update.errorString()); + LOG_ERROR("OTA: Update.end() failed: %s\n", Update.errorString()); return false; } - Serial.println("OTA: Update successful! Rebooting..."); + LOG_INFO("OTA: Update successful! Rebooting...\n"); statusMessage_ = "Update successful! Rebooting..."; Serial.flush(); NetworkManager::restart(); @@ -556,12 +557,12 @@ bool OtaUpdater::hasSufficientSpace(size_t firmwareSize) { requiredSpace = std::max(requiredSpace, kMinFreeSpace); if (availableSpace < requiredSpace) { - Serial.printf("OTA: Insufficient flash space. Need %u bytes, have %u bytes\n", requiredSpace, availableSpace); + LOG_ERROR("OTA: Insufficient flash space. Need %u bytes, have %u bytes\n", requiredSpace, availableSpace); statusMessage_ = "Error: Insufficient flash space"; return false; } - Serial.printf("OTA: Sufficient space available (%u bytes free, %u bytes required)\n", availableSpace, requiredSpace); + LOG_INFO("OTA: Sufficient space available (%u bytes free, %u bytes required)\n", availableSpace, requiredSpace); return true; } diff --git a/src/PoolController.cpp b/src/PoolController.cpp index ea5338db..868676ba 100644 --- a/src/PoolController.cpp +++ b/src/PoolController.cpp @@ -34,6 +34,7 @@ #include "OtaUpdater.hpp" #include "Utils.hpp" #include "WpsProvisioner.hpp" +#include "LogCapture.hpp" #include "StatusLed.hpp" @@ -115,21 +116,21 @@ static void loadSensorAddressMapping() { solarTemperatureNode.setAddressFilter(solarAddr); char buf[17]; addressToString(solarAddr, buf, sizeof(buf)); - Serial.printf("• Sensor mapping: Solar address loaded [%s]\n", buf); + LOG_INFO("• Sensor mapping: Solar address loaded [%s]\n", buf); } if (plen == 8 && !isAddressZero(poolAddr)) { poolTemperatureNode.setAddressFilter(poolAddr); char buf[17]; addressToString(poolAddr, buf, sizeof(buf)); - Serial.printf("• Sensor mapping: Pool address loaded [%s]\n", buf); + LOG_INFO("• Sensor mapping: Pool address loaded [%s]\n", buf); } if ((slen == 8 && !isAddressZero(solarAddr)) || (plen == 8 && !isAddressZero(poolAddr))) { - Serial.println("• Sensor mapping: address filters applied (one or both sensors)"); + LOG_INFO("• Sensor mapping: address filters applied (one or both sensors)\n"); } else { - Serial.println("• Sensor mapping: no addresses configured — using default device indices"); - Serial.println(" ℹ To configure: long-press Button 1 → Sensor Setup page → assign sensors"); + LOG_WARN("• Sensor mapping: no addresses configured — using default device indices\n"); + LOG_INFO(" ℹ To configure: long-press Button 1 → Sensor Setup page → assign sensors\n"); } } @@ -166,33 +167,33 @@ auto PoolControllerContext::initializeController() -> void { continue; } #endif - Serial.printf("✖ PIN CONFLICT: %s (pin %d) and %s (pin %d) use same pin!\n", pinNames[i], pins[i], pinNames[j], pins[j]); + LOG_ERROR("✖ PIN CONFLICT: %s (pin %d) and %s (pin %d) use same pin!\n", pinNames[i], pins[i], pinNames[j], pins[j]); pinConflict = true; } } } if (pinConflict) { - Serial.println("✖ FATAL: Pin configuration conflicts detected!"); - Serial.println(" System will reboot in 5 seconds to try and recover..."); + LOG_ERROR("✖ FATAL: Pin configuration conflicts detected!\n"); + LOG_WARN(" System will reboot in 5 seconds to try and recover...\n"); Serial.flush(); delay(5000); ESP.restart(); // F27 Fix! Clean restart instead of blocking WDT loop } else { - Serial.println("✓ Pin configuration validated - no conflicts (optimierte Belegung)"); - Serial.printf(" Solar Temp (DS18B20): GPIO %d\n", PIN_DS_SOLAR); - Serial.printf(" Pool Temp (DS18B20): GPIO %d", PIN_DS_POOL); + LOG_INFO("✓ Pin configuration validated - no conflicts (optimierte Belegung)\n"); + LOG_INFO(" Solar Temp (DS18B20): GPIO %d\n", PIN_DS_SOLAR); #ifdef NORVI_AE01_R - Serial.print(" (shared bus via GPIO25)"); + LOG_INFO(" Pool Temp (DS18B20): GPIO %d (shared bus via GPIO25)\n", PIN_DS_POOL); +#else + LOG_INFO(" Pool Temp (DS18B20): GPIO %d\n", PIN_DS_POOL); #endif - Serial.println(); - Serial.printf(" Pool Pump (Relay): GPIO %d\n", PIN_RELAY_POOL); - Serial.printf(" Solar Pump (Relay): GPIO %d\n", PIN_RELAY_SOLAR); - Serial.printf(" Status LED: GPIO %d", PIN_LED_STATUS); + LOG_INFO(" Pool Pump (Relay): GPIO %d\n", PIN_RELAY_POOL); + LOG_INFO(" Solar Pump (Relay): GPIO %d\n", PIN_RELAY_SOLAR); #ifdef LED_BUILTIN - Serial.print(" (LED_BUILTIN)"); + LOG_INFO(" Status LED: GPIO %d (LED_BUILTIN)\n", PIN_LED_STATUS); +#else + LOG_INFO(" Status LED: GPIO %d\n", PIN_LED_STATUS); #endif - Serial.println(); } // Set measurement intervals and propagate to all nodes @@ -333,13 +334,13 @@ auto PoolControllerContext::setup() -> void { } else { operationModeNode.setMode("auto"); } - Serial.printf("→ Mode switched to: %s\n", operationModeNode.getMode().c_str()); + LOG_INFO("→ Mode switched to: %s\n", operationModeNode.getMode().c_str()); break; } case NorviOledDisplay::MenuItem::PUMP: // Toggle pool pump poolPumpNode.setSwitch(!poolPumpNode.getSwitch()); - Serial.printf("→ Pump toggled: %s\n", poolPumpNode.getSwitch() ? "ON" : "OFF"); + LOG_INFO("→ Pump toggled: %s\n", poolPumpNode.getSwitch() ? "ON" : "OFF"); break; case NorviOledDisplay::MenuItem::EXIT: // No action — just exit @@ -361,7 +362,7 @@ auto PoolControllerContext::setup() -> void { uint8_t solarAddr[8], poolAddr[8]; NorviOledDisplay::getMapping(solarAddr, poolAddr); ConfigManager::saveSensorMapping(solarAddr, poolAddr); - Serial.println("→ Sensor mapping saved — rebooting..."); + LOG_INFO("→ Sensor mapping saved — rebooting...\n"); NetworkManager::restart(); return true; } @@ -372,7 +373,7 @@ auto PoolControllerContext::setup() -> void { // --- Boot-loop detection --- bootLoopDetected_ = SystemMonitor::detectBootLoop(); if (bootLoopDetected_) { - Serial.println("✖ SAFE MODE ACTIVE — all relays forced OFF"); + LOG_ERROR("✖ SAFE MODE ACTIVE — all relays forced OFF\n"); DegradationManager::forceSafeMode(); // Clear stored relay states @@ -407,9 +408,9 @@ auto PoolControllerContext::setup() -> void { if (solarTemperatureNode.hasAddressFilter() || poolTemperatureNode.hasAddressFilter()) { char buf[17]; solarTemperatureNode.getDeviceAddressString(buf, sizeof(buf)); - Serial.printf(" ◦ Solar node → device [%s] (status: %s)\n", buf, solarTemperatureNode.isSensorFound() ? "✓" : "✖"); + LOG_INFO(" ◦ Solar node → device [%s] (status: %s)\n", buf, solarTemperatureNode.isSensorFound() ? "✓" : "✖"); poolTemperatureNode.getDeviceAddressString(buf, sizeof(buf)); - Serial.printf(" ◦ Pool node → device [%s] (status: %s)\n", buf, poolTemperatureNode.isSensorFound() ? "✓" : "✖"); + LOG_INFO(" ◦ Pool node → device [%s] (status: %s)\n", buf, poolTemperatureNode.isSensorFound() ? "✓" : "✖"); } OperationModeNode::suppressPersist(false); @@ -420,7 +421,7 @@ auto PoolControllerContext::setup() -> void { // OTA safety: detect version transition and verify config integrity ConfigManager::logOtaTransition(); - Serial.printf("✓ Controller setup completed. Free heap: %u B\n", ESP.getFreeHeap()); + LOG_INFO("✓ Controller setup completed. Free heap: %u B\n", ESP.getFreeHeap()); } /** @@ -451,7 +452,7 @@ auto PoolControllerContext::loop() -> void { bootCounterCleared = true; SystemMonitor::clearBootLoopCounter(); if (bootLoopDetected_) { - Serial.println("→ Safe-mode: 5 min stable — boot-loop counter cleared"); + LOG_INFO("→ Safe-mode: 5 min stable — boot-loop counter cleared\n"); DegradationManager::unforceSafeMode(); bootLoopDetected_ = false; } diff --git a/src/RelayModuleNode.cpp b/src/RelayModuleNode.cpp index 0ee3d595..b79344ed 100644 --- a/src/RelayModuleNode.cpp +++ b/src/RelayModuleNode.cpp @@ -11,6 +11,7 @@ #include "RelayModuleNode.hpp" #include "Utils.hpp" #include "DegradationManager.hpp" +#include "LogCapture.hpp" RelayModuleNode::RelayModuleNode(const char *id, const char *name, const uint8_t pin) : RelayModuleNode(id, name, pin, true) {} @@ -24,7 +25,7 @@ RelayModuleNode::RelayModuleNode(const char *id, const char *name, const uint8_t } void RelayModuleNode::begin() { - Serial.printf("• RelayModule Node '%s' initializing on PIN %d...\n", _id, _pin); + LOG_INFO("• RelayModule Node '%s' initializing on PIN %d...\n", _id, _pin); // ── Safe-start sequence ─────────────────────────────────────────────── // @@ -55,7 +56,7 @@ void RelayModuleNode::begin() { // 3. Apply polarity and transition to persisted state (OFF→ON if needed) digitalWrite(_pin, _currentState == _activeLow ? LOW : HIGH); - Serial.printf(" ◦ Relay restored to state: %s\n", _currentState ? "ON" : "OFF"); + LOG_INFO(" ◦ Relay restored to state: %s\n", _currentState ? "ON" : "OFF"); } void RelayModuleNode::setSwitch(const bool state) { @@ -67,7 +68,7 @@ void RelayModuleNode::setSwitch(const bool state) { // a relay to switch ON. Only OFF transitions are permitted so relays default // to the safe OFF state. if (state && PoolController::DegradationManager::isSafe()) { - Serial.println(" ⚠ SAFE MODE — ignoring relay ON request"); + LOG_WARN(" ⚠ SAFE MODE — ignoring relay ON request\n"); return; } @@ -76,12 +77,15 @@ void RelayModuleNode::setSwitch(const bool state) { digitalWrite(_pin, state == _activeLow ? LOW : HIGH); _currentState = state; + // Curated log event for MQTT event entity (only on real state change) + PoolController::LogCapture::logEvent(state ? "PUMP_ON" : "PUMP_OFF", "%s %s", getId(), state ? "ON" : "OFF"); + // Persist relay state via Preferences (NVS) preferences.begin(_id, false); preferences.putBool("switch", state); preferences.end(); - Serial.printf(" ◦ Relay '%s' switched to: %s\n", _id, state ? "ON" : "OFF"); + LOG_INFO(" ◦ Relay '%s' switched to: %s\n", _id, state ? "ON" : "OFF"); } bool RelayModuleNode::getSwitch() { @@ -91,6 +95,6 @@ bool RelayModuleNode::getSwitch() { void RelayModuleNode::loop() { if (Utils::shouldMeasure(_lastMeasurement, _measurementInterval)) { _lastMeasurement = millis(); - Serial.printf("〽 Relay '%s' status: %s\n", _id, getSwitch() ? "ON" : "OFF"); + LOG_DEBUG("〽 Relay '%s' status: %s\n", _id, getSwitch() ? "ON" : "OFF"); } } diff --git a/src/RuleAuto.cpp b/src/RuleAuto.cpp index 87a4dd0f..24e77463 100644 --- a/src/RuleAuto.cpp +++ b/src/RuleAuto.cpp @@ -10,23 +10,25 @@ #include "RuleAuto.hpp" #include // for isnan() +#include "LogCapture.hpp" + RuleAuto::RuleAuto(RelayModuleNode *solarRelay, RelayModuleNode *poolRelay) { _solarRelay = solarRelay; _poolRelay = poolRelay; } void RuleAuto::loop() { - Serial.println("§ RuleAuto: loop"); + LOG_INFO("§ RuleAuto: loop\n"); // Validate temperature readings before making decisions float poolTemp = getPoolTemperature(); float solarTemp = getSolarTemperature(); if (std::isnan(poolTemp) || std::isnan(solarTemp)) { - Serial.println(" ⚠ RuleAuto: Invalid temperature readings detected"); - Serial.printf(" Pool temp: %f\n", poolTemp); - Serial.printf(" Solar temp: %f\n", solarTemp); - Serial.println(" Turning off solar pump for safety"); + LOG_WARN(" ⚠ RuleAuto: Invalid temperature readings detected\n"); + LOG_WARN(" Pool temp: %f\n", poolTemp); + LOG_WARN(" Solar temp: %f\n", solarTemp); + LOG_WARN(" Turning off solar pump for safety\n"); // Turn off solar pump for safety, but keep pool pump running on timer _solarRelay->setSwitch(false); @@ -44,40 +46,40 @@ void RuleAuto::loop() { if (_solarRelay->getSwitch()) { // solar is on if (getSolarTemperature() < (getSolarMinTemperature() - hyst)) { - Serial.printf(" § RuleAuto: Solar below min. required solar temp. (%f). Switch solar off\n", getSolarMinTemperature()); + LOG_INFO(" § RuleAuto: Solar below min. required solar temp. (%f). Switch solar off\n", getSolarMinTemperature()); _solarRelay->setSwitch(false); } else if (getPoolTemperature() >= (getSolarTemperature() + hyst)) { - Serial.printf(" § RuleAuto: Pool temp. (%f) reaches solar temp (%f). Switch solar off\n", getPoolTemperature(), + LOG_INFO(" § RuleAuto: Pool temp. (%f) reaches solar temp (%f). Switch solar off\n", getPoolTemperature(), getSolarTemperature()); _solarRelay->setSwitch(false); } else if (getPoolTemperature() >= getPoolMaxTemperature()) { - Serial.printf(" § RuleAuto: Pool temp. (%f) reached max. temperature (%f). Switch solar off\n", getPoolTemperature(), + LOG_INFO(" § RuleAuto: Pool temp. (%f) reached max. temperature (%f). Switch solar off\n", getPoolTemperature(), getPoolMaxTemperature()); _solarRelay->setSwitch(false); } else { - Serial.println(" § RuleAuto: Solar on -> no change"); + LOG_INFO(" § RuleAuto: Solar on -> no change\n"); } } else { // solar is off if ((getPoolTemperature() <= (getPoolMaxTemperature() - hyst)) && (getPoolTemperature() <= (getSolarTemperature() - hyst)) && ((getSolarMinTemperature() + hyst) <= getSolarTemperature())) { - Serial.printf(" § RuleAuto: Pool temp (%f) below max temp minus hysteresis (%f). Switch solar on\n", - getPoolTemperature(), getPoolMaxTemperature() - hyst); + LOG_INFO(" § RuleAuto: Pool temp (%f) below max temp minus hysteresis (%f). Switch solar on\n", getPoolTemperature(), + getPoolMaxTemperature() - hyst); _solarRelay->setSwitch(true); } else { - Serial.println(" § RuleAuto: Solar off -> no change"); + LOG_INFO(" § RuleAuto: Solar off -> no change\n"); } } } else { if (_solarRelay->getSwitch()) { - Serial.println(" § RuleAuto: pool pump is disabled. Switch solar off"); + LOG_INFO(" § RuleAuto: pool pump is disabled. Switch solar off\n"); _solarRelay->setSwitch(false); } } - Serial.printf(" § RuleAuto: Pool temp. : %f\n", getPoolTemperature()); - Serial.printf(" § RuleAuto: max. Pool temp.: %f\n", getPoolMaxTemperature()); - Serial.printf(" § RuleAuto: Solar temp. : %f\n", getSolarTemperature()); - Serial.printf(" § RuleAuto: min. Solar temp.: %f\n", getSolarMinTemperature()); + LOG_INFO(" § RuleAuto: Pool temp. : %f\n", getPoolTemperature()); + LOG_INFO(" § RuleAuto: max. Pool temp.: %f\n", getPoolMaxTemperature()); + LOG_INFO(" § RuleAuto: Solar temp. : %f\n", getSolarTemperature()); + LOG_INFO(" § RuleAuto: min. Solar temp.: %f\n", getSolarMinTemperature()); } diff --git a/src/RuleBoost.cpp b/src/RuleBoost.cpp index c808b70f..d20dd7b2 100644 --- a/src/RuleBoost.cpp +++ b/src/RuleBoost.cpp @@ -11,14 +11,15 @@ #include #include // For isnan() +#include "LogCapture.hpp" + RuleBoost::RuleBoost(RelayModuleNode *solarRelay, RelayModuleNode *poolRelay) { _solarRelay = solarRelay; _poolRelay = poolRelay; } void RuleBoost::loop() { - Serial.print(cIndent); - Serial.println(F("§ RuleBoost: loop")); + LOG_INFO("%s§ RuleBoost: loop\n", cIndent); // Check for invalid temperatures (NaN from sensor disconnect) float poolTemp = getPoolTemperature(); @@ -27,8 +28,7 @@ void RuleBoost::loop() { // Safety: Turn off solar if any temperature is invalid if (isnan(poolTemp) || isnan(solarTemp)) { if (_solarRelay->getSwitch()) { - Serial.print(cIndent); - Serial.println(F("§ RuleBoost: Invalid temperature sensor. Switch solar off for safety")); + LOG_INFO("%s§ RuleBoost: Invalid temperature sensor. Switch solar off for safety\n", cIndent); _solarRelay->setSwitch(false); } return; @@ -38,26 +38,22 @@ void RuleBoost::loop() { if (_solarRelay->getSwitch()) { // solar is ON — check if it should turn OFF if (poolTemp > getPoolMaxTemperature()) { - Serial.print(cIndent); - Serial.println(F("§ RuleBoost: Maximum pool temp reached. Switch solar off")); + LOG_INFO("%s§ RuleBoost: Maximum pool temp reached. Switch solar off\n", cIndent); _solarRelay->setSwitch(false); } else if (poolTemp > (solarTemp + getTemperatureHysteresis())) { - Serial.print(cIndent); - Serial.println(F("§ RuleBoost: Pool temp reaches solar temp. Switch solar off")); + LOG_INFO("%s§ RuleBoost: Pool temp reaches solar temp. Switch solar off\n", cIndent); _solarRelay->setSwitch(false); } } else { // solar is OFF — check if it should turn ON if ((poolTemp < (getPoolMaxTemperature() - getTemperatureHysteresis())) && (poolTemp < (solarTemp - getTemperatureHysteresis()))) { - Serial.print(cIndent); - Serial.println(F("§ RuleBoost: below max. Temperature. Switch solar on")); + LOG_INFO("%s§ RuleBoost: below max. Temperature. Switch solar on\n", cIndent); _solarRelay->setSwitch(true); } } } else { - Serial.print(cIndent); - Serial.println(F("§ RuleBoost: pool pump is disabled.")); + LOG_INFO("%s§ RuleBoost: pool pump is disabled.\n", cIndent); if (_solarRelay->getSwitch()) { _solarRelay->setSwitch(false); } diff --git a/src/RuleManu.cpp b/src/RuleManu.cpp index e32042a9..bbad2f97 100644 --- a/src/RuleManu.cpp +++ b/src/RuleManu.cpp @@ -9,10 +9,11 @@ #include "RuleManu.hpp" #include +#include "LogCapture.hpp" RuleManu::RuleManu() {} void RuleManu::loop() { // no ruling if manual - Serial.println(F(" ◦ § RuleManu: loop")); + LOG_INFO(" ◦ § RuleManu: loop\n"); } diff --git a/src/RuleTimer.cpp b/src/RuleTimer.cpp index e11e2e69..435d0c07 100644 --- a/src/RuleTimer.cpp +++ b/src/RuleTimer.cpp @@ -8,6 +8,7 @@ */ #include "RuleTimer.hpp" +#include "LogCapture.hpp" RuleTimer::RuleTimer(RelayModuleNode *solarRelay, RelayModuleNode *poolRelay) { _solarRelay = solarRelay; @@ -15,7 +16,7 @@ RuleTimer::RuleTimer(RelayModuleNode *solarRelay, RelayModuleNode *poolRelay) { } void RuleTimer::loop() { - Serial.println("§ RuleTimer: loop"); + LOG_INFO("§ RuleTimer: loop\n"); _poolRelay->setSwitch(checkPoolPumpTimer(getPoolTemperature())); diff --git a/src/StatusLed.cpp b/src/StatusLed.cpp index 6c52d19c..b28f904b 100644 --- a/src/StatusLed.cpp +++ b/src/StatusLed.cpp @@ -16,6 +16,7 @@ #include #include "Config.hpp" +#include "LogCapture.hpp" namespace PoolController { @@ -32,10 +33,18 @@ void StatusLed::begin() { // Modellunabhängiger Pin — überschreibe Config.hpp-Default, falls die // Platform einen spezifischen LED_BUILTIN definiert. #ifdef LED_BUILTIN - ledPin_ = static_cast(LED_BUILTIN); - Serial.printf("• StatusLed using LED_BUILTIN (GPIO %d)\n", ledPin_); + // Override Config.hpp default only when it uses the generic value (GPIO2), + // meaning no board-specific config set a different pin. This lets NORVI + // (external LED on GPIO27) keep its explicit assignment while standard + // ESP32 dev boards still get LED_BUILTIN (typically also GPIO2). + if (PIN_LED_STATUS == 2) { + ledPin_ = static_cast(LED_BUILTIN); + LOG_INFO("• StatusLed using LED_BUILTIN (GPIO %d)\n", ledPin_); + } else { + LOG_INFO("• StatusLed using config pin GPIO %d (board-specific, LED_BUILTIN overridden)\n", ledPin_); + } #else - Serial.printf("• StatusLed using default GPIO %d (no LED_BUILTIN defined)\n", ledPin_); + LOG_INFO("• StatusLed using config default GPIO %d (no LED_BUILTIN)\n", ledPin_); #endif pinMode(ledPin_, OUTPUT); @@ -46,10 +55,10 @@ void StatusLed::begin() { if (warnPin_ >= 0) { pinMode(static_cast(warnPin_), OUTPUT); digitalWrite(static_cast(warnPin_), LOW); - Serial.printf("• StatusLed WARN pin enabled on GPIO %d\n", warnPin_); + LOG_INFO("• StatusLed WARN pin enabled on GPIO %d\n", warnPin_); } - Serial.println("✓ StatusLed initialized"); + LOG_INFO("✓ StatusLed initialized\n"); } // ── Pattern setzen ───────────────────────────────────────────────────────── diff --git a/src/SystemMonitor.hpp b/src/SystemMonitor.hpp index 466b2dc0..b87d6a1f 100644 --- a/src/SystemMonitor.hpp +++ b/src/SystemMonitor.hpp @@ -23,6 +23,8 @@ #include #include +#include "LogCapture.hpp" + namespace PoolController { /** @@ -92,7 +94,7 @@ class SystemMonitor { // Critical memory — reboot immediately if (freeHeap < CRITICAL_MEMORY_THRESHOLD) { - Serial.printf("CRITICAL: Free heap %d bytes < %d bytes. Rebooting...\n", freeHeap, CRITICAL_MEMORY_THRESHOLD); + LOG_ERROR("CRITICAL: Free heap %d bytes < %d bytes. Rebooting...\n", freeHeap, CRITICAL_MEMORY_THRESHOLD); Serial.flush(); delay(1000); ESP.restart(); @@ -100,8 +102,8 @@ class SystemMonitor { // Low memory — log warning if (freeHeap < LOW_MEMORY_THRESHOLD && !lowMemoryWarning) { - Serial.printf("WARNING: Low memory detected. Free heap: %d bytes " - "(min: %d)\n", + LOG_WARN("WARNING: Low memory detected. Free heap: %d bytes " + "(min: %d)\n", freeHeap, minFreeHeap); lowMemoryWarning = true; } else if (freeHeap >= LOW_MEMORY_THRESHOLD && lowMemoryWarning) { @@ -117,7 +119,7 @@ class SystemMonitor { /** Force a reboot */ static void reboot() { - Serial.println("System reboot requested"); + LOG_INFO("System reboot requested\n"); Serial.flush(); delay(1000); ESP.restart(); @@ -154,12 +156,12 @@ class SystemMonitor { int bootCount = prefs.getInt("bootCount", 0) + 1; - Serial.printf(" Boot counter: %d\n", bootCount); + LOG_INFO(" Boot counter: %d\n", bootCount); bool isBootLoop = (bootCount >= BOOT_LOOP_MAX_COUNT); if (isBootLoop) { - Serial.printf("✖ BOOT-LOOP DETECTED (%d consecutive boots)\n", bootCount); - Serial.println(" Entering safe mode — all relays OFF"); + LOG_ERROR("✖ BOOT-LOOP DETECTED (%d consecutive boots)\n", bootCount); + LOG_ERROR(" Entering safe mode — all relays OFF\n"); } prefs.putInt("bootCount", bootCount); diff --git a/src/TimeClientHelper.cpp b/src/TimeClientHelper.cpp index ec36eb57..aefee3ea 100644 --- a/src/TimeClientHelper.cpp +++ b/src/TimeClientHelper.cpp @@ -9,6 +9,7 @@ #include // For settimeofday +#include "LogCapture.hpp" #include "NetworkManager.hpp" #include "TimeClientHelper.hpp" @@ -150,9 +151,9 @@ void syncSystemClock() { tv.tv_sec = ntpTime; tv.tv_usec = 0; settimeofday(&tv, nullptr); - Serial.printf("Time: System clock set to %ld\n", ntpTime); + LOG_INFO("Time: System clock set to %ld\n", ntpTime); } else { - Serial.println("Time: Cannot set system clock - NTP time not valid"); + LOG_WARN("Time: Cannot set system clock - NTP time not valid\n"); } } diff --git a/src/Timer.cpp b/src/Timer.cpp index b3db18a4..1571f04e 100644 --- a/src/Timer.cpp +++ b/src/Timer.cpp @@ -10,6 +10,7 @@ #include "Timer.hpp" #include "TimeClientHelper.hpp" #include "ConfigManager.hpp" +#include "LogCapture.hpp" /** * Get current date/time, with validation @@ -87,7 +88,7 @@ uint16_t calculateEffectiveEndMinutes(uint16_t baseStartMinutes, uint16_t baseEn // Calculate new end minutes (add runtime to start, can wrap past midnight) uint16_t extended = baseStartMinutes + totalRuntime; - Serial.printf(" → TempCirc: %.1f°C, base=%umin, extra=%umin, total=%umin, end=%02d:%02d\n", poolTemp, baseRuntime, extra, + LOG_INFO(" → TempCirc: %.1f°C, base=%umin, extra=%umin, total=%umin, end=%02d:%02d\n", poolTemp, baseRuntime, extra, totalRuntime, (extended / 60) % 24, extended % 60); return extended; diff --git a/src/WebPortal.cpp b/src/WebPortal.cpp index 73ca8d13..d8529d8b 100644 --- a/src/WebPortal.cpp +++ b/src/WebPortal.cpp @@ -38,6 +38,7 @@ #include "SystemMonitor.hpp" #include "TimeClientHelper.hpp" #include "Version.h" +#include "LogCapture.hpp" namespace PoolController { @@ -60,7 +61,7 @@ constexpr uint16_t WebPortal::kDnsPort; bool WebPortal::begin() { if (!LittleFS.begin(false)) { - Serial.println("✖ LittleFS mount failed — static web assets may be unavailable"); + LOG_ERROR("✖ LittleFS mount failed — static web assets may be unavailable\n"); } setupRoutes(); @@ -69,12 +70,12 @@ bool WebPortal::begin() { if (NetworkManager::isApMode()) { dnsServer_.setErrorReplyCode(DNSReplyCode::NoError); dnsServer_.start(kDnsPort, "*", WiFi.softAPIP()); - Serial.println("✓ Captive Portal DNS running."); + LOG_INFO("✓ Captive Portal DNS running.\n"); dnsServerStarted_ = true; } server_.begin(); - Serial.println("✓ Web Server running on port 80."); + LOG_INFO("✓ Web Server running on port 80.\n"); // Initialize CSRF token generateCsrfToken(); @@ -87,7 +88,7 @@ void WebPortal::loop() { if (!dnsServerStarted_) { dnsServer_.setErrorReplyCode(DNSReplyCode::NoError); dnsServer_.start(kDnsPort, "*", WiFi.softAPIP()); - Serial.println("✓ Captive Portal DNS running."); + LOG_INFO("✓ Captive Portal DNS running.\n"); dnsServerStarted_ = true; } dnsServer_.processNextRequest(); @@ -96,7 +97,7 @@ void WebPortal::loop() { // Session timeout checking if (activeSessionToken_.length() > 0 && (millis() - sessionStartTime_ > kSessionTimeoutMs)) { - Serial.println("Session timed out."); + LOG_WARN("Session timed out.\n"); activeSessionToken_ = ""; } } @@ -256,6 +257,14 @@ void WebPortal::setupRoutes() { apiSaveSensorMapping(); }); + // Log view — GET is unauthenticated (read-only), clear remains authenticated. + server_.on("/api/logs", HTTP_GET, apiGetLogs); + server_.on("/api/logs/clear", HTTP_POST, []() { + if (!handleAuthentication()) + return; + apiClearLogs(); + }); + // LittleFS file upload (for OTA-safe web asset deployment) server_.on( "/api/fs/upload", HTTP_POST, @@ -281,7 +290,7 @@ void WebPortal::setupRoutes() { return; HTTPUpload &upload = server_.upload(); if (upload.status == UPLOAD_FILE_START) { - Serial.printf("Signed OTA Update Starting: %s\n", upload.filename.c_str()); + LOG_INFO("Signed OTA Update Starting: %s\n", upload.filename.c_str()); if (!Update.begin(UPDATE_SIZE_UNKNOWN)) { Update.printError(Serial); } @@ -291,7 +300,7 @@ void WebPortal::setupRoutes() { } } else if (upload.status == UPLOAD_FILE_END) { if (Update.end(true)) { - Serial.printf("Signed OTA Update Success: %u bytes\n", upload.totalSize); + LOG_INFO("Signed OTA Update Success: %u bytes\n", upload.totalSize); } else { Update.printError(Serial); } @@ -509,6 +518,99 @@ void WebPortal::apiGetStatus() { } } +// ── Log view (REST /api/logs) ────────────────────────────────────────────── + +size_t WebPortal::buildLogsJson(uint32_t since, uint32_t epoch, size_t count, LogLevel minLevel, char *buf, size_t bufSize) { + if (buf == nullptr || bufSize == 0) { + return 0; + } + + // Copy entries out of the ring into a fixed array (snapshot consistency — + // getEntries reads under the log mutex). Static: no stack pressure. + static LogEntry entries[LogCapture::LOG_BUFFER_ENTRIES]; + size_t n = LogCapture::getEntries(since, epoch, count, minLevel, entries, LogCapture::LOG_BUFFER_ENTRIES); + + JsonDocument doc; + doc["ok"] = true; + // The client echoes the boot epoch it last saw; a mismatch with the current + // boot tells it to discard its cursor even when the new sequence has already + // grown past it. Always report the CURRENT epoch, not the requested one. + doc["boot"] = LogCapture::epoch(); + // getEntries() treats `since` as an exclusive cursor (skips entry.seq <= since), + // so next must be the highest sequence actually consumed, not lastSeq()+1: + // a cursor of lastSeq()+1 would skip the entry whose seq equals that value on + // the next poll, and truncated responses would jump past unreturned entries. + // With no entries, keep the previous cursor (no progress, nothing skipped). + doc["next"] = (n > 0) ? entries[n - 1].seq : since; + + JsonArray arr = doc["entries"].to(); + for (size_t i = 0; i < n; ++i) { + JsonObject obj = arr.add(); + obj["seq"] = entries[i].seq; + obj["t"] = entries[i].uptimeMs; + obj["level"] = LogCapture::levelName(entries[i].level); + obj["msg"] = entries[i].message; + } + + size_t jsonLength = serializeJson(doc, buf, bufSize); + // Signal truncation (buffer too small) instead of returning broken JSON + if (jsonLength >= bufSize) { + return 0; + } + return jsonLength; +} + +void WebPortal::apiGetLogs() { + uint32_t since = 0; + // Omitted boot parameter = current boot: the documented since-polling flow + // keeps working incrementally. Only clients that explicitly send a boot epoch + // get reboot detection (a stale epoch forces a full dump). + uint32_t epoch = LogCapture::epoch(); + size_t count = 200; + LogLevel minLevel = LogLevel::Info; + + if (server_.hasArg("since")) { + since = static_cast(atol(server_.arg("since").c_str())); + } + if (server_.hasArg("boot")) { + // Parse as unsigned 32-bit: esp_random() produces values above LONG_MAX + // on roughly half of boots, which atol() would overflow (→ stale epoch → + // full ring + duplicate entries on every poll). strtoul reconstructs the + // full uint32 range; on invalid input we keep the current boot (safe + // fallback that preserves incremental since-polling). + char *end = nullptr; + const unsigned long v = strtoul(server_.arg("boot").c_str(), &end, 10); + if (end != server_.arg("boot").c_str() && v <= UINT32_MAX) { + epoch = static_cast(v); + } + } + if (server_.hasArg("count")) { + long c = atol(server_.arg("count").c_str()); + if (c > 0 && c <= 500) { + count = static_cast(c); + } + } + if (server_.hasArg("level")) { + minLevel = LogCapture::parseLevel(server_.arg("level").c_str()); + } + + // Serialize directly to a pre-allocated buffer to minimize String usage. + // Worst case: LOG_BUFFER_ENTRIES entries x ~140 bytes each + envelope. + // Use a static buffer to avoid heap fragmentation. + static char jsonBuffer[16384]; + size_t jsonLength = buildLogsJson(since, epoch, count, minLevel, jsonBuffer, sizeof(jsonBuffer)); + if (jsonLength > 0) { + server_.send(200, "application/json", jsonBuffer); + } else { + server_.send(500, "text/plain", "JSON serialization error"); + } +} + +void WebPortal::apiClearLogs() { + LogCapture::clear(); + server_.send(200, "application/json", "{\"ok\":true}"); +} + void WebPortal::apiScanWiFi() { int n = WiFi.scanNetworks(); JsonDocument doc; @@ -1116,19 +1218,19 @@ void WebPortal::handleFsUploadStream() { path = upload.filename; } if (path.length() == 0) { - Serial.println("FS Upload: missing path argument — aborting"); + LOG_WARN("FS Upload: missing path argument — aborting\n"); return; } // Security: only allow files under /web/ if (!path.startsWith("/web/")) { - Serial.printf("FS Upload: path \"%s\" not under /web/ — rejected\n", path.c_str()); + LOG_WARN("FS Upload: path \"%s\" not under /web/ — rejected\n", path.c_str()); return; } // Security: prevent path traversal if (path.indexOf("..") != -1) { - Serial.printf("FS Upload: path traversal detected: \"%s\"\n", path.c_str()); + LOG_WARN("FS Upload: path traversal detected: \"%s\"\n", path.c_str()); return; } @@ -1139,11 +1241,11 @@ void WebPortal::handleFsUploadStream() { fsUploadFile = LittleFS.open(path, "w"); if (!fsUploadFile) { - Serial.printf("FS Upload: failed to open \"%s\" for writing\n", path.c_str()); + LOG_ERROR("FS Upload: failed to open \"%s\" for writing\n", path.c_str()); return; } - Serial.printf("FS Upload: started \"%s\" (%u bytes)\n", path.c_str(), upload.totalSize); + LOG_INFO("FS Upload: started \"%s\" (%u bytes)\n", path.c_str(), upload.totalSize); } else if (upload.status == UPLOAD_FILE_WRITE) { if (fsUploadFile) { @@ -1153,7 +1255,7 @@ void WebPortal::handleFsUploadStream() { } else if (upload.status == UPLOAD_FILE_END) { if (fsUploadFile) { fsUploadFile.close(); - Serial.printf("FS Upload: finished \"%s\" (%u bytes)\n", upload.filename.c_str(), upload.totalSize); + LOG_INFO("FS Upload: finished \"%s\" (%u bytes)\n", upload.filename.c_str(), upload.totalSize); } } } diff --git a/src/WebPortal.hpp b/src/WebPortal.hpp index 262f143c..0831097b 100644 --- a/src/WebPortal.hpp +++ b/src/WebPortal.hpp @@ -13,6 +13,8 @@ #include #include +#include "LogCapture.hpp" + namespace PoolController { /** @@ -59,6 +61,12 @@ class WebPortal { /** @brief Get login lockout duration in milliseconds. */ static uint32_t getLoginLockoutMs() { return kLoginLockoutMs; } + // ── Log view helper (public for testing) ── + /** @brief Serialize LogCapture entries as the /api/logs JSON payload. + * @param epoch boot epoch of the client's cursor (see LogCapture::epoch()). + * @return bytes written (0 on error / empty buffer). */ + static size_t buildLogsJson(uint32_t since, uint32_t epoch, size_t count, LogLevel minLevel, char *buf, size_t bufSize); + private: /** @brief Register all HTTP routes, handlers, and static asset paths. */ static void setupRoutes(); @@ -86,6 +94,10 @@ class WebPortal { // ── REST API Handlers ── /** @brief GET /api/status — return JSON with all telemetry data. */ static void apiGetStatus(); + /** @brief GET /api/logs — return JSON with captured log entries (unauthenticated, read-only). */ + static void apiGetLogs(); + /** @brief POST /api/logs/clear — empty the LogCapture ring buffer (authenticated). */ + static void apiClearLogs(); /** @brief GET /api/wifi/scan — return JSON list of visible WiFi networks. */ static void apiScanWiFi(); /** @brief GET /api/config — return current configuration as JSON. */ diff --git a/src/WpsProvisioner.cpp b/src/WpsProvisioner.cpp index 57593109..0d842ea7 100644 --- a/src/WpsProvisioner.cpp +++ b/src/WpsProvisioner.cpp @@ -17,6 +17,7 @@ #include #include "ConfigManager.hpp" +#include "LogCapture.hpp" namespace { constexpr gpio_num_t WPS_TRIGGER_PIN{GPIO_NUM_0}; @@ -41,7 +42,7 @@ static WpsProvisionState wpsProvisionState{}; auto stopWps() -> void { const esp_err_t disableErr = esp_wifi_wps_disable(); if (disableErr != ESP_OK && disableErr != ESP_ERR_WIFI_WPS_SM) { - Serial.printf("WPS disable failed: 0x%x (%s)\n", static_cast(disableErr), esp_err_to_name(disableErr)); + LOG_ERROR("WPS disable failed: 0x%x (%s)\n", static_cast(disableErr), esp_err_to_name(disableErr)); } } @@ -60,13 +61,13 @@ auto startWps() -> bool { modelNumberLen < 0 || static_cast(modelNumberLen) >= sizeof(config.factory_info.model_number) || modelNameLen < 0 || static_cast(modelNameLen) >= sizeof(config.factory_info.model_name) || deviceNameLen < 0 || static_cast(deviceNameLen) >= sizeof(config.factory_info.device_name)) { - Serial.println(F("WPS: factory-info string truncated")); + LOG_INFO("WPS: factory-info string truncated\n"); return false; } const esp_err_t enableErr = esp_wifi_wps_enable(&config); if (enableErr != ESP_OK) { - Serial.printf("WPS enable failed: 0x%x (%s)\n", static_cast(enableErr), esp_err_to_name(enableErr)); + LOG_ERROR("WPS enable failed: 0x%x (%s)\n", static_cast(enableErr), esp_err_to_name(enableErr)); return false; } @@ -76,7 +77,7 @@ auto startWps() -> bool { const esp_err_t startErr = esp_wifi_wps_start(0); #endif if (startErr != ESP_OK) { - Serial.printf("WPS start failed: 0x%x (%s)\n", static_cast(startErr), esp_err_to_name(startErr)); + LOG_ERROR("WPS start failed: 0x%x (%s)\n", static_cast(startErr), esp_err_to_name(startErr)); stopWps(); return false; } @@ -93,7 +94,7 @@ auto persistWpsWifiCredentials() -> bool { WiFi.SSID().toCharArray(connectedSsid, sizeof(connectedSsid)); if (connectedSsid[0] == '\0') { - Serial.println(F("WPS: no SSID after successful pairing")); + LOG_INFO("WPS: no SSID after successful pairing\n"); return false; } @@ -102,11 +103,11 @@ auto persistWpsWifiCredentials() -> bool { PoolController::ConfigManager::setConfigured(true); // P1: Mark device as configured if (!PoolController::ConfigManager::save()) { - Serial.println(F("WPS: failed to persist WiFi credentials to config")); + LOG_ERROR("WPS: failed to persist WiFi credentials to config\n"); return false; } - Serial.printf("WPS: persisted WiFi credentials for SSID '%s'\n", connectedSsid); + LOG_INFO("WPS: persisted WiFi credentials for SSID '%s'\n", connectedSsid); return true; } @@ -165,7 +166,7 @@ auto WpsProvisioner::runIfRequested() -> void { return; } - Serial.println(F("WPS: trigger button held, starting WPS provisioning")); + LOG_INFO("WPS: trigger button held, starting WPS provisioning\n"); wpsProvisionState.success.store(false); wpsProvisionState.failed.store(false); @@ -190,10 +191,10 @@ auto WpsProvisioner::runIfRequested() -> void { if (wpsProvisionState.success.load() && waitForWifiConnected(WPS_CONNECT_TIMEOUT_MS)) { const bool persisted = persistWpsWifiCredentials(); if (!persisted) { - Serial.println(F("WPS: connected, but credentials were not persisted")); + LOG_INFO("WPS: connected, but credentials were not persisted\n"); } } else { - Serial.println(F("WPS: provisioning failed or timed out")); + LOG_ERROR("WPS: provisioning failed or timed out\n"); stopWps(); // Retry with previously stored WiFi credentials. WiFi.begin(); diff --git a/src/main.cpp b/src/main.cpp index 5813e69d..56bf860b 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -11,6 +11,7 @@ */ #include +#include "LogCapture.hpp" #include "PoolController.hpp" /** @brief Singleton context owning all controller subsystems. */ @@ -33,6 +34,11 @@ auto setup() -> void { delay(10); } + // Central logging service — must start before context.setup() so boot-time + // LOG_* entries (WiFi/MQTT init, sensor scans) are captured and the MQTT + // export watermark sees the pre-boot sequence. Serial is already up here. + PoolController::LogCapture::begin(); + context.setup(); } diff --git a/test/native/CMakeLists.txt b/test/native/CMakeLists.txt index d3518b6f..5cf49be1 100644 --- a/test/native/CMakeLists.txt +++ b/test/native/CMakeLists.txt @@ -54,6 +54,7 @@ set(SERVICE_SOURCES ${PROJ_ROOT}/src/DegradationManager.cpp ${PROJ_ROOT}/src/SystemMonitor.cpp ${PROJ_ROOT}/src/OtaUpdater.cpp + ${PROJ_ROOT}/src/LogCapture.cpp ) # Mock sources (compiled once) @@ -75,6 +76,8 @@ set(TEST_SOURCES ${CMAKE_CURRENT_SOURCE_DIR}/tests/test_security.cpp ${CMAKE_CURRENT_SOURCE_DIR}/tests/test_state_manager.cpp ${CMAKE_CURRENT_SOURCE_DIR}/tests/test_timer.cpp + ${CMAKE_CURRENT_SOURCE_DIR}/tests/test_logcapture.cpp + ${CMAKE_CURRENT_SOURCE_DIR}/tests/test_webportal_logs.cpp ) add_executable(test_runner diff --git a/test/native/mocks/Arduino.h b/test/native/mocks/Arduino.h index 309f4ca0..fa6f110d 100644 --- a/test/native/mocks/Arduino.h +++ b/test/native/mocks/Arduino.h @@ -121,8 +121,17 @@ class String { // ---- Serial mock ---- class SerialClass { public: + // Optional stdout capture for tests that need to assert on Serial output. + // Disabled by default so existing tests are unaffected. + static std::string s_capture; + static bool s_captureEnabled; + static void enableCapture() { s_captureEnabled = true; s_capture.clear(); } + static void disableCapture() { s_captureEnabled = false; s_capture.clear(); } + static const std::string &capture() { return s_capture; } + void begin(int) {} void print(const char *s) { + if (s_captureEnabled) s_capture += s; fprintf(stdout, "%s", s); fflush(stdout); } diff --git a/test/native/mocks/NetworkManager.cpp b/test/native/mocks/NetworkManager.cpp index 73fd3f75..fb729157 100644 --- a/test/native/mocks/NetworkManager.cpp +++ b/test/native/mocks/NetworkManager.cpp @@ -7,5 +7,8 @@ bool NetworkManager::_wifiConnected = true; bool NetworkManager::_mqttConnected = true; bool NetworkManager::_apMode = false; int NetworkManager::_wifiRssi = -65; +bool NetworkManager::_publishOk = true; +std::function NetworkManager::_publishHook; +std::string NetworkManager::_publishHookTopic; } // namespace PoolController diff --git a/test/native/mocks/NetworkManager.hpp b/test/native/mocks/NetworkManager.hpp index a9588e60..0ea7562b 100644 --- a/test/native/mocks/NetworkManager.hpp +++ b/test/native/mocks/NetworkManager.hpp @@ -20,7 +20,15 @@ class NetworkManager { static String getLocalIP() { return String("192.168.1.100"); } static bool publish(const char *topic, const char *payload, bool retained = false) { - return _mqttClient.publish(topic, 1, retained, payload) > 0; + if (!_publishOk) return false; + bool ok = _mqttClient.publish(topic, 1, retained, payload) > 0; + if (_publishHook && _publishHookTopic == topic) { + auto hook = std::move(_publishHook); // one-shot: prevents recursion + _publishHook = nullptr; + _publishHookTopic.clear(); + hook(); + } + return ok; } static bool subscribe(const char *topic) { return _mqttClient.subscribe(topic) > 0; } @@ -37,6 +45,19 @@ class NetworkManager { static void setMqttConnected(bool v) { _mqttConnected = v; } static void setApMode(bool v) { _apMode = v; } static void setWiFiRSSI(int rssi) { _wifiRssi = rssi; } + // Simulate AsyncMqttClient refusing to enqueue (publish returns false). + static void setPublishOk(bool ok) { _publishOk = ok; } + // One-shot hook fired when the next publish() targets `topic` — lets a test + // simulate a reentrant publishStates() from the AsyncMqttClient callback + // path while an export on that topic is already in progress. + static void setPublishHook(const char *topic, std::function cb) { + _publishHookTopic = topic ? topic : ""; + _publishHook = std::move(cb); + } + static void clearPublishHook() { + _publishHook = nullptr; + _publishHookTopic.clear(); + } static AsyncMqttClient &getClient() { return _mqttClient; } @@ -46,6 +67,9 @@ class NetworkManager { static bool _mqttConnected; static bool _apMode; static int _wifiRssi; + static bool _publishOk; + static std::function _publishHook; + static std::string _publishHookTopic; }; } // namespace PoolController diff --git a/test/native/mocks/Update.h b/test/native/mocks/Update.h index 3e5c820e..d4d69276 100644 --- a/test/native/mocks/Update.h +++ b/test/native/mocks/Update.h @@ -25,7 +25,7 @@ class UpdateClass { void printError(Print &p) {} void printError(int) {} void printError(SerialClass &s) {} - String errorString() { return String(""); } + const char* errorString() { return ""; } void abort() {} }; static UpdateClass Update; diff --git a/test/native/mocks/captures.cpp b/test/native/mocks/captures.cpp index 937db47a..d14ac18d 100644 --- a/test/native/mocks/captures.cpp +++ b/test/native/mocks/captures.cpp @@ -1,11 +1,16 @@ // Global capture instances for test assertions #include #include +#include "Arduino.h" #include "WebServer.h" #include "AsyncMqttClient.h" WebServerCapture wsCapture; MqttClientCapture mqttCapture; +// Serial mock capture state (disabled by default) +std::string SerialClass::s_capture; +bool SerialClass::s_captureEnabled = false; + // Preferences static storage (shared across all instances like real NVS) std::map Preferences::s_data; diff --git a/test/native/relay_safety/CMakeLists.txt b/test/native/relay_safety/CMakeLists.txt index 6007c4fd..45aeb9a1 100644 --- a/test/native/relay_safety/CMakeLists.txt +++ b/test/native/relay_safety/CMakeLists.txt @@ -32,6 +32,7 @@ set(PRODUCTION_SOURCES ${PROJ_ROOT}/src/RuleBoost.cpp ${PROJ_ROOT}/src/RuleTimer.cpp ${PROJ_ROOT}/src/Timer.cpp + ${PROJ_ROOT}/src/LogCapture.cpp ) set(STUB_SOURCES diff --git a/test/native/relay_safety/stubs.cpp b/test/native/relay_safety/stubs.cpp index d6fbb7ed..c7360ac9 100644 --- a/test/native/relay_safety/stubs.cpp +++ b/test/native/relay_safety/stubs.cpp @@ -25,6 +25,11 @@ // Static storage backing the mock Preferences (NVS) key/value store. std::map Preferences::s_data; +// Serial mock capture state (disabled by default) — LogCapture.cpp's +// Serial mirror references these statics via Arduino.h. +std::string SerialClass::s_capture; +bool SerialClass::s_captureEnabled = false; + // ── ConfigManager: only the static settings_ member is referenced (via // getSettings(), which Timer.cpp's calculateEffectiveEndMinutes() calls). // Default member initializers in ControllerSettings give sane defaults. ── diff --git a/test/native/tests/test_logcapture.cpp b/test/native/tests/test_logcapture.cpp new file mode 100644 index 00000000..a03b1046 --- /dev/null +++ b/test/native/tests/test_logcapture.cpp @@ -0,0 +1,420 @@ +/** + * @file test_logcapture.cpp + * @brief Unit tests for LogCapture ring buffer — wrapping, seq, filters, clear, truncation. + */ + +#include +#include + +// Mock includes (picked up via -I mocks/) +#include "Arduino.h" +#include "LogCapture.hpp" + +// Test framework +extern void test_begin(const char *suite, const char *name); +extern void test_pass(const char *file, int line); +extern void test_fail(const char *file, int line, const char *msg); +extern void test_suite_end(const char *name, int passed, int failed); + +#define ASSERT_TRUE(cond) \ + do { \ + if (!(cond)) { \ + test_fail(__FILE__, __LINE__, "Expected true: " #cond); \ + return 1; \ + } \ + test_pass(__FILE__, __LINE__); \ + } while (0) + +#define ASSERT_FALSE(cond) ASSERT_TRUE(!(cond)) + +#define ASSERT_EQ(a, b) \ + do { \ + auto _a = (a); \ + auto _b = (b); \ + if (_a != _b) { \ + char _msg[256]; \ + snprintf(_msg, sizeof(_msg), "Expected %s == %s: got %lld vs %lld", #a, #b, (long long)_a, (long long)_b); \ + test_fail(__FILE__, __LINE__, _msg); \ + return 1; \ + } \ + test_pass(__FILE__, __LINE__); \ + } while (0) + +using PoolController::LogCapture; +using PoolController::LogEntry; +using PoolController::LogLevel; + +int run_logcapture_tests() { + int passed = 0, failed = 0; + int rc; + + // Keep test output clean — mirror goes to stdout via the mock Serial. + LogCapture::setLogToSerial(false); + + // ── Test: ring wraparound keeps newest entries ── + { + test_begin("LogCapture", "wraparound keeps newest entries"); + LogCapture::begin(); + const size_t N = LogCapture::LOG_BUFFER_ENTRIES + 5; + for (size_t i = 0; i < N; ++i) { + LogCapture::log(LogLevel::Info, "entry %zu", i); + } + LogEntry entries[LogCapture::LOG_BUFFER_ENTRIES]; + size_t got = LogCapture::getEntries(0, LogCapture::epoch(), 4096, LogLevel::Debug, entries, LogCapture::LOG_BUFFER_ENTRIES); + rc = (got == LogCapture::LOG_BUFFER_ENTRIES) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected %u entries, got %u", (unsigned)LogCapture::LOG_BUFFER_ENTRIES, (unsigned)got); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::wraparound", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + + test_begin("LogCapture", "wraparound oldest seq > 0"); + rc = (entries[0].seq > 0) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + test_fail(__FILE__, __LINE__, "Oldest kept entry should have seq > 0"); + failed++; + } + test_suite_end("LogCapture::wraparound_oldest", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: seq monotonicity ── + { + test_begin("LogCapture", "lastSeq equals number of logs"); + LogCapture::begin(); + const size_t N = 5; + for (size_t i = 0; i < N; ++i) { + LogCapture::log(LogLevel::Info, "log %zu", i); + } + rc = (LogCapture::lastSeq() == N) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected lastSeq %u, got %u", (unsigned)N, (unsigned)LogCapture::lastSeq()); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::lastseq", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + + test_begin("LogCapture", "entries have strictly increasing seq"); + LogEntry entries[N]; + size_t got = LogCapture::getEntries(0, LogCapture::epoch(), N, LogLevel::Debug, entries, N); + bool increasing = (got == N); + for (size_t i = 1; increasing && i < got; ++i) { + increasing = (entries[i].seq > entries[i - 1].seq); + } + rc = increasing ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + test_fail(__FILE__, __LINE__, "Entries must have strictly increasing seq"); + failed++; + } + test_suite_end("LogCapture::seq_increasing", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: since-filter returns only seq > sinceSeq ── + { + test_begin("LogCapture", "since filter returns only newer entries"); + LogCapture::begin(); + for (size_t i = 0; i < 5; ++i) { + LogCapture::log(LogLevel::Info, "log %zu", i); + } + LogEntry entries[8]; + size_t got = LogCapture::getEntries(3, LogCapture::epoch(), 8, LogLevel::Debug, entries, 8); + rc = (got == 2 && entries[0].seq == 4 && entries[1].seq == 5) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected 2 entries seq 4..5, got %u", (unsigned)got); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::since", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: stale cursor from before a reboot is clamped to 0 ── + { + test_begin("LogCapture", "stale pre-reboot cursor returns whole ring"); + LogCapture::begin(); + for (size_t i = 0; i < 5; ++i) { + LogCapture::log(LogLevel::Info, "boot %zu", i); + } + // begin() restarts the sequence at 0, so a cursor persisted across the + // reboot (higher than every new seq) must not suppress the whole ring. + LogEntry entries[8]; + size_t got = LogCapture::getEntries(1000, LogCapture::epoch(), 8, LogLevel::Debug, entries, 8); + rc = (got == 5 && entries[0].seq == 1 && entries[4].seq == 5) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected 5 entries seq 1..5, got %u", (unsigned)got); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::stale_cursor", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: level filter ── + { + test_begin("LogCapture", "level filter >= Warning"); + LogCapture::begin(); + LogCapture::log(LogLevel::Debug, "d"); + LogCapture::log(LogLevel::Info, "i"); + LogCapture::log(LogLevel::Warning, "w"); + LogCapture::log(LogLevel::Error, "e"); + LogEntry entries[8]; + size_t got = LogCapture::getEntries(0, LogCapture::epoch(), 8, LogLevel::Warning, entries, 8); + rc = (got == 2 && entries[0].level == LogLevel::Warning && entries[1].level == LogLevel::Error) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected 2 warn/error entries, got %u", (unsigned)got); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::level", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: clear hides entries but keeps seq ── + { + test_begin("LogCapture", "clear empties ring"); + LogCapture::begin(); + LogCapture::log(LogLevel::Info, "a"); + LogCapture::log(LogLevel::Info, "b"); + LogCapture::log(LogLevel::Info, "c"); + LogCapture::clear(); + LogEntry entries[8]; + size_t got = LogCapture::getEntries(0, LogCapture::epoch(), 8, LogLevel::Debug, entries, 8); + rc = (got == 0) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected 0 entries after clear, got %u", (unsigned)got); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::clear_empty", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + + test_begin("LogCapture", "clear keeps lastSeq"); + rc = (LogCapture::lastSeq() == 3) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected lastSeq 3 after clear, got %u", (unsigned)LogCapture::lastSeq()); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::clear_seq", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + + test_begin("LogCapture", "post-clear entries continue above watermark"); + LogCapture::log(LogLevel::Info, "d"); + size_t got2 = LogCapture::getEntries(0, LogCapture::epoch(), 8, LogLevel::Debug, entries, 8); + rc = (got2 == 1 && entries[0].seq == 4) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected 1 entry seq 4 after clear, got %u", (unsigned)got2); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::clear_watermark", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: truncation of oversized messages ── + { + test_begin("LogCapture", "long message is truncated safely"); + LogCapture::begin(); + char longMsg[LOG_MSG_SIZE * 2]; + memset(longMsg, 'A', sizeof(longMsg) - 1); + longMsg[sizeof(longMsg) - 1] = '\0'; + LogCapture::log(LogLevel::Info, "%s", longMsg); + LogEntry entries[2]; + size_t got = LogCapture::getEntries(0, LogCapture::epoch(), 2, LogLevel::Debug, entries, 2); + size_t len = strnlen(entries[0].message, sizeof(entries[0].message)); + rc = (got == 1 && len == LOG_MSG_SIZE - 1 && entries[0].message[len] == '\0') ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected truncated len %d, got %u", LOG_MSG_SIZE - 1, (unsigned)len); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::truncation", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: Serial mirror keeps the full message even when the ring truncates ── + { + test_begin("LogCapture", "serial mirror keeps full message when ring truncates"); + LogCapture::begin(); + LogCapture::setLogToSerial(true); + SerialClass::enableCapture(); + + // Message longer than a ring slot: the ring copy must be truncated to + // LOG_MSG_SIZE-1, but the Serial mirror must receive the full text. + char longMsg[LOG_MSG_SIZE * 3]; + memset(longMsg, 'C', sizeof(longMsg) - 1); + longMsg[sizeof(longMsg) - 1] = '\0'; + LogCapture::log(LogLevel::Info, "%s", longMsg); + + const std::string serialOut = SerialClass::capture(); + SerialClass::disableCapture(); + LogCapture::setLogToSerial(false); + + LogEntry entries[2]; + size_t got = LogCapture::getEntries(0, LogCapture::epoch(), 2, LogLevel::Debug, entries, 2); + size_t ringLen = strnlen(entries[0].message, sizeof(entries[0].message)); + + rc = (got == 1 && ringLen == LOG_MSG_SIZE - 1 && serialOut.size() == sizeof(longMsg) - 1 && + memcmp(serialOut.data(), longMsg, sizeof(longMsg) - 1) == 0) + ? 0 + : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[128]; + snprintf(msg, sizeof(msg), "ring len %u (want %d), serial len %zu (want %zu)", (unsigned)ringLen, LOG_MSG_SIZE - 1, + serialOut.size(), sizeof(longMsg) - 1); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::serial_full_mirror", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: logEvent prefix marker ── + { + test_begin("LogCapture", "logEvent prefixes event type"); + LogCapture::begin(); + LogCapture::logEvent("MODE_CHANGED", "to auto"); + LogEntry entries[2]; + size_t got = LogCapture::getEntries(0, LogCapture::epoch(), 2, LogLevel::Debug, entries, 2); + bool hasPrefix = (got == 1 && entries[0].message[0] == '[' && strstr(entries[0].message, "MODE_CHANGED") != nullptr); + rc = hasPrefix ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected '[MODE_CHANGED] ...', got '%s'", got == 1 ? entries[0].message : "(none)"); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::logevent", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: parseLevel ── + { + test_begin("LogCapture", "parseLevel case-insensitive"); + rc = (LogCapture::parseLevel("warning") == LogLevel::Warning && LogCapture::parseLevel("ERROR") == LogLevel::Error && + LogCapture::parseLevel("Debug") == LogLevel::Debug && LogCapture::parseLevel("bogus") == LogLevel::Info) + ? 0 + : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + test_fail(__FILE__, __LINE__, "parseLevel mapping wrong"); + failed++; + } + test_suite_end("LogCapture::parselevel", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: reboot epoch distinguishes stale cursors ── + { + test_begin("LogCapture", "boot epoch changes across reboots"); + LogCapture::begin(); + const uint32_t e1 = LogCapture::epoch(); + LogCapture::begin(); + const uint32_t e2 = LogCapture::epoch(); + rc = (e2 != e1) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + test_fail(__FILE__, __LINE__, "epoch must change after begin()"); + failed++; + } + test_suite_end("LogCapture::reboot_epoch::changes", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + { + test_begin("LogCapture", "stale pre-reboot cursor with new seq <= since returns whole ring"); + // Scenario from the review: boot 1 fills seq 1..20, client cursor since=20. + // Reboot (begin) restarts seq at 0; by the first poll the new boot already + // reached s_seq == 40. The old seq-only clamp (sinceSeq > s_seq) would NOT + // trigger (20 <= 40) and silently skip new-boot entries 1..20. The epoch + // mismatch must force a full re-read instead. + LogCapture::begin(); + const uint32_t boot1 = LogCapture::epoch(); + for (uint32_t i = 0; i < 20; ++i) { + LogCapture::log(LogLevel::Info, "boot1 %u", i); + } + LogCapture::begin(); + for (uint32_t i = 0; i < 40; ++i) { + LogCapture::log(LogLevel::Info, "boot2 %u", i); + } + LogEntry entries[64]; + size_t got = LogCapture::getEntries(20, boot1, 64, LogLevel::Debug, entries, 64); + rc = (got == 40 && entries[0].seq == 1 && entries[39].seq == 40) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected 40 entries seq 1..40, got %u", (unsigned)got); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::reboot_epoch::stale_cursor", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + { + test_begin("LogCapture", "current-boot cursor still filters by since"); + // Same ring as above, but the client now echoes the CURRENT epoch: the + // cursor since=20 is trusted and only entries 21..40 are returned. + LogCapture::begin(); + for (uint32_t i = 0; i < 40; ++i) { + LogCapture::log(LogLevel::Info, "boot %u", i); + } + LogEntry entries[64]; + size_t got = LogCapture::getEntries(20, LogCapture::epoch(), 64, LogLevel::Debug, entries, 64); + rc = (got == 20 && entries[0].seq == 21 && entries[19].seq == 40) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[64]; + snprintf(msg, sizeof(msg), "Expected 20 entries seq 21..40, got %u", (unsigned)got); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("LogCapture::reboot_epoch::current_cursor", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + return passed + failed; +} diff --git a/test/native/tests/test_main.cpp b/test/native/tests/test_main.cpp index dfc0725f..83580bc1 100644 --- a/test/native/tests/test_main.cpp +++ b/test/native/tests/test_main.cpp @@ -106,6 +106,8 @@ extern int run_mqttpublisher_tests(); extern int run_security_tests(); extern int run_state_manager_tests(); extern int run_timer_tests(); +extern int run_logcapture_tests(); +extern int run_webportal_logs_tests(); int main() { printf("\n══════════════════════════════════════════════════\n"); @@ -120,6 +122,8 @@ int main() { total += run_security_tests(); total += run_state_manager_tests(); total += run_timer_tests(); + total += run_logcapture_tests(); + total += run_webportal_logs_tests(); printf("\n══════════════════════════════════════════════════\n"); printf(" Results: %d suites passed, %d suites failed\n", g_testsPassed, g_testsFailed); diff --git a/test/native/tests/test_mqttpublisher.cpp b/test/native/tests/test_mqttpublisher.cpp index 1810bb84..c0a0b636 100644 --- a/test/native/tests/test_mqttpublisher.cpp +++ b/test/native/tests/test_mqttpublisher.cpp @@ -11,6 +11,7 @@ #include "AsyncMqttClient.h" #include "MqttPublisher.hpp" +#include "LogCapture.hpp" #include "ConfigManager.hpp" #include "NetworkManager.hpp" #include "DallasTemperatureNode.hpp" @@ -505,5 +506,424 @@ int run_mqttpublisher_tests() { test_suite_end("MqttPublisher::preset_state_none", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); } + // ── Test: Event-entity discovery payload ── + // Task 5: publishEventDiscovery("logs", ...) must announce the HA MQTT + // "event" component with the curated event_types whitelist. + { + test_begin("MqttPublisher::publishEventDiscovery", "event entity with platform and event_types"); + + mqttCapture.clear(); + NetworkManager::setMqttConnected(true); + MqttPublisher::begin(); + MqttPublisher::publishDiscovery(); + + const MqttMessage *cfg = mqttCapture.findPublished("homeassistant/event/pool-controller/logs/config"); + int missing = 0; + if (cfg == nullptr) { + test_fail(__FILE__, __LINE__, "Missing event discovery config topic"); + missing++; + } else { + JsonDocument doc; + DeserializationError err = deserializeJson(doc, cfg->payload); + if (err) { + char buf[128]; + snprintf(buf, sizeof(buf), "Event config is not valid JSON: %s", err.c_str()); + test_fail(__FILE__, __LINE__, buf); + missing++; + } else { + // platform must be "event" (HA event component) + if (strcmp(doc["platform"] | "", "event") != 0) { + test_fail(__FILE__, __LINE__, "event config platform != 'event'"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + // state_topic must point at the event state topic + if (strcmp(doc["state_topic"] | "", "homeassistant/event/pool-controller/logs/state") != 0) { + test_fail(__FILE__, __LINE__, "event config state_topic mismatch"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + if (!doc.containsKey("availability_topic")) { + test_fail(__FILE__, __LINE__, "event config missing availability_topic"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + // event_types must contain the curated whitelist (LOG_WARN + MODE_CHANGED probe) + JsonArray types = doc["event_types"]; + bool hasWarn = false; + bool hasMode = false; + for (JsonVariant t : types) { + if (strcmp(t | "", "LOG_WARN") == 0) + hasWarn = true; + if (strcmp(t | "", "MODE_CHANGED") == 0) + hasMode = true; + } + if (!hasWarn) { + test_fail(__FILE__, __LINE__, "event_types missing LOG_WARN"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + if (!hasMode) { + test_fail(__FILE__, __LINE__, "event_types missing MODE_CHANGED"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + if (!cfg->retained) { + test_fail(__FILE__, __LINE__, "event config must be retained"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + } + } + + rc = (missing == 0) ? 0 : 1; + if (rc == 0) + passed++; + else + failed++; + test_suite_end("MqttPublisher::publishEventDiscovery", missing == 0 ? 1 : 0, missing); + } + + // ── Test: Export pump exports WARN entries as LOG_WARN events ── + // Task 5: WARN/ERROR entries without marker → {"event_type":"LOG_WARN",...} + // on the event state topic, plus a JSON-line on the raw pool-controller/log topic. + { + test_begin("MqttPublisher::publishStates", "exports WARN entry as LOG_WARN event"); + + mqttCapture.clear(); + NetworkManager::setMqttConnected(true); + LogCapture::begin(); + MqttPublisher::begin(); + + LogCapture::log(LogLevel::Warning, "solar pump overheated"); + MqttPublisher::publishStates(); + + int missing = 0; + const MqttMessage *ev = mqttCapture.findPublished("homeassistant/event/pool-controller/logs/state"); + if (ev == nullptr) { + test_fail(__FILE__, __LINE__, "No event state published for WARN entry"); + missing++; + } else { + JsonDocument doc; + DeserializationError err = deserializeJson(doc, ev->payload); + if (err) { + test_fail(__FILE__, __LINE__, "Event state is not valid JSON"); + missing++; + } else { + if (strcmp(doc["event_type"] | "", "LOG_WARN") != 0) { + test_fail(__FILE__, __LINE__, "event_type != LOG_WARN for WARN entry"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + const char *msg = doc["message"]; + if (msg == nullptr || strstr(msg, "overheated") == nullptr) { + test_fail(__FILE__, __LINE__, "event message missing WARN body"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + } + } + + // Raw topic for external tools: {"seq":…,"t":…,"level":…,"msg":…} + const MqttMessage *raw = mqttCapture.findPublished("pool-controller/log"); + if (raw == nullptr) { + test_fail(__FILE__, __LINE__, "Raw pool-controller/log topic not published"); + missing++; + } else { + JsonDocument doc; + DeserializationError err = deserializeJson(doc, raw->payload); + if (err) { + test_fail(__FILE__, __LINE__, "Raw log line is not valid JSON"); + missing++; + } else { + if ((doc["seq"] | 0u) == 0u) { + test_fail(__FILE__, __LINE__, "Raw log line missing seq"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + if (strcmp(doc["level"] | "", "warning") != 0) { + test_fail(__FILE__, __LINE__, "Raw log line level != warning"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + const char *msg = doc["msg"]; + if (msg == nullptr || strstr(msg, "overheated") == nullptr) { + test_fail(__FILE__, __LINE__, "Raw log line missing message"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + } + } + + rc = (missing == 0) ? 0 : 1; + if (rc == 0) + passed++; + else + failed++; + test_suite_end("MqttPublisher::export_warn_event", missing == 0 ? 1 : 0, missing); + } + + // ── Test: WARN/ERROR emitted BEFORE MqttPublisher::begin() is preserved ── + // The export watermark starts at seq 0 (beginning of the current boot), so + // boot-loop errors, ConfigManager failures, and WPS/SSID warnings logged + // before the publisher starts are still exported — not permanently dropped. + { + test_begin("MqttPublisher::publishStates", "pre-publisher WARN is exported"); + + mqttCapture.clear(); + NetworkManager::setMqttConnected(true); + LogCapture::begin(); + LogCapture::log(LogLevel::Warning, "no SSID configured"); + MqttPublisher::begin(); + + MqttPublisher::publishStates(); + + const MqttMessage *ev = mqttCapture.findPublished("homeassistant/event/pool-controller/logs/state"); + const MqttMessage *raw = mqttCapture.findPublished("pool-controller/log"); + + rc = (ev != nullptr && raw != nullptr) ? 0 : 1; + if (rc == 0) { + JsonDocument doc; + DeserializationError err = deserializeJson(doc, ev->payload); + if (err || strcmp(doc["event_type"] | "", "LOG_WARN") != 0) { + test_fail(__FILE__, __LINE__, "pre-publisher WARN not exported as LOG_WARN"); + rc = 1; + } else + test_pass(__FILE__, __LINE__); // NOLINT + } else { + test_fail(__FILE__, __LINE__, "pre-publisher WARN must be exported via MQTT"); + } + if (rc == 0) + passed++; + else + failed++; + test_suite_end("MqttPublisher::export_pre_publisher_warn", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: Info entries are NOT exported ── + // Task 5 volume control: only WARN/ERROR and curated events cross MQTT. + { + test_begin("MqttPublisher::publishStates", "Info entries are not exported"); + + mqttCapture.clear(); + NetworkManager::setMqttConnected(true); + LogCapture::begin(); + MqttPublisher::begin(); + + LogCapture::log(LogLevel::Info, "normal heartbeat"); + MqttPublisher::publishStates(); + + const MqttMessage *ev = mqttCapture.findPublished("homeassistant/event/pool-controller/logs/state"); + const MqttMessage *raw = mqttCapture.findPublished("pool-controller/log"); + + rc = (ev == nullptr && raw == nullptr) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + test_fail(__FILE__, __LINE__, "Info entry must not be exported via MQTT"); + failed++; + } + test_suite_end("MqttPublisher::export_no_info", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: Export pump dedup — second call without new entries publishes nothing ── + { + test_begin("MqttPublisher::publishStates", "no duplicate export on second call"); + + mqttCapture.clear(); + NetworkManager::setMqttConnected(true); + LogCapture::begin(); + MqttPublisher::begin(); + + LogCapture::log(LogLevel::Error, "boom"); + MqttPublisher::publishStates(); + + int firstCount = 0; + for (const auto &m : mqttCapture.published) { + if (m.topic == "homeassistant/event/pool-controller/logs/state") + firstCount++; + } + + mqttCapture.clear(); + MqttPublisher::publishStates(); + const MqttMessage *ev2 = mqttCapture.findPublished("homeassistant/event/pool-controller/logs/state"); + const MqttMessage *raw2 = mqttCapture.findPublished("pool-controller/log"); + + rc = (firstCount == 1 && ev2 == nullptr && raw2 == nullptr) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + test_fail(__FILE__, __LINE__, "publishStates re-exported already-exported entries"); + failed++; + } + test_suite_end("MqttPublisher::export_dedup", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: failed publish keeps the watermark → entry is retried next pass ── + // Task 5: NetworkManager::publish() can return false (MQTT queue refused / + // disconnected mid-burst). The watermark must NOT advance past such an + // entry, otherwise the event is dropped permanently. + { + test_begin("MqttPublisher::publishStates", "failed publish does not advance watermark"); + + mqttCapture.clear(); + NetworkManager::setMqttConnected(true); + NetworkManager::setPublishOk(false); // simulate AsyncMqttClient refusing to enqueue + LogCapture::begin(); + MqttPublisher::begin(); + + LogCapture::log(LogLevel::Error, "queued when broker back"); + MqttPublisher::publishStates(); + + // No event may be marked exported while publish fails. + const MqttMessage *ev = mqttCapture.findPublished("homeassistant/event/pool-controller/logs/state"); + bool clean = (ev == nullptr); + + // Broker accepts again → the same entry must now be exported (retry). + NetworkManager::setPublishOk(true); + mqttCapture.clear(); + MqttPublisher::publishStates(); + const MqttMessage *ev2 = mqttCapture.findPublished("homeassistant/event/pool-controller/logs/state"); + const MqttMessage *raw2 = mqttCapture.findPublished("pool-controller/log"); + + rc = (clean && ev2 != nullptr && raw2 != nullptr) ? 0 : 1; + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + char msg[160]; + snprintf(msg, sizeof(msg), "clean=%d ev2=%s raw2=%s (no retry)", clean ? 1 : 0, + ev2 != nullptr ? ev2->payload.c_str() : "NULL", raw2 != nullptr ? raw2->payload.c_str() : "NULL"); + test_fail(__FILE__, __LINE__, msg); + failed++; + } + test_suite_end("MqttPublisher::export_retry_publish_fail", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: reentrant export (AsyncTCP callback path) is skipped by the guard ── + // handleMqttMessage → publishStates() can run on the AsyncTCP task while the + // loop task is mid-exportLogEvents(). Both share the static snapshot buffer + // and the watermark; the guard must make the nested export a no-op so the + // event is published exactly once and the watermark is not regressed. + { + test_begin("MqttPublisher::publishStates", "reentrant export during publish is skipped"); + + mqttCapture.clear(); + NetworkManager::setMqttConnected(true); + LogCapture::begin(); + MqttPublisher::begin(); + + LogCapture::log(LogLevel::Warning, "reentrant guard probe"); + // Fire one nested publishStates() from inside the export's event-state + // publish — simulates the AsyncTCP callback task preempting the loop task. + bool hookFired = false; + NetworkManager::setPublishHook("homeassistant/event/pool-controller/logs/state", [&hookFired]() { + hookFired = true; + MqttPublisher::publishStates(); + }); + MqttPublisher::publishStates(); + + int missing = 0; + if (!hookFired) { + test_fail(__FILE__, __LINE__, "publish hook did not fire mid-export"); + missing++; + } + + // The WARN event must be exported exactly once (nested call deferred). + size_t evCount = 0, rawCount = 0; + for (const auto &m : mqttCapture.published) { + if (m.topic == "homeassistant/event/pool-controller/logs/state") + evCount++; + if (m.topic == "pool-controller/log") + rawCount++; + } + if (evCount != 1) { + test_fail(__FILE__, __LINE__, "event state published != 1 times (nested export interleaved)"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + if (rawCount != 1) { + test_fail(__FILE__, __LINE__, "raw log topic published != 1 times (nested export interleaved)"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + + // Watermark must not have regressed: a follow-up pass publishes nothing new. + NetworkManager::clearPublishHook(); + MqttPublisher::publishStates(); + size_t evAfter = 0; + for (const auto &m : mqttCapture.published) + if (m.topic == "homeassistant/event/pool-controller/logs/state") + evAfter++; + if (evAfter != 1) { + test_fail(__FILE__, __LINE__, "watermark regressed — follow-up pass re-exported event"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + + rc = (missing == 0) ? 0 : 1; + if (rc == 0) + passed++; + else + failed++; + test_suite_end("MqttPublisher::export_reentrancy_guard", missing == 0 ? 1 : 0, missing); + } + + // ── Test: logEvent marker becomes event_type on the event state topic ── + // Task 5: LogCapture::logEvent("[MODE_CHANGED] ...") → event_type=MODE_CHANGED. + // Info-level events are NOT mirrored to the raw topic (raw is WARN/ERROR only). + { + test_begin("MqttPublisher::publishStates", "logEvent marker exported as event_type"); + + mqttCapture.clear(); + NetworkManager::setMqttConnected(true); + LogCapture::begin(); + MqttPublisher::begin(); + + LogCapture::logEvent("MODE_CHANGED", "switched to auto"); + MqttPublisher::publishStates(); + + int missing = 0; + const MqttMessage *ev = mqttCapture.findPublished("homeassistant/event/pool-controller/logs/state"); + if (ev == nullptr) { + test_fail(__FILE__, __LINE__, "No event state published for logEvent"); + missing++; + } else { + JsonDocument doc; + DeserializationError err = deserializeJson(doc, ev->payload); + if (err) { + test_fail(__FILE__, __LINE__, "Event state is not valid JSON"); + missing++; + } else { + if (strcmp(doc["event_type"] | "", "MODE_CHANGED") != 0) { + test_fail(__FILE__, __LINE__, "event_type != MODE_CHANGED"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + if (strcmp(doc["message"] | "", "switched to auto") != 0) { + test_fail(__FILE__, __LINE__, "event message mismatch"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + } + } + + const MqttMessage *raw = mqttCapture.findPublished("pool-controller/log"); + if (raw != nullptr) { + test_fail(__FILE__, __LINE__, "Info-level event must not be mirrored to raw topic"); + missing++; + } else + test_pass(__FILE__, __LINE__); // NOLINT + + rc = (missing == 0) ? 0 : 1; + if (rc == 0) + passed++; + else + failed++; + test_suite_end("MqttPublisher::export_event_marker", missing == 0 ? 1 : 0, missing); + } + return passed + failed; } diff --git a/test/native/tests/test_webportal_logs.cpp b/test/native/tests/test_webportal_logs.cpp new file mode 100644 index 00000000..6c65b70d --- /dev/null +++ b/test/native/tests/test_webportal_logs.cpp @@ -0,0 +1,226 @@ +/** + * @file test_webportal_logs.cpp + * @brief Tests for WebPortal::buildLogsJson — the /api/logs JSON builder hook. + * + * buildLogsJson is a public static test hook (pattern: "Rate limiting + * helpers (public for testing)") that serializes LogCapture entries into + * the JSON payload served by apiGetLogs. These tests verify the payload + * shape and the since/count/level filters without needing the WebServer. + */ + +#include +#include +#include +#include "Arduino.h" +#include "ArduinoJson.h" + +// Mock WebPortal dependencies +#include "WebServer.h" +#include "DNSServer.h" +#include "WebPortal.hpp" +#include "LogCapture.hpp" + +using namespace PoolController; // NOLINT(build/namespaces) + +// Global test helpers +extern WebServerCapture wsCapture; + +extern void test_begin(const char *suite, const char *name); +extern void test_pass(const char *file, int line); +extern void test_fail(const char *file, int line, const char *msg); +extern void test_suite_end(const char *name, int passed, int failed); + +#define ASSERT_TRUE(cond) \ + do { \ + if (!(cond)) { \ + test_fail(__FILE__, __LINE__, "Expected true: " #cond); \ + return 1; \ + } \ + test_pass(__FILE__, __LINE__); \ + } while (0) + +#define ASSERT_EQ(a, b) \ + do { \ + auto _a = (a); \ + auto _b = (b); \ + if (_a != _b) { \ + char _msg[256]; \ + snprintf(_msg, sizeof(_msg), "Expected %s == %s: got %lld vs %lld", #a, #b, (long long)_a, (long long)_b); \ + test_fail(__FILE__, __LINE__, _msg); \ + return 1; \ + } \ + test_pass(__FILE__, __LINE__); \ + } while (0) + +namespace { + +// Serializes via the hook and parses the result. Returns true on success. +bool buildAndParse(uint32_t since, uint32_t epoch, size_t count, LogLevel minLevel, JsonDocument &doc, size_t &payloadLen) { + char buf[8192]; + payloadLen = WebPortal::buildLogsJson(since, epoch, count, minLevel, buf, sizeof(buf)); + if (payloadLen == 0) { + return false; + } + DeserializationError err = deserializeJson(doc, buf); + return err == DeserializationError::Ok; +} + +} // namespace + +int run_webportal_logs_tests() { + int passed = 0, failed = 0; + int rc; + + // Keep test output clean — no Serial mirror. + LogCapture::setLogToSerial(false); + + // ── Test: full dump — ok, next, entries with all fields ── + { + test_begin("WebPortal::buildLogsJson", "full dump has ok, next, entries"); + LogCapture::begin(); + LogCapture::log(LogLevel::Info, "boot msg %d", 1); + LogCapture::log(LogLevel::Info, "boot msg %d", 2); + + JsonDocument doc; + size_t len = 0; + rc = buildAndParse(0, LogCapture::epoch(), 200, LogLevel::Debug, doc, len) ? 0 : 1; + if (rc == 0) { + // next = highest consumed seq (2), NOT lastSeq()+1 (3): the client sends + // next back as the exclusive `since` cursor, so seq 3 must not be skipped. + rc = (doc["ok"] == true && doc["next"] == 2 && doc["boot"] == LogCapture::epoch()) ? 0 : 1; + } + if (rc == 0) { + JsonArray arr = doc["entries"].as(); + rc = (arr.size() == 2) ? 0 : 1; + } + if (rc == 0) { + JsonArray arr = doc["entries"].as(); + rc = (arr[0]["seq"] == 1 && arr[0]["level"] == "info" && strcmp(arr[0]["msg"], "boot msg 1") == 0 && + arr[0]["t"].is()) + ? 0 + : 1; + } + if (rc == 0) { + JsonArray arr = doc["entries"].as(); + rc = (arr[1]["seq"] == 2 && strcmp(arr[1]["msg"], "boot msg 2") == 0) ? 0 : 1; + } + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + test_fail(__FILE__, __LINE__, "buildLogsJson full dump malformed"); + failed++; + } + test_suite_end("WebPortal::buildLogsJson::full", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: since filter returns only newer entries ── + { + test_begin("WebPortal::buildLogsJson", "since filter returns newer entries"); + LogCapture::begin(); + for (int i = 1; i <= 5; ++i) { + LogCapture::log(LogLevel::Info, "msg %d", i); + } + + JsonDocument doc; + size_t len = 0; + rc = buildAndParse(3, LogCapture::epoch(), 200, LogLevel::Debug, doc, len) ? 0 : 1; + if (rc == 0) { + JsonArray arr = doc["entries"].as(); + rc = (arr.size() == 2 && arr[0]["seq"] == 4 && arr[1]["seq"] == 5) ? 0 : 1; + } + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + test_fail(__FILE__, __LINE__, "since=3 should yield seq 4 and 5"); + failed++; + } + test_suite_end("WebPortal::buildLogsJson::since", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: count cap limits entry count ── + { + test_begin("WebPortal::buildLogsJson", "count cap limits entries"); + LogCapture::begin(); + for (int i = 1; i <= 5; ++i) { + LogCapture::log(LogLevel::Info, "msg %d", i); + } + + JsonDocument doc; + size_t len = 0; + rc = buildAndParse(0, LogCapture::epoch(), 2, LogLevel::Debug, doc, len) ? 0 : 1; + if (rc == 0) { + JsonArray arr = doc["entries"].as(); + rc = (arr.size() == 2 && arr[0]["seq"] == 1 && arr[1]["seq"] == 2) ? 0 : 1; + } + if (rc == 0) { + // Truncated response must NOT jump to lastSeq+1 (6): next = last consumed + // seq (2), so the client's next poll with since=2 fetches 3..5. + rc = (doc["next"] == 2) ? 0 : 1; + } + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + test_fail(__FILE__, __LINE__, "count=2 should yield seq 1 and 2"); + failed++; + } + test_suite_end("WebPortal::buildLogsJson::count", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: level filter excludes lower severities ── + { + test_begin("WebPortal::buildLogsJson", "level filter excludes lower severities"); + LogCapture::begin(); + LogCapture::log(LogLevel::Debug, "debug line"); + LogCapture::log(LogLevel::Info, "info line"); + LogCapture::log(LogLevel::Warning, "warn line"); + LogCapture::log(LogLevel::Error, "error line"); + + JsonDocument doc; + size_t len = 0; + rc = buildAndParse(0, LogCapture::epoch(), 200, LogLevel::Warning, doc, len) ? 0 : 1; + if (rc == 0) { + JsonArray arr = doc["entries"].as(); + rc = (arr.size() == 2 && arr[0]["level"] == "warning" && arr[1]["level"] == "error") ? 0 : 1; + } + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + test_fail(__FILE__, __LINE__, "level=warning should yield warning and error only"); + failed++; + } + test_suite_end("WebPortal::buildLogsJson::level", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + // ── Test: empty result yields entries: [] ── + { + test_begin("WebPortal::buildLogsJson", "empty result yields empty entries"); + LogCapture::begin(); + LogCapture::log(LogLevel::Info, "a"); + LogCapture::log(LogLevel::Info, "b"); + LogCapture::clear(); + + JsonDocument doc; + size_t len = 0; + rc = buildAndParse(0, LogCapture::epoch(), 200, LogLevel::Debug, doc, len) ? 0 : 1; + if (rc == 0) { + JsonArray arr = doc["entries"].as(); + // No entries consumed → cursor stays at the requested since (0), so the + // client does not skip anything when new entries arrive. + rc = (arr.size() == 0 && doc["ok"] == true && doc["next"] == 0 && doc["boot"] == LogCapture::epoch()) ? 0 : 1; + } + if (rc == 0) { + test_pass(__FILE__, __LINE__); + passed++; + } else { + test_fail(__FILE__, __LINE__, "after clear entries should be empty, next stays at since"); + failed++; + } + test_suite_end("WebPortal::buildLogsJson::empty", rc == 0 ? 1 : 0, rc != 0 ? 1 : 0); + } + + return passed + failed; +}