From 45e1924e443fd589043d835f9d52550921c093e8 Mon Sep 17 00:00:00 2001 From: Tero Marttila Date: Wed, 17 Jun 2026 16:32:21 +0300 Subject: [PATCH 1/7] i2s_out: guard against repeated I2S_TX_REMPTY_INT_ST, assert on unset stats_out_timer_start --- components/i2s_out/esp32/i2s.c | 5 +++-- components/i2s_out/esp32/intr_iram.c | 20 ++++++++++++++++---- 2 files changed, 19 insertions(+), 6 deletions(-) diff --git a/components/i2s_out/esp32/i2s.c b/components/i2s_out/esp32/i2s.c index cc4f2488..57feb752 100644 --- a/components/i2s_out/esp32/i2s.c +++ b/components/i2s_out/esp32/i2s.c @@ -164,7 +164,7 @@ int i2s_out_i2s_flush(struct i2s_out *i2s_out, TickType_t timeout) taskEXIT_CRITICAL(&i2s_out->mux); if (i2s_done) { - LOG_DEBUG("done"); + LOG_DEBUG("done i2s_out=%d", i2s_out->i2s_done); return 0; } else if (!xTaskNotifyWait(0, I2S_OUT_TASK_NOTIFY_BIT_I2S_DONE, &bits, timeout)) { @@ -177,7 +177,7 @@ int i2s_out_i2s_flush(struct i2s_out *i2s_out, TickType_t timeout) return -1; } else { - LOG_DEBUG("wait -> done"); + LOG_DEBUG("wait bits=%08x i2s_out=%d", bits, i2s_out->i2s_done); return 0; } @@ -199,4 +199,5 @@ void i2s_out_i2s_stop(struct i2s_out *i2s_out) // reset event state i2s_out->i2s_done = false; i2s_out->i2s_done_task = NULL; + i2s_out->stats_out_timer_start = 0; } diff --git a/components/i2s_out/esp32/intr_iram.c b/components/i2s_out/esp32/intr_iram.c index 6340e57b..640d4955 100644 --- a/components/i2s_out/esp32/intr_iram.c +++ b/components/i2s_out/esp32/intr_iram.c @@ -52,7 +52,9 @@ static void i2s_out_intr_i2s_done(struct i2s_out *i2s_out, BaseType_t *pxHigherP } // stats - stats_timer_stop(&i2s_out->stats.out_timer, &i2s_out->stats_out_timer_start); + if (i2s_out->stats_out_timer_start) { + stats_timer_stop(&i2s_out->stats.out_timer, &i2s_out->stats_out_timer_start); + } } static void i2s_intr_out_dscr_err_handler(struct i2s_out *i2s_out) @@ -112,11 +114,21 @@ static void i2s_intr_tx_rempty_handler(struct i2s_out *i2s_out, BaseType_t *pxHi // XXX: ignore if fired before dma_done, will be re-enabled // XXX: may indicate a timing glitch in the output data? LOG_ISR_WARN("tx rempty dma_done=%u i2s_done=%u", i2s_out->dma_done, i2s_out->i2s_done); - } else { - LOG_ISR_DEBUG("tx rempty dma_done=%u i2s_done=%u", i2s_out->dma_done, i2s_out->i2s_done); - i2s_out_intr_i2s_done(i2s_out, pxHigherPriorityTaskWoken); + return; + } + + if (i2s_out->i2s_done) { + // XXX: ignore if fired again + // XXX: unknown why this might happen + LOG_ISR_WARN("tx rempty dma_done=%u i2s_done=%u", i2s_out->dma_done, i2s_out->i2s_done); + + return; } + + LOG_ISR_DEBUG("tx rempty dma_done=%u i2s_done=%u", i2s_out->dma_done, i2s_out->i2s_done); + + i2s_out_intr_i2s_done(i2s_out, pxHigherPriorityTaskWoken); } void i2s_intr_handler(void *arg) From 5e09550cc1ec9c5aeb9883bfe13685a74a3842e3 Mon Sep 17 00:00:00 2001 From: Tero Marttila Date: Wed, 17 Jun 2026 16:45:26 +0300 Subject: [PATCH 2/7] i2s_out: track i2s_start state --- components/i2s_out/esp32/i2s.c | 9 ++++++--- components/i2s_out/esp32/intr_iram.c | 11 +++++++++-- components/i2s_out/i2s_out.h | 2 ++ 3 files changed, 17 insertions(+), 5 deletions(-) diff --git a/components/i2s_out/esp32/i2s.c b/components/i2s_out/esp32/i2s.c index 57feb752..00125a91 100644 --- a/components/i2s_out/esp32/i2s.c +++ b/components/i2s_out/esp32/i2s.c @@ -117,6 +117,7 @@ int i2s_out_i2s_setup(struct i2s_out *i2s_out, const struct i2s_out_options *opt ); // reset event state + i2s_out->i2s_start = false; i2s_out->i2s_done = false; i2s_out->i2s_done_task = NULL; @@ -131,11 +132,11 @@ void i2s_out_i2s_start(struct i2s_out *i2s_out) i2s_out->i2s_done = false; i2s_out->i2s_done_task = NULL; - // track active time - i2s_out->stats_out_timer_start = stats_timer_start(&i2s_out->stats.out_timer); - taskENTER_CRITICAL(&i2s_out->mux); + i2s_out->i2s_start = true; + i2s_out->stats_out_timer_start = stats_timer_start(&i2s_out->stats.out_timer); + // NOTE: there seems to always be three extra BCK cycles at the start of TX // XXX: occasionally, some trailing bits of the last TX will get transmitted first... // possibly if DMA is slow, and the FIFO does not yet contain the new data? @@ -193,6 +194,8 @@ void i2s_out_i2s_stop(struct i2s_out *i2s_out) i2s_intr_clear(i2s_out->dev, I2S_TX_REMPTY_INT_CLR); i2s_ll_tx_stop(i2s_out->dev); + + i2s_out->i2s_start = false; taskEXIT_CRITICAL(&i2s_out->mux); diff --git a/components/i2s_out/esp32/intr_iram.c b/components/i2s_out/esp32/intr_iram.c index 640d4955..3253b9c2 100644 --- a/components/i2s_out/esp32/intr_iram.c +++ b/components/i2s_out/esp32/intr_iram.c @@ -110,10 +110,17 @@ static void i2s_intr_tx_rempty_handler(struct i2s_out *i2s_out, BaseType_t *pxHi i2s_intr_disable(i2s_out->dev, I2S_TX_REMPTY_INT_ENA); i2s_intr_clear(i2s_out->dev, I2S_TX_REMPTY_INT_CLR); + if (!i2s_out->i2s_start) { + // XXX: ignore if fired before i2s_out_i2s_start() + LOG_ISR_WARN("tx rempty i2s_start=%d dma_done=%u i2s_done=%u", i2s_out->i2s_start, i2s_out->dma_done, i2s_out->i2s_done); + + return; + } + if (!i2s_out->dma_done) { // XXX: ignore if fired before dma_done, will be re-enabled // XXX: may indicate a timing glitch in the output data? - LOG_ISR_WARN("tx rempty dma_done=%u i2s_done=%u", i2s_out->dma_done, i2s_out->i2s_done); + LOG_ISR_WARN("tx rempty i2s_start=%d dma_done=%u i2s_done=%u", i2s_out->i2s_start, i2s_out->dma_done, i2s_out->i2s_done); return; } @@ -121,7 +128,7 @@ static void i2s_intr_tx_rempty_handler(struct i2s_out *i2s_out, BaseType_t *pxHi if (i2s_out->i2s_done) { // XXX: ignore if fired again // XXX: unknown why this might happen - LOG_ISR_WARN("tx rempty dma_done=%u i2s_done=%u", i2s_out->dma_done, i2s_out->i2s_done); + LOG_ISR_WARN("tx rempty i2s_start=%d dma_done=%u i2s_done=%u", i2s_out->i2s_start, i2s_out->dma_done, i2s_out->i2s_done); return; } diff --git a/components/i2s_out/i2s_out.h b/components/i2s_out/i2s_out.h index 30af2b7a..15847829 100644 --- a/components/i2s_out/i2s_out.h +++ b/components/i2s_out/i2s_out.h @@ -71,6 +71,8 @@ struct i2s_out { bool dma_start; // initialized by i2s_out_dma_setup(), set by i2s_out_dma_start(), cleared by i2s_out_dma_stop() bool dma_done; + + bool i2s_start; // set by i2s_out_i2s_start(), cleared by i2s_out_i2s_stop() bool i2s_done; TaskHandle_t dma_out_task; // task waiting for dma_out_desc to update From fa816d61324235fcc54b5e7a090fb5de7f2a0436 Mon Sep 17 00:00:00 2001 From: Tero Marttila Date: Wed, 17 Jun 2026 16:48:32 +0300 Subject: [PATCH 3/7] i2s_out: clear interrupts after stopping ll peripheral --- components/i2s_out/esp32/dma.c | 11 +++++------ components/i2s_out/esp32/i2s.c | 4 ++-- 2 files changed, 7 insertions(+), 8 deletions(-) diff --git a/components/i2s_out/esp32/dma.c b/components/i2s_out/esp32/dma.c index 39d4a921..edbc7fcf 100644 --- a/components/i2s_out/esp32/dma.c +++ b/components/i2s_out/esp32/dma.c @@ -604,14 +604,8 @@ void i2s_out_dma_stop(struct i2s_out *i2s_out) { LOG_DEBUG(""); - // reset write state - i2s_out->dma_start = false; - taskENTER_CRITICAL(&i2s_out->mux); - i2s_intr_disable(i2s_out->dev, I2S_OUT_DSCR_ERR_INT_ENA | I2S_OUT_EOF_INT_ENA); - i2s_intr_clear(i2s_out->dev, I2S_OUT_DSCR_ERR_INT_CLR | I2S_OUT_EOF_INT_CLR); - i2s_ll_rx_stop_link(i2s_out->dev); i2s_ll_tx_stop_link(i2s_out->dev); @@ -620,6 +614,11 @@ void i2s_out_dma_stop(struct i2s_out *i2s_out) i2s_ll_rx_reset_dma(i2s_out->dev); i2s_ll_tx_reset_dma(i2s_out->dev); + i2s_intr_disable(i2s_out->dev, I2S_OUT_DSCR_ERR_INT_ENA | I2S_OUT_EOF_INT_ENA); + i2s_intr_clear(i2s_out->dev, I2S_OUT_DSCR_ERR_INT_CLR | I2S_OUT_EOF_INT_CLR); + + i2s_out->dma_start = false; + taskEXIT_CRITICAL(&i2s_out->mux); // reset eof state diff --git a/components/i2s_out/esp32/i2s.c b/components/i2s_out/esp32/i2s.c index 00125a91..7eac8b91 100644 --- a/components/i2s_out/esp32/i2s.c +++ b/components/i2s_out/esp32/i2s.c @@ -190,11 +190,11 @@ void i2s_out_i2s_stop(struct i2s_out *i2s_out) taskENTER_CRITICAL(&i2s_out->mux); + i2s_ll_tx_stop(i2s_out->dev); + i2s_intr_disable(i2s_out->dev, I2S_TX_REMPTY_INT_ENA); i2s_intr_clear(i2s_out->dev, I2S_TX_REMPTY_INT_CLR); - i2s_ll_tx_stop(i2s_out->dev); - i2s_out->i2s_start = false; taskEXIT_CRITICAL(&i2s_out->mux); From 5ea75efd8ae8619369e08a3aa0cf8639246a1205 Mon Sep 17 00:00:00 2001 From: Tero Marttila Date: Wed, 17 Jun 2026 16:49:04 +0300 Subject: [PATCH 4/7] i2s_out: only re-enable tx rempty if i2s_start and disabled, log warn --- components/i2s_out/esp32/intr.h | 5 +++++ components/i2s_out/esp32/intr_iram.c | 10 +++++++--- 2 files changed, 12 insertions(+), 3 deletions(-) diff --git a/components/i2s_out/esp32/intr.h b/components/i2s_out/esp32/intr.h index c0175994..af53d205 100644 --- a/components/i2s_out/esp32/intr.h +++ b/components/i2s_out/esp32/intr.h @@ -3,6 +3,11 @@ #include #include +static inline bool i2s_intr_enabled(i2s_dev_t *hw, uint32_t mask) +{ + return hw->int_ena.val & mask; +} + static inline void i2s_intr_enable(i2s_dev_t *hw, uint32_t mask) { hw->int_ena.val |= mask; diff --git a/components/i2s_out/esp32/intr_iram.c b/components/i2s_out/esp32/intr_iram.c index 3253b9c2..05c973cb 100644 --- a/components/i2s_out/esp32/intr_iram.c +++ b/components/i2s_out/esp32/intr_iram.c @@ -93,9 +93,13 @@ static void i2s_intr_out_eof_handler(struct i2s_out *i2s_out, BaseType_t *pxHigh i2s_out_intr_dma_out_desc(i2s_out, eof_desc, pxHigherPriorityTaskWoken); i2s_out_intr_dma_done(i2s_out, pxHigherPriorityTaskWoken); - // XXX: ensure tx rempty intr is enabled, in case it fired during DMA and was disabled? - i2s_intr_clear(i2s_out->dev, I2S_TX_REMPTY_INT_CLR); - i2s_intr_enable(i2s_out->dev, I2S_TX_REMPTY_INT_ENA); + if (i2s_out->i2s_start && !i2s_intr_enabled(i2s_out->dev, I2S_TX_REMPTY_INT_ENA)) { + LOG_ISR_WARN("re-enable tx rempty interrupt"); + + // XXX: ensure tx rempty intr is enabled, in case it fired prematurely during DMA and was disabled? + i2s_intr_clear(i2s_out->dev, I2S_TX_REMPTY_INT_CLR); + i2s_intr_enable(i2s_out->dev, I2S_TX_REMPTY_INT_ENA); + } } else { LOG_ISR_ERROR("unknown desc=%p owner=%u len=%u", eof_desc, eof_desc->owner, eof_desc->len); From 7e6b687a3ba3c33207170354d8d9d17f41de6c51 Mon Sep 17 00:00:00 2001 From: Tero Marttila Date: Wed, 17 Jun 2026 16:49:18 +0300 Subject: [PATCH 5/7] i2s_out: drop missed eof to INFO level, always happens for short descrs --- components/i2s_out/esp32/intr_iram.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/components/i2s_out/esp32/intr_iram.c b/components/i2s_out/esp32/intr_iram.c index 05c973cb..1046fa7c 100644 --- a/components/i2s_out/esp32/intr_iram.c +++ b/components/i2s_out/esp32/intr_iram.c @@ -11,7 +11,7 @@ static void i2s_out_intr_dma_out_desc(struct i2s_out *i2s_out, struct dma_desc * { // update dma_out_desc and reset descs for write for (struct dma_desc *desc = i2s_out->dma_out_desc; (desc != NULL) && (desc != eof_desc); desc = desc->next) { - LOG_ISR_WARN("missed desc=%p owner=%u len=%u", desc, desc->owner, desc->len); + LOG_ISR_INFO("missed desc=%p owner=%u len=%u", desc, desc->owner, desc->len); i2s_dma_desc_reset(desc); } From 9d1f5d03a2edc0b2b7e4b1cd44a44dc68c9b004c Mon Sep 17 00:00:00 2001 From: Tero Marttila Date: Wed, 17 Jun 2026 16:50:11 +0300 Subject: [PATCH 6/7] i2s_out: log isr WARN on missing stats_out_timer_start --- components/i2s_out/esp32/intr_iram.c | 2 ++ 1 file changed, 2 insertions(+) diff --git a/components/i2s_out/esp32/intr_iram.c b/components/i2s_out/esp32/intr_iram.c index 1046fa7c..bd8a23b9 100644 --- a/components/i2s_out/esp32/intr_iram.c +++ b/components/i2s_out/esp32/intr_iram.c @@ -54,6 +54,8 @@ static void i2s_out_intr_i2s_done(struct i2s_out *i2s_out, BaseType_t *pxHigherP // stats if (i2s_out->stats_out_timer_start) { stats_timer_stop(&i2s_out->stats.out_timer, &i2s_out->stats_out_timer_start); + } else { + LOG_ISR_WARN("invalid stats_out_timer_start"); } } From a4ea0c8562b748bf60aa21bf283ae2b2eb796b0d Mon Sep 17 00:00:00 2001 From: Tero Marttila Date: Wed, 17 Jun 2026 16:58:43 +0300 Subject: [PATCH 7/7] i2s_out: tweak dma_start=true ordering --- components/i2s_out/esp32/dma.c | 3 ++- components/i2s_out/esp32/i2s.c | 1 + 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/components/i2s_out/esp32/dma.c b/components/i2s_out/esp32/dma.c index edbc7fcf..57c4ad3d 100644 --- a/components/i2s_out/esp32/dma.c +++ b/components/i2s_out/esp32/dma.c @@ -535,13 +535,14 @@ int i2s_out_dma_start(struct i2s_out *i2s_out) i2s_intr_clear(i2s_out->dev, I2S_OUT_DSCR_ERR_INT_CLR | I2S_OUT_EOF_INT_CLR); i2s_intr_enable(i2s_out->dev, I2S_OUT_DSCR_ERR_INT_ENA | I2S_OUT_EOF_INT_ENA); + i2s_out->dma_start = true; + i2s_ll_enable_dma(i2s_out->dev, true); i2s_ll_start_out_link(i2s_out->dev); taskEXIT_CRITICAL(&i2s_out->mux); // reset state for next write() - i2s_out->dma_start = true; i2s_out->dma_write_desc = i2s_out->dma_data_desc; return 0; diff --git a/components/i2s_out/esp32/i2s.c b/components/i2s_out/esp32/i2s.c index 7eac8b91..4dd18708 100644 --- a/components/i2s_out/esp32/i2s.c +++ b/components/i2s_out/esp32/i2s.c @@ -143,6 +143,7 @@ void i2s_out_i2s_start(struct i2s_out *i2s_out) // let's hope that the EOF frame is always zeroes, and zero bytes at the start are harmless... i2s_ll_tx_start(i2s_out->dev); + // can only be enabled once tx is running, will otherwise always fire immediately i2s_intr_clear(i2s_out->dev, I2S_TX_REMPTY_INT_CLR); i2s_intr_enable(i2s_out->dev, I2S_TX_REMPTY_INT_ENA);