2009-02-03 15:51:53

by Frederic Danis

[permalink] [raw]
Subject: BlueZ pairing failure and kernel 2.6.24 crash

HCI sniffer - Bluetooth packet analyzer ver 1.40
device: hci0 snap_len: 1028 filter: 0xffffffff
2008-12-08 18:59:46.112548 < HCI Command: Create Connection (0x01|0x0005) plen 13
bdaddr 00:0A:D9:14:D0:85 ptype 0xcc18 rswitch 0x01 clkoffset 0x0000
Packet type: DM1 DM3 DM5 DH1 DH3 DH5
2008-12-08 18:59:46.118621 > HCI Event: Command Status (0x0f) plen 4
Create Connection (0x01|0x0005) status 0x00 ncmd 1
2008-12-08 18:59:46.861053 > HCI Event: Connect Complete (0x03) plen 11
status 0x00 handle 1 bdaddr 00:0A:D9:14:D0:85 type ACL encrypt 0x00
2008-12-08 18:59:46.861145 < ACL data: handle 1 flags 0x02 dlen 10
L2CAP(s): Info req: type 2
2008-12-08 18:59:46.861175 < HCI Command: Read Remote Supported Features (0x01|0x001b) plen 2
handle 1
2008-12-08 18:59:46.861694 > HCI Event: Command Status (0x0f) plen 4
Unknown (0x00|0x0000) status 0x00 ncmd 2
2008-12-08 18:59:46.861724 < HCI Command: Write Link Policy Settings (0x02|0x000d) plen 4
handle 1 policy 0x07
Link policy: RSWITCH HOLD SNIFF
2008-12-08 18:59:46.865875 > HCI Event: Command Status (0x0f) plen 4
Read Remote Supported Features (0x01|0x001b) status 0x00 ncmd 1
2008-12-08 18:59:46.865936 < HCI Command: Remote Name Request (0x01|0x0019) plen 10
bdaddr 00:0A:D9:14:D0:85 mode 2 clkoffset 0x0000
2008-12-08 18:59:46.869110 > HCI Event: Command Status (0x0f) plen 4
Remote Name Request (0x01|0x0019) status 0x0c ncmd 0
Error: Command Disallowed
2008-12-08 18:59:46.927276 > HCI Event: Max Slots Change (0x1b) plen 3
handle 1 slots 5
2008-12-08 18:59:46.952514 > HCI Event: Number of Completed Packets (0x13) plen 5
handle 1 packets 1
2008-12-08 18:59:46.956176 > ACL data: handle 1 flags 0x02 dlen 10
L2CAP(s): Command rej: reason 0
Command not understood
2008-12-08 18:59:46.956970 > HCI Event: Read Remote Supported Features (0x0b) plen 11
status 0x00 handle 1
Features: 0xff 0xfb 0x01 0x00 0x00 0x00 0x00 0x00
2008-12-08 18:59:46.960357 > HCI Event: Command Status (0x0f) plen 4
Unknown (0x00|0x0000) status 0x00 ncmd 1
2008-12-08 18:59:46.960418 < HCI Command: Authentication Requested (0x01|0x0011) plen 2
handle 1
2008-12-08 18:59:46.961029 > HCI Event: Command Complete (0x0e) plen 6
Write Link Policy Settings (0x02|0x000d) ncmd 2
status 0x00 handle 1
2008-12-08 18:59:46.963562 > HCI Event: Command Status (0x0f) plen 4
Authentication Requested (0x01|0x0011) status 0x00 ncmd 1
2008-12-08 18:59:46.964233 > HCI Event: Link Key Request (0x17) plen 6
bdaddr 00:0A:D9:14:D0:85
2008-12-08 18:59:46.972442 < HCI Command: Link Key Request Negative Reply (0x01|0x000c) plen 6
bdaddr 00:0A:D9:14:D0:85
2008-12-08 18:59:46.977661 > HCI Event: Command Complete (0x0e) plen 10
Link Key Request Negative Reply (0x01|0x000c) ncmd 1
status 0x00 bdaddr 00:0A:D9:14:D0:85
2008-12-08 18:59:46.978271 > HCI Event: PIN Code Request (0x16) plen 6
bdaddr 00:0A:D9:14:D0:85
2008-12-08 18:59:51.145141 > HCI Event: Auth Complete (0x06) plen 3
status 0x05 handle 1
Error: Authentication Failure
2008-12-08 18:59:51.145690 > HCI Event: Command Status (0x0f) plen 4
Unknown (0x00|0x0000) status 0x00 ncmd 2
2008-12-08 18:59:51.176605 > HCI Event: Disconn Complete (0x05) plen 4
status 0x00 handle 1 reason 0x13
Reason: Remote User Terminated Connection


