Skip to content

i2s_out: Fix i2s_start -> tx rempty -> i2s_done #128

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
SpComb wants to merge 7 commits into
base: master
Choose a base branch
from
Open

i2s_out: Fix i2s_start -> tx rempty -> i2s_done #128

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
45e1924
i2s_out: guard against repeated I2S_TX_REMPTY_INT_ST, assert on unset…
SpComb Jun 17, 2026
5e09550
i2s_out: track i2s_start state
SpComb Jun 17, 2026
fa816d6
i2s_out: clear interrupts after stopping ll peripheral
SpComb Jun 17, 2026
5ea75ef
i2s_out: only re-enable tx rempty if i2s_start and disabled, log warn
SpComb Jun 17, 2026
7e6b687
i2s_out: drop missed eof to INFO level, always happens for short descrs
SpComb Jun 17, 2026
9d1f5d0
i2s_out: log isr WARN on missing stats_out_timer_start
SpComb Jun 17, 2026
a4ea0c8
i2s_out: tweak dma_start=true ordering
SpComb Jun 17, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 7 additions & 7 deletions components/i2s_out/esp32/dma.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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);

Expand All @@ -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
Expand Down
17 changes: 11 additions & 6 deletions components/i2s_out/esp32/i2s.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand All @@ -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

@SpComb SpComb Jun 17, 2026

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Speculation: the premature tx rempty interrupts before DMA EOF might happen if DMA hasn't had a chance to put anything into the TX FIFO before i2s_out_i2s_start() starts I2S TX?

Testing shows that the i2s_intr_enable() -> i2s_ll_tx_start() ordering will always fire:

W (1522) i2s_intr_tx_rempty_handler: tx rempty i2s_start=1 dma_done=0 i2s_done=0
W (1552) i2s_intr_out_eof_handler: re-enable tx rempty interrupt
W (1552) i2s_intr_tx_rempty_handler: tx rempty i2s_start=1 dma_done=0 i2s_done=0
W (1582) i2s_intr_out_eof_handler: re-enable tx rempty interrupt
W (1582) i2s_intr_tx_rempty_handler: tx rempty i2s_start=1 dma_done=0 i2s_done=0
W (1602) i2s_intr_out_eof_handler: re-enable tx rempty interrupt
W (1602) i2s_intr_tx_rempty_handler: tx rempty i2s_start=1 dma_done=0 i2s_done=0
W (1632) i2s_intr_out_eof_handler: re-enable tx rempty interrupt
W (1632) i2s_intr_tx_rempty_handler: tx rempty i2s_start=1 dma_done=0 i2s_done=0
W (1662) i2s_intr_out_eof_handler: re-enable tx rempty interrupt

@SpComb SpComb Jun 17, 2026

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This also happens if calling i2s_out_i2s_start() -> i2s_out_dma_start().

W (1832) i2s_intr_out_eof_handler: re-enable tx rempty interrupt
W (1842) i2s_intr_tx_rempty_handler: tx rempty i2s_start=1 dma_done=0 i2s_done=0
W (1862) i2s_intr_out_eof_handler: re-enable tx rempty interrupt
W (1872) i2s_intr_tx_rempty_handler: tx rempty i2s_start=1 dma_done=0 i2s_done=0
W (1892) i2s_intr_out_eof_handler: re-enable tx rempty interrupt
W (1902) i2s_intr_tx_rempty_handler: tx rempty i2s_start=1 dma_done=0 i2s_done=0
W (1932) i2s_intr_out_eof_handler: re-enable tx rempty interrupt
W (1932) i2s_intr_tx_rempty_handler: tx rempty i2s_start=1 dma_done=0 i2s_done=0
W (1962) i2s_intr_out_eof_handler: re-enable tx rempty interrupt
W (1962) i2s_intr_tx_rempty_handler: tx rempty i2s_start=1 dma_done=0 i2s_done=0

@SpComb SpComb Jun 17, 2026 •
edited
Loading

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is a good thing, because the i2s out TX is likely to harmless at the very start of the transfer. But fixing this race would make the premature tx rempty intr warning more relevant, if some kind of memory contention causes the DMA to stall enough for the TX FIFO to empty during the frame and disrupt the WS2812B timings? Maybe we could even use i2s_ll_tx_stop_on_fifo_empty() / tx_stop_en?

i2s_intr_clear(i2s_out->dev, I2S_TX_REMPTY_INT_CLR);
i2s_intr_enable(i2s_out->dev, I2S_TX_REMPTY_INT_ENA);

Expand All @@ -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)) {
Expand All @@ -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;
}
Expand All @@ -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;
}
5 changes: 5 additions & 0 deletions components/i2s_out/esp32/intr.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,11 @@
#include <hal/i2s_ll.h>
#include <soc/i2s_reg.h>

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;
Expand Down
43 changes: 34 additions & 9 deletions components/i2s_out/esp32/intr_iram.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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);
Expand All @@ -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)
Expand Down
2 changes: 2 additions & 0 deletions components/i2s_out/i2s_out.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
Loading