hcidump / avtest issues

hcidump / avtest issues

[Mike]

Hi,

I'm having issues where hcidump seems to be losing packets.  I'm
trying to collect traces of avtest running.  Avtest properly prints
out that it sent a packet and received a reply, but I don't always see
it in hcidump.  Seems if I run avtest a lot successively, it does show
up.  I'm running a 2.6.33.20 kernel with hcidump-2.3.  Let me know if
the kernel is just too ancient, but I'd like to know if others have
seen this type of issue.

Thanks,
Mike

Re: hcidump / avtest issues

[Marcel Holtmann]

Hi Mike,

> I'm having issues where hcidump seems to be losing packets.  I'm
> trying to collect traces of avtest running.  Avtest properly prints
> out that it sent a packet and received a reply, but I don't always see
> it in hcidump.  Seems if I run avtest a lot successively, it does show
> up.  I'm running a 2.6.33.20 kernel with hcidump-2.3.  Let me know if
> the kernel is just too ancient, but I'd like to know if others have
> seen this type of issue.

actually hcidump can not loose any packets. Write them into a file in
BTSnoop format and double check with Wireshark or the Frontline Viewer.

The kernel is always sending the exact copy to the hcidump sockets and
thus there is no way you loose packets. The only explanation would be
that L2CAP socket has a bug and swallows it. Have you checked that
avtest actually reports L2CAP send errors.

Regards

Marcel

Re: hcidump / avtest issues

[Mike]

Hi Marcel,

>> I'm having issues where hcidump seems to be losing packets. =A0I'm
>> trying to collect traces of avtest running. =A0Avtest properly prints
>> out that it sent a packet and received a reply, but I don't always see
>> it in hcidump. =A0Seems if I run avtest a lot successively, it does show
>> up. =A0I'm running a 2.6.33.20 kernel with hcidump-2.3. =A0Let me know i=
f
>> the kernel is just too ancient, but I'd like to know if others have
>> seen this type of issue.
>
> actually hcidump can not loose any packets. Write them into a file in
> BTSnoop format and double check with Wireshark or the Frontline Viewer.
>
> The kernel is always sending the exact copy to the hcidump sockets and
> thus there is no way you loose packets. The only explanation would be
> that L2CAP socket has a bug and swallows it. Have you checked that
> avtest actually reports L2CAP send errors.

I was saving in btsnoop and looking at it in wireshark.  And verified
that the other side got the command by enabling debug mode on
bluetoothd.  But now I see the packet is sort of there, but it's
malformed!

Bad:
< 02 01 20 07 00 03 00 40 00 00 06 04
> 02 01 20 07 00 03 00 40 00 03 06 31

Good:
< 02 01 20 07 00 03 00 42 00 00 06 04
> 02 01 20 07 00 03 00 42 00 03 06 31

Somehow one byte is wrong (40 bad, 42 good).  Any ideas on that?  Let
me know if you'd like the logs, but I verified the --raw output of
hcidump had the same issue.

Mike

Re: hcidump / avtest issues

[Mike]

>>> I'm having issues where hcidump seems to be losing packets. =A0I'm
>>> trying to collect traces of avtest running. =A0Avtest properly prints
>>> out that it sent a packet and received a reply, but I don't always see
>>> it in hcidump. =A0Seems if I run avtest a lot successively, it does sho=
w
>>> up. =A0I'm running a 2.6.33.20 kernel with hcidump-2.3. =A0Let me know =
if
>>> the kernel is just too ancient, but I'd like to know if others have
>>> seen this type of issue.
>>
>> actually hcidump can not loose any packets. Write them into a file in
>> BTSnoop format and double check with Wireshark or the Frontline Viewer.
>>
>> The kernel is always sending the exact copy to the hcidump sockets and
>> thus there is no way you loose packets. The only explanation would be
>> that L2CAP socket has a bug and swallows it. Have you checked that
>> avtest actually reports L2CAP send errors.
>
> I was saving in btsnoop and looking at it in wireshark. =A0And verified
> that the other side got the command by enabling debug mode on
> bluetoothd. =A0But now I see the packet is sort of there, but it's
> malformed!
>
> Bad:
> < 02 01 20 07 00 03 00 40 00 00 06 04
>> 02 01 20 07 00 03 00 40 00 03 06 31
>
> Good:
> < 02 01 20 07 00 03 00 42 00 00 06 04
>> 02 01 20 07 00 03 00 42 00 03 06 31
>
> Somehow one byte is wrong (40 bad, 42 good). =A0Any ideas on that? =A0Let
> me know if you'd like the logs, but I verified the --raw output of
> hcidump had the same issue.