Attachments:
P800-traces.txt (3.26 kB)
l2cap_info_req_remove.diff (351.00 B)
Download all attachments

2009-02-26 16:05:19

by Marcel Holtmann

[permalink] [raw]
Subject: Re: BlueZ pairing failure and kernel 2.6.24 crash

Hi Frederic,

> >>> I am working with BlueZ 3.22, kernel 2.6.24 on ARM and found 2
> >>> problems :
> >>>
> >>> - I am not able to pair with some phones (Nokia N70 and
> >>> sony-ericsson P800). After some investigations, I found that a "L2CAP
> >>> information request packet" is sent just after the ACL connection.
> >>> Both phones reply with "command rejected" error, then disconnect the
> >>> ACL link before BlueZ is able to finish the pairing (see attached
> >>> traces).
> >>>
> >>> - with some other phones (LG 990 Viewty and sony-ericsson T610), the
> >>> kernel crashes after pairing initiated by the phone is completed.
> >>>
> >>> For the first problem I removed the send of the "L2CAP information
> >>> request packet" in the kernel (see attached patch). This fixes both
> >>> problems.
> >>>
> >>> I did not found any usage of the remote L2CAP information in kernel.
> >>> Is sending "L2CAP information request packet" mandatory for upper
> >>> layer and/or qualification ?
> >>> Is my fix OK ?
> >>
> >> sending the L2CAP info is just fine. It should not cause any problems. I
> >> think it is the pairing code that does some weird things at the wrong
> >> time. Can you test with bluetooth-testing.git against bluez-4.28 to
> >> verify that this issue still exists.
> >
> > I try multiple configuration to test these 2 problems :
> >
> > - pairing out failure with P800 or N70 :
> > - Ubuntu 8.04 + kernel 2.6.24.23 + BlueZ 3.26 => unable to pair (see
> > Ubuntu804_Bluez326_traces.txt)
> > - Ubuntu 8.04 + kernel 2.6.24.23 + BlueZ 4.28 => unable to pair (see
> > Ubuntu804_Bluez428_traces.txt)
> > - Ubuntu 8.10 + kernel 2.6.27.11 + BlueZ 4.12 => pairing OK (see
> > Ubuntu810_Bluez412_traces.txt)
> >
> > To perform pairing I use :
> > BlueZ 3.26 : dbus-send --system --type=method_call --print-reply
> > --dest=org.bluez /org/bluez/hci1 org.bluez.Adapter.CreateBonding
> > string:00:0A:D9:14:D0:85
> > BlueZ 4.xx : bluez-4.xx/test/simple-agent hci0 00:0A:D9:14:D0:85
> >
> > - kernel crash with LG 990 :
> > - Ubuntu 8.04 + kernel 2.6.24.23 + BlueZ 3.26 => Ubuntu freeze (kernel
> > crash)
> > - Ubuntu 8.04 + kernel 2.6.24.23 + BlueZ 4.28 => Ubuntu freeze (kernel
> > crash)
> > - Ubuntu 8.10 + kernel 2.6.27.11 + BlueZ 4.12 => pairing OK
> >
> > So, for me, it seems to be a problem in the kernel 2.6.24.
> > What is your opinion ?
> >
> > Unfortunately, I am not able to change kernel version. Do you have any
> > idea how to fix this, please ? Is my fix OK ?
> >
>
> Do you have any idea how to fix this, please ? Is my fix OK ?
> Is there any problem (interoperability, qualification, ...) to remove L2CAP info request ?

