raspberrypi/linux

Pi drops "smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0" on USB access?

Closed this issue · 19 comments

Hi,

following configuration: an USB-to-Serial converter is connected to the pi.
A 1-wire sensor network (currently 9 temp. sensors) is connected to the converter.

Every minute a cron-scheduled job launches a script that pull's every's sensors data, which takes about 10-15 seconds overall.

And then, when the usb-access happen, then following error occurs:

Dec 22 17:19:07 pi1 kernel: [10128.035877] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0

Usual only once or twice, but sometimes the message occurs up to 3 times in a row(with e.g. 1 second interval).

Beside that error, i see that - i know its strange but it's so - the amount of dropped errors on the eth0 increases also by some value of 1 to 3 on each run..

root@pi1:/usr/local/bin/rrd# ifconfig 
eth0      Link encap:Ethernet  HWaddr b8:27:eb:ba:c4:1a  
          inet addr:192.168.1.80  Bcast:192.168.1.255  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:23955 errors:0 dropped:1076 overruns:0 frame:0
          TX packets:12277 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:3312814 (3.1 MiB)  TX bytes:5088796 (4.8 MiB)

lo        Link encap:Local Loopback  
          inet addr:127.0.0.1  Mask:255.0.0.0
          UP LOOPBACK RUNNING  MTU:65536  Metric:1
          RX packets:10 errors:0 dropped:0 overruns:0 frame:0
          TX packets:10 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:800 (800.0 B)  TX bytes:800 (800.0 B)

root@pi1:/usr/local/bin/rrd# 

PI's data: Model A, a freshly installed && dist-upgraded install (rasbian image "2013-09-25-wheezy-raspbian.img"), kernel

root@pi1:/usr/local/bin/rrd# uname -a
Linux pi1 3.10.24+ #614 PREEMPT Thu Dec 19 20:38:42 GMT 2013 armv6l GNU/Linux
root@pi1:/usr/local/bin/rrd# 

The error is reproducible every time.

The USB-to-serial adapter is a

Bus 001 Device 004: ID 0403:6001 Future Technology Devices International, Ltd FT232 USB-Serial (UART) IC

Many thanks!

well , serial usb converter

  • addional hardware may consume some energy

Thus my question how you power the external device ?
may you used an powerd usb2 hub ?

i explain my question here more : i use sutch usb <> rsrs232 myself at all of my pis, and without extra powersource this was NOT stable enoth to serve an heartbeat3 <>heartbeat3 realtime data transmision.
seen eth and sdcard failtuers as well due overcomsume what the PI´s powersource lines via uSB can handel without modification to the PI its self.

currently the converter is powered directly by the pi.

But your idea is interesting; i'll try it out using an additional active usb-hub.

Stabilty are required ; - if you ran your PI in server mode ; especaly with external Hardware.

The majorpoint that i try contribute still here are stabilty and required featgers for RPi SERVER mode.
thanks to i.e popcornmix and some others where i interacted here.

ok, i've tested it - i connected a 4-port, separately powered USB 2.0 hub and the issue still persist - the messages
still come...

Damn...

I've also found a very very similar issue here - http://www.raspberrypi.org/phpBB3/viewtopic.php?t=61244&p=455950

P33M commented

What is the interval between error messages? Values posted so far indicate >5,000 seconds

Is there any negative effect on the system or network connections?

Well, the messages appear only around the time when the temperature is gathered.
That happens every minute scheduled by cron.

So, the intervals are

