On Tue, 2016-03-22 at 12:12 +0100, Georg Chini wrote:
> 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?
> >
> > >
> > > +Â Â Â Â 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.
> >
> Hi Tanu,
>
> it looks like this _is_ relevant when running very short latencies.
> Those "unnecessary underruns" occur for example when you
> try to run HDA -> HDA at 5 ms latency. So I would suggest
> to keep it mostly like it is.
> Instead of masking the whole block, I would suggest to only mask
> the rewind with "if (!in_pop)", so that at least the underruns are still
> counted.
What are the configured sink and source latencies in that "5 ms
latency" setup, and is timer-based scheduling enabled or not? My
recollection of the past discussion is that you never agreed to
configure the target loopback latency high enough to cover the case
where both the sink and source buffers are full. If the target latency
is too low in relation to the sink and source latencies, that would
explain the underruns.
If it's impossible for me to convince you to avoid configuring
inherently unsafe target latencies, then sure, let's keep draining the
message buffer in the pop callback, and live with the missed rewinds.
With timer-based scheduling there's practically nothing in the sink
buffer to rewind anyway when we are in the pop callback.
--Â
Tanu
