diff --git a/components/i2s_out/esp32/dma.c b/components/i2s_out/esp32/dma.c index 39d4a921..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; @@ -604,14 +605,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 +615,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 cc4f2488..4dd18708 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,17 +132,18 @@ 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? // 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); @@ -164,7 +166,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 +179,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; } @@ -189,14 +191,17 @@ 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); // 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.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 6340e57b..bd8a23b9 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); } @@ -52,7 +52,11 @@ 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); + } else { + LOG_ISR_WARN("invalid stats_out_timer_start"); + } } static void i2s_intr_out_dscr_err_handler(struct i2s_out *i2s_out) @@ -91,9 +95,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); @@ -108,15 +116,32 @@ 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); - } else { - LOG_ISR_DEBUG("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); - 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 i2s_start=%d dma_done=%u i2s_done=%u", i2s_out->i2s_start, 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) 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