root@pi1:~# tail /var/log/syslog -n 50
Jan 24 08:07:05 pi1 kernel: [131652.577887] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:08:04 pi1 kernel: [131711.465887] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:08:09 pi1 kernel: [131715.882482] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:08:12 pi1 kernel: [131718.818884] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:09:02 pi1 kernel: [131769.345751] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:09:08 pi1 kernel: [131775.234554] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:10:06 pi1 kernel: [131832.674347] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:11:03 pi1 kernel: [131890.106151] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:11:09 pi1 kernel: [131895.986948] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:12:04 pi1 kernel: [131950.930416] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:12:05 pi1 kernel: [131952.386613] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:13:03 pi1 kernel: [132009.810414] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:13:06 pi1 kernel: [132012.746813] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:13:10 pi1 kernel: [132017.171418] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:14:05 pi1 kernel: [132072.122879] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:15:08 pi1 kernel: [132135.467490] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:16:07 pi1 kernel: [132194.315469] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:18:05 pi1 kernel: [132312.139492] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:18:09 pi1 kernel: [132316.556095] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:19:08 pi1 kernel: [132375.436089] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:20:06 pi1 kernel: [132432.851884] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:21:07 pi1 kernel: [132493.676159] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:21:11 pi1 kernel: [132498.092751] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:22:02 pi1 kernel: [132549.627756] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:23:03 pi1 kernel: [132609.979959] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:23:09 pi1 kernel: [132615.868752] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:24:08 pi1 kernel: [132675.212820] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:25:03 pi1 kernel: [132729.692216] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:25:04 pi1 kernel: [132731.164416] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:25:05 pi1 kernel: [132732.628619] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:25:10 pi1 kernel: [132737.037213] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:26:12 pi1 kernel: [132798.853618] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:27:02 pi1 kernel: [132849.396481] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:27:04 pi1 kernel: [132850.868685] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:28:07 pi1 kernel: [132914.141280] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:29:03 pi1 kernel: [132970.148894] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:29:04 pi1 kernel: [132971.629084] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:30:02 pi1 kernel: [133029.572956] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:30:05 pi1 kernel: [133032.509356] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:30:08 pi1 kernel: [133035.445756] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:31:04 pi1 kernel: [133090.933295] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:31:10 pi1 kernel: [133096.830101] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:33:02 pi1 kernel: [133209.205369] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:33:09 pi1 kernel: [133216.558360] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:33:11 pi1 kernel: [133218.022564] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:35:03 pi1 kernel: [133329.909765] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:36:07 pi1 kernel: [133393.710436] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:37:04 pi1 kernel: [133451.142235] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:37:10 pi1 kernel: [133457.023035] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
Jan 24 08:37:11 pi1 kernel: [133458.495227] smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0
root@pi1:~# 

pretty random at the beginning of the every minute.

And - no, there are no any negative side effects (at least i do not see any) nor on the system, nor with the network i my constellation.

Sutch happen on my PI when i have heayly SD card load + USB2 + network with smsc95xx .
-> issue with interupt sheduler.
This issue exist since +1J - with any kernels .

can allmost ignored as tcp just resend the tcp fragment(s) ..

Hmm,, i my case there is almost no network activity.

As to the "heavily loaded SD" / USB - in my case, at least, it's absolutely not the case.
The values that are gathered are written into appropriate RRDs, but these are sequential and very small
writes...

I'm having same issues with my RPi. I also have a FT232 USB-to-Serial adapter connected.
I'm also having trouble to interpret correct data through the USB-to-Serial adapter sometimes. It seems to miss some bytes once in a while.

I'm using 3.10.25 kernel

Same problem here:

pi@raspberrypi ~ $ /opt/vc/bin/vcgencmd version
Feb 21 2014 17:44:46
Copyright (c) 2012 Broadcom
version 67f299c3a92a793fb8b8efcaf94f7f553153f89a (clean) (release)

pi@raspberrypi ~ $ uname -a
Linux raspberrypi 3.10.30+ #642 PREEMPT Fri Feb 21 17:33:42 GMT 2014 armv6l GNU/Linux

pi@raspberrypi ~ $ lsusb
Bus 001 Device 002: ID 0424:9512 Standard Microsystems Corp.
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp.
Bus 001 Device 004: ID 0403:6001 Future Technology Devices International, Ltd FT232 USB-Serial (UART) IC

pi@raspberrypi ~ $ usb-devices

