jpmschweitzer/desklock
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases 4 Wiki Activity

Fork fix: the SDIO wedge is FIXED (esp-hosted-mcu #167)
Test, Build and Push / test-gateway (push) Successful in 12s
Details
Test, Build and Push / release (push) Skipped
Details
Test, Build and Push / build-gateway (push) Skipped
Details

Browse Source 
Root cause (verified against our exact IDF tree, not the community guess):
the "258" in "sdio_write_task: Failed to send data: 258" is NOT a timeout
(that is 263). 258 = 0x102 = ESP_ERR_INVALID_ARG. On the ESP32-P4, block-
mode CMD53 writes require the SOURCE buffer to be 64-byte (cache-line)
aligned; the IDF sdmmc driver rejects a misaligned source with INVALID_ARG
BEFORE any bus activity. esp_hosts write loop then declares "Unrecoverable
host sdio state" and reboots the whole P4. The audio TX payload is not
64-aligned, so streaming mic audio wedged on the very FIRST frame (which is
exactly what we saw: listening -> instant Failed to send -> reboot).

This also explains why buffer/queue/clock/retry tuning all did nothing: the
write never reached the bus. And why our symptom was instant, not after
~100 writes (the community block-mode-desync theory) — it is the first
misaligned buffer, every time.

Fix: vendored esp_hosted 2.12.11 as an editable local component (overrides
the registry copy) and bounce a misaligned TX payload through one aligned
DMA scratch buffer in hosted_sdio_write_block (port_esp_hosted_host_sdio.c).
TX is serialized by the bus lock so a single static bounce buffer is safe;
freed in hosted_sdio_deinit. Host-only change — no C6 reflash.

VERIFIED ON HARDWARE (autonomous self-test): 40s of continuous mic-audio
upstream streaming — the traffic that previously wedged on the first frame
— ran clean, zero timeouts, zero reboots. A guarded SDIO_TX_SELFTEST harness
is kept (compiled out) for future SDIO stress testing.

Credit: root cause + patch designed via multi-agent investigation; the
precise 258=INVALID_ARG decode (correcting the upstream community timeout
assumption) came from checking our actual esp_err.h.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
jpmschweitzer
2026-07-15 09:50:27 +02:00
co-authored by Claude Fable 5
parent ac9d24e0f9
commit cb5826e02b
666 changed files with 216925 additions and 0 deletions
Download Patch File Download Diff File Expand all files Collapse all files
firmware/components/esp_hosted/host/utils/stats.c
+241
View File
@@ -0,0 +1,241 @@
/*
* SPDX-FileCopyrightText: 2015-2026 Espressif Systems (Shanghai) CO LTD
*
* SPDX-License-Identifier: Apache-2.0
*/
/** Includes **/
#include "stats.h"
#if TEST_RAW_TP
#include "transport_drv.h"
#endif
#include "esp_log.h"
#include "esp_hosted_transport_init.h"
#include "esp_hosted_os_abstraction.h"
#include "port_esp_hosted_host_os.h"
// use mempool and zero copy for Tx
#include "mempool.h"
#if ESP_PKT_STATS
struct pkt_stats_t pkt_stats;
void *pkt_stats_thread = NULL;
#endif
#ifdef ESP_PKT_NUM_DEBUG
struct dbg_stats_t dbg_stats;
#endif
#if ESP_PKT_STATS || TEST_RAW_TP
static const char *TAG = "stats";
#endif
/** Constants/Macros **/
#define RAW_TP_TX_TASK_STACK_SIZE 2048
/** Exported variables **/
/** Function declaration **/
/** Exported Functions **/
// disable usage of mempool for now
#define DISABLE_MEMPOOL 1
#if TEST_RAW_TP
static int test_raw_tp = 0;
static uint8_t log_raw_tp_stats_timer_running = 0;
static uint32_t raw_tp_timer_count = 0;
void *hosted_timer_handler = NULL;
static void * raw_tp_tx_task_id = 0;
static uint64_t test_raw_tx_len = 0;
static uint64_t test_raw_rx_len = 0;
#if !DISABLE_MEMPOOL
static struct mempool * buf_mp_g = NULL;
#endif
void stats_mempool_free(void* ptr)
{
#if DISABLE_MEMPOOL
g_h.funcs->_h_free(ptr);
#else
mempool_free(buf_mp_g, ptr);
#endif
}
void test_raw_tp_cleanup(void)
{
int ret = 0;
if (log_raw_tp_stats_timer_running) {
ret = g_h.funcs->_h_timer_stop(hosted_timer_handler);
if (!ret) {
log_raw_tp_stats_timer_running = 0;
}
raw_tp_timer_count = 0;
}
if (raw_tp_tx_task_id) {
ret = g_h.funcs->_h_thread_cancel(raw_tp_tx_task_id);
raw_tp_tx_task_id = 0;
}
}
void raw_tp_timer_func(void * arg)
{
#if USE_FLOATING_POINT
double actual_bandwidth_tx = 0;
double actual_bandwidth_rx = 0;
#else
uint64_t actual_bandwidth_tx = 0;
uint64_t actual_bandwidth_rx = 0;
#endif
int32_t div = 1024;
actual_bandwidth_tx = (test_raw_tx_len*8)/TEST_RAW_TP__TIMEOUT;
actual_bandwidth_rx = (test_raw_rx_len*8)/TEST_RAW_TP__TIMEOUT;
#if USE_FLOATING_POINT
ESP_LOGI(TAG, "%lu-%lu sec Tx:%.2f Rx:%.2f kbps\n\r", raw_tp_timer_count, raw_tp_timer_count + TEST_RAW_TP__TIMEOUT, actual_bandwidth_tx/div, actual_bandwidth_rx/div);
#else
ESP_LOGI(TAG, "%lu-%lu sec Tx:%lu Rx:%lu Kbps", raw_tp_timer_count, raw_tp_timer_count + TEST_RAW_TP__TIMEOUT, (unsigned long)actual_bandwidth_tx/div, (unsigned long)actual_bandwidth_rx/div);
#endif
raw_tp_timer_count+=TEST_RAW_TP__TIMEOUT;
test_raw_tx_len = test_raw_rx_len = 0;
}
static void raw_tp_tx_task(void const* pvParameters)
{
int ret;
static uint16_t seq_num = 0;
uint8_t *raw_tp_tx_buf = NULL;
uint32_t *ptr = NULL;
uint32_t i = 0;
g_h.funcs->_h_sleep(5);
#if !DISABLE_MEMPOOL
buf_mp_g = mempool_create(MAX_TRANSPORT_BUFFER_SIZE);
#ifdef H_USE_MEMPOOL
assert(buf_mp_g);
#endif
#endif // !DISABLE_MEMPOOL
while (1) {
#if CONFIG_H_LOWER_MEMCOPY
raw_tp_tx_buf = (uint8_t*)g_h.funcs->_h_calloc(1, MAX_TRANSPORT_BUFFER_SIZE);
ptr = (uint32_t*) raw_tp_tx_buf;
for (i=0; i<(TEST_RAW_TP__BUF_SIZE/4-1); i++, ptr++)
*ptr = 0xBAADF00D;
ret = esp_hosted_tx(ESP_TEST_IF, 0, raw_tp_tx_buf, TEST_RAW_TP__BUF_SIZE, H_BUFF_ZEROCOPY, raw_tp_tx_buf, H_DEFLT_FREE_FUNC, 0);
#else
#if DISABLE_MEMPOOL
raw_tp_tx_buf = g_h.funcs->_h_malloc_align(MAX_TRANSPORT_BUFFER_SIZE, HOSTED_MEM_ALIGNMENT_64);
g_h.funcs->_h_memset(raw_tp_tx_buf, 0, MAX_TRANSPORT_BUFFER_SIZE);
#else
raw_tp_tx_buf = mempool_alloc(buf_mp_g, MAX_TRANSPORT_BUFFER_SIZE, true);
#endif
ptr = (uint32_t*) (raw_tp_tx_buf + H_ESP_PAYLOAD_HEADER_OFFSET);
for (i=0; i<(TEST_RAW_TP__BUF_SIZE/4-1); i++, ptr++)
*ptr = 0xBAADF00D;
ret = esp_hosted_tx(ESP_TEST_IF, 0, raw_tp_tx_buf, TEST_RAW_TP__BUF_SIZE, H_BUFF_ZEROCOPY, raw_tp_tx_buf, stats_mempool_free, 0);
#endif
if (ret) {
ESP_LOGE(TAG, "Failed to send to queue\n");
continue;
}
#if CONFIG_H_LOWER_MEMCOPY
g_h.funcs->_h_free(raw_tp_tx_buf);
#endif
test_raw_tx_len += (TEST_RAW_TP__BUF_SIZE);
seq_num++;
}
}
static void process_raw_tp_flags(uint8_t cap)
{
test_raw_tp_cleanup();
if (test_raw_tp) {
hosted_timer_handler = g_h.funcs->_h_timer_start("raw_tp_timer", SEC_TO_MILLISEC(TEST_RAW_TP__TIMEOUT),
H_TIMER_TYPE_PERIODIC, raw_tp_timer_func, NULL);
if (!hosted_timer_handler) {
ESP_LOGE(TAG, "Failed to create timer\n\r");
return;
}
log_raw_tp_stats_timer_running = 1;
ESP_LOGD(TAG, "capabilities: %d", cap);
if ((cap & ESP_TEST_RAW_TP__HOST_TO_ESP) ||
(cap & ESP_TEST_RAW_TP__BIDIRECTIONAL)) {
raw_tp_tx_task_id = g_h.funcs->_h_thread_create("raw_tp_tx", DFLT_TASK_PRIO,
RAW_TP_TX_TASK_STACK_SIZE, raw_tp_tx_task, NULL);
assert(raw_tp_tx_task_id);
}
}
}
static void start_test_raw_tp(void)
{
test_raw_tp = 1;
}
static void stop_test_raw_tp(void)
{
test_raw_tp = 0;
}
void process_test_capabilities(uint8_t cap)
{
ESP_LOGI(TAG, "ESP peripheral capabilities: 0x%x", cap);
if ((cap & ESP_TEST_RAW_TP) == ESP_TEST_RAW_TP) {
start_test_raw_tp();
ESP_LOGI(TAG, "***** Host Raw throughput Testing (report per %u sec) *****\n\r",TEST_RAW_TP__TIMEOUT);
} else {
ESP_LOGW(TAG, "Raw Throughput testing not enabled on slave. Stopping test.");
stop_test_raw_tp();
}
process_raw_tp_flags(H_TEST_RAW_TP_DIR);
}
void update_test_raw_tp_rx_len(uint16_t len)
{
test_raw_rx_len+=(len);
}
#endif
#if H_MEM_STATS
struct mem_stats h_stats_g;
#endif
#if ESP_PKT_STATS
void stats_timer_func(void * arg)
{
ESP_LOGI(TAG, "STA: s2h{in[%lu] out[%lu]} h2s{in(flowctrl_drop[%lu] in[%lu or %lu]) out(ok[%lu] drop[%lu])} flwctl{on[%lu] off[%lu]}",
pkt_stats.sta_rx_in,pkt_stats.sta_rx_out,
pkt_stats.sta_tx_flowctrl_drop, pkt_stats.sta_tx_in_pass, pkt_stats.sta_tx_trans_in, pkt_stats.sta_tx_out, pkt_stats.sta_tx_out_drop,
pkt_stats.sta_flow_ctrl_on, pkt_stats.sta_flow_ctrl_off);
ESP_LOGI(TAG, "internal: free %d l-free %d min-free %d, psram: free %d l-free %d min-free %d",
heap_caps_get_free_size(MALLOC_CAP_8BIT) - heap_caps_get_free_size(MALLOC_CAP_SPIRAM),
heap_caps_get_largest_free_block(MALLOC_CAP_8BIT | MALLOC_CAP_INTERNAL),
heap_caps_get_minimum_free_size(MALLOC_CAP_8BIT | MALLOC_CAP_INTERNAL),
heap_caps_get_free_size(MALLOC_CAP_SPIRAM),
heap_caps_get_largest_free_block(MALLOC_CAP_SPIRAM),
heap_caps_get_minimum_free_size(MALLOC_CAP_SPIRAM));
}
#endif
void create_debugging_tasks(void)
{
#if ESP_PKT_STATS
ESP_LOGI(TAG, "Start Pkt_stats reporting thread [timer: %u sec]", ESP_PKT_STATS_REPORT_INTERVAL);
pkt_stats_thread = g_h.funcs->_h_timer_start("pkt_stats_timer", SEC_TO_MILLISEC(ESP_PKT_STATS_REPORT_INTERVAL),
H_TIMER_TYPE_PERIODIC, stats_timer_func, NULL);
assert(pkt_stats_thread);
#endif
}
firmware/components/esp_hosted/host/utils/stats.h
+144
View File
@@ -0,0 +1,144 @@
/*
* SPDX-FileCopyrightText: 2015-2025 Espressif Systems (Shanghai) CO LTD
*
* SPDX-License-Identifier: Apache-2.0
*/
#ifndef __STATS__H
#define __STATS__H
#include "port_esp_hosted_host_config.h"
#ifdef __cplusplus
extern "C" {
#endif
/* Stats CONFIG:
*
* 1. TEST_RAW_TP
* These are debug stats which show the raw throughput
* performance of transport like SPI or SDIO
* (a) TEST_RAW_TP__ESP_TO_HOST
* When this enabled, throughput will be measured from ESP to Host
*
* (b) TEST_RAW_TP__HOST_TO_ESP
* This is opposite of TEST_RAW_TP__ESP_TO_HOST. when (a) TEST_RAW_TP__ESP_TO_HOST
* is disabled, it will automatically mean throughput to be measured from host to ESP
*/
#define TEST_RAW_TP H_TEST_RAW_TP
/* TEST_RAW_TP is disabled on production.
* This is only to test the throughout over transport
* like SPI or SDIO. In this testing, dummy task will
* push the packets over transport.
* Currently this testing is possible on one direction
* at a time
*/
#if TEST_RAW_TP
#define TEST_RAW_TP__TIMEOUT H_RAW_TP_REPORT_INTERVAL
void update_test_raw_tp_rx_len(uint16_t len);
void process_test_capabilities(uint8_t cap);
/* Please note, this size is to assess transport speed,
* so kept maximum possible for that transport
*
* If you want to compare maximum network throughput and
* relevance with max transport speed, Plz lower this value to
* UDP: 1460 - H_ESP_PAYLOAD_HEADER_OFFSET = 1460-12=1448
* TCP: Find MSS in nodes
* H_ESP_PAYLOAD_HEADER_OFFSET is header size, which is not included in calcs
*/
#define TEST_RAW_TP__BUF_SIZE H_RAW_TP_PKT_LEN
#endif
#if H_MEM_STATS
struct mempool_stats
{
uint32_t num_fresh_alloc;
uint32_t num_reuse;
uint32_t num_free;
};
struct spi_stats
{
int rx_alloc;
int rx_freed;
int tx_alloc;
int tx_dummy_alloc;
int tx_freed;
};
struct nw_stats
{
int tx_alloc;
int tx_freed;
};
struct others_stats {
int tx_others_freed;
};
struct mem_stats {
struct mempool_stats mp_stats;
struct spi_stats spi_mem_stats;
struct nw_stats nw_mem_stats;
struct others_stats others;
};
extern struct mem_stats h_stats_g;
#endif /*H_MEM_STATS*/
#ifdef ESP_PKT_NUM_DEBUG
struct dbg_stats_t {
uint16_t tx_pkt_num;
uint16_t exp_rx_pkt_num;
};
extern struct dbg_stats_t dbg_stats;
#define UPDATE_HEADER_TX_PKT_NO(h) h->pkt_num = htole16(dbg_stats.tx_pkt_num++)
#define UPDATE_HEADER_RX_PKT_NO(h) \
do { \
uint16_t rcvd_pkt_num = le16toh(h->pkt_num); \
if (dbg_stats.exp_rx_pkt_num != rcvd_pkt_num) { \
ESP_LOGI(TAG, "exp_pkt_num[%u], rx_pkt_num[%u]", \
dbg_stats.exp_rx_pkt_num, rcvd_pkt_num); \
dbg_stats.exp_rx_pkt_num = rcvd_pkt_num; \
} \
dbg_stats.exp_rx_pkt_num++; \
} while(0);
#else /*ESP_PKT_NUM_DEBUG*/
#define UPDATE_HEADER_TX_PKT_NO(h)
#define UPDATE_HEADER_RX_PKT_NO(h)
#endif /*ESP_PKT_NUM_DEBUG*/
#if ESP_PKT_STATS
struct pkt_stats_t {
uint32_t sta_rx_in;
uint32_t sta_rx_out;
uint32_t sta_tx_in_pass;
uint32_t sta_tx_trans_in;
uint32_t sta_tx_flowctrl_drop;
uint32_t sta_tx_out;
uint32_t sta_tx_out_drop;
uint32_t sta_flow_ctrl_on;
uint32_t sta_flow_ctrl_off;
};
extern struct pkt_stats_t pkt_stats;
#endif /*ESP_PKT_STATS*/
#ifdef __cplusplus
}
#endif
void create_debugging_tasks(void);
#endif