On 10.08.2016 23:41, Tanu Kaskinen wrote:
> 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?
There are several places where minimum_latency is set. I would have
to initialize extra_latency at all those places. So it is better to
initialize
the variable when it is used the first time.
> To me it would make much more sense to just start from zero, then go to
> 5 ms, then to 10 ms etc.
I can probably reorder it a bit so that extra_latency really starts with 0.
Also I have to think a bit more about it because I did not take into
account that minimum_latency may change.
>> + 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!"
This is just printing the counter each hour and therefore giving
you something like the observed underrun rate. The advantage
of printing it before it is decremented is that you can still see if
there is one underrun per hour, otherwise you would not notice it.
I could remove the log message completely if you prefer.
>
> It would be also nice to have log messages when the counter goes up,
> not only when it goes down.
There are log messages when an underrun occurs though they
do not mention explicitly that the counter was increased.
>
>> + }
>> +
>> /* 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.
When I resend the patches I will take care of the
variables-used-in-multiple-threads problem. I think
there was a reason why I did not use the moving
callback but I can't remember right now.
>
> 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.
Don't understand, isn't that already called from the main thread?
>
>> }
>> }
>>
>> @@ -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?
This is to suppress unnecessary log messages after startup or when
source or sink changes. See also comment at the bottom.
>
>> 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.
One question: It is only unsafe if both threads try to modify a
variable, correct? So is it OK if one threads sets a variable while
the other only reads it? Or do I have to take into account that
one thread may read the variable while the other modifies it at
the same time?
>
> What's the purpose of the !u->source_sink_changed check?
The condition may be met before the stream is completely set up, so the
check is to avoid false increments of the underrun counter.
It may actually be that the two checks above are no longer necessary when
I also wait for the source to startup, I will check when I finished the next
version.
>
> --
> Tanu
> _______________________________________________
> pulseaudio-discuss mailing list
> pulseaudio-discuss at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/pulseaudio-discuss