T:  Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=480 MxCh= 1
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=01 MxPS=64 #Cfgs=  1
P:  Vendor=1d6b ProdID=0002 Rev=03.10
S:  Manufacturer=Linux 3.10.30+ dwc_otg_hcd
S:  Product=DWC OTG Controller
S:  SerialNumber=bcm2708_usb
C:  #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=0mA
I:  If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub

T:  Bus=01 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  2 Spd=480 MxCh= 3
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=02 MxPS=64 #Cfgs=  1
P:  Vendor=0424 ProdID=9512 Rev=02.00
C:  #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=2mA
I:  If#= 0 Alt= 1 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=02 Driver=hub

T:  Bus=01 Lev=02 Prnt=02 Port=00 Cnt=01 Dev#=  3 Spd=480 MxCh= 0
D:  Ver= 2.00 Cls=ff(vend.) Sub=00 Prot=01 MxPS=64 #Cfgs=  1
P:  Vendor=0424 ProdID=ec00 Rev=02.00
C:  #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=2mA
I:  If#= 0 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=00 Prot=ff Driver=smsc95xx

T:  Bus=01 Lev=02 Prnt=02 Port=02 Cnt=02 Dev#=  4 Spd=12  MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS= 8 #Cfgs=  1
P:  Vendor=0403 ProdID=6001 Rev=06.00
S:  Manufacturer=FTDI
S:  Product=FT232R USB UART
S:  SerialNumber=XXXXXXX
C:  #Ifs= 1 Cfg#= 1 Atr=a0 MxPwr=90mA
I:  If#= 0 Alt= 0 #EPs= 2 Cls=ff(vend.) Sub=ff Prot=ff Driver=ftdi_sio

Also same problem I got after adding a FT232R USB to serial converter...
After many of these error messages the RPi disconnects from the LAN and has to be power cycled to come back to life... Very bad situation.

root@raspi:~/dosfstools# /opt/vc/bin/vcgencmd version
Jan  6 2014 21:19:57
Copyright (c) 2012 Broadcom
version b00bb3ae73bd2799df0e938b7a5f17f45303fb53 (clean) (release)

root@raspi:~/dosfstools# uname -a
Linux raspi 3.10.25+ #622 PREEMPT Fri Jan 3 18:41:00 GMT 2014 armv6l GNU/Linux

root@raspi:~/dosfstools# lsusb
Bus 001 Device 002: ID 0424:9512 Standard Microsystems Corp.
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp.
Bus 001 Device 004: ID 0403:6001 Future Technology Devices International, Ltd FT232 USB-Serial (UART) IC

root@raspi:~/dosfstools# usb-devices
T:  Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=480 MxCh= 1
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=01 MxPS=64 #Cfgs=  1
P:  Vendor=1d6b ProdID=0002 Rev=03.10
S:  Manufacturer=Linux 3.10.25+ dwc_otg_hcd
S:  Product=DWC OTG Controller
S:  SerialNumber=bcm2708_usb
C:  #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=0mA
I:  If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub

T:  Bus=01 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  2 Spd=480 MxCh= 3
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=02 MxPS=64 #Cfgs=  1
P:  Vendor=0424 ProdID=9512 Rev=02.00
C:  #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=2mA
I:  If#= 0 Alt= 1 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=02 Driver=hub

T:  Bus=01 Lev=02 Prnt=02 Port=00 Cnt=01 Dev#=  3 Spd=480 MxCh= 0
D:  Ver= 2.00 Cls=ff(vend.) Sub=00 Prot=01 MxPS=64 #Cfgs=  1
P:  Vendor=0424 ProdID=ec00 Rev=02.00
C:  #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=2mA
I:  If#= 0 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=00 Prot=ff Driver=smsc95xx

T:  Bus=01 Lev=02 Prnt=02 Port=01 Cnt=02 Dev#=  4 Spd=12  MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS= 8 #Cfgs=  1
P:  Vendor=0403 ProdID=6001 Rev=06.00
S:  Manufacturer=FTDI
S:  Product=FT232R USB UART
S:  SerialNumber=A702J95H
C:  #Ifs= 1 Cfg#= 1 Atr=a0 MxPwr=90mA
I:  If#= 0 Alt= 0 #EPs= 2 Cls=ff(vend.) Sub=ff Prot=ff Driver=ftdi_sio

