From 8b22c4c85b01fa95e06bd81d7003afa860b5b2a4 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sat, 30 Nov 2024 22:47:37 +0100 Subject: [PATCH 01/64] Add Wokwi config template --- data-templates/device-config-wokwi.json | 8 ++++++++ 1 file changed, 8 insertions(+) create mode 100644 data-templates/device-config-wokwi.json diff --git a/data-templates/device-config-wokwi.json b/data-templates/device-config-wokwi.json new file mode 100644 index 00000000..9dbb5250 --- /dev/null +++ b/data-templates/device-config-wokwi.json @@ -0,0 +1,8 @@ +{ + "id": "wokwi", + "instance": "wokwi", + "location": "local", + "peripherals": [ + ], + "sleepWhenIdle": true +} From 45f6d4ee52d1a426f3d5d29dedefa5868c716148 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sat, 30 Nov 2024 22:47:54 +0100 Subject: [PATCH 02/64] Use the ESP's own mDNS --- main/kernel/drivers/MdnsDriver.hpp | 52 +++++++++++++++++------------- 1 file changed, 30 insertions(+), 22 deletions(-) diff --git a/main/kernel/drivers/MdnsDriver.hpp b/main/kernel/drivers/MdnsDriver.hpp index 2baa3c77..c12fb775 100644 --- a/main/kernel/drivers/MdnsDriver.hpp +++ b/main/kernel/drivers/MdnsDriver.hpp @@ -1,7 +1,8 @@ #pragma once #include -#include + +#include #include #include @@ -37,27 +38,32 @@ class MdnsDriver { Log.info("mDNS: initializing"); WiFiConnection connection(wifi); - MDNS.begin(hostname); - MDNS.setInstanceName(instanceName); + ESP_ERROR_CHECK(mdns_init()); + + mdns_hostname_set(hostname.c_str()); + mdns_instance_name_set(instanceName.c_str()); Log.debug("mDNS: Advertising service %s on %s.local, version: %s", instanceName.c_str(), hostname.c_str(), version.c_str()); - MDNS.addService("farmhub", "tcp", 80); - MDNS.addServiceTxt("farmhub", "tcp", "version", version); + mdns_service_add(instanceName.c_str(), "_farmhub", "_tcp", 80, nullptr, 0); + mdns_txt_item_t txt[] = { + { "version", version.c_str() }, + }; + mdns_service_txt_set("_farmhub", "_tcp", txt, 1); Log.info("mDNS: configured"); mdnsReady.set(); }); } - bool lookupService(const String& serviceName, const String& port, MdnsRecord& record, bool loadFromCache = true) { + bool lookupService(const String& serviceName, const String& port, MdnsRecord& record, bool loadFromCache = true, milliseconds timeout = 5s) { // Wait indefinitely Lock lock(lookupMutex); - auto result = lookupServiceUnderMutex(serviceName, port, record, loadFromCache); + auto result = lookupServiceUnderMutex(serviceName, port, record, loadFromCache, timeout); return result; } private: - bool lookupServiceUnderMutex(const String& serviceName, const String& port, MdnsRecord& record, bool loadFromCache) { + bool lookupServiceUnderMutex(const String& serviceName, const String& port, MdnsRecord& record, bool loadFromCache, milliseconds timeout) { // TODO Use a callback and retry if cached entry doesn't work String cacheKey = serviceName + "." + port; if (loadFromCache) { @@ -80,23 +86,25 @@ class MdnsDriver { WiFiConnection connection(wifi); mdnsReady.awaitSet(); - auto count = MDNS.queryService(serviceName.c_str(), port.c_str()); - if (count == 0) { + + mdns_result_t* results = nullptr; + esp_err_t err = mdns_query_ptr(String("_" + serviceName).c_str(), String("_" + port).c_str(), timeout.count(), 1, &results); + if (err) { + Log.error("mDNS: query failed for %s.%s: %d", + serviceName.c_str(), port.c_str(), err); return false; } - Log.info("mDNS: found %d services, choosing first:", - count); - for (int i = 0; i < count; i++) { - Log.info(" %s%d) %s:%d (%s)", - i == 0 ? "*" : " ", - i + 1, - MDNS.hostname(i).c_str(), - MDNS.port(i), - MDNS.address(i).toString().c_str()); + if (results == nullptr) { + Log.info("mDNS: no results found for %s.%s", + serviceName.c_str(), port.c_str()); + return false; } - record.hostname = MDNS.hostname(0); - record.ip = MDNS.address(0); - record.port = MDNS.port(0); + + auto& result = results[0]; + record.hostname = result.hostname; + record.ip = IPAddress(result.addr->addr.u_addr.ip4.addr); + record.port = result.port; + mdns_query_results_free(results); nvs.set(cacheKey, record); From f47c669f583ae7a3438ebf82c0ff4f7f29fad453 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sun, 1 Dec 2024 00:06:03 +0100 Subject: [PATCH 03/64] Switch to ESP-IDF's own NTP client --- .gitmodules | 3 - components/CMakeLists.txt | 3 - components/NTPClient | 1 - main/kernel/drivers/RtcDriver.hpp | 121 +++++++++++++++--------------- sdkconfig.defaults | 4 + 5 files changed, 66 insertions(+), 66 deletions(-) delete mode 160000 components/NTPClient diff --git a/.gitmodules b/.gitmodules index 1a75da7c..ec4c1153 100644 --- a/.gitmodules +++ b/.gitmodules @@ -7,9 +7,6 @@ [submodule "components/ArxContainer"] path = components/ArxContainer url = https://github.com/hideakitai/ArxContainer -[submodule "components/NTPClient"] - path = components/NTPClient - url = https://github.com/arduino-libraries/NTPClient [submodule "components/SHT31"] path = components/SHT31 url = https://github.com/RobTillaart/SHT31 diff --git a/components/CMakeLists.txt b/components/CMakeLists.txt index 1ccd79fa..f252bf4e 100644 --- a/components/CMakeLists.txt +++ b/components/CMakeLists.txt @@ -19,9 +19,6 @@ idf_component_register( SRCS ${mqtt_sources} INCLUDE_DIRS "MQTTPubSubClient/src" "ArxTypeTraits" "ArxContainer" - SRCS "NTPClient/NTPClient.cpp" - INCLUDE_DIRS "NTPClient" - SRCS "OneWire/OneWire.cpp" INCLUDE_DIRS "OneWire" diff --git a/components/NTPClient b/components/NTPClient deleted file mode 160000 index 78d4237b..00000000 --- a/components/NTPClient +++ /dev/null @@ -1 +0,0 @@ -Subproject commit 78d4237b3ae12d801ccf48c5f86f48ef3720d2b4 diff --git a/main/kernel/drivers/RtcDriver.hpp b/main/kernel/drivers/RtcDriver.hpp index ff08699b..2a1c2a4b 100644 --- a/main/kernel/drivers/RtcDriver.hpp +++ b/main/kernel/drivers/RtcDriver.hpp @@ -1,11 +1,11 @@ #pragma once -#include #include #include #include -#include +#include "esp_netif_sntp.h" +#include "esp_sntp.h" #include #include @@ -41,32 +41,25 @@ class RtcDriver { , mdns(mdns) , ntpConfig(ntpConfig) , rtcInSync(rtcInSync) { - // TODO We should not need two separate tasks here - Task::run("rtc-check", 3172, [this](Task& task) { - while (true) { - if (isTimeSet()) { - Log.info("RTC: time is set"); - this->rtcInSync.set(); - break; - } - task.delayUntil(1s); - } - }); + + if (isTimeSet()) { + Log.info("RTC: time is already set"); + rtcInSync.set(); + } + Task::run("ntp-sync", 4096, [this, &wifi](Task& task) { while (true) { { WiFiConnection connection(wifi); - ensureConfigured(); - if (!ntpClient->forceUpdate()) { + if (updateTime()) { + trustMdnsCache = true; + } else { // Attempt a retry, but with mDNS cache disabled Log.error("RTC: NTP update failed, retrying in 10 seconds with mDNS cache disabled"); - ntpClient.reset(); trustMdnsCache = false; task.delay(10s); continue; } - trustMdnsCache = true; - setOrAdjustTime(system_clock::from_time_t(ntpClient->getEpochTime())); } // We are good for a while now @@ -85,19 +78,24 @@ class RtcDriver { } private: - void ensureConfigured() { - if (ntpClient.has_value()) { - return; - } + bool updateTime() { + esp_sntp_config_t config = ESP_NETIF_SNTP_DEFAULT_CONFIG("pool.ntp.org"); + config.start = false; + config.smooth_sync = true; + config.server_from_dhcp = true; + config.renew_servers_after_new_IP = true; + config.wait_for_sync = true; + config.ip_event_to_renew = IP_EVENT_STA_GOT_IP; + ESP_ERROR_CHECK(esp_netif_sntp_init(&config)); #ifdef WOKWI - Log.debug("RTC: using default NTP server for Wokwi"); - ntpClient.emplace(udp); + Log.info("RTC: using default NTP server for Wokwi"); #else + // TODO Check this if (ntpConfig.host.get().length() > 0) { Log.info("RTC: using NTP server %s from configuration", ntpConfig.host.get().c_str()); - ntpClient.emplace(udp, ntpConfig.host.get().c_str()); + esp_sntp_setservername(0, ntpConfig.host.get().c_str()); } else { MdnsRecord ntpServer; if (mdns.lookupService("ntp", "udp", ntpServer, trustMdnsCache)) { @@ -105,57 +103,62 @@ class RtcDriver { ntpServer.hostname.c_str(), ntpServer.port, ntpServer.ip.toString().c_str()); - ntpClient.emplace(udp, ntpServer.ip); + auto serverIp = convertIp4(ntpServer.ip); + esp_sntp_setserver(0, &serverIp); } else { Log.info("RTC: no NTP server configured, using default"); - ntpClient.emplace(udp); } } #endif + ESP_ERROR_CHECK(esp_netif_sntp_start()); - // TODO Use built in configTime() instead - // We are using the external NTP client library, because the built in configTime() does not - // reliably update the time for some reason. - ntpClient->begin(); - } + printServers(); - static void setOrAdjustTime(time_point newEpochTime) { - // Threshold for deciding between settimeofday and adjtime - const auto threshold = 30s; + bool success = false; + for (int retry = 0; retry < 10; retry++) { + auto ret = esp_netif_sntp_sync_wait(ticks(10s).count()); + if (ret == ESP_OK) { + success = true; + rtcInSync.set(); + break; + } else { + Log.info("RTC: waiting for time sync returned %d, retry #%d", ret, retry); + } + } - // Get current time - auto now = system_clock::now(); + esp_netif_sntp_deinit(); + return success; + } - // Calculate the difference - auto difference = newEpochTime - now; - - if (difference.count() == 0) { - Log.debug("RTC: Time is already correct at %lld", - duration_cast(newEpochTime.time_since_epoch()).count()); - } else if (abs(difference) < threshold) { - // If the difference is smaller, adjust the time gradually - struct timeval adj = { .tv_sec = (time_t) duration_cast(difference).count(), .tv_usec = 0 }; - adjtime(&adj, NULL); - Log.debug("RTC: Adjusted time by %lld ms to %lld", - duration_cast(difference).count(), - duration_cast(newEpochTime.time_since_epoch()).count()); - } else { - // If the difference is larger than the threshold, set the time directly - struct timeval tv = { .tv_sec = (time_t) duration_cast(newEpochTime.time_since_epoch()).count(), .tv_usec = 0 }; - settimeofday(&tv, NULL); - Log.debug("RTC: Set time from %lld to %lld", - duration_cast(now.time_since_epoch()).count(), - duration_cast(newEpochTime.time_since_epoch()).count()); + static void printServers(void) { + Log.info("List of configured NTP servers:"); + + for (uint8_t i = 0; i < SNTP_MAX_SERVERS; ++i) { + if (esp_sntp_getservername(i)) { + Log.info(" - server %d: '%s'", i, esp_sntp_getservername(i)); + } else { + char buff[48]; + ip_addr_t const* ip = esp_sntp_getserver(i); + if (ipaddr_ntoa_r(ip, buff, 48) != NULL) { + Log.info(" - server %d: %s", i, buff); + } + } } } + // TODO Use ESP-IDF's ip4_addr_t + static ip_addr_t convertIp4(const IPAddress& ip) { + ip_addr_t espIP; + IP4_ADDR(&espIP.u_addr.ip4, ip[0], ip[1], ip[2], ip[3]); + espIP.type = IPADDR_TYPE_V4; + return espIP; + } + WiFiDriver& wifi; MdnsDriver& mdns; const Config& ntpConfig; StateSource& rtcInSync; - WiFiUDP udp; - std::optional ntpClient; bool trustMdnsCache = true; }; diff --git a/sdkconfig.defaults b/sdkconfig.defaults index 54d35f3a..a79c4cbc 100644 --- a/sdkconfig.defaults +++ b/sdkconfig.defaults @@ -38,6 +38,10 @@ CONFIG_PARTITION_TABLE_FILENAME="partitions.csv" # Increase main task stack from default 3584 CONFIG_ESP_MAIN_TASK_STACK_SIZE=6144 +# Allow time to be adjusted smoothly +CONFIG_LWIP_DHCP_GET_NTP_SRV=y +CONFIG_SNTP_TIME_SYNC_METHOD_SMOOTH=y + # # Power management # From 0cd535f341e75853495ce0d95c99684590c59699 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sun, 1 Dec 2024 14:28:04 +0100 Subject: [PATCH 04/64] Use ESP-IDF's own MQTT implementation --- .gitmodules | 9 - components/ArxContainer | 1 - components/ArxTypeTraits | 1 - components/CMakeLists.txt | 3 - components/MQTTPubSubClient | 1 - main/kernel/Kernel.hpp | 2 + main/kernel/drivers/MqttDriver.hpp | 287 ++++++++++++++++++++--------- 7 files changed, 197 insertions(+), 107 deletions(-) delete mode 160000 components/ArxContainer delete mode 160000 components/ArxTypeTraits delete mode 160000 components/MQTTPubSubClient diff --git a/.gitmodules b/.gitmodules index ec4c1153..7aa51f79 100644 --- a/.gitmodules +++ b/.gitmodules @@ -1,12 +1,3 @@ -[submodule "components/MQTTPubSubClient"] - path = components/MQTTPubSubClient - url = https://github.com/hideakitai/MQTTPubSubClient -[submodule "components/ArxTypeTraits"] - path = components/ArxTypeTraits - url = https://github.com/hideakitai/ArxTypeTraits -[submodule "components/ArxContainer"] - path = components/ArxContainer - url = https://github.com/hideakitai/ArxContainer [submodule "components/SHT31"] path = components/SHT31 url = https://github.com/RobTillaart/SHT31 diff --git a/components/ArxContainer b/components/ArxContainer deleted file mode 160000 index d6affcd0..00000000 --- a/components/ArxContainer +++ /dev/null @@ -1 +0,0 @@ -Subproject commit d6affcd0bc83219b863c20abf7c269214db8db2a diff --git a/components/ArxTypeTraits b/components/ArxTypeTraits deleted file mode 160000 index 7a44152a..00000000 --- a/components/ArxTypeTraits +++ /dev/null @@ -1 +0,0 @@ -Subproject commit 7a44152a9a49e8592dc13fccd65f4169d428ecac diff --git a/components/CMakeLists.txt b/components/CMakeLists.txt index f252bf4e..7367e96b 100644 --- a/components/CMakeLists.txt +++ b/components/CMakeLists.txt @@ -16,9 +16,6 @@ idf_component_register( SRCS "DallasTemperature/DallasTemperature.cpp" INCLUDE_DIRS "DallasTemperature" - SRCS ${mqtt_sources} - INCLUDE_DIRS "MQTTPubSubClient/src" "ArxTypeTraits" "ArxContainer" - SRCS "OneWire/OneWire.cpp" INCLUDE_DIRS "OneWire" diff --git a/components/MQTTPubSubClient b/components/MQTTPubSubClient deleted file mode 160000 index 43771e81..00000000 --- a/components/MQTTPubSubClient +++ /dev/null @@ -1 +0,0 @@ -Subproject commit 43771e8104899f86ad92a22266427608d7a2d262 diff --git a/main/kernel/Kernel.hpp b/main/kernel/Kernel.hpp index 0a41317b..499f8748 100644 --- a/main/kernel/Kernel.hpp +++ b/main/kernel/Kernel.hpp @@ -7,6 +7,8 @@ #include #include +#include +#include #include diff --git a/main/kernel/drivers/MqttDriver.hpp b/main/kernel/drivers/MqttDriver.hpp index 942897a1..53b140ec 100644 --- a/main/kernel/drivers/MqttDriver.hpp +++ b/main/kernel/drivers/MqttDriver.hpp @@ -6,10 +6,8 @@ #include #include -#include -#include - -#include +#include +#include #include #include @@ -205,15 +203,13 @@ class MqttDriver { , clientId(getClientId(config.clientId.get(), instanceName)) , powerSaveMode(powerSaveMode) , mqttReady(mqttReady) { - Task::run("mqtt:init", 4096, [this](Task& task) { - setup(); - Task::run("mqtt", 5120, [this](Task& task) { - runEventLoop(task); - }); - Task::loop("mqtt:incoming", 4096, [this](Task& task) { - incomingQueue.take([&](const IncomingMessage& message) { - processIncomingMessage(message); - }); + + Task::run("mqtt", 5120, [this](Task& task) { + runEventLoop(task); + }); + Task::loop("mqtt:incoming", 4096, [this](Task& task) { + incomingQueue.take([&](const IncomingMessage& message) { + processIncomingMessage(message); }); }); } @@ -278,14 +274,6 @@ class MqttDriver { return outgoingQueue.offerIn(MQTT_QUEUE_TIMEOUT, Subscription { topic, qos, handler }); } - void setup() { - // TODO Figure out the right keep alive value - mqttClient.setKeepAliveTimeout(180); - mqttClient.subscribe([this](const String& topic, const String& payload, const size_t size) { - incomingQueue.offerIn(MQTT_QUEUE_TIMEOUT, topic, payload); - }); - } - String joinStrings(std::list strings) { if (strings.empty()) { return ""; @@ -302,13 +290,11 @@ class MqttDriver { time_point alertUntil = system_clock::now() + 5s; while (true) { - auto timeout = alertUntil - system_clock::now(); + auto timeout = duration_cast(alertUntil - system_clock::now()); if (timeout > 0ns) { Log.trace("MQTT: Alert for another %lld seconds, checking for incoming messages", duration_cast(timeout).count()); ensureConnected(task); - // Process incoming network traffic - mqttClient.update(); timeout = std::min(timeout, MQTT_LOOP_INTERVAL); } else { if (powerSaveMode) { @@ -352,8 +338,21 @@ class MqttDriver { } void disconnect() { - mqttClient.disconnect(); - wifiConnection.reset(); + if (client != nullptr) { + Log.debug("Disconnecting from MQTT server"); + mqttReady.clear(); + ESP_ERROR_CHECK(esp_mqtt_client_disconnect(client)); + stopMqttClient(); + wifiConnection.reset(); + } + } + + void stopMqttClient() { + if (client != nullptr) { + ESP_ERROR_CHECK(esp_mqtt_client_stop(client)); + ESP_ERROR_CHECK(esp_mqtt_client_destroy(client)); + client = nullptr; + } } bool connectIfNecessary() { @@ -363,65 +362,83 @@ class MqttDriver { Log.trace("MQTT: Connected to WiFi"); } - if (!mqttClient.isConnected()) { + if (!mqttReady.isSet()) { Log.debug("MQTT: Connecting to MQTT server"); - mqttReady.clear(); - String serverCert; - String clientCert; - String clientKey; + if (client == nullptr) { + String serverCert; + String clientCert; + String clientKey; - MdnsRecord mqttServer; + esp_mqtt_client_config_t mqttConfig = {}; + mqttConfig.network.timeout_ms = duration_cast(10s).count(); #ifdef WOKWI - Log.debug("MQTT: Using MQTT server on Wokwi host"); - mqttServer.hostname = "host.wokwi.internal"; - mqttServer.port = 1883; + mqttConfig.broker.address.transport = MQTT_TRANSPORT_OVER_TCP; + mqttConfig.broker.address.hostname = "host.wokwi.internal"; + mqttConfig.broker.address.port = 1883; #else - if (config.host.get().length() > 0) { - mqttServer.hostname = config.host.get(); - mqttServer.port = config.port.get(); - if (config.serverCert.hasValue()) { - serverCert = joinStrings(config.serverCert.get()); - clientCert = joinStrings(config.clientCert.get()); - clientKey = joinStrings(config.clientKey.get()); + if (config.host.get().length() > 0) { + mqttConfig.broker.address.hostname = config.host.get().c_str(); + mqttConfig.broker.address.port = config.port.get(); + if (config.serverCert.hasValue()) { + mqttConfig.broker.address.transport = MQTT_TRANSPORT_OVER_SSL; + serverCert = joinStrings(config.serverCert.get()); + clientCert = joinStrings(config.clientCert.get()); + clientKey = joinStrings(config.clientKey.get()); + } else { + mqttConfig.broker.address.transport = MQTT_TRANSPORT_OVER_TCP; + } + } else { + // TODO Handle lookup failure + MdnsRecord mqttServer; + mdns.lookupService("mqtt", "tcp", mqttServer, trustMdnsCache); + mqttConfig.broker.address.transport = MQTT_TRANSPORT_OVER_TCP; + if (mqttServer.ip == IPAddress()) { + mqttConfig.broker.address.hostname = mqttServer.hostname.c_str(); + } else { + mqttConfig.broker.address.hostname = mqttServer.ip.toString().c_str(); + } + mqttConfig.broker.address.port = mqttServer.port; } - } else { - // TODO Handle lookup failure - mdns.lookupService("mqtt", "tcp", mqttServer, trustMdnsCache); - } #endif + Log.debug("MQTT: server: %s:%ld, client ID is '%s'", + mqttConfig.broker.address.hostname, mqttConfig.broker.address.port, clientId.c_str()); + + if (!serverCert.isEmpty()) { + // TODO Make TLS work + // Log.debug("MQTT: server: %s:%d, client ID is '%s', using TLS", + // hostname.c_str(), mqttServer.port, clientId.c_str()); + // Log.trace("Server cert: %s", serverCert.c_str()); + // Log.trace("Client cert: %s", clientCert.c_str()); + // wifiClientSecure.setCACert(serverCert.c_str()); + // wifiClientSecure.setCertificate(clientCert.c_str()); + // wifiClientSecure.setPrivateKey(clientKey.c_str()); + // wifiClientSecure.connect(mqttServer.hostname.c_str(), mqttServer.port); + // mqttClient.begin(wifiClientSecure); + } - String hostname; - if (mqttServer.ip == IPAddress()) { - hostname = mqttServer.hostname; - } else { - hostname = mqttServer.ip.toString(); - } + client = esp_mqtt_client_init(&mqttConfig); + /* The last argument may be used to pass data to the event handler, in this example mqtt_event_handler */ + ESP_ERROR_CHECK(esp_mqtt_client_register_event(client, MQTT_EVENT_ANY, handleMqttEventCallback, this)); + + esp_err_t err = esp_mqtt_client_start(client); - if (serverCert.isEmpty()) { - Log.debug("MQTT: server: %s:%d, client ID is '%s'", - hostname.c_str(), mqttServer.port, clientId.c_str()); - wifiClient.connect(hostname.c_str(), mqttServer.port); - mqttClient.begin(wifiClient); + if (err != ESP_OK) { + Log.error("MQTT: Connection failed, error = 0x%x", err); + trustMdnsCache = false; + return false; + } else { + trustMdnsCache = true; + } } else { - Log.debug("MQTT: server: %s:%d, client ID is '%s', using TLS", - hostname.c_str(), mqttServer.port, clientId.c_str()); - Log.trace("Server cert: %s", serverCert.c_str()); - Log.trace("Client cert: %s", clientCert.c_str()); - wifiClientSecure.setCACert(serverCert.c_str()); - wifiClientSecure.setCertificate(clientCert.c_str()); - wifiClientSecure.setPrivateKey(clientKey.c_str()); - wifiClientSecure.connect(mqttServer.hostname.c_str(), mqttServer.port); - mqttClient.begin(wifiClientSecure); + // TODO Reconnection probably doesn't work like this? + Log.debug("MQTT: Reconnecting to MQTT server"); + ESP_ERROR_CHECK(esp_mqtt_client_reconnect(client)); } - - if (!mqttClient.connect(clientId.c_str())) { - Log.error("MQTT: Connection failed, error = %d", - mqttClient.getLastError()); - trustMdnsCache = false; + if (!mqttReady.awaitSet(MQTT_CONNECTION_TIMEOUT)) { + Log.debug("MQTT: Connecting to MQTT server timed out"); + stopMqttClient(); return false; - } else { - trustMdnsCache = true; } // Re-subscribe to existing subscriptions @@ -430,22 +447,105 @@ class MqttDriver { } Log.debug("MQTT: Connected"); - mqttReady.set(); } return true; } + static void handleMqttEventCallback(void* userData, esp_event_base_t eventBase, int32_t eventId, void* eventData) { + auto event = static_cast(eventData); + // Log.trace("MQTT: Event dispatched from event loop: base=%s, event_id=%d, client=%p, data=%p, data_len=%d, topic=%p, topic_len=%d, msg_id=%d", + // eventBase, event->event_id, event->client, event->data, event->data_len, event->topic, event->topic_len, event->msg_id); + auto* driver = static_cast(userData); + driver->handleMqttEvent(eventId, event); + } + + void handleMqttEvent(int eventId, esp_mqtt_event_handle_t event) { + switch (eventId) { + case MQTT_EVENT_BEFORE_CONNECT: { + Log.trace("MQTT: Connecting to MQTT server"); + break; + } + case MQTT_EVENT_CONNECTED: { + Log.trace("MQTT: Connected to MQTT server"); + mqttReady.set(); + break; + } + case MQTT_EVENT_DISCONNECTED: { + Log.trace("MQTT: Disconnected from MQTT server"); + mqttReady.clear(); + break; + } + case MQTT_EVENT_SUBSCRIBED: { + Log.trace("MQTT: Subscribed, message ID: %d", event->msg_id); + break; + } + case MQTT_EVENT_UNSUBSCRIBED: { + Log.trace("MQTT: Unsubscribed, message ID: %d", event->msg_id); + break; + } + case MQTT_EVENT_PUBLISHED: { + Log.trace("MQTT: Published, message ID %d", event->msg_id); + break; + } + case MQTT_EVENT_DATA: { + String topic(event->topic, event->topic_len); + String payload(event->data, event->data_len); + Log.trace("MQTT: Received message on topic '%s'", + topic.c_str()); + incomingQueue.offerIn(MQTT_QUEUE_TIMEOUT, IncomingMessage { topic, payload }); + break; + } + case MQTT_EVENT_ERROR: { + if (event->error_handle->error_type == MQTT_ERROR_TYPE_TCP_TRANSPORT) { + Log.error("Last errno string (%s)", strerror(event->error_handle->esp_transport_sock_errno)); + logErrorIfNonZero("reported from esp-tls", event->error_handle->esp_tls_last_esp_err); + logErrorIfNonZero("reported from tls stack", event->error_handle->esp_tls_stack_err); + logErrorIfNonZero("captured as transport's socket errno", event->error_handle->esp_transport_sock_errno); + } + break; + } + default: { + Log.warn("MQTT: Unknown event %d", eventId); + break; + } + } + } + + static void logErrorIfNonZero(const char* message, int error) { + if (error != 0) { + Log.error(" - %s: %d", message, error); + } + } + void processOutgoingMessage(const OutgoingMessage message) { - bool success = mqttClient.publish(message.topic, message.payload, message.retain == Retention::Retain, static_cast(message.qos)); + int ret = esp_mqtt_client_publish( + client, + message.topic.c_str(), + message.payload.c_str(), + message.payload.length(), + static_cast(message.qos), + message.retain == Retention::Retain); #ifdef DUMP_MQTT if (message.log == LogPublish::Log) { - Log.trace("MQTT: Published to '%s' (size: %d)", - message.topic.c_str(), message.payload.length()); + Log.trace("MQTT: Published to '%s' (size: %d), result: %d", + message.topic.c_str(), message.payload.length(), ret); } #endif - if (!success) { - Log.trace("MQTT: Error publishing to '%s', error = %d", - message.topic.c_str(), mqttClient.getLastError()); + bool success; + switch (ret) { + case -1: + Log.debug("MQTT: Error publishing to '%s'", + message.topic.c_str()); + success = false; + break; + case -2: + Log.debug("MQTT: Outbox full, message to '%s' dropped", + message.topic.c_str()); + success = false; + break; + default: + success = true; + break; } if (message.waitingTask != nullptr) { uint32_t status = success ? OutgoingMessage::PUBLISH_SUCCESS : OutgoingMessage::PUBLISH_FAILED; @@ -498,14 +598,19 @@ class MqttDriver { bool registerSubscriptionWithMqtt(const Subscription& subscription) { Log.trace("MQTT: Subscribing to topic '%s' (qos = %d)", subscription.topic.c_str(), static_cast(subscription.qos)); - bool success = mqttClient.subscribe(subscription.topic, static_cast(subscription.qos), [](const String& payload, const size_t size) { - // Global handler will take care of putting the received message on the incoming queue - }); - if (!success) { - Log.error("MQTT: Error subscribing to topic '%s', error = %d\n", - subscription.topic.c_str(), mqttClient.getLastError()); + int ret = esp_mqtt_client_subscribe(client, subscription.topic.c_str(), static_cast(subscription.qos)); + switch (ret) { + case -1: + Log.error("MQTT: Error subscribing to topic '%s'", + subscription.topic.c_str()); + return false; + case -2: + Log.error("MQTT: Subscription to topic '%s' failed, outbox full", + subscription.topic.c_str()); + return false; + default: + return true; } - return success; } static String getClientId(const String& clientId, const String& instanceName) { @@ -517,8 +622,6 @@ class MqttDriver { WiFiDriver& wifi; std::optional wifiConnection; - WiFiClient wifiClient; - WiFiClientSecure wifiClientSecure; MdnsDriver& mdns; bool trustMdnsCache = true; const Config& config; @@ -526,8 +629,7 @@ class MqttDriver { const bool powerSaveMode; StateSource& mqttReady; - static constexpr int MQTT_BUFFER_SIZE = 2048; - MQTTPubSub::PubSubClient mqttClient; + esp_mqtt_client_handle_t client; Queue> outgoingQueue { "mqtt-outgoing", config.queueSize.get() }; Queue incomingQueue { "mqtt-incoming", config.queueSize.get() }; @@ -535,7 +637,8 @@ class MqttDriver { std::list subscriptions; // TODO Review these values - static constexpr nanoseconds MQTT_LOOP_INTERVAL = 1s; + static constexpr milliseconds MQTT_CONNECTION_TIMEOUT = 10s; + static constexpr milliseconds MQTT_LOOP_INTERVAL = 1s; static constexpr milliseconds MQTT_DISCONNECTED_CHECK_INTERVAL = 5s; static constexpr milliseconds MQTT_QUEUE_TIMEOUT = 1s; static constexpr milliseconds MQTT_ALERT_AFTER_OUTGOING = 1s; From aed89cdbb223e67dd53f4979b5576c2c114d2ea7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sun, 1 Dec 2024 16:25:01 +0100 Subject: [PATCH 05/64] Allow Task::delay() to be called from a static context --- main/kernel/Task.hpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/main/kernel/Task.hpp b/main/kernel/Task.hpp index ba524d1a..fbd1157e 100644 --- a/main/kernel/Task.hpp +++ b/main/kernel/Task.hpp @@ -129,7 +129,7 @@ class Task { }); } - void delay(ticks time) { + static void delay(ticks time) { // Log.trace("Task '%s' delaying for %lld ms", // pcTaskGetName(nullptr), duration_cast(time).count()); vTaskDelay(time.count()); From f94b0da79b88b8eb3514da5d21f8fc5829bfeeaa Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sun, 1 Dec 2024 16:25:41 +0100 Subject: [PATCH 06/64] Stop MQTT client if cannot connect --- main/kernel/drivers/MqttDriver.hpp | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/main/kernel/drivers/MqttDriver.hpp b/main/kernel/drivers/MqttDriver.hpp index 53b140ec..687acacb 100644 --- a/main/kernel/drivers/MqttDriver.hpp +++ b/main/kernel/drivers/MqttDriver.hpp @@ -426,6 +426,7 @@ class MqttDriver { if (err != ESP_OK) { Log.error("MQTT: Connection failed, error = 0x%x", err); trustMdnsCache = false; + stopMqttClient(); return false; } else { trustMdnsCache = true; @@ -629,7 +630,7 @@ class MqttDriver { const bool powerSaveMode; StateSource& mqttReady; - esp_mqtt_client_handle_t client; + esp_mqtt_client_handle_t client = nullptr; Queue> outgoingQueue { "mqtt-outgoing", config.queueSize.get() }; Queue incomingQueue { "mqtt-incoming", config.queueSize.get() }; From e542631cba18dad86d42ed48e8ef4dc31a8ee882 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sun, 1 Dec 2024 16:25:58 +0100 Subject: [PATCH 07/64] Use ESP-IDF's own HTTPS OTA --- main/kernel/Kernel.hpp | 99 +++++++++++++++++++++++++++++------------- 1 file changed, 69 insertions(+), 30 deletions(-) diff --git a/main/kernel/Kernel.hpp b/main/kernel/Kernel.hpp index 499f8748..28be256c 100644 --- a/main/kernel/Kernel.hpp +++ b/main/kernel/Kernel.hpp @@ -4,12 +4,11 @@ #include #include +#include +#include +#include #include -#include -#include -#include - #include #include @@ -216,7 +215,6 @@ class Kernel { return ""; } - Log.info("Starting update..."); auto fUpdate = fs.open(UPDATE_FILE, FILE_READ); JsonDocument doc; auto error = deserializeJson(doc, fUpdate); @@ -231,39 +229,80 @@ class Kernel { return "Command contains empty url"; } + Log.info("Updating from version %s via URL %s", + FARMHUB_VERSION, url.c_str()); + Log.debug("Waiting for network..."); WiFiConnection connection(wifi, WiFiConnection::Mode::NoAwait); if (!connection.await(15s)) { return "Network not ready, aborting update"; } - httpUpdate.setFollowRedirects(HTTPC_STRICT_FOLLOW_REDIRECTS); - Log.info("Updating from version %s via URL %s", - FARMHUB_VERSION, url.c_str()); - - HTTPUpdateResult result = HTTP_UPDATE_NO_UPDATES; - // Run in separate task to allocate enough stack - SemaphoreHandle_t completionSemaphore = xSemaphoreCreateBinary(); - Task::run("http-update", 16 * 1024, [&](Task& task) { - // Allocate on heap to avoid wasting stack - std::unique_ptr client = std::make_unique(); - // Allow insecure connections for testing - client->setInsecure(); - result = httpUpdate.update(*client, url, FARMHUB_VERSION); - xSemaphoreGive(completionSemaphore); - }); - xSemaphoreTake(completionSemaphore, portMAX_DELAY); - - switch (result) { - case HTTP_UPDATE_FAILED: - return httpUpdate.getLastErrorString() + " (" + String(httpUpdate.getLastError()) + ")"; - case HTTP_UPDATE_NO_UPDATES: - return "No updates available"; - case HTTP_UPDATE_OK: - return "Update OK"; + Log.info("WiFi connected: %s", WiFi.localIP().toString().c_str()); + + // TODO Disable power save mode for WiFi + + esp_http_client_config_t httpConfig = { + .url = url.c_str(), + .timeout_ms = duration_cast(2min).count(), + .max_redirection_count = 5, + .event_handler = httpEventHandler, + .buffer_size = 8192, + .buffer_size_tx = 8192, + .user_data = this, + // TODO Do we need this? + .skip_cert_common_name_check = true, + .crt_bundle_attach = esp_crt_bundle_attach, + .keep_alive_enable = true, + }; + esp_https_ota_config_t otaConfig = { + .http_config = &httpConfig, + // TODO Make it work without partial downloads + // With this we seem to be able to install a new firmware, even if very slowly; + // without it we get the error upon download completion: 'no more processes'. + .partial_http_download = true, + }; + esp_err_t ret = esp_https_ota(&otaConfig); + if (ret == ESP_OK) { + Log.info("Update succeeded, rebooting in 5 seconds..."); + Task::delay(5s); + esp_restart(); + } else { + Log.error("Update failed (err = %d), continuing with regular boot", + ret); + return "Firmware upgrade failed: " + String(ret); + } + } // namespace farmhub::kernel + + static esp_err_t httpEventHandler(esp_http_client_event_t* event) { + switch (event->event_id) { + case HTTP_EVENT_ERROR: + Log.error("HTTP error, status code: %d", + esp_http_client_get_status_code(event->client)); + break; + case HTTP_EVENT_ON_CONNECTED: + Log.debug("HTTP connected"); + break; + case HTTP_EVENT_HEADERS_SENT: + Log.trace("HTTP headers sent"); + break; + case HTTP_EVENT_ON_HEADER: + Log.trace("HTTP header: %s: %s", event->header_key, event->header_value); + break; + case HTTP_EVENT_ON_DATA: + Log.debug("HTTP data: %d bytes", event->data_len); + break; + case HTTP_EVENT_ON_FINISH: + Log.debug("HTTP finished"); + break; + case HTTP_EVENT_DISCONNECTED: + Log.debug("HTTP disconnected"); + break; default: - return "Unknown response"; + Log.warn("Unknown HTTP event %d", event->event_id); + break; } + return ESP_OK; } TDeviceConfiguration& deviceConfig; From b7569a097e83e42fb4ab961a32e3dce9ea53aebd Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sun, 1 Dec 2024 18:09:14 +0100 Subject: [PATCH 08/64] Reduce NTP server printout level --- main/kernel/drivers/RtcDriver.hpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/main/kernel/drivers/RtcDriver.hpp b/main/kernel/drivers/RtcDriver.hpp index 2a1c2a4b..3167a0ef 100644 --- a/main/kernel/drivers/RtcDriver.hpp +++ b/main/kernel/drivers/RtcDriver.hpp @@ -131,7 +131,7 @@ class RtcDriver { } static void printServers(void) { - Log.info("List of configured NTP servers:"); + Log.debug("List of configured NTP servers:"); for (uint8_t i = 0; i < SNTP_MAX_SERVERS; ++i) { if (esp_sntp_getservername(i)) { @@ -140,7 +140,7 @@ class RtcDriver { char buff[48]; ip_addr_t const* ip = esp_sntp_getserver(i); if (ipaddr_ntoa_r(ip, buff, 48) != NULL) { - Log.info(" - server %d: %s", i, buff); + Log.debug(" - server %d: %s", i, buff); } } } From 74a72db9eff8e2c66199e75b3b2627530df0f061 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sun, 1 Dec 2024 19:06:49 +0100 Subject: [PATCH 09/64] Use ESP-IDF WiFi implementation only --- main/devices/Device.hpp | 52 +++--- main/kernel/Kernel.hpp | 5 +- main/kernel/Strings.hpp | 28 --- main/kernel/drivers/WiFiDriver.hpp | 266 +++++++++++++++++------------ 4 files changed, 195 insertions(+), 156 deletions(-) delete mode 100644 main/kernel/Strings.hpp diff --git a/main/devices/Device.hpp b/main/devices/Device.hpp index 581a46e5..284890da 100644 --- a/main/devices/Device.hpp +++ b/main/devices/Device.hpp @@ -5,6 +5,8 @@ #include +#include "esp_netif.h" +#include "esp_wifi.h" #include #include @@ -194,26 +196,34 @@ class ConsolePrinter { private: static String wifiStatus() { - switch (WiFi.status()) { - case WL_NO_SHIELD: - return "\033[0;31moff\033[0m"; - case WL_IDLE_STATUS: - return "\033[0;31midle\033[0m"; - case WL_NO_SSID_AVAIL: - return "\033[0;31mno SSID\033[0m"; - case WL_SCAN_COMPLETED: - return "\033[0;33mscan completed\033[0m"; - case WL_CONNECTED: - return "\033[0;33m" + WiFi.localIP().toString() + "\033[0m"; - case WL_CONNECT_FAILED: - return "\033[0;31mfailed\033[0m"; - case WL_CONNECTION_LOST: - return "\033[0;31mconnection lost\033[0m"; - case WL_DISCONNECTED: - return "\033[0;33mdisconnected\033[0m"; - default: - return "\033[0;31munknown\033[0m"; + esp_netif_t* netif = esp_netif_get_handle_from_ifkey("WIFI_AP_DEF"); + if (!netif) { + return "\033[0;31moff\033[0m"; + } + + // Retrieve the current Wi-Fi station connection status + wifi_ap_record_t ap_info; + esp_err_t err = esp_wifi_sta_get_ap_info(&ap_info); + + // TODO Handle ESP_ERR_WIFI_CONN, or better yet, use `WiFiDriver` directly + if (err == ESP_ERR_WIFI_NOT_CONNECT) { + return "\033[0;33mdisconnected\033[0m"; + } else if (err == ESP_ERR_WIFI_NOT_STARTED) { + return "\033[0;31mWi-Fi not started\033[0m"; + } else if (err != ESP_OK) { + return "\033[0;31m" + String(esp_err_to_name(err)) + "\033[0m"; } + + // Check IP address + esp_netif_ip_info_t ip_info; + err = esp_netif_get_ip_info(netif, &ip_info); + if (err == ESP_OK && ip_info.ip.addr != 0) { + static char ip_str[32]; + snprintf(ip_str, sizeof(ip_str), "\033[0;33m" IPSTR "\033[0m", IP2STR(&ip_info.ip)); + return ip_str; + } + + return "\033[0;31midle\033[0m"; } int counter; @@ -522,8 +532,8 @@ class Device { deviceConfig.model.get().c_str(), deviceConfig.instance.get().c_str(), deviceConfig.getHostname().c_str(), - WiFi.localIP().toString().c_str(), - WiFi.SSID().c_str(), + kernel.wifi.getIp().value_or("").c_str(), + kernel.wifi.getSsid().value_or("").c_str(), duration_cast(system_clock::now().time_since_epoch()).count()); } diff --git a/main/kernel/Kernel.hpp b/main/kernel/Kernel.hpp index 28be256c..6f1e5400 100644 --- a/main/kernel/Kernel.hpp +++ b/main/kernel/Kernel.hpp @@ -238,8 +238,6 @@ class Kernel { return "Network not ready, aborting update"; } - Log.info("WiFi connected: %s", WiFi.localIP().toString().c_str()); - // TODO Disable power save mode for WiFi esp_http_client_config_t httpConfig = { @@ -324,7 +322,10 @@ class Kernel { StateSource mqttReadyState = stateManager.createStateSource("mqtt-ready"); StateSource kernelReadyState = stateManager.createStateSource("kernel-ready"); +public: WiFiDriver wifi { networkRequestedState, networkReadyState, configPortalRunningState, deviceConfig.getHostname(), deviceConfig.sleepWhenIdle.get() }; + +private: MdnsDriver mdns { wifi, deviceConfig.getHostname(), "ugly-duckling", version, mdnsReadyState }; RtcDriver rtc { wifi, mdns, deviceConfig.ntp.get(), rtcInSyncState }; diff --git a/main/kernel/Strings.hpp b/main/kernel/Strings.hpp deleted file mode 100644 index 30bccb90..00000000 --- a/main/kernel/Strings.hpp +++ /dev/null @@ -1,28 +0,0 @@ -#pragma once - -#include - -namespace farmhub::kernel { - -class StringPrint : public Print { -public: - String buffer; - - virtual size_t write(uint8_t byte) { - buffer += (char) byte; - return 1; - } - - virtual size_t write(const uint8_t* buffer, size_t size) { - for (size_t i = 0; i < size; i++) { - write(buffer[i]); - } - return size; - } - - void clear() { - buffer = ""; - } -}; - -} // namespace farmhub::kernel diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index d2e7f2e3..08a17857 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -3,15 +3,12 @@ #include #include -#include -#include - +#include #include #include #include #include -#include #include using namespace std::chrono_literals; @@ -29,95 +26,143 @@ class WiFiDriver { , powerSaveMode(powerSaveMode) { Log.debug("WiFi: initializing"); - WiFi.begin(); - if (powerSaveMode) { - auto listenInterval = 50; - Log.debug("WiFi enabling power save mode, listen interval: %d", - listenInterval); - esp_wifi_set_ps(WIFI_PS_MAX_MODEM); - wifi_config_t conf; - ESP_ERROR_CHECK(esp_wifi_get_config(WIFI_IF_STA, &conf)); - conf.sta.listen_interval = listenInterval; - ESP_ERROR_CHECK(esp_wifi_set_config(WIFI_IF_STA, &conf)); - } - - WiFi.onEvent( - [](WiFiEvent_t event, WiFiEventInfo_t info) { - Log.debug("WiFi: connected to %s", - String(info.wifi_sta_connected.ssid, info.wifi_sta_connected.ssid_len).c_str()); - }, - ARDUINO_EVENT_WIFI_STA_CONNECTED); - WiFi.onEvent( - [this, &networkReady](WiFiEvent_t event, WiFiEventInfo_t info) { - Log.debug("WiFi: got IP %s, netmask %s, gateway %s", - IPAddress(info.got_ip.ip_info.ip.addr).toString().c_str(), - IPAddress(info.got_ip.ip_info.netmask.addr).toString().c_str(), - IPAddress(info.got_ip.ip_info.gw.addr).toString().c_str()); - networkReady.set(); - eventQueue.offer(WiFiEvent::CONNECTED); - }, - ARDUINO_EVENT_WIFI_STA_GOT_IP); - WiFi.onEvent( - [this, &networkReady](WiFiEvent_t event, WiFiEventInfo_t info) { - Log.debug("WiFi: lost IP address"); - networkReady.clear(); - eventQueue.offer(WiFiEvent::DISCONNECTED); - }, - ARDUINO_EVENT_WIFI_STA_LOST_IP); - WiFi.onEvent( - [this, &networkReady](WiFiEvent_t event, WiFiEventInfo_t info) { - Log.debug("WiFi: disconnected from %s, reason: %s", - String(info.wifi_sta_disconnected.ssid, info.wifi_sta_disconnected.ssid_len).c_str(), - WiFi.disconnectReasonName(static_cast(info.wifi_sta_disconnected.reason))); - networkReady.clear(); - eventQueue.offer(WiFiEvent::DISCONNECTED); - }, - ARDUINO_EVENT_WIFI_STA_DISCONNECTED); - WiFi.onEvent( - [&configPortalRunning](WiFiEvent_t event, WiFiEventInfo_t info) { - Log.debug("WiFi: provisioning started"); - configPortalRunning.set(); - }, - ARDUINO_EVENT_PROV_START); - WiFi.onEvent( - [](WiFiEvent_t event, WiFiEventInfo_t info) { - Log.debug("Received Wi-Fi credentials for SSID '%s'", - (const char*) info.prov_cred_recv.ssid); - }, - ARDUINO_EVENT_PROV_CRED_RECV); - WiFi.onEvent( - [](WiFiEvent_t event, WiFiEventInfo_t info) { - Log.debug("WiFi: provisioning failed because %s", - info.prov_fail_reason == NETWORK_PROV_WIFI_STA_AUTH_ERROR ? "authentication failed" : "AP not found"); - }, - ARDUINO_EVENT_PROV_CRED_FAIL); - WiFi.onEvent( - [](WiFiEvent_t event, WiFiEventInfo_t info) { - Log.debug("WiFi: provisioning successful"); - }, - ARDUINO_EVENT_PROV_CRED_SUCCESS); - WiFi.onEvent( - [&configPortalRunning](WiFiEvent_t event, WiFiEventInfo_t info) { - Log.debug("WiFi: provisioning finished"); - configPortalRunning.clear(); - }, - ARDUINO_EVENT_PROV_END); + // Initialize TCP/IP adapter and event loop + ESP_ERROR_CHECK(esp_netif_init()); + ESP_ERROR_CHECK(esp_event_loop_create_default()); + + // Create default WiFi station interface + esp_netif_create_default_wifi_sta(); + esp_netif_create_default_wifi_ap(); + + // Initialize WiFi + wifi_init_config_t cfg = WIFI_INIT_CONFIG_DEFAULT(); + ESP_ERROR_CHECK(esp_wifi_init(&cfg)); + ESP_ERROR_CHECK(esp_wifi_set_storage(WIFI_STORAGE_RAM)); + + // Register event handlers + ESP_ERROR_CHECK(esp_event_handler_register(WIFI_EVENT, ESP_EVENT_ANY_ID, &WiFiDriver::onWiFiEvent, this)); + ESP_ERROR_CHECK(esp_event_handler_register(IP_EVENT, ESP_EVENT_ANY_ID, &WiFiDriver::onIpEvent, this)); + + // TODO Rewrite provisioning + // WiFi.onEvent( + // [&configPortalRunning](WiFiEvent_t event, WiFiEventInfo_t info) { + // Log.debug("WiFi: provisioning started"); + // configPortalRunning.set(); + // }, + // ARDUINO_EVENT_PROV_START); + // WiFi.onEvent( + // [](WiFiEvent_t event, WiFiEventInfo_t info) { + // Log.debug("Received Wi-Fi credentials for SSID '%s'", + // (const char*) info.prov_cred_recv.ssid); + // }, + // ARDUINO_EVENT_PROV_CRED_RECV); + // WiFi.onEvent( + // [](WiFiEvent_t event, WiFiEventInfo_t info) { + // Log.debug("WiFi: provisioning failed because %s", + // info.prov_fail_reason == NETWORK_PROV_WIFI_STA_AUTH_ERROR ? "authentication failed" : "AP not found"); + // }, + // ARDUINO_EVENT_PROV_CRED_FAIL); + // WiFi.onEvent( + // [](WiFiEvent_t event, WiFiEventInfo_t info) { + // Log.debug("WiFi: provisioning successful"); + // }, + // ARDUINO_EVENT_PROV_CRED_SUCCESS); + // WiFi.onEvent( + // [&configPortalRunning](WiFiEvent_t event, WiFiEventInfo_t info) { + // Log.debug("WiFi: provisioning finished"); + // configPortalRunning.clear(); + // }, + // ARDUINO_EVENT_PROV_END); Task::run("wifi", 3072, [this](Task&) { runLoop(); }); } + std::optional getSsid() { + Lock lock(metadataMutex); + return ssid; + } + + std::optional getIp() { + Lock lock(metadataMutex); + return ip.transform([](const esp_ip4_addr_t& ip) { + char ipString[16]; + esp_ip4addr_ntoa(&ip, ipString, sizeof(ipString)); + return String(ipString); + }); + } + private: + // Event handler for WiFi events + static void onWiFiEvent(void* arg, esp_event_base_t eventBase, int32_t eventId, void* eventData) { + auto* driver = static_cast(arg); + switch (eventId) { + case WIFI_EVENT_STA_CONNECTED: { + auto event = static_cast(eventData); + String ssid(event->ssid, event->ssid_len); + { + Lock lock(driver->metadataMutex); + driver->ssid = ssid; + } + Log.debug("WiFi: Connected to the AP %s", + ssid.c_str()); + break; + } + case WIFI_EVENT_STA_DISCONNECTED: { + auto event = static_cast(eventData); + driver->networkReady.clear(); + driver->eventQueue.offer(WiFiEvent::DISCONNECTED); + { + Lock lock(driver->metadataMutex); + driver->ssid.reset(); + } + Log.debug("WiFi: Disconnected from the AP %s, reason: %d", + String(event->ssid, event->ssid_len).c_str(), event->reason); + break; + } + } + } + + // Event handler for IP events + static void onIpEvent(void* arg, esp_event_base_t eventBase, int32_t eventId, void* eventData) { + auto* driver = static_cast(arg); + switch (eventId) { + case IP_EVENT_STA_GOT_IP: { + auto* event = static_cast(eventData); + driver->networkReady.set(); + driver->eventQueue.offer(WiFiEvent::CONNECTED); + { + Lock lock(driver->metadataMutex); + driver->ip = event->ip_info.ip; + } + Log.debug("WiFi: Got IP - " IPSTR, IP2STR(&event->ip_info.ip)); + break; + } + case IP_EVENT_STA_LOST_IP: { + driver->networkReady.clear(); + driver->eventQueue.offer(WiFiEvent::DISCONNECTED); + { + Lock lock(driver->metadataMutex); + driver->ip.reset(); + } + Log.debug("WiFi: Lost IP"); + break; + } + } + } + inline void runLoop() { int clients = 0; + bool connected = false; while (true) { - auto event = eventQueue.pollIn(WIFI_CHECK_INTERVAL); - if (event.has_value()) { + for (auto event = eventQueue.pollIn(WIFI_CHECK_INTERVAL); event.has_value(); event = eventQueue.poll()) { switch (event.value()) { case WiFiEvent::CONNECTED: + connected = true; break; case WiFiEvent::DISCONNECTED: + connected = false; break; case WiFiEvent::WANTS_CONNECT: clients++; @@ -128,7 +173,6 @@ class WiFiDriver { } } - bool connected = WiFi.isConnected(); if (clients > 0) { networkRequested.set(); if (!connected && !configPortalRunning.isSet()) { @@ -146,43 +190,51 @@ class WiFiDriver { } void connect() { - // Print wifi status - Log.debug("WiFi status: %d", - WiFi.status()); #ifdef WOKWI Log.debug("Skipping WiFi provisioning on Wokwi"); - // Use Wokwi WiFi network - WiFi.begin("Wokwi-GUEST", "", 6); -#else - StringPrint qr; -// BLE Provisioning using the ESP SoftAP Prov works fine for any BLE SoC, including ESP32, ESP32S3 and ESP32C3. -#if CONFIG_BLUEDROID_ENABLED && !defined(USE_SOFT_AP) - Log.debug("Begin Provisioning using BLE"); - // Sample uuid that user can pass during provisioning using BLE - uint8_t uuid[16] = { 0xb4, 0xdf, 0x5a, 0x1c, 0x3f, 0x6b, 0xf4, 0xbf, 0xea, 0x4a, 0x82, 0x03, 0x04, 0x90, 0x1a, 0x02 }; - WiFiProv.beginProvision( - NETWORK_PROV_SCHEME_BLE, NETWORK_PROV_SCHEME_HANDLER_FREE_BLE, NETWORK_PROV_SECURITY_1, pop, hostname.c_str(), serviceKey, uuid, resetProvisioned); - WiFiProv.printQR(hostname.c_str(), pop, "ble", qr); + wifi_config_t wifi_config = { + .sta = { + .ssid = "Wokwi-GUEST", + .password = "", + .channel = 6 } + }; + + setWiFiMode(WIFI_MODE_STA, wifi_config); + ESP_ERROR_CHECK(esp_wifi_set_config(WIFI_IF_STA, &wifi_config)); + ESP_ERROR_CHECK(esp_wifi_start()); + ESP_ERROR_CHECK(esp_wifi_connect()); #else - Log.debug("Begin Provisioning using Soft AP"); - WiFiProv.beginProvision( - NETWORK_PROV_SCHEME_SOFTAP, NETWORK_PROV_SCHEME_HANDLER_NONE, NETWORK_PROV_SECURITY_1, pop, hostname.c_str(), serviceKey, nullptr, resetProvisioned); - WiFiProv.printQR(hostname.c_str(), pop, "softap", qr); -#endif - Log.debug("%s", - qr.buffer.c_str()); + // TODO Rewrite provisioning + // WiFiProv.beginProvision( + // NETWORK_PROV_SCHEME_SOFTAP, NETWORK_PROV_SCHEME_HANDLER_NONE, NETWORK_PROV_SECURITY_1, pop, hostname.c_str(), serviceKey, nullptr, resetProvisioned); + // WiFiProv.printQR(hostname.c_str(), pop, "softap", qr); + // Log.debug("%s", + // qr.buffer.c_str()); #endif } + // TODO This should probably be about setting STA only + void setWiFiMode(wifi_mode_t mode, wifi_config_t& config) { + ESP_ERROR_CHECK(esp_wifi_set_mode(mode)); + + if (powerSaveMode) { + auto listenInterval = 50; + Log.debug("WiFi enabling power save mode, listen interval: %d", + listenInterval); + ESP_ERROR_CHECK(esp_wifi_set_ps(WIFI_PS_MAX_MODEM)); + config.sta.listen_interval = listenInterval; + } + } + static constexpr const char* pop = "abcd1234"; static constexpr const char* serviceKey = nullptr; static constexpr const bool resetProvisioned = false; void disconnect() { networkReady.clear(); - if (!WiFi.disconnect(true)) { - Log.error("WiFi: failed to shut down"); - } + Log.debug("WiFi: Disconnecting"); + ESP_ERROR_CHECK(esp_wifi_disconnect()); + ESP_ERROR_CHECK(esp_wifi_stop()); } StateSource& acquire() { @@ -213,6 +265,10 @@ class WiFiDriver { static constexpr milliseconds WIFI_QUEUE_TIMEOUT = 1s; static constexpr milliseconds WIFI_CHECK_INTERVAL = 5s; + Mutex metadataMutex; + std::optional ssid; + std::optional ip; + friend class WiFiConnection; }; From 2160427017ee9ea642c0e8083fa01c4bf75da1fc Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sun, 1 Dec 2024 20:36:32 +0100 Subject: [PATCH 10/64] Remove now unnecessary HTTPUpdate library --- components/CMakeLists.txt | 4 ---- 1 file changed, 4 deletions(-) diff --git a/components/CMakeLists.txt b/components/CMakeLists.txt index 7367e96b..f43754ba 100644 --- a/components/CMakeLists.txt +++ b/components/CMakeLists.txt @@ -25,10 +25,6 @@ idf_component_register( SRCS "SHT2x/SHT2x.cpp" INCLUDE_DIRS "SHT2x" - SRCS "../managed_components/espressif__arduino-esp32/libraries/HTTPUpdate/src/HTTPUpdate.cpp" - INCLUDE_DIRS "../managed_components/espressif__arduino-esp32/libraries/HTTPUpdate/src" - REQUIRES app_update - REQUIRES "arduino-esp32" ) From 1d09e1e965578abfb8753b3007e0bbb65b84de9c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sun, 1 Dec 2024 20:37:29 +0100 Subject: [PATCH 11/64] Display WIFI info correctly on debug status bar --- main/devices/Device.hpp | 35 ++++++++++++++++++++++++++++------- 1 file changed, 28 insertions(+), 7 deletions(-) diff --git a/main/devices/Device.hpp b/main/devices/Device.hpp index 284890da..a5544c91 100644 --- a/main/devices/Device.hpp +++ b/main/devices/Device.hpp @@ -196,22 +196,43 @@ class ConsolePrinter { private: static String wifiStatus() { - esp_netif_t* netif = esp_netif_get_handle_from_ifkey("WIFI_AP_DEF"); + auto netif = esp_netif_get_default_netif(); if (!netif) { return "\033[0;31moff\033[0m"; } + wifi_mode_t mode; + ESP_ERROR_CHECK(esp_wifi_get_mode(&mode)); + + switch (mode) { + case WIFI_MODE_STA: + break; + case WIFI_MODE_NULL: + return "\033[0;31moff\033[0m"; + case WIFI_MODE_AP: + return "\033[0;32mAP\033[0m"; + case WIFI_MODE_APSTA: + return "\033[0;32mAPSTA\033[0m"; + default: + return "\033[0;31munknown mode\033[0m"; + } + // Retrieve the current Wi-Fi station connection status wifi_ap_record_t ap_info; esp_err_t err = esp_wifi_sta_get_ap_info(&ap_info); // TODO Handle ESP_ERR_WIFI_CONN, or better yet, use `WiFiDriver` directly - if (err == ESP_ERR_WIFI_NOT_CONNECT) { - return "\033[0;33mdisconnected\033[0m"; - } else if (err == ESP_ERR_WIFI_NOT_STARTED) { - return "\033[0;31mWi-Fi not started\033[0m"; - } else if (err != ESP_OK) { - return "\033[0;31m" + String(esp_err_to_name(err)) + "\033[0m"; + switch (err) { + case ESP_OK: + break; + case ESP_ERR_WIFI_CONN: + return "\033[0;32mconnection-error\033[0m"; + case ESP_ERR_WIFI_NOT_CONNECT: + return "\033[0;33mdisconnected\033[0m"; + case ESP_ERR_WIFI_NOT_STARTED: + return "\033[0;31mWi-Fi not started\033[0m"; + default: + return "\033[0;31m" + String(esp_err_to_name(err)) + "\033[0m"; } // Check IP address From d60559d56f19043079fb292dfe1e69768b05845b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Sun, 1 Dec 2024 20:55:30 +0100 Subject: [PATCH 12/64] Do not report missing fiels from struct initializers --- main/kernel/PcntManager.hpp | 2 -- main/kernel/SleepManager.hpp | 2 +- main/kernel/drivers/WiFiDriver.hpp | 3 ++- main/main.cpp | 2 +- 4 files changed, 4 insertions(+), 5 deletions(-) diff --git a/main/kernel/PcntManager.hpp b/main/kernel/PcntManager.hpp index 7157164d..f1e1f732 100644 --- a/main/kernel/PcntManager.hpp +++ b/main/kernel/PcntManager.hpp @@ -64,7 +64,6 @@ class PcntManager { .low_limit = std::numeric_limits::min(), .high_limit = std::numeric_limits::max(), .intr_priority = 0, - .flags = {}, }; pcnt_unit_handle_t unit = nullptr; ESP_ERROR_CHECK(pcnt_new_unit(&unitConfig, &unit)); @@ -77,7 +76,6 @@ class PcntManager { pcnt_chan_config_t channelConfig = { .edge_gpio_num = pin->getGpio(), .level_gpio_num = -1, - .flags = {}, }; pcnt_channel_handle_t channel = nullptr; ESP_ERROR_CHECK(pcnt_new_channel(unit, &channelConfig, &channel)); diff --git a/main/kernel/SleepManager.hpp b/main/kernel/SleepManager.hpp index 4925d360..61a393f8 100644 --- a/main/kernel/SleepManager.hpp +++ b/main/kernel/SleepManager.hpp @@ -89,7 +89,7 @@ class SleepManager { esp_pm_config_t pm_config = { .max_freq_mhz = MAX_CPU_FREQ_MHZ, .min_freq_mhz = MIN_CPU_FREQ_MHZ, - .light_sleep_enable = enableLightSleep + .light_sleep_enable = enableLightSleep, }; ESP_ERROR_CHECK(esp_pm_configure(&pm_config)); } diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index 08a17857..0deec700 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -196,7 +196,8 @@ class WiFiDriver { .sta = { .ssid = "Wokwi-GUEST", .password = "", - .channel = 6 } + .channel = 6, + } }; setWiFiMode(WIFI_MODE_STA, wifi_config); diff --git a/main/main.cpp b/main/main.cpp index 5f4a7caf..781d7b34 100644 --- a/main/main.cpp +++ b/main/main.cpp @@ -47,7 +47,7 @@ static void dumpPerTaskHeapInfo() { .num_totals = &s_prepopulated_num, .max_totals = MAX_TASK_NUM, .blocks = s_block_arr, - .max_blocks = MAX_BLOCK_NUM + .max_blocks = MAX_BLOCK_NUM, }; heap_caps_get_per_task_info(&heapInfo); From 1cd24f34c5636085bac78cc3543ab59121232322 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 10:18:56 +0100 Subject: [PATCH 13/64] Track WOKWI as a build input --- main/CMakeLists.txt | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/main/CMakeLists.txt b/main/CMakeLists.txt index a4b253a0..85e06559 100644 --- a/main/CMakeLists.txt +++ b/main/CMakeLists.txt @@ -12,8 +12,9 @@ if(NOT DEFINED WOKWI) set(WOKWI "$ENV{WOKWI}") endif() -# Make sure we reconfigure if UD_DEBUG changes +# Make sure we reconfigure if parameters change set_property(DIRECTORY PROPERTY UD_DEBUG_TRACKER "${UD_DEBUG}") +set_property(DIRECTORY PROPERTY WOKWI_TRACKER "${WOKWI}") idf_component_register( SRCS ${app_sources} From a8a05aa3e3d163ec30f060cd128c864780f43f3c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 10:20:11 +0100 Subject: [PATCH 14/64] Do not report missing fields from struct initializers --- CMakeLists.txt | 3 +++ 1 file changed, 3 insertions(+) diff --git a/CMakeLists.txt b/CMakeLists.txt index 9d0d4a79..dba13fb7 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -44,6 +44,9 @@ if(UD_GEN STREQUAL MK4) add_compile_definitions(HWCDCSerial=Serial0) endif() +# Keep struct initializers simple +add_compile_options("-Wno-missing-field-initializers") + project(ugly-duckling) # Use `idf.py -DFSUPLOAD=1 flash` to upload the data partition From 2133b1e364b77134e9777642c386163c4fd64075 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 10:20:30 +0100 Subject: [PATCH 15/64] Properly handle mDNS results --- main/kernel/drivers/MdnsDriver.hpp | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/main/kernel/drivers/MdnsDriver.hpp b/main/kernel/drivers/MdnsDriver.hpp index c12fb775..3ea6403f 100644 --- a/main/kernel/drivers/MdnsDriver.hpp +++ b/main/kernel/drivers/MdnsDriver.hpp @@ -100,8 +100,10 @@ class MdnsDriver { return false; } - auto& result = results[0]; - record.hostname = result.hostname; + auto& result = *results; + if (result.hostname != nullptr) { + record.hostname = result.hostname; + } record.ip = IPAddress(result.addr->addr.u_addr.ip4.addr); record.port = result.port; mdns_query_results_free(results); From d6f38e4a541ebfb3b5261b6880d0c1adc63763ea Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 10:20:45 +0100 Subject: [PATCH 16/64] Handle MQTT server lookup properly --- main/kernel/drivers/MqttDriver.hpp | 46 ++++++++++++++++++------------ 1 file changed, 28 insertions(+), 18 deletions(-) diff --git a/main/kernel/drivers/MqttDriver.hpp b/main/kernel/drivers/MqttDriver.hpp index 687acacb..0253ac81 100644 --- a/main/kernel/drivers/MqttDriver.hpp +++ b/main/kernel/drivers/MqttDriver.hpp @@ -370,37 +370,47 @@ class MqttDriver { String clientCert; String clientKey; - esp_mqtt_client_config_t mqttConfig = {}; - mqttConfig.network.timeout_ms = duration_cast(10s).count(); #ifdef WOKWI - mqttConfig.broker.address.transport = MQTT_TRANSPORT_OVER_TCP; - mqttConfig.broker.address.hostname = "host.wokwi.internal"; - mqttConfig.broker.address.port = 1883; + esp_mqtt_client_config_t mqttConfig = { + .broker { + .address { + .hostname = "host.wokwi.internal", + .transport = MQTT_TRANSPORT_OVER_TCP, + .port = 1883, + }, + } + }; #else + MdnsRecord mqttServer; if (config.host.get().length() > 0) { - mqttConfig.broker.address.hostname = config.host.get().c_str(); - mqttConfig.broker.address.port = config.port.get(); + mqttServer.hostname = config.host.get(); + mqttServer.port = config.port.get(); if (config.serverCert.hasValue()) { - mqttConfig.broker.address.transport = MQTT_TRANSPORT_OVER_SSL; serverCert = joinStrings(config.serverCert.get()); clientCert = joinStrings(config.clientCert.get()); clientKey = joinStrings(config.clientKey.get()); - } else { - mqttConfig.broker.address.transport = MQTT_TRANSPORT_OVER_TCP; } } else { // TODO Handle lookup failure - MdnsRecord mqttServer; mdns.lookupService("mqtt", "tcp", mqttServer, trustMdnsCache); - mqttConfig.broker.address.transport = MQTT_TRANSPORT_OVER_TCP; - if (mqttServer.ip == IPAddress()) { - mqttConfig.broker.address.hostname = mqttServer.hostname.c_str(); - } else { - mqttConfig.broker.address.hostname = mqttServer.ip.toString().c_str(); - } - mqttConfig.broker.address.port = mqttServer.port; } + + String hostname = mqttServer.ip == IPAddress() + ? mqttServer.hostname + : mqttServer.ip.toString(); + auto transport = serverCert.isEmpty() ? MQTT_TRANSPORT_OVER_TCP : MQTT_TRANSPORT_OVER_SSL; + esp_mqtt_client_config_t mqttConfig = { + .broker { + .address { + .hostname = hostname.c_str(), + .transport = transport, + .port = static_cast(mqttServer.port), + }, + } + }; #endif + mqttConfig.network.timeout_ms = duration_cast(10s).count(); + Log.debug("MQTT: server: %s:%ld, client ID is '%s'", mqttConfig.broker.address.hostname, mqttConfig.broker.address.port, clientId.c_str()); From 752cc0ba31ef0eb51b6dcc9006a090f7d40ed2c4 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 10:50:12 +0100 Subject: [PATCH 17/64] Connect to WiFi using stored credentials --- main/kernel/drivers/WiFiDriver.hpp | 47 ++++++++++++++++++------------ 1 file changed, 29 insertions(+), 18 deletions(-) diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index 0deec700..0f7f9b3d 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -98,6 +98,11 @@ class WiFiDriver { static void onWiFiEvent(void* arg, esp_event_base_t eventBase, int32_t eventId, void* eventData) { auto* driver = static_cast(arg); switch (eventId) { + case WIFI_EVENT_STA_START: { + Log.debug("WiFi: Started"); + ESP_ERROR_CHECK(esp_wifi_connect()); + break; + } case WIFI_EVENT_STA_CONNECTED: { auto event = static_cast(eventData); String ssid(event->ssid, event->ssid_len); @@ -191,40 +196,46 @@ class WiFiDriver { void connect() { #ifdef WOKWI - Log.debug("Skipping WiFi provisioning on Wokwi"); - wifi_config_t wifi_config = { + Log.debug("WiFi: Skipping provisioning on Wokwi"); + wifi_config_t wifiConfig = { .sta = { .ssid = "Wokwi-GUEST", .password = "", .channel = 6, } }; - - setWiFiMode(WIFI_MODE_STA, wifi_config); - ESP_ERROR_CHECK(esp_wifi_set_config(WIFI_IF_STA, &wifi_config)); - ESP_ERROR_CHECK(esp_wifi_start()); - ESP_ERROR_CHECK(esp_wifi_connect()); + startStation(wifiConfig); #else - // TODO Rewrite provisioning - // WiFiProv.beginProvision( - // NETWORK_PROV_SCHEME_SOFTAP, NETWORK_PROV_SCHEME_HANDLER_NONE, NETWORK_PROV_SECURITY_1, pop, hostname.c_str(), serviceKey, nullptr, resetProvisioned); - // WiFiProv.printQR(hostname.c_str(), pop, "softap", qr); - // Log.debug("%s", - // qr.buffer.c_str()); + // TODO Maybe use wifi_prov_mgr_is_provisioned() to check if we have been + wifi_config_t wifiConfig; + ESP_ERROR_CHECK(esp_wifi_get_config(WIFI_IF_STA, &wifiConfig)); + if (strlen((const char*) wifiConfig.sta.ssid)) { + Log.debug("WiFi: Connecting using stored credentials to %s", + wifiConfig.sta.ssid); + startStation(wifiConfig); + } else { + // TODO Rewrite provisioning + // WiFiProv.beginProvision( + // NETWORK_PROV_SCHEME_SOFTAP, NETWORK_PROV_SCHEME_HANDLER_NONE, NETWORK_PROV_SECURITY_1, pop, hostname.c_str(), serviceKey, nullptr, resetProvisioned); + // WiFiProv.printQR(hostname.c_str(), pop, "softap", qr); + // Log.debug("%s", + // qr.buffer.c_str()); + } #endif } - // TODO This should probably be about setting STA only - void setWiFiMode(wifi_mode_t mode, wifi_config_t& config) { - ESP_ERROR_CHECK(esp_wifi_set_mode(mode)); - + void startStation(wifi_config_t& config) { if (powerSaveMode) { auto listenInterval = 50; - Log.debug("WiFi enabling power save mode, listen interval: %d", + Log.trace("WiFi enabling power save mode, listen interval: %d", listenInterval); ESP_ERROR_CHECK(esp_wifi_set_ps(WIFI_PS_MAX_MODEM)); config.sta.listen_interval = listenInterval; } + + ESP_ERROR_CHECK(esp_wifi_set_mode(WIFI_MODE_STA)); + ESP_ERROR_CHECK(esp_wifi_set_config(WIFI_IF_STA, &config)); + ESP_ERROR_CHECK(esp_wifi_start()); } static constexpr const char* pop = "abcd1234"; From ae8321191a0a03a7f693781218a16d4255cad864 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 10:58:13 +0100 Subject: [PATCH 18/64] Simplify WiFiDriver event handling --- main/kernel/drivers/WiFiDriver.hpp | 51 ++++++++++++++++-------------- 1 file changed, 28 insertions(+), 23 deletions(-) diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index 0f7f9b3d..33b1d16e 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -40,8 +40,8 @@ class WiFiDriver { ESP_ERROR_CHECK(esp_wifi_set_storage(WIFI_STORAGE_RAM)); // Register event handlers - ESP_ERROR_CHECK(esp_event_handler_register(WIFI_EVENT, ESP_EVENT_ANY_ID, &WiFiDriver::onWiFiEvent, this)); - ESP_ERROR_CHECK(esp_event_handler_register(IP_EVENT, ESP_EVENT_ANY_ID, &WiFiDriver::onIpEvent, this)); + ESP_ERROR_CHECK(esp_event_handler_register(WIFI_EVENT, ESP_EVENT_ANY_ID, &WiFiDriver::onEvent, this)); + ESP_ERROR_CHECK(esp_event_handler_register(IP_EVENT, ESP_EVENT_ANY_ID, &WiFiDriver::onEvent, this)); // TODO Rewrite provisioning // WiFi.onEvent( @@ -94,9 +94,16 @@ class WiFiDriver { } private: - // Event handler for WiFi events - static void onWiFiEvent(void* arg, esp_event_base_t eventBase, int32_t eventId, void* eventData) { + static void onEvent(void* arg, esp_event_base_t eventBase, int32_t eventId, void* eventData) { auto* driver = static_cast(arg); + if (eventBase == WIFI_EVENT) { + driver->onWiFiEvent(eventId, eventData); + } else if (eventBase == IP_EVENT) { + driver->onIpEvent(eventId, eventData); + } + } + + void onWiFiEvent(int32_t eventId, void* eventData) { switch (eventId) { case WIFI_EVENT_STA_START: { Log.debug("WiFi: Started"); @@ -105,22 +112,22 @@ class WiFiDriver { } case WIFI_EVENT_STA_CONNECTED: { auto event = static_cast(eventData); - String ssid(event->ssid, event->ssid_len); + String newSsid(event->ssid, event->ssid_len); { - Lock lock(driver->metadataMutex); - driver->ssid = ssid; + Lock lock(metadataMutex); + ssid = newSsid; } Log.debug("WiFi: Connected to the AP %s", - ssid.c_str()); + newSsid.c_str()); break; } case WIFI_EVENT_STA_DISCONNECTED: { auto event = static_cast(eventData); - driver->networkReady.clear(); - driver->eventQueue.offer(WiFiEvent::DISCONNECTED); + networkReady.clear(); + eventQueue.offer(WiFiEvent::DISCONNECTED); { - Lock lock(driver->metadataMutex); - driver->ssid.reset(); + Lock lock(metadataMutex); + ssid.reset(); } Log.debug("WiFi: Disconnected from the AP %s, reason: %d", String(event->ssid, event->ssid_len).c_str(), event->reason); @@ -129,27 +136,25 @@ class WiFiDriver { } } - // Event handler for IP events - static void onIpEvent(void* arg, esp_event_base_t eventBase, int32_t eventId, void* eventData) { - auto* driver = static_cast(arg); + void onIpEvent(int32_t eventId, void* eventData) { switch (eventId) { case IP_EVENT_STA_GOT_IP: { auto* event = static_cast(eventData); - driver->networkReady.set(); - driver->eventQueue.offer(WiFiEvent::CONNECTED); + networkReady.set(); + eventQueue.offer(WiFiEvent::CONNECTED); { - Lock lock(driver->metadataMutex); - driver->ip = event->ip_info.ip; + Lock lock(metadataMutex); + ip = event->ip_info.ip; } Log.debug("WiFi: Got IP - " IPSTR, IP2STR(&event->ip_info.ip)); break; } case IP_EVENT_STA_LOST_IP: { - driver->networkReady.clear(); - driver->eventQueue.offer(WiFiEvent::DISCONNECTED); + networkReady.clear(); + eventQueue.offer(WiFiEvent::DISCONNECTED); { - Lock lock(driver->metadataMutex); - driver->ip.reset(); + Lock lock(metadataMutex); + ip.reset(); } Log.debug("WiFi: Lost IP"); break; From d723a400ca788b780ef44d330b3c349ab71d1e5c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 12:19:02 +0100 Subject: [PATCH 19/64] Polis NTP sync --- main/kernel/drivers/RtcDriver.hpp | 30 ++++++++++++++++-------------- 1 file changed, 16 insertions(+), 14 deletions(-) diff --git a/main/kernel/drivers/RtcDriver.hpp b/main/kernel/drivers/RtcDriver.hpp index 3167a0ef..4f72e3d5 100644 --- a/main/kernel/drivers/RtcDriver.hpp +++ b/main/kernel/drivers/RtcDriver.hpp @@ -93,37 +93,39 @@ class RtcDriver { #else // TODO Check this if (ntpConfig.host.get().length() > 0) { - Log.info("RTC: using NTP server %s from configuration", + Log.debug("RTC: using NTP server %s from configuration", ntpConfig.host.get().c_str()); esp_sntp_setservername(0, ntpConfig.host.get().c_str()); } else { MdnsRecord ntpServer; if (mdns.lookupService("ntp", "udp", ntpServer, trustMdnsCache)) { - Log.info("RTC: using NTP server %s:%d (%s) from mDNS", + Log.debug("RTC: using NTP server %s:%d (%s) from mDNS", ntpServer.hostname.c_str(), ntpServer.port, ntpServer.ip.toString().c_str()); auto serverIp = convertIp4(ntpServer.ip); esp_sntp_setserver(0, &serverIp); } else { - Log.info("RTC: no NTP server configured, using default"); + Log.debug("RTC: no NTP server configured, using default"); } } #endif - ESP_ERROR_CHECK(esp_netif_sntp_start()); - printServers(); bool success = false; - for (int retry = 0; retry < 10; retry++) { - auto ret = esp_netif_sntp_sync_wait(ticks(10s).count()); - if (ret == ESP_OK) { - success = true; - rtcInSync.set(); - break; - } else { - Log.info("RTC: waiting for time sync returned %d, retry #%d", ret, retry); - } + ESP_ERROR_CHECK(esp_netif_sntp_start()); + + auto ret = esp_netif_sntp_sync_wait(ticks(10s).count()); + // It's okay to assume RTC is _roughly_ in sync even if + // we're not yet finished with smooth sync + if (ret == ESP_OK || ret == ESP_ERR_NOT_FINISHED) { + rtcInSync.set(); + success = true; + Log.debug("RTC: sync finished successfully"); + } else if (ret == ESP_ERR_TIMEOUT) { + Log.debug("RTC: waiting for time sync timed out"); + } else { + Log.debug("RTC: waiting for time sync returned 0x%x", ret); } esp_netif_sntp_deinit(); From 5ff84ece9489d46a46790f95d5954ed1566a7a4a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 12:19:22 +0100 Subject: [PATCH 20/64] Enable WiFi provisioning --- main/kernel/drivers/WiFiDriver.hpp | 127 +++++++++++++++++++---------- 1 file changed, 85 insertions(+), 42 deletions(-) diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index 33b1d16e..c60184fb 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -5,6 +5,8 @@ #include #include +#include +#include #include #include @@ -42,37 +44,7 @@ class WiFiDriver { // Register event handlers ESP_ERROR_CHECK(esp_event_handler_register(WIFI_EVENT, ESP_EVENT_ANY_ID, &WiFiDriver::onEvent, this)); ESP_ERROR_CHECK(esp_event_handler_register(IP_EVENT, ESP_EVENT_ANY_ID, &WiFiDriver::onEvent, this)); - - // TODO Rewrite provisioning - // WiFi.onEvent( - // [&configPortalRunning](WiFiEvent_t event, WiFiEventInfo_t info) { - // Log.debug("WiFi: provisioning started"); - // configPortalRunning.set(); - // }, - // ARDUINO_EVENT_PROV_START); - // WiFi.onEvent( - // [](WiFiEvent_t event, WiFiEventInfo_t info) { - // Log.debug("Received Wi-Fi credentials for SSID '%s'", - // (const char*) info.prov_cred_recv.ssid); - // }, - // ARDUINO_EVENT_PROV_CRED_RECV); - // WiFi.onEvent( - // [](WiFiEvent_t event, WiFiEventInfo_t info) { - // Log.debug("WiFi: provisioning failed because %s", - // info.prov_fail_reason == NETWORK_PROV_WIFI_STA_AUTH_ERROR ? "authentication failed" : "AP not found"); - // }, - // ARDUINO_EVENT_PROV_CRED_FAIL); - // WiFi.onEvent( - // [](WiFiEvent_t event, WiFiEventInfo_t info) { - // Log.debug("WiFi: provisioning successful"); - // }, - // ARDUINO_EVENT_PROV_CRED_SUCCESS); - // WiFi.onEvent( - // [&configPortalRunning](WiFiEvent_t event, WiFiEventInfo_t info) { - // Log.debug("WiFi: provisioning finished"); - // configPortalRunning.clear(); - // }, - // ARDUINO_EVENT_PROV_END); + ESP_ERROR_CHECK(esp_event_handler_register(WIFI_PROV_EVENT, ESP_EVENT_ANY_ID, &WiFiDriver::onEvent, this)); Task::run("wifi", 3072, [this](Task&) { runLoop(); @@ -100,6 +72,8 @@ class WiFiDriver { driver->onWiFiEvent(eventId, eventData); } else if (eventBase == IP_EVENT) { driver->onIpEvent(eventId, eventData); + } else if (eventBase == WIFI_PROV_EVENT) { + driver->onWiFiProvEvent(eventId, eventData); } } @@ -107,7 +81,14 @@ class WiFiDriver { switch (eventId) { case WIFI_EVENT_STA_START: { Log.debug("WiFi: Started"); - ESP_ERROR_CHECK(esp_wifi_connect()); + esp_err_t err = esp_wifi_connect(); + if (err != ESP_OK) { + Log.debug("WiFi: Failed to start connecting: %s", esp_err_to_name(err)); + } + break; + } + case WIFI_EVENT_STA_STOP: { + Log.debug("WiFi: Stopped"); break; } case WIFI_EVENT_STA_CONNECTED: { @@ -133,6 +114,14 @@ class WiFiDriver { String(event->ssid, event->ssid_len).c_str(), event->reason); break; } + case WIFI_EVENT_AP_STACONNECTED: { + Log.info("WiFi: SoftAP transport connected"); + break; + } + case WIFI_EVENT_AP_STADISCONNECTED: { + Log.info("WiFi: SoftAP transport disconnected"); + break; + } } } @@ -162,6 +151,39 @@ class WiFiDriver { } } + void onWiFiProvEvent(int32_t eventId, void* eventData) { + switch (eventId) { + case WIFI_PROV_START: { + Log.debug("WiFi: provisioning started"); + // configPortalRunning.set(); + break; + } + case WIFI_PROV_CRED_RECV: { + auto wifiConfig = static_cast(eventData); + Log.debug("Received Wi-Fi credentials for SSID '%s'", + (const char*) wifiConfig->ssid); + break; + } + case WIFI_PROV_CRED_FAIL: { + auto* reason = static_cast(eventData); + Log.debug("WiFi: provisioning failed because %s", + *reason == WIFI_PROV_STA_AUTH_ERROR + ? "authentication failed" + : "AP not found"); + break; + } + case WIFI_PROV_CRED_SUCCESS: { + Log.debug("WiFi: provisioning successful"); + break; + } + case WIFI_PROV_END: { + Log.debug("WiFi: provisioning finished"); + configPortalRunning.clear(); + break; + } + } + } + inline void runLoop() { int clients = 0; bool connected = false; @@ -211,20 +233,19 @@ class WiFiDriver { }; startStation(wifiConfig); #else - // TODO Maybe use wifi_prov_mgr_is_provisioned() to check if we have been - wifi_config_t wifiConfig; - ESP_ERROR_CHECK(esp_wifi_get_config(WIFI_IF_STA, &wifiConfig)); - if (strlen((const char*) wifiConfig.sta.ssid)) { + bool provisioned = false; + ESP_ERROR_CHECK(wifi_prov_mgr_is_provisioned(&provisioned)); + if (provisioned) { + wifi_config_t wifiConfig; + ESP_ERROR_CHECK(esp_wifi_get_config(WIFI_IF_STA, &wifiConfig)); Log.debug("WiFi: Connecting using stored credentials to %s", wifiConfig.sta.ssid); startStation(wifiConfig); } else { - // TODO Rewrite provisioning - // WiFiProv.beginProvision( - // NETWORK_PROV_SCHEME_SOFTAP, NETWORK_PROV_SCHEME_HANDLER_NONE, NETWORK_PROV_SECURITY_1, pop, hostname.c_str(), serviceKey, nullptr, resetProvisioned); - // WiFiProv.printQR(hostname.c_str(), pop, "softap", qr); - // Log.debug("%s", - // qr.buffer.c_str()); + if (!configPortalRunning.isSet()) { + configPortalRunning.set(); + startProvisioning(); + } } #endif } @@ -243,6 +264,28 @@ class WiFiDriver { ESP_ERROR_CHECK(esp_wifi_start()); } + void startProvisioning() { + // Initialize provisioning manager + wifi_prov_mgr_config_t config = { + .scheme = wifi_prov_scheme_softap, + .scheme_event_handler = WIFI_PROV_EVENT_HANDLER_NONE + }; + ESP_ERROR_CHECK(wifi_prov_mgr_init(config)); + + char serviceName[32]; + uint8_t mac[6]; + const char* ssid_prefix = "PROV_"; + esp_wifi_get_mac(WIFI_IF_STA, mac); + snprintf(serviceName, sizeof(serviceName), "%s%02X%02X%02X", + ssid_prefix, mac[3], mac[4], mac[5]); + Log.debug("WiFi: Starting provisioning service '%s'", + serviceName); + + ESP_ERROR_CHECK(wifi_prov_mgr_start_provisioning(WIFI_PROV_SECURITY_1, pop, serviceName, serviceKey)); + + // TODO Maybe print QR code? + } + static constexpr const char* pop = "abcd1234"; static constexpr const char* serviceKey = nullptr; static constexpr const bool resetProvisioned = false; From 2c7f4a8bf10b7086a559e0f71f7196370eace484 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 14:03:40 +0100 Subject: [PATCH 21/64] Restart provisioning on failed credentials --- main/kernel/drivers/WiFiDriver.hpp | 1 + 1 file changed, 1 insertion(+) diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index c60184fb..efea232f 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -170,6 +170,7 @@ class WiFiDriver { *reason == WIFI_PROV_STA_AUTH_ERROR ? "authentication failed" : "AP not found"); + ESP_ERROR_CHECK(wifi_prov_mgr_reset_sm_state_on_failure()); break; } case WIFI_PROV_CRED_SUCCESS: { From fe350775df14a2d7c66ecf954117c11b29509d55 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 14:11:36 +0100 Subject: [PATCH 22/64] Keep WiFi on while provisioning finishes --- main/kernel/drivers/WiFiDriver.hpp | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index efea232f..3f170fa9 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -155,7 +155,8 @@ class WiFiDriver { switch (eventId) { case WIFI_PROV_START: { Log.debug("WiFi: provisioning started"); - // configPortalRunning.set(); + // Do not turn WiFi off until provisioning finishes + acquire(); break; } case WIFI_PROV_CRED_RECV: { @@ -180,6 +181,7 @@ class WiFiDriver { case WIFI_PROV_END: { Log.debug("WiFi: provisioning finished"); configPortalRunning.clear(); + release(); break; } } From fb934d951d78d3d9f08b4f9f1b74bae368240c92 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 14:16:51 +0100 Subject: [PATCH 23/64] De-init WiFi provisioning once finished --- main/kernel/drivers/WiFiDriver.hpp | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index 3f170fa9..4898b777 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -180,6 +180,7 @@ class WiFiDriver { } case WIFI_PROV_END: { Log.debug("WiFi: provisioning finished"); + wifi_prov_mgr_deinit(); configPortalRunning.clear(); release(); break; @@ -246,8 +247,11 @@ class WiFiDriver { startStation(wifiConfig); } else { if (!configPortalRunning.isSet()) { + Log.debug("WiFi: No stored credentials, starting provisioning"); configPortalRunning.set(); startProvisioning(); + } else { + Log.trace("WiFi: Provisioning already running"); } } #endif From 9a3c1067b959702529f9265a21b461cd38cec3d6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 14:22:57 +0100 Subject: [PATCH 24/64] Set MQTT client ID --- main/kernel/drivers/MqttDriver.hpp | 1 + 1 file changed, 1 insertion(+) diff --git a/main/kernel/drivers/MqttDriver.hpp b/main/kernel/drivers/MqttDriver.hpp index 0253ac81..cf542e56 100644 --- a/main/kernel/drivers/MqttDriver.hpp +++ b/main/kernel/drivers/MqttDriver.hpp @@ -410,6 +410,7 @@ class MqttDriver { }; #endif mqttConfig.network.timeout_ms = duration_cast(10s).count(); + mqttConfig.credentials.client_id = clientId.c_str(); Log.debug("MQTT: server: %s:%ld, client ID is '%s'", mqttConfig.broker.address.hostname, mqttConfig.broker.address.port, clientId.c_str()); From e1a56ff7191b4a7ba80ef644e6235b41230a22e9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 16:00:01 +0100 Subject: [PATCH 25/64] Do a debug build --- CMakeLists.txt | 3 +++ 1 file changed, 3 insertions(+) diff --git a/CMakeLists.txt b/CMakeLists.txt index dba13fb7..eb03bd8f 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -47,6 +47,9 @@ endif() # Keep struct initializers simple add_compile_options("-Wno-missing-field-initializers") +# TODO Make this depend on some flag +set(CMAKE_BUILD_TYPE Debug) + project(ugly-duckling) # Use `idf.py -DFSUPLOAD=1 flash` to upload the data partition From 4d96ca8fbd9159f25e6e553685822d4cd285d1d8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 16:34:56 +0100 Subject: [PATCH 26/64] Handle MQTTS connections --- main/kernel/drivers/MqttDriver.hpp | 124 ++++++++++++++++------------- 1 file changed, 67 insertions(+), 57 deletions(-) diff --git a/main/kernel/drivers/MqttDriver.hpp b/main/kernel/drivers/MqttDriver.hpp index cf542e56..1abdde3e 100644 --- a/main/kernel/drivers/MqttDriver.hpp +++ b/main/kernel/drivers/MqttDriver.hpp @@ -199,10 +199,16 @@ class MqttDriver { StateSource& mqttReady) : wifi(wifi) , mdns(mdns) - , config(config) + , configHostname(config.host.get()) + , configPort(config.port.get()) + , configServerCert(joinStrings(config.serverCert.get())) + , configClientCert(joinStrings(config.clientCert.get())) + , configClientKey(joinStrings(config.clientKey.get())) , clientId(getClientId(config.clientId.get(), instanceName)) , powerSaveMode(powerSaveMode) - , mqttReady(mqttReady) { + , mqttReady(mqttReady) + , outgoingQueue("mqtt-outgoing", config.queueSize.get()) + , incomingQueue("mqtt-incoming", config.queueSize.get()) { Task::run("mqtt", 5120, [this](Task& task) { runEventLoop(task); @@ -366,76 +372,74 @@ class MqttDriver { Log.debug("MQTT: Connecting to MQTT server"); if (client == nullptr) { - String serverCert; - String clientCert; - String clientKey; - + String hostname; + uint32_t port; + if (configHostname.isEmpty()) { #ifdef WOKWI - esp_mqtt_client_config_t mqttConfig = { - .broker { - .address { - .hostname = "host.wokwi.internal", - .transport = MQTT_TRANSPORT_OVER_TCP, - .port = 1883, - }, - } - }; + hostname = "host.wokwi.internal"; + port = 1883; #else - MdnsRecord mqttServer; - if (config.host.get().length() > 0) { - mqttServer.hostname = config.host.get(); - mqttServer.port = config.port.get(); - if (config.serverCert.hasValue()) { - serverCert = joinStrings(config.serverCert.get()); - clientCert = joinStrings(config.clientCert.get()); - clientKey = joinStrings(config.clientKey.get()); + MdnsRecord mqttServer; + if (!mdns.lookupService("mqtt", "tcp", mqttServer, trustMdnsCache)) { + Log.error("MQTT: Failed to lookup MQTT server"); + return false; } + hostname = mqttServer.ip == IPAddress() + ? mqttServer.hostname + : mqttServer.ip.toString(); + port = mqttServer.port; +#endif } else { - // TODO Handle lookup failure - mdns.lookupService("mqtt", "tcp", mqttServer, trustMdnsCache); + hostname = configHostname; + port = configPort; } - String hostname = mqttServer.ip == IPAddress() - ? mqttServer.hostname - : mqttServer.ip.toString(); - auto transport = serverCert.isEmpty() ? MQTT_TRANSPORT_OVER_TCP : MQTT_TRANSPORT_OVER_SSL; - esp_mqtt_client_config_t mqttConfig = { + esp_mqtt_client_config_t config = { .broker { .address { .hostname = hostname.c_str(), - .transport = transport, - .port = static_cast(mqttServer.port), + .port = port, }, - } + }, + .credentials { + .client_id = clientId.c_str(), + }, + .network { + .timeout_ms = duration_cast(10s).count(), + }, }; -#endif - mqttConfig.network.timeout_ms = duration_cast(10s).count(); - mqttConfig.credentials.client_id = clientId.c_str(); Log.debug("MQTT: server: %s:%ld, client ID is '%s'", - mqttConfig.broker.address.hostname, mqttConfig.broker.address.port, clientId.c_str()); - - if (!serverCert.isEmpty()) { - // TODO Make TLS work - // Log.debug("MQTT: server: %s:%d, client ID is '%s', using TLS", - // hostname.c_str(), mqttServer.port, clientId.c_str()); - // Log.trace("Server cert: %s", serverCert.c_str()); - // Log.trace("Client cert: %s", clientCert.c_str()); - // wifiClientSecure.setCACert(serverCert.c_str()); - // wifiClientSecure.setCertificate(clientCert.c_str()); - // wifiClientSecure.setPrivateKey(clientKey.c_str()); - // wifiClientSecure.connect(mqttServer.hostname.c_str(), mqttServer.port); - // mqttClient.begin(wifiClientSecure); + config.broker.address.hostname, + config.broker.address.port, + config.credentials.client_id); + + if (!configServerCert.isEmpty()) { + config.broker.address.transport = MQTT_TRANSPORT_OVER_SSL; + config.broker.verification.certificate = configServerCert.c_str(); + Log.debug("MQTT: Server cert:\n%s", + config.broker.verification.certificate); + + if (!configClientCert.isEmpty() && !configClientKey.isEmpty()) { + config.credentials.authentication = { + .certificate = configClientCert.c_str(), + .key = configClientKey.c_str(), + }; + Log.debug("MQTT: Client cert:\n%s", + config.credentials.authentication.certificate); + } + } else { + config.broker.address.transport = MQTT_TRANSPORT_OVER_TCP; } - client = esp_mqtt_client_init(&mqttConfig); - /* The last argument may be used to pass data to the event handler, in this example mqtt_event_handler */ + client = esp_mqtt_client_init(&config); + ESP_ERROR_CHECK(esp_mqtt_client_register_event(client, MQTT_EVENT_ANY, handleMqttEventCallback, this)); esp_err_t err = esp_mqtt_client_start(client); - if (err != ESP_OK) { - Log.error("MQTT: Connection failed, error = 0x%x", err); + Log.error("MQTT: Connection failed, error = 0x%x: %s", + err, esp_err_to_name(err)); trustMdnsCache = false; stopMqttClient(); return false; @@ -525,7 +529,7 @@ class MqttDriver { static void logErrorIfNonZero(const char* message, int error) { if (error != 0) { - Log.error(" - %s: %d", message, error); + Log.error(" - %s: 0x%x", message, error); } } @@ -636,15 +640,21 @@ class MqttDriver { std::optional wifiConnection; MdnsDriver& mdns; bool trustMdnsCache = true; - const Config& config; + + const String configHostname; + const int configPort; + const String configServerCert; + const String configClientCert; + const String configClientKey; const String clientId; + const bool powerSaveMode; StateSource& mqttReady; esp_mqtt_client_handle_t client = nullptr; - Queue> outgoingQueue { "mqtt-outgoing", config.queueSize.get() }; - Queue incomingQueue { "mqtt-incoming", config.queueSize.get() }; + Queue> outgoingQueue; + Queue incomingQueue; // TODO Use a map instead std::list subscriptions; From e2b3a46c15f9f74ad09ebe5b3bae5cf6fb2c03d8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 17:05:06 +0100 Subject: [PATCH 27/64] Connect to WiFi only once --- main/kernel/Kernel.hpp | 22 +++++++-------- main/kernel/drivers/WiFiDriver.hpp | 45 +++++++++++++++++++----------- 2 files changed, 38 insertions(+), 29 deletions(-) diff --git a/main/kernel/Kernel.hpp b/main/kernel/Kernel.hpp index 6f1e5400..94baad89 100644 --- a/main/kernel/Kernel.hpp +++ b/main/kernel/Kernel.hpp @@ -153,16 +153,13 @@ class Kernel { void updateState() { KernelState newState; - if (networkRequestedState.isSet() && !networkReadyState.isSet()) { - // We don't have network - if (configPortalRunningState.isSet()) { - // We are waiting for the user to configure the network - newState = KernelState::NETWORK_CONFIGURING; - } else { - // We are waiting for network connection - newState = KernelState::NETWORK_CONNECTING; - } - } else if (!rtcInSyncState.isSet()) { + if (configPortalRunningState.isSet()) { + // We are waiting for the user to configure the network + newState = KernelState::NETWORK_CONFIGURING; + } else if (networkConnectingState.isSet()) { + // We are waiting for network connection + newState = KernelState::NETWORK_CONNECTING; + } else if (networkRequestedState.isSet() && !rtcInSyncState.isSet()) { newState = KernelState::RTC_SYNCING; } else if (networkRequestedState.isSet() && !mqttReadyState.isSet()) { // We are waiting for MQTT connection @@ -170,7 +167,7 @@ class Kernel { } else if (!kernelReadyState.isSet()) { // We are waiting for init to finish newState = KernelState::INIT_FINISHING; - } else if (networkRequestedState.isSet()) { + } else if (networkReadyState.isSet()) { newState = KernelState::TRNASMITTING; } else { newState = KernelState::IDLE; @@ -315,6 +312,7 @@ class Kernel { KernelState state = KernelState::BOOTING; StateManager stateManager; StateSource networkRequestedState = stateManager.createStateSource("network-requested"); + StateSource networkConnectingState = stateManager.createStateSource("network-connecting"); StateSource networkReadyState = stateManager.createStateSource("network-ready"); StateSource configPortalRunningState = stateManager.createStateSource("config-portal-running"); StateSource rtcInSyncState = stateManager.createStateSource("rtc-in-sync"); @@ -323,7 +321,7 @@ class Kernel { StateSource kernelReadyState = stateManager.createStateSource("kernel-ready"); public: - WiFiDriver wifi { networkRequestedState, networkReadyState, configPortalRunningState, deviceConfig.getHostname(), deviceConfig.sleepWhenIdle.get() }; + WiFiDriver wifi { networkRequestedState, networkConnectingState, networkReadyState, configPortalRunningState, deviceConfig.getHostname(), deviceConfig.sleepWhenIdle.get() }; private: MdnsDriver mdns { wifi, deviceConfig.getHostname(), "ugly-duckling", version, mdnsReadyState }; diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index 4898b777..089334e2 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -20,8 +20,9 @@ namespace farmhub::kernel::drivers { class WiFiDriver { public: - WiFiDriver(StateSource& networkRequested, StateSource& networkReady, StateSource& configPortalRunning, const String& hostname, bool powerSaveMode) + WiFiDriver(StateSource& networkRequested, StateSource& networkConnecting, StateSource& networkReady, StateSource& configPortalRunning, const String& hostname, bool powerSaveMode) : networkRequested(networkRequested) + , networkConnecting(networkConnecting) , networkReady(networkReady) , configPortalRunning(configPortalRunning) , hostname(hostname) @@ -105,11 +106,12 @@ class WiFiDriver { case WIFI_EVENT_STA_DISCONNECTED: { auto event = static_cast(eventData); networkReady.clear(); - eventQueue.offer(WiFiEvent::DISCONNECTED); + networkConnecting.clear(); { Lock lock(metadataMutex); ssid.reset(); } + eventQueue.offer(WiFiEvent::DISCONNECTED); Log.debug("WiFi: Disconnected from the AP %s, reason: %d", String(event->ssid, event->ssid_len).c_str(), event->reason); break; @@ -130,21 +132,22 @@ class WiFiDriver { case IP_EVENT_STA_GOT_IP: { auto* event = static_cast(eventData); networkReady.set(); - eventQueue.offer(WiFiEvent::CONNECTED); + networkConnecting.clear(); { Lock lock(metadataMutex); ip = event->ip_info.ip; } + eventQueue.offer(WiFiEvent::CONNECTED); Log.debug("WiFi: Got IP - " IPSTR, IP2STR(&event->ip_info.ip)); break; } case IP_EVENT_STA_LOST_IP: { networkReady.clear(); - eventQueue.offer(WiFiEvent::DISCONNECTED); { Lock lock(metadataMutex); ip.reset(); } + eventQueue.offer(WiFiEvent::DISCONNECTED); Log.debug("WiFi: Lost IP"); break; } @@ -182,6 +185,7 @@ class WiFiDriver { Log.debug("WiFi: provisioning finished"); wifi_prov_mgr_deinit(); configPortalRunning.clear(); + networkConnecting.clear(); release(); break; } @@ -211,9 +215,15 @@ class WiFiDriver { if (clients > 0) { networkRequested.set(); - if (!connected && !configPortalRunning.isSet()) { - Log.trace("WiFi: Connecting for first client"); - connect(); + if (!connected) { + if (networkConnecting.isSet()) { + Log.trace("WiFi: Already connecting"); + } else if (configPortalRunning.isSet()) { + Log.trace("WiFi: Provisioning already running"); + } else { + Log.trace("WiFi: Connecting for first client"); + connect(); + } } } else { networkRequested.clear(); @@ -237,27 +247,27 @@ class WiFiDriver { }; startStation(wifiConfig); #else + networkConnecting.set(); + bool provisioned = false; ESP_ERROR_CHECK(wifi_prov_mgr_is_provisioned(&provisioned)); if (provisioned) { wifi_config_t wifiConfig; ESP_ERROR_CHECK(esp_wifi_get_config(WIFI_IF_STA, &wifiConfig)); - Log.debug("WiFi: Connecting using stored credentials to %s", - wifiConfig.sta.ssid); + Log.debug("WiFi: Connecting using stored credentials to %s (password '%s')", + wifiConfig.sta.ssid, wifiConfig.sta.password); startStation(wifiConfig); } else { - if (!configPortalRunning.isSet()) { - Log.debug("WiFi: No stored credentials, starting provisioning"); - configPortalRunning.set(); - startProvisioning(); - } else { - Log.trace("WiFi: Provisioning already running"); - } + Log.debug("WiFi: No stored credentials, starting provisioning"); + configPortalRunning.set(); + startProvisioning(); } #endif } void startStation(wifi_config_t& config) { + ESP_ERROR_CHECK(esp_wifi_stop()); + if (powerSaveMode) { auto listenInterval = 50; Log.trace("WiFi enabling power save mode, listen interval: %d", @@ -315,6 +325,7 @@ class WiFiDriver { } StateSource& networkRequested; + StateSource& networkConnecting; StateSource& networkReady; StateSource& configPortalRunning; const String hostname; @@ -330,7 +341,7 @@ class WiFiDriver { CopyQueue eventQueue { "wifi-events", 16 }; static constexpr milliseconds WIFI_QUEUE_TIMEOUT = 1s; - static constexpr milliseconds WIFI_CHECK_INTERVAL = 5s; + static constexpr milliseconds WIFI_CHECK_INTERVAL = 1min; Mutex metadataMutex; std::optional ssid; From a08b7ae6f79ae80493b9c80b739c79350466b878 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 17:05:17 +0100 Subject: [PATCH 28/64] Reduce log level for MQTT certs --- main/kernel/drivers/MqttDriver.hpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/main/kernel/drivers/MqttDriver.hpp b/main/kernel/drivers/MqttDriver.hpp index 1abdde3e..0a73e4d9 100644 --- a/main/kernel/drivers/MqttDriver.hpp +++ b/main/kernel/drivers/MqttDriver.hpp @@ -417,7 +417,7 @@ class MqttDriver { if (!configServerCert.isEmpty()) { config.broker.address.transport = MQTT_TRANSPORT_OVER_SSL; config.broker.verification.certificate = configServerCert.c_str(); - Log.debug("MQTT: Server cert:\n%s", + Log.trace("MQTT: Server cert:\n%s", config.broker.verification.certificate); if (!configClientCert.isEmpty() && !configClientKey.isEmpty()) { @@ -425,7 +425,7 @@ class MqttDriver { .certificate = configClientCert.c_str(), .key = configClientKey.c_str(), }; - Log.debug("MQTT: Client cert:\n%s", + Log.trace("MQTT: Client cert:\n%s", config.credentials.authentication.certificate); } } else { From ca76ec65d0d87159b9769bffd6ca27e887e43942 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 18:42:05 +0100 Subject: [PATCH 29/64] Only print NTP servers at debug --- main/kernel/drivers/RtcDriver.hpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/main/kernel/drivers/RtcDriver.hpp b/main/kernel/drivers/RtcDriver.hpp index 4f72e3d5..fb6cb8fd 100644 --- a/main/kernel/drivers/RtcDriver.hpp +++ b/main/kernel/drivers/RtcDriver.hpp @@ -137,7 +137,7 @@ class RtcDriver { for (uint8_t i = 0; i < SNTP_MAX_SERVERS; ++i) { if (esp_sntp_getservername(i)) { - Log.info(" - server %d: '%s'", i, esp_sntp_getservername(i)); + Log.debug(" - server %d: '%s'", i, esp_sntp_getservername(i)); } else { char buff[48]; ip_addr_t const* ip = esp_sntp_getserver(i); From e59de52bed13eaa4e6340e951b1cc18ad918c28b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 21:19:16 +0100 Subject: [PATCH 30/64] Demote creating state log --- main/kernel/StateManager.hpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/main/kernel/StateManager.hpp b/main/kernel/StateManager.hpp index 20ed4ff3..d0c7a5e3 100644 --- a/main/kernel/StateManager.hpp +++ b/main/kernel/StateManager.hpp @@ -18,7 +18,7 @@ class StateManager { } StateSource createStateSource(const String& name) { - Log.debug("Creating state: %s", + Log.trace("Creating state: %s", name.c_str()); if (nextEventBit > 31) { throw std::runtime_error("Too many states"); From ac63ad088f099fcd43df5ec3672e943a1876970d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 21:19:30 +0100 Subject: [PATCH 31/64] Signal network connecting in Wokwi --- main/kernel/drivers/WiFiDriver.hpp | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index 089334e2..b5f23e5f 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -236,6 +236,7 @@ class WiFiDriver { } void connect() { + networkConnecting.set(); #ifdef WOKWI Log.debug("WiFi: Skipping provisioning on Wokwi"); wifi_config_t wifiConfig = { @@ -247,8 +248,6 @@ class WiFiDriver { }; startStation(wifiConfig); #else - networkConnecting.set(); - bool provisioned = false; ESP_ERROR_CHECK(wifi_prov_mgr_is_provisioned(&provisioned)); if (provisioned) { From 4eaf4b79ad5f9e7336ed35828336df3fb03a82fe Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 21:19:39 +0100 Subject: [PATCH 32/64] Add MK4 Wokwi simulation --- wokwi/diagram.flow-control-mk4.json | 96 +++++++++++++++++++++++++++++ 1 file changed, 96 insertions(+) create mode 100644 wokwi/diagram.flow-control-mk4.json diff --git a/wokwi/diagram.flow-control-mk4.json b/wokwi/diagram.flow-control-mk4.json new file mode 100644 index 00000000..29ffa248 --- /dev/null +++ b/wokwi/diagram.flow-control-mk4.json @@ -0,0 +1,96 @@ +{ + "version": 1, + "author": "Lóránt Pintér", + "editor": "wokwi", + "parts": [ + { "type": "board-esp32-s2-devkitm-1", "id": "esp", "top": -0.18, "left": 4.57, "attrs": {} }, + { + "type": "wokwi-led", + "id": "statusLed", + "top": 130.8, + "left": 176.6, + "attrs": { "color": "white", "label": "Status" } + }, + { + "type": "wokwi-resistor", + "id": "r1", + "top": 32.75, + "left": 163.2, + "attrs": { "value": "22" } + }, + { + "type": "wokwi-resistor", + "id": "r2", + "top": 81.05, + "left": -135.8, + "rotate": 180, + "attrs": { "value": "22" } + }, + { + "type": "wokwi-led", + "id": "dain1Led", + "top": 63.6, + "left": -178.6, + "attrs": { "color": "yellow", "label": "Valve PH", "flip": "" } + }, + { + "type": "wokwi-led", + "id": "dain2Led", + "top": 25.2, + "left": -130.6, + "attrs": { "color": "orange", "label": "Valve EN", "flip": "" } + }, + { + "type": "wokwi-resistor", + "id": "r3", + "top": 119.45, + "left": -193.4, + "rotate": 180, + "attrs": { "value": "22" } + }, + { + "type": "wokwi-led", + "id": "nsleepLed", + "top": 140.4, + "left": -53.8, + "attrs": { "color": "red", "label": "NSleep", "flip": "" } + }, + { + "type": "wokwi-resistor", + "id": "r4", + "top": 196.25, + "left": -59, + "rotate": 180, + "attrs": { "value": "22" } + }, + { + "type": "wokwi-pushbutton", + "id": "btn1", + "top": -61, + "left": 19.2, + "attrs": { "color": "green", "label": "Flash", "bounce": "0" } + } + ], + "connections": [ + [ "esp:TX", "$serialMonitor:RX", "", [] ], + [ "esp:RX", "$serialMonitor:TX", "", [] ], + [ "r1:1", "esp:3V3.2", "green", [ "v0" ] ], + [ "dain1Led:C", "r3:2", "green", [ "h-28.4", "v19.2" ] ], + [ "r2:1", "esp:GND.1", "black", [ "v0" ] ], + [ "dain2Led:C", "r2:2", "green", [ "h0" ] ], + [ "r3:1", "esp:GND.1", "black", [ "v0" ] ], + [ "nsleepLed:A", "esp:47", "green", [ "v0" ] ], + [ "nsleepLed:C", "r4:2", "green", [ "h-18.8", "v28.8" ] ], + [ "r4:1", "esp:GND.1", "black", [ "v0" ] ], + [ "esp:GND.4", "btn1:2.l", "black", [ "h0" ] ], + [ "esp:GND.2", "r1:1", "black", [ "h0" ] ], + [ "r1:2", "statusLed:A", "green", [ "v0" ] ], + [ "statusLed:C", "esp:26", "green", [ "v0" ] ], + [ "btn1:1.l", "esp:0", "green", [ "h-86.4", "v148.13" ] ], + [ "esp:GND.2", "btn1:2.r", "black", [ "h0", "v-52.13" ] ], + [ "dain1Led:A", "esp:11", "green", [ "v0", "h105.6", "v28.8" ] ], + [ "dain2Led:A", "esp:10", "green", [ "v0", "h67.2", "v57.6" ] ], + [ "nsleepLed:A", "esp:13", "green", [ "v0", "h19.2", "v-19.2" ] ] + ], + "dependencies": {} +} From 94cd5db82eca61da6585d98000f7a91b616c14e2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 21:42:34 +0100 Subject: [PATCH 33/64] Fix backtrace lookup --- lookup-backtrace.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lookup-backtrace.py b/lookup-backtrace.py index a1ebb738..4cd8d163 100755 --- a/lookup-backtrace.py +++ b/lookup-backtrace.py @@ -6,7 +6,7 @@ # Define regex patterns for the two formats PATTERN1 = r"caller ((?:0x[0-9a-fA-F]+:)+0x[0-9a-fA-F]+)" -PATTERN2 = r"Backtrace: ((?:0x[0-9a-fA-F]+:[0-9a-fA-F]+ ?)+)" +PATTERN2 = r"Backtrace: ((?:0x[0-9a-fA-F]+:0x[0-9a-fA-F]+ ?)+)" def parse_and_run_addr2line(line): # Print the input line From ae1b5f8a3cd96c1c732f7fa2646577de332c96c8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 21:42:46 +0100 Subject: [PATCH 34/64] Do not stop a not-started MQTT client --- main/kernel/drivers/MqttDriver.hpp | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/main/kernel/drivers/MqttDriver.hpp b/main/kernel/drivers/MqttDriver.hpp index 0a73e4d9..bb69e4d0 100644 --- a/main/kernel/drivers/MqttDriver.hpp +++ b/main/kernel/drivers/MqttDriver.hpp @@ -356,6 +356,12 @@ class MqttDriver { void stopMqttClient() { if (client != nullptr) { ESP_ERROR_CHECK(esp_mqtt_client_stop(client)); + destroyMqttClient(); + } + } + + void destroyMqttClient() { + if (client != nullptr) { ESP_ERROR_CHECK(esp_mqtt_client_destroy(client)); client = nullptr; } @@ -441,7 +447,7 @@ class MqttDriver { Log.error("MQTT: Connection failed, error = 0x%x: %s", err, esp_err_to_name(err)); trustMdnsCache = false; - stopMqttClient(); + destroyMqttClient(); return false; } else { trustMdnsCache = true; From b3fad819fbea25f0dd40fcd5f9ca56b44681858d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 22:28:19 +0100 Subject: [PATCH 35/64] Print only the leftmost 256 characters in logs --- main/kernel/Log.hpp | 14 ++++---------- 1 file changed, 4 insertions(+), 10 deletions(-) diff --git a/main/kernel/Log.hpp b/main/kernel/Log.hpp index 0ff27de3..dc93d6af 100644 --- a/main/kernel/Log.hpp +++ b/main/kernel/Log.hpp @@ -163,16 +163,10 @@ class FarmhubLog : public LogConsumer { return; } - if (size < bufferSize) { - Lock lock(bufferMutex); - vsnprintf(buffer, size + 1, format, args); - consumer(buffer); - } else { - char* localBuffer = new char[size + 1]; - vsnprintf(localBuffer, size + 1, format, args); - consumer(localBuffer); - delete[] localBuffer; - } + auto capacity = std::min(size + 1, bufferSize); + Lock lock(bufferMutex); + vsnprintf(buffer, capacity, format, args); + consumer(buffer); } constexpr static int bufferSize = 128; From 903a31e59b9727656cb85ee1c34eeb8064b255da Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 22:28:36 +0100 Subject: [PATCH 36/64] Print memory info in debug log when heap tracing --- main/devices/Device.hpp | 12 ++++++++++-- 1 file changed, 10 insertions(+), 2 deletions(-) diff --git a/main/devices/Device.hpp b/main/devices/Device.hpp index a5544c91..d901e486 100644 --- a/main/devices/Device.hpp +++ b/main/devices/Device.hpp @@ -162,9 +162,17 @@ class ConsolePrinter { buffer->concat(timeBuffer); buffer->concat("\033[0m [\033[0;31m"); buffer->concat(pcTaskGetName(nullptr)); - buffer->concat("\033[0m/\033[0;32m"); + buffer->concat("\033[0m@\033[0;32m"); buffer->concat(xPortGetCoreID()); - buffer->concat("\033[0m] "); + buffer->concat("\033[0m"); +#ifdef CONFIG_HEAP_TRACING + buffer->concat("|S:"); + buffer->concat(uxTaskGetStackHighWaterMark(nullptr)); + buffer->concat("B|H:"); + buffer->concat(((float) ESP.getFreeHeap()) / 1024.0f); + buffer->concat("kB"); +#endif + buffer->concat("] "); switch (level) { case Level::Fatal: buffer->concat("\033[0;31mFATAL\033[0m "); From bcf864f11abc5c34334d4237461a12ef4cc34de7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 22:28:45 +0100 Subject: [PATCH 37/64] Inline delay() function --- main/kernel/Task.hpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/main/kernel/Task.hpp b/main/kernel/Task.hpp index fbd1157e..f3c91655 100644 --- a/main/kernel/Task.hpp +++ b/main/kernel/Task.hpp @@ -129,7 +129,7 @@ class Task { }); } - static void delay(ticks time) { + static inline void delay(ticks time) { // Log.trace("Task '%s' delaying for %lld ms", // pcTaskGetName(nullptr), duration_cast(time).count()); vTaskDelay(time.count()); From 22c7198505eb9fcf24e0242673697747d4d10206 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 22:44:09 +0100 Subject: [PATCH 38/64] Log stack sizes when heap tracing --- main/main.cpp | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/main/main.cpp b/main/main.cpp index 781d7b34..f02ed76a 100644 --- a/main/main.cpp +++ b/main/main.cpp @@ -58,11 +58,12 @@ static void dumpPerTaskHeapInfo() { ? pcTaskGetName(taskInfo.task) : "Pre-Scheduler allocs"; taskName.resize(configMAX_TASK_NAME_LEN, ' '); - printf("Task %p: %s CAP_8BIT: %d, CAP_32BIT: %d\n", + printf("Task %p: %s CAP_8BIT: %d, CAP_32BIT: %d, STACK LEFT: %ld\n", taskInfo.task, taskName.c_str(), taskInfo.size[0], - taskInfo.size[1]); + taskInfo.size[1], + uxTaskGetStackHighWaterMark2(taskInfo.task)); } printf("\n\n"); @@ -84,7 +85,7 @@ extern "C" void app_main() { Task::loop("task-heaps", 8192, [](Task& task) { while (true) { dumpPerTaskHeapInfo(); - vTaskDelay(ticks(5s).count()); + Task::delay(ticks(5s)); } }); #endif From 355824a98adcee00566e163c2ae5d3abd868d3ae Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 23:20:28 +0100 Subject: [PATCH 39/64] Reduce battery stack size --- main/devices/Device.hpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/main/devices/Device.hpp b/main/devices/Device.hpp index d901e486..c92cdbe2 100644 --- a/main/devices/Device.hpp +++ b/main/devices/Device.hpp @@ -346,7 +346,7 @@ class ConfiguredKernel { consolePrinter.registerBattery(battery); #endif - Task::loop("battery", 3072, [this](Task& task) { + Task::loop("battery", 2048, [this](Task& task) { task.delayUntil(LOW_POWER_CHECK_INTERVAL); auto currentVoltage = battery->getVoltage(); batteryVoltage.record(currentVoltage); From 3b5f96792fdf6e5fee34b49e5285733c037ffbc0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 23:20:55 +0100 Subject: [PATCH 40/64] Rename mDNS init task --- main/kernel/drivers/MdnsDriver.hpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/main/kernel/drivers/MdnsDriver.hpp b/main/kernel/drivers/MdnsDriver.hpp index 3ea6403f..55d3ed71 100644 --- a/main/kernel/drivers/MdnsDriver.hpp +++ b/main/kernel/drivers/MdnsDriver.hpp @@ -34,7 +34,7 @@ class MdnsDriver { : wifi(wifi) , mdnsReady(mdnsReady) { // TODO Add error handling - Task::run("mdns", 4096, [&wifi, &mdnsReady, instanceName, hostname, version](Task& task) { + Task::run("mdns:init", 4096, [&wifi, &mdnsReady, instanceName, hostname, version](Task& task) { Log.info("mDNS: initializing"); WiFiConnection connection(wifi); From e520580a9bc4587c769c3e5be6de4c6b2169f38a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 23:21:41 +0100 Subject: [PATCH 41/64] Reduce status-update stack size --- main/kernel/Kernel.hpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/main/kernel/Kernel.hpp b/main/kernel/Kernel.hpp index 94baad89..6b88bf1e 100644 --- a/main/kernel/Kernel.hpp +++ b/main/kernel/Kernel.hpp @@ -76,7 +76,7 @@ class Kernel { getMacAddress().c_str()); // TODO Allocate less memory when FARMHUB_DEBUG is disabled - Task::loop("status-update", 3172, [this](Task&) { updateState(); }); + Task::loop("status-update", 3072, [this](Task&) { updateState(); }); httpUpdateResult = handleHttpUpdate(); if (!httpUpdateResult.isEmpty()) { From a8df9b4b118ccc87327a80d07e0af19e6d8bdfe9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 23:22:45 +0100 Subject: [PATCH 42/64] Delete `main` task --- main/main.cpp | 2 ++ 1 file changed, 2 insertions(+) diff --git a/main/main.cpp b/main/main.cpp index f02ed76a..99f088cc 100644 --- a/main/main.cpp +++ b/main/main.cpp @@ -89,4 +89,6 @@ extern "C" void app_main() { } }); #endif + + vTaskDelete(NULL); } From af734c6e1c2ad5c60d6224eeec776f515ccb22e0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 23:22:55 +0100 Subject: [PATCH 43/64] Reduce stack size of heap tracking --- main/main.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/main/main.cpp b/main/main.cpp index 99f088cc..3b9d794a 100644 --- a/main/main.cpp +++ b/main/main.cpp @@ -82,7 +82,7 @@ extern "C" void app_main() { new farmhub::devices::Device(); #ifdef CONFIG_HEAP_TASK_TRACKING - Task::loop("task-heaps", 8192, [](Task& task) { + Task::loop("task-heaps", 4096, [](Task& task) { while (true) { dumpPerTaskHeapInfo(); Task::delay(ticks(5s)); From 80d1cd06f9c24d1f7d7a18deace9e9d600d4b164 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 23:30:18 +0100 Subject: [PATCH 44/64] Reduce switch-manager stack size --- main/kernel/drivers/SwitchManager.hpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/main/kernel/drivers/SwitchManager.hpp b/main/kernel/drivers/SwitchManager.hpp index 55c10e0f..e6b644d4 100644 --- a/main/kernel/drivers/SwitchManager.hpp +++ b/main/kernel/drivers/SwitchManager.hpp @@ -36,7 +36,7 @@ static void handleSwitchInterrupt(void* arg); class SwitchManager { public: SwitchManager() { - Task::loop("switch-manager", 3172, [this](Task& task) { + Task::loop("switch-manager", 1536, [this](Task& task) { SwitchStateChange stateChange = switchStateInterrupts.take(); auto state = stateChange.switchState; auto engaged = stateChange.engaged; From 5a9747eb6b19c4cfb8d0c0d776d2198ea65746fd Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 23:30:45 +0100 Subject: [PATCH 45/64] Increase WiFiDriver stack --- main/kernel/drivers/WiFiDriver.hpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index b5f23e5f..66684f5b 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -47,7 +47,7 @@ class WiFiDriver { ESP_ERROR_CHECK(esp_event_handler_register(IP_EVENT, ESP_EVENT_ANY_ID, &WiFiDriver::onEvent, this)); ESP_ERROR_CHECK(esp_event_handler_register(WIFI_PROV_EVENT, ESP_EVENT_ANY_ID, &WiFiDriver::onEvent, this)); - Task::run("wifi", 3072, [this](Task&) { + Task::run("wifi-driver", 4096, [this](Task&) { runLoop(); }); } From cbf5e20ffd56af0050e7b155300246031dfe6e39 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 23:36:56 +0100 Subject: [PATCH 46/64] Use a vector to keep track of blink patterns --- main/kernel/drivers/LedDriver.hpp | 19 ++++++++++--------- 1 file changed, 10 insertions(+), 9 deletions(-) diff --git a/main/kernel/drivers/LedDriver.hpp b/main/kernel/drivers/LedDriver.hpp index 6d8692ce..785bba31 100644 --- a/main/kernel/drivers/LedDriver.hpp +++ b/main/kernel/drivers/LedDriver.hpp @@ -2,7 +2,7 @@ #include #include -#include +#include #include #include @@ -17,7 +17,7 @@ namespace farmhub::kernel::drivers { class LedDriver { public: - typedef std::list BlinkPattern; + typedef std::vector BlinkPattern; LedDriver(const String& name, PinPtr pin) : pin(pin) @@ -28,11 +28,11 @@ class LedDriver { pin->pinMode(OUTPUT); Task::loop(name, 2048, [this](Task& task) { - if (currentPattern.empty()) { - currentPattern = pattern; + if (cursor == pattern.end()) { + cursor = pattern.begin(); } - milliseconds blinkTime = currentPattern.front(); - currentPattern.pop_front(); + milliseconds blinkTime = *cursor; + cursor++; if (blinkTime > milliseconds::zero()) { setLedState(LOW); @@ -44,7 +44,7 @@ class LedDriver { ticks timeout = blinkTime < milliseconds::zero() ? -blinkTime : blinkTime; patternQueue.pollIn(timeout, [this](const BlinkPattern& newPattern) { pattern = newPattern; - currentPattern = {}; + cursor = pattern.cbegin(); }); }); } @@ -61,7 +61,7 @@ class LedDriver { setPattern({ blinkRate / 2, -blinkRate / 2 }); } - void blinkPatternInMs(std::list pattern) { + void blinkPatternInMs(std::vector pattern) { blinkPattern(BlinkPattern(pattern.begin(), pattern.end())); } @@ -86,8 +86,9 @@ class LedDriver { const PinPtr pin; Queue patternQueue; BlinkPattern pattern; + std::vector::const_iterator cursor = pattern.cbegin(); std::atomic ledState; - BlinkPattern currentPattern; + }; } // namespace farmhub::kernel::drivers From 58afe860f7015e6399c1d83f32b7937e2d306eed Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 23:50:33 +0100 Subject: [PATCH 47/64] No need for extra loop --- main/main.cpp | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/main/main.cpp b/main/main.cpp index 3b9d794a..b5dd9b87 100644 --- a/main/main.cpp +++ b/main/main.cpp @@ -83,10 +83,8 @@ extern "C" void app_main() { #ifdef CONFIG_HEAP_TASK_TRACKING Task::loop("task-heaps", 4096, [](Task& task) { - while (true) { - dumpPerTaskHeapInfo(); - Task::delay(ticks(5s)); - } + dumpPerTaskHeapInfo(); + Task::delay(ticks(5s)); }); #endif From e49cc65e6b655598c369e6c04daf069f9f9f31a1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Mon, 2 Dec 2024 23:50:58 +0100 Subject: [PATCH 48/64] Move status printing to its own function --- main/devices/Device.hpp | 108 +++++++++++++++++++++------------------- 1 file changed, 56 insertions(+), 52 deletions(-) diff --git a/main/devices/Device.hpp b/main/devices/Device.hpp index c92cdbe2..c064ab5b 100644 --- a/main/devices/Device.hpp +++ b/main/devices/Device.hpp @@ -95,56 +95,9 @@ namespace farmhub::devices { class ConsolePrinter { public: ConsolePrinter() { - static const String spinner = "|/-\\"; - static const int spinnerLength = spinner.length(); status.reserve(256); Task::loop("console", 3072, 1, [this](Task& task) { - status.clear(); - - counter = (counter + 1) % spinnerLength; - status.concat("["); - status.concat(spinner.substring(counter, counter + 1)); - status.concat("] "); - - status.concat("\033[33m"); - status.concat(FARMHUB_VERSION); - status.concat("\033[0m"); - - status.concat(", WIFI: "); - status.concat(wifiStatus()); - - status.concat(", uptime: \033[33m"); - status.concat(String(float(millis()) / 1000.0f, 1)); - status.concat("\033[0m s"); - - status.concat(", RTC: \033[33m"); - status.concat(RtcDriver::isTimeSet() ? "OK" : "UNSYNCED"); - status.concat("\033[0m"); - - status.concat(", heap: \033[33m"); - status.concat(String(float(ESP.getFreeHeap()) / 1024.0f, 2)); - status.concat("\033[0m kB"); - - status.concat(", CPU: \033[33m"); - status.concat(esp_clk_cpu_freq() / 1000000); - status.concat("\033[0m MHz"); - - { - Lock lock(batteryMutex); - if (battery != nullptr) { - status.concat(", battery: \033[33m"); - status.concat(String(battery->getVoltage(), 2)); - status.concat("\033[0m V"); - } - } - - Log.printToSerial("\033[1G\033[0K"); - - consoleQueue.drain([](const String& line) { - Log.printlnToSerial(line.c_str()); - }); - - Log.printToSerial(status.c_str()); + printStatus(); task.delayUntil(100ms); }); } @@ -155,6 +108,7 @@ class ConsolePrinter { } void printLog(Level level, const char* message) { + static char timeBuffer[12]; sprintf(timeBuffer, "%8.3f", millis() / 1000.0); String* buffer = new String(); buffer->reserve(256); @@ -203,7 +157,58 @@ class ConsolePrinter { } private: - static String wifiStatus() { + void printStatus() { + static const char* spinner = "|/-\\"; + static const int spinnerLength = strlen(spinner); + + status.clear(); + counter = (counter + 1) % spinnerLength; + status.concat("["); + status.concat(spinner[counter]); + status.concat("] "); + + status.concat("\033[33m"); + status.concat(FARMHUB_VERSION); + status.concat("\033[0m"); + + status.concat(", WIFI: "); + status.concat(wifiStatus()); + + status.concat(", uptime: \033[33m"); + status.concat(String(float(millis()) / 1000.0f, 1)); + status.concat("\033[0m s"); + + status.concat(", RTC: \033[33m"); + status.concat(RtcDriver::isTimeSet() ? "OK" : "UNSYNCED"); + status.concat("\033[0m"); + + status.concat(", heap: \033[33m"); + status.concat(String(float(ESP.getFreeHeap()) / 1024.0f, 2)); + status.concat("\033[0m kB"); + + status.concat(", CPU: \033[33m"); + status.concat(esp_clk_cpu_freq() / 1000000); + status.concat("\033[0m MHz"); + + { + Lock lock(batteryMutex); + if (battery != nullptr) { + status.concat(", battery: \033[33m"); + status.concat(String(battery->getVoltage(), 2)); + status.concat("\033[0m V"); + } + } + + Log.printToSerial("\033[1G\033[0K"); + + consoleQueue.drain([](const String& line) { + Log.printlnToSerial(line.c_str()); + }); + + Log.printToSerial(status.c_str()); + } + + static const char* wifiStatus() { auto netif = esp_netif_get_default_netif(); if (!netif) { return "\033[0;31moff\033[0m"; @@ -240,7 +245,7 @@ class ConsolePrinter { case ESP_ERR_WIFI_NOT_STARTED: return "\033[0;31mWi-Fi not started\033[0m"; default: - return "\033[0;31m" + String(esp_err_to_name(err)) + "\033[0m"; + return esp_err_to_name(err); } // Check IP address @@ -256,12 +261,11 @@ class ConsolePrinter { } int counter; - char timeBuffer[12]; String status; Mutex batteryMutex; std::shared_ptr battery; - Queue consoleQueue { "console", 128 }; + Queue consoleQueue { "console", 16 }; }; ConsolePrinter consolePrinter; From 2800bfe7e8bd839dfc3fedd16e79b3fafb1c86f2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 00:01:44 +0100 Subject: [PATCH 49/64] Reduce stack of battery voltage check --- main/devices/Device.hpp | 52 ++++++++++++++++++++++------------------- 1 file changed, 28 insertions(+), 24 deletions(-) diff --git a/main/devices/Device.hpp b/main/devices/Device.hpp index c064ab5b..96c362db 100644 --- a/main/devices/Device.hpp +++ b/main/devices/Device.hpp @@ -350,30 +350,8 @@ class ConfiguredKernel { consolePrinter.registerBattery(battery); #endif - Task::loop("battery", 2048, [this](Task& task) { - task.delayUntil(LOW_POWER_CHECK_INTERVAL); - auto currentVoltage = battery->getVoltage(); - batteryVoltage.record(currentVoltage); - auto voltage = batteryVoltage.getAverage(); - - if (voltage != 0.0 && voltage < BATTERY_SHUTDOWN_THRESHOLD) { - Log.info("Battery voltage low (%.2f V < %.2f), starting shutdown process, will go to deep sleep in %lld seconds", - voltage, BATTERY_SHUTDOWN_THRESHOLD, duration_cast(LOW_BATTERY_SHUTDOWN_TIMEOUT).count()); - - // TODO Publihs all MQTT messages, then shut down WiFi, and _then_ start shutting down peripherals - // Doing so would result in less of a power spike, which can be important if the battery is already low - - // Run in separate task to allocate enough stack - Task::run("shutdown", 8192, [&](Task& task) { - // Notify all shutdown listeners - for (auto& listener : shutdownListeners) { - listener(); - } - Log.printlnToSerial("Shutdown process finished"); - }); - task.delay(LOW_BATTERY_SHUTDOWN_TIMEOUT); - enterLowPowerDeepSleep(); - } + Task::loop("battery", 1536, [this](Task& task) { + checkBatteryVoltage(task); }); } @@ -399,6 +377,32 @@ class ConfiguredKernel { const shared_ptr battery; private: + void checkBatteryVoltage(Task& task) { + task.delayUntil(LOW_POWER_CHECK_INTERVAL); + auto currentVoltage = battery->getVoltage(); + batteryVoltage.record(currentVoltage); + auto voltage = batteryVoltage.getAverage(); + + if (voltage != 0.0 && voltage < BATTERY_SHUTDOWN_THRESHOLD) { + Log.info("Battery voltage low (%.2f V < %.2f), starting shutdown process, will go to deep sleep in %lld seconds", + voltage, BATTERY_SHUTDOWN_THRESHOLD, duration_cast(LOW_BATTERY_SHUTDOWN_TIMEOUT).count()); + + // TODO Publihs all MQTT messages, then shut down WiFi, and _then_ start shutting down peripherals + // Doing so would result in less of a power spike, which can be important if the battery is already low + + // Run in separate task to allocate enough stack + Task::run("shutdown", 8192, [&](Task& task) { + // Notify all shutdown listeners + for (auto& listener : shutdownListeners) { + listener(); + } + Log.printlnToSerial("Shutdown process finished"); + }); + task.delay(LOW_BATTERY_SHUTDOWN_TIMEOUT); + enterLowPowerDeepSleep(); + } + } + [[noreturn]] inline void enterLowPowerDeepSleep() { Log.printlnToSerial("Entering low power deep sleep"); ESP.deepSleep(duration_cast(LOW_POWER_SLEEP_CHECK_INTERVAL).count()); From 9c2ddc5b082ddd049f9d570011493e309fbb423c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 00:10:35 +0100 Subject: [PATCH 50/64] Move handling blinking to its own function --- main/kernel/drivers/LedDriver.hpp | 41 +++++++++++++++++-------------- 1 file changed, 22 insertions(+), 19 deletions(-) diff --git a/main/kernel/drivers/LedDriver.hpp b/main/kernel/drivers/LedDriver.hpp index 785bba31..23a8ca5c 100644 --- a/main/kernel/drivers/LedDriver.hpp +++ b/main/kernel/drivers/LedDriver.hpp @@ -28,24 +28,7 @@ class LedDriver { pin->pinMode(OUTPUT); Task::loop(name, 2048, [this](Task& task) { - if (cursor == pattern.end()) { - cursor = pattern.begin(); - } - milliseconds blinkTime = *cursor; - cursor++; - - if (blinkTime > milliseconds::zero()) { - setLedState(LOW); - } else { - setLedState(HIGH); - } - - // TOOD Substract processing time from delay - ticks timeout = blinkTime < milliseconds::zero() ? -blinkTime : blinkTime; - patternQueue.pollIn(timeout, [this](const BlinkPattern& newPattern) { - pattern = newPattern; - cursor = pattern.cbegin(); - }); + handleIteration(); }); } @@ -74,6 +57,27 @@ class LedDriver { } private: + void handleIteration() { + if (cursor == pattern.end()) { + cursor = pattern.begin(); + } + milliseconds blinkTime = *cursor; + cursor++; + + if (blinkTime > milliseconds::zero()) { + setLedState(LOW); + } else { + setLedState(HIGH); + } + + // TOOD Substract processing time from delay + ticks timeout = blinkTime < milliseconds::zero() ? -blinkTime : blinkTime; + patternQueue.pollIn(timeout, [this](const BlinkPattern& newPattern) { + pattern = newPattern; + cursor = pattern.cbegin(); + }); + } + void setPattern(const BlinkPattern& pattern) { patternQueue.put(pattern); } @@ -88,7 +92,6 @@ class LedDriver { BlinkPattern pattern; std::vector::const_iterator cursor = pattern.cbegin(); std::atomic ledState; - }; } // namespace farmhub::kernel::drivers From 95a01fee00cf803f90eb4488d1681be1148ad1f3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 00:18:56 +0100 Subject: [PATCH 51/64] Use a vector to avoid allocations --- main/kernel/MovingAverage.hpp | 36 ++++++++++++++++++++++------------- 1 file changed, 23 insertions(+), 13 deletions(-) diff --git a/main/kernel/MovingAverage.hpp b/main/kernel/MovingAverage.hpp index b5825141..d80363be 100644 --- a/main/kernel/MovingAverage.hpp +++ b/main/kernel/MovingAverage.hpp @@ -1,24 +1,33 @@ #pragma once -#include +#include namespace farmhub::kernel { template class MovingAverage { public: - MovingAverage(size_t maxMeasurements) - : maxMeasurements(maxMeasurements) { + explicit MovingAverage(std::size_t maxMeasurements) + : maxMeasurements(maxMeasurements) + , measurements(maxMeasurements, T(0)) + , currentIndex(0) + , count(0) + , sum(0) + , average(0) { } void record(T measurement) { - while (measurements.size() >= maxMeasurements) { - sum -= measurements.front(); - measurements.pop_front(); + if (count == maxMeasurements) { + sum -= measurements[currentIndex]; + } else { + ++count; } - measurements.emplace_back(measurement); + + measurements[currentIndex] = measurement; sum += measurement; - average = sum / measurements.size(); + average = sum / count; + + currentIndex = (currentIndex + 1) % maxMeasurements; } T getAverage() const { @@ -26,11 +35,12 @@ class MovingAverage { } private: - const size_t maxMeasurements; - - std::deque measurements; - T sum = 0; - T average = 0; + const std::size_t maxMeasurements; + std::vector measurements; + std::size_t currentIndex; + std::size_t count; + T sum; + T average; }; } // namespace farmhub::kernel From 57ded7ec03ccdfce7db210ce3c67fd7e5dda1b09 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 00:29:01 +0100 Subject: [PATCH 52/64] Fix typo --- main/kernel/Kernel.hpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/main/kernel/Kernel.hpp b/main/kernel/Kernel.hpp index 6b88bf1e..6ccd24f0 100644 --- a/main/kernel/Kernel.hpp +++ b/main/kernel/Kernel.hpp @@ -147,7 +147,7 @@ class Kernel { RTC_SYNCING, MQTT_CONNECTING, INIT_FINISHING, - TRNASMITTING, + TRANSMITTING, IDLE }; @@ -168,7 +168,7 @@ class Kernel { // We are waiting for init to finish newState = KernelState::INIT_FINISHING; } else if (networkReadyState.isSet()) { - newState = KernelState::TRNASMITTING; + newState = KernelState::TRANSMITTING; } else { newState = KernelState::IDLE; } @@ -196,7 +196,7 @@ class Kernel { case KernelState::INIT_FINISHING: statusLed.blink(1500ms); break; - case KernelState::TRNASMITTING: + case KernelState::TRANSMITTING: statusLed.turnOn(); break; case KernelState::IDLE: From e6f31751c7f10080d9978d4298ad388257a3a4f0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 00:29:31 +0100 Subject: [PATCH 53/64] Polish function declaration --- main/kernel/drivers/LedDriver.hpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/main/kernel/drivers/LedDriver.hpp b/main/kernel/drivers/LedDriver.hpp index 23a8ca5c..ed4834c6 100644 --- a/main/kernel/drivers/LedDriver.hpp +++ b/main/kernel/drivers/LedDriver.hpp @@ -48,7 +48,7 @@ class LedDriver { blinkPattern(BlinkPattern(pattern.begin(), pattern.end())); } - void blinkPattern(BlinkPattern pattern) { + void blinkPattern(const BlinkPattern& pattern) { if (pattern.empty()) { turnOff(); } else { From ee8121211814d7bac30a3a4261697f3e1ceae59d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 00:33:34 +0100 Subject: [PATCH 54/64] Simplify logging --- main/kernel/Log.hpp | 9 +-------- 1 file changed, 1 insertion(+), 8 deletions(-) diff --git a/main/kernel/Log.hpp b/main/kernel/Log.hpp index dc93d6af..698cb071 100644 --- a/main/kernel/Log.hpp +++ b/main/kernel/Log.hpp @@ -1,7 +1,6 @@ #pragma once #include -#include #include #include @@ -152,12 +151,6 @@ class FarmhubLog : public LogConsumer { private: void logImpl(Level level, const char* format, va_list args) { - withFormattedString(format, args, [this, level](const char* message) { - consumer.load()->consumeLog(level, message); - }); - } - - void withFormattedString(const char* format, va_list args, std::function consumer) { int size = vsnprintf(nullptr, 0, format, args); if (size <= 0) { return; @@ -166,7 +159,7 @@ class FarmhubLog : public LogConsumer { auto capacity = std::min(size + 1, bufferSize); Lock lock(bufferMutex); vsnprintf(buffer, capacity, format, args); - consumer(buffer); + consumer.load()->consumeLog(level, buffer); } constexpr static int bufferSize = 128; From 53c7d6d68303207a285185e5a07819b97c1ef4b7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 11:32:32 +0100 Subject: [PATCH 55/64] Polish NTP settings --- sdkconfig.defaults | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/sdkconfig.defaults b/sdkconfig.defaults index a79c4cbc..158d7d18 100644 --- a/sdkconfig.defaults +++ b/sdkconfig.defaults @@ -38,9 +38,10 @@ CONFIG_PARTITION_TABLE_FILENAME="partitions.csv" # Increase main task stack from default 3584 CONFIG_ESP_MAIN_TASK_STACK_SIZE=6144 -# Allow time to be adjusted smoothly +# Allow time to be adjusted smoothly from the DHCP server's recommendation CONFIG_LWIP_DHCP_GET_NTP_SRV=y -CONFIG_SNTP_TIME_SYNC_METHOD_SMOOTH=y +# Figure out how to enable smooth adjustment +# CONFIG_SNTP_SYNC_MODE_SMOOTH=y # # Power management From ae211d4190de758a064fcfd930742f957c7ef18f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 11:32:45 +0100 Subject: [PATCH 56/64] Update deprecated config setting --- sdkconfig.defaults | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sdkconfig.defaults b/sdkconfig.defaults index 158d7d18..28527c72 100644 --- a/sdkconfig.defaults +++ b/sdkconfig.defaults @@ -58,7 +58,7 @@ CONFIG_PM_RTOS_IDLE_OPT=y # Power down stuff CONFIG_PM_SLP_DISABLE_GPIO=y CONFIG_PM_POWER_DOWN_CPU_IN_LIGHT_SLEEP=y -CONFIG_PM_POWER_DOWN_TAGMEM_IN_LIGHT_SLEEP=y +CONFIG_PM_RESTORE_CACHE_TAGMEM_AFTER_LIGHT_SLEEP=y # TODO Experiment with this # CONFIG_PM_POWER_DOWN_PERIPHERAL_IN_LIGHT_SLEEP=y From 64446b584701f6e8f7f9504793f403e87ff8ca03 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 11:39:25 +0100 Subject: [PATCH 57/64] Switch to ESP logging, step 1 --- main/devices/Device.hpp | 28 +++--- main/kernel/Command.hpp | 14 +-- main/kernel/Concurrent.hpp | 4 +- main/kernel/Configuration.hpp | 6 +- main/kernel/FileSystem.hpp | 6 +- main/kernel/I2CManager.hpp | 26 +++--- main/kernel/Kernel.hpp | 30 +++---- main/kernel/NvsStore.hpp | 16 ++-- main/kernel/PcntManager.hpp | 2 +- main/kernel/PwmManager.hpp | 2 +- main/kernel/SleepManager.hpp | 18 ++-- main/kernel/StateManager.hpp | 4 +- main/kernel/Task.hpp | 12 +-- main/kernel/Telemetry.hpp | 2 +- main/kernel/Watchdog.hpp | 4 +- main/kernel/drivers/BatteryDriver.hpp | 2 +- main/kernel/drivers/Bq27220Driver.hpp | 10 +-- main/kernel/drivers/Drv8801Driver.hpp | 6 +- main/kernel/drivers/Drv8833Driver.hpp | 4 +- main/kernel/drivers/Drv8874Driver.hpp | 6 +- main/kernel/drivers/LedDriver.hpp | 2 +- main/kernel/drivers/MdnsDriver.hpp | 16 ++-- main/kernel/drivers/MqttDriver.hpp | 86 +++++++++---------- main/kernel/drivers/RtcDriver.hpp | 24 +++--- main/kernel/drivers/SwitchManager.hpp | 4 +- main/kernel/drivers/WiFiDriver.hpp | 50 +++++------ main/main.cpp | 17 ++++ main/peripherals/Peripheral.hpp | 28 +++--- main/peripherals/chicken_door/ChickenDoor.hpp | 28 +++--- .../environment/Ds18B20SoilSensor.hpp | 12 +-- main/peripherals/environment/Environment.hpp | 2 +- .../environment/Sht2xComponent.hpp | 4 +- .../environment/Sht31Component.hpp | 4 +- .../environment/SoilMoistureSensor.hpp | 4 +- .../fence/ElectricFenceMonitor.hpp | 6 +- .../flow_meter/FlowMeterComponent.hpp | 4 +- main/peripherals/light_sensor/Bh1750.hpp | 2 +- main/peripherals/light_sensor/Tsl2591.hpp | 4 +- main/peripherals/multiplexer/Xl9535.hpp | 4 +- main/peripherals/valve/ValveComponent.hpp | 28 +++--- main/peripherals/valve/ValveConfig.hpp | 4 +- main/peripherals/valve/ValveScheduler.hpp | 4 +- sdkconfig.defaults | 1 + 43 files changed, 279 insertions(+), 261 deletions(-) diff --git a/main/devices/Device.hpp b/main/devices/Device.hpp index 96c362db..50d3f8ac 100644 --- a/main/devices/Device.hpp +++ b/main/devices/Device.hpp @@ -355,12 +355,12 @@ class ConfiguredKernel { }); } - Log.log(Level::Info, F(" ______ _ _ _")); - Log.log(Level::Info, F(" | ____| | | | | | |")); - Log.log(Level::Info, F(" | |__ __ _ _ __ _ __ ___ | |__| |_ _| |__")); - Log.log(Level::Info, F(" | __/ _` | '__| '_ ` _ \\| __ | | | | '_ \\")); - Log.log(Level::Info, F(" | | | (_| | | | | | | | | | | | |_| | |_) |")); - Log.log(Level::Info, F(" |_| \\__,_|_| |_| |_| |_|_| |_|\\__,_|_.__/ %s"), FARMHUB_VERSION); + LOGI(" ______ _ _ _"); + LOGI(" | ____| | | | | | |"); + LOGI(" | |__ __ _ _ __ _ __ ___ | |__| |_ _| |__"); + LOGI(" | __/ _` | '__| '_ ` _ \\| __ | | | | '_ \\"); + LOGI(" | | | (_| | | | | | | | | | | | |_| | |_) |"); + LOGI(" |_| \\__,_|_| |_| |_| |_|_| |_|\\__,_|_.__/ " FARMHUB_VERSION); } void registerShutdownListener(std::function listener) { @@ -384,7 +384,7 @@ class ConfiguredKernel { auto voltage = batteryVoltage.getAverage(); if (voltage != 0.0 && voltage < BATTERY_SHUTDOWN_THRESHOLD) { - Log.info("Battery voltage low (%.2f V < %.2f), starting shutdown process, will go to deep sleep in %lld seconds", + LOGI("Battery voltage low (%.2f V < %.2f), starting shutdown process, will go to deep sleep in %lld seconds", voltage, BATTERY_SHUTDOWN_THRESHOLD, duration_cast(LOW_BATTERY_SHUTDOWN_TIMEOUT).count()); // TODO Publihs all MQTT messages, then shut down WiFi, and _then_ start shutting down peripherals @@ -450,10 +450,10 @@ class Device { Device() { kernel.switches.onReleased("factory-reset", deviceDefinition.bootPin, SwitchMode::PullUp, [this](const Switch&, milliseconds duration) { if (duration >= 15s) { - Log.info("Factory reset triggered after %lld ms", duration.count()); + LOGI("Factory reset triggered after %lld ms", duration.count()); kernel.performFactoryReset(true); } else if (duration >= 5s) { - Log.info("WiFi reset triggered after %lld ms", duration.count()); + LOGI("WiFi reset triggered after %lld ms", duration.count()); kernel.performFactoryReset(false); } }); @@ -463,9 +463,9 @@ class Device { configuredKernel.registerShutdownListener([this]() { peripheralManager.shutdown(); }); - Log.info("Battery configured"); + LOGI("Battery configured"); } else { - Log.info("No battery configured"); + LOGI("No battery configured"); } #if defined(FARMHUB_DEBUG) || defined(FARMHUB_REPORT_MEMORY) @@ -508,14 +508,14 @@ class Device { JsonArray peripheralsInitJson = peripheralsInitDoc.to(); auto builtInPeripheralsCofig = deviceDefinition.getBuiltInPeripherals(); - Log.debug("Loading configuration for %d built-in peripherals", + LOGD("Loading configuration for %d built-in peripherals", builtInPeripheralsCofig.size()); for (auto& perpheralConfig : builtInPeripheralsCofig) { peripheralManager.createPeripheral(perpheralConfig, peripheralsInitJson); } auto& peripheralsConfig = deviceConfig.peripherals.get(); - Log.info("Loading configuration for %d user-configured peripherals", + LOGI("Loading configuration for %d user-configured peripherals", peripheralsConfig.size()); bool peripheralError = false; for (auto& perpheralConfig : peripheralsConfig) { @@ -563,7 +563,7 @@ class Device { kernel.getKernelReadyState().set(); - Log.info("Device ready in %.2f s (kernel version %s on %s instance '%s' with hostname '%s' and IP '%s', SSID '%s', current time is %lld)", + LOGI("Device ready in %.2f s (kernel version %s on %s instance '%s' with hostname '%s' and IP '%s', SSID '%s', current time is %lld)", millis() / 1000.0, kernel.version.c_str(), deviceConfig.model.get().c_str(), diff --git a/main/kernel/Command.hpp b/main/kernel/Command.hpp index 638491d4..4e4c1ce4 100644 --- a/main/kernel/Command.hpp +++ b/main/kernel/Command.hpp @@ -48,9 +48,9 @@ class PingCommand : public Command { try { pingResponse(); } catch (const std::exception& e) { - Log.error("Failed to send ping response: %s", e.what()); + LOGE("Failed to send ping response: %s", e.what()); } catch (...) { - Log.error("Failed to send ping response"); + LOGE("Failed to send ping response"); } response["pong"] = millis(); } @@ -79,7 +79,7 @@ class SleepCommand : public Command { void handle(const JsonObject& request, JsonObject& response) override { seconds duration = seconds(request["duration"].as()); esp_sleep_enable_timer_wakeup(((microseconds) duration).count()); - Log.info("Sleeping for %lld seconds in light sleep mode", + LOGI("Sleeping for %lld seconds in light sleep mode", duration.count()); esp_deep_sleep_start(); } @@ -132,7 +132,7 @@ class FileReadCommand : public FileCommand { if (!path.startsWith("/")) { path = "/" + path; } - Log.info("Reading %s", + LOGI("Reading %s", path.c_str()); response["path"] = path; File file = fs.open(path, FILE_READ); @@ -156,7 +156,7 @@ class FileWriteCommand : public FileCommand { if (!path.startsWith("/")) { path = "/" + path; } - Log.info("Writing %s", + LOGI("Writing %s", path.c_str()); String contents = request["contents"]; response["path"] = path; @@ -183,7 +183,7 @@ class FileRemoveCommand : public FileCommand { if (!path.startsWith("/")) { path = "/" + path; } - Log.info("Removing %s", + LOGI("Removing %s", path.c_str()); response["path"] = path; if (fs.remove(path)) { @@ -214,7 +214,7 @@ class HttpUpdateCommand : public Command { prepareUpdate(url); response["success"] = true; Task::run("update", 3072, [](Task& task) { - Log.info("Restarting in 5 seconds to apply update"); + LOGI("Restarting in 5 seconds to apply update"); delay(5000); ESP.restart(); }); diff --git a/main/kernel/Concurrent.hpp b/main/kernel/Concurrent.hpp index 4109da4d..bf3ca17b 100644 --- a/main/kernel/Concurrent.hpp +++ b/main/kernel/Concurrent.hpp @@ -60,7 +60,7 @@ class Queue : public BaseQueue { TMessage* copy = new TMessage(std::forward(args)...); bool sentWithoutDropping = xQueueSend(this->queue, ©, timeout.count()) == pdTRUE; if (!sentWithoutDropping) { - ESP_LOGW("farmhub", "Overflow in queue '%s', dropping message\n", + LOGW("Overflow in queue '%s', dropping message\n", this->name.c_str()); delete copy; } @@ -137,7 +137,7 @@ class CopyQueue : public BaseQueue { bool offerIn(ticks timeout, const TMessage message) { bool sentWithoutDropping = xQueueSend(this->queue, &message, timeout.count()) == pdTRUE; if (!sentWithoutDropping) { - ESP_LOGW("farmhub", "Overflow in queue '%s', dropping message", + LOGW("Overflow in queue '%s', dropping message", this->name.c_str()); } return sentWithoutDropping; diff --git a/main/kernel/Configuration.hpp b/main/kernel/Configuration.hpp index 67552e20..fa2ed34f 100644 --- a/main/kernel/Configuration.hpp +++ b/main/kernel/Configuration.hpp @@ -279,7 +279,7 @@ class ConfigurationFile { ConfigurationFile(const FileSystem& fs, const String& path) : path(path) { if (!fs.exists(path)) { - Log.debug("The configuration file '%s' was not found, falling back to defaults", + LOGD("The configuration file '%s' was not found, falling back to defaults", path.c_str()); } else { File file = fs.open(path, FILE_READ); @@ -294,14 +294,14 @@ class ConfigurationFile { case DeserializationError::Code::Ok: break; case DeserializationError::Code::EmptyInput: - Log.debug("The configuration file '%s' is empty, falling back to defaults", + LOGD("The configuration file '%s' is empty, falling back to defaults", path.c_str()); break; default: throw ConfigurationException("Cannot open config file " + path + " (" + String(error.c_str()) + ")"); } update(json.as()); - Log.info("Effective configuration for '%s': %s", + LOGI("Effective configuration for '%s': %s", path.c_str(), toString().c_str()); } onUpdate([&fs, path](const JsonObject& json) { diff --git a/main/kernel/FileSystem.hpp b/main/kernel/FileSystem.hpp index 865dfa06..5b54e794 100644 --- a/main/kernel/FileSystem.hpp +++ b/main/kernel/FileSystem.hpp @@ -71,17 +71,17 @@ class UninitializedFileSystem : public FileSystem { static FileSystem* initializeFileSystem() { if (!SPIFFS.begin()) { - Log.info("File system not initialized"); + LOGI("File system not initialized"); return new UninitializedFileSystem(); } - Log.info("File system contents:"); + LOGI("File system contents:"); File root = SPIFFS.open("/", FILE_READ); while (true) { File file = root.openNextFile(); if (!file) { break; } - Log.info(" - %s (%d bytes)", + LOGI(" - %s (%d bytes)", file.path(), file.size()); file.close(); } diff --git a/main/kernel/I2CManager.hpp b/main/kernel/I2CManager.hpp index b336cb75..897bb48a 100644 --- a/main/kernel/I2CManager.hpp +++ b/main/kernel/I2CManager.hpp @@ -69,34 +69,34 @@ class I2CTransmission { ~I2CTransmission() { auto result = wire().endTransmission(); if (result != 0) { - Log.error("Communication unsuccessful with I2C device %s at address 0x%02x, result: %d", + LOGE("Communication unsuccessful with I2C device %s at address 0x%02x, result: %d", device->name.c_str(), device->address, result); } } size_t requestFrom(size_t len, bool stopBit = true) { - Log.trace("Requesting %d bytes from I2C device %s at address 0x%02x", + LOGV("Requesting %d bytes from I2C device %s at address 0x%02x", len, device->name.c_str(), device->address); auto count = wire().requestFrom(device->address, len, stopBit); - Log.trace("Received %d bytes from I2C device %s at address 0x%02x", + LOGV("Received %d bytes from I2C device %s at address 0x%02x", count, device->name.c_str(), device->address); return count; } size_t write(uint8_t data) { - Log.trace("Writing 0x%02x to I2C device %s at address 0x%02x", + LOGV("Writing 0x%02x to I2C device %s at address 0x%02x", data, device->name.c_str(), device->address); auto count = wire().write(data); - Log.trace("Wrote %d bytes to I2C device %s at address 0x%02x", + LOGV("Wrote %d bytes to I2C device %s at address 0x%02x", count, device->name.c_str(), device->address); return count; } size_t write(const uint8_t* data, size_t quantity) { - Log.trace("Writing %d bytes to I2C device %s at address 0x%02x", + LOGV("Writing %d bytes to I2C device %s at address 0x%02x", quantity, device->name.c_str(), device->address); auto count = wire().write(data, quantity); - Log.trace("Wrote %d bytes to I2C device %s at address 0x%02x", + LOGV("Wrote %d bytes to I2C device %s at address 0x%02x", count, device->name.c_str(), device->address); return count; } @@ -107,20 +107,20 @@ class I2CTransmission { int read() { auto value = wire().read(); - Log.trace("Read 0x%02x from I2C device %s at address 0x%02x", + LOGV("Read 0x%02x from I2C device %s at address 0x%02x", value, device->name.c_str(), device->address); return value; } int peek() { auto value = wire().peek(); - Log.trace("Peeked 0x%02x from I2C device %s at address 0x%02x", + LOGV("Peeked 0x%02x from I2C device %s at address 0x%02x", value, device->name.c_str(), device->address); return value; } void flush() { - Log.trace("Flushing I2C device %s at address 0x%02x", + LOGV("Flushing I2C device %s at address 0x%02x", device->name.c_str(), device->address); wire().flush(); } @@ -150,7 +150,7 @@ class I2CManager { shared_ptr createDevice(const String& name, InternalPinPtr sda, InternalPinPtr scl, uint8_t address) { auto device = std::make_shared(name, getBusFor(sda, scl), address); - Log.info("Created I2C device %s at address 0x%02x", + LOGI("Created I2C device %s at address 0x%02x", name.c_str(), address); // Test if communication is possible I2CTransmission tx(device); @@ -162,11 +162,11 @@ class I2CManager { GpioPair key = std::make_pair(sda, scl); auto it = busMap.find(key); if (it != busMap.end()) { - Log.trace("Reusing already registered I2C bus for SDA: %s, SCL: %s", + LOGV("Reusing already registered I2C bus for SDA: %s, SCL: %s", sda->getName().c_str(), scl->getName().c_str()); return *(it->second); } else { - Log.debug("Creating new I2C bus for SDA: %s, SCL: %s", + LOGD("Creating new I2C bus for SDA: %s, SCL: %s", sda->getName().c_str(), scl->getName().c_str()); if (nextBus >= 2) { throw std::runtime_error("Maximum number of I2C buses reached"); diff --git a/main/kernel/Kernel.hpp b/main/kernel/Kernel.hpp index 6ccd24f0..0d3416e9 100644 --- a/main/kernel/Kernel.hpp +++ b/main/kernel/Kernel.hpp @@ -68,7 +68,7 @@ class Kernel { , mqttConfig(mqttConfig) , statusLed(statusLed) { - Log.info("Initializing FarmHub kernel version %s on %s instance '%s' with hostname '%s' and MAC address %s", + LOGI("Initializing FarmHub kernel version %s on %s instance '%s' with hostname '%s' and MAC address %s", version.c_str(), deviceConfig.model.get().c_str(), deviceConfig.instance.get().c_str(), @@ -80,7 +80,7 @@ class Kernel { httpUpdateResult = handleHttpUpdate(); if (!httpUpdateResult.isEmpty()) { - Log.error("HTTP update failed because: %s", + LOGE("HTTP update failed because: %s", httpUpdateResult.c_str()); } } @@ -174,7 +174,7 @@ class Kernel { } if (newState != state) { - Log.debug("Kernel state changed from %d to %d", + LOGD("Kernel state changed from %d to %d", static_cast(state), static_cast(newState)); state = newState; switch (newState) { @@ -226,10 +226,10 @@ class Kernel { return "Command contains empty url"; } - Log.info("Updating from version %s via URL %s", + LOGI("Updating from version %s via URL %s", FARMHUB_VERSION, url.c_str()); - Log.debug("Waiting for network..."); + LOGD("Waiting for network..."); WiFiConnection connection(wifi, WiFiConnection::Mode::NoAwait); if (!connection.await(15s)) { return "Network not ready, aborting update"; @@ -259,11 +259,11 @@ class Kernel { }; esp_err_t ret = esp_https_ota(&otaConfig); if (ret == ESP_OK) { - Log.info("Update succeeded, rebooting in 5 seconds..."); + LOGI("Update succeeded, rebooting in 5 seconds..."); Task::delay(5s); esp_restart(); } else { - Log.error("Update failed (err = %d), continuing with regular boot", + LOGE("Update failed (err = %d), continuing with regular boot", ret); return "Firmware upgrade failed: " + String(ret); } @@ -272,29 +272,29 @@ class Kernel { static esp_err_t httpEventHandler(esp_http_client_event_t* event) { switch (event->event_id) { case HTTP_EVENT_ERROR: - Log.error("HTTP error, status code: %d", + LOGE("HTTP error, status code: %d", esp_http_client_get_status_code(event->client)); break; case HTTP_EVENT_ON_CONNECTED: - Log.debug("HTTP connected"); + LOGD("HTTP connected"); break; case HTTP_EVENT_HEADERS_SENT: - Log.trace("HTTP headers sent"); + LOGV("HTTP headers sent"); break; case HTTP_EVENT_ON_HEADER: - Log.trace("HTTP header: %s: %s", event->header_key, event->header_value); + LOGV("HTTP header: %s: %s", event->header_key, event->header_value); break; case HTTP_EVENT_ON_DATA: - Log.debug("HTTP data: %d bytes", event->data_len); + LOGD("HTTP data: %d bytes", event->data_len); break; case HTTP_EVENT_ON_FINISH: - Log.debug("HTTP finished"); + LOGD("HTTP finished"); break; case HTTP_EVENT_DISCONNECTED: - Log.debug("HTTP disconnected"); + LOGD("HTTP disconnected"); break; default: - Log.warn("Unknown HTTP event %d", event->event_id); + LOGW("Unknown HTTP event %d", event->event_id); break; } return ESP_OK; diff --git a/main/kernel/NvsStore.hpp b/main/kernel/NvsStore.hpp index 4c4a3b7a..507baa33 100644 --- a/main/kernel/NvsStore.hpp +++ b/main/kernel/NvsStore.hpp @@ -39,17 +39,17 @@ class NvsStore { bool get(const char* key, T& value) { return withPreferences(true, [&]() { if (!preferences.isKey(key)) { - Log.trace("NVS: get(%s) = not found", + LOGV("NVS: get(%s) = not found", key); return false; } String jsonString = preferences.getString(key); - Log.trace("NVS: get(%s) = %s", + LOGV("NVS: get(%s) = %s", key, jsonString.c_str()); JsonDocument jsonDocument; deserializeJson(jsonDocument, jsonString); if (jsonDocument.isNull()) { - Log.error("NVS: get(%s) = invalid JSON", + LOGE("NVS: get(%s) = invalid JSON", key); return false; } @@ -70,7 +70,7 @@ class NvsStore { jsonDocument.set(value); String jsonString; serializeJson(jsonDocument, jsonString); - Log.trace("NVS: set(%s) = %s", + LOGV("NVS: set(%s) = %s", key, jsonString.c_str()); return preferences.putString(key, jsonString.c_str()); }); @@ -82,7 +82,7 @@ class NvsStore { bool remove(const char* key) { return withPreferences(false, [&]() { - Log.trace("NVS: remove(%s)", + LOGV("NVS: remove(%s)", key); if (preferences.isKey(key)) { return preferences.remove(key); @@ -95,16 +95,16 @@ class NvsStore { private: bool withPreferences(bool readOnly, std::function action) { Lock lock(preferencesMutex); - Log.trace("NVS: %s '%s'", + LOGV("NVS: %s '%s'", readOnly ? "read" : "write", name.c_str()); if (!preferences.begin(name.c_str(), readOnly)) { - Log.error("NVS: failed to %s '%s'", + LOGE("NVS: failed to %s '%s'", readOnly ? "read" : "write", name.c_str()); return false; } bool result = action(); preferences.end(); - Log.trace("NVS: finished %s '%s', result: %s", + LOGV("NVS: finished %s '%s', result: %s", readOnly ? "read" : "write", name.c_str(), result ? "true" : "false"); return result; } diff --git a/main/kernel/PcntManager.hpp b/main/kernel/PcntManager.hpp index f1e1f732..2c61de26 100644 --- a/main/kernel/PcntManager.hpp +++ b/main/kernel/PcntManager.hpp @@ -85,7 +85,7 @@ class PcntManager { ESP_ERROR_CHECK(pcnt_unit_clear_count(unit)); ESP_ERROR_CHECK(pcnt_unit_start(unit)); - Log.debug("Registered PCNT unit on pin %s", + LOGD("Registered PCNT unit on pin %s", pin->getName().c_str()); return PcntUnit(unit, pin); } diff --git a/main/kernel/PwmManager.hpp b/main/kernel/PwmManager.hpp index b70c94e5..e425ba08 100644 --- a/main/kernel/PwmManager.hpp +++ b/main/kernel/PwmManager.hpp @@ -38,7 +38,7 @@ class PwmManager { public: PwmPin registerPin(InternalPinPtr pin, uint32_t freq, uint8_t resolutionBits = 8) { ledcAttach(pin->getGpio(), freq, resolutionBits); - Log.debug("Registered PWM channel on pin %s with freq %ld and resolution %d", + LOGD("Registered PWM channel on pin %s with freq %ld and resolution %d", pin->getName().c_str(), freq, resolutionBits); return PwmPin(pin, freq, resolutionBits); } diff --git a/main/kernel/SleepManager.hpp b/main/kernel/SleepManager.hpp index 61a393f8..ae27718b 100644 --- a/main/kernel/SleepManager.hpp +++ b/main/kernel/SleepManager.hpp @@ -35,24 +35,24 @@ class SleepManager { static bool shouldSleepWhenIdle(bool requestedSleepWhenIdle) { if (requestedSleepWhenIdle) { #if FARMHUB_DEBUG - Log.warn("Light sleep is disabled in debug mode"); + LOGW("Light sleep is disabled in debug mode"); return false; #elif WOKWI // See https://github.com/wokwi/wokwi-features/issues/922 - Log.warn("Light sleep is disabled when running under Wokwi"); + LOGW("Light sleep is disabled when running under Wokwi"); return false; #elif not(CONFIG_PM_ENABLE) - Log.info("Power management is disabled because CONFIG_PM_ENABLE is not set"); + LOGI("Power management is disabled because CONFIG_PM_ENABLE is not set"); return false; #elif not(CONFIG_FREERTOS_USE_TICKLESS_IDLE) - Log.info("Light sleep is disabled because CONFIG_FREERTOS_USE_TICKLESS_IDLE is not set"); + LOGI("Light sleep is disabled because CONFIG_FREERTOS_USE_TICKLESS_IDLE is not set"); return false; #else - Log.info("Light sleep is enabled"); + LOGI("Light sleep is enabled"); return true; #endif } else { - Log.info("Light sleep is disabled"); + LOGI("Light sleep is disabled"); return false; } } @@ -62,7 +62,7 @@ class SleepManager { void keepAwake() { Lock lock(requestCountMutex); requestCount++; - Log.debug("Task %s requested the device to keep awake, counter at %d", + LOGD("Task %s requested the device to keep awake, counter at %d", pcTaskGetName(nullptr), requestCount); if (requestCount == 1) { configurePowerManagement(false); @@ -72,7 +72,7 @@ class SleepManager { void allowSleep() { Lock lock(requestCountMutex); requestCount--; - Log.debug("Task %s finished with insomniac activity, counter at %d", + LOGD("Task %s finished with insomniac activity, counter at %d", pcTaskGetName(nullptr), requestCount); if (requestCount == 0) { configurePowerManagement(true); @@ -81,7 +81,7 @@ class SleepManager { private: void configurePowerManagement(bool enableLightSleep) { - Log.trace("Configuring power management, CPU max/min at %d/%d MHz, light sleep is %s", + LOGV("Configuring power management, CPU max/min at %d/%d MHz, light sleep is %s", MAX_CPU_FREQ_MHZ, MIN_CPU_FREQ_MHZ, enableLightSleep ? "enabled" : "disabled"); // Configure dynamic frequency scaling: // maximum and minimum frequencies are set in sdkconfig, diff --git a/main/kernel/StateManager.hpp b/main/kernel/StateManager.hpp index d0c7a5e3..baa3f860 100644 --- a/main/kernel/StateManager.hpp +++ b/main/kernel/StateManager.hpp @@ -18,7 +18,7 @@ class StateManager { } StateSource createStateSource(const String& name) { - Log.trace("Creating state: %s", + LOGV("Creating state: %s", name.c_str()); if (nextEventBit > 31) { throw std::runtime_error("Too many states"); @@ -28,7 +28,7 @@ class StateManager { } State combineStates(const String& name, const std::list& states) const { - Log.debug("Creating combined state: %s", + LOGD("Creating combined state: %s", name.c_str()); int eventBits = 0; for (auto& state : states) { diff --git a/main/kernel/Task.hpp b/main/kernel/Task.hpp index f3c91655..7a34d0e3 100644 --- a/main/kernel/Task.hpp +++ b/main/kernel/Task.hpp @@ -81,12 +81,12 @@ class Task { } static TaskHandle run(const String& name, uint32_t stackSize, UBaseType_t priority, const TaskFunction runFunction) { TaskFunction* taskFunction = new TaskFunction(runFunction); - Log.debug("Creating task %s with priority %d and stack size %ld", + LOGD("Creating task %s with priority %d and stack size %ld", name.c_str(), priority, stackSize); TaskHandle_t handle = nullptr; auto result = xTaskCreate(executeTask, name.c_str(), stackSize, taskFunction, priority, &handle); if (result != pdPASS) { - Log.error("Failed to create task %s: %d", name.c_str(), result); + LOGE("Failed to create task %s: %d", name.c_str(), result); delete taskFunction; return TaskHandle(); } @@ -112,7 +112,7 @@ class Task { return RunResult::OK; } else { callee.abort(); - Log.trace("Task '%s' timed out", + LOGV("Task '%s' timed out", name.c_str()); return RunResult::TIMEOUT; } @@ -130,13 +130,13 @@ class Task { } static inline void delay(ticks time) { - // Log.trace("Task '%s' delaying for %lld ms", + // LOGV("Task '%s' delaying for %lld ms", // pcTaskGetName(nullptr), duration_cast(time).count()); vTaskDelay(time.count()); } bool delayUntil(ticks time) { - // Log.trace("Task '%s' delaying until %lld ms", + // LOGV("Task '%s' delaying until %lld ms", // pcTaskGetName(nullptr), duration_cast(time).count()); if (xTaskDelayUntil(&lastWakeTime, time.count())) { return true; @@ -180,7 +180,7 @@ class Task { private: ~Task() { - Log.trace("Finished task %s\n", + LOGV("Finished task %s\n", pcTaskGetName(nullptr)); vTaskDelete(nullptr); } diff --git a/main/kernel/Telemetry.hpp b/main/kernel/Telemetry.hpp index ff30fe21..812794e7 100644 --- a/main/kernel/Telemetry.hpp +++ b/main/kernel/Telemetry.hpp @@ -27,7 +27,7 @@ class TelemetryCollector { } void registerProvider(const String& name, std::shared_ptr provider) { - Log.trace("Registering telemetry provider %s", name.c_str()); + LOGV("Registering telemetry provider %s", name.c_str()); // TODO Check for duplicates providers.emplace(name, provider); } diff --git a/main/kernel/Watchdog.hpp b/main/kernel/Watchdog.hpp index 7c7074a8..3a6df8c5 100644 --- a/main/kernel/Watchdog.hpp +++ b/main/kernel/Watchdog.hpp @@ -33,7 +33,7 @@ class Watchdog { callback(WatchdogState::TimedOut); }); callback(WatchdogState::Started); - Log.debug("Watchdog started with a timeout of %.2f seconds", + LOGD("Watchdog started with a timeout of %.2f seconds", duration_cast(timeout).count() / 1000.0); } @@ -43,7 +43,7 @@ class Watchdog { handle.abort(); callback(WatchdogState::Cacnelled); handle = TaskHandle(); - Log.debug("Watchdog cancelled"); + LOGD("Watchdog cancelled"); } } diff --git a/main/kernel/drivers/BatteryDriver.hpp b/main/kernel/drivers/BatteryDriver.hpp index a111a179..aa87de81 100644 --- a/main/kernel/drivers/BatteryDriver.hpp +++ b/main/kernel/drivers/BatteryDriver.hpp @@ -26,7 +26,7 @@ class AnalogBatteryDriver AnalogBatteryDriver(InternalPinPtr pin, float voltageDividerRatio) : pin(pin) , voltageDividerRatio(voltageDividerRatio) { - Log.info("Initializing analog battery driver on pin %s", + LOGI("Initializing analog battery driver on pin %s", pin->getName().c_str()); pin->pinMode(INPUT); diff --git a/main/kernel/drivers/Bq27220Driver.hpp b/main/kernel/drivers/Bq27220Driver.hpp index 961633f0..c06682c5 100644 --- a/main/kernel/drivers/Bq27220Driver.hpp +++ b/main/kernel/drivers/Bq27220Driver.hpp @@ -14,22 +14,22 @@ class Bq27220Driver : public BatteryDriver { public: Bq27220Driver(I2CManager& i2c, InternalPinPtr sda, InternalPinPtr scl, const uint8_t address = 0x55) : device(i2c.createDevice("battery:bq27220", sda, scl, address)) { - Log.info("Initializing BQ27220 driver on SDA %s, SCL %s", + LOGI("Initializing BQ27220 driver on SDA %s, SCL %s", sda->getName().c_str(), scl->getName().c_str()); auto deviceType = readControlWord(0x0001); if (deviceType != 0x0220) { - Log.error("BQ27220 at address 0x%02x is not a BQ27220 (0x%04x)", + LOGE("BQ27220 at address 0x%02x is not a BQ27220 (0x%04x)", address, deviceType); return; } - Log.info("Found BQ27220 at address 0x%02x, FW version 0x%04x, HW version 0x%04x", + LOGI("Found BQ27220 at address 0x%02x, FW version 0x%04x, HW version 0x%04x", address, readControlWord(0x0002), readControlWord(0x0003)); } float getVoltage() override { - // Log.trace("Capacityt: %d/%d", readWord(0x10), readWord(0x12)); + // LOGV("Capacityt: %d/%d", readWord(0x10), readWord(0x12)); return readWord(0x08) / 1000.0; } @@ -61,7 +61,7 @@ class Bq27220Driver : public BatteryDriver { I2CTransmission tx(device); auto rxResult = tx.requestFrom((uint8_t) length); if (rxResult != length) { - Log.error("Failed to read from 0x%02x: %d", reg, rxResult); + LOGE("Failed to read from 0x%02x: %d", reg, rxResult); return false; } for (size_t i = 0; i < length; i++) { diff --git a/main/kernel/drivers/Drv8801Driver.hpp b/main/kernel/drivers/Drv8801Driver.hpp index 8f0c0404..4ee0bc4b 100644 --- a/main/kernel/drivers/Drv8801Driver.hpp +++ b/main/kernel/drivers/Drv8801Driver.hpp @@ -41,7 +41,7 @@ class Drv8801Driver , faultPin(faultPin) , sleepPin(sleepPin) { - Log.info("Initializing DRV8801 on pins enable = %s, phase = %s, fault = %s, sleep = %s, mode1 = %s, mode2 = %s, current = %s", + LOGI("Initializing DRV8801 on pins enable = %s, phase = %s, fault = %s, sleep = %s, mode1 = %s, mode2 = %s, current = %s", enablePin->getName().c_str(), phasePin->getName().c_str(), faultPin->getName().c_str(), @@ -66,7 +66,7 @@ class Drv8801Driver void drive(MotorPhase phase, double duty = 1) override { if (duty == 0) { - Log.debug("Stopping"); + LOGD("Stopping"); sleep(); enablePin->digitalWrite(LOW); return; @@ -76,7 +76,7 @@ class Drv8801Driver int direction = (phase == MotorPhase::FORWARD ? 1 : -1); int dutyValue = phaseChannel.maxValue() / 2 + direction * (int) (phaseChannel.maxValue() / 2 * duty); - Log.debug("Driving motor %s at %d%%", + LOGD("Driving motor %s at %d%%", phase == MotorPhase::FORWARD ? "forward" : "reverse", (int) (duty * 100)); diff --git a/main/kernel/drivers/Drv8833Driver.hpp b/main/kernel/drivers/Drv8833Driver.hpp index 03469285..0800c380 100644 --- a/main/kernel/drivers/Drv8833Driver.hpp +++ b/main/kernel/drivers/Drv8833Driver.hpp @@ -34,7 +34,7 @@ class Drv8833Driver { , faultPin(faultPin) , sleepPin(sleepPin) { - Log.info("Initializing DRV8833 on pins ain1 = %s, ain2 = %s, bin1 = %s, bin2 = %s, fault = %s, sleep = %s", + LOGI("Initializing DRV8833 on pins ain1 = %s, ain2 = %s, bin1 = %s, bin2 = %s, fault = %s, sleep = %s", ain1Pin->getName().c_str(), ain2Pin->getName().c_str(), bin1Pin->getName().c_str(), @@ -79,7 +79,7 @@ class Drv8833Driver { void drive(MotorPhase phase, double duty = 1) override { int dutyValue = static_cast((in1Channel.maxValue() + in1Channel.maxValue() * duty) / 2); - Log.debug("Driving motor %s on pins %s/%s at %d%% (duty = %d)", + LOGD("Driving motor %s on pins %s/%s at %d%% (duty = %d)", phase == MotorPhase::FORWARD ? "forward" : "reverse", in1Channel.pin->getName().c_str(), in2Channel.pin->getName().c_str(), diff --git a/main/kernel/drivers/Drv8874Driver.hpp b/main/kernel/drivers/Drv8874Driver.hpp index ec3e17dc..0845fc8b 100644 --- a/main/kernel/drivers/Drv8874Driver.hpp +++ b/main/kernel/drivers/Drv8874Driver.hpp @@ -39,7 +39,7 @@ class Drv8874Driver , faultPin(faultPin) , sleepPin(sleepPin) { - Log.info("Initializing DRV8874 on pins in1 = %s, in2 = %s, fault = %s, sleep = %s, current = %s", + LOGI("Initializing DRV8874 on pins in1 = %s, in2 = %s, fault = %s, sleep = %s, current = %s", in1Pin->getName().c_str(), in2Pin->getName().c_str(), faultPin->getName().c_str(), @@ -55,14 +55,14 @@ class Drv8874Driver void drive(MotorPhase phase, double duty = 1) override { if (duty == 0) { - Log.debug("Stopping motor"); + LOGD("Stopping motor"); sleep(); return; } wakeUp(); int dutyValue = in1Channel.maxValue() / 2 + (int) (in1Channel.maxValue() / 2 * duty); - Log.debug("Driving motor %s at %d%%", + LOGD("Driving motor %s at %d%%", phase == MotorPhase::FORWARD ? "forward" : "reverse", (int) (duty * 100)); diff --git a/main/kernel/drivers/LedDriver.hpp b/main/kernel/drivers/LedDriver.hpp index ed4834c6..d4afedbf 100644 --- a/main/kernel/drivers/LedDriver.hpp +++ b/main/kernel/drivers/LedDriver.hpp @@ -23,7 +23,7 @@ class LedDriver { : pin(pin) , patternQueue(name, 1) , pattern({ -milliseconds::max() }) { - Log.info("Initializing LED driver on pin %s", + LOGI("Initializing LED driver on pin %s", pin->getName().c_str()); pin->pinMode(OUTPUT); diff --git a/main/kernel/drivers/MdnsDriver.hpp b/main/kernel/drivers/MdnsDriver.hpp index 55d3ed71..5a636b86 100644 --- a/main/kernel/drivers/MdnsDriver.hpp +++ b/main/kernel/drivers/MdnsDriver.hpp @@ -35,21 +35,21 @@ class MdnsDriver { , mdnsReady(mdnsReady) { // TODO Add error handling Task::run("mdns:init", 4096, [&wifi, &mdnsReady, instanceName, hostname, version](Task& task) { - Log.info("mDNS: initializing"); + LOGI("mDNS: initializing"); WiFiConnection connection(wifi); ESP_ERROR_CHECK(mdns_init()); mdns_hostname_set(hostname.c_str()); mdns_instance_name_set(instanceName.c_str()); - Log.debug("mDNS: Advertising service %s on %s.local, version: %s", + LOGD("mDNS: Advertising service %s on %s.local, version: %s", instanceName.c_str(), hostname.c_str(), version.c_str()); mdns_service_add(instanceName.c_str(), "_farmhub", "_tcp", 80, nullptr, 0); mdns_txt_item_t txt[] = { { "version", version.c_str() }, }; mdns_service_txt_set("_farmhub", "_tcp", txt, 1); - Log.info("mDNS: configured"); + LOGI("mDNS: configured"); mdnsReady.set(); }); @@ -69,17 +69,17 @@ class MdnsDriver { if (loadFromCache) { if (nvs.get(cacheKey, record)) { if (record.validate()) { - Log.debug("mDNS: found %s in NVS cache: %s", + LOGD("mDNS: found %s in NVS cache: %s", cacheKey.c_str(), record.hostname.c_str()); return true; } else { - Log.debug("mDNS: invalid record in NVS cache for %s, removing", + LOGD("mDNS: invalid record in NVS cache for %s, removing", cacheKey.c_str()); nvs.remove(cacheKey); } } } else { - Log.debug("mDNS: removing untrusted record for %s from NVS cache", + LOGD("mDNS: removing untrusted record for %s from NVS cache", cacheKey.c_str()); nvs.remove(cacheKey); } @@ -90,12 +90,12 @@ class MdnsDriver { mdns_result_t* results = nullptr; esp_err_t err = mdns_query_ptr(String("_" + serviceName).c_str(), String("_" + port).c_str(), timeout.count(), 1, &results); if (err) { - Log.error("mDNS: query failed for %s.%s: %d", + LOGE("mDNS: query failed for %s.%s: %d", serviceName.c_str(), port.c_str(), err); return false; } if (results == nullptr) { - Log.info("mDNS: no results found for %s.%s", + LOGI("mDNS: no results found for %s.%s", serviceName.c_str(), port.c_str()); return false; } diff --git a/main/kernel/drivers/MqttDriver.hpp b/main/kernel/drivers/MqttDriver.hpp index bb69e4d0..3c430d78 100644 --- a/main/kernel/drivers/MqttDriver.hpp +++ b/main/kernel/drivers/MqttDriver.hpp @@ -91,7 +91,7 @@ class MqttDriver { // Clear topic and wait for it to be cleared auto clearStatus = mqtt.clear(fullTopic(suffix), Retention::Retain, QoS::ExactlyOnce, std::chrono::seconds { 5 }, MQTT_ALERT_AFTER_INCOMING); if (clearStatus != PublishStatus::Success) { - Log.error("MQTT: Failed to clear retained command topic '%s', status: %d", + LOGE("MQTT: Failed to clear retained command topic '%s', status: %d", suffix.c_str(), static_cast(clearStatus)); } @@ -230,7 +230,7 @@ class MqttDriver { if (log == LogPublish::Log) { String serializedJson; serializeJsonPretty(json, serializedJson); - Log.debug("MQTT: Queuing topic '%s'%s (qos = %d): %s", + LOGD("MQTT: Queuing topic '%s'%s (qos = %d): %s", topic.c_str(), (retain == Retention::Retain ? " (retain)" : ""), static_cast(qos), serializedJson.c_str()); } #endif @@ -242,7 +242,7 @@ class MqttDriver { } PublishStatus clear(const String& topic, Retention retain, QoS qos, ticks timeout = ticks::zero(), milliseconds extendAlert = MQTT_ALERT_AFTER_OUTGOING) { - Log.debug("MQTT: Clearing topic '%s'", + LOGD("MQTT: Clearing topic '%s'", topic.c_str()); return executeAndAwait(timeout, [&](TaskHandle_t waitingTask) { return outgoingQueue.offerIn(MQTT_QUEUE_TIMEOUT, OutgoingMessage { topic, "", retain, qos, waitingTask, LogPublish::Log, extendAlert }); @@ -298,13 +298,13 @@ class MqttDriver { while (true) { auto timeout = duration_cast(alertUntil - system_clock::now()); if (timeout > 0ns) { - Log.trace("MQTT: Alert for another %lld seconds, checking for incoming messages", + LOGV("MQTT: Alert for another %lld seconds, checking for incoming messages", duration_cast(timeout).count()); ensureConnected(task); timeout = std::min(timeout, MQTT_LOOP_INTERVAL); } else { if (powerSaveMode) { - Log.trace("MQTT: Not alert anymore, disconnecting"); + LOGV("MQTT: Not alert anymore, disconnecting"); disconnect(); timeout = MQTT_MAX_TIMEOUT_POWER_SAVE; } else { @@ -312,21 +312,21 @@ class MqttDriver { } } - // Log.trace("MQTT: Waiting for outgoing event for %lld ms", duration_cast(timeout).count()); + // LOGV("MQTT: Waiting for outgoing event for %lld ms", duration_cast(timeout).count()); outgoingQueue.pollIn(duration_cast(timeout), [&](const auto& event) { - Log.trace("MQTT: Processing outgoing event"); + LOGV("MQTT: Processing outgoing event"); ensureConnected(task); std::visit( [&](auto&& arg) { using T = std::decay_t; if constexpr (std::is_same_v) { - Log.trace("MQTT: Processing outgoing message: %s", + LOGV("MQTT: Processing outgoing message: %s", arg.topic.c_str()); processOutgoingMessage(arg); alertUntil = std::max(alertUntil, system_clock::now() + arg.extendAlert); } else if constexpr (std::is_same_v) { - Log.trace("MQTT: Processing subscription"); + LOGV("MQTT: Processing subscription"); processSubscription(arg); alertUntil = std::max(alertUntil, system_clock::now() + MQTT_ALERT_AFTER_OUTGOING); } @@ -345,7 +345,7 @@ class MqttDriver { void disconnect() { if (client != nullptr) { - Log.debug("Disconnecting from MQTT server"); + LOGD("Disconnecting from MQTT server"); mqttReady.clear(); ESP_ERROR_CHECK(esp_mqtt_client_disconnect(client)); stopMqttClient(); @@ -369,13 +369,13 @@ class MqttDriver { bool connectIfNecessary() { if (!wifiConnection.has_value()) { - Log.trace("MQTT: Connecting to WiFi..."); + LOGV("MQTT: Connecting to WiFi..."); wifiConnection.emplace(wifi); - Log.trace("MQTT: Connected to WiFi"); + LOGV("MQTT: Connected to WiFi"); } if (!mqttReady.isSet()) { - Log.debug("MQTT: Connecting to MQTT server"); + LOGD("MQTT: Connecting to MQTT server"); if (client == nullptr) { String hostname; @@ -387,7 +387,7 @@ class MqttDriver { #else MdnsRecord mqttServer; if (!mdns.lookupService("mqtt", "tcp", mqttServer, trustMdnsCache)) { - Log.error("MQTT: Failed to lookup MQTT server"); + LOGE("MQTT: Failed to lookup MQTT server"); return false; } hostname = mqttServer.ip == IPAddress() @@ -415,7 +415,7 @@ class MqttDriver { }, }; - Log.debug("MQTT: server: %s:%ld, client ID is '%s'", + LOGD("MQTT: server: %s:%ld, client ID is '%s'", config.broker.address.hostname, config.broker.address.port, config.credentials.client_id); @@ -423,7 +423,7 @@ class MqttDriver { if (!configServerCert.isEmpty()) { config.broker.address.transport = MQTT_TRANSPORT_OVER_SSL; config.broker.verification.certificate = configServerCert.c_str(); - Log.trace("MQTT: Server cert:\n%s", + LOGV("MQTT: Server cert:\n%s", config.broker.verification.certificate); if (!configClientCert.isEmpty() && !configClientKey.isEmpty()) { @@ -431,7 +431,7 @@ class MqttDriver { .certificate = configClientCert.c_str(), .key = configClientKey.c_str(), }; - Log.trace("MQTT: Client cert:\n%s", + LOGV("MQTT: Client cert:\n%s", config.credentials.authentication.certificate); } } else { @@ -444,7 +444,7 @@ class MqttDriver { esp_err_t err = esp_mqtt_client_start(client); if (err != ESP_OK) { - Log.error("MQTT: Connection failed, error = 0x%x: %s", + LOGE("MQTT: Connection failed, error = 0x%x: %s", err, esp_err_to_name(err)); trustMdnsCache = false; destroyMqttClient(); @@ -454,11 +454,11 @@ class MqttDriver { } } else { // TODO Reconnection probably doesn't work like this? - Log.debug("MQTT: Reconnecting to MQTT server"); + LOGD("MQTT: Reconnecting to MQTT server"); ESP_ERROR_CHECK(esp_mqtt_client_reconnect(client)); } if (!mqttReady.awaitSet(MQTT_CONNECTION_TIMEOUT)) { - Log.debug("MQTT: Connecting to MQTT server timed out"); + LOGD("MQTT: Connecting to MQTT server timed out"); stopMqttClient(); return false; } @@ -468,14 +468,14 @@ class MqttDriver { registerSubscriptionWithMqtt(subscription); } - Log.debug("MQTT: Connected"); + LOGD("MQTT: Connected"); } return true; } static void handleMqttEventCallback(void* userData, esp_event_base_t eventBase, int32_t eventId, void* eventData) { auto event = static_cast(eventData); - // Log.trace("MQTT: Event dispatched from event loop: base=%s, event_id=%d, client=%p, data=%p, data_len=%d, topic=%p, topic_len=%d, msg_id=%d", + // LOGV("MQTT: Event dispatched from event loop: base=%s, event_id=%d, client=%p, data=%p, data_len=%d, topic=%p, topic_len=%d, msg_id=%d", // eventBase, event->event_id, event->client, event->data, event->data_len, event->topic, event->topic_len, event->msg_id); auto* driver = static_cast(userData); driver->handleMqttEvent(eventId, event); @@ -484,42 +484,42 @@ class MqttDriver { void handleMqttEvent(int eventId, esp_mqtt_event_handle_t event) { switch (eventId) { case MQTT_EVENT_BEFORE_CONNECT: { - Log.trace("MQTT: Connecting to MQTT server"); + LOGV("MQTT: Connecting to MQTT server"); break; } case MQTT_EVENT_CONNECTED: { - Log.trace("MQTT: Connected to MQTT server"); + LOGV("MQTT: Connected to MQTT server"); mqttReady.set(); break; } case MQTT_EVENT_DISCONNECTED: { - Log.trace("MQTT: Disconnected from MQTT server"); + LOGV("MQTT: Disconnected from MQTT server"); mqttReady.clear(); break; } case MQTT_EVENT_SUBSCRIBED: { - Log.trace("MQTT: Subscribed, message ID: %d", event->msg_id); + LOGV("MQTT: Subscribed, message ID: %d", event->msg_id); break; } case MQTT_EVENT_UNSUBSCRIBED: { - Log.trace("MQTT: Unsubscribed, message ID: %d", event->msg_id); + LOGV("MQTT: Unsubscribed, message ID: %d", event->msg_id); break; } case MQTT_EVENT_PUBLISHED: { - Log.trace("MQTT: Published, message ID %d", event->msg_id); + LOGV("MQTT: Published, message ID %d", event->msg_id); break; } case MQTT_EVENT_DATA: { String topic(event->topic, event->topic_len); String payload(event->data, event->data_len); - Log.trace("MQTT: Received message on topic '%s'", + LOGV("MQTT: Received message on topic '%s'", topic.c_str()); incomingQueue.offerIn(MQTT_QUEUE_TIMEOUT, IncomingMessage { topic, payload }); break; } case MQTT_EVENT_ERROR: { if (event->error_handle->error_type == MQTT_ERROR_TYPE_TCP_TRANSPORT) { - Log.error("Last errno string (%s)", strerror(event->error_handle->esp_transport_sock_errno)); + LOGE("Last errno string (%s)", strerror(event->error_handle->esp_transport_sock_errno)); logErrorIfNonZero("reported from esp-tls", event->error_handle->esp_tls_last_esp_err); logErrorIfNonZero("reported from tls stack", event->error_handle->esp_tls_stack_err); logErrorIfNonZero("captured as transport's socket errno", event->error_handle->esp_transport_sock_errno); @@ -527,7 +527,7 @@ class MqttDriver { break; } default: { - Log.warn("MQTT: Unknown event %d", eventId); + LOGW("MQTT: Unknown event %d", eventId); break; } } @@ -535,7 +535,7 @@ class MqttDriver { static void logErrorIfNonZero(const char* message, int error) { if (error != 0) { - Log.error(" - %s: 0x%x", message, error); + LOGE(" - %s: 0x%x", message, error); } } @@ -549,19 +549,19 @@ class MqttDriver { message.retain == Retention::Retain); #ifdef DUMP_MQTT if (message.log == LogPublish::Log) { - Log.trace("MQTT: Published to '%s' (size: %d), result: %d", + LOGV("MQTT: Published to '%s' (size: %d), result: %d", message.topic.c_str(), message.payload.length(), ret); } #endif bool success; switch (ret) { case -1: - Log.debug("MQTT: Error publishing to '%s'", + LOGD("MQTT: Error publishing to '%s'", message.topic.c_str()); success = false; break; case -2: - Log.debug("MQTT: Outbox full, message to '%s' dropped", + LOGD("MQTT: Outbox full, message to '%s' dropped", message.topic.c_str()); success = false; break; @@ -586,15 +586,15 @@ class MqttDriver { const String& payload = message.payload; if (payload.isEmpty()) { - Log.trace("MQTT: Ignoring empty payload"); + LOGV("MQTT: Ignoring empty payload"); return; } #ifdef DUMP_MQTT - Log.debug("MQTT: Received '%s' (size: %d): %s", + LOGD("MQTT: Received '%s' (size: %d): %s", topic.c_str(), payload.length(), payload.c_str()); #else - Log.debug("MQTT: Received '%s' (size: %d)", + LOGD("MQTT: Received '%s' (size: %d)", topic.c_str(), payload.length()); #endif for (auto subscription : subscriptions) { @@ -606,28 +606,28 @@ class MqttDriver { subscription.handle(topic, json.as()); }); if (result != Task::RunResult::OK) { - Log.error("MQTT: Incoming handler for topic '%s' timed out", + LOGE("MQTT: Incoming handler for topic '%s' timed out", topic.c_str()); } return; } } - Log.warn("MQTT: No handler for topic '%s'", + LOGW("MQTT: No handler for topic '%s'", topic.c_str()); } // Actually subscribe to the given topic bool registerSubscriptionWithMqtt(const Subscription& subscription) { - Log.trace("MQTT: Subscribing to topic '%s' (qos = %d)", + LOGV("MQTT: Subscribing to topic '%s' (qos = %d)", subscription.topic.c_str(), static_cast(subscription.qos)); int ret = esp_mqtt_client_subscribe(client, subscription.topic.c_str(), static_cast(subscription.qos)); switch (ret) { case -1: - Log.error("MQTT: Error subscribing to topic '%s'", + LOGE("MQTT: Error subscribing to topic '%s'", subscription.topic.c_str()); return false; case -2: - Log.error("MQTT: Subscription to topic '%s' failed, outbox full", + LOGE("MQTT: Subscription to topic '%s' failed, outbox full", subscription.topic.c_str()); return false; default: diff --git a/main/kernel/drivers/RtcDriver.hpp b/main/kernel/drivers/RtcDriver.hpp index fb6cb8fd..ba8bc258 100644 --- a/main/kernel/drivers/RtcDriver.hpp +++ b/main/kernel/drivers/RtcDriver.hpp @@ -43,7 +43,7 @@ class RtcDriver { , rtcInSync(rtcInSync) { if (isTimeSet()) { - Log.info("RTC: time is already set"); + LOGI("RTC: time is already set"); rtcInSync.set(); } @@ -55,7 +55,7 @@ class RtcDriver { trustMdnsCache = true; } else { // Attempt a retry, but with mDNS cache disabled - Log.error("RTC: NTP update failed, retrying in 10 seconds with mDNS cache disabled"); + LOGE("RTC: NTP update failed, retrying in 10 seconds with mDNS cache disabled"); trustMdnsCache = false; task.delay(10s); continue; @@ -89,24 +89,24 @@ class RtcDriver { ESP_ERROR_CHECK(esp_netif_sntp_init(&config)); #ifdef WOKWI - Log.info("RTC: using default NTP server for Wokwi"); + LOGI("RTC: using default NTP server for Wokwi"); #else // TODO Check this if (ntpConfig.host.get().length() > 0) { - Log.debug("RTC: using NTP server %s from configuration", + LOGD("RTC: using NTP server %s from configuration", ntpConfig.host.get().c_str()); esp_sntp_setservername(0, ntpConfig.host.get().c_str()); } else { MdnsRecord ntpServer; if (mdns.lookupService("ntp", "udp", ntpServer, trustMdnsCache)) { - Log.debug("RTC: using NTP server %s:%d (%s) from mDNS", + LOGD("RTC: using NTP server %s:%d (%s) from mDNS", ntpServer.hostname.c_str(), ntpServer.port, ntpServer.ip.toString().c_str()); auto serverIp = convertIp4(ntpServer.ip); esp_sntp_setserver(0, &serverIp); } else { - Log.debug("RTC: no NTP server configured, using default"); + LOGD("RTC: no NTP server configured, using default"); } } #endif @@ -121,11 +121,11 @@ class RtcDriver { if (ret == ESP_OK || ret == ESP_ERR_NOT_FINISHED) { rtcInSync.set(); success = true; - Log.debug("RTC: sync finished successfully"); + LOGD("RTC: sync finished successfully"); } else if (ret == ESP_ERR_TIMEOUT) { - Log.debug("RTC: waiting for time sync timed out"); + LOGD("RTC: waiting for time sync timed out"); } else { - Log.debug("RTC: waiting for time sync returned 0x%x", ret); + LOGD("RTC: waiting for time sync returned 0x%x", ret); } esp_netif_sntp_deinit(); @@ -133,16 +133,16 @@ class RtcDriver { } static void printServers(void) { - Log.debug("List of configured NTP servers:"); + LOGD("List of configured NTP servers:"); for (uint8_t i = 0; i < SNTP_MAX_SERVERS; ++i) { if (esp_sntp_getservername(i)) { - Log.debug(" - server %d: '%s'", i, esp_sntp_getservername(i)); + LOGD(" - server %d: '%s'", i, esp_sntp_getservername(i)); } else { char buff[48]; ip_addr_t const* ip = esp_sntp_getserver(i); if (ipaddr_ntoa_r(ip, buff, 48) != NULL) { - Log.debug(" - server %d: %s", i, buff); + LOGD(" - server %d: %s", i, buff); } } } diff --git a/main/kernel/drivers/SwitchManager.hpp b/main/kernel/drivers/SwitchManager.hpp index e6b644d4..e1dfbb15 100644 --- a/main/kernel/drivers/SwitchManager.hpp +++ b/main/kernel/drivers/SwitchManager.hpp @@ -40,7 +40,7 @@ class SwitchManager { SwitchStateChange stateChange = switchStateInterrupts.take(); auto state = stateChange.switchState; auto engaged = stateChange.engaged; - Log.trace("Switch %s is %s", + LOGV("Switch %s is %s", state->name.c_str(), engaged ? "engaged" : "released"); if (engaged) { state->engagementStarted = system_clock::now(); @@ -66,7 +66,7 @@ class SwitchManager { } const Switch& registerHandler(const String& name, InternalPinPtr pin, SwitchMode mode, SwitchEngagementHandler engagementHandler, SwitchReleaseHandler releaseHandler) { - Log.info("Registering switch %s on pin %s, mode %s", + LOGI("Registering switch %s on pin %s, mode %s", name.c_str(), pin->getName().c_str(), mode == SwitchMode::PullUp ? "pull-up" : "pull-down"); // Configure PIN_INPUT as input diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index 66684f5b..eb7c425c 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -27,7 +27,7 @@ class WiFiDriver { , configPortalRunning(configPortalRunning) , hostname(hostname) , powerSaveMode(powerSaveMode) { - Log.debug("WiFi: initializing"); + LOGD("WiFi: initializing"); // Initialize TCP/IP adapter and event loop ESP_ERROR_CHECK(esp_netif_init()); @@ -81,15 +81,15 @@ class WiFiDriver { void onWiFiEvent(int32_t eventId, void* eventData) { switch (eventId) { case WIFI_EVENT_STA_START: { - Log.debug("WiFi: Started"); + LOGD("WiFi: Started"); esp_err_t err = esp_wifi_connect(); if (err != ESP_OK) { - Log.debug("WiFi: Failed to start connecting: %s", esp_err_to_name(err)); + LOGD("WiFi: Failed to start connecting: %s", esp_err_to_name(err)); } break; } case WIFI_EVENT_STA_STOP: { - Log.debug("WiFi: Stopped"); + LOGD("WiFi: Stopped"); break; } case WIFI_EVENT_STA_CONNECTED: { @@ -99,7 +99,7 @@ class WiFiDriver { Lock lock(metadataMutex); ssid = newSsid; } - Log.debug("WiFi: Connected to the AP %s", + LOGD("WiFi: Connected to the AP %s", newSsid.c_str()); break; } @@ -112,16 +112,16 @@ class WiFiDriver { ssid.reset(); } eventQueue.offer(WiFiEvent::DISCONNECTED); - Log.debug("WiFi: Disconnected from the AP %s, reason: %d", + LOGD("WiFi: Disconnected from the AP %s, reason: %d", String(event->ssid, event->ssid_len).c_str(), event->reason); break; } case WIFI_EVENT_AP_STACONNECTED: { - Log.info("WiFi: SoftAP transport connected"); + LOGI("WiFi: SoftAP transport connected"); break; } case WIFI_EVENT_AP_STADISCONNECTED: { - Log.info("WiFi: SoftAP transport disconnected"); + LOGI("WiFi: SoftAP transport disconnected"); break; } } @@ -138,7 +138,7 @@ class WiFiDriver { ip = event->ip_info.ip; } eventQueue.offer(WiFiEvent::CONNECTED); - Log.debug("WiFi: Got IP - " IPSTR, IP2STR(&event->ip_info.ip)); + LOGD("WiFi: Got IP - " IPSTR, IP2STR(&event->ip_info.ip)); break; } case IP_EVENT_STA_LOST_IP: { @@ -148,7 +148,7 @@ class WiFiDriver { ip.reset(); } eventQueue.offer(WiFiEvent::DISCONNECTED); - Log.debug("WiFi: Lost IP"); + LOGD("WiFi: Lost IP"); break; } } @@ -157,20 +157,20 @@ class WiFiDriver { void onWiFiProvEvent(int32_t eventId, void* eventData) { switch (eventId) { case WIFI_PROV_START: { - Log.debug("WiFi: provisioning started"); + LOGD("WiFi: provisioning started"); // Do not turn WiFi off until provisioning finishes acquire(); break; } case WIFI_PROV_CRED_RECV: { auto wifiConfig = static_cast(eventData); - Log.debug("Received Wi-Fi credentials for SSID '%s'", + LOGD("Received Wi-Fi credentials for SSID '%s'", (const char*) wifiConfig->ssid); break; } case WIFI_PROV_CRED_FAIL: { auto* reason = static_cast(eventData); - Log.debug("WiFi: provisioning failed because %s", + LOGD("WiFi: provisioning failed because %s", *reason == WIFI_PROV_STA_AUTH_ERROR ? "authentication failed" : "AP not found"); @@ -178,11 +178,11 @@ class WiFiDriver { break; } case WIFI_PROV_CRED_SUCCESS: { - Log.debug("WiFi: provisioning successful"); + LOGD("WiFi: provisioning successful"); break; } case WIFI_PROV_END: { - Log.debug("WiFi: provisioning finished"); + LOGD("WiFi: provisioning finished"); wifi_prov_mgr_deinit(); configPortalRunning.clear(); networkConnecting.clear(); @@ -217,18 +217,18 @@ class WiFiDriver { networkRequested.set(); if (!connected) { if (networkConnecting.isSet()) { - Log.trace("WiFi: Already connecting"); + LOGV("WiFi: Already connecting"); } else if (configPortalRunning.isSet()) { - Log.trace("WiFi: Provisioning already running"); + LOGV("WiFi: Provisioning already running"); } else { - Log.trace("WiFi: Connecting for first client"); + LOGV("WiFi: Connecting for first client"); connect(); } } } else { networkRequested.clear(); if (connected && powerSaveMode) { - Log.trace("WiFi: No more clients, disconnecting"); + LOGV("WiFi: No more clients, disconnecting"); disconnect(); } } @@ -238,7 +238,7 @@ class WiFiDriver { void connect() { networkConnecting.set(); #ifdef WOKWI - Log.debug("WiFi: Skipping provisioning on Wokwi"); + LOGD("WiFi: Skipping provisioning on Wokwi"); wifi_config_t wifiConfig = { .sta = { .ssid = "Wokwi-GUEST", @@ -253,11 +253,11 @@ class WiFiDriver { if (provisioned) { wifi_config_t wifiConfig; ESP_ERROR_CHECK(esp_wifi_get_config(WIFI_IF_STA, &wifiConfig)); - Log.debug("WiFi: Connecting using stored credentials to %s (password '%s')", + LOGD("WiFi: Connecting using stored credentials to %s (password '%s')", wifiConfig.sta.ssid, wifiConfig.sta.password); startStation(wifiConfig); } else { - Log.debug("WiFi: No stored credentials, starting provisioning"); + LOGD("WiFi: No stored credentials, starting provisioning"); configPortalRunning.set(); startProvisioning(); } @@ -269,7 +269,7 @@ class WiFiDriver { if (powerSaveMode) { auto listenInterval = 50; - Log.trace("WiFi enabling power save mode, listen interval: %d", + LOGV("WiFi enabling power save mode, listen interval: %d", listenInterval); ESP_ERROR_CHECK(esp_wifi_set_ps(WIFI_PS_MAX_MODEM)); config.sta.listen_interval = listenInterval; @@ -294,7 +294,7 @@ class WiFiDriver { esp_wifi_get_mac(WIFI_IF_STA, mac); snprintf(serviceName, sizeof(serviceName), "%s%02X%02X%02X", ssid_prefix, mac[3], mac[4], mac[5]); - Log.debug("WiFi: Starting provisioning service '%s'", + LOGD("WiFi: Starting provisioning service '%s'", serviceName); ESP_ERROR_CHECK(wifi_prov_mgr_start_provisioning(WIFI_PROV_SECURITY_1, pop, serviceName, serviceKey)); @@ -308,7 +308,7 @@ class WiFiDriver { void disconnect() { networkReady.clear(); - Log.debug("WiFi: Disconnecting"); + LOGD("WiFi: Disconnecting"); ESP_ERROR_CHECK(esp_wifi_disconnect()); ESP_ERROR_CHECK(esp_wifi_stop()); } diff --git a/main/main.cpp b/main/main.cpp index b5dd9b87..a92aed8b 100644 --- a/main/main.cpp +++ b/main/main.cpp @@ -6,6 +6,17 @@ #include #include +#include + +#define FARMHUB_LOG(level, format, ...) \ + ESP_LOG_LEVEL_LOCAL(level, "farmhub", format, ##__VA_ARGS__) + +#define LOGE(format, ...) FARMHUB_LOG(ESP_LOG_ERROR, format, ##__VA_ARGS__) +#define LOGW(format, ...) FARMHUB_LOG(ESP_LOG_WARN, format, ##__VA_ARGS__) +#define LOGI(format, ...) FARMHUB_LOG(ESP_LOG_INFO, format, ##__VA_ARGS__) +#define LOGD(format, ...) FARMHUB_LOG(ESP_LOG_DEBUG, format, ##__VA_ARGS__) +#define LOGV(format, ...) FARMHUB_LOG(ESP_LOG_VERBOSE, format, ##__VA_ARGS__) + #ifdef CONFIG_HEAP_TRACING #include #include @@ -75,6 +86,12 @@ static void dumpPerTaskHeapInfo() { extern "C" void app_main() { initArduino(); +#ifdef FARMHUB_DEBUG + esp_log_level_set("farmhub", ESP_LOG_DEBUG); +#else + esp_log_level_set("farmhub", ESP_LOG_INFO); +#endif + #ifdef CONFIG_HEAP_TRACING ESP_ERROR_CHECK(heap_trace_init_standalone(trace_record, NUM_RECORDS)); #endif diff --git a/main/peripherals/Peripheral.hpp b/main/peripherals/Peripheral.hpp index 8f533d0c..f86a6e68 100644 --- a/main/peripherals/Peripheral.hpp +++ b/main/peripherals/Peripheral.hpp @@ -34,7 +34,7 @@ class PeripheralBase , mqttRoot(mqttRoot) , telemetrySize(telemetrySize) { mqttRoot->registerCommand("ping", [this](const JsonObject& request, JsonObject& response) { - Log.trace("Received ping request"); + LOGV("Received ping request"); publishTelemetry(); response["pong"] = millis(); }); @@ -48,7 +48,7 @@ class PeripheralBase populateTelemetry(telemetryJson); if (telemetryJson.begin() == telemetryJson.end()) { // No telemetry added - Log.trace("No telemetry to publish for peripheral: %s", name.c_str()); + LOGV("No telemetry to publish for peripheral: %s", name.c_str()); return; } mqttRoot->publish("telemetry", telemetryDoc); @@ -80,7 +80,7 @@ class Peripheral } virtual void configure(const TConfig& config) { - Log.trace("No configuration to apply for peripheral: %s", name.c_str()); + LOGV("No configuration to apply for peripheral: %s", name.c_str()); } }; @@ -138,7 +138,7 @@ class PeripheralFactory : public PeripheralFactoryBase { // Use short prefix because SPIFFS has a 32 character limit ConfigurationFile* configFile = new ConfigurationFile(FileSystem::get(), "/p/" + name); mqttRoot->subscribe("config", [name, configFile](const String&, const JsonObject& configJson) { - Log.debug("Received configuration update for peripheral: %s", name.c_str()); + LOGD("Received configuration update for peripheral: %s", name.c_str()); configFile->update(configJson); }); @@ -178,19 +178,19 @@ class PeripheralManager } void registerFactory(PeripheralFactoryBase& factory) { - Log.debug("Registering peripheral factory: %s", + LOGD("Registering peripheral factory: %s", factory.factoryType.c_str()); factories.insert(std::make_pair(factory.factoryType, std::reference_wrapper(factory))); } bool createPeripheral(const String& peripheralConfig, JsonArray peripheralsInitJson) { - Log.info("Creating peripheral with config: %s", + LOGI("Creating peripheral with config: %s", peripheralConfig.c_str()); PeripheralDeviceConfiguration deviceConfig; try { deviceConfig.loadFromString(peripheralConfig); } catch (const std::exception& e) { - Log.error("Failed to parse peripheral config because %s:\n%s", + LOGE("Failed to parse peripheral config because %s:\n%s", e.what(), peripheralConfig.c_str()); return false; } @@ -202,7 +202,7 @@ class PeripheralManager try { Lock lock(stateMutex); if (state == State::Stopped) { - Log.error("Not creating peripheral '%s' because the peripheral manager is stopped", + LOGE("Not creating peripheral '%s' because the peripheral manager is stopped", name.c_str()); return false; } @@ -214,12 +214,12 @@ class PeripheralManager return true; } catch (const std::exception& e) { - Log.error("Failed to create '%s' peripheral '%s' because %s", + LOGE("Failed to create '%s' peripheral '%s' because %s", type.c_str(), name.c_str(), e.what()); initJson["error"] = String(e.what()); return false; } catch (...) { - Log.error("Failed to create '%s' peripheral '%s' because of an unknown exception", + LOGE("Failed to create '%s' peripheral '%s' because of an unknown exception", type.c_str(), name.c_str()); initJson["error"] = "unknown exception"; return false; @@ -229,7 +229,7 @@ class PeripheralManager void publishTelemetry() override { Lock lock(stateMutex); if (state == State::Stopped) { - Log.debug("Not publishing telemetry because the peripheral manager is stopped"); + LOGD("Not publishing telemetry because the peripheral manager is stopped"); return; } for (auto& peripheral : peripherals) { @@ -240,10 +240,10 @@ class PeripheralManager void shutdown() { Lock lock(stateMutex); if (state == State::Stopped) { - Log.debug("Peripheral manager is already stopped"); + LOGD("Peripheral manager is already stopped"); return; } - Log.info("Shutting down peripheral manager"); + LOGI("Shutting down peripheral manager"); state = State::Stopped; PeripheralBase::ShutdownParameters parameters; for (auto& peripheral : peripherals) { @@ -262,7 +262,7 @@ class PeripheralManager }; unique_ptr createPeripheral(const String& name, const String& factoryType, const String& configJson, JsonObject& initConfigJson) { - Log.debug("Creating peripheral '%s' with factory '%s'", + LOGD("Creating peripheral '%s' with factory '%s'", name.c_str(), factoryType.c_str()); auto it = factories.find(factoryType); if (it == factories.end()) { diff --git a/main/peripherals/chicken_door/ChickenDoor.hpp b/main/peripherals/chicken_door/ChickenDoor.hpp index 7bec698a..714cc843 100644 --- a/main/peripherals/chicken_door/ChickenDoor.hpp +++ b/main/peripherals/chicken_door/ChickenDoor.hpp @@ -122,7 +122,7 @@ class ChickenDoorComponent // TODO Make this configurable { - Log.info("Initializing chicken door %s, open switch %s, close switch %s", + LOGI("Initializing chicken door %s, open switch %s, close switch %s", name.c_str(), openSwitch.getPin()->getName().c_str(), closedSwitch.getPin()->getName().c_str()); motor.stop(); @@ -166,7 +166,7 @@ class ChickenDoorComponent void configure(const ChickenDoorConfig& config) { openLevel = config.openLevel.get(); closeLevel = config.closeLevel.get(); - Log.info("Configured chicken door %s to close at %.2f lux, and open at %.2f lux", + LOGI("Configured chicken door %s to close at %.2f lux, and open at %.2f lux", name.c_str(), closeLevel, openLevel); } @@ -182,7 +182,7 @@ class ChickenDoorComponent if (currentState != targetState) { if (currentState != lastState) { - Log.trace("Going from state %d to %d (light level %.2f)", + LOGV("Going from state %d to %d (light level %.2f)", static_cast(currentState), static_cast(targetState), lightSensor.getCurrentLevel()); watchdog.restart(); } @@ -199,7 +199,7 @@ class ChickenDoorComponent } } else { if (currentState != lastState) { - Log.trace("Reached state %d (light level %.2f)", + LOGV("Reached state %d (light level %.2f)", static_cast(currentState), lightSensor.getCurrentLevel()); watchdog.cancel(); motor.stop(); @@ -235,9 +235,9 @@ class ChickenDoorComponent // State update received } else if constexpr (std::is_same_v) { if (arg.state == DoorState::NONE) { - Log.info("Override cancelled"); + LOGI("Override cancelled"); } else { - Log.info("Override received: %d duration: %lld sec", + LOGI("Override received: %d duration: %lld sec", static_cast(arg.state), duration_cast(arg.until - system_clock::now()).count()); } { @@ -247,7 +247,7 @@ class ChickenDoorComponent } this->publishTelemetry(); } else if constexpr (std::is_same_v) { - Log.error("Watchdog timeout, stopping operation"); + LOGE("Watchdog timeout, stopping operation"); operationState = OperationState::WATCHDOG_TIMEOUT; motor.stop(); this->publishTelemetry(); @@ -260,15 +260,15 @@ class ChickenDoorComponent void handleWatchdogEvent(WatchdogState state) { switch (state) { case WatchdogState::Started: - Log.info("Watchdog started"); + LOGI("Watchdog started"); sleepManager.keepAwake(); break; case WatchdogState::Cacnelled: - Log.info("Watchdog cancelled"); + LOGI("Watchdog cancelled"); sleepManager.allowSleep(); break; case WatchdogState::TimedOut: - Log.error("Watchdog timed out"); + LOGE("Watchdog timed out"); sleepManager.allowSleep(); updateQueue.offer(WatchdogTimeout {}); break; @@ -283,7 +283,7 @@ class ChickenDoorComponent bool open = openSwitch.isEngaged(); bool close = closedSwitch.isEngaged(); if (open && close) { - Log.error("Both open and close switches are engaged"); + LOGE("Both open and close switches are engaged"); return DoorState::NONE; } else if (open) { return DoorState::OPEN; @@ -299,7 +299,7 @@ class ChickenDoorComponent return overrideState; } else { if (overrideState != DoorState::NONE) { - Log.info("Override expired, returning to scheduled state"); + LOGI("Override expired, returning to scheduled state"); Lock lock(stateMutex); overrideState = DoorState::NONE; overrideUntil = time_point::min(); @@ -440,8 +440,8 @@ class ChickenDoorFactory throw PeripheralCreationException("Unknown light sensor type: " + lightSensorType); } } catch (const PeripheralCreationException& e) { - Log.error("Could not initialize light sensor because %s", e.what()); - Log.warn("Initializing without a light sensor"); + LOGE("Could not initialize light sensor because %s", e.what()); + LOGW("Initializing without a light sensor"); // TODO Do not pass I2C parameters to NoLightSensorComponent return std::make_unique>(name, mqttRoot, services.i2c, 0x00, services.sleepManager, services.switches, motor, deviceConfig); } diff --git a/main/peripherals/environment/Ds18B20SoilSensor.hpp b/main/peripherals/environment/Ds18B20SoilSensor.hpp index 35fa9bcb..d5e6c6fb 100644 --- a/main/peripherals/environment/Ds18B20SoilSensor.hpp +++ b/main/peripherals/environment/Ds18B20SoilSensor.hpp @@ -35,15 +35,15 @@ class Ds18B20SoilSensorComponent InternalPinPtr pin) : Component(name, mqttRoot) { - Log.info("Initializing DS18B20 soil temperature sensor on pin %s", + LOGI("Initializing DS18B20 soil temperature sensor on pin %s", pin->getName().c_str()); oneWire.begin(pin->getGpio()); // locate devices on the bus - Log.trace("Locating devices..."); + LOGV("Locating devices..."); sensors.begin(); - Log.debug("Found %d devices, parasitic power is %s", + LOGD("Found %d devices, parasitic power is %s", sensors.getDeviceCount(), sensors.isParasitePowerMode() ? "ON" : "OFF"); @@ -53,18 +53,18 @@ class Ds18B20SoilSensorComponent } // show the addresses we found on the bus - Log.debug("Device 0 Address: %s", + LOGD("Device 0 Address: %s", toStringAddress(thermometer).c_str()); } void populateTelemetry(JsonObject& json) override { if (!sensors.requestTemperaturesByIndex(0)) { - Log.error("Failed to get temperature from DS18B20 sensor"); + LOGE("Failed to get temperature from DS18B20 sensor"); return; } float temperature = sensors.getTempCByIndex(0); if (temperature == DEVICE_DISCONNECTED_C) { - Log.error("Failed to get temperature from DS18B20 sensor"); + LOGE("Failed to get temperature from DS18B20 sensor"); return; } json["temperature"] = temperature; diff --git a/main/peripherals/environment/Environment.hpp b/main/peripherals/environment/Environment.hpp index 0ff596d0..04c7cb6b 100644 --- a/main/peripherals/environment/Environment.hpp +++ b/main/peripherals/environment/Environment.hpp @@ -52,7 +52,7 @@ class I2CEnvironmentFactory unique_ptr> createPeripheral(const String& name, const I2CDeviceConfig& deviceConfig, shared_ptr mqttRoot, PeripheralServices& services) override { auto i2cConfig = deviceConfig.parse(defaultAddress); - Log.info("Creating %s sensor %s with %s", + LOGI("Creating %s sensor %s with %s", sensorType.c_str(), name.c_str(), i2cConfig.toString().c_str()); return make_unique>(name, sensorType, mqttRoot, services.i2c, i2cConfig); } diff --git a/main/peripherals/environment/Sht2xComponent.hpp b/main/peripherals/environment/Sht2xComponent.hpp index 27e90976..6cbdcbd0 100644 --- a/main/peripherals/environment/Sht2xComponent.hpp +++ b/main/peripherals/environment/Sht2xComponent.hpp @@ -38,7 +38,7 @@ class Sht2xComponent // TODO Add configuration for fast / slow measurement // TODO Add a separate task to do measurements to unblock telemetry collection? - Log.info("Initializing %s environment sensor with %s", + LOGI("Initializing %s environment sensor with %s", sensorType.c_str(), config.toString().c_str()); if (!sensor.begin()) { @@ -51,7 +51,7 @@ class Sht2xComponent void populateTelemetry(JsonObject& json) override { if (!sensor.read()) { - Log.error("Failed to read environment sensor: %d", + LOGE("Failed to read environment sensor: %d", sensor.getError()); return; } diff --git a/main/peripherals/environment/Sht31Component.hpp b/main/peripherals/environment/Sht31Component.hpp index 58b19a14..1918b2a4 100644 --- a/main/peripherals/environment/Sht31Component.hpp +++ b/main/peripherals/environment/Sht31Component.hpp @@ -34,7 +34,7 @@ class Sht31Component // TODO Add configuration for fast / slow measurement // TODO Add a separate task to do measurements to unblock telemetry collection? - Log.info("Initializing %s environment sensor with %s", + LOGI("Initializing %s environment sensor with %s", sensorType.c_str(), config.toString().c_str()); if (!sensor.begin()) { @@ -47,7 +47,7 @@ class Sht31Component void populateTelemetry(JsonObject& json) override { if (!sensor.read()) { - Log.error("Failed to read SHT3x environment sensor: %d", + LOGE("Failed to read SHT3x environment sensor: %d", sensor.getError()); return; } diff --git a/main/peripherals/environment/SoilMoistureSensor.hpp b/main/peripherals/environment/SoilMoistureSensor.hpp index 4bb7fe11..84aa288f 100644 --- a/main/peripherals/environment/SoilMoistureSensor.hpp +++ b/main/peripherals/environment/SoilMoistureSensor.hpp @@ -38,7 +38,7 @@ class SoilMoistureSensorComponent , waterValue(config.water.get()) , pin(config.pin.get()) { - Log.info("Initializing soil moisture sensor on pin %s; air value: %d; water value: %d", + LOGI("Initializing soil moisture sensor on pin %s; air value: %d; water value: %d", pin->getName().c_str(), airValue, waterValue); pin->pinMode(INPUT); @@ -46,7 +46,7 @@ class SoilMoistureSensorComponent void populateTelemetry(JsonObject& json) override { uint16_t soilMoistureValue = pin->analogRead(); - Log.trace("Soil moisture value: %d", + LOGV("Soil moisture value: %d", soilMoistureValue); const double run = waterValue - airValue; diff --git a/main/peripherals/fence/ElectricFenceMonitor.hpp b/main/peripherals/fence/ElectricFenceMonitor.hpp index ce408454..a68160d7 100644 --- a/main/peripherals/fence/ElectricFenceMonitor.hpp +++ b/main/peripherals/fence/ElectricFenceMonitor.hpp @@ -58,7 +58,7 @@ class ElectricFenceMonitorComponent pinsDescription += ", "; pinsDescription += pinConfig.pin->getName() + "=" + String(pinConfig.voltage) + "V"; } - Log.info("Initializing electric fence with pins %s", pinsDescription.c_str()); + LOGI("Initializing electric fence with pins %s", pinsDescription.c_str()); for (auto& pinConfig : config.pins.get()) { auto unit = pcnt.registerUnit(pinConfig.pin); @@ -74,7 +74,7 @@ class ElectricFenceMonitorComponent if (count > 0) { lastVoltage = max(pin.voltage, lastVoltage); - Log.trace("Counted %d pulses on pin %s (voltage: %dV)", + LOGV("Counted %d pulses on pin %s (voltage: %dV)", count, pin.pcntUnit.getPin()->getName().c_str(), pin.voltage); } } @@ -82,7 +82,7 @@ class ElectricFenceMonitorComponent Lock lock(updateMutex); this->lastVoltage = lastVoltage; } - Log.trace("Last voltage: %d", + LOGV("Last voltage: %d", lastVoltage); task.delayUntil(measurementFrequency); }); diff --git a/main/peripherals/flow_meter/FlowMeterComponent.hpp b/main/peripherals/flow_meter/FlowMeterComponent.hpp index 96b8ec16..8fc04ab9 100644 --- a/main/peripherals/flow_meter/FlowMeterComponent.hpp +++ b/main/peripherals/flow_meter/FlowMeterComponent.hpp @@ -33,7 +33,7 @@ class FlowMeterComponent : Component(name, mqttRoot) , qFactor(qFactor) { - Log.info("Initializing flow meter on pin %s with Q = %.2f", + LOGI("Initializing flow meter on pin %s with Q = %.2f", pin->getName().c_str(), qFactor); pcntUnit = pcnt.registerUnit(pin); @@ -54,7 +54,7 @@ class FlowMeterComponent if (pulses > 0) { Lock lock(updateMutex); double currentVolume = pulses / this->qFactor / 60.0f; - Log.trace("Counted %d pulses, %.2f l/min, %.2f l", + LOGV("Counted %d pulses, %.2f l/min, %.2f l", pulses, currentVolume / (elapsed.count() / 1000.0f / 60.0f), currentVolume); volume += currentVolume; lastSeenFlow = now; diff --git a/main/peripherals/light_sensor/Bh1750.hpp b/main/peripherals/light_sensor/Bh1750.hpp index 2a76616b..c9e4dc10 100644 --- a/main/peripherals/light_sensor/Bh1750.hpp +++ b/main/peripherals/light_sensor/Bh1750.hpp @@ -47,7 +47,7 @@ class Bh1750Component : LightSensorComponent(name, mqttRoot, measurementFrequency, latencyInterval) , sensor(config.address) { - Log.info("Initializing BH1750 light sensor with %s", + LOGI("Initializing BH1750 light sensor with %s", config.toString().c_str()); // TODO Make mode configurable diff --git a/main/peripherals/light_sensor/Tsl2591.hpp b/main/peripherals/light_sensor/Tsl2591.hpp index 9d78055a..00efe621 100644 --- a/main/peripherals/light_sensor/Tsl2591.hpp +++ b/main/peripherals/light_sensor/Tsl2591.hpp @@ -47,7 +47,7 @@ class Tsl2591Component seconds latencyInterval) : LightSensorComponent(name, mqttRoot, measurementFrequency, latencyInterval) { - Log.info("Initializing TSL2591 light sensor with %s", + LOGI("Initializing TSL2591 light sensor with %s", config.toString().c_str()); if (!sensor.begin(&i2c.getWireFor(config), config.address)) { @@ -60,7 +60,7 @@ class Tsl2591Component sensor_t sensorInfo; sensor.getSensor(&sensorInfo); - Log.debug("Found sensor: %s, driver version: %ld, unique ID: %ld, max value: %.2f lux, min value: %.2f lux, resolution: %.2f mlux", + LOGD("Found sensor: %s, driver version: %ld, unique ID: %ld, max value: %.2f lux, min value: %.2f lux, resolution: %.2f mlux", sensorInfo.name, sensorInfo.version, sensorInfo.sensor_id, sensorInfo.max_value, sensorInfo.min_value, sensorInfo.resolution * 1000); runLoop(); diff --git a/main/peripherals/multiplexer/Xl9535.hpp b/main/peripherals/multiplexer/Xl9535.hpp index a177f5ab..31d8005c 100644 --- a/main/peripherals/multiplexer/Xl9535.hpp +++ b/main/peripherals/multiplexer/Xl9535.hpp @@ -24,7 +24,7 @@ class Xl9535Component I2CConfig config) : Component(name, mqttRoot) , device(i2c.createDevice(name, config)) { - Log.info("Initializing XL9535 multiplexer with %s", + LOGI("Initializing XL9535 multiplexer with %s", config.toString().c_str()); } @@ -129,7 +129,7 @@ class Xl9535 // Create a pin for each bit in the pins mask for (int i = 0; i < 16; i++) { String pinName = name + ":" + String(i); - Log.trace("Registering external pin %s", + LOGV("Registering external pin %s", pinName.c_str()); auto pin = std::make_shared(pinName, component, i); Pin::registerPin(pinName, pin); diff --git a/main/peripherals/valve/ValveComponent.hpp b/main/peripherals/valve/ValveComponent.hpp index d45e6828..8eb00991 100644 --- a/main/peripherals/valve/ValveComponent.hpp +++ b/main/peripherals/valve/ValveComponent.hpp @@ -213,18 +213,18 @@ class ValveComponent : public Component { , strategy(strategy) , publishTelemetry(publishTelemetry) { - Log.info("Creating valve '%s' with strategy %s", + LOGI("Creating valve '%s' with strategy %s", name.c_str(), strategy.describe().c_str()); ValveState initState; switch (strategy.getDefaultState()) { case ValveState::OPEN: - Log.info("Assuming valve '%s' is open by default", + LOGI("Assuming valve '%s' is open by default", name.c_str()); initState = ValveState::OPEN; break; case ValveState::CLOSED: - Log.info("Assuming valve '%s' is closed by default", + LOGI("Assuming valve '%s' is closed by default", name.c_str()); initState = ValveState::CLOSED; break; @@ -233,11 +233,11 @@ class ValveComponent : public Component { ValveState lastStoredState; if (nvs.get("state", lastStoredState)) { initState = lastStoredState; - Log.info("Restored state for valve '%s' from NVS: %d", + LOGI("Restored state for valve '%s' from NVS: %d", name.c_str(), static_cast(state)); } else { initState = ValveState::CLOSED; - Log.info("No stored state for valve '%s', defaulting to closed", + LOGI("No stored state for valve '%s', defaulting to closed", name.c_str()); } break; @@ -261,7 +261,7 @@ class ValveComponent : public Component { Task::loop(name, 4096, [this, name](Task& task) { auto now = system_clock::now(); if (overrideState != ValveState::NONE && now >= overrideUntil.load()) { - Log.info("Valve '%s' override expired", name.c_str()); + LOGI("Valve '%s' override expired", name.c_str()); overrideUntil = time_point(); overrideState = ValveState::NONE; } @@ -276,7 +276,7 @@ class ValveComponent : public Component { update.state = ValveState::CLOSED; } } - Log.info("Valve '%s' state is %d, will change after %.2f sec at %lld", + LOGI("Valve '%s' state is %d, will change after %.2f sec at %lld", name.c_str(), static_cast(update.state), duration_cast(update.validFor).count() / 1000.0, @@ -305,7 +305,7 @@ class ValveComponent : public Component { } void setSchedules(const std::list& schedules) { - Log.debug("Setting %d schedules for valve %s", + LOGD("Setting %d schedules for valve %s", schedules.size(), name.c_str()); updateQueue.put(ScheduleSpec { schedules }); } @@ -325,7 +325,7 @@ class ValveComponent : public Component { void closeBeforeShutdown() { // TODO Lock the valve to prevent concurrent access - Log.info("Shutting down valve '%s', closing it", + LOGI("Shutting down valve '%s', closing it", name.c_str()); close(); } @@ -333,23 +333,23 @@ class ValveComponent : public Component { private: void override(ValveState state, time_point until) { if (state == ValveState::NONE) { - Log.info("Clearing override for valve '%s'", name.c_str()); + LOGI("Clearing override for valve '%s'", name.c_str()); } else { - Log.info("Overriding valve '%s' to state %d until %lld", + LOGI("Overriding valve '%s' to state %d until %lld", name.c_str(), static_cast(state), duration_cast(until.time_since_epoch()).count()); } updateQueue.put(OverrideSpec { state, until }); } void open() { - Log.info("Opening valve '%s'", name.c_str()); + LOGI("Opening valve '%s'", name.c_str()); KeepAwake keepAwake(sleepManager); strategy.open(); setState(ValveState::OPEN); } void close() { - Log.info("Closing valve '%s'", name.c_str()); + LOGI("Closing valve '%s'", name.c_str()); KeepAwake keepAwake(sleepManager); strategy.close(); setState(ValveState::CLOSED); @@ -385,7 +385,7 @@ class ValveComponent : public Component { void setState(ValveState state) { this->state = state; if (!nvs.set("state", state)) { - Log.error("Failed to store state for valve '%s': %d", + LOGE("Failed to store state for valve '%s': %d", name.c_str(), static_cast(state)); } } diff --git a/main/peripherals/valve/ValveConfig.hpp b/main/peripherals/valve/ValveConfig.hpp index 3be5d488..a64a26c7 100644 --- a/main/peripherals/valve/ValveConfig.hpp +++ b/main/peripherals/valve/ValveConfig.hpp @@ -107,7 +107,7 @@ bool convertToJson(const ValveControlStrategyType& src, JsonVariant dst) { case ValveControlStrategyType::Latching: return dst.set("latching"); default: - Log.error("Unknown strategy: %d", + LOGE("Unknown strategy: %d", static_cast(src)); return dst.set("NC"); } @@ -121,7 +121,7 @@ void convertFromJson(JsonVariantConst src, ValveControlStrategyType& dst) { } else if (strategy == "latching") { dst = ValveControlStrategyType::Latching; } else { - Log.error("Unknown strategy: %s", + LOGE("Unknown strategy: %s", strategy.c_str()); dst = ValveControlStrategyType::NormallyClosed; } diff --git a/main/peripherals/valve/ValveScheduler.hpp b/main/peripherals/valve/ValveScheduler.hpp index 7595d9be..b8c4e4e0 100644 --- a/main/peripherals/valve/ValveScheduler.hpp +++ b/main/peripherals/valve/ValveScheduler.hpp @@ -61,7 +61,7 @@ class ValveScheduler { auto duration = schedule.getDuration(); #ifndef GTEST - Log.info("Considering schedule starting at %lld (current time: %lld), period %lld, duration %lld", + LOGI("Considering schedule starting at %lld (current time: %lld), period %lld, duration %lld", duration_cast(start.time_since_epoch()).count(), duration_cast(now.time_since_epoch()).count(), duration_cast(period).count(), @@ -82,7 +82,7 @@ class ValveScheduler { // Damn you, C++ chrono, for not having a working modulo operator auto periodPosition = nanoseconds(duration_cast(diff).count() % duration_cast(period).count()); #ifndef GTEST - Log.info("Diff: %lld sec, at: %lld sec, should be open until %lld / %lld sec", + LOGI("Diff: %lld sec, at: %lld sec, should be open until %lld / %lld sec", duration_cast(diff).count(), duration_cast(periodPosition).count(), duration_cast(duration).count(), diff --git a/sdkconfig.defaults b/sdkconfig.defaults index 28527c72..e15a61d7 100644 --- a/sdkconfig.defaults +++ b/sdkconfig.defaults @@ -17,6 +17,7 @@ CONFIG_COMPILER_CXX_EXCEPTIONS=y # Less chatty CONFIG_BOOTLOADER_LOG_LEVEL_ERROR=y CONFIG_LOG_DEFAULT_LEVEL_WARN=y +CONFIG_LOG_MAXIMUM_LEVEL_VERBOSE=y # Seems like a good idea to have some stack checks CONFIG_COMPILER_STACK_CHECK_MODE_NORM=y From 48b598f77453557896a10d8a13e43cdeb2af1ab2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 13:48:50 +0100 Subject: [PATCH 58/64] Use ESP-IDF log, take 2 --- main/devices/Device.hpp | 186 +++++++++--------- main/kernel/Command.hpp | 3 +- main/kernel/FileSystem.hpp | 2 - main/kernel/I2CManager.hpp | 1 - main/kernel/Kernel.hpp | 9 +- main/kernel/Log.hpp | 169 +++------------- main/kernel/NvsStore.hpp | 1 - main/kernel/PcntManager.hpp | 2 - main/kernel/PwmManager.hpp | 2 - main/kernel/SleepManager.hpp | 1 - main/kernel/Task.hpp | 5 +- main/kernel/drivers/BatteryDriver.hpp | 1 - main/kernel/drivers/Bq27220Driver.hpp | 1 - main/kernel/drivers/LedDriver.hpp | 1 - main/kernel/drivers/MdnsDriver.hpp | 1 - main/kernel/drivers/RtcDriver.hpp | 1 - main/kernel/drivers/SwitchManager.hpp | 1 - main/kernel/drivers/WiFiDriver.hpp | 1 - main/main.cpp | 17 +- main/peripherals/Peripheral.hpp | 3 +- main/peripherals/chicken_door/ChickenDoor.hpp | 1 - main/peripherals/environment/Environment.hpp | 1 - .../environment/Sht2xComponent.hpp | 1 - .../environment/Sht31Component.hpp | 1 - .../environment/SoilMoistureSensor.hpp | 1 - .../fence/ElectricFenceMonitor.hpp | 1 - .../flow_meter/FlowMeterComponent.hpp | 1 - main/peripherals/light_sensor/Bh1750.hpp | 1 - main/peripherals/light_sensor/LightSensor.hpp | 1 - main/peripherals/light_sensor/Tsl2591.hpp | 1 - main/peripherals/valve/ValveComponent.hpp | 1 - main/peripherals/valve/ValveConfig.hpp | 1 - sdkconfig.defaults | 3 + 33 files changed, 131 insertions(+), 292 deletions(-) diff --git a/main/devices/Device.hpp b/main/devices/Device.hpp index 50d3f8ac..34a6bf3e 100644 --- a/main/devices/Device.hpp +++ b/main/devices/Device.hpp @@ -15,7 +15,6 @@ #include #include #include -#include #include #include @@ -94,7 +93,8 @@ namespace farmhub::devices { #ifdef FARMHUB_DEBUG class ConsolePrinter { public: - ConsolePrinter() { + ConsolePrinter(const shared_ptr battery) + : battery(battery) { status.reserve(256); Task::loop("console", 3072, 1, [this](Task& task) { printStatus(); @@ -102,60 +102,6 @@ class ConsolePrinter { }); } - void registerBattery(std::shared_ptr battery) { - Lock lock(batteryMutex); - this->battery = battery; - } - - void printLog(Level level, const char* message) { - static char timeBuffer[12]; - sprintf(timeBuffer, "%8.3f", millis() / 1000.0); - String* buffer = new String(); - buffer->reserve(256); - buffer->concat("\033[0;90m"); - buffer->concat(timeBuffer); - buffer->concat("\033[0m [\033[0;31m"); - buffer->concat(pcTaskGetName(nullptr)); - buffer->concat("\033[0m@\033[0;32m"); - buffer->concat(xPortGetCoreID()); - buffer->concat("\033[0m"); -#ifdef CONFIG_HEAP_TRACING - buffer->concat("|S:"); - buffer->concat(uxTaskGetStackHighWaterMark(nullptr)); - buffer->concat("B|H:"); - buffer->concat(((float) ESP.getFreeHeap()) / 1024.0f); - buffer->concat("kB"); -#endif - buffer->concat("] "); - switch (level) { - case Level::Fatal: - buffer->concat("\033[0;31mFATAL\033[0m "); - break; - case Level::Error: - buffer->concat("\033[0;31mERROR\033[0m "); - break; - case Level::Warning: - buffer->concat("\033[0;33mWARNING\033[0m "); - break; - case Level::Info: - buffer->concat("\033[0;32mINFO\033[0m "); - break; - case Level::Debug: - buffer->concat("\033[0;34mDEBUG\033[0m "); - break; - case Level::Trace: - buffer->concat("\033[0;36mTRACE\033[0m "); - break; - default: - break; - } - buffer->concat(message); - if (!consoleQueue.offer(*buffer)) { - Log.printlnToSerial(buffer->c_str()); - } - delete buffer; - } - private: void printStatus() { static const char* spinner = "|/-\\"; @@ -190,22 +136,13 @@ class ConsolePrinter { status.concat(esp_clk_cpu_freq() / 1000000); status.concat("\033[0m MHz"); - { - Lock lock(batteryMutex); - if (battery != nullptr) { - status.concat(", battery: \033[33m"); - status.concat(String(battery->getVoltage(), 2)); - status.concat("\033[0m V"); - } + if (battery != nullptr) { + status.concat(", battery: \033[33m"); + status.concat(String(battery->getVoltage(), 2)); + status.concat("\033[0m V"); } - Log.printToSerial("\033[1G\033[0K"); - - consoleQueue.drain([](const String& line) { - Log.printlnToSerial(line.c_str()); - }); - - Log.printToSerial(status.c_str()); + printf("\033[1G\033[0K%s", status.c_str()); } static const char* wifiStatus() { @@ -262,13 +199,8 @@ class ConsolePrinter { int counter; String status; - Mutex batteryMutex; - std::shared_ptr battery; - - Queue consoleQueue { "console", 16 }; + const std::shared_ptr battery; }; - -ConsolePrinter consolePrinter; #endif struct LogRecord { @@ -276,11 +208,29 @@ struct LogRecord { String message; }; -class ConsoleProvider : public LogConsumer { +#define FARMHUB_LOG_COLOR_BLACK "30" +#define FARMHUB_LOG_COLOR_RED "31" +#define FARMHUB_LOG_COLOR_GREEN "32" +#define FARMHUB_LOG_COLOR_BROWN "33" +#define FARMHUB_LOG_COLOR_BLUE "34" +#define FARMHUB_LOG_COLOR_PURPLE "35" +#define FARMHUB_LOG_COLOR_CYAN "36" +#define FARMHUB_LOG_COLOR(COLOR) "\033[0;" COLOR "m" +#define FARMHUB_LOG_BOLD(COLOR) "\033[1;" COLOR "m" +#define FARMHUB_LOG_RESET_COLOR "\033[0m" + +class ConsoleProvider; + +static ConsoleProvider* consoleProvider; + +class ConsoleProvider { public: ConsoleProvider(Queue& logRecords, Level recordedLevel) : logRecords(logRecords) , recordedLevel(recordedLevel) { + consoleProvider = this; + originalVprintf = esp_log_set_vprintf(ConsoleProvider::processLogFunc); + #ifndef WOKWI Serial.begin(115200); Serial1.begin(115200, SERIAL_8N1, pins::RXD0->getGpio(), pins::TXD0->getGpio()); @@ -288,23 +238,77 @@ class ConsoleProvider : public LogConsumer { Serial0.begin(115200); #endif #endif - Log.setConsumer(this); } - void consumeLog(Level level, const char* message) override { +private: + static int processLogFunc(const char* format, va_list args) { + return consoleProvider->processLog(format, args); + } + + int processLog(const char* format, va_list args) { + Level level = getLevel(format[0]); if (level <= recordedLevel) { - logRecords.offer(level, message); + std::lock_guard lock(bufferMutex); + vsnprintf(buffer, sizeof(buffer), format, args); + logRecords.offer(level, buffer); + } + +#ifdef FARMHUB_DEBUG + // Erase the current line + printf("\033[1G\033[0K"); + switch (level) { + case Level::Error: + printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_RED)); + break; + case Level::Warning: + printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_BROWN)); + break; + case Level::Info: + printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_GREEN)); + break; + default: + break; } +#endif + + int count = originalVprintf(format, args); + #ifdef FARMHUB_DEBUG - consolePrinter.printLog(level, message); -#else - Log.printlnToSerial(message); + switch (level) { + case Level::Error: + case Level::Warning: + case Level::Info: + printf(FARMHUB_LOG_RESET_COLOR); + break; + default: + break; + } #endif + return count; } -private: + static inline Level getLevel(char c) { + switch (c) { + case 'E': + return Level::Error; + case 'W': + return Level::Warning; + case 'I': + return Level::Info; + case 'D': + return Level::Debug; + case 'V': + return Level::Verbose; + default: + return Level::Info; + } + } + + vprintf_like_t originalVprintf; Queue& logRecords; const Level recordedLevel; + std::mutex bufferMutex; + char buffer[128]; }; class MemoryTelemetryProvider : public TelemetryProvider { @@ -341,15 +345,11 @@ class ConfiguredKernel { // due to the high current draw of the boot process. auto voltage = battery->getVoltage(); if (voltage != 0.0 && voltage < BATTERY_BOOT_THRESHOLD) { - Log.printfToSerial("Battery voltage too low (%.2f V < %.2f), entering deep sleep\n", + ESP_LOGW("battery", "Battery voltage too low (%.2f V < %.2f), entering deep sleep\n", voltage, BATTERY_BOOT_THRESHOLD); enterLowPowerDeepSleep(); } -#ifdef FARMHUB_DEBUG - consolePrinter.registerBattery(battery); -#endif - Task::loop("battery", 1536, [this](Task& task) { checkBatteryVoltage(task); }); @@ -377,6 +377,10 @@ class ConfiguredKernel { const shared_ptr battery; private: +#ifdef FARMHUB_DEBUG + ConsolePrinter consolePrinter { battery }; +#endif + void checkBatteryVoltage(Task& task) { task.delayUntil(LOW_POWER_CHECK_INTERVAL); auto currentVoltage = battery->getVoltage(); @@ -396,7 +400,7 @@ class ConfiguredKernel { for (auto& listener : shutdownListeners) { listener(); } - Log.printlnToSerial("Shutdown process finished"); + printf("Shutdown process finished\n"); }); task.delay(LOW_BATTERY_SHUTDOWN_TIMEOUT); enterLowPowerDeepSleep(); @@ -404,7 +408,7 @@ class ConfiguredKernel { } [[noreturn]] inline void enterLowPowerDeepSleep() { - Log.printlnToSerial("Entering low power deep sleep"); + printf("Entering low power deep sleep\n"); ESP.deepSleep(duration_cast(LOW_POWER_SLEEP_CHECK_INTERVAL).count()); // Signal to the compiler that we are not returning for real abort(); diff --git a/main/kernel/Command.hpp b/main/kernel/Command.hpp index 4e4c1ce4..1ba21467 100644 --- a/main/kernel/Command.hpp +++ b/main/kernel/Command.hpp @@ -9,7 +9,6 @@ #include #include -#include #include #include @@ -65,7 +64,7 @@ class RestartCommand : public Command { : Command("restart") { } void handle(const JsonObject& request, JsonObject& response) override { - Log.printlnToSerial("Restarting..."); + printf("Restarting...\n"); Serial.flush(); ESP.restart(); } diff --git a/main/kernel/FileSystem.hpp b/main/kernel/FileSystem.hpp index 5b54e794..c4fe49ff 100644 --- a/main/kernel/FileSystem.hpp +++ b/main/kernel/FileSystem.hpp @@ -2,8 +2,6 @@ #include -#include - namespace farmhub::kernel { class FileSystem; diff --git a/main/kernel/I2CManager.hpp b/main/kernel/I2CManager.hpp index 897bb48a..a44e2fda 100644 --- a/main/kernel/I2CManager.hpp +++ b/main/kernel/I2CManager.hpp @@ -8,7 +8,6 @@ #include #include -#include #include namespace farmhub::kernel { diff --git a/main/kernel/Kernel.hpp b/main/kernel/Kernel.hpp index 0d3416e9..d7cbdcce 100644 --- a/main/kernel/Kernel.hpp +++ b/main/kernel/Kernel.hpp @@ -15,7 +15,6 @@ #include #include -#include #include #include #include @@ -110,7 +109,7 @@ class Kernel { } void performFactoryReset(bool completeReset) { - Log.printlnToSerial("Performing factory reset"); + LOGI("Performing factory reset"); statusLed.turnOn(); delay(1000); @@ -124,14 +123,14 @@ class Kernel { delay(1000); statusLed.turnOn(); - Log.printlnToSerial(" - Deleting the file system..."); + LOGI(" - Deleting the file system..."); fs.reset(); } - Log.printlnToSerial(" - Clearing NVS..."); + LOGI(" - Clearing NVS..."); nvs_flash_erase(); - Log.printlnToSerial(" - Restarting..."); + LOGI(" - Restarting..."); ESP.restart(); } diff --git a/main/kernel/Log.hpp b/main/kernel/Log.hpp index 698cb071..525c33b8 100644 --- a/main/kernel/Log.hpp +++ b/main/kernel/Log.hpp @@ -1,34 +1,31 @@ #pragma once -#include -#include +#include #include -#include +#include namespace farmhub::kernel { -#define FARMHUB_LOG_LEVEL_SILENT 0 -#define FARMHUB_LOG_LEVEL_FATAL 1 -#define FARMHUB_LOG_LEVEL_ERROR 2 -#define FARMHUB_LOG_LEVEL_WARNING 3 -#define FARMHUB_LOG_LEVEL_INFO 4 -#define FARMHUB_LOG_LEVEL_DEBUG 5 -#define FARMHUB_LOG_LEVEL_TRACE 6 -#define FARMHUB_LOG_LEVEL_ALL 100 - enum class Level { - Silent = FARMHUB_LOG_LEVEL_SILENT, - Fatal = FARMHUB_LOG_LEVEL_FATAL, - Error = FARMHUB_LOG_LEVEL_ERROR, - Warning = FARMHUB_LOG_LEVEL_WARNING, - Info = FARMHUB_LOG_LEVEL_INFO, - Debug = FARMHUB_LOG_LEVEL_DEBUG, - Trace = FARMHUB_LOG_LEVEL_TRACE, - All = FARMHUB_LOG_LEVEL_ALL + None = ESP_LOG_NONE, + Error = ESP_LOG_ERROR, + Warning = ESP_LOG_WARN, + Info = ESP_LOG_INFO, + Debug = ESP_LOG_DEBUG, + Verbose = ESP_LOG_VERBOSE, }; +#define FARMHUB_LOG(level, format, ...) \ + ESP_LOG_LEVEL_LOCAL(level, "farmhub", format, ##__VA_ARGS__) + +#define LOGE(format, ...) FARMHUB_LOG(ESP_LOG_ERROR, format, ##__VA_ARGS__) +#define LOGW(format, ...) FARMHUB_LOG(ESP_LOG_WARN, format, ##__VA_ARGS__) +#define LOGI(format, ...) FARMHUB_LOG(ESP_LOG_INFO, format, ##__VA_ARGS__) +#define LOGD(format, ...) FARMHUB_LOG(ESP_LOG_DEBUG, format, ##__VA_ARGS__) +#define LOGV(format, ...) FARMHUB_LOG(ESP_LOG_VERBOSE, format, ##__VA_ARGS__) + #ifndef FARMHUB_LOG_LEVEL #ifdef FARMHUB_DEBUG #define FARMHUB_LOG_LEVEL FARMHUB_LOG_LEVEL_DEBUG @@ -44,132 +41,12 @@ void convertFromJson(JsonVariantConst src, Level& dst) { dst = static_cast(src.as()); } -class LogConsumer { -public: - virtual void consumeLog(Level level, const char* message) = 0; -}; - -class FarmhubLog : public LogConsumer { -public: - inline void __attribute__((format(printf, 2, 3))) fatal(const char* format, ...) { -#if FARMHUB_LOG_LEVEL >= FARMHUB_LOG_LEVEL_FATAL - va_list args; - va_start(args, format); - logImpl(Level::Fatal, format, args); - va_end(args); -#endif - } - - inline void __attribute__((format(printf, 2, 3))) error(const char* format, ...) { -#if FARMHUB_LOG_LEVEL >= FARMHUB_LOG_LEVEL_ERROR - va_list args; - va_start(args, format); - logImpl(Level::Error, format, args); - va_end(args); -#endif - } - - inline void __attribute__((format(printf, 2, 3))) warn(const char* format, ...) { -#if FARMHUB_LOG_LEVEL >= FARMHUB_LOG_LEVEL_WARNING - va_list args; - va_start(args, format); - logImpl(Level::Warning, format, args); - va_end(args); -#endif - } - - inline void __attribute__((format(printf, 2, 3))) info(const char* format, ...) { -#if FARMHUB_LOG_LEVEL >= FARMHUB_LOG_LEVEL_INFO - va_list args; - va_start(args, format); - logImpl(Level::Info, format, args); - va_end(args); -#endif - } - - inline void __attribute__((format(printf, 2, 3))) debug(const char* format, ...) { -#if FARMHUB_LOG_LEVEL >= FARMHUB_LOG_LEVEL_DEBUG - va_list args; - va_start(args, format); - logImpl(Level::Debug, format, args); - va_end(args); -#endif - } - - inline void __attribute__((format(printf, 2, 3))) trace(const char* format, ...) { -#if FARMHUB_LOG_LEVEL >= FARMHUB_LOG_LEVEL_TRACE - va_list args; - va_start(args, format); - logImpl(Level::Trace, format, args); - va_end(args); +static void initLogging() { +#ifdef FARMHUB_DEBUG + esp_log_level_set("farmhub", ESP_LOG_DEBUG); +#else + esp_log_level_set("farmhub", ESP_LOG_INFO); #endif - } - - void __attribute__((format(printf, 3, 4))) log(Level level, const char* format, ...) { - va_list args; - va_start(args, format); - logImpl(level, format, args); - va_end(args); - } - - void log(Level level, const __FlashStringHelper* format, ...) { - int len = strnlen_P(reinterpret_cast(format), bufferSize - 1); - char formatInSram[len + 1]; - strncpy_P(formatInSram, reinterpret_cast(format), len); - formatInSram[len] = '\0'; - va_list args; - va_start(args, format); - logImpl(level, formatInSram, args); - va_end(args); - } - - void setConsumer(LogConsumer* consumer) { - this->consumer = consumer; - } - - /** - * @brief Default implementation of LogConsumer. - */ - void consumeLog(Level level, const char* message) override { - printlnToSerial(message); - } - - void printlnToSerial(const char* message = "") { - printf("%s\n", message); - } - - void printToSerial(const char* message) { - printf("%s", message); - } - - inline void __attribute__((format(printf, 2, 3))) printfToSerial(const char* format, ...) { - va_list args; - va_start(args, format); - vprintf(format, args); - va_end(args); - } - -private: - void logImpl(Level level, const char* format, va_list args) { - int size = vsnprintf(nullptr, 0, format, args); - if (size <= 0) { - return; - } - - auto capacity = std::min(size + 1, bufferSize); - Lock lock(bufferMutex); - vsnprintf(buffer, capacity, format, args); - consumer.load()->consumeLog(level, buffer); - } - - constexpr static int bufferSize = 128; - // TODO Maybe use a thread_local here? - Mutex bufferMutex; - char buffer[bufferSize]; - std::atomic consumer { this }; -}; - -extern FarmhubLog Log; -FarmhubLog Log = FarmhubLog(); +} } // namespace farmhub::kernel diff --git a/main/kernel/NvsStore.hpp b/main/kernel/NvsStore.hpp index 507baa33..22357170 100644 --- a/main/kernel/NvsStore.hpp +++ b/main/kernel/NvsStore.hpp @@ -7,7 +7,6 @@ #include #include -#include namespace farmhub::kernel { diff --git a/main/kernel/PcntManager.hpp b/main/kernel/PcntManager.hpp index 2c61de26..dc6ec652 100644 --- a/main/kernel/PcntManager.hpp +++ b/main/kernel/PcntManager.hpp @@ -6,8 +6,6 @@ #include -#include - namespace farmhub::kernel { // TODO Figure out what to do with low/high speed modes diff --git a/main/kernel/PwmManager.hpp b/main/kernel/PwmManager.hpp index e425ba08..d10803b3 100644 --- a/main/kernel/PwmManager.hpp +++ b/main/kernel/PwmManager.hpp @@ -2,8 +2,6 @@ #include -#include - namespace farmhub::kernel { // TODO Figure out what to do with low/high speed modes diff --git a/main/kernel/SleepManager.hpp b/main/kernel/SleepManager.hpp index ae27718b..5b161ec0 100644 --- a/main/kernel/SleepManager.hpp +++ b/main/kernel/SleepManager.hpp @@ -5,7 +5,6 @@ #include #include -#include // FIXME Why do we need to define these manually? #if CONFIG_IDF_TARGET_ESP32 diff --git a/main/kernel/Task.hpp b/main/kernel/Task.hpp index 7a34d0e3..10d5a484 100644 --- a/main/kernel/Task.hpp +++ b/main/kernel/Task.hpp @@ -8,7 +8,6 @@ #include -#include #include using namespace std::chrono; @@ -142,7 +141,7 @@ class Task { return true; } auto newWakeTime = xTaskGetTickCount(); - Log.printfToSerial("Task '%s' missed deadline by %lld ms\n", + printf("Task '%s' missed deadline by %lld ms\n", pcTaskGetName(nullptr), duration_cast(ticks(newWakeTime - lastWakeTime)).count()); lastWakeTime = newWakeTime; return false; @@ -164,7 +163,7 @@ class Task { return time - (currentTime - ticks(lastWakeTime)); } else { // 'currentTime' has surpassed our target time, indicating the delay has expired. - Log.printfToSerial("Task '%s' is already past deadline by %lld ms\n", + printf("Task '%s' is already past deadline by %lld ms\n", pcTaskGetName(nullptr), duration_cast(currentTime - ticks(lastWakeTime)).count()); return ticks::zero(); } diff --git a/main/kernel/drivers/BatteryDriver.hpp b/main/kernel/drivers/BatteryDriver.hpp index aa87de81..7993f23b 100644 --- a/main/kernel/drivers/BatteryDriver.hpp +++ b/main/kernel/drivers/BatteryDriver.hpp @@ -2,7 +2,6 @@ #include -#include #include #include diff --git a/main/kernel/drivers/Bq27220Driver.hpp b/main/kernel/drivers/Bq27220Driver.hpp index c06682c5..59c5156d 100644 --- a/main/kernel/drivers/Bq27220Driver.hpp +++ b/main/kernel/drivers/Bq27220Driver.hpp @@ -3,7 +3,6 @@ #include #include -#include #include using namespace farmhub::kernel; diff --git a/main/kernel/drivers/LedDriver.hpp b/main/kernel/drivers/LedDriver.hpp index d4afedbf..2808fe6c 100644 --- a/main/kernel/drivers/LedDriver.hpp +++ b/main/kernel/drivers/LedDriver.hpp @@ -5,7 +5,6 @@ #include #include -#include #include #include diff --git a/main/kernel/drivers/MdnsDriver.hpp b/main/kernel/drivers/MdnsDriver.hpp index 5a636b86..5d563735 100644 --- a/main/kernel/drivers/MdnsDriver.hpp +++ b/main/kernel/drivers/MdnsDriver.hpp @@ -5,7 +5,6 @@ #include #include -#include #include #include #include diff --git a/main/kernel/drivers/RtcDriver.hpp b/main/kernel/drivers/RtcDriver.hpp index ba8bc258..7f46825d 100644 --- a/main/kernel/drivers/RtcDriver.hpp +++ b/main/kernel/drivers/RtcDriver.hpp @@ -7,7 +7,6 @@ #include "esp_netif_sntp.h" #include "esp_sntp.h" -#include #include #include diff --git a/main/kernel/drivers/SwitchManager.hpp b/main/kernel/drivers/SwitchManager.hpp index e1dfbb15..ada6b204 100644 --- a/main/kernel/drivers/SwitchManager.hpp +++ b/main/kernel/drivers/SwitchManager.hpp @@ -9,7 +9,6 @@ #include #include -#include #include #include diff --git a/main/kernel/drivers/WiFiDriver.hpp b/main/kernel/drivers/WiFiDriver.hpp index eb7c425c..1461fd67 100644 --- a/main/kernel/drivers/WiFiDriver.hpp +++ b/main/kernel/drivers/WiFiDriver.hpp @@ -9,7 +9,6 @@ #include #include -#include #include #include diff --git a/main/main.cpp b/main/main.cpp index a92aed8b..bf299e79 100644 --- a/main/main.cpp +++ b/main/main.cpp @@ -6,16 +6,7 @@ #include #include -#include - -#define FARMHUB_LOG(level, format, ...) \ - ESP_LOG_LEVEL_LOCAL(level, "farmhub", format, ##__VA_ARGS__) - -#define LOGE(format, ...) FARMHUB_LOG(ESP_LOG_ERROR, format, ##__VA_ARGS__) -#define LOGW(format, ...) FARMHUB_LOG(ESP_LOG_WARN, format, ##__VA_ARGS__) -#define LOGI(format, ...) FARMHUB_LOG(ESP_LOG_INFO, format, ##__VA_ARGS__) -#define LOGD(format, ...) FARMHUB_LOG(ESP_LOG_DEBUG, format, ##__VA_ARGS__) -#define LOGV(format, ...) FARMHUB_LOG(ESP_LOG_VERBOSE, format, ##__VA_ARGS__) +#include #ifdef CONFIG_HEAP_TRACING #include @@ -86,11 +77,7 @@ static void dumpPerTaskHeapInfo() { extern "C" void app_main() { initArduino(); -#ifdef FARMHUB_DEBUG - esp_log_level_set("farmhub", ESP_LOG_DEBUG); -#else - esp_log_level_set("farmhub", ESP_LOG_INFO); -#endif + initLogging(); #ifdef CONFIG_HEAP_TRACING ESP_ERROR_CHECK(heap_trace_init_standalone(trace_record, NUM_RECORDS)); diff --git a/main/peripherals/Peripheral.hpp b/main/peripherals/Peripheral.hpp index f86a6e68..3fcb57c7 100644 --- a/main/peripherals/Peripheral.hpp +++ b/main/peripherals/Peripheral.hpp @@ -5,7 +5,6 @@ #include #include -#include #include #include #include @@ -247,7 +246,7 @@ class PeripheralManager state = State::Stopped; PeripheralBase::ShutdownParameters parameters; for (auto& peripheral : peripherals) { - Log.printfToSerial("Shutting down peripheral '%s'\n", + LOGI("Shutting down peripheral '%s'", peripheral->name.c_str()); peripheral->shutdown(parameters); } diff --git a/main/peripherals/chicken_door/ChickenDoor.hpp b/main/peripherals/chicken_door/ChickenDoor.hpp index 714cc843..ce1e8823 100644 --- a/main/peripherals/chicken_door/ChickenDoor.hpp +++ b/main/peripherals/chicken_door/ChickenDoor.hpp @@ -9,7 +9,6 @@ #include #include -#include #include #include #include diff --git a/main/peripherals/environment/Environment.hpp b/main/peripherals/environment/Environment.hpp index 04c7cb6b..e3777f0e 100644 --- a/main/peripherals/environment/Environment.hpp +++ b/main/peripherals/environment/Environment.hpp @@ -4,7 +4,6 @@ #include #include -#include #include #include diff --git a/main/peripherals/environment/Sht2xComponent.hpp b/main/peripherals/environment/Sht2xComponent.hpp index 6cbdcbd0..847a3b72 100644 --- a/main/peripherals/environment/Sht2xComponent.hpp +++ b/main/peripherals/environment/Sht2xComponent.hpp @@ -6,7 +6,6 @@ #include #include -#include #include #include diff --git a/main/peripherals/environment/Sht31Component.hpp b/main/peripherals/environment/Sht31Component.hpp index 1918b2a4..6a24cd6d 100644 --- a/main/peripherals/environment/Sht31Component.hpp +++ b/main/peripherals/environment/Sht31Component.hpp @@ -6,7 +6,6 @@ #include #include -#include #include #include diff --git a/main/peripherals/environment/SoilMoistureSensor.hpp b/main/peripherals/environment/SoilMoistureSensor.hpp index 84aa288f..bd1ab284 100644 --- a/main/peripherals/environment/SoilMoistureSensor.hpp +++ b/main/peripherals/environment/SoilMoistureSensor.hpp @@ -6,7 +6,6 @@ #include #include -#include #include #include diff --git a/main/peripherals/fence/ElectricFenceMonitor.hpp b/main/peripherals/fence/ElectricFenceMonitor.hpp index a68160d7..ca0f1f4b 100644 --- a/main/peripherals/fence/ElectricFenceMonitor.hpp +++ b/main/peripherals/fence/ElectricFenceMonitor.hpp @@ -7,7 +7,6 @@ #include #include -#include #include #include diff --git a/main/peripherals/flow_meter/FlowMeterComponent.hpp b/main/peripherals/flow_meter/FlowMeterComponent.hpp index 8fc04ab9..407cff06 100644 --- a/main/peripherals/flow_meter/FlowMeterComponent.hpp +++ b/main/peripherals/flow_meter/FlowMeterComponent.hpp @@ -8,7 +8,6 @@ #include #include #include -#include #include #include #include diff --git a/main/peripherals/light_sensor/Bh1750.hpp b/main/peripherals/light_sensor/Bh1750.hpp index c9e4dc10..e50b3bc5 100644 --- a/main/peripherals/light_sensor/Bh1750.hpp +++ b/main/peripherals/light_sensor/Bh1750.hpp @@ -12,7 +12,6 @@ #include #include #include -#include #include #include diff --git a/main/peripherals/light_sensor/LightSensor.hpp b/main/peripherals/light_sensor/LightSensor.hpp index 17bbd27e..da5051d9 100644 --- a/main/peripherals/light_sensor/LightSensor.hpp +++ b/main/peripherals/light_sensor/LightSensor.hpp @@ -12,7 +12,6 @@ #include #include #include -#include #include #include diff --git a/main/peripherals/light_sensor/Tsl2591.hpp b/main/peripherals/light_sensor/Tsl2591.hpp index 00efe621..dae00d97 100644 --- a/main/peripherals/light_sensor/Tsl2591.hpp +++ b/main/peripherals/light_sensor/Tsl2591.hpp @@ -13,7 +13,6 @@ #include #include #include -#include #include #include diff --git a/main/peripherals/valve/ValveComponent.hpp b/main/peripherals/valve/ValveComponent.hpp index 8eb00991..d24e6e72 100644 --- a/main/peripherals/valve/ValveComponent.hpp +++ b/main/peripherals/valve/ValveComponent.hpp @@ -12,7 +12,6 @@ #include #include -#include #include #include #include diff --git a/main/peripherals/valve/ValveConfig.hpp b/main/peripherals/valve/ValveConfig.hpp index a64a26c7..b38a42a9 100644 --- a/main/peripherals/valve/ValveConfig.hpp +++ b/main/peripherals/valve/ValveConfig.hpp @@ -5,7 +5,6 @@ #include #include -#include #include #include diff --git a/sdkconfig.defaults b/sdkconfig.defaults index e15a61d7..babb1a17 100644 --- a/sdkconfig.defaults +++ b/sdkconfig.defaults @@ -19,6 +19,9 @@ CONFIG_BOOTLOADER_LOG_LEVEL_ERROR=y CONFIG_LOG_DEFAULT_LEVEL_WARN=y CONFIG_LOG_MAXIMUM_LEVEL_VERBOSE=y +# We do our own coloring in debug mode +CONFIG_LOG_COLORS=n + # Seems like a good idea to have some stack checks CONFIG_COMPILER_STACK_CHECK_MODE_NORM=y From c7d8025620515cbabe7a06d23ded52dd485bb3b0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 13:53:49 +0100 Subject: [PATCH 59/64] Fix typos --- main/devices/Device.hpp | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/main/devices/Device.hpp b/main/devices/Device.hpp index 34a6bf3e..30b24a59 100644 --- a/main/devices/Device.hpp +++ b/main/devices/Device.hpp @@ -391,7 +391,7 @@ class ConfiguredKernel { LOGI("Battery voltage low (%.2f V < %.2f), starting shutdown process, will go to deep sleep in %lld seconds", voltage, BATTERY_SHUTDOWN_THRESHOLD, duration_cast(LOW_BATTERY_SHUTDOWN_TIMEOUT).count()); - // TODO Publihs all MQTT messages, then shut down WiFi, and _then_ start shutting down peripherals + // TODO Publish all MQTT messages, then shut down WiFi, and _then_ start shutting down peripherals // Doing so would result in less of a power spike, which can be important if the battery is already low // Run in separate task to allocate enough stack @@ -511,19 +511,19 @@ class Device { JsonDocument peripheralsInitDoc; JsonArray peripheralsInitJson = peripheralsInitDoc.to(); - auto builtInPeripheralsCofig = deviceDefinition.getBuiltInPeripherals(); + auto builtInPeripheralsConfig = deviceDefinition.getBuiltInPeripherals(); LOGD("Loading configuration for %d built-in peripherals", - builtInPeripheralsCofig.size()); - for (auto& perpheralConfig : builtInPeripheralsCofig) { - peripheralManager.createPeripheral(perpheralConfig, peripheralsInitJson); + builtInPeripheralsConfig.size()); + for (auto& peripheralConfig : builtInPeripheralsConfig) { + peripheralManager.createPeripheral(peripheralConfig, peripheralsInitJson); } auto& peripheralsConfig = deviceConfig.peripherals.get(); LOGI("Loading configuration for %d user-configured peripherals", peripheralsConfig.size()); bool peripheralError = false; - for (auto& perpheralConfig : peripheralsConfig) { - if (!peripheralManager.createPeripheral(perpheralConfig.get(), peripheralsInitJson)) { + for (auto& peripheralConfig : peripheralsConfig) { + if (!peripheralManager.createPeripheral(peripheralConfig.get(), peripheralsInitJson)) { peripheralError = true; } } From 99cae185059f4460b84df20921d09a28c5ffd82c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 14:01:50 +0100 Subject: [PATCH 60/64] Move ConsoleProvider to its own file --- main/devices/Device.hpp | 109 +------------------------------------ main/kernel/Console.hpp | 117 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 118 insertions(+), 108 deletions(-) create mode 100644 main/kernel/Console.hpp diff --git a/main/devices/Device.hpp b/main/devices/Device.hpp index 30b24a59..693fecbe 100644 --- a/main/devices/Device.hpp +++ b/main/devices/Device.hpp @@ -14,6 +14,7 @@ #include #include +#include #include #include #include @@ -203,114 +204,6 @@ class ConsolePrinter { }; #endif -struct LogRecord { - Level level; - String message; -}; - -#define FARMHUB_LOG_COLOR_BLACK "30" -#define FARMHUB_LOG_COLOR_RED "31" -#define FARMHUB_LOG_COLOR_GREEN "32" -#define FARMHUB_LOG_COLOR_BROWN "33" -#define FARMHUB_LOG_COLOR_BLUE "34" -#define FARMHUB_LOG_COLOR_PURPLE "35" -#define FARMHUB_LOG_COLOR_CYAN "36" -#define FARMHUB_LOG_COLOR(COLOR) "\033[0;" COLOR "m" -#define FARMHUB_LOG_BOLD(COLOR) "\033[1;" COLOR "m" -#define FARMHUB_LOG_RESET_COLOR "\033[0m" - -class ConsoleProvider; - -static ConsoleProvider* consoleProvider; - -class ConsoleProvider { -public: - ConsoleProvider(Queue& logRecords, Level recordedLevel) - : logRecords(logRecords) - , recordedLevel(recordedLevel) { - consoleProvider = this; - originalVprintf = esp_log_set_vprintf(ConsoleProvider::processLogFunc); - -#ifndef WOKWI - Serial.begin(115200); - Serial1.begin(115200, SERIAL_8N1, pins::RXD0->getGpio(), pins::TXD0->getGpio()); -#if Serial != Serial0 - Serial0.begin(115200); -#endif -#endif - } - -private: - static int processLogFunc(const char* format, va_list args) { - return consoleProvider->processLog(format, args); - } - - int processLog(const char* format, va_list args) { - Level level = getLevel(format[0]); - if (level <= recordedLevel) { - std::lock_guard lock(bufferMutex); - vsnprintf(buffer, sizeof(buffer), format, args); - logRecords.offer(level, buffer); - } - -#ifdef FARMHUB_DEBUG - // Erase the current line - printf("\033[1G\033[0K"); - switch (level) { - case Level::Error: - printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_RED)); - break; - case Level::Warning: - printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_BROWN)); - break; - case Level::Info: - printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_GREEN)); - break; - default: - break; - } -#endif - - int count = originalVprintf(format, args); - -#ifdef FARMHUB_DEBUG - switch (level) { - case Level::Error: - case Level::Warning: - case Level::Info: - printf(FARMHUB_LOG_RESET_COLOR); - break; - default: - break; - } -#endif - return count; - } - - static inline Level getLevel(char c) { - switch (c) { - case 'E': - return Level::Error; - case 'W': - return Level::Warning; - case 'I': - return Level::Info; - case 'D': - return Level::Debug; - case 'V': - return Level::Verbose; - default: - return Level::Info; - } - } - - vprintf_like_t originalVprintf; - Queue& logRecords; - const Level recordedLevel; - std::mutex bufferMutex; - char buffer[128]; -}; - class MemoryTelemetryProvider : public TelemetryProvider { public: void populateTelemetry(JsonObject& json) override { diff --git a/main/kernel/Console.hpp b/main/kernel/Console.hpp new file mode 100644 index 00000000..e54de3ec --- /dev/null +++ b/main/kernel/Console.hpp @@ -0,0 +1,117 @@ +#pragma once + +#include + +#include + +namespace farmhub::kernel { + +struct LogRecord { + Level level; + String message; +}; + +#define FARMHUB_LOG_COLOR_BLACK "30" +#define FARMHUB_LOG_COLOR_RED "31" +#define FARMHUB_LOG_COLOR_GREEN "32" +#define FARMHUB_LOG_COLOR_BROWN "33" +#define FARMHUB_LOG_COLOR_BLUE "34" +#define FARMHUB_LOG_COLOR_PURPLE "35" +#define FARMHUB_LOG_COLOR_CYAN "36" +#define FARMHUB_LOG_COLOR(COLOR) "\033[0;" COLOR "m" +#define FARMHUB_LOG_BOLD(COLOR) "\033[1;" COLOR "m" +#define FARMHUB_LOG_RESET_COLOR "\033[0m" + +class ConsoleProvider; + +static ConsoleProvider* consoleProvider; + +class ConsoleProvider { +public: + ConsoleProvider(Queue& logRecords, Level recordedLevel) + : logRecords(logRecords) + , recordedLevel(recordedLevel) { + consoleProvider = this; + originalVprintf = esp_log_set_vprintf(ConsoleProvider::processLogFunc); + +#ifndef WOKWI + Serial.begin(115200); + Serial1.begin(115200, SERIAL_8N1, pins::RXD0->getGpio(), pins::TXD0->getGpio()); +#if Serial != Serial0 + Serial0.begin(115200); +#endif +#endif + } + +private: + static int processLogFunc(const char* format, va_list args) { + return consoleProvider->processLog(format, args); + } + + int processLog(const char* format, va_list args) { + Level level = getLevel(format[0]); + if (level <= recordedLevel) { + std::lock_guard lock(bufferMutex); + vsnprintf(buffer, sizeof(buffer), format, args); + logRecords.offer(level, buffer); + } + +#ifdef FARMHUB_DEBUG + // Erase the current line + printf("\033[1G\033[0K"); + switch (level) { + case Level::Error: + printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_RED)); + break; + case Level::Warning: + printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_BROWN)); + break; + case Level::Info: + printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_GREEN)); + break; + default: + break; + } +#endif + + int count = originalVprintf(format, args); + +#ifdef FARMHUB_DEBUG + switch (level) { + case Level::Error: + case Level::Warning: + case Level::Info: + printf(FARMHUB_LOG_RESET_COLOR); + break; + default: + break; + } +#endif + return count; + } + + static inline Level getLevel(char c) { + switch (c) { + case 'E': + return Level::Error; + case 'W': + return Level::Warning; + case 'I': + return Level::Info; + case 'D': + return Level::Debug; + case 'V': + return Level::Verbose; + default: + return Level::Info; + } + } + + vprintf_like_t originalVprintf; + Queue& logRecords; + const Level recordedLevel; + std::mutex bufferMutex; + char buffer[128]; +}; + +} // namespace farmhub::kernel From c8a5d9227f1584f7a1925e48ad3ab80b0002b2cc Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 14:37:38 +0100 Subject: [PATCH 61/64] Fix buffer size --- main/kernel/Console.hpp | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/main/kernel/Console.hpp b/main/kernel/Console.hpp index e54de3ec..99e13c79 100644 --- a/main/kernel/Console.hpp +++ b/main/kernel/Console.hpp @@ -52,7 +52,7 @@ class ConsoleProvider { Level level = getLevel(format[0]); if (level <= recordedLevel) { std::lock_guard lock(bufferMutex); - vsnprintf(buffer, sizeof(buffer), format, args); + vsnprintf(buffer, BUFFER_SIZE, format, args); logRecords.offer(level, buffer); } @@ -111,7 +111,8 @@ class ConsoleProvider { Queue& logRecords; const Level recordedLevel; std::mutex bufferMutex; - char buffer[128]; + static constexpr size_t BUFFER_SIZE = 128; + char buffer[BUFFER_SIZE]; }; } // namespace farmhub::kernel From fe26f6e69677e68534e9bcf055831990f18882c1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 14:38:13 +0100 Subject: [PATCH 62/64] Do not initialize Serial --- main/kernel/Console.hpp | 8 -------- 1 file changed, 8 deletions(-) diff --git a/main/kernel/Console.hpp b/main/kernel/Console.hpp index 99e13c79..bf8cf1a2 100644 --- a/main/kernel/Console.hpp +++ b/main/kernel/Console.hpp @@ -33,14 +33,6 @@ class ConsoleProvider { , recordedLevel(recordedLevel) { consoleProvider = this; originalVprintf = esp_log_set_vprintf(ConsoleProvider::processLogFunc); - -#ifndef WOKWI - Serial.begin(115200); - Serial1.begin(115200, SERIAL_8N1, pins::RXD0->getGpio(), pins::TXD0->getGpio()); -#if Serial != Serial0 - Serial0.begin(115200); -#endif -#endif } private: From d871ecf53eb48fb5fbd0a28dd55b99129981af59 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Tue, 3 Dec 2024 15:22:26 +0100 Subject: [PATCH 63/64] Allocate fewer WiFi buffers to free up some DIRAM --- sdkconfig.mk4.defaults | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/sdkconfig.mk4.defaults b/sdkconfig.mk4.defaults index df4c6ef1..1c8296b4 100644 --- a/sdkconfig.mk4.defaults +++ b/sdkconfig.mk4.defaults @@ -1 +1,8 @@ CONFIG_ESPTOOLPY_FLASHSIZE_4MB=y + +# Give us more DIRAM +ESP32_WIFI_DYNAMIC_TX_BUFFER=y +CONFIG_ESP32_WIFI_STATIC_RX_BUFFER_NUM=6 +CONFIG_ESP32_WIFI_DYNAMIC_RX_BUFFER_NUM=12 +CONFIG_ESP32_WIFI_STATIC_TX_BUFFER_NUM=6 +CONFIG_ESP32_WIFI_DYNAMIC_TX_BUFFER_NUM=12 From 238aac2dc76aa866b5172ba58be6088cc1ef4bb7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=B3r=C3=A1nt=20Pint=C3=A9r?= Date: Wed, 4 Dec 2024 00:59:52 +0100 Subject: [PATCH 64/64] Implement vprintf() contract properly --- main/kernel/Console.hpp | 17 +++++++++++------ 1 file changed, 11 insertions(+), 6 deletions(-) diff --git a/main/kernel/Console.hpp b/main/kernel/Console.hpp index bf8cf1a2..a3bda882 100644 --- a/main/kernel/Console.hpp +++ b/main/kernel/Console.hpp @@ -48,32 +48,37 @@ class ConsoleProvider { logRecords.offer(level, buffer); } + int count = 0; #ifdef FARMHUB_DEBUG // Erase the current line - printf("\033[1G\033[0K"); + count += printf("\033[1G\033[0K"); switch (level) { case Level::Error: - printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_RED)); + count += printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_RED)); break; case Level::Warning: - printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_BROWN)); + count += printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_BROWN)); break; case Level::Info: - printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_GREEN)); + count += printf(FARMHUB_LOG_COLOR(FARMHUB_LOG_COLOR_GREEN)); break; default: break; } #endif - int count = originalVprintf(format, args); + int originalCount = originalVprintf(format, args); + if (originalCount < 0) { + return originalCount; + } + count += originalCount; #ifdef FARMHUB_DEBUG switch (level) { case Level::Error: case Level::Warning: case Level::Info: - printf(FARMHUB_LOG_RESET_COLOR); + count += printf(FARMHUB_LOG_RESET_COLOR); break; default: break;