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

Issue 623868 link

Starred by 3 users

Issue metadata

Status: Verified
Owner:
Closed: Oct 2016
Cc:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug

Blocking:
issue 568236
issue 569010
issue 588070
issue 626036



Sign in to add a comment

CRAS: super high buffer level

Project Member Reported by hychao@chromium.org, Jun 28 2016

Issue description

This is observed on below devices:
- Modi 2 DAC
- logitech g930

So creating this bug to track the investigation of this common problem.
According to their original bugs and attached audio dump, the output buffer stays at rather high level causing audio delay and pausing/skipping, but the root cause is still unclear.

Note that I haven't reproduce this on my existing USB headset/DACs. Still need to catch more log while transitioning from normal delay to high delay.
 
logitech-g930-audio-dump.txt
507 KB View Download
Haven't been able to reproduce the problem on both the USB devices.
One thing I noticed is the rate estimator in CRAS reports the actual sample rate has gone up to 48K * 1.000019, but CRAS does good job on keeping the buffer level. 
Will need more experiment.
Blocking: 569010

Comment 3 by hychao@chromium.org, Jul 15 2016

Blocking: 626036
Cc: dgreid@chromium.org
Status: Started (was: Assigned)
Summary: CRAS: super high buffer level (was: CRAS: super high buffer level when using USB audio)
 Issue 626036  helps me find out the usage pattern to trigger this issue. Attached a script which can reproduce easily, on any output type. 

To observe this problem, I can use "cras_test_client --dump_a | grep SET_DEV_WAKE | head -n 30" and watch the hw_level number increases in a few seconds.
cras_stream_stress.py
489 bytes View Download

Comment 4 by hychao@chromium.org, Jul 15 2016

I uploaded a patch to fix the problem:
https://chromium-review.googlesource.com/360880 CRAS: audio_thread - Align stream fetch tim

also wrote a test to simulate the usage pattern, can be used to verify my fix:
https://chromium-review.googlesource.com/360785 Add audio_CrasOutputStress test

Project Member

Comment 5 by bugdroid1@chromium.org, Jul 21 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/autotest/+/62bf1f449b0c4a5f2d1c9e6a357f362ca4df5f48

commit 62bf1f449b0c4a5f2d1c9e6a357f362ca4df5f48
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Fri Jul 15 13:59:19 2016

Add audio_CrasOutputStress test

This test repeatedly add output streams of random sample rate
and block size and remove them to check if output buffer would
drift to unreasonable high level.

BUG= chromium:623868 
TEST=Run audio_CrasOutputStress on Pixel.

Change-Id: I7acc944d35853e132c69d37dd975e4aa0b173aa2
Reviewed-on: https://chromium-review.googlesource.com/360785
Commit-Ready: Hsinyu Chao <hychao@chromium.org>
Tested-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Cheng-Yi Chiang <cychiang@chromium.org>

[add] https://crrev.com/62bf1f449b0c4a5f2d1c9e6a357f362ca4df5f48/client/site_tests/audio_CrasOutputStress/audio_CrasOutputStress.py
[add] https://crrev.com/62bf1f449b0c4a5f2d1c9e6a357f362ca4df5f48/client/site_tests/audio_CrasOutputStress/control

Project Member

Comment 6 by bugdroid1@chromium.org, Jul 21 2016

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

commit 3089a1acfbc21b35a548ec5bb2a45ed1bf87923a
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Wed Jul 13 12:33:49 2016

CRAS: audio_thread - Align stream fetch time

A usage pattern is found to make output buffer drift crazily high.
While output device running with stream A, the buffer level is
expected to stay in range [X, X + d1]. Suppose the new stream B is
connected when output buffer at level X + d' and stream A is
immediately removed, the output buffer will change to stay in
[X + d', x + d' + d2].
The root cause is that when a new stream is added when output device
is already running, its fetch time isn't aligned with any of the
existing stream, so the above scenario is very likely to happen.

BUG= chromium:623868 
TEST=Use audio_CrasOutputStress test to verify the problem is fixed.

Change-Id: I071c76ea647a587fb7bd6e8361eedf1029474fc8
Reviewed-on: https://chromium-review.googlesource.com/360880
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/3089a1acfbc21b35a548ec5bb2a45ed1bf87923a/cras/src/server/dev_stream.c
[modify] https://crrev.com/3089a1acfbc21b35a548ec5bb2a45ed1bf87923a/cras/src/server/dev_stream.h
[modify] https://crrev.com/3089a1acfbc21b35a548ec5bb2a45ed1bf87923a/cras/src/server/audio_thread.c
[modify] https://crrev.com/3089a1acfbc21b35a548ec5bb2a45ed1bf87923a/cras/src/tests/audio_thread_unittest.cc
[modify] https://crrev.com/3089a1acfbc21b35a548ec5bb2a45ed1bf87923a/cras/src/tests/dev_stream_unittest.cc