I had the same problem and solved it by reducing the USB speed to version 1.1. This is sufficient for most applications and my Raspi is running with WIFI USB and USB-RS232 adapter for 15 days without extra hub or power!!

Add both commands below to your /boot/cmdline.txt file:

smsc95xx.turbo_mode=N dwc_otg.speed=1

When this does not help sufficient try an old SD card. I also found problems with some
modern (3.3V) SD cards.

Interesting, will try it out. Thx.

👍
Looks promising. At least no error messages :-)

the only question now is whether the nic performance will be also affected..

According to http://www.raspberrypi.org/phpBB3/viewtopic.php?f=44&t=8010&start=75 -

yes, it will decrease.

I'll test and post...

I tried adding
smsc95xx.turbo_mode=N dwc_otg.speed=1
to /boot/cmdline.txt

But afterwards my USB webcam didn't work, and I got these error messages in kern.log:

Mar 7 16:20:19 davepi kernel: [ 58.562682] INFO:: schedule_periodic: Insufficient periodic bandwidth for periodic transfer.
Mar 7 16:20:19 davepi kernel: [ 58.562682]
Mar 7 16:20:19 davepi kernel: [ 58.562730] ERROR::dwc_otg_hcd_urb_enqueue:554: DWC OTG HCD URB Enqueue failed adding QTD. Error status -1
Mar 7 16:20:19 davepi kernel: [ 58.562730]
Mar 7 16:20:19 davepi kernel: [ 58.562753] uvcvideo: Failed to submit URB 0 (-1).

so I don't think that's a workaround for everyone...

It seems that your video stream is more than the USB1.1 speed

Released in January 1996, USB 1.0 specified data rates of 1.5 Mbit/s (
Low-Bandwidth) and 12 Mbit/s (Full-Bandwidth).

Check your USB devices that they are all USB 2.0 compatible. Also check
your adapter (cable). Some chinese
adapters have high impedance DC cable. With 1-2 Ampere the voltage drop
could be to high.

Try with only your USB webcam

2014-03-07 17:30 GMT+01:00 davebiffuk notifications@github.com:

I tried adding
smsc95xx.turbo_mode=N dwc_otg.speed=1
to /boot/cmdline.txt

But afterwards my USB webcam didn't work, and I got these error messages
in kern.log:

Mar 7 16:20:19 davepi kernel: [ 58.562682] INFO:: schedule_periodic:
Insufficient periodic bandwidth for periodic transfer.
Mar 7 16:20:19 davepi kernel: [ 58.562682]
Mar 7 16:20:19 davepi kernel: [ 58.562730]
ERROR::dwc_otg_hcd_urb_enqueue:554: DWC OTG HCD URB Enqueue failed adding
QTD. Error status -1
Mar 7 16:20:19 davepi kernel: [ 58.562730]
Mar 7 16:20:19 davepi kernel: [ 58.562753] uvcvideo: Failed to submit URB
0 (-1).

so I don't think that's a workaround for everyone...

Reply to this email directly or view it on GitHubhttps://github.com//issues/470#issuecomment-37040580
.

P33M commented

Please retry (without dwc_otg.speed=1) with BRANCH=next firmware.

See http://www.raspberrypi.org/phpBB3/viewtopic.php?f=28&t=70437 for information.

Thanks P33M. I updated to BRANCH=next firmware last night and the "smsc95xx 1-1.1:1.0 eth0: unexpected urb length 0" messages have completely ceased. The Pi has been up for 9 hours now. So far so good!

For completeness, this is:

Mar 19 2014 16:52:53 
Copyright (c) 2012 Broadcom
version e071d425eca6ab200aefcf89056f3dcaf9510093 (clean) (release)

with this cmdline.txt:

dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0x3 console=ttyAMA0,115200 kgdboc=ttyAMA0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 elevator=deadline rootwait

Thanks again!

Dave

P33M commented

Marking as fixed in BRANCH=next