2007-05-29 16:11:38

by Emanuele Novelli

[permalink] [raw]
Subject: [Bluez-users] [Bluez Users] Page timeout during sdp on heavy traffic.

Hi

I wrote a little application to simulate an heavy traffic.
Simply discovers devices using hci0 and for each device discovered starts a
thread to search service using hci1.
Rinse and repeat forever.
Usually I have 5-6 bluetooth devices in the area.
I'm not using d-bus messaging (yet) but i guess i'll try that too to check

Anyway I noticed a large number of timeouts during search services on
devices who previously returned correct service record.


hcidump of a usual scenario

this one a correct connect and answer

2007-05-29 16:46:53.268457 < HCI Command: Create Connection (0x01|0x0005)
plen 13
bdaddr 00:17:E2:0A:79:8D ptype 0xcc18 rswitch 0x01 clkoffset 0x0000
Packet type: DM1 DM3 DM5 DH1 DH3 DH5
2007-05-29 16:46:53.290125 > HCI Event: Command Status (0x0f) plen 4
Create Connection (0x01|0x0005) status 0x00 ncmd 1
2007-05-29 16:46:53.653134 > HCI Event: Connect Complete (0x03) plen 11
status 0x00 handle 42 bdaddr 00:17:E2:0A:79:8D type ACL encrypt 0x00
2007-05-29 16:46:53.653155 < ACL data: handle 42 flags 0x02 dlen 12
L2CAP(s): Connect req: psm 1 scid 0x0040
2007-05-29 16:46:53.653161 < HCI Command: Read Remote Supported Features
(0x01|0x001b) plen 2
handle 42
2007-05-29 16:46:53.664138 > HCI Event: Command Status (0x0f) plen 4
Read Remote Supported Features (0x01|0x001b) status 0x00 ncmd 0
2007-05-29 16:46:53.676153 > HCI Event: Number of Completed Packets (0x13)
plen 5
handle 42 packets 1
2007-05-29 16:46:53.678133 > HCI Event: Max Slots Change (0x1b) plen 3
handle 42 slots 5
2007-05-29 16:46:53.687136 > HCI Event: Command Status (0x0f) plen 4
Unknown (0x00|0x0000) status 0x00 ncmd 1
2007-05-29 16:46:53.687155 < HCI Command: Write Link Policy Settings
(0x02|0x000d) plen 4
handle 42 policy 0x0f
Link policy: RSWITCH HOLD SNIFF PARK
2007-05-29 16:46:53.691132 > HCI Event: Command Complete (0x0e) plen 6
Write Link Policy Settings (0x02|0x000d) ncmd 1
status 0x00 handle 42
2007-05-29 16:46:53.691143 < HCI Command: Remote Name Request (0x01|0x0019)
plen 10
bdaddr 00:17:E2:0A:79:8D mode 2 clkoffset 0x0000
2007-05-29 16:46:53.694136 > ACL data: handle 42 flags 0x02 dlen 16
L2CAP(s): Connect rsp: dcid 0x0040 scid 0x0040 result 0 status 0
Connection successful
2007-05-29 16:46:53.694151 < ACL data: handle 42 flags 0x02 dlen 12
L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 0
2007-05-29 16:46:53.696140 > HCI Event: Command Status (0x0f) plen 4
Remote Name Request (0x01|0x0019) status 0x00 ncmd 1
2007-05-29 16:46:53.697137 > ACL data: handle 42 flags 0x02 dlen 16
L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 4
MTU 1024
2007-05-29 16:46:53.697151 < ACL data: handle 42 flags 0x02 dlen 18
L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 4
Success
MTU 1024
2007-05-29 16:46:53.700133 > HCI Event: Read Remote Supported Features
(0x0b) plen 11
status 0x00 handle 42
Features: 0xff 0xfe 0x0d 0x00 0x08 0x08 0x00 0x00
2007-05-29 16:46:53.701140 > HCI Event: Number of Completed Packets (0x13)
plen 5
handle 42 packets 1
2007-05-29 16:46:53.703138 > HCI Event: Number of Completed Packets (0x13)
plen 5
handle 42 packets 1
2007-05-29 16:46:53.714139 > ACL data: handle 42 flags 0x02 dlen 14
L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 0
Success
2007-05-29 16:46:53.714287 < ACL data: handle 42 flags 0x02 dlen 24
L2CAP(d): cid 0x0040 len 20 [psm 1]
SDP SSA Req: tid 0x0 len 0xf
pat uuid-16 0x1105 (OBEXObjPush)
max 65535
aid(s) 0x0000 - 0xffff
cont 00
2007-05-29 16:46:53.723134 > HCI Event: Remote Name Req Complete (0x07) plen
255
status 0x00 bdaddr 00:17:E2:0A:79:8D name 'Motorola PEBL'
2007-05-29 16:46:53.724144 > HCI Event: Number of Completed Packets (0x13)
plen 5
handle 42 packets 1
2007-05-29 16:46:53.979159 > ACL data: handle 42 flags 0x02 dlen 339
2007-05-29 16:46:53.994167 > ACL data: handle 42 flags 0x01 dlen 220
L2CAP(d): cid 0x0040 len 555 [psm 1]
SDP SSA Rsp: tid 0x0 len 0x226
count 547
record #0
aid 0x0000 (SrvRecHndl)
uint 0x10008
aid 0x0001 (SrvClassIDList)
< uuid-16 0x1105 (OBEXObjPush) >
aid 0x0002 (SrvRecState)
uint 0x1
aid 0x0004 (ProtocolDescList)
< < uuid-16 0x0100 (L2CAP) > <
uuid-16 0x0003 (RFCOMM) uint 0x8 > <
uuid-16 0x0008 (OBEX) > >
aid 0x0005 (BrwGrpList)
< uuid-16 0x1002 (PubBrwsGrp) >
aid 0x0006 (LangBaseAttrIDList)
< uint 0x656e uint 0x6a uint 0x100 uint 0x6672 uint 0x6a
uint 0xc800 uint 0x6465 uint 0x6a uint 0xc803 uint 0x6974 uint 0x6a uint
0xc806 uint 0x6573 uint 0x6a uint 0xc809 uint 0x7472 uint 0x6a uint 0xc80c
uint 0x656c uint 0x6a uint 0xc80f >
aid 0x0009 (BTProfileDescList)
< < uuid-16 0x1105 (OBEXObjPush) uint 0x100 > >
aid 0x0100 (SrvName)
str "OBEX Object Push"
aid 0x0101 (SrvDesc)
str "OBEX Object Push"
aid 0x0102 (ProviderName)
str "Motorola"
aid 0x0303 (SuppFormatsList)
< uint 0xff >
aid 0xc800 (unknown)
str "Push objet OBEX"
aid 0xc801 (unknown)
str "Push objet OBEX"
aid 0xc802 (unknown)
str "Motorola"
aid 0xc803 (unknown)
str "OBEX Objekt senden"
aid 0xc804 (unknown)
str "OBEX Objekt senden"
aid 0xc805 (unknown)
str "Motorola"
aid 0xc806 (unknown)
str "Invio oggetto OBEX"
aid 0xc807 (unknown)
str "Invio oggetto OBEX"
aid 0xc808 (unknown)
str "Motorola"
aid 0xc809 (unknown)
str "OBEX Object Push"
aid 0xc80a (unknown)
str "OBEX Object Push"
aid 0xc80b (unknown)
str "Motorola"
aid 0xc80c (unknown)
str "OBEX Object Push"
aid 0xc80d (unknown)
str "OBEX Object Push"
aid 0xc80e (unknown)
str "Motorola"
aid 0xc80f (unknown)
str ce 91 ce bd cf 84 ce b9 ce ba ce b5 ce af ce bc 2e 50
75 73
aid 0xc810 (unknown)
str ce 91 ce bd cf 84 ce b9 ce ba ce b5 ce af ce bc 2e 50
75 73
aid 0xc811 (unknown)
str "Motorola"
cont 00
2007-05-29 16:46:53.994523 < ACL data: handle 42 flags 0x02 dlen 12
L2CAP(s): Disconn req: dcid 0x0040 scid 0x0040
2007-05-29 16:46:54.000158 > HCI Event: Number of Completed Packets (0x13)
plen 5
handle 42 packets 1
2007-05-29 16:46:54.010167 > ACL data: handle 42 flags 0x02 dlen 12
L2CAP(s): Disconn rsp: dcid 0x0040 scid 0x0040
2007-05-29 16:46:56.009566 < HCI Command: Disconnect (0x01|0x0006) plen 3
handle 42 reason 0x13
Reason: Remote User Terminated Connection
2007-05-29 16:46:56.014212 > HCI Event: Command Status (0x0f) plen 4
Disconnect (0x01|0x0006) status 0x00 ncmd 1
2007-05-29 16:46:56.017211 > HCI Event: Disconn Complete (0x05) plen 4
status 0x00 handle 42 reason 0x16
Reason: Connection Terminated by Local Host


