fix(multimodal): stabilize downstream audio playback

- add configurable prebuffer and adaptive rebuffer for packet jitter
- mute stalled output, auto-clear I2S DMA, and abort inactive playback after 3 seconds
- discard stale-generation packets and add optional downstream diagnostics
This commit is contained in:
chenjintao
2026-08-11 15:25:26 +08:00
parent b60a0373ba
commit 3ce9b38098
5 changed files with 703 additions and 10 deletions
@@ -131,6 +131,26 @@
#define CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_IDLE_MUTE_MS 250
#endif
#ifndef CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_ACTIVE_STALL_MUTE_MS
#define CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_ACTIVE_STALL_MUTE_MS 3000
#endif
#ifndef CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_PREBUFFER_MS
#define CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_PREBUFFER_MS 160
#endif
#ifndef CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_REBUFFER_GAP_MS
#define CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_REBUFFER_GAP_MS 120
#endif
#ifndef CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_MAX_REBUFFER_MS
#define CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_MAX_REBUFFER_MS 640
#endif
#ifndef CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ENABLE
#define CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ENABLE 0
#endif
#ifndef CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_PLAYBACK_TASK_STACK
#define CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_PLAYBACK_TASK_STACK 12288
#endif
@@ -304,6 +324,8 @@ typedef struct {
bool downstream_output_primed;
bool downstream_response_active;
bool downstream_response_end_received;
TickType_t downstream_last_audio_tick;
TickType_t downstream_last_response_activity_tick;
esp_timer_handle_t downstream_idle_mute_timer;
QueueHandle_t downstream_playback_queue;
bool downstream_playback_queue_with_caps;
@@ -347,6 +369,29 @@ static uint32_t s_downstream_overflow_count;
static TickType_t s_downstream_overflow_last_log_tick;
static uint32_t s_downstream_queued_packet_total;
static uint32_t s_downstream_played_packet_total;
#if CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ENABLE
typedef struct {
TickType_t response_begin_tick;
TickType_t arrival_last_tick;
TickType_t first_arrival_tick;
TickType_t first_playback_tick;
TickType_t last_playback_tick;
TickType_t queue_empty_since_tick;
uint32_t arrival_gap_min_ms;
uint32_t arrival_gap_max_ms;
uint64_t arrival_gap_total_ms;
uint32_t arrival_gap_samples;
UBaseType_t queue_depth_min;
UBaseType_t queue_depth_max;
uint32_t queue_empty_events;
uint32_t queue_empty_max_ms;
uint32_t enqueue_failures;
uint32_t playback_failures;
bool summary_logged;
} downstream_diagnostics_t;
static downstream_diagnostics_t s_downstream_diagnostics;
#endif
static SemaphoreHandle_t s_downstream_playback_queue_mutex;
static bool s_downstream_playback_queue_mutex_initializing;
#if ( configSUPPORT_STATIC_ALLOCATION == 1 )
@@ -360,6 +405,7 @@ typedef struct {
typedef struct {
size_t len;
uint32_t playback_generation;
uint8_t *data;
} downstream_packet_t;
@@ -197,6 +197,7 @@ static esp_err_t init_i2s_bus(multimodal_audio_ctx_t *ctx)
(i2s_port_t)CONFIG_MULTIMODAL_AUDIO_I2S_PORT, I2S_ROLE_MASTER);
chan_cfg.dma_desc_num = CONFIG_MULTIMODAL_AUDIO_I2S_DMA_DESC_NUM;
chan_cfg.dma_frame_num = CONFIG_MULTIMODAL_AUDIO_I2S_DMA_FRAME_NUM;
chan_cfg.auto_clear_after_cb = true;
esp_err_t err = i2s_new_channel(&chan_cfg, &ctx->tx_handle, &ctx->rx_handle);
if (err != ESP_OK) {
ESP_LOGE(TAG, "Create I2S channels failed: %s", esp_err_to_name(err));
@@ -247,7 +248,7 @@ static esp_err_t init_i2s_bus(multimodal_audio_ctx_t *ctx)
}
ESP_LOGI(TAG,
"I2S ready: port=%d mclk=%d bclk=%d ws=%d dout=%d din=%d use_mclk=%d dma(desc=%d frame=%d)",
"I2S ready: port=%d mclk=%d bclk=%d ws=%d dout=%d din=%d use_mclk=%d dma(desc=%d frame=%d auto_clear=1)",
CONFIG_MULTIMODAL_AUDIO_I2S_PORT,
CONFIG_MULTIMODAL_AUDIO_I2S_MCLK_GPIO,
CONFIG_MULTIMODAL_AUDIO_I2S_BCLK_GPIO,
@@ -425,6 +425,16 @@ static void drain_downstream_playback_queue(multimodal_audio_ctx_t *ctx)
unlock_downstream_playback_queue();
}
static void drain_downstream_playback_queue_now(multimodal_audio_ctx_t *ctx)
{
if (ctx == NULL || !lock_downstream_playback_queue(0)) {
return;
}
QueueHandle_t queue = ctx->downstream_playback_queue;
drain_downstream_playback_queue_handle(queue);
unlock_downstream_playback_queue();
}
static void track_uplink_packet_queued(size_t len)
{
#if CONFIG_MULTIMODAL_AUDIO_LOG_UPLINK_LEVELS
@@ -545,6 +555,270 @@ static esp_err_t stop_downstream_idle_mute_task(multimodal_audio_ctx_t *ctx, int
#define MULTIMODAL_AUDIO_DOWNSTREAM_STATS_INTERVAL 200U
#define MULTIMODAL_AUDIO_DOWNSTREAM_BACKLOG_WARN_MS 5000U
#define MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ACTIVE_INTERVAL_MS 1000U
#if CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ENABLE
static void reset_downstream_diagnostics(void)
{
TickType_t now = xTaskGetTickCount();
portENTER_CRITICAL(&s_audio_runtime_lock);
memset(&s_downstream_diagnostics, 0, sizeof(s_downstream_diagnostics));
s_downstream_diagnostics.response_begin_tick = now;
s_downstream_diagnostics.arrival_gap_min_ms = UINT32_MAX;
s_downstream_diagnostics.queue_depth_min = UINT32_MAX;
portEXIT_CRITICAL(&s_audio_runtime_lock);
}
static void note_downstream_arrival(UBaseType_t queue_depth)
{
TickType_t now = xTaskGetTickCount();
bool first_arrival = false;
uint32_t first_arrival_ms = 0U;
portENTER_CRITICAL(&s_audio_runtime_lock);
TickType_t previous = s_downstream_diagnostics.arrival_last_tick;
if (s_downstream_diagnostics.first_arrival_tick == 0U) {
s_downstream_diagnostics.first_arrival_tick = now;
first_arrival = true;
first_arrival_ms = (uint32_t)pdTICKS_TO_MS(
now - s_downstream_diagnostics.response_begin_tick);
}
s_downstream_diagnostics.arrival_last_tick = now;
if (previous != 0U) {
uint32_t gap_ms = (uint32_t)pdTICKS_TO_MS(now - previous);
if (gap_ms < s_downstream_diagnostics.arrival_gap_min_ms) {
s_downstream_diagnostics.arrival_gap_min_ms = gap_ms;
}
if (gap_ms > s_downstream_diagnostics.arrival_gap_max_ms) {
s_downstream_diagnostics.arrival_gap_max_ms = gap_ms;
}
s_downstream_diagnostics.arrival_gap_total_ms += gap_ms;
s_downstream_diagnostics.arrival_gap_samples++;
}
if (queue_depth < s_downstream_diagnostics.queue_depth_min) {
s_downstream_diagnostics.queue_depth_min = queue_depth;
}
if (queue_depth > s_downstream_diagnostics.queue_depth_max) {
s_downstream_diagnostics.queue_depth_max = queue_depth;
}
portEXIT_CRITICAL(&s_audio_runtime_lock);
if (first_arrival) {
ESP_LOGI(TAG,
"Downstream diagnostics first packet: wait_ms=%u queue_depth=%u",
(unsigned)first_arrival_ms,
(unsigned)queue_depth);
}
}
static void note_downstream_playback(void)
{
TickType_t now = xTaskGetTickCount();
bool first_playback = false;
uint32_t first_playback_ms = 0U;
portENTER_CRITICAL(&s_audio_runtime_lock);
if (s_downstream_diagnostics.first_playback_tick == 0U) {
s_downstream_diagnostics.first_playback_tick = now;
first_playback = true;
first_playback_ms = (uint32_t)pdTICKS_TO_MS(
now - s_downstream_diagnostics.response_begin_tick);
}
s_downstream_diagnostics.last_playback_tick = now;
portEXIT_CRITICAL(&s_audio_runtime_lock);
if (first_playback) {
ESP_LOGI(TAG,
"Downstream diagnostics first playback: wait_ms=%u",
(unsigned)first_playback_ms);
}
}
static void note_downstream_queue_empty(void)
{
TickType_t now = xTaskGetTickCount();
portENTER_CRITICAL(&s_audio_runtime_lock);
if (s_downstream_diagnostics.queue_empty_since_tick == 0U) {
s_downstream_diagnostics.queue_empty_since_tick = now;
}
portEXIT_CRITICAL(&s_audio_runtime_lock);
}
static void note_downstream_queue_recovered(void)
{
TickType_t now = xTaskGetTickCount();
uint32_t empty_ms = 0U;
portENTER_CRITICAL(&s_audio_runtime_lock);
TickType_t empty_since = s_downstream_diagnostics.queue_empty_since_tick;
if (empty_since != 0U) {
empty_ms = (uint32_t)pdTICKS_TO_MS(now - empty_since);
s_downstream_diagnostics.queue_empty_since_tick = 0U;
s_downstream_diagnostics.queue_empty_events++;
if (empty_ms > s_downstream_diagnostics.queue_empty_max_ms) {
s_downstream_diagnostics.queue_empty_max_ms = empty_ms;
}
}
portEXIT_CRITICAL(&s_audio_runtime_lock);
if (empty_ms >= s_audio.opus_frame_duration_ms) {
ESP_LOGW(TAG,
"Downstream diagnostics: queue recovered after %u ms empty",
(unsigned)empty_ms);
}
}
static void note_downstream_enqueue_failure(void)
{
portENTER_CRITICAL(&s_audio_runtime_lock);
s_downstream_diagnostics.enqueue_failures++;
portEXIT_CRITICAL(&s_audio_runtime_lock);
}
static void note_downstream_playback_failure(void)
{
portENTER_CRITICAL(&s_audio_runtime_lock);
s_downstream_diagnostics.playback_failures++;
portEXIT_CRITICAL(&s_audio_runtime_lock);
}
static void log_downstream_diagnostics(const char *phase, bool final_summary)
{
downstream_diagnostics_t snapshot = {0};
TickType_t now = xTaskGetTickCount();
portENTER_CRITICAL(&s_audio_runtime_lock);
if (final_summary && s_downstream_diagnostics.summary_logged) {
portEXIT_CRITICAL(&s_audio_runtime_lock);
return;
}
if (final_summary) {
s_downstream_diagnostics.summary_logged = true;
}
snapshot = s_downstream_diagnostics;
portEXIT_CRITICAL(&s_audio_runtime_lock);
uint32_t gap_min_ms = snapshot.arrival_gap_samples > 0U ?
snapshot.arrival_gap_min_ms : 0U;
uint32_t gap_avg_ms = snapshot.arrival_gap_samples > 0U ?
(uint32_t)(snapshot.arrival_gap_total_ms / snapshot.arrival_gap_samples) : 0U;
UBaseType_t depth_min = snapshot.queue_depth_min != UINT32_MAX ?
snapshot.queue_depth_min : 0U;
uint32_t response_age_ms = snapshot.response_begin_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(now - snapshot.response_begin_tick) : 0U;
uint32_t first_arrival_ms = snapshot.first_arrival_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(snapshot.first_arrival_tick - snapshot.response_begin_tick) : 0U;
uint32_t last_arrival_age_ms = snapshot.arrival_last_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(now - snapshot.arrival_last_tick) : 0U;
uint32_t first_playback_ms = snapshot.first_playback_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(snapshot.first_playback_tick - snapshot.response_begin_tick) : 0U;
uint32_t last_playback_age_ms = snapshot.last_playback_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(now - snapshot.last_playback_tick) : 0U;
UBaseType_t current_depth = 0U;
if (lock_downstream_playback_queue(pdMS_TO_TICKS(20))) {
QueueHandle_t queue = s_audio.downstream_playback_queue;
if (queue != NULL) {
current_depth = uxQueueMessagesWaiting(queue);
}
unlock_downstream_playback_queue();
}
ESP_LOGI(TAG,
"Downstream diagnostics %s: response_age_ms=%u first_packet=%d first_packet_ms=%u last_packet_age_ms=%u first_playback=%d first_playback_ms=%u last_playback_age_ms=%u queued=%u played=%u current_depth=%u depth_min=%u depth_max=%u arrival_gap_ms(min/avg/max)=%u/%u/%u empty_events=%u empty_max_ms=%u enqueue_failures=%u playback_failures=%u",
phase != NULL ? phase : "snapshot",
(unsigned)response_age_ms,
snapshot.first_arrival_tick != 0U ? 1 : 0,
(unsigned)first_arrival_ms,
(unsigned)last_arrival_age_ms,
snapshot.first_playback_tick != 0U ? 1 : 0,
(unsigned)first_playback_ms,
(unsigned)last_playback_age_ms,
(unsigned)s_downstream_queued_packet_total,
(unsigned)s_downstream_played_packet_total,
(unsigned)current_depth,
(unsigned)depth_min,
(unsigned)snapshot.queue_depth_max,
(unsigned)gap_min_ms,
(unsigned)gap_avg_ms,
(unsigned)snapshot.arrival_gap_max_ms,
(unsigned)snapshot.queue_empty_events,
(unsigned)snapshot.queue_empty_max_ms,
(unsigned)snapshot.enqueue_failures,
(unsigned)snapshot.playback_failures);
}
static void log_downstream_active_diagnostics(void)
{
downstream_diagnostics_t snapshot = {0};
TickType_t now = xTaskGetTickCount();
portENTER_CRITICAL(&s_audio_runtime_lock);
snapshot = s_downstream_diagnostics;
portEXIT_CRITICAL(&s_audio_runtime_lock);
uint32_t response_age_ms = snapshot.response_begin_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(now - snapshot.response_begin_tick) : 0U;
uint32_t last_packet_age_ms = snapshot.arrival_last_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(now - snapshot.arrival_last_tick) : 0U;
uint32_t last_playback_age_ms = snapshot.last_playback_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(now - snapshot.last_playback_tick) : 0U;
uint32_t queued = s_downstream_queued_packet_total;
uint32_t played = s_downstream_played_packet_total;
uint32_t pending_estimate = queued > played ? queued - played : 0U;
ESP_LOGW(TAG,
"Downstream diagnostics active_wait: response_age_ms=%u first_packet=%d last_packet_age_ms=%u first_playback=%d last_playback_age_ms=%u queued=%u played=%u pending_estimate=%u enqueue_failures=%u playback_failures=%u",
(unsigned)response_age_ms,
snapshot.first_arrival_tick != 0U ? 1 : 0,
(unsigned)last_packet_age_ms,
snapshot.first_playback_tick != 0U ? 1 : 0,
(unsigned)last_playback_age_ms,
(unsigned)queued,
(unsigned)played,
(unsigned)pending_estimate,
(unsigned)snapshot.enqueue_failures,
(unsigned)snapshot.playback_failures);
}
static void arm_downstream_active_diagnostics(multimodal_audio_ctx_t *ctx)
{
esp_timer_handle_t timer = audio_get_downstream_idle_mute_timer(ctx);
if (timer == NULL) {
return;
}
(void)esp_timer_stop(timer);
(void)esp_timer_start_once(
timer,
(uint64_t)MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ACTIVE_INTERVAL_MS * 1000ULL);
}
#else
static inline void reset_downstream_diagnostics(void) {}
static inline void note_downstream_arrival(UBaseType_t queue_depth) { (void)queue_depth; }
static inline void note_downstream_playback(void) {}
static inline void note_downstream_queue_empty(void) {}
static inline void note_downstream_queue_recovered(void) {}
static inline void note_downstream_enqueue_failure(void) {}
static inline void note_downstream_playback_failure(void) {}
static inline void log_downstream_diagnostics(const char *phase, bool final_summary)
{
(void)phase;
(void)final_summary;
}
static inline void log_downstream_active_diagnostics(void) {}
static inline void arm_downstream_active_diagnostics(multimodal_audio_ctx_t *ctx)
{
esp_timer_handle_t timer = audio_get_downstream_idle_mute_timer(ctx);
if (timer == NULL) {
return;
}
(void)esp_timer_stop(timer);
(void)esp_timer_start_once(
timer,
(uint64_t)CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_ACTIVE_STALL_MUTE_MS * 1000ULL);
}
#endif
static void log_downstream_pcm_stats(uint32_t played,
size_t opus_len,
@@ -1378,6 +1652,50 @@ static bool snapshot_downstream_response_active(void)
return active;
}
static TickType_t snapshot_downstream_last_audio_tick(const multimodal_audio_ctx_t *ctx)
{
TickType_t tick = 0;
portENTER_CRITICAL(&s_audio_runtime_lock);
if (ctx != NULL) {
tick = ctx->downstream_last_audio_tick;
}
portEXIT_CRITICAL(&s_audio_runtime_lock);
return tick;
}
static TickType_t snapshot_downstream_last_response_activity_tick(
const multimodal_audio_ctx_t *ctx)
{
TickType_t tick = 0;
portENTER_CRITICAL(&s_audio_runtime_lock);
if (ctx != NULL) {
tick = ctx->downstream_last_response_activity_tick;
}
portEXIT_CRITICAL(&s_audio_runtime_lock);
return tick;
}
static void update_downstream_last_audio_tick(multimodal_audio_ctx_t *ctx,
TickType_t tick)
{
portENTER_CRITICAL(&s_audio_runtime_lock);
if (ctx != NULL) {
ctx->downstream_last_audio_tick = tick;
ctx->downstream_last_response_activity_tick = tick;
}
portEXIT_CRITICAL(&s_audio_runtime_lock);
}
static void update_downstream_response_activity_tick(multimodal_audio_ctx_t *ctx,
TickType_t tick)
{
portENTER_CRITICAL(&s_audio_runtime_lock);
if (ctx != NULL && ctx->downstream_response_active) {
ctx->downstream_last_response_activity_tick = tick;
}
portEXIT_CRITICAL(&s_audio_runtime_lock);
}
static void update_downstream_response_state(bool active, bool end_received)
{
portENTER_CRITICAL(&s_audio_runtime_lock);
@@ -1391,6 +1709,24 @@ static void notify_downstream_playback_stopped(void)
notify_downstream_playback_finished(MULTIMODAL_AUDIO_DOWNSTREAM_PLAYBACK_STOPPED);
}
static void abort_downstream_response_after_active_stall(multimodal_audio_ctx_t *ctx,
uint32_t idle_ms)
{
ESP_LOGW(TAG,
"Downstream protection watchdog: abort stalled response idle_ms=%u",
(unsigned)idle_ms);
(void)advance_downstream_playback_generation();
notify_downstream_playback_stopped();
update_downstream_response_state(false, false);
if (audio_get_downstream_playback_task(ctx) != NULL ||
audio_get_downstream_playback_starting(ctx)) {
audio_set_downstream_playback_stopping(ctx, true);
audio_set_downstream_playback_keep_stopping_on_exit(ctx, false);
audio_set_downstream_playback_stop_requested(ctx, true);
}
drain_downstream_playback_queue_now(ctx);
}
static void maybe_notify_downstream_playback_completed_after_drain(const char *reason)
{
if (!snapshot_downstream_response_end_received()) {
@@ -1413,6 +1749,7 @@ static void maybe_notify_downstream_playback_completed_after_drain(const char *r
ESP_LOGI(TAG,
"Downstream playback completed after response end (%s)",
reason ? reason : "drained");
log_downstream_diagnostics("playback_complete", true);
notify_downstream_playback_completed();
update_downstream_response_state(false, false);
}
@@ -1456,10 +1793,111 @@ static uint32_t get_downstream_idle_mute_timeout_ms(void)
return timeout_ms;
}
static uint32_t get_downstream_active_stall_mute_timeout_ms(void)
{
uint32_t timeout_ms =
(uint32_t)CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_ACTIVE_STALL_MUTE_MS;
uint32_t idle_timeout_ms = get_downstream_idle_mute_timeout_ms();
return timeout_ms < idle_timeout_ms ? idle_timeout_ms : timeout_ms;
}
static UBaseType_t get_downstream_prebuffer_packet_count(
const multimodal_audio_ctx_t *ctx)
{
uint32_t frame_ms = ctx != NULL && ctx->opus_frame_duration_ms != 0U ?
ctx->opus_frame_duration_ms : 20U;
uint32_t packet_count =
((uint32_t)CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_PREBUFFER_MS + frame_ms - 1U) /
frame_ms;
if (packet_count == 0U) {
packet_count = 1U;
}
UBaseType_t queue_len = get_downstream_playback_queue_len();
return packet_count > (uint32_t)queue_len ? queue_len : (UBaseType_t)packet_count;
}
static UBaseType_t get_downstream_recovery_packet_count(
const multimodal_audio_ctx_t *ctx,
uint32_t underrun_count)
{
uint32_t frame_ms = ctx != NULL && ctx->opus_frame_duration_ms != 0U ?
ctx->opus_frame_duration_ms : 20U;
uint32_t base_ms = (uint32_t)CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_PREBUFFER_MS;
if (base_ms < frame_ms) {
base_ms = frame_ms;
}
uint32_t max_ms = (uint32_t)CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_MAX_REBUFFER_MS;
if (max_ms < base_ms) {
max_ms = base_ms;
}
uint64_t scaled_ms = (uint64_t)base_ms * ((uint64_t)underrun_count + 1ULL);
uint32_t recovery_ms = scaled_ms > max_ms ? max_ms : (uint32_t)scaled_ms;
uint32_t packet_count = (recovery_ms + frame_ms - 1U) / frame_ms;
UBaseType_t queue_len = get_downstream_playback_queue_len();
return packet_count > (uint32_t)queue_len ? queue_len : (UBaseType_t)packet_count;
}
static uint32_t get_downstream_rebuffer_gap_ms(const multimodal_audio_ctx_t *ctx)
{
uint32_t frame_ms = ctx != NULL && ctx->opus_frame_duration_ms != 0U ?
ctx->opus_frame_duration_ms : 20U;
uint32_t gap_ms = (uint32_t)CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_REBUFFER_GAP_MS;
return gap_ms < frame_ms ? frame_ms : gap_ms;
}
static void restart_downstream_idle_mute_timer(multimodal_audio_ctx_t *ctx,
uint32_t timeout_ms)
{
esp_timer_handle_t timer = audio_get_downstream_idle_mute_timer(ctx);
if (timer == NULL) {
return;
}
(void)esp_timer_stop(timer);
(void)esp_timer_start_once(timer, (uint64_t)(timeout_ms == 0U ? 1U : timeout_ms) * 1000ULL);
}
static void downstream_idle_mute_timer_cb(void *arg)
{
multimodal_audio_ctx_t *ctx = (multimodal_audio_ctx_t *)arg;
if (ctx == NULL || snapshot_downstream_response_active()) {
if (ctx == NULL) {
return;
}
const bool response_active = snapshot_downstream_response_active();
if (response_active) {
log_downstream_active_diagnostics();
TickType_t now = xTaskGetTickCount();
TickType_t last_audio_tick = snapshot_downstream_last_audio_tick(ctx);
uint32_t idle_ms = last_audio_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(now - last_audio_tick) : 0U;
uint32_t idle_timeout_ms = get_downstream_idle_mute_timeout_ms();
uint32_t stall_timeout_ms = get_downstream_active_stall_mute_timeout_ms();
if (idle_ms < idle_timeout_ms) {
restart_downstream_idle_mute_timer(ctx, idle_timeout_ms - idle_ms);
return;
}
if (ctx->initialized && ctx->codec_dev != NULL) {
(void)set_downstream_output_mute_if_needed(ctx, true, "Active response gap");
}
if (idle_ms < stall_timeout_ms) {
uint32_t remaining_ms = stall_timeout_ms - idle_ms;
#if CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ENABLE
if (remaining_ms > MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ACTIVE_INTERVAL_MS) {
remaining_ms = MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ACTIVE_INTERVAL_MS;
}
#endif
restart_downstream_idle_mute_timer(ctx, remaining_ms);
return;
}
TickType_t last_activity_tick = snapshot_downstream_last_response_activity_tick(ctx);
uint32_t response_idle_ms = last_activity_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(now - last_activity_tick) : idle_ms;
if (response_idle_ms < stall_timeout_ms) {
restart_downstream_idle_mute_timer(ctx, stall_timeout_ms - response_idle_ms);
return;
}
abort_downstream_response_after_active_stall(ctx, idle_ms);
return;
}
@@ -1504,13 +1942,11 @@ static esp_err_t ensure_downstream_idle_mute_task(multimodal_audio_ctx_t *ctx)
static void notify_downstream_audio_active(multimodal_audio_ctx_t *ctx)
{
esp_timer_handle_t timer = audio_get_downstream_idle_mute_timer(ctx);
if (ctx == NULL || timer == NULL) {
if (ctx == NULL) {
return;
}
(void)esp_timer_stop(timer);
(void)esp_timer_start_once(timer, (uint64_t)get_downstream_idle_mute_timeout_ms() * 1000ULL);
update_downstream_last_audio_tick(ctx, xTaskGetTickCount());
restart_downstream_idle_mute_timer(ctx, get_downstream_idle_mute_timeout_ms());
}
static esp_err_t ensure_downstream_tx_bounce_buffer(multimodal_audio_ctx_t *ctx)
@@ -1678,29 +2114,167 @@ static void downstream_playback_task(void *arg)
(unsigned)get_downstream_playback_max_packet_bytes());
downstream_packet_t packet = {0};
uint32_t buffered_generation = UINT32_MAX;
TickType_t buffer_wait_since = 0U;
TickType_t queue_empty_since = 0U;
TickType_t underrun_since = 0U;
TickType_t first_recovery_packet_tick = 0U;
bool playback_buffer_ready = false;
bool generation_started = false;
uint32_t recovery_underrun_count = 0U;
while (!audio_get_downstream_playback_stop_requested(ctx)) {
BaseType_t received = pdFALSE;
QueueHandle_t queue = NULL;
if (lock_downstream_playback_queue(pdMS_TO_TICKS(20))) {
QueueHandle_t queue = ctx->downstream_playback_queue;
queue = ctx->downstream_playback_queue;
unlock_downstream_playback_queue();
if (queue != NULL) {
received = xQueueReceive(queue, &packet, pdMS_TO_TICKS(20));
}
uint32_t current_generation = snapshot_downstream_playback_generation();
if (current_generation != buffered_generation) {
buffered_generation = current_generation;
buffer_wait_since = xTaskGetTickCount();
queue_empty_since = 0U;
underrun_since = 0U;
first_recovery_packet_tick = 0U;
playback_buffer_ready = false;
generation_started = false;
recovery_underrun_count = 0U;
}
if (queue != NULL && !playback_buffer_ready) {
UBaseType_t queued_packets = uxQueueMessagesWaiting(queue);
UBaseType_t target_packets = generation_started ?
get_downstream_recovery_packet_count(ctx, recovery_underrun_count) :
get_downstream_prebuffer_packet_count(ctx);
TickType_t now = xTaskGetTickCount();
if (generation_started && queued_packets > 0U && first_recovery_packet_tick == 0U) {
first_recovery_packet_tick = now;
}
bool response_ended = snapshot_downstream_response_end_received();
if (queued_packets >= target_packets || (response_ended && queued_packets > 0U)) {
playback_buffer_ready = true;
uint32_t buffered_ms = (uint32_t)queued_packets * ctx->opus_frame_duration_ms;
uint32_t waited_ms = buffer_wait_since != 0U ?
(uint32_t)pdTICKS_TO_MS(now - buffer_wait_since) : 0U;
if (generation_started) {
uint32_t outage_ms = underrun_since != 0U ?
(uint32_t)pdTICKS_TO_MS(now - underrun_since) : waited_ms;
#if CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ENABLE
uint32_t first_packet_wait_ms =
underrun_since != 0U && first_recovery_packet_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(
first_recovery_packet_tick - underrun_since) : 0U;
uint32_t held_after_first_packet_ms = first_recovery_packet_tick != 0U ?
(uint32_t)pdTICKS_TO_MS(now - first_recovery_packet_tick) : 0U;
#endif
ESP_LOGI(TAG,
"Downstream recovery buffer ready: depth=%u target=%u buffered_ms=%u waited_ms=%u outage_ms=%u",
(unsigned)queued_packets,
(unsigned)target_packets,
(unsigned)buffered_ms,
(unsigned)waited_ms,
(unsigned)outage_ms);
#if CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ENABLE
ESP_LOGW(TAG,
"Downstream protection evidence: underrun=%u outage_ms=%u first_packet_wait_ms=%u held_after_first_packet_ms=%u buffered_ms=%u legacy_would_resume_at_first_packet=1",
(unsigned)recovery_underrun_count,
(unsigned)outage_ms,
(unsigned)first_packet_wait_ms,
(unsigned)held_after_first_packet_ms,
(unsigned)buffered_ms);
#endif
note_downstream_queue_recovered();
} else {
ESP_LOGI(TAG,
"Downstream initial buffer ready: depth=%u target=%u buffered_ms=%u waited_ms=%u",
(unsigned)queued_packets,
(unsigned)target_packets,
(unsigned)buffered_ms,
(unsigned)waited_ms);
#if CONFIG_MULTIMODAL_AUDIO_DOWNSTREAM_DIAGNOSTICS_ENABLE
ESP_LOGI(TAG,
"Downstream protection evidence: initial_wait_ms=%u buffered_ms=%u first_audio_jitter_budget_ms=%u",
(unsigned)waited_ms,
(unsigned)buffered_ms,
(unsigned)buffered_ms);
#endif
}
}
}
if (queue != NULL && playback_buffer_ready) {
received = xQueueReceive(queue, &packet, pdMS_TO_TICKS(20));
}
/* The response can change while xQueueReceive() is waiting. Do not let
* the previous generation's playback/empty state contaminate the new
* response diagnostics or completion handling. */
if (snapshot_downstream_playback_generation() != buffered_generation) {
if (received == pdTRUE) {
free_downstream_packet(&packet);
}
continue;
}
if (received != pdTRUE || packet.data == NULL || packet.len == 0U) {
if (snapshot_downstream_response_end_received()) {
maybe_notify_downstream_playback_completed_after_drain("queue_empty");
} else if (playback_buffer_ready && generation_started &&
snapshot_downstream_response_active()) {
TickType_t now = xTaskGetTickCount();
if (queue_empty_since == 0U) {
queue_empty_since = now;
note_downstream_queue_empty();
}
uint32_t empty_ms = (uint32_t)pdTICKS_TO_MS(now - queue_empty_since);
if (empty_ms >= get_downstream_rebuffer_gap_ms(ctx)) {
if (recovery_underrun_count < UINT32_MAX) {
recovery_underrun_count++;
}
UBaseType_t recovery_target = get_downstream_recovery_packet_count(
ctx,
recovery_underrun_count);
(void)set_downstream_output_mute_if_needed(
ctx,
true,
"Playback underrun");
playback_buffer_ready = false;
underrun_since = queue_empty_since;
buffer_wait_since = now;
first_recovery_packet_tick = 0U;
queue_empty_since = 0U;
ESP_LOGW(TAG,
"Downstream protection engaged: empty_ms=%u underrun=%u recovery_target=%u packets target_ms=%u output_muted=1",
(unsigned)empty_ms,
(unsigned)recovery_underrun_count,
(unsigned)recovery_target,
(unsigned)((uint32_t)recovery_target *
ctx->opus_frame_duration_ms));
}
}
vTaskDelay(pdMS_TO_TICKS(10));
continue;
}
if (queue_empty_since != 0U) {
note_downstream_queue_recovered();
queue_empty_since = 0U;
}
if (packet.playback_generation != snapshot_downstream_playback_generation()) {
free_downstream_packet(&packet);
continue;
}
if (!audio_get_downstream_playback_stop_requested(ctx)) {
esp_err_t err = handle_downstream_opus_sync(packet.data, packet.len);
if (err != ESP_OK && err != ESP_ERR_INVALID_STATE) {
note_downstream_playback_failure();
ESP_LOGW(TAG, "Downstream playback packet failed: %s", esp_err_to_name(err));
}
}
generation_started = true;
free_downstream_packet(&packet);
}
@@ -2079,6 +2653,7 @@ static esp_err_t handle_downstream_opus_sync(const uint8_t *data, size_t len)
(unsigned)out_frame.decoded_size);
return (esp_err_t)write_ret;
}
note_downstream_playback();
notify_downstream_playback_started(playback_generation);
notify_downstream_audio_active(ctx);
if ((played % MULTIMODAL_AUDIO_DOWNSTREAM_STATS_INTERVAL) == 0U) {
@@ -2150,6 +2725,7 @@ static esp_err_t handle_downstream_opus_sync(const uint8_t *data, size_t len)
(unsigned)out_codec_bytes);
return (esp_err_t)write_ret;
}
note_downstream_playback();
notify_downstream_playback_started(playback_generation);
notify_downstream_audio_active(ctx);
if ((played % MULTIMODAL_AUDIO_DOWNSTREAM_STATS_INTERVAL) == 0U) {
@@ -2199,20 +2775,24 @@ esp_err_t multimodal_audio_handle_downstream_opus(const uint8_t *data, size_t le
esp_err_t task_err = ensure_downstream_playback_task(ctx);
if (task_err != ESP_OK) {
note_downstream_enqueue_failure();
return task_err;
}
downstream_packet_t packet = {
.len = len,
.playback_generation = snapshot_downstream_playback_generation(),
.data = (uint8_t *)audio_psram_first_malloc(len),
};
if (packet.data == NULL) {
note_downstream_enqueue_failure();
return ESP_ERR_NO_MEM;
}
memcpy(packet.data, data, len);
esp_err_t queue_err = ESP_OK;
if (!lock_downstream_playback_queue(pdMS_TO_TICKS(20))) {
note_downstream_enqueue_failure();
free_downstream_packet(&packet);
return ESP_ERR_TIMEOUT;
}
@@ -2220,6 +2800,7 @@ esp_err_t multimodal_audio_handle_downstream_opus(const uint8_t *data, size_t le
QueueHandle_t queue = ctx->downstream_playback_queue;
if (ctx->downstream_playback_stopping || queue == NULL) {
unlock_downstream_playback_queue();
note_downstream_enqueue_failure();
free_downstream_packet(&packet);
return ESP_ERR_INVALID_STATE;
}
@@ -2245,12 +2826,15 @@ esp_err_t multimodal_audio_handle_downstream_opus(const uint8_t *data, size_t le
queue_err = ESP_ERR_TIMEOUT;
}
if (queue_err != ESP_OK) {
note_downstream_enqueue_failure();
free_downstream_packet(&packet);
return queue_err;
}
if (queued) {
update_downstream_response_activity_tick(ctx, xTaskGetTickCount());
uint32_t total = ++s_downstream_queued_packet_total;
note_downstream_arrival(queued_depth);
uint32_t queued_ms = (uint32_t)queued_depth * ctx->opus_frame_duration_ms;
if ((total % MULTIMODAL_AUDIO_DOWNSTREAM_STATS_INTERVAL) == 0U) {
ESP_LOGI(TAG,
@@ -2267,6 +2851,9 @@ esp_err_t multimodal_audio_handle_downstream_opus(const uint8_t *data, size_t le
(unsigned)queued_depth,
(unsigned)queued_ms);
}
if ((total % MULTIMODAL_AUDIO_DOWNSTREAM_STATS_INTERVAL) == 0U) {
log_downstream_diagnostics("periodic", false);
}
}
return ESP_OK;
@@ -2281,15 +2868,19 @@ esp_err_t multimodal_audio_begin_downstream_response(void)
uint32_t playback_generation = advance_downstream_playback_generation();
TickType_t begin_tick = xTaskGetTickCount();
portENTER_CRITICAL(&s_audio_runtime_lock);
ctx->downstream_response_active = true;
ctx->downstream_response_end_received = false;
ctx->downstream_output_primed = false;
ctx->downstream_playback_in_progress = false;
ctx->downstream_last_audio_tick = begin_tick;
ctx->downstream_last_response_activity_tick = begin_tick;
portEXIT_CRITICAL(&s_audio_runtime_lock);
s_downstream_queued_packet_total = 0U;
s_downstream_played_packet_total = 0U;
reset_downstream_diagnostics();
ESP_LOGI(TAG,
"Downstream response begin: sample_rate=%u frame=%ums codec_channels=%u pa_gpio=%d out_volume=%d",
(unsigned)ctx->opus_sample_rate,
@@ -2321,6 +2912,8 @@ esp_err_t multimodal_audio_begin_downstream_response(void)
esp_err_t idle_err = ensure_downstream_idle_mute_task(ctx);
if (idle_err != ESP_OK) {
ESP_LOGW(TAG, "Prepare downstream idle mute failed: %s", esp_err_to_name(idle_err));
} else {
arm_downstream_active_diagnostics(ctx);
}
esp_err_t task_err = ensure_downstream_playback_task(ctx);