Merge branch 'slave_ota' into 'feature/esp_as_mcu_host'

fix(ota): Fixed slave OTA through SDIO transport

See merge request app-frameworks/esp_hosted!454

CMakeLists.txt

@@ -52,7 +52,7 @@ else()
 endif()
 
 idf_component_register(SRCS ${COMPONENT_SRCS}
-	REQUIRES soc esp_event esp_netif esp_timer driver esp_wifi sdmmc bt
+	REQUIRES soc esp_event esp_netif esp_timer driver esp_wifi sdmmc bt esp_http_client
 	EXCLUDE_SRCS ${EXCLUDE_COMPONENT_SRCS}
 	INCLUDE_DIRS ${COMPONENT_ADD_INCLUDEDIRS})
 

Kconfig

@@ -570,11 +570,6 @@ ESP32P4_SDIO_CLK_FREQ_KHZ_RANGE_MAX := 80000
 			Note: the slave will only process one RPC request (sync and async) at a time
 
 	menu "Debug Settings"
-		config ESP_HOSTED_ENABLE_HEXDUMP
-			bool "Hexdump logs enable"
-			default n
-				help
-					Enable Hex logs to print msg content
 
 		config ESP_RAW_THROUGHPUT_TRANSPORT
 			bool "RawTP: Transport level throughput debug test"

common/include/esp_hosted_log.h

@@ -18,31 +18,17 @@
 #define __ESP_HOSTED_LOG_H
 #include "esp_log.h"
 
-
-#if CONFIG_ESP_HOSTED_ENABLE_HEXDUMP
-
-  #define ESP_PRIV_HEXDUMP(tag1, tag2, buff, len, curr_level)                   \
-    if ( LOG_LOCAL_LEVEL >= curr_level) {                                       \
-      ESP_LOGD(tag1, tag2 " len:%d", (int)len);                                                     \
-      ESP_LOG_BUFFER_HEXDUMP(tag2, buff, len, curr_level);                           \
-    }
-
-  #define ESP_HEXLOGE(tag2, buff, len) ESP_PRIV_HEXDUMP(TAG, tag2, buff, len, ESP_LOG_ERROR)
-  #define ESP_HEXLOGW(tag2, buff, len) ESP_PRIV_HEXDUMP(TAG, tag2, buff, len, ESP_LOG_WARN)
-  #define ESP_HEXLOGI(tag2, buff, len) ESP_PRIV_HEXDUMP(TAG, tag2, buff, len, ESP_LOG_INFO)
-  #define ESP_HEXLOGD(tag2, buff, len) ESP_PRIV_HEXDUMP(TAG, tag2, buff, len, ESP_LOG_DEBUG)
-  #define ESP_HEXLOGV(tag2, buff, len) ESP_PRIV_HEXDUMP(TAG, tag2, buff, len, ESP_LOG_VERBOSE)
-
-#else
-
-#define ESP_HEXLOGE(tag2, buff, len)
-#define ESP_HEXLOGW(tag2, buff, len)
-#define ESP_HEXLOGI(tag2, buff, len)
-#define ESP_HEXLOGD(tag2, buff, len)
-#define ESP_HEXLOGV(tag2, buff, len)
-
-#endif
-
+#define ESP_PRIV_HEXDUMP(tag1, tag2, buff, len, curr_level)                   \
+  if ( LOG_LOCAL_LEVEL >= curr_level) {                                       \
+    ESP_LOG_LEVEL_LOCAL(curr_level, tag1, "%s: len[%d]", tag2, (int)len);     \
+    ESP_LOG_BUFFER_HEXDUMP(tag2, buff, len, curr_level);                      \
+  }
+
+#define ESP_HEXLOGE(tag2, buff, len) ESP_PRIV_HEXDUMP(TAG, tag2, buff, len, ESP_LOG_ERROR)
+#define ESP_HEXLOGW(tag2, buff, len) ESP_PRIV_HEXDUMP(TAG, tag2, buff, len, ESP_LOG_WARN)
+#define ESP_HEXLOGI(tag2, buff, len) ESP_PRIV_HEXDUMP(TAG, tag2, buff, len, ESP_LOG_INFO)
+#define ESP_HEXLOGD(tag2, buff, len) ESP_PRIV_HEXDUMP(TAG, tag2, buff, len, ESP_LOG_DEBUG)
+#define ESP_HEXLOGV(tag2, buff, len) ESP_PRIV_HEXDUMP(TAG, tag2, buff, len, ESP_LOG_VERBOSE)
 
 #endif
 

