New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 862047 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Closed: Jul 22
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug

Blocked on:
issue 860408



Sign in to add a comment

CRAS: multiple input device eventually will have deviated buffer level

Project Member Reported by hychao@chromium.org, Jul 10

Issue description

This is found when investigating echo problem of CFM use case. Since this can be reproduced by https://webaudiodemos.appspot.com/input/index.html so it's not CFM specific.

At first I noticed a minor problem in rate_estimator, but even with that fixed and seeing rates stable, buffer levels still deviate between the two input iodevs.

NOTE:
The following experiments are all done with the rate_estimator fix, plus disabling the coarse_rate_adjust mechanism in dev_stream.c, in order to better inspect buffer level in input device.

With a bunch more experiments, I've identified the best test case to trigger the problem:
 - Open two Jabra speakerphones, which uses 16Khz rate.
 - create input stream with buffer_frames:1024, cb_threshold:1024, frame_rate:48000

Note that currently cras_test_client always make cb_threshold *2 = buffer_frames, so we need code change before doing this experiment.

To observe this issue, grep in audio dump to look at how 'hw_level' grows:

   1143611.458979917  READ_AUDIO                     dev:7 hw_level:41 read:0
   1143611.458991723  READ_AUDIO                     dev:9 hw_level:0 read:0
   1143611.459044104  READ_AUDIO                     dev:7 hw_level:41 read:0
   1143611.459055930  READ_AUDIO                     dev:9 hw_level:0 read:0
   1143611.459102717  READ_AUDIO                     dev:7 hw_level:41 read:0
   1143611.459117405  READ_AUDIO                     dev:9 hw_level:16 read:3

...

   1143676.930030505  READ_AUDIO                     dev:7 hw_level:383 read:0
   1143676.930042476  READ_AUDIO                     dev:9 hw_level:0 read:0
   1143676.930083245  READ_AUDIO                     dev:7 hw_level:383 read:0
   1143676.930095041  READ_AUDIO                     dev:9 hw_level:0 read:0
   1143676.930135537  READ_AUDIO                     dev:7 hw_level:383 read:0
   1143676.930147401  READ_AUDIO                     dev:9 hw_level:0 read:0

in just a minutes, hw_level differs to 300 frames.
 
Labels: M-69
Got two CLs so far,

(1) https://chromium-review.googlesource.com/c/chromiumos/third_party/adhd/+/1131358
(2) https://chromium-review.googlesource.com/c/chromiumos/third_party/adhd/+/1134707

To clarify the purpose of each CL:
The frame leak problem fixed by the 1st CL was actually unveiled by my earlier CL:
https://chromium-review.googlesource.com/c/chromiumos/third_party/adhd/+/1126800
which fixed a infinite loop issue  crbug.com/860408 
The infinite loop bug seems living there since a lone time ago. But it needs some luck to be reproduced.

I believe the 2nd CL is the fix to the original problem reported by CFM team in b/110506794

We should merge them all for multiple Jabra use cases.

Blockedon: 860408
Cc: kotah@chromium.org
Labels: Proj-Hotrod Hotlist-Enterprise
Cc: cvintila@chromium.org
Project Member

Comment 5 by bugdroid1@chromium.org, Jul 13

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/adhd/+/8d4161c8e935c0e7eac8f69037e5e95113a74c09

commit 8d4161c8e935c0e7eac8f69037e5e95113a74c09
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Fri Jul 13 15:14:26 2018

CRAS: rate_estimator - Don't reset when input buffer is zero

Current behavior resets rate_estimator when seeing zero buffer
level in iodev. This makes sense to output because underrun is
a rarely happened error case so we reset rate_estimator hoping
to drop unreliable result. However we shouldn't do this for
input iodev, because:
(1) Input level==0 is a very common case and it's not error at
all.
(2) Bug is found that, when rate_estimator happens to return
estimated rate 15998 for 16KHz hardware. And unluckily in the
following many windows it hits level==0 and got reset, fmt_conv
will keep using this smaller rate(15998) to resample buffers
and cause buffer level deviate between multiple input iodev.

