From f49f727ae2a154b09dc3d89996eab6c5df5589b2 Mon Sep 17 00:00:00 2001 From: David Gwilliam Date: Thu, 12 Feb 2026 05:46:10 -0800 Subject: [PATCH] snapshot --- sketches/doorbell/doorbell.ino | 244 ++++++++++++++++++++++++--------- 1 file changed, 177 insertions(+), 67 deletions(-) diff --git a/sketches/doorbell/doorbell.ino b/sketches/doorbell/doorbell.ino index 3dcf228..727f16b 100644 --- a/sketches/doorbell/doorbell.ino +++ b/sketches/doorbell/doorbell.ino @@ -39,6 +39,9 @@ Arduino_DataBus *bus = new Arduino_HWSPI(15, 14, 7, 6, -1); Arduino_GFX *gfx = new Arduino_ST7789(bus, 21, 1, true, 172, 320, 34, 0, 34, 0); enum State { STATE_SILENT, STATE_ALERT }; +enum LogLevel { LOG_DEBUG, LOG_INFO, LOG_WARN, LOG_ERROR, LOG_FATAL }; + +const LogLevel CURRENT_LOG_LEVEL = LOG_DEBUG; State currentState = STATE_SILENT; State lastPublishedState = STATE_SILENT; @@ -48,6 +51,7 @@ unsigned long lastSilencePoll = 0; unsigned long nextPollTime = 0; unsigned long blinkStartTime = 0; bool blinkPhase = false; +bool backlightState = false; // Explicit tracking String lastCommandId = ""; String lastSilenceId = ""; @@ -56,24 +60,81 @@ String alertMessage = ""; unsigned long long epochOffsetMs = 0; +// ============== PROFESSIONAL LOGGING ============== + +void logMessage(LogLevel level, const char* component, const char* message) { + if (level < CURRENT_LOG_LEVEL) return; + + const char* levelStr; + switch (level) { + case LOG_DEBUG: levelStr = "DEBUG"; break; + case LOG_INFO: levelStr = "INFO "; break; + case LOG_WARN: levelStr = "WARN "; break; + case LOG_ERROR: levelStr = "ERROR"; break; + case LOG_FATAL: levelStr = "FATAL"; break; + default: levelStr = "?????"; break; + } + + char timestamp[32]; + formatIsoTimestamp(timestamp, sizeof(timestamp)); + + Serial.print(timestamp); + Serial.print(" ["); + Serial.print(levelStr); + Serial.print("] "); + Serial.print(component); + Serial.print(": "); + Serial.println(message); +} + +void logValue(LogLevel level, const char* component, const char* name, long long value) { + if (level < CURRENT_LOG_LEVEL) return; + char buf[128]; + snprintf(buf, sizeof(buf), "%s=%lld", name, value); + logMessage(level, component, buf); +} + +void logString(LogLevel level, const char* component, const char* name, const String& value) { + if (level < CURRENT_LOG_LEVEL) return; + char buf[256]; + snprintf(buf, sizeof(buf), "%s=[%s]", name, value.c_str()); + logMessage(level, component, buf); +} + +void formatIsoTimestamp(char* buf, size_t len) { + unsigned long long epochMs = getEpochMs(); + time_t seconds = epochMs / 1000; + unsigned int ms = epochMs % 1000; + + struct tm* tm = gmtime(&seconds); + snprintf(buf, len, "%04d-%02d-%02dT%02d:%02d:%02d.%03dZ", + tm->tm_year + 1900, tm->tm_mon + 1, tm->tm_mday, + tm->tm_hour, tm->tm_min, tm->tm_sec, ms); +} + +// ============== SETUP ============== + void setup() { Serial.begin(115200); delay(3000); - Serial.println("\n=== KLUBHAUS DOORBELL v3.6.1 ==="); - Serial.println("Fix: restored missing loop() function"); + + logMessage(LOG_INFO, "MAIN", "=== KLUBHAUS DOORBELL v3.7 ==="); + logMessage(LOG_INFO, "MAIN", "Features: structured logging, epoch timestamps, backlight fix"); pinMode(BACKLIGHT_PIN, OUTPUT); - digitalWrite(BACKLIGHT_PIN, LOW); + setBacklight(false); // Start OFF pinMode(BUTTON_PIN, INPUT_PULLUP); gfx->begin(); - digitalWrite(BACKLIGHT_PIN, HIGH); + setBacklight(true); // ON for test testDisplay(); delay(300); transitionTo(STATE_SILENT); + logMessage(LOG_INFO, "WIFI", "Connecting..."); WiFi.begin(ssid, password); + int timeout = 0; while (WiFi.status() != WL_CONNECTED && timeout < 40) { delay(500); @@ -82,51 +143,65 @@ void setup() { } if (WiFi.status() != WL_CONNECTED) { - Serial.println("\nWiFi FAILED"); + Serial.println(); + logMessage(LOG_FATAL, "WIFI", "Connection failed"); showFatalError("OFFLINE"); - } else { - Serial.println("\nWiFi OK: " + WiFi.localIP().toString()); - initEpochTime(); - publishStatus(); + return; } - Serial.println("=== READY ==="); + Serial.println(); + char ipBuf[64]; + snprintf(ipBuf, sizeof(ipBuf), "Connected: %s", WiFi.localIP().toString().c_str()); + logMessage(LOG_INFO, "WIFI", ipBuf); + + initEpochTime(); + publishStatus(); + + logMessage(LOG_INFO, "MAIN", "=== READY ==="); +} + +// ============== BACKLIGHT CONTROL ============== + +void setBacklight(bool on) { + digitalWrite(BACKLIGHT_PIN, on ? HIGH : LOW); + if (backlightState != on) { + backlightState = on; + logValue(LOG_DEBUG, "BACKLIGHT", "state", on ? 1 : 0); + } } // ============== EPOCH TIME ============== void initEpochTime() { + logMessage(LOG_INFO, "TIME", "Initializing NTP..."); configTime(0, 0, "pool.ntp.org", "time.nist.gov"); - Serial.print("Syncing NTP..."); time_t now = 0; int retries = 0; while (now < 1000000000 && retries < 30) { delay(500); now = time(nullptr); - Serial.print("."); retries++; } if (now > 1000000000) { epochOffsetMs = (now * 1000ULL) - millis(); - Serial.println(" OK"); - Serial.print("Epoch offset: "); - Serial.println((unsigned long)epochOffsetMs); + logValue(LOG_INFO, "TIME", "epochOffsetMs", (long long)epochOffsetMs); + char ts[32]; + formatIsoTimestamp(ts, sizeof(ts)); + logString(LOG_INFO, "TIME", "syncedAt", ts); } else { - Serial.println(" FAILED — using boot-relative time"); + logMessage(LOG_WARN, "TIME", "NTP sync failed — using boot-relative timestamps"); epochOffsetMs = 0; } } unsigned long long getEpochMs() { - if (epochOffsetMs == 0) { - return millis(); - } + if (epochOffsetMs == 0) return millis(); return epochOffsetMs + millis(); } -// ============== MAIN LOOP (RESTORED) ============== +// ============== MAIN LOOP ============== void loop() { unsigned long now = millis(); @@ -157,7 +232,7 @@ void loop() { } updateBlink(now); if (now - blinkStartTime >= BLINK_DURATION) { - Serial.println("ALERT TIMEOUT"); + logMessage(LOG_INFO, "STATE", "Alert timeout — transitioning to SILENT"); transitionTo(STATE_SILENT); } break; @@ -170,10 +245,12 @@ void loop() { void publishStatus() { if (WiFi.status() != WL_CONNECTED) { - Serial.println("Status: skip (no WiFi)"); + logMessage(LOG_WARN, "HTTP", "Status publish skipped — no WiFi"); return; } + logMessage(LOG_DEBUG, "HTTP", "POST /STATUS_klubhaus_topic"); + HTTPClient http; http.begin(STATUS_POST_URL); http.addHeader("Content-Type", "text/plain"); @@ -186,10 +263,13 @@ void publishStatus() { String payload; serializeJson(doc, payload); + unsigned long reqStart = millis(); int code = http.POST(payload); - Serial.print("Status: "); - Serial.print(payload); - Serial.println(String(" (") + code + ")"); + unsigned long duration = millis() - reqStart; + + char logBuf[512]; + snprintf(logBuf, sizeof(logBuf), "status=%d duration=%lums payload=%s", code, duration, payload.c_str()); + logString(LOG_INFO, "HTTP", "response", logBuf); http.end(); lastPublishedState = currentState; @@ -198,10 +278,7 @@ void publishStatus() { void transitionTo(State newState) { if (newState == currentState) return; - Serial.print("STATE: "); - Serial.print(currentState == STATE_SILENT ? "SILENT" : "ALERT"); - Serial.print(" -> "); - Serial.println(newState == STATE_SILENT ? "SILENT" : "ALERT"); + logMessage(LOG_INFO, "STATE", newState == STATE_SILENT ? "SILENT <- ALERT" : "ALERT <- SILENT"); currentState = newState; @@ -209,11 +286,11 @@ void transitionTo(State newState) { case STATE_SILENT: alertMessage = ""; gfx->fillScreen(COLOR_BLACK); - digitalWrite(BACKLIGHT_PIN, LOW); + setBacklight(false); // EXPLICIT OFF break; case STATE_ALERT: - digitalWrite(BACKLIGHT_PIN, HIGH); + setBacklight(true); // EXPLICIT ON blinkStartTime = millis(); blinkPhase = false; drawAlertScreen(ALERT_BG_1, ALERT_TEXT_1); @@ -226,50 +303,66 @@ void transitionTo(State newState) { // ============== TOPIC POLLING ============== void checkCommandTopic() { - Serial.println("Poll COMMAND..."); - String response = fetchNtfyJson(COMMAND_POLL_URL); - if (response.length() == 0) return; + logMessage(LOG_DEBUG, "HTTP", "GET /ALERT_klubhaus_topic/json"); + + unsigned long reqStart = millis(); + String response = fetchNtfyJson(COMMAND_POLL_URL, "COMMAND"); + unsigned long duration = millis() - reqStart; + + if (response.length() == 0) { + logMessage(LOG_DEBUG, "HTTP", "No new messages (204 or empty)"); + return; + } StaticJsonDocument<512> doc; DeserializationError error = deserializeJson(doc, response); if (error) { - Serial.print(" JSON error: "); - Serial.println(error.c_str()); + char errBuf[128]; + snprintf(errBuf, sizeof(errBuf), "JSON parse failed: %s", error.c_str()); + logMessage(LOG_ERROR, "JSON", errBuf); return; } String id = doc["id"] | ""; String message = doc["message"] | ""; + long long serverTime = doc["time"] | 0; message.trim(); + + char logBuf[512]; + snprintf(logBuf, sizeof(logBuf), "duration=%lums id=[%s] message=[%s] serverTime=%lld", + duration, id.c_str(), message.c_str(), serverTime); + logString(LOG_INFO, "COMMAND", "received", logBuf); + if (message.length() == 0) { - Serial.println(" Empty message, skip"); + logMessage(LOG_DEBUG, "COMMAND", "Empty message — discarded"); return; } if (id == lastCommandId && id.length() > 0) { - Serial.println(" Same ID, skip"); + logMessage(LOG_DEBUG, "COMMAND", "Duplicate ID — discarded"); return; } lastCommandId = id; - Serial.print(" NEW: ["); - Serial.print(message); - Serial.println("]"); - if (message.equalsIgnoreCase("SILENCE")) { - Serial.println(" -> SILENCE command"); + logMessage(LOG_INFO, "COMMAND", "SILENCE command — acknowledging"); transitionTo(STATE_SILENT); flashConfirm("SILENCE", COLOR_MINT, COLOR_BLACK); } else { - Serial.println(" -> ALERT trigger"); + logString(LOG_INFO, "COMMAND", "ALERT trigger", message); alertMessage = message; transitionTo(STATE_ALERT); } } void checkSilenceTopic() { - String response = fetchNtfyJson(SILENCE_POLL_URL); + logMessage(LOG_DEBUG, "HTTP", "GET /SILENCE_klubhaus_topic/json"); + + unsigned long reqStart = millis(); + String response = fetchNtfyJson(SILENCE_POLL_URL, "SILENCE"); + unsigned long duration = millis() - reqStart; + if (response.length() == 0) return; StaticJsonDocument<512> doc; @@ -280,23 +373,24 @@ void checkSilenceTopic() { String message = doc["message"] | ""; message.trim(); - if (message.length() == 0) return; + char logBuf[512]; + snprintf(logBuf, sizeof(logBuf), "duration=%lums id=[%s] message=[%s]", + duration, id.c_str(), message.c_str()); + logString(LOG_INFO, "SILENCE", "received", logBuf); + + if (message.length() == 0) return; if (id == lastSilenceId && id.length() > 0) return; lastSilenceId = id; - Serial.print("Silence topic: ["); - Serial.print(message); - Serial.println("]"); - if (currentState == STATE_ALERT) { - Serial.println(" -> Force silence"); + logMessage(LOG_INFO, "SILENCE", "Force silence — acknowledging"); transitionTo(STATE_SILENT); flashConfirm("SILENCED", COLOR_MINT, COLOR_BLACK); } } -String fetchNtfyJson(const char* url) { +String fetchNtfyJson(const char* url, const char* topicName) { HTTPClient http; http.begin(url); http.setTimeout(8000); @@ -304,22 +398,31 @@ String fetchNtfyJson(const char* url) { int code = http.GET(); if (code == 204) { + logMessage(LOG_DEBUG, "HTTP", "204 No Content"); http.end(); return ""; } - if (code == 429 || code == 500 || code == 502 || code == 503) { - Serial.print(" HTTP error "); - Serial.print(code); - Serial.println(" — backing off 60s"); + if (code == 429) { + logMessage(LOG_WARN, "HTTP", "429 Rate Limited — backing off 60s"); + nextPollTime = millis() + ERROR_BACKOFF; + http.end(); + return ""; + } + + if (code >= 500) { + char errBuf[64]; + snprintf(errBuf, sizeof(errBuf), "%d Server Error — backing off 60s", code); + logMessage(LOG_ERROR, "HTTP", errBuf); nextPollTime = millis() + ERROR_BACKOFF; http.end(); return ""; } if (code != 200) { - Serial.print(" HTTP error: "); - Serial.println(code); + char errBuf[64]; + snprintf(errBuf, sizeof(errBuf), "Unexpected status %d", code); + logMessage(LOG_ERROR, "HTTP", errBuf); http.end(); return ""; } @@ -327,6 +430,7 @@ String fetchNtfyJson(const char* url) { String payload = http.getString(); http.end(); + // ntfy JSON streaming: take first line only int newline = payload.indexOf('\n'); if (newline > 0) payload = payload.substring(0, newline); @@ -336,12 +440,15 @@ String fetchNtfyJson(const char* url) { // ============== VISUALS ============== void flashConfirm(const char* text, uint16_t bgColor, uint16_t textColor) { - digitalWrite(BACKLIGHT_PIN, HIGH); + logString(LOG_DEBUG, "DISPLAY", "flashConfirm", text); + setBacklight(true); gfx->fillScreen(bgColor); drawCenteredText(text, 3, textColor, bgColor, 70); delay(500); gfx->fillScreen(COLOR_BLACK); - digitalWrite(BACKLIGHT_PIN, LOW); + if (currentState == STATE_SILENT) { + setBacklight(false); + } } void drawAlertScreen(uint16_t bgColor, uint16_t textColor) { @@ -385,11 +492,12 @@ void drawCenteredText(const char* text, int textSize, uint16_t textColor, uint16 } void showFatalError(const char* text) { - digitalWrite(BACKLIGHT_PIN, HIGH); + logString(LOG_FATAL, "DISPLAY", "fatalError", text); + setBacklight(true); gfx->fillScreen(COLOR_BLACK); drawCenteredText(text, 3, COLOR_FUCHSIA, COLOR_BLACK, 70); delay(3000); - digitalWrite(BACKLIGHT_PIN, LOW); + setBacklight(false); } // ============== BUTTON ============== @@ -398,20 +506,20 @@ void handleButton() { bool pressed = (digitalRead(BUTTON_PIN) == LOW); if (pressed && !lastButtonState) { - Serial.println("BUTTON PRESSED"); - digitalWrite(BACKLIGHT_PIN, HIGH); + logMessage(LOG_INFO, "BUTTON", "PRESSED"); + setBacklight(true); gfx->fillScreen(COLOR_COCAINE); drawCenteredText("TEST MODE", 2, COLOR_BLACK, COLOR_COCAINE, 70); } else if (!pressed && lastButtonState) { - Serial.println("BUTTON RELEASED"); + logMessage(LOG_INFO, "BUTTON", "RELEASED"); if (currentState == STATE_ALERT) { - Serial.println(" -> Reset to SILENT"); + logMessage(LOG_INFO, "BUTTON", "Action: reset to SILENT"); transitionTo(STATE_SILENT); flashConfirm("SILENCED", COLOR_MINT, COLOR_BLACK); } else { gfx->fillScreen(COLOR_BLACK); - digitalWrite(BACKLIGHT_PIN, LOW); + setBacklight(false); } } lastButtonState = pressed; @@ -433,7 +541,9 @@ void updateBlink(unsigned long now) { // ============== TEST ============== void testDisplay() { + logMessage(LOG_DEBUG, "DISPLAY", "Running color test..."); uint16_t colors[] = {COLOR_TEAL, COLOR_FUCHSIA, COLOR_COCAINE, COLOR_MINT, COLOR_BLACK}; + const char* names[] = {"TEAL", "FUCHSIA", "COCAINE", "MINT", "BLACK"}; for (int i = 0; i < 5; i++) { gfx->fillScreen(colors[i]); delay(100);