From f98c0c6ff25be865ab14fc9f36c5cbbdab110ad5 Mon Sep 17 00:00:00 2001 From: Maurizio Branca Date: Mon, 25 Oct 2021 11:02:38 +0200 Subject: [PATCH 1/4] Add logs on OTA process steps These additional log statements highlight each step in the Over-the-Air (OTA) update process. --- src/AIoTC_Config.h | 2 +- src/ArduinoIoTCloudTCP.cpp | 10 ++++++++-- src/utility/ota/OTA-samd.cpp | 4 ++++ 3 files changed, 13 insertions(+), 3 deletions(-) diff --git a/src/AIoTC_Config.h b/src/AIoTC_Config.h index 9ceb2ac62..6df348af8 100644 --- a/src/AIoTC_Config.h +++ b/src/AIoTC_Config.h @@ -62,7 +62,7 @@ # if defined(ARDUINO_AVR_UNO_WIFI_REV2) # define DEBUG_VERBOSE(fmt, ...) # else -# define DEBUG_VERBOSE(fmt, ...) //Debug.print(DBG_VERBOSE, fmt, ## __VA_ARGS__) +# define DEBUG_VERBOSE(fmt, ...) Debug.print(DBG_VERBOSE, fmt, ## __VA_ARGS__) # endif #endif diff --git a/src/ArduinoIoTCloudTCP.cpp b/src/ArduinoIoTCloudTCP.cpp index 4cac10c6d..d6fbf1189 100644 --- a/src/ArduinoIoTCloudTCP.cpp +++ b/src/ArduinoIoTCloudTCP.cpp @@ -369,8 +369,10 @@ ArduinoIoTCloudTCP::State ArduinoIoTCloudTCP::handle_SyncTime() ArduinoIoTCloudTCP::State ArduinoIoTCloudTCP::handle_ConnectMqttBroker() { + DEBUG_VERBOSE("ArduinoIoTCloudTCP::%s connecting to %s:%d (attempt %d)", __FUNCTION__, _brokerAddress.c_str(), _brokerPort, _last_connection_attempt_cnt); if (_mqttClient.connect(_brokerAddress.c_str(), _brokerPort)) { + DEBUG_VERBOSE("ArduinoIoTCloudTCP::%s connected to %s:%d", __FUNCTION__, _brokerAddress.c_str(), _brokerPort); _last_connection_attempt_cnt = 0; return State::SubscribeMqttTopics; } @@ -395,7 +397,8 @@ ArduinoIoTCloudTCP::State ArduinoIoTCloudTCP::handle_SubscribeMqttTopics() return State::ConnectPhy; } - if (!_mqttClient.subscribe(_dataTopicIn)) + DEBUG_VERBOSE("ArduinoIoTCloudTCP::%s subscribing to %s ...", __FUNCTION__, _dataTopicIn.c_str()); + if (!_mqttClient.subscribe(_dataTopicIn, 0)) { DEBUG_ERROR("ArduinoIoTCloudTCP::%s could not subscribe to %s", __FUNCTION__, _dataTopicIn.c_str()); #if !defined(__AVR__) @@ -403,10 +406,12 @@ ArduinoIoTCloudTCP::State ArduinoIoTCloudTCP::handle_SubscribeMqttTopics() #endif return State::SubscribeMqttTopics; } + DEBUG_VERBOSE("ArduinoIoTCloudTCP::%s subscribed to %s", __FUNCTION__, _dataTopicIn.c_str()); if (_shadowTopicIn != "") { - if (!_mqttClient.subscribe(_shadowTopicIn)) + DEBUG_VERBOSE("ArduinoIoTCloudTCP::%s subscribing to %s ...", __FUNCTION__, _shadowTopicIn.c_str()); + if (!_mqttClient.subscribe(_shadowTopicIn, 0)) { DEBUG_ERROR("ArduinoIoTCloudTCP::%s could not subscribe to %s", __FUNCTION__, _shadowTopicIn.c_str()); #if !defined(__AVR__) @@ -415,6 +420,7 @@ ArduinoIoTCloudTCP::State ArduinoIoTCloudTCP::handle_SubscribeMqttTopics() return State::SubscribeMqttTopics; } } + DEBUG_VERBOSE("ArduinoIoTCloudTCP::%s subscribed to %s", __FUNCTION__, _shadowTopicIn.c_str()); DEBUG_INFO("Connected to Arduino IoT Cloud"); execCloudEventCallback(ArduinoIoTCloudEvent::CONNECT); diff --git a/src/utility/ota/OTA-samd.cpp b/src/utility/ota/OTA-samd.cpp index f555415b8..dbce80dfc 100644 --- a/src/utility/ota/OTA-samd.cpp +++ b/src/utility/ota/OTA-samd.cpp @@ -47,6 +47,7 @@ int samd_onOTARequest(char const * ota_url) watchdog_reset(); + DEBUG_VERBOSE("ArduinoIoTCloudTCP::%s downloading to nina: %s", __FUNCTION__, ota_url); /* Trigger direct download to nina module. */ uint8_t nina_ota_err_code = 0; if (!WiFiStorage.downloadOTA(ota_url, &nina_ota_err_code)) @@ -55,6 +56,9 @@ int samd_onOTARequest(char const * ota_url) return static_cast(OTAError::DownloadFailed); } + DEBUG_VERBOSE("ArduinoIoTCloudTCP::%s download successful", __FUNCTION__); + DEBUG_VERBOSE("ArduinoIoTCloudTCP::%s performing reset to reboot", __FUNCTION__); + /* Perform the reset to reboot to SxU. */ NVIC_SystemReset(); #endif /* OTA_STORAGE_SNU */ From 6044ad956d18eeba7087b8a494c2c66902fcea89 Mon Sep 17 00:00:00 2001 From: Maurizio Branca Date: Wed, 27 Oct 2021 15:45:21 +0200 Subject: [PATCH 2/4] Add verbose logs for portenta h7 --- src/utility/ota/OTA-portenta-h7.cpp | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/utility/ota/OTA-portenta-h7.cpp b/src/utility/ota/OTA-portenta-h7.cpp index 52faf73f8..1caffb8ee 100644 --- a/src/utility/ota/OTA-portenta-h7.cpp +++ b/src/utility/ota/OTA-portenta-h7.cpp @@ -61,6 +61,7 @@ int portenta_h7_onOTARequest(char const * ota_url) watchdog_reset(); /* Download the OTA file from the web storage location. */ + DEBUG_VERBOSE("Arduino_Portenta_OTA_QSPI::download(%s) started", ota_url); int const ota_portenta_qspi_download_ret_code = ota_portenta_qspi.download(ota_url, true /* is_https */); DEBUG_VERBOSE("Arduino_Portenta_OTA_QSPI::download(%s) returns %d", ota_url, ota_portenta_qspi_download_ret_code); @@ -83,6 +84,8 @@ int portenta_h7_onOTARequest(char const * ota_url) return static_cast(ota_portenta_err); } + DEBUG_VERBOSE("Arduino_Portenta_OTA_QSPI::reboot() performing reset to reboot"); + /* Perform the reset to reboot - then the bootloader performs the actual application update. */ NVIC_SystemReset(); } From 441f6b82b3dc4bfd44aa91e45ad9a13b3a70fe30 Mon Sep 17 00:00:00 2001 From: Maurizio Branca Date: Wed, 27 Oct 2021 15:57:16 +0200 Subject: [PATCH 3/4] Add verbose logs for rp2040 --- src/utility/ota/OTA-nano-rp2040.cpp | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/src/utility/ota/OTA-nano-rp2040.cpp b/src/utility/ota/OTA-nano-rp2040.cpp index 48071be7c..bf29babfb 100644 --- a/src/utility/ota/OTA-nano-rp2040.cpp +++ b/src/utility/ota/OTA-nano-rp2040.cpp @@ -119,6 +119,8 @@ int rp2040_connect_onOTARequest(char const * ota_url) watchdog_reset(); + DEBUG_VERBOSE("%s downloading: %s", __FUNCTION__, ota_url); + URI url(ota_url); Client * client = nullptr; int port = 0; @@ -233,6 +235,7 @@ int rp2040_connect_onOTARequest(char const * ota_url) DEBUG_INFO("%s: %d bytes received", __FUNCTION__, ftell(file)); fclose(file); + DEBUG_VERBOSE("%s download successful", __FUNCTION__); /* Unmount the filesystem. */ if ((err = fs.unmount()) != 0) @@ -241,6 +244,8 @@ int rp2040_connect_onOTARequest(char const * ota_url) return static_cast(OTAError::RP2040_ErrorUnmount); } + DEBUG_VERBOSE("%s performing reset to reboot", __FUNCTION__); + /* Perform the reset to reboot to SFU. */ mbed_watchdog_trigger_reset(); /* If watchdog is enabled we should not reach this point */ From 614ebe66bcb91586bb224b0aed30d3772e075f07 Mon Sep 17 00:00:00 2001 From: Maurizio Branca Date: Wed, 27 Oct 2021 16:15:18 +0200 Subject: [PATCH 4/4] Drop explicit QoS in subscribes This was intended as as just test, back the the default value. --- src/ArduinoIoTCloudTCP.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/ArduinoIoTCloudTCP.cpp b/src/ArduinoIoTCloudTCP.cpp index d6fbf1189..2f5269a81 100644 --- a/src/ArduinoIoTCloudTCP.cpp +++ b/src/ArduinoIoTCloudTCP.cpp @@ -398,7 +398,7 @@ ArduinoIoTCloudTCP::State ArduinoIoTCloudTCP::handle_SubscribeMqttTopics() } DEBUG_VERBOSE("ArduinoIoTCloudTCP::%s subscribing to %s ...", __FUNCTION__, _dataTopicIn.c_str()); - if (!_mqttClient.subscribe(_dataTopicIn, 0)) + if (!_mqttClient.subscribe(_dataTopicIn)) { DEBUG_ERROR("ArduinoIoTCloudTCP::%s could not subscribe to %s", __FUNCTION__, _dataTopicIn.c_str()); #if !defined(__AVR__) @@ -411,7 +411,7 @@ ArduinoIoTCloudTCP::State ArduinoIoTCloudTCP::handle_SubscribeMqttTopics() if (_shadowTopicIn != "") { DEBUG_VERBOSE("ArduinoIoTCloudTCP::%s subscribing to %s ...", __FUNCTION__, _shadowTopicIn.c_str()); - if (!_mqttClient.subscribe(_shadowTopicIn, 0)) + if (!_mqttClient.subscribe(_shadowTopicIn)) { DEBUG_ERROR("ArduinoIoTCloudTCP::%s could not subscribe to %s", __FUNCTION__, _shadowTopicIn.c_str()); #if !defined(__AVR__)