BUG= chromium:862047 
TEST=Run two Jabra recording, and verify buffer leve doesn't
deviate over long time.

Change-Id: Id8b979e609ccd998db9611a596294a056955f002
Reviewed-on: https://chromium-review.googlesource.com/1134707
Commit-Ready: Hsinyu Chao <hychao@chromium.org>
Tested-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Dylan Reid <dgreid@chromium.org>

[modify] https://crrev.com/8d4161c8e935c0e7eac8f69037e5e95113a74c09/cras/src/server/cras_iodev.c
[modify] https://crrev.com/8d4161c8e935c0e7eac8f69037e5e95113a74c09/cras/src/server/rate_estimator.c

Project Member

Comment 6 by bugdroid1@chromium.org, Jul 18

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/adhd/+/c62ac4d4c75684886b839c3bd9d00df817ea7c92

commit c62ac4d4c75684886b839c3bd9d00df817ea7c92
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Wed Jul 18 04:53:20 2018

CRAS: fmt_conv - Handle leaked frame

When input device opened in 16KHz then SRC to 48KHz, there's a
corner case in fmt_conv when converting 1 frame of data to 2
frames buffer.
The scenario is when linear resampler resamples 1 frame to 1
frame, and the speex library resamples 0 frame to 2 frames in
the 16KHz -> 48KHz round of SRC.

It is a bug that leaks one frame, because linear resampler processed
1 frame, but later SRC didn't consume it. This could get accumulated
and introduce large latency between multiple input iodevs.

Fixing this problem by specifically checking if the used input
frames in speex resampling is zero, and sets 0 frame as used
by fmt_conv.

BUG= chromium:862047 
TEST=Enable two Jabra devices, run
cras_test_client --capture_file /tmp/1 --rate 48000
and check the device buffer levels doesn't deviate.

Change-Id: Ia232a29464c8e3d99d09850b76f6209c44826cf4
Reviewed-on: https://chromium-review.googlesource.com/1131358
Commit-Ready: ChromeOS CL Exonerator Bot <chromiumos-cl-exonerator@appspot.gserviceaccount.com>
Tested-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Hsinyu Chao <hychao@chromium.org>

[modify] https://crrev.com/c62ac4d4c75684886b839c3bd9d00df817ea7c92/cras/src/tests/fmt_conv_unittest.cc
[modify] https://crrev.com/c62ac4d4c75684886b839c3bd9d00df817ea7c92/cras/src/server/cras_fmt_conv.c

Verified on 10888.0.0.

I have run the old and the new version with two jabras, and plotted the relative delay between the mic streams, as well as measured the delay in the mixed output stream using audacity.

The old version had a slow drift of the absolute delay between the mic streams, which occasionally went ballistic, which is when we heard the two streams overlap with the distinct "Echo" effect.

The new version keeps the delay bounded, and the delay is on the order of 6-16 ms. Marginally audible as a reverb, but not like the old "echo" effect.

Note: The graph for "after.png" has a glitch at 2pm, because I restarted the streams at that time.
Screenshot from 2018-07-19 13-23-23.png
35.2 KB View Download
after.png
18.6 KB View Download
Cc: bhthompson@chromium.org
Labels: M-68 Merge-Request-68
Thanks Mats for verifying this. Requesting R68 merge.
Project Member

Comment 9 by sheriffbot@chromium.org, Jul 20

Labels: -Merge-Request-68 Hotlist-Merge-Review Merge-Review-68
This bug requires manual review: We are only 3 days from stable.
Please contact the milestone owner if you have questions.
Owners: cmasso@(Android), kariahda@(iOS), bhthompson@(ChromeOS), abdulsyed@(Desktop)

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
As a justification: Affecting customers. More background in b/110506794 (google internal).
Labels: -Hotlist-Merge-Review -Merge-Review-68 Merge-Approved-68
Project Member

Comment 12 by bugdroid1@chromium.org, Jul 22