host/api/esp_hosted_api.c

@@ -95,8 +95,16 @@ static esp_err_t add_esp_wifi_remote_channels(void)
 	return ESP_OK;
 }
 
+static void set_host_modules_log_level(void)
+{
+	esp_log_level_set("rpc_core", ESP_LOG_WARN);
+	esp_log_level_set("rpc_rsp", ESP_LOG_WARN);
+	esp_log_level_set("rpc_evt", ESP_LOG_WARN);
+}
 esp_err_t esp_hosted_init(void(*esp_hosted_up_cb)(void))
 {
+	set_host_modules_log_level();
+
 	//create_esp_hosted_transport_up_sem();
 	ESP_LOGI(TAG, "ESP-Hosted starting. Hosted_Tasks: prio:%u, stack: %u RPC_task_stack: %u",
 			DFLT_TASK_PRIO, DFLT_TASK_STACK_SIZE, RPC_TASK_STACK_SIZE);
@@ -366,6 +374,12 @@ esp_err_t esp_wifi_remote_get_max_tx_power(int8_t *power)
 	return rpc_wifi_get_max_tx_power(power);
 }
 
+esp_err_t esp_hosted_ota(const char* image_url)
+{
+	return rpc_ota(image_url);
+}
+
+
 //esp_err_t esp_wifi_remote_scan_get_ap_record(wifi_ap_record_t *ap_record)
 //esp_err_t esp_wifi_remote_set_csi(_Bool en)
 //esp_err_t esp_wifi_remote_set_csi_rx_cb(wifi_csi_cb_t cb, void *ctx)

host/api/esp_hosted_api.h

@@ -93,6 +93,7 @@ esp_err_t esp_wifi_remote_set_protocol(wifi_interface_t ifx, uint8_t protocol_bi
 esp_err_t esp_wifi_remote_get_protocol(wifi_interface_t ifx, uint8_t *protocol_bitmap);
 esp_err_t esp_wifi_remote_set_max_tx_power(int8_t power);
 esp_err_t esp_wifi_remote_get_max_tx_power(int8_t *power);
+esp_err_t esp_hosted_ota(const char* image_url);
 
 #ifdef __cplusplus
 }

host/drivers/rpc/core/rpc_core.c

@@ -590,7 +590,7 @@ static ctrl_cmd_t * get_response(int *read_len, ctrl_cmd_t *app_req)
 		if (errno == ETIMEDOUT)
 			ESP_LOGW(TAG, "Resp timedout for req[0x%x]\n", app_req->msg_id);
 		else
-			ESP_LOGE(TAG, "ERR [%u] ret[%u] for Req[0x%x]\n", errno, ret, app_req->msg_id);
+			ESP_LOGE(TAG, "ERR [%u] ret[%d] for Req[0x%x]\n", errno, ret, app_req->msg_id);
 		return NULL;
 	}
 

host/drivers/rpc/core/rpc_evt.c