you don't have to do the information request, but then you have to make
sure that you do this the right way. Otherwise you mess with the state
machine of L2CAP.

Have you ever looked at the patches from bluetooth-testing.git, because
I did fix a couple of race conditions that came up when implementing the
information request support. They only show when using non-blocking
L2CAP sockets.

Regards

Marcel



2009-02-26 09:48:44

by Frederic Danis

[permalink] [raw]
Subject: Re: BlueZ pairing failure and kernel 2.6.24 crash

Hello Marcel,
> Hello Marcel,
>> Hi Frederic,
>>
>>> I am working with BlueZ 3.22, kernel 2.6.24 on ARM and found 2
>>> problems :
>>>
>>> - I am not able to pair with some phones (Nokia N70 and
>>> sony-ericsson P800). After some investigations, I found that a "L2CAP
>>> information request packet" is sent just after the ACL connection.
>>> Both phones reply with "command rejected" error, then disconnect the
>>> ACL link before BlueZ is able to finish the pairing (see attached
>>> traces).
>>>
>>> - with some other phones (LG 990 Viewty and sony-ericsson T610), the
>>> kernel crashes after pairing initiated by the phone is completed.
>>>
>>> For the first problem I removed the send of the "L2CAP information
>>> request packet" in the kernel (see attached patch). This fixes both
>>> problems.
>>>
>>> I did not found any usage of the remote L2CAP information in kernel.
>>> Is sending "L2CAP information request packet" mandatory for upper
>>> layer and/or qualification ?
>>> Is my fix OK ?
>>
>> sending the L2CAP info is just fine. It should not cause any problems. I
>> think it is the pairing code that does some weird things at the wrong
>> time. Can you test with bluetooth-testing.git against bluez-4.28 to
>> verify that this issue still exists.
>
> I try multiple configuration to test these 2 problems :
>
> - pairing out failure with P800 or N70 :
> - Ubuntu 8.04 + kernel 2.6.24.23 + BlueZ 3.26 => unable to pair (see
> Ubuntu804_Bluez326_traces.txt)
> - Ubuntu 8.04 + kernel 2.6.24.23 + BlueZ 4.28 => unable to pair (see
> Ubuntu804_Bluez428_traces.txt)
> - Ubuntu 8.10 + kernel 2.6.27.11 + BlueZ 4.12 => pairing OK (see
> Ubuntu810_Bluez412_traces.txt)
>
> To perform pairing I use :
> BlueZ 3.26 : dbus-send --system --type=method_call --print-reply
> --dest=org.bluez /org/bluez/hci1 org.bluez.Adapter.CreateBonding
> string:00:0A:D9:14:D0:85
> BlueZ 4.xx : bluez-4.xx/test/simple-agent hci0 00:0A:D9:14:D0:85
>
> - kernel crash with LG 990 :
> - Ubuntu 8.04 + kernel 2.6.24.23 + BlueZ 3.26 => Ubuntu freeze (kernel
> crash)
> - Ubuntu 8.04 + kernel 2.6.24.23 + BlueZ 4.28 => Ubuntu freeze (kernel
> crash)
> - Ubuntu 8.10 + kernel 2.6.27.11 + BlueZ 4.12 => pairing OK
>
> So, for me, it seems to be a problem in the kernel 2.6.24.
> What is your opinion ?
>
> Unfortunately, I am not able to change kernel version. Do you have any
> idea how to fix this, please ? Is my fix OK ?
>
> Regards
>
> Fred
>
>

Do you have any idea how to fix this, please ? Is my fix OK ?
Is there any problem (interoperability, qualification, ...) to remove L2CAP info request ?

Regards

Fred