Comment 7 by hychao@chromium.org, Jul 22 2016

Cc: keta...@chromium.org
Labels: Merge-Request-53 OS-Chrome
Request merge to 53 we we can solve many other bugs finally.

Comment 8 by dimu@google.com, Jul 22 2016

Labels: -Merge-Request-53 Merge-Approved-53 Hotlist-Merge-Approved
Your change meets the bar and is auto-approved for M53 (branch: 2785)
Project Member

Comment 9 by bugdroid1@chromium.org, Jul 25 2016

Labels: merge-merged-release-R53-8530.B
The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/autotest/+/0c63b87a26e09083b5a562319e9f2c293ae143d4

commit 0c63b87a26e09083b5a562319e9f2c293ae143d4
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Fri Jul 15 13:59:19 2016

Add audio_CrasOutputStress test

This test repeatedly add output streams of random sample rate
and block size and remove them to check if output buffer would
drift to unreasonable high level.

BUG= chromium:623868 
TEST=Run audio_CrasOutputStress on Pixel.

Change-Id: I7acc944d35853e132c69d37dd975e4aa0b173aa2
Reviewed-on: https://chromium-review.googlesource.com/360785
Commit-Ready: Hsinyu Chao <hychao@chromium.org>
Tested-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Cheng-Yi Chiang <cychiang@chromium.org>
(cherry picked from commit 62bf1f449b0c4a5f2d1c9e6a357f362ca4df5f48)
Reviewed-on: https://chromium-review.googlesource.com/362795
Reviewed-by: Hsinyu Chao <hychao@chromium.org>
Commit-Queue: Hsinyu Chao <hychao@chromium.org>

[add] https://crrev.com/0c63b87a26e09083b5a562319e9f2c293ae143d4/client/site_tests/audio_CrasOutputStress/audio_CrasOutputStress.py
[add] https://crrev.com/0c63b87a26e09083b5a562319e9f2c293ae143d4/client/site_tests/audio_CrasOutputStress/control

note:
autotest ebuild change is also needed for R53
https://chromium-review.googlesource.com/#/c/362260/
Is this needed in M53 CROS?
Yes it is. We got lots of reports for this as you can see from the blocking issue list.
I have merged the autotest to R53 and watching it to run https://wmatrix.googleplex.com/matrix/unfiltered?hide_missing=True&tests=audio_CrasOutputStress&days_back=20&releases=53

After see it started running and failing, I'll merge the fix to R53.
Project Member

Comment 13 by sheriffbot@chromium.org, Jul 26 2016

This issue has been approved for a merge. Please merge the fix to any appropriate branches as soon as possible!

If all merges have been completed, please remove any remaining Merge-Approved labels from this issue.

Thanks for your time! To disable nags, add the Disable-Nags label.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
Project Member

Comment 14 by bugdroid1@chromium.org, Jul 27 2016

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

commit d4d0ce64f1173f76d54675a388b2439123dc8640
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Wed Jul 13 12:33:49 2016

CRAS: audio_thread - Align stream fetch time

A usage pattern is found to make output buffer drift crazily high.
While output device running with stream A, the buffer level is
expected to stay in range [X, X + d1]. Suppose the new stream B is
connected when output buffer at level X + d' and stream A is
immediately removed, the output buffer will change to stay in
[X + d', x + d' + d2].
The root cause is that when a new stream is added when output device
is already running, its fetch time isn't aligned with any of the
existing stream, so the above scenario is very likely to happen.

BUG= chromium:623868 
TEST=Use audio_CrasOutputStress test to verify the problem is fixed.

Change-Id: I071c76ea647a587fb7bd6e8361eedf1029474fc8
Reviewed-on: https://chromium-review.googlesource.com/360880
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 3089a1acfbc21b35a548ec5bb2a45ed1bf87923a)
Reviewed-on: https://chromium-review.googlesource.com/363713
Reviewed-by: Hsinyu Chao <hychao@chromium.org>
Commit-Queue: Hsinyu Chao <hychao@chromium.org>

[modify] https://crrev.com/d4d0ce64f1173f76d54675a388b2439123dc8640/cras/src/server/dev_stream.c
[modify] https://crrev.com/d4d0ce64f1173f76d54675a388b2439123dc8640/cras/src/server/dev_stream.h
[modify] https://crrev.com/d4d0ce64f1173f76d54675a388b2439123dc8640/cras/src/server/audio_thread.c
[modify] https://crrev.com/d4d0ce64f1173f76d54675a388b2439123dc8640/cras/src/tests/audio_thread_unittest.cc
[modify] https://crrev.com/d4d0ce64f1173f76d54675a388b2439123dc8640/cras/src/tests/dev_stream_unittest.cc

Labels: -Merge-Approved-53
Status: Fixed (was: Started)
Labels: VerifyIn-54

Comment 17 by son...@google.com, Oct 3 2016