this one is a page timeout some minutes later (on the same device)

2007-05-29 16:57:46.372114 < HCI Command: Create Connection (0x01|0x0005)
plen 13
bdaddr 00:17:E2:0A:79:8D ptype 0xcc18 rswitch 0x01 clkoffset 0x0000
Packet type: DM1 DM3 DM5 DH1 DH3 DH5
2007-05-29 16:57:46.393452 > HCI Event: Command Status (0x0f) plen 4
Create Connection (0x01|0x0005) status 0x00 ncmd 1
2007-05-29 16:57:56.397591 > HCI Event: Connect Complete (0x03) plen 11
status 0x04 handle 0 bdaddr 00:17:E2:0A:79:8D type ACL encrypt 0x00
Error: Page Timeout

This happens almost on all devices I contact. I wonder since this is a
rather close loop if something does not close on remote device during the
various attempts or if the problem is on the local HCI. Maybe the page
timeout is from the local device ? (hci1)

Going further ahead with the test the same devices start again answering
without problems and then again they timeout.

Any hint is welcome :)


Attachments:
(No filename) (8.25 kB)
(No filename) (14.57 kB)
(No filename) (286.00 B)
(No filename) (164.00 B)
Download all attachments

2007-05-30 07:58:04

by Marcel Holtmann

[permalink] [raw]
Subject: Re: [Bluez-users] [Bluez Users] Page timeout during sdp on heavy traffic.

Hi Emanuele,

> Maybe I was not clear sorry, the sdp search I do on hci1 is
> serialized. It's a thread started each one a new device is discovered.
> He does 1 sdp search and quit. Then another one is started on next
> device on the list of the discovered ones.

please don't use the word threads if it has nothing to do with your
setup. It confuses people and it confuses me. It is a minor technical
detail.

> I know I cant do inquiry and page at same time but I read elsewhere on
> this forum that using 2 separate hci at once you can actually achieve
> that. But maybe I was wrong if so sorry for the silly question.
> Simply I do inquiry with hci0 (never stops) and each time it finds a
> group devices I start an sdp search on hci1 (1 device at time
> serialized) but as I wrote sometimes this request return page timeout
> while other time it works well as per the hcidump I attached on
> previous message.
> At this time the inquiry is always running (not periodic inquiry
> simply a looped inquiry request)
> That's only to check what's happening on heavy traffic.

So in general that works perfectly fine. Having inquiry on one and
service discovery running on another dongle.

However there are some minor details that needs to taken into account.
The piconets you create with your service discovery need also to be
taken down and this will be done by kernel automatically. This might
interfere with the next page. A sdp_close() will close the SDP session,
but it might still take another 3 seconds or more before the kernel
finally terminates the piconet. Never underestimate this.

Also the name resolving will create a temporary piconet and thus a page
from a different device might fail.

Regards

Marcel



-------------------------------------------------------------------------
This SF.net email is sponsored by DB2 Express
Download DB2 Express C - the FREE version of DB2 express and take
control of your XML. No limits. Just data. Click to get it now.
http://sourceforge.net/powerbar/db2/
_______________________________________________
Bluez-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/bluez-users

2007-05-30 07:36:03

by Emanuele Novelli

[permalink] [raw]
Subject: Re: [Bluez-users] [Bluez Users] Page timeout during sdp on heavy traffic.

2007/5/29, Marcel Holtmann <[email protected]>:
>
> Hi Emanuele,
>
> > I wrote a little application to simulate an heavy traffic.
> > Simply discovers devices using hci0 and for each device discovered
> > starts a thread to search service using hci1.
> > Rinse and repeat forever.
> > Usually I have 5-6 bluetooth devices in the area.
> > I'm not using d-bus messaging (yet) but i guess i'll try that too to
> > check
> >
> > Anyway I noticed a large number of timeouts during search services on
> > devices who previously returned correct service record.
>
> I have no idea how often I have to say that, but you can't page devices
> at the same time. The chips simply don't support that. The same reason
> why you can run an inquiry and page at the same time. It is not
> possible. Period. And this means you have to serialize the SDP service
> requests.
>
> New kernel versions try to handling pending page attempts for piconet
> creation, but that is also limited. And simultaneous name resolve
> request can also cause troubles.
>
> Regards
>
> Marcel
>
>
Maybe I was not clear sorry, the sdp search I do on hci1 is serialized. It's
a thread started each one a new device is discovered. He does 1 sdp search
and quit. Then another one is started on next device on the list of the
discovered ones.

I know I cant do inquiry and page at same time but I read elsewhere on this
forum that using 2 separate hci at once you can actually achieve that. But
maybe I was wrong if so sorry for the silly question.
Simply I do inquiry with hci0 (never stops) and each time it finds a group
devices I start an sdp search on hci1 (1 device at time serialized) but as I
wrote sometimes this request return page timeout while other time it works
well as per the hcidump I attached on previous message.
At this time the inquiry is always running (not periodic inquiry simply a
looped inquiry request)
That's only to check what's happening on heavy traffic.

Is possible that an inquiry and an sdp on 2 separate threads even if on 2
differents hci can cause problems someway during threads context switch?


Attachments:
(No filename) (2.04 kB)
(No filename) (2.42 kB)
(No filename) (286.00 B)
(No filename) (164.00 B)
Download all attachments

2007-05-29 20:20:54

by Marcel Holtmann

[permalink] [raw]
Subject: Re: [Bluez-users] [Bluez Users] Page timeout during sdp on heavy traffic.

Hi Emanuele,

> I wrote a little application to simulate an heavy traffic.
> Simply discovers devices using hci0 and for each device discovered
> starts a thread to search service using hci1.
> Rinse and repeat forever.
> Usually I have 5-6 bluetooth devices in the area.
> I'm not using d-bus messaging (yet) but i guess i'll try that too to
> check
>
> Anyway I noticed a large number of timeouts during search services on
> devices who previously returned correct service record.

I have no idea how often I have to say that, but you can't page devices
at the same time. The chips simply don't support that. The same reason
why you can run an inquiry and page at the same time. It is not
possible. Period. And this means you have to serialize the SDP service
requests.

New kernel versions try to handling pending page attempts for piconet
creation, but that is also limited. And simultaneous name resolve
request can also cause troubles.

Regards

Marcel



-------------------------------------------------------------------------
This SF.net email is sponsored by DB2 Express
Download DB2 Express C - the FREE version of DB2 express and take
control of your XML. No limits. Just data. Click to get it now.
http://sourceforge.net/powerbar/db2/
_______________________________________________
Bluez-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/bluez-users