On 06.12.2015 22:38, Tanu Kaskinen wrote:
> On Wed, 2015-02-25 at 19:43 +0100, Georg Chini wrote:
>> React by adjusting buffer latency.
>> ---
>> src/modules/module-loopback.c | 38 ++++++++++++++++++++++++++++++++++++--
>> 1 file changed, 36 insertions(+), 2 deletions(-)
>>
>> diff --git a/src/modules/module-loopback.c b/src/modules/module-loopback.c
>> index 09f2f58..cbd0ac9 100644
>> --- a/src/modules/module-loopback.c
>> +++ b/src/modules/module-loopback.c
>> @@ -84,6 +84,8 @@ struct userdata {
>> int64_t send_counter;
>> uint32_t sink_adjust_counter;
>> uint32_t source_adjust_counter;
>> + uint32_t underruns;
>> + uint32_t no_peeks;
>>
>> pa_usec_t latency;
>> pa_usec_t buffer_latency;
>> @@ -200,7 +202,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;
>> pa_usec_t final_latency, source_sink_latency, current_buffer_latency, current_latency, corrected_latency;
>> int32_t latency_difference;
>> pa_usec_t snapshot_delay;
>> @@ -208,6 +210,8 @@ 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 = PA_MIN(u->sink_adjust_counter, u->source_adjust_counter) * u->adjust_time / PA_USEC_PER_SEC / 3600;
>> u->sink_adjust_counter +=1;
>> u->source_adjust_counter +=1;
>>
>> @@ -215,6 +219,21 @@ static void adjust_rates(struct userdata *u) {
>> u->source_latency_sum += u->latency_snapshot.source_latency;
>> u->sink_latency_sum += u->latency_snapshot.sink_latency;
>>
>> + /* If we are seeing underruns or cannot peek into the queue during pop then the latency is too small */
> Why do you count the number of peek failures? Why isn't it enough to
> count underruns?
First, sorry for the late reply. I have been very busy the last weeks
and also
worked on a new controller version.
There are situations where I observe large latency changes when only the
peek failures are visible and no underruns are reported. Maybe that is a
consequence of the problem you point out below.
>
>> + if (u->underruns > 2 || u->no_peeks > 30) {
>> + u->buffer_latency += 5 * PA_USEC_PER_MSEC;
>> + pa_log_warn("Too many underruns, increasing buffer latency to %0.2f ms", (double) u->buffer_latency / PA_USEC_PER_MSEC);
>> + u->underruns = 0;
>> + u->no_peeks = 0;
>> + }
>> +
>> + /* Allow one underrun and 15 no peek messages per hour */
>> + if (PA_MIN(u->sink_adjust_counter, u->source_adjust_counter) * u->adjust_time / PA_USEC_PER_SEC / 3600 > hours) {
>> + pa_log_info("Underrun counters: %u, %u", u->underruns, u->no_peeks);
>> + u->underruns = PA_CLIP_SUB(u->underruns, 1u);
>> + u->no_peeks = PA_CLIP_SUB(u->no_peeks, 15u);
>> + }
>> +
>> /* Rates and latencies*/
>> old_rate = u->sink_input->sample_spec.rate;
>> base_rate = u->source_output->sample_spec.rate;
>> @@ -450,6 +469,8 @@ static void source_output_detach_cb(pa_source_output *o) {
>> u->source_sink_changed = true;
>> u->source_latency_sum = 0;
>> u->source_adjust_counter = 0;
>> + u->underruns = 0;
>> + u->no_peeks = 0;
>> u->buffer_latency = u->initial_buffer_latency;
>> }
>>
>> @@ -570,6 +591,8 @@ static void update_source_requested_latency_cb(pa_source_output *i) {
>> if (!u->source_sink_changed) {
>> u->source_adjust_counter = 0;
>> u->source_latency_sum = 0;
>> + u->underruns = 0;
>> + u->no_peeks = 0;
>> }
>> }
>> }
>> @@ -590,7 +613,10 @@ 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) {
>> + u->no_peeks +=1;
>> + pa_log_info("Could not peek into queue");
>> + }
>> return -1;
>> }
>>
>> @@ -648,6 +674,8 @@ static int sink_input_process_msg_cb(pa_msgobject *obj, int code, void *data, in
>> pa_memblockq_is_readable(u->memblockq)) {
>>
>> pa_log_debug("Requesting rewind due to end of underrun.");
>> + if (!u->source_sink_changed)
>> + u->underruns +=1;
>> 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);
> This seems buggy (also without your patch). This code is guarded by "if
> (!in_pop)". The message queue is drained in the beginning of the pop
> callback, and if the POST message that ends an underrun is processed in
> the pop callback, then the rewind is not done, and the underrun won't
> be counted in u->underruns.
>
> Neither of the problems is particularly serious, so we could ignore
> them, but the fix seems simple to me: it should be safe to just remove
> the message queue draining from the pop callback. It would mean that if
> the memblockq is empty, and a POST message is ready for processing when
> the pop callback is called, the audio in the message won't be used, and
> an unnecessary underrun will occur. I believe that's not a real
> problem, however. The memblockq should be empty only when the sink and
> source buffers are full, and if the sink buffer is full, the pop
> callback won't be called.
>
I will test what happens when I remove the message queue draining
from the pop callback, but I fear this might significantly impact the
latency calculations.
