Issue metadata
Sign in to add a comment
|
HSP only headset automatically disconnects from the chromebook |
||||||||||||||||||||||
Issue description
Version: 8743.25.0
OS: chrome
What steps will reproduce the problem?
(1)Connect a HSP only headset (samsung HM1200 and Bluedio T9+ headsets )
(2)leave it connected
What is the expected output?
The headset should stay connected
What do you see instead?
The headset disconnects after about 10 seconds
Please use labels and text to provide additional information.
The same thing things happens if we play music through the headphones. This happens across multiple Chromebooks
This was working fine before .
Hychao@ -- may be regression due to recent CRAS changes?
Below is the log snippet ftom the btmon messages
> HCI Event: Disconnect Complete (0x05) plen 4 [hci0] 26.785499
Status: Success (0x00)
Handle: 257
Reason: Connection Terminated By Local Host (0x16)
> SCO Data RX: Handle 257 flags 0x00 dlen 48 [hci0] 26.786484
> SCO Data RX: Handle 257 flags 0x00 dlen 48 [hci0] 26.786504
> SCO Data RX: Handle 257 flags 0x00 dlen 48 [hci0] 26.786508
< ACL Data TX: Handle 256 flags 0x00 dlen 8 [hci0] 51.618670
Channel: 72 len 4 [PSM 0 mode 0] {chan 0}
0b 53 01 b8 .S..
< HCI Command: Exit Sniff Mode (0x02|0x0004) plen 2 [hci0] 51.618705
Handle: 256
< ACL Data TX: Handle 256 flags 0x00 dlen 8 [hci0] 51.618716
Channel: 72 len 4 [PSM 0 mode 0] {chan 0}
1b 53 01 32 .S.2
> HCI Event: Command Status (0x0f) plen 4 [hci0] 51.781420
Exit Sniff Mode (0x02|0x0004) ncmd 1
Status: Success (0x00)
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 51.783424
Num handles: 1
Handle: 256
Count: 1
> ACL Data RX: Handle 256 flags 0x02 dlen 8 [hci0] 51.785481
Channel: 65 len 4 [PSM 0 mode 0] {chan 0}
0b 73 01 92 .s..
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 51.786426
Num handles: 1
Handle: 256
Count: 1
> HCI Event: Mode Change (0x14) plen 6 [hci0] 51.787442
Status: Success (0x00)
Handle: 256
Mode: Active (0x00)
Interval: 0.000 msec (0x0000)
> ACL Data RX: Handle 256 flags 0x02 dlen 8 [hci0] 51.787953
Channel: 65 len 4 [PSM 0 mode 0] {chan 0}
1b 73 01 18 .s..
< ACL Data TX: Handle 256 flags 0x00 dlen 8 [hci0] 51.788016
Channel: 72 len 4 [PSM 0 mode 0] {chan 0}
03 53 01 fd .S..
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 51.792426
Num handles: 1
Handle: 256
Count: 1
> ACL Data RX: Handle 256 flags 0x02 dlen 8 [hci0] 51.862973
Channel: 65 len 4 [PSM 0 mode 0] {chan 0}
03 73 01 d7 .s..
< ACL Data TX: Handle 256 flags 0x00 dlen 12 [hci0] 51.863177
L2CAP: Disconnection Request (0x06) ident 8 len 4
Destination CID: 72
Source CID: 65
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 51.867430
Num handles: 1
Handle: 256
Count: 1
> ACL Data RX: Handle 256 flags 0x02 dlen 12 [hci0] 51.869430
L2CAP: Disconnection Response (0x07) ident 8 len 4
Destination CID: 72
Source CID: 65
< HCI Command: Read Clock Offset (0x01|0x001f) plen 2 [hci0] 53.386444
Handle: 256
> HCI Event: Command Status (0x0f) plen 4 [hci0] 53.387425
Read Clock Offset (0x01|0x001f) ncmd 1
Status: Success (0x00)
< HCI Command: Disconnect (0x01|0x0006) plen 3 [hci0] 53.387481
Handle: 256
Reason: Remote User Terminated Connection (0x13)
> HCI Event: Command Status (0x0f) plen 4 [hci0] 53.388420
Disconnect (0x01|0x0006) ncmd 1
Status: Success (0x00)
> HCI Event: Read Clock Offset Complete (0x1c) plen 5 [hci0] 53.392427
Status: Success (0x00)
Handle: 256
Clock offset: 0x3aee
> HCI Event: Disconnect Complete (0x05) plen 4 [hci0] 53.472448
Status: Success (0x00)
Handle: 256
Reason: Connection Terminated By Local Host (0x16)
@ Device Disconnected: 50:F5:20:8A:D3:D9 (0) reason 2
,
Sep 16 2016
Yes this might be related to the series of change in CRAS https://chromium-review.googlesource.com/#/c/377847/ Can I borrow one such headset from you ? Also, how often can this be reproduced ? Thanks!
,
Sep 17 2016
I am pretty sure this has something to do with the recent changes. The error message cras_server[19235]: Connection watch timeout. was added in https://chromium-review.googlesource.com/377845. 2016-09-17T15:27:48.577671-07:00 INFO chrom[10896]: --enable-logging --gpu-sandbox-failures-fatal=yes --gpu-sandbox-start-early --num-raster-threads=1 --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=23.0.0.162-r1 --ui-prioritize-in-gpu-process --use-cras --use-gl=egl --user-data-dir=/home/chronos --vmodule=screen_locker=2,webui_screen_locker=2,lock_state_controller=2,webui_login_view=2,power_button_observer=2,*ui/display/chromeos*=1,*ash/display*=1,*ui/ozone*=1,*zygote*=1,*plugin*=2,*chromeos/login/*=1,*arc/*=1 --enable-centered-app-list --enable-touchview --ash-enable-palette --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/oem_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/oem_small.jpg --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --arc-available --enable-arc --login-profile=user --system-developer-mode --bwsi --homepage=chrome://newtab/ --incognito --log-level=1 --login-user=$guest --login-user=$guest --login-profile=e6da2e81942b94c2844d2aa96a02dd3d3eefc0d9: set rlimit success 2016-09-17T15:27:52.864657-07:00 DEBUG bluetoothd[2176]: src/device.c:connect_profiles() /org/bluez/hci0/dev_50_F5_20_8A_D3_D9 0000111e-0000-1000-8000-00805f9b34fb, client :1.56 2016-09-17T15:28:21.185711-07:00 DEBUG bluetoothd[2176]: last message repeated 4 times 2016-09-17T15:28:21.185242-07:00 ERR shill[1624]: [ERROR:wifi.cc(2499)] Scan time unreliable 2016-09-17T15:28:22.896293-07:00 DEBUG bluetoothd[2176]: src/device.c:connect_profiles() /org/bluez/hci0/dev_50_F5_20_8A_D3_D9 0000111e-0000-1000-8000-00805f9b34fb, client :1.56 2016-09-17T15:28:26.125900-07:00 NOTICE /usr/sbin/chromeos-trim[19357]: /mnt/stateful_partition fully trimmed in 993 seconds 2016-09-17T15:28:26.140162-07:00 INFO periodic_scheduler[19359]: trim: job completed 2016-09-17T15:28:28.902612-07:00 DEBUG bluetoothd[2176]: src/device.c:connect_profiles() /org/bluez/hci0/dev_50_F5_20_8A_D3_D9 0000111e-0000-1000-8000-00805f9b34fb, client :1.56 2016-09-17T15:28:34.908932-07:00 DEBUG bluetoothd[2176]: src/device.c:connect_profiles() /org/bluez/hci0/dev_50_F5_20_8A_D3_D9 0000111e-0000-1000-8000-00805f9b34fb, client :1.56 2016-09-17T15:28:38.912023-07:00 ERR cras_server[19235]: Connection watch timeout. 2016-09-17T15:28:38.914222-07:00 DEBUG bluetoothd[2176]: src/service.c:change_state() 0xab4da7e0: device 50:F5:20:8A:D3:D9 profile Hands-Free Voice gateway state changed: connected -> disconnecting (0) 2016-09-17T15:28:38.914347-07:00 DEBUG bluetoothd[2176]: src/service.c:change_state() 0xab4d6e20: device 50:F5:20:8A:D3:D9 profile Headset Voice gateway state changed: connected -> disconnecting (0) 2016-09-17T15:28:38.923712-07:00 DEBUG bluetoothd[2176]: src/service.c:change_state() 0xab4da7e0: device 50:F5:20:8A:D3:D9 profile Hands-Free Voice gateway state changed: disconnecting -> disconnected (0) 2016-09-17T15:28:38.923830-07:00 DEBUG bluetoothd[2176]: src/service.c:btd_service_unref() 0xab4da7e0: ref=2
,
Sep 17 2016
Hi pbathini@, could you test if this starts from 8743.20.0 ? https://crosland.corp.google.com/log/8743.19.0..8743.20.0 Shows the 6 CLs were added starting at that version. I will check next week if we can find a quick solution, otherwise we need to revert on R54. Thanks!
,
Sep 19 2016
I checked on 8743.18.0 build on samus and the HSP headset was working fine. On 8743.20.0 build on same samus , I can see the disconnect issue. The problem started from 8743.20.0 build
,
Sep 20 2016
Thank you for the testing. I will debug today.
,
Sep 20 2016
,
Sep 20 2016
Great! With Miao's help we have found the root cause. I will submit the fix shortly.
,
Sep 20 2016
https://chromium-review.googlesource.com/386603 should fix this.
,
Sep 21 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/third_party/adhd/+/dab3c96c7ea42a321f1ef60034a76ae435af5270 commit dab3c96c7ea42a321f1ef60034a76ae435af5270 Author: Cheng-Yi Chiang <cychiang@chromium.org> Date: Tue Sep 20 08:31:27 2016 CRAS: hfp_ag_profile - Start audio gateway in bt device On HFP/HSP only headset, cras_hfp_ag_start is called in cras_hfp_ag_slc_initialized when SetConfiguration is called from bluez. However, that does not mark HFP/HSP as connected, and cause connection watcher to fail after timeout because it thinks HFP/HSP is still not connected. Move cras_hfp_ag_start from cras_hfp_ag_slc_initialized to cras_bt_device_audio_gateway_initialized to unify the path to start audio gateway. With that, the HFP/HSP will be mark as connected and connection watcher will not fail. BUG= chromium:647468 TEST=Test with HM1100 (HFP only device), connection is not lost. TEST=Test with IKBT74 (A2DP and HFP), playback and record both work. Change-Id: I45029c2a9ab855bbf27bdd950fe5dc779b74fef8 Signed-off-by: Cheng-Yi Chiang <cychiang@chromium.org> Reviewed-on: https://chromium-review.googlesource.com/386603 Reviewed-by: Chinyue Chen <chinyue@chromium.org> Reviewed-by: Dylan Reid <dgreid@chromium.org> [modify] https://crrev.com/dab3c96c7ea42a321f1ef60034a76ae435af5270/cras/src/server/cras_bt_device.c [modify] https://crrev.com/dab3c96c7ea42a321f1ef60034a76ae435af5270/cras/src/server/cras_bt_device.h [modify] https://crrev.com/dab3c96c7ea42a321f1ef60034a76ae435af5270/cras/src/server/cras_hfp_ag_profile.c
,
Sep 22 2016
We need to merge CL in #10 to R54 for all HSP-only headset. Thanks!
,
Sep 22 2016
Your change meets the bar and is auto-approved for M54 (branch: 2840)
,
Sep 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
,
Sep 28 2016
https://chromium-review.googlesource.com/#/c/390591/1 was merged.
,
Sep 28 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/third_party/adhd/+/c94fca3b14f3472ced77b1bd7646b4aba5062577 commit c94fca3b14f3472ced77b1bd7646b4aba5062577 Author: Cheng-Yi Chiang <cychiang@chromium.org> Date: Tue Sep 20 08:31:27 2016 CRAS: hfp_ag_profile - Start audio gateway in bt device On HFP/HSP only headset, cras_hfp_ag_start is called in cras_hfp_ag_slc_initialized when SetConfiguration is called from bluez. However, that does not mark HFP/HSP as connected, and cause connection watcher to fail after timeout because it thinks HFP/HSP is still not connected. Move cras_hfp_ag_start from cras_hfp_ag_slc_initialized to cras_bt_device_audio_gateway_initialized to unify the path to start audio gateway. With that, the HFP/HSP will be mark as connected and connection watcher will not fail. BUG= chromium:647468 TEST=Test with HM1100 (HFP only device), connection is not lost. TEST=Test with IKBT74 (A2DP and HFP), playback and record both work. Change-Id: I45029c2a9ab855bbf27bdd950fe5dc779b74fef8 Signed-off-by: Cheng-Yi Chiang <cychiang@chromium.org> Reviewed-on: https://chromium-review.googlesource.com/386603 Reviewed-by: Chinyue Chen <chinyue@chromium.org> Reviewed-by: Dylan Reid <dgreid@chromium.org> (cherry picked from commit dab3c96c7ea42a321f1ef60034a76ae435af5270) Reviewed-on: https://chromium-review.googlesource.com/390591 [modify] https://crrev.com/c94fca3b14f3472ced77b1bd7646b4aba5062577/cras/src/server/cras_bt_device.c [modify] https://crrev.com/c94fca3b14f3472ced77b1bd7646b4aba5062577/cras/src/server/cras_bt_device.h [modify] https://crrev.com/c94fca3b14f3472ced77b1bd7646b4aba5062577/cras/src/server/cras_hfp_ag_profile.c
,
Sep 29 2016
The HSP only headset now works on M-55 and M-54
,
Aug 14
|
|||||||||||||||||||||||
►
Sign in to add a comment |
|||||||||||||||||||||||
Comment 1 by pbath...@chromium.org
, Sep 15 2016