BTW, I would say the issue exists more when SDP is going on (as when I
run the test a lot before a disconnect, it starts working -- no more
SDP later on).  And we can see that it classified the packet as SDP,
not AVDTP.  I'm tracking the hcidump code now, not entirely sure how
data goes into one or the other.

Re: hcidump / avtest issues

[Marcel Holtmann]

Hi Mike,

> >>> I'm having issues where hcidump seems to be losing packets.  I'm
> >>> trying to collect traces of avtest running.  Avtest properly prints
> >>> out that it sent a packet and received a reply, but I don't always see
> >>> it in hcidump.  Seems if I run avtest a lot successively, it does show
> >>> up.  I'm running a 2.6.33.20 kernel with hcidump-2.3.  Let me know if
> >>> the kernel is just too ancient, but I'd like to know if others have
> >>> seen this type of issue.
> >>
> >> actually hcidump can not loose any packets. Write them into a file in
> >> BTSnoop format and double check with Wireshark or the Frontline Viewer.
> >>
> >> The kernel is always sending the exact copy to the hcidump sockets and
> >> thus there is no way you loose packets. The only explanation would be
> >> that L2CAP socket has a bug and swallows it. Have you checked that
> >> avtest actually reports L2CAP send errors.
> >
> > I was saving in btsnoop and looking at it in wireshark.  And verified
> > that the other side got the command by enabling debug mode on
> > bluetoothd.  But now I see the packet is sort of there, but it's
> > malformed!
> >
> > Bad:
> > < 02 01 20 07 00 03 00 40 00 00 06 04
> >> 02 01 20 07 00 03 00 40 00 03 06 31
> >
> > Good:
> > < 02 01 20 07 00 03 00 42 00 00 06 04
> >> 02 01 20 07 00 03 00 42 00 03 06 31
> >
> > Somehow one byte is wrong (40 bad, 42 good).  Any ideas on that?  Let
> > me know if you'd like the logs, but I verified the --raw output of
> > hcidump had the same issue.
> 
> BTW, I would say the issue exists more when SDP is going on (as when I
> run the test a lot before a disconnect, it starts working -- no more
> SDP later on).  And we can see that it classified the packet as SDP,
> not AVDTP.  I'm tracking the hcidump code now, not entirely sure how
> data goes into one or the other.

the hcidump code is pure raw data. It is the same data that goes to the
driver. Trust me here, that is how the kernel works, it clones the skb
before sending to the driver and sends a copy back to hcidump. So you
will not find a bug in the hcidump raw data.

The only way something can go wrong if L2CAP has an issue. Are you using
L2CAP basic modem or enhanced retransmission?

Regards

Marcel

Re: hcidump / avtest issues

[Mike]

Hi Marcel,

