Hi All,
Hopefully someone can assist me, I have been chasing this issue for a
couple weeks now, and have narrowed it down but I don't have enough
knowledge of the kernel to fix it without breaking other things.
Attached is a BTSnoop file (time 40.312096) of the session if that
would help? I am developing on the 2.6.29 kernel, but I have observed
the same on the latest Ubuntu 9.10 (kernel 2.6.31).
The issue seems to occur when a "encrypt change" occurs during a
connection request (ie. Role Switch). If the device hasn't received
the connection response and a encryption change occurs then the kernel
issues another connection request.
Now, as far as I can tell, it seems that the first connection is
accepted by the remote device but the response hasn't made it to the
kernel by the time it issues the second request (Frontline logs
available to verify). This second request is rejected by the remote
device with "no resources available" as it already has the a valid
connection, leading to a "disconn req". This seems to be very
consistent with my setup.
Any help would be greatly appreciated.
Steve
--------------------------------------------------------------------------------------------------------------------------------
2007-09-20 12:00:51.265985 > ACL data: handle 37 flags 0x02 dlen 8
L2CAP(d): cid 0x0041 len 4 [psm 3]
RFCOMM(s): SABM: cr 1 dlci 4 pf 1 ilen 0 fcs 0x96
2007-09-20 12:00:51.267045 < ACL data: handle 37 flags 0x02 dlen 8
L2CAP(d): cid 0x0041 len 4 [psm 3]
RFCOMM(s): UA: cr 1 dlci 4 pf 1 ilen 0 fcs 0x5d
2007-09-20 12:00:51.267217 < HCI Command: Switch Role (0x02|0x000b) plen 7
bdaddr 00:21:06:30:6E:41 role 0x00
Role: Master
2007-09-20 12:00:51.267290 < ACL data: handle 37 flags 0x02 dlen 12
L2CAP(d): cid 0x0041 len 8 [psm 3]
RFCOMM(s): MSC CMD: cr 0 dlci 0 pf 0 ilen 4 fcs 0xaa mcc_len 2
dlci 4 fc 0 rtc 1 rtr 1 ic 0 dv 1 b1 1 b2 1 b3 0 len 0
2007-09-20 12:00:51.269856 > HCI Event: Command Status (0x0f) plen 4
Switch Role (0x02|0x000b) status 0x00 ncmd 1
2007-09-20 12:00:51.282950 > HCI Event: Encrypt Change (0x08) plen 4
status 0x00 handle 37 encrypt 0x00
2007-09-20 12:00:51.390453 < ACL data: handle 37 flags 0x02 dlen 12
L2CAP(s): Connect req: psm 1 scid 0x0040
2007-09-20 12:00:51.445469 > HCI Event: Role Change (0x12) plen 8
status 0x00 bdaddr 00:21:06:30:6E:41 role 0x00
Role: Master
2007-09-20 12:00:51.456253 > HCI Event: Max Slots Change (0x1b) plen 3
handle 37 slots 5
2007-09-20 12:00:51.518145 > ACL data: handle 37 flags 0x02 dlen 12
L2CAP(s): Connect req: psm 1 scid 0x0040
2007-09-20 12:00:51.518178 > HCI Event: Encrypt Change (0x08) plen 4
status 0x00 handle 37 encrypt 0x01
2007-09-20 12:00:51.518378 < ACL data: handle 37 flags 0x02 dlen 16
L2CAP(s): Connect rsp: dcid 0x0042 scid 0x0040 result 0 status 0
Connection successful
2007-09-20 12:00:51.518414 < ACL data: handle 37 flags 0x02 dlen 12
L2CAP(s): Connect req: psm 1 scid 0x0040
2007-09-20 12:00:51.520523 > HCI Event: Number of Completed Packets
(0x13) plen 5
handle 37 packets 1
2007-09-20 12:00:51.521742 > HCI Event: Number of Completed Packets
(0x13) plen 5
handle 37 packets 1
2007-09-20 12:00:51.522730 > HCI Event: Number of Completed Packets
(0x13) plen 5
handle 37 packets 1
2007-09-20 12:00:51.524349 > ACL data: handle 37 flags 0x02 dlen 12
L2CAP(d): cid 0x0041 len 8 [psm 3]
RFCOMM(s): MSC CMD: cr 1 dlci 0 pf 0 ilen 4 fcs 0x70 mcc_len 2
dlci 4 fc 0 rtc 1 rtr 1 ic 0 dv 1 b1 1 b2 1 b3 0 len 0
2007-09-20 12:00:51.524381 > HCI Event: Number of Completed Packets
(0x13) plen 5
handle 37 packets 1
2007-09-20 12:00:51.525940 > ACL data: handle 37 flags 0x02 dlen 12
L2CAP(d): cid 0x0041 len 8 [psm 3]
RFCOMM(s): MSC RSP: cr 1 dlci 0 pf 0 ilen 4 fcs 0x70 mcc_len 2
dlci 4 fc 0 rtc 1 rtr 1 ic 0 dv 1 b1 1 b2 1 b3 0 len 0
2007-09-20 12:00:51.525974 > HCI Event: Number of Completed Packets
(0x13) plen 5
handle 37 packets 1
2007-09-20 12:00:51.526759 > ACL data: handle 37 flags 0x02 dlen 16
L2CAP(s): Connect rsp: dcid 0x0042 scid 0x0040 result 0 status 0
Connection successful
2007-09-20 12:00:51.526853 < ACL data: handle 37 flags 0x02 dlen 12
L2CAP(s): Config req: dcid 0x0042 flags 0x00 clen 0
2007-09-20 12:00:51.528239 > ACL data: handle 37 flags 0x02 dlen 16
L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 4
MTU 1024
2007-09-20 12:00:51.528336 < ACL data: handle 37 flags 0x02 dlen 18
L2CAP(s): Config rsp: scid 0x0042 flags 0x00 result 0 clen 4
MTU 1024
2007-09-20 12:00:51.529564 > ACL data: handle 37 flags 0x02 dlen 16
L2CAP(s): Config req: dcid 0x0042 flags 0x00 clen 4
MTU 1024
2007-09-20 12:00:51.529694 < ACL data: handle 37 flags 0x02 dlen 18
L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 4
MTU 1024
2007-09-20 12:00:51.529771 < ACL data: handle 37 flags 0x02 dlen 12
L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 0
2007-09-20 12:00:51.530532 > ACL data: handle 37 flags 0x02 dlen 16
L2CAP(s): Connect rsp: dcid 0x0043 scid 0x0040 result 4 status 0
Connection refused - no resources available
2007-09-20 12:00:51.531946 > HCI Event: Number of Completed Packets
(0x13) plen 5
handle 37 packets 1
2007-09-20 12:00:51.532963 > HCI Event: Number of Completed Packets
(0x13) plen 5
handle 37 packets 1