Closed Bug 1141899 Opened 9 years ago Closed 9 years ago

[NFC][Bluetooth][Nexus5-L] Could not auto connect NFC headset

Categories

(Firefox OS Graveyard :: Bluetooth, defect)

ARM
Gonk (Firefox OS)
defect
Not set
normal

Tracking

(blocking-b2g:2.2+, firefox38 wontfix, firefox39 wontfix, firefox40 fixed, b2g-v2.2 verified, b2g-master verified)

VERIFIED FIXED
2.2 S10 (17apr)
blocking-b2g 2.2+
Tracking Status
firefox38 --- wontfix
firefox39 --- wontfix
firefox40 --- fixed
b2g-v2.2 --- verified
b2g-master --- verified

People

(Reporter: ashiue, Assigned: jaliu)

References

Details

Attachments

(4 files, 3 obsolete files)

Attached file nexus_5_nfc_bt.log
Gaia-Rev        5af6f8d5d6161dea02002634c6d0a570a122e5dd
Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g37_v2_2/rev/ec87adb8cf13
Build-ID        20150310162504
Version         37.0
Device-Name     hammerhead
FW-Release      5.0
FW-Incremental  eng.cltbld.20150310.201846
FW-Date         Tue Mar 10 20:19:04 EDT 2015
Bootloader      HHZ11k

STR:
1. Enable NFC on device
2. Tap NFC-headset on device
3. When BT connect dialog pop-up, press "Yes" to connect to the NFC-headset

Expect result:
NFC headset has been paired and auto connected

