Hi, Gustavo, 2011/1/20 Liang Bao <tim.bao@xxxxxxxxx>: > 2011/1/20 Gustavo F. Padovan <padovan@xxxxxxxxxxxxxx>: >> Hi Bao, >> >> * tim.bao@xxxxxxxxx <tim.bao@xxxxxxxxx> [2011-01-19 21:22:09 +0800]: >> >>> From: Bao Liang <tim.bao@xxxxxxxxx> >>> >>> This patch fixes a minor issue that two connection responses will be sent >>> for one L2CAP connection request. If the L2CAP connection request is first >>> blocked due to security reason and responded with reason "security block", >>> the state of the connection remains BT_CONNECT2. If a pairing procedure >>> completes successfully before the ACL connection is down, local host will >>> send another connection complete response. See the following packets >>> captured by hcidump. >>> >>> 2010-12-07 22:21:24.928096 < ACL data: handle 12 flags 0x00 dlen 16 >>> 0000: 0c 00 01 00 03 19 08 00 41 00 53 00 03 00 00 00 ........A.S..... >>> ... ... >>> >>> 2010-12-07 22:21:35.791747 > HCI Event: Auth Complete (0x06) plen 3 >>> status 0x00 handle 12 >>> ... ... >>> >>> 2010-12-07 22:21:35.872372 > ACL data: handle 12 flags 0x02 dlen 16 >>> L2CAP(s): Connect rsp: dcid 0x0054 scid 0x0040 result 0 status 0 >>> Connection successful >> >> Please provide a more helpful hcidump showing at least the connection request >> and the two connection response. > Sure, here's the full log of one try with the following steps: > - Unpair from the host side while KB is connected.(2010-12-07 22:21:13.133047) > - Press the "Connect" button of Logitech V470, the mouse will try to > connect back although it's put into discoverable mode > meanwhile(2010-12-07 22:21:24.459891). > - HID control channel will be asked to UNPLUG but the HID interrupt > channel will be refused for reason security block. See 2010-12-07 > 22:21:24.928096 - no idea why it's not decoded into ASCII format by > hcidump but FTS4BT can decode it as "Result: Refused - Security > block" > - Quickly start pair from phone side before the ACL link is down. For > dev purpose, the ACL timeout is increased but the phenomenon is still > observable with a starndard version if start pair quickly enough. > Pairing will complete without error. See 2010-12-07 22:21:35.791747 > - Immediately after "auth complete", host side will respond to the > V470 with "connection successful". See 2010-12-07 22:21:35.872372 > > I also post log of multiple tries (including this) to > http://pastebin.com/TPHgNUKd for your reference. > > It's not a big issue and connection can be finally made by a second > try in most cases. However, removing this will set the state to closed > because the host actually declined the connection request and hence a > second rsp to the l2cap_conn_req shall not be sent. Just my two cents. > > 2010-12-07 22:21:13.099872 > HCI Event: Disconn Complete (0x05) plen 4 > status 0x00 handle 11 reason 0x16 > Reason: Connection Terminated by Local Host > 2010-12-07 22:21:13.125585 < HCI Command: Delete Stored Link Key > (0x03|0x0012) plen 7 > bdaddr 00:1F:20:01:C9:B8 all 0 > 2010-12-07 22:21:13.133047 > HCI Event: Command Complete (0x0e) plen 6 > Delete Stored Link Key (0x03|0x0012) ncmd 1 > status 0x00 deleted 0 > 2010-12-07 22:21:24.459891 > HCI Event: Connect Request (0x04) plen 10 > bdaddr 00:1F:20:01:C9:B8 class 0x002580 type ACL > 2010-12-07 22:21:24.460063 < HCI Command: Accept Connection Request > (0x01|0x0009) plen 7 > bdaddr 00:1F:20:01:C9:B8 role 0x00 > Role: Master > 2010-12-07 22:21:24.470041 > HCI Event: Command Status (0x0f) plen 4 > Accept Connection Request (0x01|0x0009) status 0x00 ncmd 1 > 2010-12-07 22:21:24.629984 > HCI Event: Role Change (0x12) plen 8 > status 0x00 bdaddr 00:1F:20:01:C9:B8 role 0x00 > Role: Master > 2010-12-07 22:21:24.780008 > HCI Event: Connect Complete (0x03) plen 11 > status 0x00 handle 12 bdaddr 00:1F:20:01:C9:B8 type ACL encrypt 0x00 > 2010-12-07 22:21:24.780135 < HCI Command: Read Remote Supported > Features (0x01|0x001b) plen 2 > handle 12 > 2010-12-07 22:21:24.792511 > HCI Event: Command Status (0x0f) plen 4 > Read Remote Supported Features (0x01|0x001b) status 0x00 ncmd 1 > 2010-12-07 22:21:24.792546 > HCI Event: Read Remote Supported Features > (0x0b) plen 11 > status 0x00 handle 12 > Features: 0xbc 0x02 0x04 0x38 0x08 0x00 0x00 0x00 > 2010-12-07 22:21:24.815529 > ACL data: handle 12 flags 0x02 dlen 12 > L2CAP(s): Connect req: psm 17 scid 0x0052 > 2010-12-07 22:21:24.815727 < ACL data: handle 12 flags 0x00 dlen 16 > 0C 00 01 00 03 17 08 00 40 00 52 00 01 00 00 00 > 2010-12-07 22:21:24.815848 < ACL data: handle 12 flags 0x00 dlen 10 > 06 00 01 00 0A 01 02 00 02 00 > 2010-12-07 22:21:24.822141 < HCI Command: Remote Name Request > (0x01|0x0019) plen 10 > bdaddr 00:1F:20:01:C9:B8 mode 2 clkoffset 0x0000 > 2010-12-07 22:21:24.832574 > HCI Event: Number of Completed Packets > (0x13) plen 5 > handle 12 packets 2 > 2010-12-07 22:21:24.832597 > HCI Event: Command Status (0x0f) plen 4 > Remote Name Request (0x01|0x0019) status 0x00 ncmd 1 > 2010-12-07 22:21:24.832602 > ACL data: handle 12 flags 0x02 dlen 16 > L2CAP(s): Info rsp: type 2 result 0 > Extended feature mask 0x0004 > Bi-directional QoS > 2010-12-07 22:21:24.832756 < ACL data: handle 12 flags 0x00 dlen 16 > 0C 00 01 00 03 17 08 00 40 00 52 00 00 00 00 00 > 2010-12-07 22:21:24.879811 > ACL data: handle 12 flags 0x02 dlen 16 > L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 4 > MTU 185 > 2010-12-07 22:21:24.879871 < ACL data: handle 12 flags 0x00 dlen 18 > 0E 00 01 00 05 18 0A 00 52 00 00 00 00 00 01 02 B9 00 > 2010-12-07 22:21:24.879960 < ACL data: handle 12 flags 0x00 dlen 12 > 08 00 01 00 04 02 04 00 52 00 00 00 > 2010-12-07 22:21:24.899815 > HCI Event: Number of Completed Packets > (0x13) plen 5 > handle 12 packets 2 > 2010-12-07 22:21:24.899828 > HCI Event: Remote Name Req Complete (0x07) plen 255 > status 0x00 bdaddr 00:1F:20:01:C9:B8 name 'Bluetooth Laser Travel Mouse' > 2010-12-07 22:21:24.919852 > ACL data: handle 12 flags 0x02 dlen 18 > L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 4 > Success > MTU 185 > 2010-12-07 22:21:24.919865 > ACL data: handle 12 flags 0x02 dlen 12 > L2CAP(s): Connect req: psm 19 scid 0x0053 > 2010-12-07 22:21:24.919951 < ACL data: handle 12 flags 0x00 dlen 16 > 0C 00 01 00 03 19 08 00 41 00 53 00 01 00 02 00 > 2010-12-07 22:21:24.920192 < ACL data: handle 12 flags 0x00 dlen 5 > 01 00 52 00 15 > 2010-12-07 22:21:24.920308 < ACL data: handle 12 flags 0x00 dlen 12 > 08 00 01 00 06 03 04 00 52 00 40 00 > 2010-12-07 22:21:24.928096 < ACL data: handle 12 flags 0x00 dlen 16 > 0C 00 01 00 03 19 08 00 41 00 53 00 03 00 00 00 > 2010-12-07 22:21:24.929844 > HCI Event: Number of Completed Packets > (0x13) plen 5 > handle 12 packets 2 > 2010-12-07 22:21:24.929857 > HCI Event: Number of Completed Packets > (0x13) plen 5 > handle 12 packets 2 > 2010-12-07 22:21:24.939857 > ACL data: handle 12 flags 0x02 dlen 12 > L2CAP(s): Disconn rsp: dcid 0x0052 scid 0x0040 > 2010-12-07 22:21:25.109941 > HCI Event: Number of Completed Packets > (0x13) plen 5 > handle 12 packets 1 > 2010-12-07 22:21:27.273753 < HCI Command: Authentication Requested > (0x01|0x0011) plen 2 > handle 12 > 2010-12-07 22:21:27.290059 > HCI Event: Command Status (0x0f) plen 4 > Authentication Requested (0x01|0x0011) status 0x00 ncmd 1 > 2010-12-07 22:21:27.290081 > HCI Event: Link Key Request (0x17) plen 6 > bdaddr 00:1F:20:01:C9:B8 > 2010-12-07 22:21:27.291243 < HCI Command: Link Key Request Negative > Reply (0x01|0x000c) plen 6 > bdaddr 00:1F:20:01:C9:B8 > 2010-12-07 22:21:27.300072 > HCI Event: Command Complete (0x0e) plen 10 > Link Key Request Negative Reply (0x01|0x000c) ncmd 1 > status 0x00 bdaddr 00:1F:20:01:C9:B8 > 2010-12-07 22:21:27.300101 > HCI Event: PIN Code Request (0x16) plen 6 > bdaddr 00:1F:20:01:C9:B8 > 2010-12-07 22:21:35.678564 < HCI Command: PIN Code Request Reply > (0x01|0x000d) plen 23 > bdaddr 00:1F:20:01:C9:B8 len 4 pin '0000' > 2010-12-07 22:21:35.692679 > HCI Event: Command Complete (0x0e) plen 10 > PIN Code Request Reply (0x01|0x000d) ncmd 1 > status 0x00 bdaddr 00:1F:20:01:C9:B8 > 2010-12-07 22:21:35.791738 > HCI Event: Link Key Notification (0x18) plen 23 > bdaddr 00:1F:20:01:C9:B8 key EFA3DFDFC773E2B4C5D5C3E409DA84A9 type 0 > 2010-12-07 22:21:35.791747 > HCI Event: Auth Complete (0x06) plen 3 > status 0x00 handle 12 > 2010-12-07 22:21:35.791829 < ACL data: handle 12 flags 0x00 dlen 16 > 0C 00 01 00 03 19 08 00 41 00 53 00 00 00 00 00 > 2010-12-07 22:21:35.817243 < ACL data: handle 12 flags 0x00 dlen 12 > 08 00 01 00 02 04 04 00 01 00 40 00 > 2010-12-07 22:21:35.832388 > HCI Event: Number of Completed Packets > (0x13) plen 5 > handle 12 packets 2 > 2010-12-07 22:21:35.872372 > ACL data: handle 12 flags 0x02 dlen 16 > L2CAP(s): Connect rsp: dcid 0x0054 scid 0x0040 result 0 status 0 > Connection successful > 2010-12-07 22:21:35.872429 < ACL data: handle 12 flags 0x00 dlen 12 > 08 00 01 00 04 05 04 00 54 00 00 00 > 2010-12-07 22:21:35.902318 > ACL data: handle 12 flags 0x02 dlen 18 > L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 4 > Success > MTU 185 > 2010-12-07 22:21:35.902330 > ACL data: handle 12 flags 0x02 dlen 16 > L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 4 > MTU 185 > 2010-12-07 22:21:35.902407 < ACL data: handle 12 flags 0x00 dlen 18 > 0E 00 01 00 05 1A 0A 00 54 00 00 00 00 00 01 02 B9 00 > 2010-12-07 22:21:35.902707 < ACL data: handle 12 flags 0x00 dlen 24 > 14 00 54 00 06 00 00 00 0F 35 03 19 01 00 FF FF 35 05 0A 00 > 00 FF FF 00 > 2010-12-07 22:21:35.923249 > HCI Event: Number of Completed Packets > (0x13) plen 5 > handle 12 packets 2 > 2010-12-07 22:21:36.042451 > ACL data: handle 12 flags 0x02 dlen 27 > 2010-12-07 22:21:36.042480 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.042487 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.052466 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.052485 > ACL data: handle 12 flags 0x01 dlen 24 > L2CAP(d): cid 0x0040 len 128 [psm 0] > 07 00 00 00 7B 00 76 36 01 C0 36 01 60 09 00 00 0A 00 01 00 > 00 09 00 01 35 03 19 11 24 09 00 04 35 0D 35 06 19 01 00 09 > 00 11 35 03 19 00 11 09 00 05 35 03 19 10 02 09 00 06 35 09 > 09 65 6E 09 00 6A 09 01 00 09 00 09 35 08 35 06 19 11 24 09 > 01 00 09 00 0D 35 0F 35 0D 35 06 19 01 00 09 00 13 35 03 19 > 00 11 09 01 00 25 22 4C 6F 67 69 74 65 63 68 20 56 34 37 30 > 20 43 6F 72 64 02 00 76 > 2010-12-07 22:21:36.053674 < ACL data: handle 12 flags 0x00 dlen 26 > 16 00 54 00 06 00 01 00 11 35 03 19 01 00 FF FF 35 05 0A 00 > 00 FF FF 02 00 76 > 2010-12-07 22:21:36.062537 > HCI Event: Number of Completed Packets > (0x13) plen 5 > handle 12 packets 2 > 2010-12-07 22:21:36.180597 > ACL data: handle 12 flags 0x02 dlen 27 > 2010-12-07 22:21:36.180613 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.180621 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.180625 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.192515 > ACL data: handle 12 flags 0x01 dlen 24 > L2CAP(d): cid 0x0040 len 128 [psm 0] > 07 00 01 00 7B 00 76 6C 65 73 73 20 4C 61 73 65 72 20 4D 6F > 75 73 65 09 01 01 25 0F 42 6C 75 65 74 6F 6F 74 68 20 4D 6F > 75 73 65 09 01 02 25 08 4C 6F 67 69 74 65 63 68 09 02 00 09 > 01 00 09 02 01 09 01 11 09 02 02 08 80 09 02 03 08 21 09 02 > 04 28 01 09 02 05 28 01 09 02 06 35 68 35 66 08 22 25 62 05 > 01 09 02 A1 01 85 02 09 01 A1 00 05 09 19 01 29 08 15 00 25 > 01 75 01 95 08 02 00 EC > 2010-12-07 22:21:36.193599 < ACL data: handle 12 flags 0x00 dlen 26 > 16 00 54 00 06 00 02 00 11 35 03 19 01 00 FF FF 35 05 0A 00 > 00 FF FF 02 00 EC > 2010-12-07 22:21:36.300605 > ACL data: handle 12 flags 0x02 dlen 27 > 2010-12-07 22:21:36.300622 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.312521 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.312539 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.312543 > ACL data: handle 12 flags 0x01 dlen 24 > L2CAP(d): cid 0x0040 len 128 [psm 0] > 07 00 02 00 7B 00 76 81 02 05 01 09 30 09 31 16 01 F8 26 FF > 07 75 0C 95 02 81 06 09 38 15 81 25 7F 75 08 95 01 81 06 05 > 0C 0A 38 02 75 08 95 01 81 06 C0 C0 06 00 FF 09 01 A1 01 85 > 10 75 08 95 06 15 00 26 FF 00 09 01 81 00 09 01 91 00 C0 09 > 02 07 35 08 35 06 09 04 09 09 01 00 09 02 08 28 00 09 02 09 > 28 01 09 02 0A 28 01 09 02 0B 09 01 00 09 02 0C 09 0C 80 09 > 02 0D 28 00 09 02 01 62 > 2010-12-07 22:21:36.313630 < ACL data: handle 12 flags 0x00 dlen 26 > 16 00 54 00 06 00 03 00 11 35 03 19 01 00 FF FF 35 05 0A 00 > 00 FF FF 02 01 62 > 2010-12-07 22:21:36.322432 > HCI Event: Number of Completed Packets > (0x13) plen 5 > handle 12 packets 2 > 2010-12-07 22:21:36.440618 > ACL data: handle 12 flags 0x02 dlen 27 > 2010-12-07 22:21:36.440635 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.440639 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.440643 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.452517 > ACL data: handle 12 flags 0x01 dlen 1 > L2CAP(d): cid 0x0040 len 105 [psm 0] > 07 00 03 00 64 00 61 02 0E 28 01 36 00 5A 09 00 00 0A 00 01 > 00 01 09 00 01 35 03 19 12 00 09 00 04 35 0D 35 06 19 01 00 > 09 00 01 35 03 19 00 01 09 00 05 35 03 19 10 02 09 00 09 35 > 08 35 06 19 12 00 09 01 00 09 02 00 09 01 00 09 02 01 09 04 > 6D 09 02 02 09 B0 08 09 02 03 09 03 17 09 02 04 28 01 09 02 > 05 09 00 02 00 > 2010-12-07 22:21:36.484591 < ACL data: handle 12 flags 0x00 dlen 24 > 14 00 54 00 06 00 04 00 0F 35 03 19 12 00 FF FF 35 05 0A 00 > 00 FF FF 00 > 2010-12-07 22:21:36.592512 > ACL data: handle 12 flags 0x02 dlen 27 > 2010-12-07 22:21:36.592536 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.592540 > ACL data: handle 12 flags 0x01 dlen 27 > 2010-12-07 22:21:36.592550 > ACL data: handle 12 flags 0x01 dlen 27 > L2CAP(d): cid 0x0040 len 104 [psm 0] > 07 00 04 00 63 00 60 36 00 5D 36 00 5A 09 00 00 0A 00 01 00 > 01 09 00 01 35 03 19 12 00 09 00 04 35 0D 35 06 19 01 00 09 > 00 01 35 03 19 00 01 09 00 05 35 03 19 10 02 09 00 09 35 08 > 35 06 19 12 00 09 01 00 09 02 00 09 01 00 09 02 01 09 04 6D > 09 02 02 09 B0 08 09 02 03 09 03 17 09 02 04 28 01 09 02 05 > 09 00 02 00 > 2010-12-07 22:21:36.666846 < ACL data: handle 12 flags 0x00 dlen 12 > 08 00 01 00 02 06 04 00 11 00 42 00 > 2010-12-07 22:21:36.672425 > HCI Event: Number of Completed Packets > (0x13) plen 5 > handle 12 packets 2 > 2010-12-07 22:21:36.702399 > ACL data: handle 12 flags 0x02 dlen 16 > L2CAP(s): Connect rsp: dcid 0x0000 scid 0x0042 result 4 status 0 > Connection refused - no resources available > 2010-12-07 22:21:38.422526 > ACL data: handle 12 flags 0x02 dlen 12 > L2CAP(s): Disconn req: dcid 0x0040 scid 0x0054 > 2010-12-07 22:21:38.422675 < ACL data: handle 12 flags 0x00 dlen 12 > 08 00 01 00 07 1B 04 00 40 00 54 00 > 2010-12-07 22:21:38.602501 > HCI Event: Number of Completed Packets > (0x13) plen 5 > handle 12 packets 1 > 2010-12-07 22:21:38.602523 > HCI Event: Disconn Complete (0x05) plen 4 > status 0x00 handle 12 reason 0x16 > Reason: Connection Terminated by Local Host Please let me know if there's any information needed. Thanks. >> >> -- >> Gustavo F. Padovan >> http://profusion.mobi >> > -- To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