Status: Assigned (was: Fixed)
Still tests are failing with "'Buffer level %d drift too high', 65536"

https://wmatrix.googleplex.com/failures/unfiltered?hide_missing=True&tests=audio_CrasOutputStress&releases=tot&platforms=samus&days_back=30
I can constantly reproduce on Samus. After bisect, I found the cause is below commit in CRAS:

commit 50cf4aec95391fb7768d9a98e35e618edc7443f3
Author: Cheng-Yi Chiang <cychiang@chromium.org>
Date:   Tue Jul 26 17:28:00 2016 +0800

    CRAS: iodev - Add state variable in cras_iodev

But it does not affecting Peppy.

Labels: M-55
https://chromium-review.googlesource.com/#/c/394457/ is the fix.
https://bugs.chromium.org/p/chromium/issues/detail?id=654614 seems to be related.
Also need to merge to R55.
Project Member

Comment 20 by bugdroid1@chromium.org, Oct 11 2016

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

commit 08f6e5054416273cfa19ab12b8b17c9207eb55b3
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Fri Oct 07 07:43:47 2016

CRAS: iodev - Fix no stream playback state transition

When the last output stream is removed, iodev transits to the
NO_STREAM_RUN state if it was in NORMAL_RUN state. However
this iodev may not started yet if the output stream was added
and then removed right away.
This bug causes failure for test audio_CrasOutputStress on Samus
because its internal speaker open could take 150 ms long so
that the 1st short life stream has destroyed already. And the
incorrect state change causes the iodev never started, hence its
buffer level accumulates to 65535.

BUG= chromium:623868 
TEST=test_that -b samus audio_CrasOutputStress should pass

Change-Id: Iba282e1f09a3b611cd1d4c4021667fd91d8a2781
Reviewed-on: https://chromium-review.googlesource.com/394457
Commit-Ready: Cheng-Yi Chiang <cychiang@chromium.org>
Tested-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Dylan Reid <dgreid@chromium.org>

[modify] https://crrev.com/08f6e5054416273cfa19ab12b8b17c9207eb55b3/cras/src/server/cras_iodev.c

Labels: -Hotlist-Merge-Approved -merge-merged-release-R53-8530.B -VerifyIn-54 Merge-Request-55
Status: Started (was: Assigned)
Request merge the CO from #20 to M55
Labels: -Pri-3 Pri-1

Comment 23 by dimu@chromium.org, Oct 12 2016

Labels: -Merge-Request-55 Merge-Approved-55 Hotlist-Merge-Approved
Your change meets the bar and is auto-approved for M55 (branch: 2883)
Project Member

Comment 24 by bugdroid1@chromium.org, Oct 13 2016

Labels: merge-merged-release-R55-8872.B
The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/adhd/+/6b16c791599b1c4c75babbb8868131bcfaa7443f

commit 6b16c791599b1c4c75babbb8868131bcfaa7443f
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Fri Oct 07 07:43:47 2016

CRAS: iodev - Fix no stream playback state transition

When the last output stream is removed, iodev transits to the
NO_STREAM_RUN state if it was in NORMAL_RUN state. However
this iodev may not started yet if the output stream was added
and then removed right away.
This bug causes failure for test audio_CrasOutputStress on Samus
because its internal speaker open could take 150 ms long so
that the 1st short life stream has destroyed already. And the
incorrect state change causes the iodev never started, hence its
buffer level accumulates to 65535.

BUG= chromium:623868 
TEST=test_that -b samus audio_CrasOutputStress should pass

Change-Id: Iba282e1f09a3b611cd1d4c4021667fd91d8a2781
Reviewed-on: https://chromium-review.googlesource.com/394457
Commit-Ready: Cheng-Yi Chiang <cychiang@chromium.org>
Tested-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Dylan Reid <dgreid@chromium.org>
(cherry picked from commit 08f6e5054416273cfa19ab12b8b17c9207eb55b3)
Reviewed-on: https://chromium-review.googlesource.com/397032
Commit-Queue: Hsinyu Chao <hychao@chromium.org>

[modify] https://crrev.com/6b16c791599b1c4c75babbb8868131bcfaa7443f/cras/src/server/cras_iodev.c

Status: Fixed (was: Started)
Project Member

Comment 26 by sheriffbot@chromium.org, Oct 16 2016

This issue has been approved for a merge. Please merge the fix to any appropriate branches as soon as possible!

If all merges have been completed, please remove any remaining Merge-Approved labels from this issue.

Thanks for your time! To disable nags, add the Disable-Nags label.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
Labels: -Merge-Approved-55

Comment 28 by dchan@google.com, Apr 17 2017

Labels: VerifyIn-59

Comment 29 by dchan@google.com, May 30 2017

Labels: VerifyIn-60
Status: Verified (was: Fixed)
Verified in Chrome OS 9667.0.0, 61.0.3130.0.

Sign in to add a comment