Closed DemTerritory closed 1 year ago
DemTerritory
commented
1 year ago Disabling SPI before sending data does not re-enable TLS (:
spi_bus_remove_device(dac_dev); spi_bus_free(DAC_HOST); ret_bytes = esp_tls_conn_write(tls, header.c_str(), header.length()); // Does not work
ginkgm
commented
1 year ago Hi @DemTerritory
Could you provide a minimal code to reproduce the issue? This will help us to locate the issue faster, thanks!
DemTerritory
commented
1 year ago I made a short demo of the error based on the "Wi-Fi Station Example". The result of his work: "Task watchdog got triggered". If you comment out "Initialize the SPI bus" then everything is ok.
DemTerritory
commented
1 year ago void app_main(void) { //Initialize NVS esp_err_t ret = nvs_flash_init(); if (ret == ESP_ERR_NVS_NO_FREE_PAGES || ret == ESP_ERR_NVS_NEW_VERSION_FOUND) { ESP_ERROR_CHECK(nvs_flash_erase()); ret = nvs_flash_init(); } ESP_ERROR_CHECK(ret);
ESP_LOGI(TAG, "ESP_WIFI_MODE_STA");
wifi_init_sta();
// SPI config
#define DAC_HOST SPI3_HOST
#define PIN_DAC_CLK GPIO_NUM_35
#define PIN_DAC_MOSI GPIO_NUM_18
#define PIN_DAC_CS GPIO_NUM_16
spi_device_handle_t dac_dev;
esp_err_t err;
spi_bus_config_t dac_bus_cfg = {
.mosi_io_num = PIN_DAC_MOSI,
.miso_io_num = -1,
.sclk_io_num = PIN_DAC_CLK,
.flags = SPICOMMON_BUSFLAG_MASTER | SPICOMMON_BUSFLAG_GPIO_PINS | SPICOMMON_BUSFLAG_MOSI | SPICOMMON_BUSFLAG_SCLK,
};
spi_device_interface_config_t dac_dev_cfg = {
.command_bits = 0,
.address_bits = 8,
.mode = 1, //SPI mode 1: (CPOL, CPHA)
.clock_speed_hz = SPI_MASTER_FREQ_20M,
.spics_io_num = PIN_DAC_CS, //CS pin
.flags = SPI_DEVICE_3WIRE | SPI_DEVICE_NO_DUMMY,
.queue_size = 1,
};
//Initialize the SPI bus
err = spi_bus_initialize(DAC_HOST, &dac_bus_cfg, SPI_DMA_DISABLED);
ESP_ERROR_CHECK(err);
ESP_LOGI(TAG, "SPI bus init");
err = spi_bus_add_device(DAC_HOST, &dac_dev_cfg, &dac_dev);
ESP_ERROR_CHECK(err);
ESP_LOGI(TAG, "SPI device init");
// TLS
tls_keep_alive_cfg_t keep_alive_cfg = {
.keep_alive_enable = true,
.keep_alive_idle = 1200,
.keep_alive_interval = 300,
};
esp_tls_cfg_t tls_cfg = {
.timeout_ms = INT32_MAX,
.keep_alive_cfg = &keep_alive_cfg,
.crt_bundle_attach = esp_crt_bundle_attach
};
esp_tls_t *tls = esp_tls_init();
if (tls)
ESP_LOGI(TAG, "TSL init ok");
else
ESP_LOGE(TAG, "Failed TLS init!");
string part_url = "https://google.com";
const char *url = part_url.c_str();
ret = esp_tls_conn_http_new_sync(url, &tls_cfg, tls);
ESP_LOGI(TAG, "TLS/SSL connection open = %d", ret);
char *tls_response = (char *) heap_caps_calloc(200, 1, MALLOC_CAP_8BIT);
assert(tls_response);
uint32_t return_bytes;
string test_header;
test_header = "POST / HTTP/1.1\r\n"
"Host: google.com\r\n"
"Content-Type: application/json\r\n"
"Connection: keep-alive\r\n"
"Content-Length: 6\r\n\r\n"
"\"test\"";
return_bytes = esp_tls_conn_write(tls, test_header.c_str(), test_header.length());
ESP_LOGI(TAG, "post_data ret = %lu", return_bytes);
ESP_LOGI(TAG, "Data transfered");
return_bytes = esp_tls_conn_read(tls, tls_response, 200);
ESP_LOGI(TAG, "response read = %lu", return_bytes);}
DemTerritory
commented
1 year ago I (1608) wifi station: connected to ap SSID:Misty password:qwerty I (1618) wifi station: SPI bus init I (1618) wifi station: SPI device init I (1618) wifi station: TSL init ok I (1938) esp-x509-crt-bundle: Certificate validated I (2488) wifi station: TLS/SSL connection open = 1 E (7488) task_wdt: Task watchdog got triggered. The following tasks/users did not reset the watchdog in time: E (7488) task_wdt: - IDLE (CPU 0) E (7488) task_wdt: Tasks currently running: E (7488) task_wdt: CPU 0: main E (7488) task_wdt: CPU 1: IDLE E (7488) task_wdt: Print CPU 0 (current core) backtrace
Backtrace: 0x4200C03A:0x3FC98850 0x40377259:0x3FC98880 0x42077ACD:0x3FCA27C0 0x420220D9:0x3FCA27E0 0x42022502:0x3FCA2820 0x4202390A:0x3FCA2850 0x42023A08:0x3FCA28B0 0x42023A4F:0x3FCA28E0 0x4201A357:0x3FCA2920 0x42013E01:0x3FCA2960 0x42014433:0x3FCA2A10 0x42014A6E:0x3FCA2A50 0x420133C4:0x3FCA2A70 0x420766DA:0x3FCA2AA0 0x4200828D:0x3FCA2AC0 0x4207C7A3:0x3FCA2BE0 0x4200c03a: task_wdt_timeout_handling at C:/Users/Alex/.espressif/esp-idf/components/esp_system/task_wdt/task_wdt.c:461 (inlined by) task_wdt_isr at C:/Users/Alex/.espressif/esp-idf/components/esp_system/task_wdt/task_wdt.c:585
0x40377259: _xt_lowint1 at C:/Users/Alex/.espressif/esp-idf/components/xtensa/xtensa_vectors.S:1236
0x42077acd: esp_aes_dma_done at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/port/aes/dma/esp_aes_gdma_impl.c:18
0x420220d9: esp_aes_wait_dma_done at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/port/aes/dma/esp_aes.c:118 (inlined by) esp_aes_dma_wait_complete at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/port/aes/dma/esp_aes.c:239 (inlined by) esp_aes_process_dma at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/port/aes/dma/esp_aes.c:454
0x42022502: esp_aes_crypt_ctr at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/port/aes/dma/esp_aes.c:1074
0x4202390a: esp_aes_gcm_update at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/port/aes/esp_aes_gcm.c:481
0x42023a08: esp_aes_gcm_crypt_and_tag_partial_hw at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/port/aes/esp_aes_gcm.c:578
0x42023a4f: esp_aes_gcm_crypt_and_tag at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/port/aes/esp_aes_gcm.c:705
0x4201a357: mbedtls_cipher_aead_encrypt at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/mbedtls/library/cipher.c:1350 (inlined by) mbedtls_cipher_auth_encrypt_ext at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/mbedtls/library/cipher.c:1524
0x42013e01: mbedtls_ssl_encrypt_buf at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/mbedtls/library/ssl_msg.c:993
0x42014433: mbedtls_ssl_write_record at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/mbedtls/library/ssl_msg.c:2757
0x42014a6e: ssl_write_real at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/mbedtls/library/ssl_msg.c:5685 (inlined by) mbedtls_ssl_write at C:/Users/Alex/.espressif/esp-idf/components/mbedtls/mbedtls/library/ssl_msg.c:5721
0x420133c4: esp_mbedtls_write at C:/Users/Alex/.espressif/esp-idf/components/esp-tls/esp_tls_mbedtls.c:266 (discriminator 15)
0x420766da: esp_tls_conn_write at C:/Users/Alex/.espressif/esp-idf/components/esp-tls/esp_tls.c:137
0x4200828d: app_main at C:/Distr/ESP-IDF/tls_error_demo/main/tls_error_demo.cpp:272
0x4207c7a3: main_task at C:/Users/Alex/.espressif/esp-idf/components/freertos/app_startup.c:208 (discriminator 13)
DemTerritory
commented
1 year ago Are you going to fix this bug? I have an additional clarification to this issue. The TLS hang only occurs when the spi bus is initialized in SPI_DMA_DISABLED mode. If the mode is SPI_DMA_CH_AUTO, then TLS works correctly. I have to use DMA to send/receive two bytes to get around the bug
kayzen9
commented
1 year ago try creting separate task for tls operation with large stack. I had same problem when doing tls operation in app_main, it can fail due to small stack. ..
DemTerritory
commented
1 year ago I have provided above a simple example demonstrating this error. It does not launch additional tasks, it does not limit or allocate memory, but it freezes TLS after SPI initialization. No, the problem here is not with memory, the problem is with the SPI driver, which breaks something in DMA. The encryption functions in the ESP32-S3 are implemented in hardware and are invoked using DMA. The SPI driver can also use DMA. When initialized in SPI_DMA_DISABLED mode, SPI should not touch anything in DMA, but it still does something there and breaks DMA. The log shows that the watchdog timer is triggered because the call "esp_aes_wait_dma_done" was waiting too long for completion.
Yes, I tried in my program to increase the stack of a task that sends results via TLS. There were 4000 bytes, I made 14000 bytes, then 24000, 34000 - the result did not change
ginkgm
commented
1 year ago Hi @DemTerritory ,
Thanks for detailed issue report, your information helped a lot! We have confirmed this is an issue in the SPI driver.
Here's the fix in review:
From 83152215232b048aa510330eae2ef17d1bd8041d Mon Sep 17 00:00:00 2001
From: Xiao Xufeng <xiaoxufeng@espressif.com>
Date: Tue, 24 Oct 2023 02:52:51 +0800
Subject: [PATCH] fix(spi): fixed undesired touching to DMA
Closes https://github.com/espressif/esp-idf/issues/12241
---
components/hal/spi_hal.c | 4 +++-
components/hal/spi_slave_hal.c | 4 +++-
components/hal/spi_slave_hd_hal.c | 4 +++-
3 files changed, 9 insertions(+), 3 deletions(-)
diff --git a/components/hal/spi_hal.c b/components/hal/spi_hal.c
index d928fe997e48..25b77b8ef6b3 100644
--- a/components/hal/spi_hal.c
+++ b/components/hal/spi_hal.c
@@ -71,7 +71,9 @@ void spi_hal_init(spi_hal_context_t *hal, uint32_t host_id, const spi_hal_config
spi_ll_set_mosi_free_level(hw, 0);
#endif
spi_ll_master_init(hw);
- s_spi_hal_dma_init_config(hal);
+ if (config->dma_enabled) {
+ s_spi_hal_dma_init_config(hal);
+ }
//Force a transaction done interrupt. This interrupt won't fire yet because
//we initialized the SPI interrupt as disabled. This way, we can just
diff --git a/components/hal/spi_slave_hal.c b/components/hal/spi_slave_hal.c
index 7c437a0b3fa3..9d61e12042af 100644
--- a/components/hal/spi_slave_hal.c
+++ b/components/hal/spi_slave_hal.c
@@ -41,7 +41,9 @@ void spi_slave_hal_init(spi_slave_hal_context_t *hal, const spi_slave_hal_config
hal->dma_in = hal_config->dma_in;
hal->dma_out = hal_config->dma_out;
- s_spi_slave_hal_dma_init_config(hal);
+ if (hal->use_dma) {
+ s_spi_slave_hal_dma_init_config(hal);
+ }
spi_ll_slave_init(hal->hw);
//Force a transaction done interrupt. This interrupt won't fire yet because we initialized the SPI interrupt as
diff --git a/components/hal/spi_slave_hd_hal.c b/components/hal/spi_slave_hd_hal.c
index c2bf88a5597b..81a5bf5dfacc 100644
--- a/components/hal/spi_slave_hd_hal.c
+++ b/components/hal/spi_slave_hd_hal.c
@@ -71,7 +71,9 @@ void spi_slave_hd_hal_init(spi_slave_hd_hal_context_t *hal, const spi_slave_hd_h
hal->rx_dma_head = &hal->rx_dummy_head;
//Configure slave
- s_spi_slave_hd_hal_dma_init_config(hal);
+ if (hal_config->dma_enabled) {
+ s_spi_slave_hd_hal_dma_init_config(hal);
+ }
spi_ll_slave_hd_init(hw);
spi_ll_set_addr_bitlen(hw, hal_config->address_bits);
--
GitLab
Hopefully this will show up on Github soon. If you still find problems with the patch above, please poke me.
Thanks again!
Michael
DemTerritory
commented
1 year ago Yes this fix works for me. TLS + spi_bus_initialize (SPICOMMON_BUSFLAG_MASTER, SPI_DMA_DISABLED) now works. Thank you!
ginkgm
commented
1 year ago You are welcome!
Answers checklist.
IDF version.
v5.2-dev-2756-g2bc1f2f574
Operating System used.
Windows
How did you build your project?
VS Code IDE
If you are using Windows, please specify command line type.
None
Development Kit.
ESP32-S3 LOLIN Mini
Power Supply used.
USB
What is the expected behavior?
If the SPI Master device is not initialized, then TLS works normally. After initialization SPI, TLS hangs and watchdog got triggered.
What is the actual behavior?
If the SPI Master device is not initialized, then TLS works normally. After initialization SPI, TLS hangs and watchdog got triggered.
Steps to reproduce.
If the SPI Master device is not initialized, then TLS works normally: ret_bytes = esp_tls_conn_write(tls, header.c_str(), header.length()); // OK !!!
After initialization SPI, TLS hangs and watchdog got triggered: ESP_ERROR_CHECK(spi_bus_initialize(DAC_HOST, &dac_bus_cfg, SPI_DMA_DISABLED)); // SPI_DMA_DISABLED !!! ... ret_bytes = esp_tls_conn_write(tls, header.c_str(), header.length()); // hangs up !!!
In backtrace pay attention to "esp_aes_dma_wait_complete", despite the fact that I did not enable DMA for SPI
Debug Logs.
More Information.
No response