@@ -37,7 +37,7 @@ int rpc_parse_evt(Rpc *rpc_msg, ctrl_cmd_t *app_ntfy)
 	switch (rpc_msg->msg_id) {
 
 	case RPC_ID__Event_ESPInit: {
-		ESP_LOGD(TAG, "EVENT: ESP INIT\n");
+		ESP_LOGI(TAG, "EVENT: ESP INIT\n");
 		break;
 	} case RPC_ID__Event_Heartbeat: {
 		ESP_LOGD(TAG, "EVENT: Heartbeat\n");

host/drivers/rpc/wrap/rpc_wrap.c

@@ -29,17 +29,22 @@
 #include "rpc_wrap.h"
 #include "rpc_common.h"
 #include "esp_log.h"
+#include "esp_http_client.h"
 
 DEFINE_LOG_TAG(rpc_wrap);
+static char* OTA_TAG = "h_ota";
 
+uint8_t restart_after_slave_ota = 0;
 
 #define WIFI_VENDOR_IE_ELEMENT_ID                         0xDD
 #define OFFSET                                            4
 #define VENDOR_OUI_0                                      1
 #define VENDOR_OUI_1                                      2
 #define VENDOR_OUI_2                                      3
 #define VENDOR_OUI_TYPE                                   22
-#define CHUNK_SIZE                                        4000
+#define CHUNK_SIZE                                        1400
+#define OTA_BEGIN_RSP_TIMEOUT_SEC                         15
+#define OTA_FROM_WEB_URL                                  1
 
 
 #define RPC_DEFAULT_REQ() {                              \
@@ -794,6 +799,9 @@ int rpc_ota_begin(void)
 	ctrl_cmd_t req = RPC_DEFAULT_REQ();
 	ctrl_cmd_t *resp = NULL;
 
+	/* OTA begin takes some time to clear the partition */
+	req.rsp_timeout_sec = OTA_BEGIN_RSP_TIMEOUT_SEC;
+
 	resp = ota_begin(req);
 
 	return rpc_rsp_callback(resp);
@@ -824,6 +832,8 @@ int rpc_ota_end(void)
 	return rpc_rsp_callback(resp);
 }
 
+#if !OTA_FROM_WEB_URL
+/* This assumes full slave binary is present locally */
 int rpc_ota(char* image_path)
 {
 	FILE* f = NULL;
@@ -832,16 +842,16 @@ int rpc_ota(char* image_path)
 	if (ret == SUCCESS) {
 		f = fopen(image_path,"rb");
 		if (f == NULL) {
-			ESP_LOGE(TAG, "Failed to open file %s", image_path);
+			ESP_LOGE(OTA_TAG, "Failed to open file %s", image_path);
 			return FAILURE;
 		} else {
-			ESP_LOGV(TAG, "Success in opening %s file", image_path);
+			ESP_LOGV(OTA_TAG, "Success in opening %s file", image_path);
 		}
 		while (!feof(f)) {
 			fread(&ota_chunk, CHUNK_SIZE, 1, f);
 			ret = rpc_ota_write((uint8_t* )&ota_chunk, CHUNK_SIZE);
 			if (ret) {
-				ESP_LOGE(TAG, "OTA procedure failed!!");
+				ESP_LOGE(OTA_TAG, "OTA procedure failed!!");
 				/* TODO: Do we need to do OTA end irrespective of success/failure? */
 				rpc_ota_end();
 				return FAILURE;
@@ -854,11 +864,182 @@ int rpc_ota(char* image_path)
 	} else {
 		return FAILURE;
 	}
-	ESP_LOGE(TAG, "ESP32 will restart after 5 sec");
+	ESP_LOGE(OTA_TAG, "ESP32 will restart after 5 sec");
 	return SUCCESS;
-	ESP_LOGE(TAG, "For OTA, user need to integrate HTTP client lib and then invoke OTA");
+	ESP_LOGE(OTA_TAG, "For OTA, user need to integrate HTTP client lib and then invoke OTA");
 	return FAILURE;
 }
+#else
+uint8_t http_err = 0;
+static esp_err_t http_client_event_handler(esp_http_client_event_t *evt)
+{
+	switch(evt->event_id) {
+
+	case HTTP_EVENT_ERROR:
+		ESP_LOGI(OTA_TAG, "HTTP_EVENT_ERROR");
+		http_err = 1;
+		break;
+	case HTTP_EVENT_ON_CONNECTED:
+		ESP_LOGI(OTA_TAG, "HTTP_EVENT_ON_CONNECTED");
+		break;
+	case HTTP_EVENT_HEADER_SENT:
+		ESP_LOGI(OTA_TAG, "HTTP_EVENT_HEADER_SENT");
+		break;
+	case HTTP_EVENT_ON_HEADER:
+		ESP_LOGI(OTA_TAG, "HTTP_EVENT_ON_HEADER, key=%s, value=%s", evt->header_key, evt->header_value);
+		break;
+	case HTTP_EVENT_ON_DATA:
+		/* Nothing to handle here */
+		break;
+	case HTTP_EVENT_ON_FINISH:
+		ESP_LOGI(OTA_TAG, "HTTP_EVENT_ON_FINISH");
+		break;
+	case HTTP_EVENT_DISCONNECTED:
+		ESP_LOGI(OTA_TAG, "HTTP_EVENT_DISCONNECTED");
+		break;
+	case HTTP_EVENT_REDIRECT:
+		ESP_LOGW(TAG, "HTTP_EVENT_REDIRECT");
+		break;
+	}
+
+	return ESP_OK;
+}
+
+static esp_err_t _rpc_ota(const char* image_url)
+{
+	uint8_t *ota_chunk = NULL;
+	esp_err_t err = 0;
+	int data_read = 0;
+	int ota_failed = 0;
+
+	if (image_url == NULL) {
+		ESP_LOGE(TAG, "Invalid image URL");
+		return FAILURE;
+	}
+
+	/* Initialize HTTP client configuration */
+	esp_http_client_config_t config = {
+		.url = image_url,
+		.timeout_ms = 5000,
+		.event_handler = http_client_event_handler,
+	};
+
+	esp_http_client_handle_t client = esp_http_client_init(&config);
+
+	ESP_LOGI(OTA_TAG, "http_open");
+	if ((err = esp_http_client_open(client, 0)) != ESP_OK) {
+		ESP_LOGE(OTA_TAG, "Failed to open HTTP connection: %s", esp_err_to_name(err));
+		ESP_LOGE(OTA_TAG, "Check if URL is correct and connectable: %s", image_url);
+		esp_http_client_cleanup(client);
+		return FAILURE;
+	}
+
+	if (http_err) {
+		ESP_LOGE(TAG, "Exiting OTA, due to http failure");
+		esp_http_client_close(client);
+		esp_http_client_cleanup(client);
+		http_err = 0;
+		return FAILURE;
+	}
+
+	ESP_LOGI(OTA_TAG, "http_fetch_headers");
+	int64_t content_length = esp_http_client_fetch_headers(client);
+	if (content_length <= 0) {
+		ESP_LOGE(OTA_TAG, "HTTP client fetch headers failed");
+		ESP_LOGI(TAG, "HTTP GET Status = %d, content_length = %"PRId64,
+				esp_http_client_get_status_code(client),
+				esp_http_client_get_content_length(client));
+		esp_http_client_close(client);
+		esp_http_client_cleanup(client);
+		return FAILURE;
+	}
+
+	ESP_LOGI(TAG, "HTTP GET Status = %d, content_length = %"PRId64,
+			esp_http_client_get_status_code(client),
+			esp_http_client_get_content_length(client));
+
+	ESP_LOGW(OTA_TAG, "********* Started Slave OTA *******************");
+	ESP_LOGI(TAG, "*** Please wait for 5 mins to let slave OTA complete ***");
+
+	ESP_LOGI(OTA_TAG, "Preparing OTA");
+	if ((err = rpc_ota_begin())) {
+		ESP_LOGW(OTA_TAG, "********* Slave OTA Begin Failed *******************");
+		ESP_LOGI(OTA_TAG, "esp_ota_begin failed, error=%s", esp_err_to_name(err));
+		esp_http_client_close(client);
+		esp_http_client_cleanup(client);
+		return FAILURE;
+	}
+
+	ota_chunk = (uint8_t*)g_h.funcs->_h_calloc(1, CHUNK_SIZE);
+	if (!ota_chunk) {
+		ESP_LOGE(OTA_TAG, "Failed to allocate otachunk mem\n");
+		err = -ENOMEM;
+	}
+
+	ESP_LOGI(OTA_TAG, "Starting OTA");
+
+	if (!err) {
+		while ((data_read = esp_http_client_read(client, (char*)ota_chunk, CHUNK_SIZE)) > 0) {
+
+			ESP_LOGV(OTA_TAG, "Read image length %d", data_read);
+			if ((err = rpc_ota_write(ota_chunk, data_read))) {
+				ESP_LOGI(OTA_TAG, "rpc_ota_write failed");
+				ota_failed = err;
+				break;
+			}
+		}
+	}
+
+	g_h.funcs->_h_free(ota_chunk);
+	if (err) {
+		ESP_LOGW(OTA_TAG, "********* Slave OTA Failed *******************");
+		ESP_LOGI(OTA_TAG, "esp_ota_write failed, error=%s", esp_err_to_name(err));
+		ota_failed = -1;
+	}
+
+	if (data_read < 0) {
+		ESP_LOGE(OTA_TAG, "Error: SSL data read error");
+		ota_failed = -2;
+	}
+
+	if ((err = rpc_ota_end())) {
+		ESP_LOGW(OTA_TAG, "********* Slave OTA Failed *******************");
+		ESP_LOGI(OTA_TAG, "esp_ota_end failed, error=%s", esp_err_to_name(err));
+		esp_http_client_close(client);
+		esp_http_client_cleanup(client);
+		ota_failed = err;
+		return FAILURE;
+	}
+
+	esp_http_client_cleanup(client);
+	if (!ota_failed) {
+		ESP_LOGW(OTA_TAG, "********* Slave OTA Complete *******************");
+		ESP_LOGI(OTA_TAG, "OTA Successful, Slave will restart in while");
+		ESP_LOGE(TAG, "Need to restart host after slave OTA is complete, to avoid sync issues");
+		sleep(5);
+		ESP_LOGE(OTA_TAG, "********* Restarting Host **********************");
+		restart_after_slave_ota = 1;
+		esp_restart();
+	}
+	return ota_failed;
+}
+
+esp_err_t rpc_ota(const char* image_url)
+{
+	uint8_t ota_retry = 2;
+	int ret = 0;
+
+	do {
+		ret = _rpc_ota(image_url);
+
+		ota_retry--;
+		if (ota_retry && ret)
+			ESP_LOGI(OTA_TAG, "OTA retry left: %u\n", ota_retry);
+	} while (ota_retry && ret);
+
+	return ret;
+}
+#endif
 
 int rpc_wifi_set_max_tx_power(int8_t in_power)
 {
@@ -966,6 +1147,9 @@ int rpc_wifi_start(void)
 
 int rpc_wifi_stop(void)
 {
+	if (restart_after_slave_ota)
+		return 0;
+
 	/* implemented synchronous */
 	ctrl_cmd_t req = RPC_DEFAULT_REQ();
 	ctrl_cmd_t *resp = NULL;

host/drivers/rpc/wrap/rpc_wrap.h

@@ -75,6 +75,7 @@ esp_err_t rpc_wifi_set_protocol(wifi_interface_t ifx, uint8_t protocol_bitmap);
 esp_err_t rpc_wifi_get_protocol(wifi_interface_t ifx, uint8_t *protocol_bitmap);
 esp_err_t rpc_wifi_set_max_tx_power(int8_t power);
 esp_err_t rpc_wifi_get_max_tx_power(int8_t *power);
+esp_err_t rpc_ota(const char* image_url);
 
 #ifdef __cplusplus
 }