netdev - Re: [REGRESSION] asix: Lots of asix_rx_fixup() errors and slow transmissions

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:	Thu, 5 May 2016 09:11:15 +0100
From:	Dean Jenkins <Dean_Jenkins@...tor.com>
To:	John Stultz <john.stultz@...aro.org>
CC:	Guodong Xu <guodong.xu@...aro.org>,
	lkml <linux-kernel@...r.kernel.org>,
	Mark Craske <Mark_Craske@...tor.com>,
	"David S. Miller" <davem@...emloft.net>,
	YongQin Liu <yongqin.liu@...aro.org>,
	<linux-usb@...r.kernel.org>, <netdev@...r.kernel.org>,
	Ivan Vecera <ivecera@...hat.com>,
	"David B. Robins" <linux@...idrobins.net>
Subject: Re: [REGRESSION] asix: Lots of asix_rx_fixup() errors and slow
 transmissions

On 05/05/16 00:45, John Stultz wrote:
> On Tue, May 3, 2016 at 3:54 AM, Dean Jenkins <Dean_Jenkins@...tor.com> wrote:
>> On 03/05/16 11:04, Guodong Xu wrote:
>>> did you test on ARM 64-bit system or ARM 32-bit? I ask because HiKey
>>> is an ARM 64-bit system. I suggest we should be careful on that. I saw
>>> similar issues when transferring to a 64-bit system in other net
>>> drivers.
>> We used 32-bit ARM and never tested on 64-bit ARM so I suggest that the
>> commits need to be reviewed with 64-bit OS in mind.
>>>
>>> Do you have any suggestion on this regard?
>> Try testing on a Linux PC x86 32-bit OS which has has a kernel containing my
>> ASIX commits. This will help to confirm whether the failure is related to
>> 32-bit or 64-bit OS. Then try with Linux PC x86 64-bit OS, this should fail
>> otherwise it points to something specific in your ARM 64-bit platform.
> Just as a sample point, I have managed to reproduce exactly this issue
> on an x86_64 system by simply scp'ing a large file.
Please tell us the x86_64 kernel version number that you used and which 
Linux Distribution it was ? This allows other people a chance to 
reproduce your observations.

>
> [  417.819276] asix 1-5:1.0 eth1: asix_rx_fixup() Data Header
> synchronisation was lost, remaining 988
It is interesting that the reported "remaining" value is 988. Is 988 
always shown ? I mean that do you see any other "remaining" values for 
the "Data Header synchronisation was lost" error message ?

> [  417.823415] asix 1-5:1.0 eth1: asix_rx_fixup() Bad Header Length
> 0xef830347, offset 4
The gap in the timestamps shows 417.823415 - 417.819276 = 0.004139 = 4ms 
which is a large gap in terms of USB 2.0 high speed communications. This 
gap is expected to be in the 100us range for consecutive URBs. So 4ms is 
strange.

The expectation is that the "Data Header synchronisation was lost" error 
message resets the 32-bit header word synchronisation to the start of 
the next URB buffer. The "Bad Header Length, offset 4" is the expected 
outcome for the next URB because it is unlikely the 32-bit header word 
is at the start of URB buffer due to Ethernet frames spanning across URBs.
> [  417.827502] asix 1-5:1.0 eth1: asix_rx_fixup() Bad Header Length
> 0x31e2b348, offset 4
Timestamps show the gap to be 4ms which is strange for USB 2.0 high 
speed, are you sure high speed mode is being used ?
> [  417.843779] asix 1-5:1.0 eth1: asix_rx_fixup() Data Header
> synchronisation was lost, remaining 988
> [  417.847921] asix 1-5:1.0 eth1: asix_rx_fixup() Bad Header Length
> 0x8af91035, offset 4
> [  417.852004] asix 1-5:1.0 eth1: asix_rx_fixup() Bad Header Length
> 0x8521fa03, offset 4
> [  418.273394] asix 1-5:1.0 eth1: asix_rx_fixup() Data Header
> synchronisation was lost, remaining 988
> [  418.277532] asix 1-5:1.0 eth1: asix_rx_fixup() Bad Header Length
> 0x33cd9c7c, offset 4
> [  418.281683] asix 1-5:1.0 eth1: asix_rx_fixup() Bad Header Length
> 0x3d850896, offset 4
> [  418.286227] asix 1-5:1.0 eth1: asix_rx_fixup() Bad Header Length
> 0x86443357, offset 4
> [  418.290319] asix 1-5:1.0 eth1: asix_rx_fixup() Bad Header Length
> 0xee6c81d1, offset 4
>
> I don't have any 32bit x86 installs around so I'm not sure I can easly
> test there, but its clear its not arm64 specific.
I agree the issue is not specific to your ARM 64 bit platform.

Please can you supply the output of ifconfig for the USB to Ethernet 
adaptor, your example above shows eth1 as the device.

Please show the output of ifconfig eth1 before and after the issue is 
seen. This will show us whether the kernel logs any network errors and 
how many bytes have been transferred.

After the issue is seen, please can you show us the output of "dmesg | 
grep asix" so that we can see status messages from the ASIX driver that 
the USB to Ethernet adaptor is using. In particular we need to check 
that USB high speed operation (480Mbps) is being used and not full speed 
operation (12Mbps).

Thanks,

Regards,
Dean

>
> thanks
> -john


-- 
Dean Jenkins
Embedded Software Engineer
Linux Transportation Solutions
Mentor Embedded Software Division
Mentor Graphics (UK) Ltd.