aborts in usb-storage in branch 2.6

I can send anything you need. Here it goes some extended log.

I've noticed that abort are after ACPI debug statements. But seems acpi and usb are not sharing irqs.

CPU0

  0:     298778    IO-APIC-edge  timer
  1:       1775    IO-APIC-edge  i8042
  2:          0          XT-PIC  cascade
  8:          4    IO-APIC-edge  rtc
  9:         56   IO-APIC-level  acpi
 12:         39    IO-APIC-edge  i8042
 14:      13833    IO-APIC-edge  ide0
 15:          1    IO-APIC-edge  ide1
 16:          0   IO-APIC-level  uhci_hcd
 17:         83   IO-APIC-level  Intel 82801DB-ICH4
 18:          0   IO-APIC-level  uhci_hcd
 19:       1069   IO-APIC-level  uhci_hcd, eth0
 20:          0   IO-APIC-level  yenta
 21:          0   IO-APIC-level  yenta
 23:      10276   IO-APIC-level  ehci_hcd
NMI:          0
LOC:     298713
ERR:          0
MIS:          0

abort.log -> 2.6.0test8
devices -> 2.6.0test8
kernel.log -> 2.6.0testx where x < 8

In abort.log, is the paste of the log with kernel 2.6.0test8 in kern.log there is a log from 2.6.0test4 or 2.6.0test4-mm

On previous 2.6.0testx kernels the bug appeared to trigger when ACPI debug statements were printed, notice there are aborts after ACPI printks.

On 2.6.0test8 it seems to be triggered when doing concurrent access to the filesystem.

I would like to help in anyway I can, but ACPI and USB is far beyond my kernel knowledge, so I'm not currently able to fix the bugs myself.

Just ask if you need more information.
Thanks.

Regards.

  Pedro Larroy Tovar  |  piotr%member.fsf.org 

Software patents are a threat to innovation in Europe please check: 
	http://www.eurolinux.org/     

T:  Bus=04 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=12  MxCh= 2
B:  Alloc=  0/900 us ( 0%), #Int=  0, #Iso=  0
D:  Ver= 1.10 Cls=09(hub  ) Sub=00 Prot=00 MxPS= 8 #Cfgs=  1
P:  Vendor=0000 ProdID=0000 Rev= 2.06
S:  Manufacturer=Linux 2.6.0-test8 uhci_hcd
S:  Product=UHCI Host Controller
S:  SerialNumber=0000:00:1d.2
C:* #Ifs= 1 Cfg#= 1 Atr=40 MxPwr=  0mA
I:  If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   2 Ivl=255ms

T:  Bus=03 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=12  MxCh= 2
B:  Alloc=  0/900 us ( 0%), #Int=  0, #Iso=  0
D:  Ver= 1.10 Cls=09(hub  ) Sub=00 Prot=00 MxPS= 8 #Cfgs=  1
P:  Vendor=0000 ProdID=0000 Rev= 2.06
S:  Manufacturer=Linux 2.6.0-test8 uhci_hcd
S:  Product=UHCI Host Controller
S:  SerialNumber=0000:00:1d.1
C:* #Ifs= 1 Cfg#= 1 Atr=40 MxPwr=  0mA
I:  If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   2 Ivl=255ms

T:  Bus=03 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  2 Spd=1.5 MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS= 8 #Cfgs=  1
P:  Vendor=046d ProdID=c00f Rev=11.10
S:  Manufacturer=Logitech
S:  Product=USB-PS/2 Optical Mouse
C:* #Ifs= 1 Cfg#= 1 Atr=a0 MxPwr= 98mA
I:  If#= 0 Alt= 0 #EPs= 1 Cls=03(HID  ) Sub=01 Prot=02 Driver=hid
E:  Ad=81(I) Atr=03(Int.) MxPS=   4 Ivl=10ms

T:  Bus=02 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=12  MxCh= 2
B:  Alloc=  0/900 us ( 0%), #Int=  0, #Iso=  0
D:  Ver= 1.10 Cls=09(hub  ) Sub=00 Prot=00 MxPS= 8 #Cfgs=  1
P:  Vendor=0000 ProdID=0000 Rev= 2.06
S:  Manufacturer=Linux 2.6.0-test8 uhci_hcd
S:  Product=UHCI Host Controller
S:  SerialNumber=0000:00:1d.0
C:* #Ifs= 1 Cfg#= 1 Atr=40 MxPwr=  0mA
I:  If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   2 Ivl=255ms

T:  Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=480 MxCh= 6
B:  Alloc=  0/800 us ( 0%), #Int=  0, #Iso=  0
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=01 MxPS= 8 #Cfgs=  1
P:  Vendor=0000 ProdID=0000 Rev= 2.06
S:  Manufacturer=Linux 2.6.0-test8 ehci_hcd
S:  Product=EHCI Host Controller
S:  SerialNumber=0000:00:1d.7
C:* #Ifs= 1 Cfg#= 1 Atr=40 MxPwr=  0mA
I:  If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   2 Ivl=256ms

T:  Bus=01 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  2 Spd=480 MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=04b4 ProdID=6830 Rev= 0.01
S:  Manufacturer=Cypress Semiconductor
S:  Product=USB2.0 Storage Device
S:  SerialNumber=000000000383
C:* #Ifs= 1 Cfg#= 1 Atr=c0 MxPwr=  0mA
I:  If#= 0 Alt= 0 #EPs= 2 Cls=08(stor.) Sub=06 Prot=50 Driver=usb-storage
E:  Ad=02(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=88(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms

I looked at your logs, but I can't add much to what you already know. This certainly does appear to be some sort of interrupt sharing/routing problem -- the logs don't indicate anything specific to USB. However there's no easy way to tell what the source of that problem is.

Maybe someone who knows more about ACPI and interrupt handling can help.

Alan Stern

The logs look like a SCSI timeout - a 30 second gap, followed by abort, test unit ready, and a resend of the timed out write. That does not help much. It could certainly be a lost interrupt.

I did not see any timeout/aborts happening (immediately) after the acpi messages.

I don't know ACPI, but I thought interrupt problems it might cause happened more consistently.

-- Patrick Mansfield