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

Issue 635426 link

Starred by 1 user

Issue metadata

Status: Verified
Owner:
Closed: Dec 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

CRAS: audio underrun when using BT headset

Project Member Reported by hychao@chromium.org, Aug 8 2016

Issue description

Chrome: 52.0.2743.85
CrOS:  8350.60.0

https://feedback.corp.google.com/product/208/neutron?lView=rd&lReport=14985445400

     10087.342876089  A2DP_ENCODE                    proc:0 queued:3304 readable:3304
     10087.342880558  A2DP_WRITE                     written:-11 queued:896
     10087.342894745  FILL_AUDIO                     dev:b hw_level:0
     10087.342899431  WRITE_STREAMS_STREAM           id:f00001 shm_frames:0 cb_pending:0
     10087.342899555  WRITE_STREAMS_MIX              write_limit:0 max_offset:0
     10087.342899962  WRITE_STREAMS_MIXED            write_limit:0
     10087.342906740  A2DP_ENCODE                    proc:0 queued:3304 readable:3304
     10087.342910026  A2DP_WRITE                     written:-11 queued:896
     10087.342918614  A2DP_ENCODE                    proc:0 queued:7764 readable:7764
     10087.342922525  A2DP_WRITE                     written:-11 queued:896
     10087.342922673  FILL_AUDIO_DONE                hw_level:0 total_written:0 min_cb_level:1115     <--- buffer level drop to zero
     10087.342925005  STREAM_SLEEP_TIME              id:f00001 wake:000010087.344041020
     10087.342925954  SET_DEV_WAKE                   dev:b hw_level:1045 sleep:1045
     10087.342926231  DEV_SLEEP_TIME                 dev:b wake:000010087.364696176
     10087.342927438  SLEEP                          sleep:000000000.001116952 longest_wake:002519883
     10087.344093730  WAKE                           num_fds:0
     10087.344098720  WRITE_STREAMS_FETCH_STREAM     id:f00001 cbth:1024 delay:4629

 
Components: OS>Systems>Bluetooth

Comment 2 by hychao@chromium.org, Nov 16 2016

Status: Started (was: Assigned)
From:
10087.342906740  A2DP_ENCODE                    proc:0 queued:3304 readable:3304
to:
10087.342918614  A2DP_ENCODE                    proc:0 queued:7764 readable:7764

the PCM buffer has increased (7764 - 3304)/4 = 1115 frames, but the 'total_written' was reported zero, clearly there's a bug somewhere.
And That's where CRAS think it's underrun so fills a bunch of zeros causing audio drop out.

Comment 3 by hychao@chromium.org, Nov 17 2016

What I said in #2 is false alarm, the additional PCM buffer are zero frames filled because or underrun.
The actual problem is in the logs a little bit earlier:

     10087.342723164  WAKE                           num_fds:1
     10087.342724928  IODEV_CB                       is_write:1
     10087.342733802  A2DP_ENCODE                    proc:0 queued:10472 readable:7168
     10087.342755598  A2DP_WRITE                     written:846 queued:0
     10087.342821100  A2DP_ENCODE                    proc:3584 queued:10472 readable:7168
     10087.342821526  A2DP_ENCODE                    proc:0 queued:6888 readable:3584
     10087.342832306  A2DP_WRITE                     written:846 queued:0
     10087.342874799  A2DP_ENCODE                    proc:3584 queued:6888 readable:3584
     10087.342876089  A2DP_ENCODE                    proc:0 queued:3304 readable:3304
     10087.342880558  A2DP_WRITE                     written:-11 queued:896
     10087.342894745  FILL_AUDIO                     dev:b hw_level:0

In this IODEV_CB, we encode & flush too many frames(twice) at one time so buffer level drops below min_callback_level(= 1792 frames) and that causes audio thread to add silent frames trying to raise buffer level.

