941462 - [fugu]Ignore bluez internal error 'I/O' error code

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Bluetooth, defect)

Description

[Xinhe Yan]

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 Connect device A
2 Connect device B


Actual results:

Got a alert "Unable to pair devices"

Comment 1

[Xinhe Yan]

Beken bluetooth chip only support single link, second link request will be reject if first link have not disconnected.
create_bonding got -EIO.
 
Hi shawn,
I wanna know whether gecko/gaia will handle this case? Give a more detailed alert,ignore or ...

Comment 2

[Steven Yang [:styang]]

Need UX's input.

Comment 3

[Stephany Wilkes]

Flagging Ayman, though I'm not sure we can help much on the Gonk side.

Comment 4

[ayman maat :maat]

Hi Xinhe

I just to confirm. 
1) this bug is due to the Beken bluetooth chip only allowing the device to connect to one other BT device at a time?
2) is the problem you describe when the device is already connected to a BT device and the user.. 
    2.1) tries to connect to another BT device? or 
    2.2) when another BT device tries to connect to it? 

ni? to Xinhe

Comment 5

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

(In reply to Xinhe Yan from comment #1)
> Beken bluetooth chip only support single link, second link request will be
> reject if first link have not disconnected.
> create_bonding got -EIO.
>  
> Hi shawn,
> I wanna know whether gecko/gaia will handle this case? Give a more detailed
> alert,ignore or ...
I am not sure i can understand your statement 'create_bonding got -EIO'.
I actually wonder that this is true can you please provide hcidump and air sniffer?
I prefer to know the real problem from sniffer log and hcidump.

Comment 6

[Xinhe Yan]

(In reply to ayman maat :maat from comment #4)
> Hi Xinhe
> 
> I just to confirm. 
> 1) this bug is due to the Beken bluetooth chip only allowing the device to
> connect to one other BT device at a time?
I mean you can not link second device when first device link not disconnect. When no operation run, the link will disconnect. You can connect two devices ,but can not link them at same time.
> 2) is the problem you describe when the device is already connected to a BT
> device and the user.. 
>     2.1) tries to connect to another BT device? or 
>     2.2) when another BT device tries to connect to it? 
There is no difference. No matter connect to other device ,or other device connect local, they will create a link. If a link already exist, create second link will failed.
> ni? to Xinhe

Comment 7

[Xinhe Yan]

Attachment: hcidump for connect second device

Comment 8

[Xinhe Yan]

Hi Shawn,
I also check our android phone. When connect another device when former link still connected, there is no alert or  prompt. You can click second device some times(even not pair). But in firefox, there pop a alert "Unable to pair devices".

Comment 9

[James Zhang (Spreadtrum)]

It's fugu major bug.

Comment 10

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

I have review your hcidump log. I might need your confirmation regarding the last section.
It looks like something different from what you mentioned previously. As you mentioned in comment, ACL linke cannot be created upto 2 links.
Because I did not get any explanation for hcidump from your side. So I can only assume the last packet is your final test procedure.

From hcidump, the second ACL link established, see packet timestamp (2013-12-02 10:31:36.021903)
After that pairing procedure proceeds and it comes to PIN code Request.

2013-12-02 10:31:36.681044 > HCI Event: Command Complete (0x0e) plen 10
    Link Key Request Negative Reply (0x01|0x000c) ncmd 1
    status 0x00 bdaddr 00:EA:D6:04:36:50
2013-12-02 10:31:36.681787 > HCI Event: PIN Code Request (0x16) plen 6
    bdaddr 00:EA:D6:04:36:50

It seems the protocol stopped after PIN code request. So can you confirm any PIN code request dialog shows from gaia layer? I guess you got create_bonding with -EIO due to timeout to respond pin code.
This is just guess based on your log.

Comment 11

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

> It seems the protocol stopped after PIN code request. So can you confirm any
> PIN code request dialog shows from gaia layer? I guess you got
> create_bonding with -EIO due to timeout to respond pin code.
> This is just guess based on your log.
When you don't see any Pin Request dialog, can you please 'touch' the screen? I know a bug that the dialog was not been showed until screen has touched.

Comment 12

[Xinhe Yan]

