1002388 - [Tarako][Hamachi]gecko need remove a2dp icon after disable bt

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Bluetooth, defect)

Description

[Xinhe Yan]

Attachment: bt_a2dp_icon.tar.gz

User Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/535.19 (KHTML, like Gecko) Ubuntu/11.04 Chromium/18.0.1025.151 Chrome/18.0.1025.151 Safari/535.19

Steps to reproduce:

1 enable bt and connect a2dp headset
2 disable bt


Actual results:

a2dp icon did not disappear in status bar

Comment 1

[Xinhe Yan]

For tarako, we found this case by close bt when just connect a2dp headset.
For hamachi, I put a2dp headset in a iron box and move away.

In bt_a2dp_icon/Tarako/bt/bt_2.log, sent disconnect request have no response.
Hamachi did not send disconnect request.

Can we just remove a2dp icon when disable bt?

Comment 2

[Ben Tian (inactive)]

(In reply to Xinhe Yan from comment #1)
> For tarako, we found this case by close bt when just connect a2dp headset.
Does you build contains bug 984284's fix? Also what's the occurrence rate? I cannot repro this bug on my Tarako within 20 trials. Please attach a symptom video for us to identify the exact timing. 

> For hamachi, I put a2dp headset in a iron box and move away.
1.3 still has this bug since bug 984284's fix is not in 1.3 branch.

> In bt_a2dp_icon/Tarako/bt/bt_2.log, sent disconnect request have no response.
What's the subject that sent disconnect request and the one without response?

Comment 3

[Xinhe Yan]

(In reply to Ben Tian [:btian] from comment #2)
> > In bt_a2dp_icon/Tarako/bt/bt_2.log, sent disconnect request have no response.
> What's the subject that sent disconnect request and the one without response?
I guess without disconnect response, bluez will not send sink PropertyChanged.

Comment 4

[Xinhe Yan]

(In reply to Ben Tian [:btian] from comment #2)
> > For hamachi, I put a2dp headset in a iron box and move away.
> 1.3 still has this bug since bug 984284's fix is not in 1.3 branch.
For hamachi, this bug still can be found in master branch.
gecko:3079ee9f2aea1488ec799b922562bcf6c5aaf103
gaia:473dd9f3738b950910841bc23567b8c234562a31

Comment 5

[Ben Tian (inactive)]

(In reply to Xinhe Yan from comment #3)
> (In reply to Ben Tian [:btian] from comment #2)
> > > In bt_a2dp_icon/Tarako/bt/bt_2.log, sent disconnect request have no response.
> > What's the subject that sent disconnect request and the one without response?
> I guess without disconnect response, bluez will not send sink
> PropertyChanged.
Do you mean bluez doesn't notify gecko sink property changed if the headset doesn't respond to DuT's disconnect request?

Again, please provide the following to help investigation:
1) What's the occurrence rate?
2) A symptom clip for us to identify the timing to turn off BT and reproduce the bug.

Comment 6

[Ben Tian (inactive)]

Remove Gina and Peko since they are not working on bluetooth.

Comment 7

[Ben Tian (inactive)]

(In reply to Xinhe Yan from comment #4)
> (In reply to Ben Tian [:btian] from comment #2)
> > > For hamachi, I put a2dp headset in a iron box and move away.
> > 1.3 still has this bug since bug 984284's fix is not in 1.3 branch.
> For hamachi, this bug still can be found in master branch.
> gecko:3079ee9f2aea1488ec799b922562bcf6c5aaf103
I cannot find the gecko commit on m-c branch [1]. Can you provide more commit info or where you download the build?

[1] https://github.com/mozilla/gecko-dev/commits/master

Comment 8

[Ben Tian (inactive)]

OK. I can reproduce this bug on Tarako with the timing that BT is turned off after "media audio" is connected. The occurrence rate is not 100%.

A2DP icon remains because bluez notifies that sink state becomes "connected" after A2DP manager requests bluez disconnect. Since original sink state is already "connected", [1] blocks the sink state change and keeps waiting sink state becomes "disconnected".

[1] http://hg.mozilla.org/releases/mozilla-b2g28_v1_3t/file/5f296c701443/dom/bluetooth/bluez/BluetoothA2dpManager.cpp#l289

Xinhe, can you help check your bluez stack why it notifies sink state as "connected" after Disconnect command? Does it cache a sink state for property change notification?

Comment 9

[Shawn Huang [:shawnjohnjr][:shuang] (as a happy gecko contributor)]

Attachment: logcat-iconStillShow.txt

I can this this bug. Attached logcat with bluez log enabled.

Comment 10

[Shawn Huang [:shawnjohnjr][:shuang] (as a happy gecko contributor)]

(In reply to Shawn Huang [:shuang] [:shawnjohnjr] from comment #9)
> Created attachment 8415072 [details]
> logcat-iconStillShow.txt
> 
> I can this this bug. Attached logcat with bluez log enabled.
I reproduced this bug with Tarako and Jambox.
The interesting things is that:
AVDTP stream state already gets closed while turing off bluetooth, at the same time, a2dp is disconnecting.

*** 04-30 04:20:40.960    AVDTP stream state: Connecting ---> Connected
* User turns off Bluetooth
* Turning off procedure, disconnect all link (hfp/a2dp)
* 04-30 04:20:44.430 D/        (  649): CLOSE request succeeded ---->AVDTP stream state to CLOSED
* 04-30 04:20:44.430 D/        (  649): DEBUG: close_cfm: Source 0x18e95b8: Close_Cfm
  04-30 04:20:44.430 D/        (  649): stream state changed: CLOSING -> IDLE

*** Confirmed AVDTP closed

*** After 400 ms, incoming connection again from headset
04-30 04:20:45.010 D/        (  649): AVDTP: incoming connect from 00:21:3C:86:0E:CE
04-30 04:20:45.080 D/        (  649): AVDTP: connected transport channel to 00:21:3C:86:0E:CE

*** A2DP connected
*04-30 04:20:45.080 D/        (  649): State changed /org/bluez/649/hci0/dev_00_21_3C_86_0E_CE: SINK_STATE_CONNECTED -> SINK_STATE_CONNECTED

------------------------------------------------------------------------
Completed turned off Bluetooth
04-30 04:20:49.430 I/bluedroid(   84): test Stopping bluetoothd deamon
04-30 04:20:49.940 I/bluedroid(   84): Stopping hciattach deamon

Comment 11

[Shawn Huang [:shawnjohnjr][:shuang] (as a happy gecko contributor)]

Add additional analysis:
In normal case, we shall expect disconnect log looks like:
04-30 04:36:17.730 D/        ( 1065): CLOSE request succeeded
04-30 04:36:17.730 D/        ( 1065): stream state changed: OPEN -> CLOSING
04-30 04:36:17.740 D/        ( 1065): DEBUG: close_cfm: Source 0x1eb65c8: Close_Cfm
04-30 04:36:17.740 D/        ( 1065): stream state changed: CLOSING -> IDLE
04-30 04:36:17.740 D/        ( 1065): 0x1ebbbb0: ref=1
04-30 04:36:18.990 D/        ( 1065): Disconnected from 00:21:3C:86:0E:CE
04-30 04:36:18.990 D/        ( 1065): State changed /org/bluez/1065/hci0/dev_00_21_3C_86_0E_CE: SINK_STATE_CONNECTED -> SINK_STATE_DISCONNECTED

However, in bad case, you can see that, after avdtp changed to IDLE, bluez received Discover/Get Capabilties/Configure request again, and at the same time, we shall expected the previous disconnection event supposes to pass to sink.c, but it does not happen. But instead of, we saw Disconnection seems to be interrupted and laster it comes with incoming connection request from the remote bluetooth device after 400 ms.

*** Bad Case: attachment 8415072 [details] ***
04-30 04:20:44.430 D/        (  649): stream state changed: CLOSING -> IDLE
04-30 04:20:44.430 D/        (  649): 0x18eef50: ref=1
04-30 04:20:44.830 D/        (  649): Received DISCOVER_CMD
04-30 04:20:44.850 D/        (  649): Received  GET_CAPABILITIES_CMD
04-30 04:20:44.850 D/        (  649): DEBUG: sbc_getcap_ind: Source 0x18e95b8: Get_Capability_Ind
04-30 04:20:44.930 D/        (  649): Received SET_CONFIGURATION_CMD

Comment 12

[Shawn Huang [:shawnjohnjr][:shuang] (as a happy gecko contributor)]

I think Gecko behaves correctly to disconnect all links each by each during turning off bluetooth. The problem I saw is that disconnection is ongoing and attempts to pass to sink.c via |avdtp_state_callback|, but at the same time incoming connection request again changes the state to CONNECTED again.

Hi Xinhe,
Would you please confirm this is the same problem you observed? We need to align with problem and decide to fix either in gecko or bluez stack.

Comment 13

[Xinhe Yan]

(In reply to Shawn Huang [:shuang] [:shawnjohnjr] from comment #12)
> I think Gecko behaves correctly to disconnect all links each by each during
> turning off bluetooth. The problem I saw is that disconnection is ongoing
> and attempts to pass to sink.c via |avdtp_state_callback|, but at the same
> time incoming connection request again changes the state to CONNECTED again.
I double checked with our bluez engineer. That is not what we saw.
No incomming connection request.
What we saw is bluez send a2dp link disconnect to controller, but we did not get response from headset.
If disable bluetooth, bluez will not wait all the links disconnect. When disable bt, bluez will set links status to disconnected.

Comment 14

[Ben Tian (inactive)]

(In reply to Xinhe Yan from comment #13)
> I double checked with our bluez engineer. That is not what we saw.
> No incomming connection request.
> What we saw is bluez send a2dp link disconnect to controller, but we did not
> get response from headset.
> If disable bluetooth, bluez will not wait all the links disconnect. When
> disable bt, bluez will set links status to disconnected.
So does bluez set sink state as "disconnected"? If so, a2dp manager should receive sink state change from bluez [1] and notify gaia to remove the icon [2], even though BT headset was irresponsive.

[1] http://hg.mozilla.org/releases/mozilla-b2g28_v1_3t/file/dfc111de2faa/dom/bluetooth/bluez/linux/BluetoothDBusService.cpp#l323
[2] http://hg.mozilla.org/releases/mozilla-b2g28_v1_3t/file/dfc111de2faa/dom/bluetooth/bluez/BluetoothA2dpManager.cpp#l334

Also what's the timing did you turn BT off? Did turn off BT before the grey subtitle "connected to phone audio" became "connected to phone/media audio"?

Comment 15

[Ben Tian (inactive)]

Resolve as WFM since we adopt bluedroid now. Please reopen this bug if it happens on the latest build.