Uploaded a fix to https://chromium-review.googlesource.com/411647
Note that the CL fixes the special case to avoid A2DP dev enters underrun by itself. It's difficult to see from the log why this headset shows a slower rate(0.009978988 * 48K) but suddenly consumes large amount of data.
Project Member

Comment 4 by bugdroid1@chromium.org, Nov 23 2016

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

commit 40ec4b17c945adab7667121f50eedc57448c4eff
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Thu Nov 17 09:16:27 2016

CRAS: a2dp - Don't flush too much when buffer level is low

The original strategy of flush_data() function is to encode PCM
buffer to SBC format blocks whenever there's data and try writing the
encoded data to A2DP socket.  This could consume too much PCM buffer
in one callback to cause buffer level drops below min_buffer_level so
audio thread thinks it underruns.

BUG= chromium:635426 
TEST=unittest

Change-Id: I2f294a397868132b8810edb4a91a98f269376212
Reviewed-on: https://chromium-review.googlesource.com/411647
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/40ec4b17c945adab7667121f50eedc57448c4eff/cras/src/server/cras_a2dp_iodev.c
[modify] https://crrev.com/40ec4b17c945adab7667121f50eedc57448c4eff/cras/src/server/cras_a2dp_info.h
[modify] https://crrev.com/40ec4b17c945adab7667121f50eedc57448c4eff/cras/src/server/cras_a2dp_info.c
[modify] https://crrev.com/40ec4b17c945adab7667121f50eedc57448c4eff/cras/src/tests/a2dp_iodev_unittest.cc

Labels: M-56 Merge-Request-56
Request merge to M56. Hopefully this will alleviate the underrun.

Comment 6 by dimu@chromium.org, Dec 2 2016

Labels: -Merge-Request-56 Merge-Approved-56 Hotlist-Merge-Approved
Your change meets the bar and is auto-approved for M56 (branch: 2924)
Project Member

Comment 7 by bugdroid1@chromium.org, Dec 5 2016

Labels: merge-merged-release-R56-9000.B
The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/adhd/+/9ff07dd04343028d525c504f349a7ef18ab3a800

commit 9ff07dd04343028d525c504f349a7ef18ab3a800
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Thu Nov 17 09:16:27 2016

CRAS: a2dp - Don't flush too much when buffer level is low

The original strategy of flush_data() function is to encode PCM
buffer to SBC format blocks whenever there's data and try writing the
encoded data to A2DP socket.  This could consume too much PCM buffer
in one callback to cause buffer level drops below min_buffer_level so
audio thread thinks it underruns.

BUG= chromium:635426 
TEST=unittest

Change-Id: I2f294a397868132b8810edb4a91a98f269376212
Reviewed-on: https://chromium-review.googlesource.com/411647
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 40ec4b17c945adab7667121f50eedc57448c4eff)
Reviewed-on: https://chromium-review.googlesource.com/415853
Reviewed-by: Hsinyu Chao <hychao@chromium.org>
Commit-Queue: Hsinyu Chao <hychao@chromium.org>

[modify] https://crrev.com/9ff07dd04343028d525c504f349a7ef18ab3a800/cras/src/server/cras_a2dp_iodev.c
[modify] https://crrev.com/9ff07dd04343028d525c504f349a7ef18ab3a800/cras/src/server/cras_a2dp_info.h
[modify] https://crrev.com/9ff07dd04343028d525c504f349a7ef18ab3a800/cras/src/server/cras_a2dp_info.c
[modify] https://crrev.com/9ff07dd04343028d525c504f349a7ef18ab3a800/cras/src/tests/a2dp_iodev_unittest.cc

Status: Fixed (was: Started)
Project Member

Comment 9 by sheriffbot@chromium.org, Dec 5 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 10 by sheriffbot@chromium.org, Dec 8 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: -Hotlist-Merge-Approved -Merge-Approved-56
Status: Verified (was: Fixed)

Sign in to add a comment