On Sun, 2016-06-05 at 21:05 +0200, Georg Chini wrote:
> 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;
This initial jump in the extra latency is weird. If you want to include
(u->latency - u->minimum_latency) in the extra latency, why don't you
initialize extra latency to (u->latency - u->minimum_latency) already
in the beginning?
To me it would make much more sense to just start from zero, then go to
5 ms, then to 10 ms etc.
> +Â Â Â Â Â Â Â Â 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);
If you print the counter just before adjusting it, the log will be
misleading. If a line appears in the console saying "Underrun counter:
2", I don't think the natural thought process goes like "a-ha! the
counter value was 2 at the time of printing that message, so now it
clearly has to be 1!"
It would be also nice to have log messages when the counter goes up,
not only when it goes down.
> +Â Â Â Â }
> +
> Â Â Â Â Â /* 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;
iteration_counter, underrun_counter and extra_latency belong to the
main thread, I think, so they shouldn't be changed from the IO threads.
If you need to reset them when streams move, the "moving" callback can
be used.
source_sink_changed is used all over the place, and I don't know if
most of those uses make sense (see other comments).
> Â }
> Â
> Â /* 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;
> +Â Â Â Â Â Â Â Â }
Send a message about the source latency increase to the main thread and
update the variables there.
> Â Â Â Â Â }
> Â }
> Â
> @@ -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");
What's the purpose of this change?
> Â Â Â Â Â Â Â Â Â 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;
underrun_counter is used in the main thread, so you shouldn't access it
from the IO thread. Send a message to notify the main thread of the
underrun.
What's the purpose of the !u->source_sink_changed check?
--Â
Tanu