>> >>> I'm having issues where hcidump seems to be losing packets. =A0I'm
>> >>> trying to collect traces of avtest running. =A0Avtest properly print=
s
>> >>> out that it sent a packet and received a reply, but I don't always s=
ee
>> >>> it in hcidump. =A0Seems if I run avtest a lot successively, it does =
show
>> >>> up. =A0I'm running a 2.6.33.20 kernel with hcidump-2.3. =A0Let me kn=
ow if
>> >>> the kernel is just too ancient, but I'd like to know if others have
>> >>> seen this type of issue.
>> >>
>> >> actually hcidump can not loose any packets. Write them into a file in
>> >> BTSnoop format and double check with Wireshark or the Frontline Viewe=
r.
>> >>
>> >> The kernel is always sending the exact copy to the hcidump sockets an=
d
>> >> thus there is no way you loose packets. The only explanation would be
>> >> that L2CAP socket has a bug and swallows it. Have you checked that
>> >> avtest actually reports L2CAP send errors.
>> >
>> > I was saving in btsnoop and looking at it in wireshark. =A0And verifie=
d
>> > that the other side got the command by enabling debug mode on
>> > bluetoothd. =A0But now I see the packet is sort of there, but it's
>> > malformed!
>> >
>> > Bad:
>> > < 02 01 20 07 00 03 00 40 00 00 06 04
>> >> 02 01 20 07 00 03 00 40 00 03 06 31
>> >
>> > Good:
>> > < 02 01 20 07 00 03 00 42 00 00 06 04
>> >> 02 01 20 07 00 03 00 42 00 03 06 31
>> >
>> > Somehow one byte is wrong (40 bad, 42 good). =A0Any ideas on that? =A0=
Let
>> > me know if you'd like the logs, but I verified the --raw output of
>> > hcidump had the same issue.
>>
>> BTW, I would say the issue exists more when SDP is going on (as when I
>> run the test a lot before a disconnect, it starts working -- no more
>> SDP later on). =A0And we can see that it classified the packet as SDP,
>> not AVDTP. =A0I'm tracking the hcidump code now, not entirely sure how
>> data goes into one or the other.
>
> the hcidump code is pure raw data. It is the same data that goes to the
> driver. Trust me here, that is how the kernel works, it clones the skb
> before sending to the driver and sends a copy back to hcidump. So you
> will not find a bug in the hcidump raw data.
>
> The only way something can go wrong if L2CAP has an issue. Are you using
> L2CAP basic modem or enhanced retransmission?

Looks like ERTM was added in 2.6.36, and I didn't backport it, so must be b=
asic.

Re: hcidump / avtest issues

[Mike]

On Fri, Apr 27, 2012 at 3:57 PM, Mike <puffy.taco@gmail.com> wrote:
> Hi Marcel,
>
>>> >>> I'm having issues where hcidump seems to be losing packets. =A0I'm
>>> >>> trying to collect traces of avtest running. =A0Avtest properly prin=
ts
>>> >>> out that it sent a packet and received a reply, but I don't always =
see
>>> >>> it in hcidump. =A0Seems if I run avtest a lot successively, it does=
 show
>>> >>> up. =A0I'm running a 2.6.33.20 kernel with hcidump-2.3. =A0Let me k=
now if
>>> >>> the kernel is just too ancient, but I'd like to know if others have
>>> >>> seen this type of issue.
>>> >>
>>> >> actually hcidump can not loose any packets. Write them into a file i=
n
>>> >> BTSnoop format and double check with Wireshark or the Frontline View=
er.
>>> >>
>>> >> The kernel is always sending the exact copy to the hcidump sockets a=
nd
>>> >> thus there is no way you loose packets. The only explanation would b=
e
>>> >> that L2CAP socket has a bug and swallows it. Have you checked that
>>> >> avtest actually reports L2CAP send errors.
>>> >
>>> > I was saving in btsnoop and looking at it in wireshark. =A0And verifi=
ed
>>> > that the other side got the command by enabling debug mode on
>>> > bluetoothd. =A0But now I see the packet is sort of there, but it's
>>> > malformed!
>>> >
>>> > Bad:
>>> > < 02 01 20 07 00 03 00 40 00 00 06 04
>>> >> 02 01 20 07 00 03 00 40 00 03 06 31
>>> >
>>> > Good:
>>> > < 02 01 20 07 00 03 00 42 00 00 06 04
>>> >> 02 01 20 07 00 03 00 42 00 03 06 31
>>> >
>>> > Somehow one byte is wrong (40 bad, 42 good). =A0Any ideas on that? =
=A0Let
>>> > me know if you'd like the logs, but I verified the --raw output of
>>> > hcidump had the same issue.
>>>
>>> BTW, I would say the issue exists more when SDP is going on (as when I
>>> run the test a lot before a disconnect, it starts working -- no more
>>> SDP later on). =A0And we can see that it classified the packet as SDP,
>>> not AVDTP. =A0I'm tracking the hcidump code now, not entirely sure how
>>> data goes into one or the other.
>>
>> the hcidump code is pure raw data. It is the same data that goes to the
>> driver. Trust me here, that is how the kernel works, it clones the skb
>> before sending to the driver and sends a copy back to hcidump. So you
>> will not find a bug in the hcidump raw data.
>>
>> The only way something can go wrong if L2CAP has an issue. Are you using
>> L2CAP basic modem or enhanced retransmission?
>
> Looks like ERTM was added in 2.6.36, and I didn't backport it, so must be=
 basic.

