eddy/Project_SylDa
Watch
1
1
Fork
You've already forked Project_SylDa
 0
Code Issues 2 Pull requests Projects Releases 3 Packages Wiki Activity Actions

Replace Serial.* logging with ESP_LOG* macros (issue #8)
All checks were successful
CI / firmware (pull_request) Successful in 1m21s
Details
CI / android (pull_request) Successful in 7s
Details

Browse source 
- Convert all Serial.println/printf debug logging to ESP_LOGE/W/I/D
- Add TAG-based log identification (server/client)
- Lower CORE_DEBUG_LEVEL from 5 to 3 for production
- Keep Serial.printf for USB serial protocol commands (KEY?, VERSION?, etc.)
This commit is contained in:
eddy 2026-08-02 20:51:21 +02:00
commit 32489fbabb
3 changed files with 85 additions and 107 deletions
Download patch file Download diff file Expand all files Collapse all files

127
src/main.cpp
View file

@ -9,8 +9,11 @@
#include <esp_ota_ops.h>
#include <esp_partition.h>
#include <nvs_flash.h>
#include <esp_log.h>
#include "version.h"
static const char *TAG = "server";
#define RELAY1_PIN 1
#define RELAY2_PIN 2
#define TOUCH1_PIN 8
@ -104,12 +107,12 @@ class MyServerCallbacks : public NimBLEServerCallbacks {
bleRelay2[slot] = false;
lastSeq[slot] = 0;
connectedCount++;
Serial.printf("BLE: device connected (conn=%d, slot=%d, clients=%d/%d, mac=%s)\n",
handle, slot, connectedCount, MAX_CLIENTS,
connInfo.getAddress().toString().c_str());
ESP_LOGI(TAG, "BLE: connected (slot=%d, clients=%d/%d, mac=%s)",
slot, connectedCount, MAX_CLIENTS,
connInfo.getAddress().toString().c_str());
} else {
Serial.printf("BLE: device connected but no free slot (conn=%d, clients=%d/%d)\n",
handle, connectedCount, MAX_CLIENTS);
ESP_LOGW(TAG, "BLE: connected but no free slot (clients=%d/%d)",
connectedCount, MAX_CLIENTS);
}
pServer->startAdvertising();
}
@ -123,9 +126,9 @@ class MyServerCallbacks : public NimBLEServerCallbacks {
lastSeq[i] = 0;
connHandles[i] = 0xFFFF;
connectedCount--;
Serial.printf("BLE: device disconnected (conn=%d, slot=%d, clients=%d/%d, mac=%s)\n",
handle, i, connectedCount, MAX_CLIENTS,
connInfo.getAddress().toString().c_str());
ESP_LOGI(TAG, "BLE: disconnected (slot=%d, clients=%d/%d, mac=%s)",
i, connectedCount, MAX_CLIENTS,
connInfo.getAddress().toString().c_str());
break;
}
}
@ -134,7 +137,7 @@ class MyServerCallbacks : public NimBLEServerCallbacks {
static bool verifyHmac(const uint8_t *packet, int idx) {
if (idx < 0 || idx >= MAX_CLIENTS || !connActive[idx]) {
Serial.printf("BLE: HMAC verify called for invalid idx=%d\n", idx);
ESP_LOGW(TAG, "HMAC verify for invalid idx=%d", idx);
return false;
}
@ -145,7 +148,7 @@ static bool verifyHmac(const uint8_t *packet, int idx) {
(uint32_t)packet[4];
if (seq <= lastSeq[idx]) {
Serial.printf("BLE: replay rejected (seq=%lu, last=%lu, slot=%d)\n", seq, lastSeq[idx], idx);
ESP_LOGW(TAG, "Replay rejected (seq=%lu, last=%lu, slot=%d)", seq, lastSeq[idx], idx);
return false;
}
@ -161,7 +164,7 @@ static bool verifyHmac(const uint8_t *packet, int idx) {
mbedtls_md_hmac(mdInfo, hmacKey, HMAC_KEY_LEN, hmacData, 5, computed);
if (memcmp(computed, packet + 5, 32) != 0) {
Serial.println("BLE: HMAC mismatch");
ESP_LOGE(TAG, "HMAC mismatch");
return false;
}
@ -209,12 +212,12 @@ static void sendOtaNotify(NimBLECharacteristic *otaChar, uint8_t status, uint32_
otaChar->setValue(buf, 5);
bool ok = otaChar->notify();
if (!ok) {
Serial.printf("OTA: notify() returned false for status=0x%02X seq=%lu\n", status, seq);
ESP_LOGW(TAG, "OTA notify() failed (status=0x%02X seq=%lu)", status, seq);
}
}
static void abortOta(NimBLECharacteristic *otaChar, const char *reason) {
Serial.printf("OTA: abort — %s\n", reason);
ESP_LOGE(TAG, "OTA: abort — %s", reason);
if (otaHandle != 0) {
esp_ota_end(otaHandle);
}
@ -238,13 +241,13 @@ class OtaCharacteristicCallbacks : public NimBLECharacteristicCallbacks {
((uint32_t)data[3] << 8) | (uint32_t)data[4];
otaPartition = esp_ota_get_next_update_partition(nullptr);
if (otaPartition == nullptr) {
Serial.println("OTA: no update partition found");
ESP_LOGE(TAG, "OTA: no update partition found");
sendOtaNotify(pChar, OTA_STATUS_ERROR, 0);
return;
}
esp_err_t err = esp_ota_begin(otaPartition, otaExpectedSize, &otaHandle);
if (err != ESP_OK) {
Serial.printf("OTA: begin failed (%d)\n", err);
ESP_LOGE(TAG, "OTA: begin failed (%d)", err);
sendOtaNotify(pChar, OTA_STATUS_ERROR, 0);
return;
}
@ -261,7 +264,7 @@ class OtaCharacteristicCallbacks : public NimBLECharacteristicCallbacks {
bleRelay1[i] = false;
bleRelay2[i] = false;
}
Serial.printf("OTA: started, expecting %lu bytes\n", otaExpectedSize);
ESP_LOGI(TAG, "OTA: started, expecting %lu bytes", otaExpectedSize);
return;
}
@ -272,37 +275,35 @@ class OtaCharacteristicCallbacks : public NimBLECharacteristicCallbacks {
mbedtls_sha256_free(&otaShaCtx);
otaShaStarted = false;
Serial.printf("OTA: SHA256 verify — written=%lu expected=%lu\n", otaWritten, otaExpectedSize);
ESP_LOGD(TAG, "OTA: SHA256 verify (written=%lu expected=%lu)", otaWritten, otaExpectedSize);
if (memcmp(computedSha, otaExpectedSha, 32) != 0) {
Serial.println("OTA: SHA256 mismatch — aborting");
ESP_LOGE(TAG, "OTA: SHA256 mismatch — aborting");
esp_ota_abort(otaHandle);
otaReset();
sendOtaNotify(pChar, OTA_STATUS_ERROR, 0);
return;
}
Serial.println("OTA: SHA256 OK, setting otaReady=true, sending COMPLETE notify");
ESP_LOGI(TAG, "OTA: SHA256 OK, waiting for 0xFF confirm");
otaReady = true;
sendOtaNotify(pChar, OTA_STATUS_COMPLETE, 0);
Serial.printf("OTA: COMPLETE notify sent, otaReady=%d, otaConfirmed=%d, otaInProgress=%d\n",
otaReady, otaConfirmed, otaInProgress);
return;
}
if (!otaInProgress) {
Serial.printf("OTA: write ignored — otaInProgress=false (len=%d, data0=0x%02X)\n", len, data[0]);
ESP_LOGD(TAG, "OTA: write ignored (not in progress, len=%d data0=0x%02X)", len, data[0]);
return;
}
if (len == 1 && data[0] == 0xFF) {
Serial.printf("OTA: 0xFF received — otaReady=%d, otaEnded=%d, otaConfirmed=%d, otaInProgress=%d\n",
otaReady, otaEnded, otaConfirmed, otaInProgress);
ESP_LOGD(TAG, "OTA: 0xFF received (ready=%d ended=%d confirmed=%d inProgress=%d)",
otaReady, otaEnded, otaConfirmed, otaInProgress);
if (!otaEnded) {
Serial.println("OTA: 0xFF arrived early (esp_ota_end not yet called), deferring");
ESP_LOGD(TAG, "OTA: 0xFF arrived early, deferring");
otaEarlyConfirm = true;
return;
}
Serial.println("OTA: 0xFF confirm accepted, setting otaConfirmed=true");
ESP_LOGI(TAG, "OTA: 0xFF confirm accepted");
otaConfirmed = true;
return;
}
@ -312,12 +313,9 @@ class OtaCharacteristicCallbacks : public NimBLECharacteristicCallbacks {
((uint32_t)data[2] << 8) | (uint32_t)data[3];
size_t dataLen = len - 4;
mbedtls_sha256_update_ret(&otaShaCtx, data + 4, dataLen);
unsigned long t0 = micros();
esp_err_t err = esp_ota_write(otaHandle, data + 4, dataLen);
unsigned long elapsed = micros() - t0;
Serial.printf("OTA: chunk %lu write %d bytes in %lu us\n", seq, dataLen, elapsed);
if (err != ESP_OK) {
Serial.printf("OTA: write err at seq %lu (%d)\n", seq, err);
ESP_LOGE(TAG, "OTA: write error at seq %lu (%d)", seq, err);
sendOtaNotify(pChar, OTA_STATUS_NAK, seq);
abortOta(pChar, "write error");
return;
@ -334,15 +332,14 @@ class MyCharacteristicCallbacks : public NimBLECharacteristicCallbacks {
int idx = findClientIdx(connInfo.getConnHandle());
if (idx < 0) {
Serial.printf("BLE: write from unknown conn handle %d\n", connInfo.getConnHandle());
ESP_LOGW(TAG, "BLE: write from unknown conn handle %d", connInfo.getConnHandle());
return;
}
std::string value = pChar->getValue();
if (value.length() != HMAC_PKT_SIZE) {
Serial.printf("BLE: bad packet length %d (expected %d), slot=%d mac=%s\n",
(int)value.length(), HMAC_PKT_SIZE, idx,
connInfo.getAddress().toString().c_str());
ESP_LOGW(TAG, "BLE: bad packet length %d (expected %d), slot=%d",
(int)value.length(), HMAC_PKT_SIZE, idx);
return;
}
@ -357,16 +354,16 @@ class MyCharacteristicCallbacks : public NimBLECharacteristicCallbacks {
if (cmd == 0x01) {
bleRelay1[idx] = true;
Serial.printf("BLE: relay1 ON (seq=%lu, slot=%d)\n", seq, idx);
ESP_LOGI(TAG, "BLE: relay1 ON (seq=%lu, slot=%d)", seq, idx);
} else if (cmd == 0x00) {
bleRelay1[idx] = false;
Serial.printf("BLE: relay1 OFF (seq=%lu, slot=%d)\n", seq, idx);
ESP_LOGI(TAG, "BLE: relay1 OFF (seq=%lu, slot=%d)", seq, idx);
} else if (cmd == 0x02) {
bleRelay2[idx] = true;
Serial.printf("BLE: relay2 ON (seq=%lu, slot=%d)\n", seq, idx);
ESP_LOGI(TAG, "BLE: relay2 ON (seq=%lu, slot=%d)", seq, idx);
} else if (cmd == 0x03) {
bleRelay2[idx] = false;
Serial.printf("BLE: relay2 OFF (seq=%lu, slot=%d)\n", seq, idx);
ESP_LOGI(TAG, "BLE: relay2 OFF (seq=%lu, slot=%d)", seq, idx);
}
}
};
@ -374,7 +371,7 @@ class MyCharacteristicCallbacks : public NimBLECharacteristicCallbacks {
void setup() {
Serial.begin(115200);
delay(2000);
Serial.println("=== AtomS3 Lite BLE Relay ===");
ESP_LOGI(TAG, "=== AtomS3 Lite BLE Relay v%s ===", FIRMWARE_VERSION);
FastLED.addLeds<WS2812, LED_PIN, GRB>(leds, NUM_LEDS);
@ -385,17 +382,15 @@ void setup() {
if (len == HMAC_KEY_LEN) {
keyProvisioned = true;
Serial.println("HMAC key loaded from NVS");
ESP_LOGI(TAG, "HMAC key loaded from NVS");
} else {
keyProvisioned = false;
Serial.println("No HMAC key provisioned — connect USB and run SET_KEY");
ESP_LOGW(TAG, "No HMAC key — connect USB and run SET_KEY");
}
if (uuidLen == ESP_UUID_LEN) {
uuidProvisioned = true;
Serial.print("UUID loaded from NVS: ");
for (int i = 0; i < ESP_UUID_LEN; i++) Serial.printf("%02X", deviceUuid[i]);
Serial.println();
ESP_LOGD(TAG, "UUID loaded from NVS");
} else {
uuidProvisioned = false;
for (int i = 0; i < ESP_UUID_LEN; i++) deviceUuid[i] = (uint8_t)(esp_random() & 0xFF);
@ -403,9 +398,7 @@ void setup() {
preferences.putBytes(NVS_UUID_NAME, deviceUuid, ESP_UUID_LEN);
preferences.end();
uuidProvisioned = true;
Serial.print("Generated new UUID: ");
for (int i = 0; i < ESP_UUID_LEN; i++) Serial.printf("%02X", deviceUuid[i]);
Serial.println();
ESP_LOGD(TAG, "Generated new UUID");
}
pinMode(TOUCH1_PIN, INPUT);
@ -416,7 +409,6 @@ void setup() {
leds[0] = CRGB::Red;
FastLED.show();
Serial.println("LED red (no connection), starting BLE...");
NimBLEDevice::init("SylDa_Server");
NimBLEDevice::setMTU(248);
@ -462,20 +454,15 @@ void setup() {
pAdvertising->setMinInterval(32);
pAdvertising->setMaxInterval(64);
bool advOk = pAdvertising->start();
Serial.printf("BLE: advertising started as 'SylDa_Server' (start=%d, isAdv=%d)\n",
advOk, pAdvertising->isAdvertising());
ESP_LOGI(TAG, "BLE: advertising started");
if (keyProvisioned) {
Serial.print("HMAC Key: ");
for (int i = 0; i < HMAC_KEY_LEN; i++) {
Serial.printf("%02X", hmacKey[i]);
}
Serial.println();
ESP_LOGD(TAG, "HMAC key present");
} else {
Serial.println("No HMAC key — use USB SET_KEY to provision");
ESP_LOGW(TAG, "No HMAC key — use USB SET_KEY to provision");
}
Serial.println("Setup done.");
ESP_LOGI(TAG, "Setup done.");
}
void loop() {
@ -537,43 +524,41 @@ void loop() {
}
if (otaReady) {
Serial.printf("OTA: loop() processing otaReady — otaWritten=%lu, otaExpectedSize=%lu\n",
otaWritten, otaExpectedSize);
ESP_LOGD(TAG, "OTA: processing otaReady (written=%lu expected=%lu)",
otaWritten, otaExpectedSize);
esp_err_t err = esp_ota_end(otaHandle);
if (err != ESP_OK) {
Serial.printf("OTA: esp_ota_end failed (%d) — aborting\n", err);
ESP_LOGE(TAG, "OTA: esp_ota_end failed (%d) — aborting", err);
otaReset();
} else {
Serial.println("OTA: esp_ota_end OK, setting otaEnded=true, waiting for 0xFF confirm");
ESP_LOGI(TAG, "OTA: esp_ota_end OK, waiting for 0xFF confirm");
otaEnded = true;
otaEndedAt = millis();
}
otaReady = false;
Serial.printf("OTA: otaReady cleared — otaReady=%d, otaEnded=%d, otaConfirmed=%d, otaInProgress=%d\n",
otaReady, otaEnded, otaConfirmed, otaInProgress);
}
if (otaEnded && otaEarlyConfirm) {
Serial.println("OTA: processing deferred 0xFF confirm");
ESP_LOGD(TAG, "OTA: processing deferred 0xFF confirm");
otaConfirmed = true;
otaEarlyConfirm = false;
}
if (otaEnded && !otaConfirmed && (millis() - otaEndedAt > OTA_CONFIRM_TIMEOUT_MS)) {
Serial.printf("OTA: 0xFF confirm timeout (%lu ms) — discarding update, resuming normal operation\n",
millis() - otaEndedAt);
ESP_LOGW(TAG, "OTA: 0xFF confirm timeout (%lu ms) — discarding update",
millis() - otaEndedAt);
otaReset();
}
if (otaConfirmed) {
Serial.println("OTA: otaConfirmed=true, setting boot partition");
ESP_LOGI(TAG, "OTA: confirmed, setting boot partition");
esp_err_t err = esp_ota_set_boot_partition(otaPartition);
if (err != ESP_OK) {
Serial.printf("OTA: set boot partition failed (%d)\n", err);
ESP_LOGE(TAG, "OTA: set boot partition failed (%d)", err);
} else {
leds[0] = CRGB::Green;
FastLED.show();
Serial.println("OTA: done, rebooting...");
ESP_LOGI(TAG, "OTA: done, rebooting...");
delay(500);
esp_restart();
}
@ -652,7 +637,7 @@ void loop() {
if (relay1State != lastRelay1 || relay2State != lastRelay2) {
bool anyBle1 = (connActive[0] && bleRelay1[0]) || (connActive[1] && bleRelay1[1]);
bool anyBle2 = (connActive[0] && bleRelay2[0]) || (connActive[1] && bleRelay2[1]);
Serial.printf("Relays: R1=%s R2=%s (t1=%s t2=%s btn=%s ble1=%s ble2=%s)\n",
ESP_LOGI(TAG, "Relays: R1=%s R2=%s (t1=%s t2=%s btn=%s ble1=%s ble2=%s)",
relay1State ? "ON" : "OFF",
relay2State ? "ON" : "OFF",
t1Active ? "YES" : "no",
@ -668,7 +653,7 @@ void loop() {
if (!otaInProgress && millis() - heartbeat > 60000) {
bool anyBle1 = (connActive[0] && bleRelay1[0]) || (connActive[1] && bleRelay1[1]);
bool anyBle2 = (connActive[0] && bleRelay2[0]) || (connActive[1] && bleRelay2[1]);
Serial.printf("[heartbeat] R1=%s R2=%s t1=%s t2=%s btn=%s ble1=%s ble2=%s clients=%d\n",
ESP_LOGI(TAG, "[heartbeat] R1=%s R2=%s t1=%s t2=%s btn=%s ble1=%s ble2=%s clients=%d",
relay1State ? "ON" : "OFF",
relay2State ? "ON" : "OFF",
t1Active ? "YES" : "no",