(In reply to Shawn Huang [:shuang] [:shawnjohnjr] from comment #10)
> From hcidump, the second ACL link established, see packet timestamp
> (2013-12-02 10:31:36.021903)
> After that pairing procedure proceeds and it comes to PIN code Request.
Before second pairing procedure proceeds and PIN code Request, I click about two times, and I got a pop 'Unable to pair devices' twice. That is the problem. 
 
> It seems the protocol stopped after PIN code request. So can you confirm any
> PIN code request dialog shows from gaia layer? I guess you got
> create_bonding with -EIO due to timeout to respond pin code.
> This is just guess based on your log.
The problem occur before second PIN code request.

Comment 13

[Xinhe Yan]

(In reply to Shawn Huang [:shuang] [:shawnjohnjr] from comment #11)
> > It seems the protocol stopped after PIN code request. So can you confirm any
> > PIN code request dialog shows from gaia layer? I guess you got
> > create_bonding with -EIO due to timeout to respond pin code.
> > This is just guess based on your log.
> When you don't see any Pin Request dialog, can you please 'touch' the
> screen? I know a bug that the dialog was not been showed until screen has
> touched.
I already touch the screen before Pin Request dialog.

Steven Yang has fugu device,you can check on a real phone. May be you will have a  intuitive grasp.

Comment 14

[Xinhe Yan]

Attachment: hcidump from our android phone

Comment 15

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

(In reply to Xinhe Yan from comment #0)
> 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 Connect device A
> 2 Connect device B
> 
> 
> Actual results:
> 
> Got a alert "Unable to pair devices"

Just want to clarify STR. As you mentioned "Connect", do you refer to 'Pair' only?
From your log, i only saw pairing process and sdp query. 'Connect' refers to ACL link instead of L2CAP.

Comment 16

[Xinhe Yan]

(In reply to Shawn Huang [:shuang] [:shawnjohnjr] from comment #15)
> Just want to clarify STR. As you mentioned "Connect", do you refer to 'Pair'
> only?
Yes, I mean pair.
> From your log, i only saw pairing process and sdp query. 'Connect' refers to
> ACL link instead of L2CAP.

Comment 17

[Xinhe Yan]

I check with our android phone. After pair with device A, click device B. There were no response. I mean no alert like 'Unable to pair devices'.
I have to click like 2 or 3 times to enter pair screen appear.

There were some useful log.
E/BluetoothEventLoop.cpp(  249): onCreatePairedDeviceResult: D-Bus error: org.bluez.Error.Failed (I/O error)
V/BluetoothEventManager(  528): Received android.bluetooth.device.action.BOND_STATE_CHANGED
V/BluetoothEventManager(  528): Received android.bluetooth.device.action.BOND_STATE_CHANGED

Comment 18

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

Attachment: fail to pair logcat

Comment 19

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

Attachment: hcidump(unable to pair)

Comment 20

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

I checked this bug on fugu, and I found something required to confirm with you.
After the first device (D8:50:E6:2E:99:61) paired, I immediately pair with the second device (98:D6:F7:6B:63:12).
However, error happened "bt_io_connect: connect: Operation not permitted (1)".

12-04 06:10:07.907 D/BlueZ   (  387): auth_complete hci0 status 0
12-04 06:10:07.907 D/BlueZ   (  387): bonding_complete status 0x00
12-04 06:10:07.907 D/BlueZ   (  387): status 0x00
12-04 06:10:07.907 D/BlueZ   (  387): D8:50:E6:2E:99:61
12-04 06:10:07.907 D/BlueZ   (  387): bonding 0x0 status 0x00
12-04 06:10:07.967 I/GeckoDump(  358): --------Setting got Paired status changed event--------
......
12-04 06:10:10.947 D/BlueZ   (  387): 98:D6:F7:6B:63:12
12-04 06:10:10.947 D/BlueZ   (  387): Creating device /org/bluez/387/hci0/dev_98_D6_F7_6B_63_12
12-04 06:10:10.947 D/BlueZ   (  387): 0x13f88e0: ref=1
12-04 06:10:10.947 D/BlueZ   (  387): temporary 1
12-04 06:10:10.947 D/BlueZ   (  387): bt_io_connect: connect: Operation not permitted (1)
12-04 06:10:11.047 I/GeckoDump(  358): !!!!!!!!!Setting bt_pairError!!!!!!!
12-04 06:10:11.047 I/GeckoDump(  358): !!!!Setting Show error message!!!!

Did you see the same log as I did?

I also check the log from hcidump. I think bt chipset does not get HCI command "Create Connection" even.
Can you check if you saw the same error (bt_io_connect error) from bluez?

Comment 21

[Xinhe Yan]

(In reply to Shawn Huang [:shuang] [:shawnjohnjr] from comment #20)
> I checked this bug on fugu, and I found something required to confirm with
> you.
> After the first device (D8:50:E6:2E:99:61) paired, I immediately pair with
> the second device (98:D6:F7:6B:63:12).
> However, error happened "bt_io_connect: connect: Operation not permitted
> (1)".
> 
> 12-04 06:10:07.907 D/BlueZ   (  387): auth_complete hci0 status 0
> 12-04 06:10:07.907 D/BlueZ   (  387): bonding_complete status 0x00
> 12-04 06:10:07.907 D/BlueZ   (  387): status 0x00
> 12-04 06:10:07.907 D/BlueZ   (  387): D8:50:E6:2E:99:61
> 12-04 06:10:07.907 D/BlueZ   (  387): bonding 0x0 status 0x00
> 12-04 06:10:07.967 I/GeckoDump(  358): --------Setting got Paired status
> changed event--------
> ......
> 12-04 06:10:10.947 D/BlueZ   (  387): 98:D6:F7:6B:63:12
> 12-04 06:10:10.947 D/BlueZ   (  387): Creating device
> /org/bluez/387/hci0/dev_98_D6_F7_6B_63_12
> 12-04 06:10:10.947 D/BlueZ   (  387): 0x13f88e0: ref=1
> 12-04 06:10:10.947 D/BlueZ   (  387): temporary 1
> 12-04 06:10:10.947 D/BlueZ   (  387): bt_io_connect: connect: Operation not
> permitted (1)
> 12-04 06:10:11.047 I/GeckoDump(  358): !!!!!!!!!Setting bt_pairError!!!!!!!
> 12-04 06:10:11.047 I/GeckoDump(  358): !!!!Setting Show error message!!!!
> 
> Did you see the same log as I did?
Yes, I seen these log too.
After that, android will not give a alert. From an end-user perspective, android ignore the error.
I think gecko need eat this I/O error. Not to give a alert.
> I also check the log from hcidump. I think bt chipset does not get HCI
> command "Create Connection" even.
> Can you check if you saw the same error (bt_io_connect error) from bluez?
That same to me. Because beken chip can only handle single link.

Comment 22

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

I think bt_io_connect return error in
hciops_create_bonding function,
        conn->io = bt_io_connect(BT_IO_L2RAW, bonding_connect_cb, conn,
                                        NULL, &err,
                                        BT_IO_OPT_SOURCE_BDADDR, &dev->bdaddr,
                                        BT_IO_OPT_DEST_BDADDR, bdaddr,
                                        BT_IO_OPT_SEC_LEVEL, sec_level,
                                        BT_IO_OPT_INVALID);
In btio.c, bt_io_connect calls l2cap_connect(), which returns EPERM error code.
I think this is why we don't see the second 'Create Connection' HCI command from hcidump - since HCI command has not yet sent to bluetooth chipset. I guess it might not be related to ACL link limitation.

At least I saw this error all the time, if we pair with the second device very fast after the first device gets paired. If my observation is correct, you might also help to check from kernel bluetooth stack code.

Comment 23

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

> After that, android will not give a alert. From an end-user perspective,
> android ignore the error.
> I think gecko need eat this I/O error. Not to give a alert.
Interesting, I can see error code here with error code EPERM instead of EIO error code.
I understand your point. Given AUTH_FAILED and HOST_IS_DOWN shall be enough here, but from DOM api level, it is a little strange. ni? echou for more comments regarding ignore error based on bluetooth pairing api.

Comment 24

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

> > I also check the log from hcidump. I think bt chipset does not get HCI
> > command "Create Connection" even.
> > Can you check if you saw the same error (bt_io_connect error) from bluez?
> That same to me. Because beken chip can only handle single link.
Then we shall expect ConnectionLimitExceeded error code returned from controller.
The Connection Limit Exceeded error code indicates that an attempt to create
another connection failed because the controller is already at its limit of the
number of connections it can support.

Although, this is not your major concern.

Comment 25

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

Eric,
Android Bluetooth only checks AuthenticationFail and RemoteDeviceDown, if there is any other error, Android simply clear bonding attempt and set bond state to none, which hides pairing request error. This might need your comments for replying that pairing DomRequest.

Comment 26

[Eric Chou [:ericchou] [:echou]]

I'm ok with reporting error to Gaia only when these two status codes returned (AuthenticationFail & RemoteDeviceDown). This means that we see other returning status as "internal errors" so that Gecko Bluetooth could just cancel the bonding process but not invoke onerror callback.

Comment 27

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

Thanks for comments. I will make a patch.

Comment 28

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

This patch shall be done in these two days.

Comment 29

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

Attachment: Bug 941462 - [fugu]Ignore bluez internal error 'I/O' error code for debug message

This required to change gaia for cancel pairing message.

Comment 30

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

Attachment: Bug941462_gaia.patch

Comment 31

[Arthur Chen [:arthurcc][inactive after 6/30]]

Comment on attachment 8345763 [details] [diff] [review]
Bug941462_gaia.patch

Evelyn, could you help check this?

Comment 32

[thomas tsai]

Eric, can you review?

Comment 33

[Evelyn Hung]

Comment on attachment 8345763 [details] [diff] [review]
Bug941462_gaia.patch

Per UX design, we display error dialog when an error occurs. So I don't think skipping error dialog in this case is a good way to take, because the user doesn't have a chance to notice something wrong. If you have any question on UI, please loop UX to comment. Thanks.

Comment 34

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

After discussing with gaia team, sending Cancel Signal is also not proper here. The better way is to send error reply and make Gaia app ignore this 'InternalError'. So our conclusion is from Gecko side, replace 
'I/O error' to 'InternalError' to fit different BT stacks.

Comment 35

[Gina Yeh [:gyeh] [:ginayeh]]

Just had a short discussion with Shawn and Evelyn.

For Gecko side, since the pairing isn't initiated successfully, I think we should reply the error with an error string like "InternalError".

Shawn will update the patch today, and I can review it.

Comment 36

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

Comment on attachment 8345759 [details] [diff] [review]
Bug 941462 - [fugu]Ignore bluez internal error 'I/O' error code for debug message

Obsolete this patch since we shall reflect the error.

Comment 37

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

Attachment: 0001-Bug-941462-Reply-internal-error-code-when-getting-I-.patch

Comment 38

[Gina Yeh [:gyeh] [:ginayeh]]

Comment on attachment 8346420 [details] [diff] [review]
0001-Bug-941462-Reply-internal-error-code-when-getting-I-.patch

Review of attachment 8346420 [details] [diff] [review]:
-----------------------------------------------------------------

Please take a look at the following comments. Thanks.

::: dom/bluetooth/linux/BluetoothDBusService.cpp
@@ +435,4 @@
>    nsAutoString replyError;
>    BluetoothValue v;
>    aFunc(aMsg, nullptr, v, replyError);
> +  // if DBUS reply equals liternal error 'I/O error'

nit: Capitalization. We usually insert line breaks after 80 char.

@@ +437,5 @@
>    aFunc(aMsg, nullptr, v, replyError);
> +  // if DBUS reply equals liternal error 'I/O error'
> +  // we treat this kind of error as 'internal error' from bluez,
> +  // This usally happned when the first pairing request has not yet finished,
> +  // the second pairing request issued immediately.

Please put bug number in comments.

Comment 39

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

Attachment: [1.2f]Bug 941462 - Reply internal error code when getting I/O error from BlueZ, r=gyeh

Comment 40

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

Attachment: [Central] Bug 941462 - Reply internal error code when getting I/O error from BlueZ, r=gyeh

Comment 41

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

https://tbpl.mozilla.org/?tree=Try&rev=91187b81599c

Comment 42

[Gina Yeh [:gyeh] [:ginayeh]]

https://hg.mozilla.org/integration/b2g-inbound/rev/663c89095e7d

Comment 43

[Gina Yeh [:gyeh] [:ginayeh]]

Attachment: [v1.2f] Final patch, r=gyeh

Fix some typo in the original patch.

Comment 44

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/663c89095e7d

Comment 45

[Xinhe Yan]

(In reply to Shawn Huang [:shuang] [:shawnjohnjr] from comment #34)
> After discussing with gaia team, sending Cancel Signal is also not proper
> here. The better way is to send error reply and make Gaia app ignore this
> 'InternalError'. So our conclusion is from Gecko side, replace 
> 'I/O error' to 'InternalError' to fit different BT stacks.
Hi Evelyn&Shawn,
Is there a bug to trace gaia patch? I think patch in Comment 30 need to be review and verify.

Comment 46

[Xinhe Yan]

I fire a new bug 950571 to trace gaia patch