Closed Bug 1241052 Opened 10 years ago Closed 9 years ago

[emulator] Fix wrong type of SDP type

Categories

(Firefox OS Graveyard :: Bluetooth, defect, P2)

Product:
Firefox OS Graveyard
Component:
Bluetooth
Platform:
ARM
Gonk (Firefox OS)
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED WONTFIX

People

(Reporter: shawnjohnjr, Assigned: shawnjohnjr)

References

Details

Attachments

(10 files)

logcat.txt
165.40 KB, text/plain
Details
pair_ssp_sdp.cfa
5.44 KB, application/octet-stream
Details
with empty sdp attrinbute list
152.10 KB, text/plain
Details
error snoop log with empty attribute list
5.68 KB, text/x-log
Details
pair_sdp_good (1).cfa
16.95 KB, application/octet-stream
Details
Log: 0128-fetchuuid-with-sdpPatch
202.73 KB, text/x-vhdl
Details
Snoop Log: 0202-fetchUuid
5.15 KB, application/octet-stream
Details
Log: 0202-fetchUuid
195.50 KB, text/x-vhdl
Details
Log: 0128-pair-with-patch
181.14 KB, text/x-vhdl
Details
Log: rrrun.log-0219-fetchuuid-with-sdpPatch
207.92 KB, text/x-vhdl
Details
01-20 02:46:03.561 E/bt-hci ( 833): ==== enter btu_hcif_process_event, event from controller = [13] 01-20 02:46:03.561 D/bt-l2cap( 833): TotalWin=0,Hndl=0x21,Quota=1,Unack=1,RRQuota=0,RRUnack=0 01-20 02:46:03.561 D/bt-l2cap( 833): TotalWin=0,LinkUnack(0x21)=1,RRCheck=0,RRUnack=0 01-20 02:46:03.561 I/bt-l2cap( 833): L2CAP - st: CONFIG evt: 15 01-20 02:46:03.561 D/bt-l2cap( 833): l2c_link_adjust_chnl_allocation 01-20 02:46:03.561 D/bt-l2cap( 833): POOL ID:3, GKI_poolcount = 200, reserved_buff = 0, weighted_chnls = 2, quota_per_weighted_chnls = 101 01-20 02:46:03.561 I/bt-l2cap( 833): CID:0x0040 Priority:2 TxDataRate:1 Quota:101 01-20 02:46:03.561 I/bt-l2cap( 833): L2CAP - Calling Config_Rsp_Cb(), CID: 0x0040 01-20 02:46:03.561 I/bt-sdp ( 833): SDP - Rcvd cfg cfm, CID: 0x40 Result: 0 01-20 02:46:03.571 I/bt-l2cap( 833): L2CA_DataWrite() CID: 0x0040 Len: 20 01-20 02:46:03.571 I/bt-l2cap( 833): L2CAP - st: OPEN evt: 30 01-20 02:46:03.571 E/bt-hci ( 833): ==== enter btu_hcif_process_event, event from controller = [13] 01-20 02:46:03.571 D/bt-l2cap( 833): RR scan pri=2, lcid=0x0040, q_cout=1 01-20 02:46:03.571 D/bt-l2cap( 833): RR service pri=2, quota=4, lcid=0x0040 01-20 02:46:03.571 D/bt-l2cap( 833): TotalWin=0,Hndl=0x21,Quota=1,Unack=1,RRQuota=0,RRUnack=0 01-20 02:46:03.571 D/bt-l2cap( 833): TotalWin=0,LinkUnack(0x21)=1,RRCheck=0,RRUnack=0 01-20 02:46:03.581 E/bt-hci ( 833): ==== enter btu_hcif_process_event, event from controller = [13] 01-20 02:46:03.581 D/bt-l2cap( 833): RR scan pri=2, lcid=0x0040, q_cout=0 01-20 02:46:03.581 D/bt-l2cap( 833): TotalWin=1,LinkUnack(0x21)=0,RRCheck=0,RRUnack=0 01-20 02:46:03.581 D/bt-btif ( 833): HC lib lpm deassertion return -1 01-20 02:46:03.581 D/bt-btif ( 833): HC lib lpm deassertion return -1 01-20 02:46:03.581 I/bt-l2cap( 833): L2CAP - st: OPEN evt: 20 01-20 02:46:03.581 W/bt-sdp ( 833): process_service_search_attr_rsp 01-20 02:46:03.581 W/bt-sdp ( 833): SDP - Wrong type: 0x00 in attr_rsp
Blocks: 1175389
PDU Type PDU ID Parameters SDP_ServiceAttributeResponse 0x05 AttributeListByteCount, AttributeList, ContinuationState From the snoop trace, I did not see valid "ContinuationState" in the SDP_ServiceAttributeResponse_PDU. It looks like qemu did not handle it correctly.
Revise dependency to block marionette pairing test bug.
Blocks: 1240992
No longer blocks: 1175389
Priority: -- → P2
Current problem is: When executing SDP_ServiceSearchAttributeResponse, code doesn't set data element type and size descriptor due to UUID PnPInfo is not in the part of attribute list. It just falls into [1], so lst[0], lst[1], lst[2] won't be initialized. Also qemu bt-sdp incorrectly set sdp data element type [2]. It should be: lst[0] = (SDP_DTYPE_SEQ << 3) | SDP_DSIZE_NEXT2 [1]: https://github.com/mozilla-b2g/platform_external_qemu/blob/b2g-kitkat/hw/bt-sdp.c#L465 [2]: https://github.com/mozilla-b2g/platform_external_qemu/blob/b2g-kitkat/hw/bt-sdp.c#L467
Assignee: nobody → shuang
Blocks: 1240989
Solve the first SDP query (PnPInfo request) with empty AttributeIDList. But now it looks like sdp still failed. Need to check further. 01-27 09:09:23.250 I/bt-sdp ( 834): SDP - disconnect CID: 0x40 01-27 09:09:23.250 I/bt-l2cap( 834): L2CA_DisconnectReq() CID: 0x0040 01-27 09:09:23.250 I/bt-l2cap( 834): L2CAP - st: OPEN evt: 27 01-27 09:09:23.250 I/bt-btm ( 834): BTM_SetPowerMode: pm_id 128 BDA: bad00001 mode:0x0 01-27 09:09:23.250 D/bt-btm ( 834): BTM_SetPowerMode: mode:0x0 interval 0 max:8, min:0 01-27 09:09:23.270 D/bt-l2cap( 834): TotalWin=0,Hndl=0x21,Quota=1,Unack=1,RRQuota=0,RRUnack=0 01-27 09:09:23.270 E/bt-hci ( 834): ==== enter btu_hcif_process_event, event from controller = [13] 01-27 09:09:23.270 D/bt-l2cap( 834): RR scan pri=2, lcid=0x0040, q_cout=0 01-27 09:09:23.270 D/bt-l2cap( 834): TotalWin=1,LinkUnack(0x21)=0,RRCheck=0,RRUnack=0 01-27 09:09:23.270 D/bt-btif ( 834): HC lib lpm deassertion return -1 01-27 09:09:23.270 D/bt-btif ( 834): HC lib lpm deassertion return -1 01-27 09:09:23.270 I/bt-l2cap( 834): L2CAP - st: W4_L2CAP_DISC_RSP evt: 18 01-27 09:09:23.270 D/bt-l2cap( 834): l2cu_release_ccb: cid 0x0040 in_use: 1 01-27 09:09:23.270 D/bt-l2cap( 834): l2cu_dequeue_ccb CID: 0x0040 01-27 09:09:23.270 D/bt-l2cap( 834): l2cu_no_dynamic_ccbs() starting IDLE timeout: 4 01-27 09:09:23.270 I/bt-l2cap( 834): L2CAP - Calling DisconnectCfm_Cb(), CID: 0x0040 01-27 09:09:23.270 I/bt-sdp ( 834): SDP - Rcvd L2CAP disc cfm, CID: 0x40 01-27 09:09:23.270 D/bt-sdp ( 834): releasing SDP rsp_list 01-27 09:09:23.270 I/bt-btif ( 834): BTA got event 0x205 01-27 09:09:23.270 I/bt-btif ( 834): bta_dm_search_sm_execute state:3, event:0x205 01-27 09:09:23.270 I/bt-btif ( 834): BTA got event 0x207 01-27 09:09:23.270 I/bt-btif ( 834): bta_dm_search_sm_execute state:3, event:0x207 01-27 09:09:23.270 D/bt-btif ( 834): bta_dm_disc_result 01-27 09:09:23.270 I/bt-btif ( 834): btif_dm_search_services_evt: event = 2 01-27 09:09:23.270 D/bt-btif ( 834): btif_dm_search_services_evt:(result=0x1, services 0x0) 01-27 09:09:23.270 W/bt-btif ( 834): btif_dm_search_services_evt:SDP failed after bonding re-attempting 01-27 09:09:23.270 I/bt-btif ( 834): btif_dm_get_remote_services: remote_addr=ba:be:ba:d0:00:01
After applying SDP patch of Qemu, running marionette test [test_dom_BluetoothDevice.js] will output attached log. Log indicates the "SDP - Wrong type" issue will not be appeared.
Hi Shawn, It's the snoop log today, logcat log will be attached in next comment.
Attached file Log: 0202-fetchUuid —
logcat log mentioned above.
logcat log of [test_dom_BluetoothAdapter_pair.js] after applying SDP patch(with "return 5"). part of patch: + } + if (len == 3 - start) { + fprintf(stderr, "!!!!! %s, SDP_DTYPE_SEQ, len == 3 - start, len: %d, start: %d \n", __FUNCTION__, len, start); + len -= 3; + // test added by shawn + fprintf(stderr, "!!!!! %s Add type \n", __FUNCTION__); + lst[0] = (SDP_DTYPE_SEQ | SDP_DSIZE_NEXT1); + fprintf(stderr, "!!!!! %s, SDP_DTYPE_SEQ, len == 3 - start, type: %d \n", __FUNCTION__, lst[0]); + lst[1] = 0; + // lst[1] = 5 >> 8; + // lst[2] = 5 & 0xff; + + + // directly set Max Attribute Byte Count + rsp[0] = 2 >> 8; + rsp[1] = 2 & 0xff; + // continuation state + lst[3] = 0; + fprintf(stderr, "!!!!! %s, return 5 \n", __FUNCTION__); + return 5; + }
Log of running test test_dom_BluetoothDevice.js for reference. (Latest qemu patch(return 5) + gecko log) No SDP "wrong type" issue. No |RemoteDevicePropertiesNotification| called. Need to dig into the BT stack.
After investigating the log of above comment 14 and SDP spec, even though the first SDP query issue(comment 6) was solved then, I found that SDP still has issue[1] in its [service search] procedure, which is exactly the UUID fetching need for, and this issue result in an assertion failure "unhandled search services event" in function |btif_dm_search_services_evt| of bluetooth stack. Therefore, callback |RemoteDevicePropertiesNotification| in gecko was not called and the upper marionette test(FetchUUID) for bluetooth device failed. Most SDP/UUID related logs are as [2]. [1] 1652 02-19 17:59:52.073 I/bt-btif ( 765): btif_dm_search_services_evt: event = 6 1653 02-19 17:59:52.073 E/ ( 765): ### ASSERT : external/bluetooth/bluedroid/main/../btif/src/btif_dm.c line 1215 unhandled search services event (6) ### [2] 647 02-19 17:59:47.953 D/bt-sdp ( 765): SDP_CreateRecord ok, num_records:4 657 02-19 17:59:47.953 D/bt-btif ( 765): BTA is generating EIR 821 02-19 17:59:48.143 I/bt-btif ( 765): Adding UUID=0x1105 into EIR 823 02-19 17:59:48.143 I/bt-btif ( 765): bta_dm_eir_update_uuid UUID bit mask=0x00000080 04013420 833 02-19 17:59:48.143 D/bt-btif ( 765): PBS: SDP Registered (handle 0x00010009) 844 02-19 17:59:48.173 D/bt-btif ( 765): MAPSS: SDP Registered (handle 0x0001000a) 1351 02-19 17:59:51.683 I/Gecko ( 64): MARIONETTE LOG: INFO: [5] Fetch the UUIDs of remote device ... 1388 02-19 17:59:51.703 I/bt-btif ( 765): btif_dm_get_remote_services: remote_addr=ba:be:ba:d0:00:01 1391 02-19 17:59:51.703 I/bt-btif ( 765): bta_dm_discover services_to_search=0x3FFFFFFF, sdp_search=1 1457 02-19 17:59:51.773 D/bt-btif ( 765): bta_dm_search_cb.services = 3fffffff*********** 1458 02-19 17:59:51.773 E/bt-btif ( 765): services_to_search = 3fffffff 1459 02-19 17:59:51.773 E/bt-btif ( 765): ****************search UUID = 1200*********** 1460 02-19 17:59:51.773 I/bt-sdp ( 765): SDP - Originate started 1514 02-19 17:59:51.903 I/bt-sdp ( 765): SDP - got conn cnf, sent cfg req, CID: 0x40 1540 02-19 17:59:52.013 I/Gecko ( 64): MARIONETTE LOG: INFO: [6] Verify the UUIDs: promise rejected, reason=BtFailError: Fail 1559 02-19 17:59:52.043 D/bt-btif ( 765): cleanup slot:1, fd:30, scn:12, sdp_handle:0x10008 1560 02-19 17:59:52.043 D/bt-btif ( 765): del_rfc_sdp_rec: handle:0x10008 1578 02-19 17:59:52.053 D/bt-sdp ( 765): SDP_DeleteRecord ok, num_records:10 1594 02-19 17:59:52.053 D/bt-sdp ( 765): SDP_DeleteRecord ok, num_records:9 .... 1642 02-19 17:59:52.053 I/bt-btif ( 765): Removing UUID=0x1112 from EIR 1643 02-19 17:59:52.053 I/bt-btif ( 765): bta_dm_eir_update_uuid UUID bit mask=0x00000490 04003420 1652 02-19 17:59:52.073 I/bt-btif ( 765): btif_dm_search_services_evt: event = 6 1653 02-19 17:59:52.073 E/ ( 765): ### ASSERT : external/bluetooth/bluedroid/main/../btif/src/btif_dm.c line 1215 unhandled search services event (6) ### 1692 02-19 17:59:52.153 W/bt-l2cap( 765): L2CAP - PSM: 0x0019 not found for deregistration 1693 02-19 17:59:52.153 W/bt-l2cap( 765): L2CAP - PSM: 0x0017 not found for deregistration 1712 02-19 17:59:52.163 W/bt-sdp ( 765): process_service_search_attr_rsp 1713 02-19 17:59:52.163 I/bt-sdp ( 765): SDP - disconnect CID: 0x40 1754 02-19 17:59:52.203 I/bt-sdp ( 765): SDP - Rcvd L2CAP disc cfm, CID: 0x40 1755 02-19 17:59:52.203 D/bt-sdp ( 765): releasing SDP rsp_list
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → WONTFIX
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: