Skip site navigation (1)Skip section navigation (2)
Date:      Fri, 12 Oct 2012 16:49:41 +0200
From:      Andreas Longwitz <longwitz@incore.de>
To:        Iain Hibbert <plunky@rya-online.net>
Cc:        freebsd-bluetooth@freebsd.org
Subject:   Re: btpand problem
Message-ID:  <50782E05.5080005@incore.de>
In-Reply-To: <alpine.NEB.2.00.1210120949170.628@galant.ukfsn.org>
References:  <507736A8.4050605@incore.de> <BDA3CA14-92C0-414E-9D55-E96EA7A73312@gmail.com> <5077490F.7010901@incore.de> <CAFPOs6pF51wy9PvKLn4-OnrOqo8hU1S=P5PzTFwgUppBjqAtuA@mail.gmail.com> <alpine.NEB.2.00.1210120949170.628@galant.ukfsn.org>

next in thread | previous in thread | raw e-mail | index | archive | help
Hi,

> Is this more than one connection, can you show the entire dump? (the first
> one is a rsp from the other side, then it sends a req later..?)

I have only one connection: the dump gives the output of the command
   btpand -a panserver -d me -s NAP -i tap1. Full dump:

HCIDump - HCI packet analyzer ver 1.5
  < HCI Command: Create Connection(0x01|0x0005) plen 13
  > HCI Event: Command Status(0x0f) plen 4
  > HCI Event: Role Change(0x12) plen 8
  > HCI Event: Connect Complete(0x03) plen 11
  < HCI Command: Write Link Policy Settings(0x02|0x000d) plen 4
  < ACL data: handle 0x002a flags 0x02 dlen 12
     L2CAP(s): Connect req: psm 1 scid 0x004f
  > HCI Event: Max Slots Change(0x1b) plen 3
  > HCI Event: Number of Completed Packets(0x13) plen 5
  > HCI Event: Command Complete(0x0e) plen 6
  > ACL data: handle 0x002a flags 0x02 dlen 10
     L2CAP(s): Info req: dlen 2
  < ACL data: handle 0x002a flags 0x02 dlen 12
     L2CAP(s): Info rsp: dlen 4
  > HCI Event: Number of Completed Packets(0x13) plen 5
  > ACL data: handle 0x002a flags 0x02 dlen 16
     L2CAP(s): Connect rsp: dcid 0x0103 scid 0x004f result 0 status 0
  < ACL data: handle 0x002a flags 0x02 dlen 12
     L2CAP(s): Config req: dcid 0x0103 flags 0x0000 clen 0
  > HCI Event: Number of Completed Packets(0x13) plen 5
  > ACL data: handle 0x002a flags 0x02 dlen 18
     L2CAP(s): Config rsp: scid 0x004f flags 0x0000 result 0 clen 4
     MTU 672
  > ACL data: handle 0x002a flags 0x02 dlen 16
     L2CAP(s): Config req: dcid 0x004f flags 0x0000 clen 4
     MTU 256
  < ACL data: handle 0x002a flags 0x02 dlen 14
     L2CAP(s): Config rsp: scid 0x0103 flags 0x0000 result 0 clen 0
  < ACL data: handle 0x002a flags 0x02 dlen 24
     L2CAP(d): cid 0x103 len 20 [psm 1]
         SDP SSA Req: tid 0x0 len 0xf
           pat uuid-16 0x1116 (NAP)
           max 0xffff
           aid(s) 0x0004 (ProtocolDescList)
           cont 00
  > HCI Event: Number of Completed Packets(0x13) plen 5
  > HCI Event: Number of Completed Packets(0x13) plen 5
  > ACL data: handle 0x002a flags 0x02 dlen 51
     L2CAP(d): cid 0x4f len 47 [psm 1]
         SDP SSA Rsp: tid 0x0 len 0x2a
           cnt 0x27
           srv rec #0
             aid 0x0004 (ProtocolDescList)
                 < < uuid-16 0x0100 (L2CAP) uint 0xf  > <
                uuid-16 0x000f (BNEP) uint 0x100  < uint 0x800 uint 
0x806 uint 0x8100 uint 0x86dd  > > >

           cont 00
  < ACL data: handle 0x002a flags 0x02 dlen 12
     L2CAP(s): Disconn req: dcid 0x0103 scid 0x004f
  < ACL data: handle 0x002a flags 0x02 dlen 12
     L2CAP(s): Connect req: psm 15 scid 0x0050
  > HCI Event: Number of Completed Packets(0x13) plen 5
  > ACL data: handle 0x002a flags 0x02 dlen 12
     L2CAP(s): Disconn rsp: dcid 0x0103 scid 0x004f
  > HCI Event: Number of Completed Packets(0x13) plen 5
  > ACL data: handle 0x002a flags 0x02 dlen 16
     L2CAP(s): Connect rsp: dcid 0x0203 scid 0x0050 result 1 status 1
  > HCI Event: Link Key Request(0x17) plen 6
  < HCI Command: Link Key Request Reply(0x01|0x000b) plen 22
  > HCI Event: Command Complete(0x0e) plen 10
  > HCI Event: Encrypt Change(0x08) plen 4
  > ACL data: handle 0x002a flags 0x02 dlen 16
     L2CAP(s): Connect rsp: dcid 0x0203 scid 0x0050 result 0 status 0
  < ACL data: handle 0x002a flags 0x02 dlen 16
     L2CAP(s): Config req: dcid 0x0203 flags 0x0000 clen 4
     MTU 1691
  > HCI Event: Number of Completed Packets(0x13) plen 5
  > ACL data: handle 0x002a flags 0x02 dlen 18
     L2CAP(s): Config rsp: scid 0x0050 flags 0x0000 result 0 clen 4
     MTU 1691
  > ACL data: handle 0x002a flags 0x02 dlen 16
     L2CAP(s): Config req: dcid 0x0050 flags 0x0000 clen 4
     MTU 1691
  < ACL data: handle 0x002a flags 0x02 dlen 14
     L2CAP(s): Config rsp: scid 0x0203 flags 0x0000 result 0 clen 0
  < ACL data: handle 0x002a flags 0x02 dlen 11
     L2CAP(d): cid 0x203 len 7 [psm 15]
       BNEP: Control(0x01|0)
         Setup Req(0x01) size 0x02 dst 0x1116(NAP) src 0x1115(PANU)
  > HCI Event: Number of Completed Packets(0x13) plen 5
  > HCI Event: Number of Completed Packets(0x13) plen 5
  > ACL data: handle 0x002a flags 0x02 dlen 8
     L2CAP(d): cid 0x50 len 4 [psm 15]
       BNEP: Control(0x01|0)
         Setup Rsp(0x02) res 0x0000
  < ACL data: handle 0x002a flags 0x02 dlen 341
     L2CAP(d): cid 0x203 len 337 [psm 15]
       BNEP: Compressed DestOnly(0x04|0)
         dst ff:ff:ff:ff:ff:ff [proto 0x0800]
  > HCI Event: Number of Completed Packets(0x13) plen 5
  > HCI Event: Mode Change(0x14) plen 6
  < ACL data: handle 0x002a flags 0x02 dlen 341
     L2CAP(d): cid 0x203 len 337 [psm 15]
       BNEP: Compressed DestOnly(0x04|0)
         dst ff:ff:ff:ff:ff:ff [proto 0x0800]
  > HCI Event: Number of Completed Packets(0x13) plen 5
  < ACL data: handle 0x002a flags 0x02 dlen 341
     L2CAP(d): cid 0x203 len 337 [psm 15]
       BNEP: Compressed DestOnly(0x04|0)
         dst ff:ff:ff:ff:ff:ff [proto 0x0800]
  > HCI Event: Number of Completed Packets(0x13) plen 5
  < ACL data: handle 0x002a flags 0x02 dlen 341
     L2CAP(d): cid 0x203 len 337 [psm 15]
       BNEP: Compressed DestOnly(0x04|0)
         dst ff:ff:ff:ff:ff:ff [proto 0x0800]
  > HCI Event: Number of Completed Packets(0x13) plen 5
  < ACL data: handle 0x002a flags 0x02 dlen 341
     L2CAP(d): cid 0x203 len 337 [psm 15]
       BNEP: Compressed DestOnly(0x04|0)
         dst ff:ff:ff:ff:ff:ff [proto 0x0800]
  > HCI Event: Number of Completed Packets(0x13) plen 5
  < ACL data: handle 0x002a flags 0x02 dlen 341
     L2CAP(d): cid 0x203 len 337 [psm 15]
       BNEP: Compressed DestOnly(0x04|0)
         dst ff:ff:ff:ff:ff:ff [proto 0x0800]
  > HCI Event: Number of Completed Packets(0x13) plen 5
  < ACL data: handle 0x002a flags 0x02 dlen 341
     L2CAP(d): cid 0x203 len 337 [psm 15]
       BNEP: Compressed DestOnly(0x04|0)
         dst ff:ff:ff:ff:ff:ff [proto 0x0800]
  > HCI Event: Number of Completed Packets(0x13) plen 5
  < ACL data: handle 0x002a flags 0x02 dlen 341
     L2CAP(d): cid 0x203 len 337 [psm 15]
       BNEP: Compressed DestOnly(0x04|0)
         dst ff:ff:ff:ff:ff:ff [proto 0x0800]
  > HCI Event: Number of Completed Packets(0x13) plen 5
  < ACL data: handle 0x002a flags 0x02 dlen 41
     L2CAP(d): cid 0x203 len 37 [psm 15]
       BNEP: Compressed DestOnly(0x04|0)
         dst ff:ff:ff:ff:ff:ff [proto 0x0806]
  > HCI Event: Number of Completed Packets(0x13) plen 5
  < ACL data: handle 0x002a flags 0x02 dlen 41
     L2CAP(d): cid 0x203 len 37 [psm 15]
       BNEP: Compressed DestOnly(0x04|0)
         dst ff:ff:ff:ff:ff:ff [proto 0x0806]
  > HCI Event: Number of Completed Packets(0x13) plen 5

>> well, it looks like your device told btpand(8) that it can not accept
>> more than 672 bytes (default l2cap mtu) at a time. hence the emsgsize
>> error, i.e. datagram, btpand(8) is trying to send, is too big for
>> remote device to accept. quick fix would be to adjust mtu on the tap
>> interface to make sure btpand(8) never tries to send more than 672
>> bytes of payload.
I did try mtu=650 on my tap interface, but then large http transfers are 
stalled after some seconds. I will check again when this actual problem 
is solved.

> except that client_init() requires that the negotiated outgoing MTU be at
> least the BNEP minimum MTU (1691), and bnep_send will fail if the packet
> is larger than the channel MTU ..
>
> Andreas, can you add some debug to the end of bnep_send() something like
>
> if (nw == -1) {
> 	uint16_t mtu;
> 	socklen_t len = sizeof(mtu);
>          getsockopt(fd, BTPROTO_L2CAP, SO_L2CAP_OMTU,&mtu,&len);
> 	log_err("writev failed: %m (mtu %d)\n", mtu);
> }
>
> ?

Yes, I used the code fragment

{
         uint16_t mtu;
         socklen_t len = sizeof(mtu);
         getsockopt(chan->fd, SOL_L2CAP, SO_L2CAP_OMTU,&mtu,&len);
         log_err("writev: %m (mtu %d)\n", mtu);
}

and found mtu=1691 in all cases (ok or failed), same for SO_L2CAP_IMTU.

Andreas Longwitz



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?50782E05.5080005>