--
-----------------------------------------------
It is not by improving the oil lamp that one invents the electric bulb!
-----------------------------------------------
Danis Frederic Access Company
Software engineer
Mail : mailto:[email protected]
-----------------------------------------------

2009-02-05 15:57:30

by Frederic Danis

[permalink] [raw]
Subject: Re: BlueZ pairing failure and kernel 2.6.24 crash

< HCI Command: Create Connection (0x01|0x0005) plen 13
bdaddr 00:0A:D9:14:D0:85 ptype 0xcc18 rswitch 0x01 clkoffset 0x0000
Packet type: DM1 DM3 DM5 DH1 DH3 DH5
> HCI Event: Command Status (0x0f) plen 4
Create Connection (0x01|0x0005) status 0x00 ncmd 1
> HCI Event: Connect Complete (0x03) plen 11
status 0x00 handle 43 bdaddr 00:0A:D9:14:D0:85 type ACL encrypt 0x00
< HCI Command: Read Remote Supported Features (0x01|0x001b) plen 2
handle 43
> HCI Event: Command Status (0x0f) plen 4
Read Remote Supported Features (0x01|0x001b) status 0x00 ncmd 0
> HCI Event: Max Slots Change (0x1b) plen 3
handle 43 slots 5
> HCI Event: Command Status (0x0f) plen 4
Unknown (0x00|0x0000) status 0x00 ncmd 1
< HCI Command: Remote Name Request (0x01|0x0019) plen 10
bdaddr 00:0A:D9:14:D0:85 mode 2 clkoffset 0x0000
> HCI Event: Read Remote Supported Features (0x0b) plen 11
status 0x00 handle 43
Features: 0xff 0xfb 0x01 0x00 0x00 0x00 0x00 0x00
> HCI Event: Command Status (0x0f) plen 4
Remote Name Request (0x01|0x0019) status 0x00 ncmd 1
< HCI Command: Authentication Requested (0x01|0x0011) plen 2
handle 43
> HCI Event: Remote Name Req Complete (0x07) plen 255
status 0x00 bdaddr 00:0A:D9:14:D0:85 name 'P800 sqa'
> HCI Event: Command Status (0x0f) plen 4
Authentication Requested (0x01|0x0011) status 0x00 ncmd 1
> HCI Event: Link Key Request (0x17) plen 6
bdaddr 00:0A:D9:14:D0:85
< HCI Command: Link Key Request Negative Reply (0x01|0x000c) plen 6
bdaddr 00:0A:D9:14:D0:85
> HCI Event: Command Complete (0x0e) plen 10
Link Key Request Negative Reply (0x01|0x000c) ncmd 1
status 0x00 bdaddr 00:0A:D9:14:D0:85
> HCI Event: PIN Code Request (0x16) plen 6
bdaddr 00:0A:D9:14:D0:85
< HCI Command: PIN Code Request Reply (0x01|0x000d) plen 23
bdaddr 00:0A:D9:14:D0:85 len 1 pin '1'
> HCI Event: Command Complete (0x0e) plen 10
PIN Code Request Reply (0x01|0x000d) ncmd 1
status 0x00 bdaddr 00:0A:D9:14:D0:85
> HCI Event: Link Key Notification (0x18) plen 23
bdaddr 00:0A:D9:14:D0:85 key A904972E67A25A6104783725A3D09F3B type 0
Type: Combination Key
> HCI Event: Auth Complete (0x06) plen 3
status 0x00 handle 43
< ACL data: handle 43 flags 0x02 dlen 10
L2CAP(s): Info req: type 2
> HCI Event: Number of Completed Packets (0x13) plen 5
handle 43 packets 1
> ACL data: handle 43 flags 0x02 dlen 10
L2CAP(s): Command rej: reason 0
Command not understood
< ACL data: handle 43 flags 0x02 dlen 12
L2CAP(s): Connect req: psm 1 scid 0x0040
> HCI Event: Number of Completed Packets (0x13) plen 5
handle 43 packets 1
> ACL data: handle 43 flags 0x02 dlen 16
L2CAP(s): Connect rsp: dcid 0x0040 scid 0x0040 result 1 status 2
Connection pending - Authorization pending
> ACL data: handle 43 flags 0x02 dlen 16
L2CAP(s): Connect rsp: dcid 0x0040 scid 0x0040 result 0 status 0
Connection successful
< ACL data: handle 43 flags 0x02 dlen 12
L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 0
> ACL data: handle 43 flags 0x02 dlen 12
L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 0
< ACL data: handle 43 flags 0x02 dlen 18
L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 4
MTU 672
> HCI Event: Number of Completed Packets (0x13) plen 5
handle 43 packets 1
> HCI Event: Number of Completed Packets (0x13) plen 5
handle 43 packets 1
> ACL data: handle 43 flags 0x02 dlen 14
L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 0
Success
< ACL data: handle 43 flags 0x02 dlen 24
L2CAP(d): cid 0x0040 len 20 [psm 1]
SDP SSA Req: tid 0x0 len 0xf
pat uuid-16 0x1002 (PubBrwsGrp)
max 65535
aid(s) 0x0000 - 0xffff
cont 00
> HCI Event: Number of Completed Packets (0x13) plen 5
handle 43 packets 1
> ACL data: handle 43 flags 0x02 dlen 17
> ACL data: handle 43 flags 0x01 dlen 34
> ACL data: handle 43 flags 0x01 dlen 51
> ACL data: handle 43 flags 0x01 dlen 85
> ACL data: handle 43 flags 0x01 dlen 136
> ACL data: handle 43 flags 0x01 dlen 187
> ACL data: handle 43 flags 0x01 dlen 32
L2CAP(d): cid 0x0040 len 538 [psm 1]
SDP SSA Rsp: tid 0x0 len 0x215
count 530
record #0
aid 0x0000 (SrvRecHndl)
uint 0x10000
aid 0x0001 (SrvClassIDList)
< uuid-16 0x1112 (Headset AG) uuid-16 0x1203 (Audio) >
aid 0x0002 (SrvRecState)
uint 0x9
aid 0x0004 (ProtocolDescList)
< < uuid-16 0x0100 (L2CAP) > <
uuid-16 0x0003 (RFCOMM) uint 0x8 > >
aid 0x0005 (BrwGrpList)
< uuid-16 0x1002 (PubBrwsGrp) >
aid 0x0006 (LangBaseAttrIDList)
< uint 0x656e uint 0x6a uint 0x100 >
aid 0x0008 (SrvAvail)
uint 0xff
aid 0x0009 (BTProfileDescList)
< < uuid-16 0x1108 (Headset) uint 0x100 > >
aid 0x0100 (SrvName)
str "Voice gateway"
aid 0x0101 (SrvDesc)
str "Voice gateway"
aid 0x0102 (ProviderName)
str "Sony Ericsson"
record #1
aid 0x0000 (SrvRecHndl)
uint 0x10001
aid 0x0001 (SrvClassIDList)
< uuid-16 0x1101 (SP) >
aid 0x0002 (SrvRecState)
uint 0x9
aid 0x0004 (ProtocolDescList)
< < uuid-16 0x0100 (L2CAP) > <
uuid-16 0x0003 (RFCOMM) uint 0x1 > >
aid 0x0005 (BrwGrpList)
< uuid-16 0x1002 (PubBrwsGrp) >
aid 0x0006 (LangBaseAttrIDList)
< uint 0x656e uint 0x6a uint 0x100 >
aid 0x0007 (SrvInfoTimeToLive)
uint 0x4b0
aid 0x0008 (SrvAvail)
uint 0xff
aid 0x0100 (SrvName)
str "Bluetooth Serial Port"
aid 0x0101 (SrvDesc)
str "Bluetooth Serial Port"
aid 0x0102 (ProviderName)
str "Symbian Ltd."
record #2
aid 0x0000 (SrvRecHndl)
uint 0x10002
aid 0x0001 (SrvClassIDList)
< uuid-16 0x1103 (DUN) >
aid 0x0002 (SrvRecState)
uint 0xa
aid 0x0004 (ProtocolDescList)
< < uuid-16 0x0100 (L2CAP) > <
uuid-16 0x0003 (RFCOMM) uint 0x2 > >
aid 0x0005 (BrwGrpList)
< uuid-16 0x1002 (PubBrwsGrp) >
aid 0x0006 (LangBaseAttrIDList)
< uint 0x656e uint 0x6a uint 0x100 >
aid 0x0008 (SrvAvail)
uint 0xff
aid 0x0009 (BTProfileDescList)
< < uuid-16 0x1103 (DUN) uint 0x100 > >
aid 0x0100 (SrvName)
str "Dial-up Networking"
aid 0x0101 (SrvDesc)
str "Dial-up Networking"
aid 0x0102 (ProviderName)
str "Sony Ericsson"
record #3
aid 0x0000 (SrvRecHndl)
uint 0x10003
aid 0x0001 (SrvClassIDList)
< uuid-16 0x1105 (OBEXObjPush) >
aid 0x0004 (ProtocolDescList)
< < uuid-16 0x0100 (L2CAP) > <
uuid-16 0x0003 (RFCOMM) uint 0x3 > <
uuid-16 0x0008 (OBEX) > >
aid 0x0005 (BrwGrpList)
< uuid-16 0x1002 (PubBrwsGrp) >
aid 0x0009 (BTProfileDescList)
< < uuid-16 0x1105 (OBEXObjPush) uint 0x100 > >
aid 0x0100 (SrvName)
str "OBEX Object Push"
aid 0x0303 (SuppFormatsList)
< uint 0x1 uint 0x3 uint 0xff >
cont 00
< ACL data: handle 43 flags 0x02 dlen 12
L2CAP(s): Disconn req: dcid 0x0040 scid 0x0040
> HCI Event: Number of Completed Packets (0x13) plen 5
handle 43 packets 1
> ACL data: handle 43 flags 0x02 dlen 12
L2CAP(s): Disconn rsp: dcid 0x0040 scid 0x0040
< HCI Command: Disconnect (0x01|0x0006) plen 3
handle 43 reason 0x13
Reason: Remote User Terminated Connection
> HCI Event: Command Status (0x0f) plen 4
Disconnect (0x01|0x0006) status 0x00 ncmd 1
> HCI Event: Disconn Complete (0x05) plen 4
status 0x00 handle 43 reason 0x16
Reason: Connection Terminated by Local Host