Labels: merge-merged-release-R68-10718.B
The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/adhd/+/5c2525d3f7b232b15bb23933e95110c285669c4a

commit 5c2525d3f7b232b15bb23933e95110c285669c4a
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Sun Jul 22 15:33:29 2018

CRAS: rate_estimator - Don't reset when input buffer is zero

Current behavior resets rate_estimator when seeing zero buffer
level in iodev. This makes sense to output because underrun is
a rarely happened error case so we reset rate_estimator hoping
to drop unreliable result. However we shouldn't do this for
input iodev, because:
(1) Input level==0 is a very common case and it's not error at
all.
(2) Bug is found that, when rate_estimator happens to return
estimated rate 15998 for 16KHz hardware. And unluckily in the
following many windows it hits level==0 and got reset, fmt_conv
will keep using this smaller rate(15998) to resample buffers
and cause buffer level deviate between multiple input iodev.

BUG= chromium:862047 
TEST=Run two Jabra recording, and verify buffer leve doesn't
deviate over long time.

Change-Id: Id8b979e609ccd998db9611a596294a056955f002
Reviewed-on: https://chromium-review.googlesource.com/1134707
Commit-Ready: Hsinyu Chao <hychao@chromium.org>
Tested-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Dylan Reid <dgreid@chromium.org>
(cherry picked from commit 8d4161c8e935c0e7eac8f69037e5e95113a74c09)
Reviewed-on: https://chromium-review.googlesource.com/1146340
Reviewed-by: Hsinyu Chao <hychao@chromium.org>
Commit-Queue: Hsinyu Chao <hychao@chromium.org>

[modify] https://crrev.com/5c2525d3f7b232b15bb23933e95110c285669c4a/cras/src/server/cras_iodev.c
[modify] https://crrev.com/5c2525d3f7b232b15bb23933e95110c285669c4a/cras/src/server/rate_estimator.c

Project Member

Comment 13 by bugdroid1@chromium.org, Jul 22

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/adhd/+/8e0b2e003b2bbc6e9889322cf962c6fb436e9873

commit 8e0b2e003b2bbc6e9889322cf962c6fb436e9873
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Sun Jul 22 15:43:01 2018

CRAS: fmt_conv - Handle leaked frame

When input device opened in 16KHz then SRC to 48KHz, there's a
corner case in fmt_conv when converting 1 frame of data to 2
frames buffer.
The scenario is when linear resampler resamples 1 frame to 1
frame, and the speex library resamples 0 frame to 2 frames in
the 16KHz -> 48KHz round of SRC.

It is a bug that leaks one frame, because linear resampler processed
1 frame, but later SRC didn't consume it. This could get accumulated
and introduce large latency between multiple input iodevs.

Fixing this problem by specifically checking if the used input
frames in speex resampling is zero, and sets 0 frame as used
by fmt_conv.

BUG= chromium:862047 
TEST=Enable two Jabra devices, run
cras_test_client --capture_file /tmp/1 --rate 48000
and check the device buffer levels doesn't deviate.

Change-Id: Ia232a29464c8e3d99d09850b76f6209c44826cf4
Reviewed-on: https://chromium-review.googlesource.com/1131358
Commit-Ready: ChromeOS CL Exonerator Bot <chromiumos-cl-exonerator@appspot.gserviceaccount.com>
Tested-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Hsinyu Chao <hychao@chromium.org>
(cherry picked from commit c62ac4d4c75684886b839c3bd9d00df817ea7c92)
Reviewed-on: https://chromium-review.googlesource.com/1146342
Commit-Queue: Hsinyu Chao <hychao@chromium.org>

[modify] https://crrev.com/8e0b2e003b2bbc6e9889322cf962c6fb436e9873/cras/src/tests/fmt_conv_unittest.cc
[modify] https://crrev.com/8e0b2e003b2bbc6e9889322cf962c6fb436e9873/cras/src/server/cras_fmt_conv.c

Labels: -Merge-Approved-68 Merge-Merged
Status: Fixed (was: Started)

Sign in to add a comment