Actual result:
NFC headset has been paired but did not auto connect
blocking-b2g: --- → 2.2?
QA Whiteboard: [COM=NFC]
Allison, does this happen on flame as well or this is nexus 5 specific?
(In reply to bhavana bajaj [:bajaj] from comment #1)
> Allison, does this happen on flame as well or this is nexus 5 specific?

This issue only happens on Nexus 5.
Shawn, could be help make a judgement if we'd block on this specific nexus - 5 L issue?
Flags: needinfo?(sku)
Shawn Huang take this bug (comment 4), remove ni for myself.
Flags: needinfo?(sku)
Can you provide me the device you tested?
Flags: needinfo?(ashiue)
(In reply to Shawn Huang [:shawnjohnjr] from comment #6)
> Can you provide me the device you tested?

Sure. remove ni
Flags: needinfo?(ashiue)
I saw libfdio timerfd_create failed: Invalid argument.


03-23 14:19:42.593 E/bt-btm  ( 1720): btm_sec_disconnected - Clearing Pending flag
03-23 14:19:42.866 D/NfcNci  (  195): doPresenceCheck
03-23 14:19:42.878 E/HWComposer(  193): Non-uniform vsync interval: 17003802
03-23 14:19:43.494 E/libfdio ( 1720): timerfd_create failed: Invalid argument
03-23 18:18:27.310 I/GeckoBluetooth( 4895): CreatePairedDeviceInternal
03-23 18:18:27.310 E/bt-btif ( 4999): check_cod: remote_cod = 0x240404
03-23 18:18:32.442 E/bt-btif ( 4999): Do not find the bg connection mask for the remote device
03-23 18:18:32.442 E/bt-btif ( 4999): check_cod: remote_cod = 0x240404
03-23 18:18:32.672 I/GeckoConsole( 4895): Content JS LOG: [NfcHandoverManager]: Pairing failed 
03-23 18:18:32.672 I/GeckoConsole( 4895):     at _logVisibly (app://system.gaiamobile.org/gaia_build_defer_index.js:1663:0)
I enabled more bluedroid logs and found still error, i'm afraid I need to dig into bluedroid stack further.

03-23 18:29:28.822 I/GeckoBluetooth(  190): CreatePairedDeviceInternal: !!!!!!!  Create Bonding !!!!!!!!!
03-23 18:29:28.823 I/bt-btif (  803): btif_dm_create_bond: bd_addr=4c:21:d0:9f:12:f1, transport=0
03-23 18:29:28.823 I/bt-btif (  803): btif_dm_generic_evt: event=33026
03-23 18:29:28.823 D/bt-btif (  803): in, bd addr:4c:21:d0:9f:12:f1, prop type:4, len:4
03-23 18:29:28.823 E/bt-btif (  803): check_cod: remote_cod = 0x240404
03-23 18:29:28.823 D/bt-btif (  803): bond_state_changed: state=1 prev_state=0
03-23 18:29:28.823 I/bt-btif (  803): HAL bt_hal_cbacks->bond_state_changed_cb
03-23 18:29:28.823 I/bt-btm  (  803): BTM_InqDbRead: bd addr [4c21d09f12f1]
03-23 18:29:28.823 D/bt-btm  (  803): btm_find_dev_type - unknown device, BR/EDR assumed
03-23 18:29:28.823 D/bt-btm  (  803): btm_find_dev_type - device_type = 1 addr_type = 0
03-23 18:29:28.823 I/bt-btm  (  803): btm_sec_bond_by_transport BDA: 4c:21:d0:9f:12:f1
03-23 18:29:28.823 D/bt-btm  (  803): btm_sec_bond_by_transport: Transport used 1
03-23 18:29:28.823 I/bt-btm  (  803): btm_find_or_alloc_dev
03-23 18:29:28.823 I/bt-btm  (  803): btm_sec_alloc_dev
03-23 18:29:28.823 I/bt-btm  (  803): BTM_InqDbRead: bd addr [4c21d09f12f1]
03-23 18:29:28.823 D/bt-btm  (  803): BTM_GetHCIConnHandle
03-23 18:29:28.823 D/bt-btm  (  803): BTM_GetHCIConnHandle
03-23 18:29:28.823 D/bt-btm  (  803): before update sec_flags=0x80
03-23 18:29:28.823 I/bt-btm  (  803): BTM: BTM_DeleteStoredLinkKey: delete_all_flag: FALSE
03-23 18:29:28.823 D/bt-btm  (  803): after update sec_flags=0x80
03-23 18:29:28.823 I/bt-btm  (  803):   remote_features page[0] = 00-00-00-00
03-23 18:29:28.823 I/bt-btm  (  803):                               00-00-00-00
03-23 18:29:28.823 I/bt-btm  (  803):   remote_features page[1] = 00-00-00-00
03-23 18:29:28.823 I/bt-btm  (  803):                               00-00-00-00
03-23 18:29:28.823 I/bt-btm  (  803):   remote_features page[2] = 00-00-00-00
03-23 18:29:28.823 I/bt-btm  (  803):                               00-00-00-00
03-23 18:29:28.823 I/bt-btm  (  803): BTM_SecBond: Remote sm4: 0x0  HCI Handle: 0xffff
03-23 18:29:28.823 D/bt-btm  (  803): sec mode: 4 sm4:x0
03-23 18:29:28.823 I/bt-btm  (  803): btm_sec_change_pairing_state  Old: 0
03-23 18:29:28.823 I/bt-btm  (  803): btm_sec_change_pairing_state  New: 1 pairing_flags:0x1
03-23 18:29:28.823 I/bt-btm  (  803): BTM_ReadRemoteDeviceName: bd addr [4c21d09f12f1]
03-23 18:29:28.823 I/bt-btm  (  803): no device found in inquiry db
03-23 18:29:28.823 D/bt-btm  (  803): btm_acl_paging discing:0, paging:0 BDA: 4c21d09f12f1
03-23 18:29:28.823 D/bt-btm  (  803): connecting_bda: 000000000000
03-23 18:29:28.823 I/bt-btm  (  803): btm_find_or_alloc_dev
03-23 18:29:28.823 D/bt-btm  (  803): State:1 sm4: 0x0 sec_state:0
03-23 18:29:29.458 I/bt-btif (  803): BTHF: device_status_notification
03-23 18:29:33.955 I/bt-btm  (  803): BDA 4c:21:d0:9f:12:f1
03-23 18:29:33.955 I/bt-btm  (  803): Inquire BDA 4c:21:d0:9f:12:f1
03-23 18:29:33.955 I/bt-btm  (  803): BTM_InqDbRead: bd addr [4c21d09f12f1]
03-23 18:29:33.955 D/bt-btm  (  803): btm_find_dev_type - device_type = 0 addr_type = 0
03-23 18:29:33.955 I/bt-btm  (  803): btm_sec_rmt_name_request_complete
03-23 18:29:33.955 D/bt-btm  (  803): btm_acl_resubmit_page
03-23 18:29:33.956 I/bt-btm  (  803): Security Manager: rmt_name_complete PairState: 1  RemName:   status: 4 State:0  p_dev_rec: 0xb6bd5ebc 
03-23 18:29:33.956 I/bt-btm  (  803): btm_sec_rmt_name_request_complete() continue bonding sm4: 0x0000, status:0x4
03-23 18:29:33.956 I/bt-btm  (  803): btm_sec_change_pairing_state  Old: 1
03-23 18:29:33.956 I/bt-btm  (  803): btm_sec_change_pairing_state  New: 0 pairing_flags:0x1
03-23 18:29:33.956 I/bt-btm  (  803): BTM_IsAclConnectionUp: RemBdAddr: 4c21d09f12f1
03-23 18:29:33.956 I/bt-btm  (  803): BTM_IsAclConnectionUp: RemBdAddr: 4c21d09f12f1
03-23 18:29:33.956 I/bt-btm  (  803): BTM_IsAclConnectionUp: RemBdAddr: 4c21d09f12f1
03-23 18:29:33.956 I/bt-btm  (  803): BTM_IsAclConnectionUp: RemBdAddr: 4c21d09f12f1
03-23 18:29:33.956 D/bt-btm  (  803): btm_sec_clear_ble_keys: Clearing BLE Keys
03-23 18:29:33.956 I/bt-btm  (  803): BTM: BTM_DeleteStoredLinkKey: delete_all_flag: FALSE
03-23 18:29:33.957 E/bt-btif (  803): Do not find the bg connection mask for the remote device
03-23 18:29:33.957 D/bt-btif (  803): bta_gattc_co_cache_reset()
03-23 18:29:33.967 I/bt-btif (  803): btif_dm_upstreams_cback  ev: BTA_DM_AUTH_CMPL_EVT
03-23 18:29:33.967 D/bt-btif (  803): in, bd addr:4c:21:d0:9f:12:f1, prop type:4, len:4
03-23 18:29:33.968 E/bt-btif (  803): check_cod: remote_cod = 0x240404
03-23 18:29:33.968 D/bt-btif (  803): bond_state_changed: state=0 prev_state=1
03-23 18:29:33.968 I/bt-btif (  803): HAL bt_hal_cbacks->bond_state_changed_cb
03-23 18:29:34.143 I/GeckoConsole(  190): Content JS LOG: [NfcHandoverManager]: Pairing failed
Attachment #8581528 - Attachment description: logcat.txt → Comment 10 logcat.txt
I just know we're going to move to gonk based on version 5.1. Do we need to verify on gonk v5.1? For me, this looks like bluetooth stack related bug.
I'm afraid this will be something caused by lollipop and cannot fix from gecko/gaia.
Maybe we should try to test it on device Orion, and see if it can be reproduced.
(In reply to Alison Shiue from comment #2)
> (In reply to bhavana bajaj [:bajaj] from comment #1)
> > Allison, does this happen on flame as well or this is nexus 5 specific?
> 
> This issue only happens on Nexus 5.

Alison, I saw different bugs here. on flame-kk, v2.2 gaia nfc module also changed their behaviors. Can we check again on flame-kk for v2.2? I saw if user disconnects headset and use NFC to trigger connection. Connection always fail, but it's a different problem as I saw on Nexus-5-l, perhaps you should use another bug to track.
Flags: needinfo?(ashiue)
1. On Nexus-5-L, can be paired sometimes but cannot connect with remote device. I will check further for bluetooth stack tomorrow and hopefully I can spot the reason.

2. On flame-kk, can be paired and connect with the remote device at the first time. If the device get paired previously but disconnected, re-connection trigger by nfc never be initialized. I notice that NfcHandoverManager.js is trying to do pairing again even device is in the paired list and I don't see NfcHandoverManager creates connection.
(In reply to Shawn Huang [:shawnjohnjr] from comment #15)
> (In reply to Alison Shiue from comment #2)
> > (In reply to bhavana bajaj [:bajaj] from comment #1)
> > > Allison, does this happen on flame as well or this is nexus 5 specific?
> > 
> > This issue only happens on Nexus 5.
> 
> Alison, I saw different bugs here. on flame-kk, v2.2 gaia nfc module also
> changed their behaviors. Can we check again on flame-kk for v2.2? I saw if
> user disconnects headset and use NFC to trigger connection. Connection
> always fail, but it's a different problem as I saw on Nexus-5-l, perhaps you
> should use another bug to track.

Yes, this is an issue. I am not sure if 2.1 has the same problem since bug 1146741, I would file another bug to track track this issue. Thank you.
Flags: needinfo?(ashiue)
See Also: → 1146741
See Also: 1146741
See Also: → 1146744
Take this bug since Shawn is working on other tasks.
Assignee: shuang → jaliu
blocking-b2g: 2.2? → 2.2+
Comment on attachment 8586521 [details] [diff] [review]
(for master) Add common profile managers to profile list if Bluetooth CoD of remote device is unclear. (v0)

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

My concern is that if NFC trigger pairing and COD value is invalid or unexpected, that COD value from bluedroid stack is uninitialized value (because it never had done Inquiry so no extend Inquiry results), it could be anything, so what if that CoD value becomes to expected value but actually wrong value?

::: dom/bluetooth/BluetoothProfileController.h
@@ +52,5 @@
>  
>  // Pointing device: sub-field of minor device class (Bit 7)
>  #define IS_POINTING_DEVICE(cod)      ((GET_MINOR_DEVICE_CLASS(cod) & 0x20) >> 5)
>  
> +// Whether the value of CoD is unexpected. (i.e. Whether Bit 31 ~ Bit 24 = 0x0)

Can you add some extra explanation? It's still unclear to me.
Attachment #8586521 - Flags: review?(shuang)
- Revise previous patch based on #comment 20
Attachment #8586521 - Attachment is obsolete: true
Attachment #8586628 - Flags: review?(shuang)
Attachment #8586647 - Flags: review?(shuang)
(In reply to Shawn Huang [:shawnjohnjr] from comment #16)
> 1. On Nexus-5-L, can be paired sometimes but cannot connect with remote
> device. I will check further for bluetooth stack tomorrow and hopefully I
> can spot the reason.
> 
> 2. On flame-kk, can be paired and connect with the remote device at the
> first time. If the device get paired previously but disconnected,
> re-connection trigger by nfc never be initialized. I notice that
> NfcHandoverManager.js is trying to do pairing again even device is in the
> paired list and I don't see NfcHandoverManager creates connection.

It has been my observation that the issue only happens on nexus-5-L and the root cause is Gecko receiving a invalid CoD(class of device) from Bluetooth stack.

The behaviour of BT stack in flame-kk are different to nexus-5-L, the CoD of headset(SONY-MBH10) is correct in flame-kk. It seems that BlueDroid in nexus-5-L didn't handle CoD of SONY-MBH10 properly, however, Gecko shouldn't fail to connect to the headset even the CoD is abnormal.

In my experiment, nexus-5-L can auto connect to NFC headset normally with the fix #attachment 8586647 [details] [diff] [review].

The auto connect in Flame-kk and nexus-5-L would still fail when user manually disconnect already connected NFC headset. However, the issue is addressed in Bug 1146744 which is going to be fixed.
Status: NEW → ASSIGNED
Comment on attachment 8586647 [details] [diff] [review]
(for master) Add common profile managers to profile list if Bluetooth CoD of remote device is unclear. (v2)

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

::: dom/bluetooth/BluetoothProfileController.h
@@ +53,5 @@
>  // Pointing device: sub-field of minor device class (Bit 7)
>  #define IS_POINTING_DEVICE(cod)      ((GET_MINOR_DEVICE_CLASS(cod) & 0x20) >> 5)
>  
> +/**
> + * Whether the value of CoD is invalid. (i.e. Whether Bit 31 ~ Bit 24 != 0x0)

nit: Check whether
Comment on attachment 8587251 [details] [diff] [review]
(for 2.2) Add common profile managers to profile list if Bluetooth CoD of remote device is unclear. (v3), r=shuang

[Approval Request Comment]
> Bug caused by (feature/regressing bug #): 
Bug 967345 - Do a BT connect() for a static handover

> User impact if declined: 
Bluetooth headset can't be auto-connected after NFC handover.

> Testing completed: 
- Push to try server
- Follow the STR of this bug with v2.2 build
  Test device: nexus-5-l and Sony MBH10 (NFC/BT headset)

> Risk to taking this patch (and alternatives if risky): 
It's a nexus-5-l specific bug.
I didn't test this patch on flame-L since the image of flame-L isn't ready.

> String or UUID changes made by this patch:
no
Attachment #8587251 - Attachment is patch: true
Attachment #8587251 - Flags: approval-mozilla-b2g37?
Keywords: checkin-needed
waiting for m-c landing here..
Comment on attachment 8587251 [details] [diff] [review]
(for 2.2) Add common profile managers to profile list if Bluetooth CoD of remote device is unclear. (v3), r=shuang

Approving as the m-c merge should happen soon and this can land in parallel
Attachment #8587251 - Flags: approval-mozilla-b2g37? → approval-mozilla-b2g37+
https://hg.mozilla.org/mozilla-central/rev/670b9db2b898
Status: ASSIGNED → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
Verified on
[2.2]
Build ID               20150419162502
Gaia Revision          c15a2b6d3a783813959c2b3bffd2a131f4270b9e
Gaia Date              2015-04-17 17:49:32
Gecko Revision         https://hg.mozilla.org/releases/mozilla-b2g37_v2_2/rev/cc02ee38b252
Gecko Version          37.0
Device Name            hammerhead
Firmware(Release)      5.1
Firmware(Incremental)  eng.cltbld.20150419.201551
Firmware Date          Sun Apr 19 20:16:07 EDT 2015
Bootloader             HHZ12f

[3.0]
Build ID               20150420160201
Gaia Revision          a8e4f95dce9db727dda5d408b038f97fb4296557
Gaia Date              2015-04-20 19:30:21
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/e7112314d9d5
Gecko Version          40.0a1
Device Name            hammerhead
Firmware(Release)      5.1
Firmware(Incremental)  eng.cltbld.20150420.192508
Firmware Date          Mon Apr 20 19:25:24 EDT 2015
Bootloader             HHZ12f
Status: RESOLVED → VERIFIED
See Also: → 1214139
Device doesn't connect to headset since there's no profile to connect with incorrect cod. The cod update doesn't propagate before the device is created. I'll try to revise the flow.

===
GeckoBluetooth: RemoteDevicePropertiesNotification: 240408   <== got cod update but device isn't created
GeckoBluetooth: BondStateChangedNotification: Bond state: 2 status: 0   <== paired to headset
GeckoBluetooth: ToUint32: major service 1 major device 1f minor device 0
GeckoBluetooth: ConnectDisconnect: aCod 3f00    <== connect gets incorrect (default) cod
GeckoBluetooth: SetupProfiles: cod 3f00: audio 0 rendering 0 peripheral 0 remotecontrol 0 keyboard 0 pointing 0 invalid 0
GeckoBluetooth: StartSession: No queued profile.   <== no profile to connect based on incorrect cod
GeckoBluetooth: EndSession: mSuccess 0
Ignore comment 34. It's for bug 1214139.
See Also: 1214139
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: