Because the latency controller will try to adjust to the configured latency regardless of underruns, an underrun protection has to be implemented which will increase the target latency if too many underruns occur. Underruns are tracked and if more than 3 underruns occur, the target latency is increased in increments of 5 ms. One underrun per hour is accepted. The protection ensures, that independent from the configured latency the module will converge to a stable latency if the configured latency is too small. --- src/modules/module-loopback.c | 76 ++++++++++++++++++++++++++++++++++++++----- 1 file changed, 67 insertions(+), 9 deletions(-) diff --git a/src/modules/module-loopback.c b/src/modules/module-loopback.c index f54644f..f370ae2 100644 --- a/src/modules/module-loopback.c +++ b/src/modules/module-loopback.c @@ -79,8 +79,11 @@ struct userdata { pa_time_event *time_event; + /* Various counters */ int64_t recv_counter; int64_t send_counter; + uint32_t iteration_counter; + uint32_t underrun_counter; /* Values from command line configuration */ pa_usec_t latency; @@ -97,9 +100,12 @@ struct userdata { pa_usec_t configured_source_latency; pa_usec_t minimum_latency; + pa_usec_t extra_latency; + /* Various booleans */ bool in_pop; bool pop_called; + bool source_sink_changed; bool fixed_alsa_source; struct { @@ -203,7 +209,7 @@ static uint32_t rate_controller( /* Called from main context */ static void adjust_rates(struct userdata *u) { size_t buffer; - uint32_t old_rate, base_rate, new_rate; + uint32_t old_rate, base_rate, new_rate, hours; int32_t latency_difference; pa_usec_t current_buffer_latency, snapshot_delay, current_source_sink_latency, current_latency, latency_at_optimum_rate; pa_usec_t final_latency; @@ -211,6 +217,26 @@ static void adjust_rates(struct userdata *u) { pa_assert(u); pa_assert_ctl_context(); + /* Runtime and counters since last change of source or sink */ + hours = u->iteration_counter * u->adjust_time / PA_USEC_PER_SEC / 3600; + u->iteration_counter +=1; + + /* If we are seeing underruns then the latency is too small */ + if (u->underrun_counter > 2) { + if (u->extra_latency == 0) + u->extra_latency = PA_CLIP_SUB(u->latency, u->minimum_latency) + 5 * PA_USEC_PER_MSEC; + else + u->extra_latency += 5 * PA_USEC_PER_MSEC; + pa_log_warn("Too many underruns, increasing latency to %0.2f ms", (double)(u->extra_latency + u->minimum_latency) / PA_USEC_PER_MSEC); + u->underrun_counter = 0; + } + + /* Allow one underrun per hour */ + if (u->iteration_counter * u->adjust_time / PA_USEC_PER_SEC / 3600 > hours) { + pa_log_info("Underrun counter: %u", u->underrun_counter); + u->underrun_counter = PA_CLIP_SUB(u->underrun_counter, 1u); + } + /* Rates and latencies*/ old_rate = u->sink_input->sample_spec.rate; base_rate = u->source_output->sample_spec.rate; @@ -231,7 +257,7 @@ static void adjust_rates(struct userdata *u) { /* Latency at base rate */ latency_at_optimum_rate = current_source_sink_latency + current_buffer_latency * old_rate / base_rate; - final_latency = PA_MAX(u->latency, u->minimum_latency); + final_latency = PA_MAX(u->latency, u->minimum_latency + u->extra_latency); latency_difference = (int32_t)((int64_t)latency_at_optimum_rate - final_latency); pa_log_debug("Loopback overall latency is %0.2f ms + %0.2f ms + %0.2f ms = %0.2f ms", @@ -245,6 +271,8 @@ static void adjust_rates(struct userdata *u) { /* Calculate new rate */ new_rate = rate_controller(base_rate, u->adjust_time, latency_difference); + u->source_sink_changed = false; + /* Set rate */ pa_sink_input_set_rate(u->sink_input, new_rate); pa_log_debug("[%s] Updated sampling rate to %lu Hz.", u->sink_input->sink->name, (unsigned long) new_rate); @@ -480,6 +508,12 @@ static void source_output_detach_cb(pa_source_output *o) { pa_rtpoll_item_free(u->rtpoll_item_write); u->rtpoll_item_write = NULL; } + + /* Reset latency controller variables */ + u->source_sink_changed = true; + u->iteration_counter = 0; + u->underrun_counter = 0; + u->extra_latency = 0; } /* Called from main thread */ @@ -585,9 +619,14 @@ static void update_source_requested_latency_cb(pa_source_output *i) { if (source_latency > u->configured_source_latency) { /* The minimum latency has changed to a value larger than the configured latency */ pa_log_warn("Source latency increased to %0.2f ms", (double)source_latency / PA_USEC_PER_MSEC); + u->extra_latency = PA_CLIP_SUB(u->extra_latency, source_latency - u->configured_source_latency); u->configured_source_latency = source_latency; u->min_source_latency = source_latency; update_minimum_latency(u); + if (!u->source_sink_changed) { + u->iteration_counter = 0; + u->underrun_counter = 0; + } } } @@ -611,7 +650,8 @@ static int sink_input_pop_cb(pa_sink_input *i, size_t nbytes, pa_memchunk *chunk u->in_pop = false; if (pa_memblockq_peek(u->memblockq, chunk) < 0) { - pa_log_info("Could not peek into queue"); + if (!u->source_sink_changed) + pa_log_info("Could not peek into queue"); return -1; } @@ -667,14 +707,18 @@ static int sink_input_process_msg_cb(pa_msgobject *obj, int code, void *data, in /* Is this the end of an underrun? Then let's start things * right-away */ - if (!u->in_pop && - u->sink_input->thread_info.underrun_for > 0 && + if (u->sink_input->thread_info.underrun_for > 0 && pa_memblockq_is_readable(u->memblockq)) { - pa_log_debug("Requesting rewind due to end of underrun."); - pa_sink_input_request_rewind(u->sink_input, - (size_t) (u->sink_input->thread_info.underrun_for == (size_t) -1 ? 0 : u->sink_input->thread_info.underrun_for), - false, true, false); + if (!u->source_sink_changed) + u->underrun_counter +=1; + /* If called from within the pop callback skip the rewind */ + if (!u->in_pop) { + pa_log_debug("Requesting rewind due to end of underrun."); + pa_sink_input_request_rewind(u->sink_input, + (size_t) (u->sink_input->thread_info.underrun_for == (size_t) -1 ? 0 : u->sink_input->thread_info.underrun_for), + false, true, false); + } } return 0; @@ -757,7 +801,12 @@ static void sink_input_detach_cb(pa_sink_input *i) { u->rtpoll_item_read = NULL; } + /* Reset latency controller variables */ + u->source_sink_changed = true; u->pop_called = false; + u->iteration_counter = 0; + u->underrun_counter = 0; + u->extra_latency = 0; } /* Called from output thread context */ @@ -880,9 +929,14 @@ static void update_sink_requested_latency_cb(pa_sink_input *i) { if (sink_latency > u->configured_sink_latency) { /* The minimum latency has changed to a value larger than the configured latency */ pa_log_warn("Sink latency increased to %0.2f ms", (double)sink_latency / PA_USEC_PER_MSEC); + u->extra_latency = PA_CLIP_SUB(u->extra_latency, sink_latency - u->configured_sink_latency); u->configured_sink_latency = sink_latency; u->min_sink_latency = sink_latency; update_minimum_latency(u); + if (!u->source_sink_changed) { + u->iteration_counter = 0; + u->underrun_counter = 0; + } } } @@ -998,6 +1052,10 @@ int pa__init(pa_module *m) { u->module = m; u->latency = (pa_usec_t) latency_msec * PA_USEC_PER_MSEC; u->pop_called = false; + u->iteration_counter = 0; + u->underrun_counter = 0; + u->source_sink_changed = true; + u->extra_latency = 0; adjust_time_sec = DEFAULT_ADJUST_TIME_USEC / PA_USEC_PER_SEC; if (pa_modargs_get_value_u32(ma, "adjust_time", &adjust_time_sec) < 0) { -- 2.8.1