Attachments:
Ubuntu804_Bluez326_traces.txt (2.61 kB)
Ubuntu804_Bluez428_traces.txt (2.66 kB)
Ubuntu810_Bluez412_traces.txt (8.27 kB)
Download all attachments

2009-02-04 18:34:26

by Marcel Holtmann

[permalink] [raw]
Subject: Re: BlueZ pairing failure and kernel 2.6.24 crash

Hi Frederic,

> I am working with BlueZ 3.22, kernel 2.6.24 on ARM and found 2 problems :
>
> - I am not able to pair with some phones (Nokia N70 and sony-ericsson
> P800). After some investigations, I found that a "L2CAP information
> request packet" is sent just after the ACL connection. Both phones reply
> with "command rejected" error, then disconnect the ACL link before BlueZ
> is able to finish the pairing (see attached traces).
>
> - with some other phones (LG 990 Viewty and sony-ericsson T610), the
> kernel crashes after pairing initiated by the phone is completed.
>
> For the first problem I removed the send of the "L2CAP information
> request packet" in the kernel (see attached patch). This fixes both
> problems.
>
> I did not found any usage of the remote L2CAP information in kernel.
> Is sending "L2CAP information request packet" mandatory for upper layer
> and/or qualification ?
> Is my fix OK ?

sending the L2CAP info is just fine. It should not cause any problems. I
think it is the pairing code that does some weird things at the wrong
time. Can you test with bluetooth-testing.git against bluez-4.28 to
verify that this issue still exists.

Regards

Marcel