Hi!
I recently found a strange behaviour...
I have a device which accepts an RFCOMM connection on channel 1.
Creating the connection works just fine and I can basically communicate.
But as soon as larger chunks of data are sent (something like 128 bytes
at a time) it starts to take a pretty long time to transfer it (in the
range of about a second). The connection stays connected and data can be
sent but at a very slow pace.
This is from a 2.6.39 kernel to the device, my PC has a Bluetooth3.0 USB
device.
The interesting part is that if I try the same thing from an HTC G1
phone it works as expected, i.e. "fast". I tried to compare the HCI
settings between the HTC G1 and my notebook and did the same on my
notebook which did not help (the only obvious difference was disabled
PARK mode and a slightly different ACL MTU).
It is pretty likely that the device also has an RFCOMM bug here but
since it works with the HTC phone it must be possible to make it work
with my notebook too.
Any hint would be very much appreciated ;)
Thanks!
Cheers
nils
--
kernel concepts GbR Tel: +49-271-771091-12
Sieghuetter Hauptweg 48
D-57072 Siegen Mob: +49-176-21024535
http://www.kernelconcepts.de
Am 24.07.2011 21:20, schrieb Peter Hurley:
> On Sun, 2011-07-24 at 14:42 -0400, Nils Faerber wrote:
>> Am 24.07.2011 19:58, schrieb Nils Faerber:
>>> Am 24.07.2011 19:06, schrieb Peter Hurley:
>>>> 1. What does an hcidump -tX of the session say?
>>>
>>> The complete log would be a little longer.
>>> Is there something special that I could watch for?
> ...
>>
>> Why does the hcidump from Linux not show RFCOMM(d) parts like the G1 dump?
>
> The new l2cap code now sets the first ACL data packet
> Packet_Boundary_Flag to 'not automatically flushable' on l2cap channels
> not marked flushable (the default is not flushable).
>
> The decode of this in hcidump was fixed back in February.
OK, great, with a new one I see the RFCOMM now, thanks!
I also found another hint towards the RFCOMM lag...
If I disable SNIFF on the Linux side it behaves normal again. Once it
has entered SNIFF mode for the first time the connection starts to lag.
So I am almost suspecting not an RFCOMM but rather HCI/SNIFF issue and
this is most likely caused by the Bluetooth device rather the Linux
host. I just can not come up with an explanation why it work including
SNIFF from the older HTC G1 - there the Linux kernel is for sure much
older than on my notebook. Did something concerning SNIFF mode change
more or less recently?
> Regards,
> Peter
Cheers
nils
--
kernel concepts GbR Tel: +49-271-771091-12
Sieghuetter Hauptweg 48
D-57072 Siegen Mob: +49-176-21024535
http://www.kernelconcepts.de
T24gU3VuLCAyMDExLTA3LTI0IGF0IDE0OjQyIC0wNDAwLCBOaWxzIEZhZXJiZXIgd3JvdGU6DQo+
IEFtIDI0LjA3LjIwMTEgMTk6NTgsIHNjaHJpZWIgTmlscyBGYWVyYmVyOg0KPiA+IEFtIDI0LjA3
LjIwMTEgMTk6MDYsIHNjaHJpZWIgUGV0ZXIgSHVybGV5Og0KPiA+PiAxLiBXaGF0IGRvZXMgYW4g
aGNpZHVtcCAtdFggb2YgdGhlIHNlc3Npb24gc2F5Pw0KPiA+IA0KPiA+IFRoZSBjb21wbGV0ZSBs
b2cgd291bGQgYmUgYSBsaXR0bGUgbG9uZ2VyLg0KPiA+IElzIHRoZXJlIHNvbWV0aGluZyBzcGVj
aWFsIHRoYXQgSSBjb3VsZCB3YXRjaCBmb3I/DQouLi4NCj4gDQo+IFdoeSBkb2VzIHRoZSBoY2lk
dW1wIGZyb20gTGludXggbm90IHNob3cgUkZDT01NKGQpIHBhcnRzIGxpa2UgdGhlIEcxIGR1bXA/
DQoNClRoZSBuZXcgbDJjYXAgY29kZSBub3cgc2V0cyB0aGUgZmlyc3QgQUNMIGRhdGEgcGFja2V0
DQpQYWNrZXRfQm91bmRhcnlfRmxhZyB0byAnbm90IGF1dG9tYXRpY2FsbHkgZmx1c2hhYmxlJyBv
biBsMmNhcCBjaGFubmVscw0Kbm90IG1hcmtlZCBmbHVzaGFibGUgKHRoZSBkZWZhdWx0IGlzIG5v
dCBmbHVzaGFibGUpLg0KDQpUaGUgZGVjb2RlIG9mIHRoaXMgaW4gaGNpZHVtcCB3YXMgZml4ZWQg
YmFjayBpbiBGZWJydWFyeS4gDQoNClJlZ2FyZHMsDQpQZXRlcg0K
Am 24.07.2011 19:58, schrieb Nils Faerber:
> Am 24.07.2011 19:06, schrieb Peter Hurley:
>> 1. What does an hcidump -tX of the session say?
>
> The complete log would be a little longer.
> Is there something special that I could watch for?
>
> Here an excerpt:
>
> 1311530163.994927 > HCI Event: Number of Completed Packets (0x13) plen 5
> 0000: 01 0c 00 01 00 .....
> 1311530165.033926 > ACL data: handle 12 flags 0x02 dlen 9
> L2CAP(d): cid 0x0040 len 5 [psm 0]
> 0000: 09 ff 01 02 5c ....\
> 1311530165.034148 < ACL data: handle 12 flags 0x00 dlen 40
> 0000: 24 00 43 00 0b ef 41 01 20 40 00 57 60 00 00 03 $.C...A. @.W`...
> 0010: fc 01 00 07 00 00 00 00 58 60 00 00 fe ff 01 80 ........X`......
> 0020: 03 00 00 00 00 d7 af 9a ........
> 1311530165.034254 < ACL data: handle 12 flags 0x00 dlen 39
> 0000: 23 00 43 00 0b ef 3f 01 20 40 00 59 60 00 00 fc #.C...?. @.Y`...
> 0010: ff 01 e0 01 00 00 00 00 5a c0 00 00 fc ff 01 38 ........Z......8
> 0020: 00 00 00 00 00 cc 9a .......
> 1311530165.244924 > HCI Event: Number of Completed Packets (0x13) plen 5
> 0000: 01 0c 00 01 00 .....
> 1311530166.494919 > HCI Event: Number of Completed Packets (0x13) plen 5
> 0000: 01 0c 00 01 00 .....
> 1311530167.594936 > ACL data: handle 12 flags 0x02 dlen 9
> L2CAP(d): cid 0x0040 len 5 [psm 0]
> 0000: 09 ff 01 02 5c ....\
Strangely the dump from the Android G1 looks pretty different (and better):
1311284173.980396 > HCI Event: Number of Completed Packets (0x13) plen 5
0000: 01 01 00 01 00 .....
1311284174.009115 > ACL data: handle 1 flags 0x02 dlen 9
L2CAP(d): cid 0x0041 len 5 [psm 3]
RFCOMM(d): UIH: cr 0 dlci 2 pf 1 ilen 0 fcs 0x5c credits 2
1311284174.012621 < ACL data: handle 1 flags 0x02 dlen 40
L2CAP(d): cid 0x0043 len 36 [psm 3]
RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 32 fcs 0x9a
0000: 01 20 40 01 5a 00 00 00 00 00 00 00 00 00 00 00 .
@.Z...........
0010: 00 5b 00 00 00 00 00 00 00 00 00 00 00 00 dd a4
.[..............
1311284174.016646 > HCI Event: Number of Completed Packets (0x13) plen 5
0000: 01 01 00 01 00 .....
1311284174.048780 < ACL data: handle 1 flags 0x02 dlen 40
L2CAP(d): cid 0x0043 len 36 [psm 3]
RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 32 fcs 0x9a
0000: 01 20 40 01 5c 00 00 00 00 00 00 00 00 00 00 00 .
@.\...........
0010: 00 5d 00 00 00 00 00 00 00 00 00 00 00 00 98 90
.]..............
Why does the hcidump from Linux not show RFCOMM(d) parts like the G1 dump?
Pretty strange...
>> Regards,
>> Peter
Cheers
nils
--
kernel concepts GbR Tel: +49-271-771091-12
Sieghuetter Hauptweg 48
D-57072 Siegen Mob: +49-176-21024535
http://www.kernelconcepts.de
Am 24.07.2011 19:06, schrieb Peter Hurley:
> Hi Nils,
Hi Peter!
First, thanks for the fast reply!
> On Sun, 2011-07-24 at 12:22 -0400, Nils Faerber wrote:
>> I recently found a strange behaviour...
> ...
>> But as soon as larger chunks of data are sent (something like 128 bytes
>> at a time) it starts to take a pretty long time to transfer it (in the
>> range of about a second). The connection stays connected and data can be
>> sent but at a very slow pace.
>> This is from a 2.6.39 kernel to the device, my PC has a Bluetooth3.0 USB
>> device.
> ....
>> It is pretty likely that the device also has an RFCOMM bug here but
>> since it works with the HTC phone it must be possible to make it work
>> with my notebook too.
>>
>> Any hint would be very much appreciated ;)
>
> 1. What does an hcidump -tX of the session say?
The complete log would be a little longer.
Is there something special that I could watch for?
Here an excerpt:
1311530163.994927 > HCI Event: Number of Completed Packets (0x13) plen 5
0000: 01 0c 00 01 00 .....
1311530165.033926 > ACL data: handle 12 flags 0x02 dlen 9
L2CAP(d): cid 0x0040 len 5 [psm 0]
0000: 09 ff 01 02 5c ....\
1311530165.034148 < ACL data: handle 12 flags 0x00 dlen 40
0000: 24 00 43 00 0b ef 41 01 20 40 00 57 60 00 00 03 $.C...A. @.W`...
0010: fc 01 00 07 00 00 00 00 58 60 00 00 fe ff 01 80 ........X`......
0020: 03 00 00 00 00 d7 af 9a ........
1311530165.034254 < ACL data: handle 12 flags 0x00 dlen 39
0000: 23 00 43 00 0b ef 3f 01 20 40 00 59 60 00 00 fc #.C...?. @.Y`...
0010: ff 01 e0 01 00 00 00 00 5a c0 00 00 fc ff 01 38 ........Z......8
0020: 00 00 00 00 00 cc 9a .......
1311530165.244924 > HCI Event: Number of Completed Packets (0x13) plen 5
0000: 01 0c 00 01 00 .....
1311530166.494919 > HCI Event: Number of Completed Packets (0x13) plen 5
0000: 01 0c 00 01 00 .....
1311530167.594936 > ACL data: handle 12 flags 0x02 dlen 9
L2CAP(d): cid 0x0040 len 5 [psm 0]
0000: 09 ff 01 02 5c ....\
> 2. What flow control is being used?
You mean the serial port flow control on the RFCOMM channel?
>From my Linux app I do not use any handshake. On the G1 I can not check
since the Android app seems to go through the socket interface instead
of the /dev/rfcomm device.
> 3. What does the log say when bluetoothd is in debug mode?
In how far is bluetooth involved in the rfcomm conection? The
establishment is done manually using the rfcomm cmdline utility.
> That's where I would start...
>
> Regards,
> Peter
Cheers
nils
--
kernel concepts GbR Tel: +49-271-771091-12
Sieghuetter Hauptweg 48
D-57072 Siegen Mob: +49-176-21024535
http://www.kernelconcepts.de
SGkgTmlscywNCg0KT24gU3VuLCAyMDExLTA3LTI0IGF0IDEyOjIyIC0wNDAwLCBOaWxzIEZhZXJi
ZXIgd3JvdGU6DQo+IEhpIQ0KPiBJIHJlY2VudGx5IGZvdW5kIGEgc3RyYW5nZSBiZWhhdmlvdXIu
Li4NCi4uLg0KPiBCdXQgYXMgc29vbiBhcyBsYXJnZXIgY2h1bmtzIG9mIGRhdGEgYXJlIHNlbnQg
KHNvbWV0aGluZyBsaWtlIDEyOCBieXRlcw0KPiBhdCBhIHRpbWUpIGl0IHN0YXJ0cyB0byB0YWtl
IGEgcHJldHR5IGxvbmcgdGltZSB0byB0cmFuc2ZlciBpdCAoaW4gdGhlDQo+IHJhbmdlIG9mIGFi
b3V0IGEgc2Vjb25kKS4gVGhlIGNvbm5lY3Rpb24gc3RheXMgY29ubmVjdGVkIGFuZCBkYXRhIGNh
biBiZQ0KPiBzZW50IGJ1dCBhdCBhIHZlcnkgc2xvdyBwYWNlLg0KPiBUaGlzIGlzIGZyb20gYSAy
LjYuMzkga2VybmVsIHRvIHRoZSBkZXZpY2UsIG15IFBDIGhhcyBhIEJsdWV0b290aDMuMCBVU0IN
Cj4gZGV2aWNlLg0KLi4uLg0KPiBJdCBpcyBwcmV0dHkgbGlrZWx5IHRoYXQgdGhlIGRldmljZSBh
bHNvIGhhcyBhbiBSRkNPTU0gYnVnIGhlcmUgYnV0DQo+IHNpbmNlIGl0IHdvcmtzIHdpdGggdGhl
IEhUQyBwaG9uZSBpdCBtdXN0IGJlIHBvc3NpYmxlIHRvIG1ha2UgaXQgd29yaw0KPiB3aXRoIG15
IG5vdGVib29rIHRvby4NCj4gDQo+IEFueSBoaW50IHdvdWxkIGJlIHZlcnkgbXVjaCBhcHByZWNp
YXRlZCA7KQ0KDQoxLiBXaGF0IGRvZXMgYW4gaGNpZHVtcCAtdFggb2YgdGhlIHNlc3Npb24gc2F5
Pw0KMi4gV2hhdCBmbG93IGNvbnRyb2wgaXMgYmVpbmcgdXNlZD8NCjMuIFdoYXQgZG9lcyB0aGUg
bG9nIHNheSB3aGVuIGJsdWV0b290aGQgaXMgaW4gZGVidWcgbW9kZT8NCg0KVGhhdCdzIHdoZXJl
IEkgd291bGQgc3RhcnQuLi4NCg0KUmVnYXJkcywNClBldGVyDQo=