Unless it was added earlier.  I'm really not familiar enough.  Just
running avtest.c, sending invalid commands!

Re: hcidump / avtest issues

[Mike]

>>>> >>> I'm having issues where hcidump seems to be losing packets. =A0I'm
>>>> >>> trying to collect traces of avtest running. =A0Avtest properly pri=
nts
>>>> >>> out that it sent a packet and received a reply, but I don't always=
 see
>>>> >>> it in hcidump. =A0Seems if I run avtest a lot successively, it doe=
s show
>>>> >>> up. =A0I'm running a 2.6.33.20 kernel with hcidump-2.3. =A0Let me =
know if
>>>> >>> the kernel is just too ancient, but I'd like to know if others hav=
e
>>>> >>> seen this type of issue.
>>>> >>
>>>> >> actually hcidump can not loose any packets. Write them into a file =
in
>>>> >> BTSnoop format and double check with Wireshark or the Frontline Vie=
wer.
>>>> >>
>>>> >> The kernel is always sending the exact copy to the hcidump sockets =
and
>>>> >> thus there is no way you loose packets. The only explanation would =
be
>>>> >> that L2CAP socket has a bug and swallows it. Have you checked that
>>>> >> avtest actually reports L2CAP send errors.
>>>> >
>>>> > I was saving in btsnoop and looking at it in wireshark. =A0And verif=
ied
>>>> > that the other side got the command by enabling debug mode on
>>>> > bluetoothd. =A0But now I see the packet is sort of there, but it's
>>>> > malformed!
>>>> >
>>>> > Bad:
>>>> > < 02 01 20 07 00 03 00 40 00 00 06 04
>>>> >> 02 01 20 07 00 03 00 40 00 03 06 31
>>>> >
>>>> > Good:
>>>> > < 02 01 20 07 00 03 00 42 00 00 06 04
>>>> >> 02 01 20 07 00 03 00 42 00 03 06 31
>>>> >
>>>> > Somehow one byte is wrong (40 bad, 42 good). =A0Any ideas on that? =
=A0Let
>>>> > me know if you'd like the logs, but I verified the --raw output of
>>>> > hcidump had the same issue.
>>>>
>>>> BTW, I would say the issue exists more when SDP is going on (as when I
>>>> run the test a lot before a disconnect, it starts working -- no more
>>>> SDP later on). =A0And we can see that it classified the packet as SDP,
>>>> not AVDTP. =A0I'm tracking the hcidump code now, not entirely sure how
>>>> data goes into one or the other.
>>>
>>> the hcidump code is pure raw data. It is the same data that goes to the
>>> driver. Trust me here, that is how the kernel works, it clones the skb
>>> before sending to the driver and sends a copy back to hcidump. So you
>>> will not find a bug in the hcidump raw data.
>>>
>>> The only way something can go wrong if L2CAP has an issue. Are you usin=
g
>>> L2CAP basic modem or enhanced retransmission?
>>
>> Looks like ERTM was added in 2.6.36, and I didn't backport it, so must b=
e basic.
>
> Unless it was added earlier. =A0I'm really not familiar enough. =A0Just
> running avtest.c, sending invalid commands!

OK, finally figured it out.  Wireshark was at fault [1].  The fix has
been in Wireshark trunk for a while, but their latest stable build
doesn't have that.  Basically, it was picking the last packet for a
given CID.  If I ran it once, the AVDTP packets went first, followed
by SDP so everything was parsed as SDP.

[1] https://bugs.wireshark.org/bugzilla/show_bug.cgi?id=3D6619