Bug 8572 - uhci_hcd:usb2 slows to 131KB/s from 846KB/s in MPS IOAPIC mode - Dell OptiPlex GX240
Summary: uhci_hcd:usb2 slows to 131KB/s from 846KB/s in MPS IOAPIC mode - Dell OptiPle...
Status: CLOSED CODE_FIX
Alias: None
Product: ACPI
Classification: Unclassified
Component: BIOS (show other bugs)
Hardware: i386 Linux
: P2 normal
Assignee: Len Brown
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2007-06-03 04:16 UTC by Tear
Modified: 2007-07-25 20:12 UTC (History)
2 users (show)

See Also:
Kernel Version: 2.6.21.3
Subsystem:
Regression: ---
Bisected commit-id:


Attachments
Output of acpidump (44.01 KB, text/plain)
2007-06-03 04:20 UTC, Tear
Details
Patch which disables IO-APIC on Dell OptiPlex GX240 if ACPI is not enabled (1.99 KB, patch)
2007-06-03 04:22 UTC, Tear
Details | Diff
patch vs 2.6.22 to remove acpi=ht blacklist entry for GX240 (2.04 KB, patch)
2007-06-03 22:57 UTC, Len Brown
Details | Diff
dmesg-acpi=ht-apic.txt (13.18 KB, text/plain)
2007-06-03 23:43 UTC, Len Brown
Details
dmesg-acpi=force-apic.txt (13.92 KB, text/plain)
2007-06-04 00:16 UTC, Len Brown
Details
i386-irq-kill-irq-compression.patch (4.40 KB, patch)
2007-06-04 00:19 UTC, Len Brown
Details | Diff
Output of lspci -vv (6.73 KB, text/plain)
2007-06-04 07:38 UTC, Tear
Details
dmesg with acpi=ht and IO-APIC enabled (another) (15.25 KB, text/plain)
2007-06-04 08:10 UTC, Tear
Details
dmesg with acpi=force and the i386-irq-kill-irq-compression.patch patch applied (13.93 KB, text/plain)
2007-06-04 08:27 UTC, Tear
Details

Description Tear 2007-06-03 04:16:26 UTC
Most recent kernel where this bug did *NOT* occur: None
Distribution: Debian 4.0r0 ("Etch")
Hardware Environment: Dell OptiPlex GX240, Pentim IV 1.7GHz
Software Environment: Linux 2.6.21.3 from kernel.org

Problem Description: When ACPI is disabled but IO-APIC
is enabled, the USB ports on the front panel of
Dell OptiPlex GX240 very slowly. (Dell OptiPlex GX240
is in the ACPI blacklist so ACPI gets set up only
by acpi=ht.) This results in very slow USB performance.
Copying a few photos from an USB-enabled digital camera
takes five to six times longer compared to the performance
when the camera is connected to one ofthe USB ports on
the rear panel.

If Dell OptiPlex GX240 had not been in the ACPI blacklist,
this problem would show up only with kernels without ACPI
compiled in.

In addition, I wrote a patch which implements an IO-APIC
blacklist and disables IO-APIC on Dell Optiplex GX240
if ACPI is not enabled.

Please see the following threads for more information:

http://marc.info/?t=118079385400003&r=1&w=2
http://marc.info/?t=117897881900001&r=1&w=2

Steps to reproduce: Find a Dell OptiPlex GX240 and
boot Linux without anything appended to the kernel
command line. Notice that the USB ports on the front
panel work very slowly whereas the ports on the rear
panel work normally. Boot with "acpi=force" *OR* "noapic"
appended to the command line and notice that the USB
ports on the front panel start work at normal speed.
Comment 1 Tear 2007-06-03 04:20:19 UTC
Created attachment 11649 [details]
Output of acpidump
Comment 2 Tear 2007-06-03 04:22:07 UTC
Created attachment 11650 [details]
Patch which disables IO-APIC on Dell OptiPlex GX240 if ACPI is not enabled
Comment 3 Len Brown 2007-06-03 22:57:09 UTC
Created attachment 11655 [details]
patch vs 2.6.22 to remove acpi=ht blacklist entry for GX240

just to set the context here...
This patch to remove the acpi=ht blacklist entry for
the the OptiPlex GX240 is already in the queue for 2.6.23.
"acpi=force" is needed on the GX240 up through 2.6.22
unless this patch is applied.

After this patch is applied, there are no known ACPI-related
issues on this box -- but lets keep this bug report in the
ACPI category until we can figure out the root cause
of the legacy mode issue.
Comment 4 Len Brown 2007-06-03 23:18:04 UTC
Summarizing the e-mail thread...

USB ports on back of the box always run fast, no matter
if in ACPI mode, acpi=off Legacy mode, PIC mode, or IOAPIC mode:
2199226 bytes (2,2 MB) copied, 2.60062 seconds, 846 kB/s

USB ports on the front of the box run at that fast speed
when in ACPI mode, or when in Legacy PIC mode.
But in Legacy IOAPIC mode, they run 6x slower:
2199226 bytes (2,2 MB) copied, 16.7524 seconds, 131 kB/s

please attach the output from lspci -vv
it is necessary to trace exactly how ACPI is configuring
the interrupts for these devices.
Comment 5 Len Brown 2007-06-03 23:43:28 UTC
Created attachment 11656 [details]
dmesg-acpi=ht-apic.txt

The slow case:

usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
USB Universal Host Controller Interface driver v3.0
PCI: Setting latency timer of device 0000:00:1f.2 to 64
uhci_hcd 0000:00:1f.2: UHCI Host Controller
uhci_hcd 0000:00:1f.2: new USB bus registered, assigned bus number 1
uhci_hcd 0000:00:1f.2: irq 19, io base 0x0000ff80
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
PCI: Setting latency timer of device 0000:00:1f.4 to 64
uhci_hcd 0000:00:1f.4: UHCI Host Controller
uhci_hcd 0000:00:1f.4: new USB bus registered, assigned bus number 2
uhci_hcd 0000:00:1f.4: irq 18, io base 0x0000ff60
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected

0000:02:0c.0: 3Com PCI 3c905C Tornado at f880cc00.

PCI: Using IRQ router PIIX/ICH [8086/2440] at 0000:00:1f.0
PCI->APIC IRQ transform: 0000:00:1f.2[D] -> IRQ 19 (usb1)
PCI->APIC IRQ transform: 0000:00:1f.3[B] -> IRQ 17
PCI->APIC IRQ transform: 0000:00:1f.4[C] -> IRQ 18 (usb2)
PCI->APIC IRQ transform: 0000:00:1f.5[B] -> IRQ 17
PCI->APIC IRQ transform: 0000:01:00.0[A] -> IRQ 16
PCI->APIC IRQ transform: 0000:02:08.0[A] -> IRQ 17
PCI->APIC IRQ transform: 0000:02:0c.0[A] -> IRQ 18 (eth0)

	   CPU0
  0:	 201306   IO-APIC-edge	    timer
  1:	   1457   IO-APIC-edge	    i8042
  2:	      0    XT-PIC-XT	    cascade
  6:	      5   IO-APIC-edge	    floppy
  7:	      0   IO-APIC-edge	    parport0
  8:	      1   IO-APIC-edge	    rtc
 12:	  19218   IO-APIC-edge	    i8042
 14:	  18704   IO-APIC-edge	    ide0
 15:	   6973   IO-APIC-edge	    ide1
 16:	  56862   IO-APIC-fasteoi   r128@pci:0000:01:00.0
 17:	  20792   IO-APIC-fasteoi   Intel 82801BA-ICH2
 18:	     74   IO-APIC-fasteoi   uhci_hcd:usb2, eth0
 19:	     38   IO-APIC-fasteoi   uhci_hcd:usb1
NMI:	      0
LOC:	 201260
ERR:	      0
MIS:	      0
Comment 6 Len Brown 2007-06-04 00:16:13 UTC
Created attachment 11658 [details]
dmesg-acpi=force-apic.txt

the fast case:

ACPI: PCI Interrupt 0000:02:0c.0[A] -> GSI 18 (level, low) -> IRQ 16
3c59x: Donald Becker and others. www.scyld.com/network/vortex.html
0000:02:0c.0: 3Com PCI 3c905C Tornado at f881ac00.

ACPI: PCI Interrupt 0000:00:1f.2[D] -> GSI 19 (level, low) -> IRQ 17
PCI: Setting latency timer of device 0000:00:1f.2 to 64
uhci_hcd 0000:00:1f.2: UHCI Host Controller
uhci_hcd 0000:00:1f.2: new USB bus registered, assigned bus number 1
uhci_hcd 0000:00:1f.2: irq 17, io base 0x0000ff80
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
hda: cache flushes supported
 hda: hda1 hda2 hda3 hda4 <<6>ACPI: PCI Interrupt 0000:00:1f.4[C] -> GSI 23
(level, low) -> IRQ 18
PCI: Setting latency timer of device 0000:00:1f.4 to 64
uhci_hcd 0000:00:1f.4: UHCI Host Controller
uhci_hcd 0000:00:1f.4: new USB bus registered, assigned bus number 2
uhci_hcd 0000:00:1f.4: irq 18, io base 0x0000ff60
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected

GSI
18 0000:02:0c.0[A] (eth0)
19 0000:00:1f.2[D] (usb1) (front)
23 0000:00:1f.4[C] (usb2) (rear)

eth0 looks sane -- it is on IRQ18 in Legacy mode,
and is on GSI18 in ACPI mode, and presumably it is working
fine in both modes.

usb1 also looks sane -- it is on IRQ19 in Legacy mode,
and it is on GSI 19 in ACPI mode.

usb2 looks broken -- it is on GSI23 in ACPI mode, and is on
IRQ18 in Legacy mode.  In ACPI mode there are no programmable
interrupt links for this device - it is hard-coded in the _PRT,
so one would expect it to have the same interrupt wire in both
ACPI and Legacy mode.

The other puzzle is that the issue is with the front usb ports,
which were identified via e-mail as usb1, not as usb2.

Please connfirm that in "acpi=off" mode, the issue is with
 19:	     38   IO-APIC-fasteoi   uhci_hcd:usb1
and not with
 18:	     74   IO-APIC-fasteoi   uhci_hcd:usb2, eth0

because it would make more sense if the issue were with usb2,
for if usb2 were mis-configured in legacy mode such that it
was taking interrupts on irq23 but looking for them on irq18,
then it would only be working because the system happened
to poll it when ethernet interrupts occurred.
Indeed, if this were the case, you'd find that it worked better
under conditions of high ethernet interrupt load, and didn't
work at all if you disconnected the ethernet cable.
Comment 7 Len Brown 2007-06-04 00:19:37 UTC
Created attachment 11659 [details]
i386-irq-kill-irq-compression.patch

The ACPI-mode dmesg and /proc/interrupts in e-mail don't match --
probably because they were taken on  different boots and the
probe order may have changed.

Please apply this patch to disable "irq compression", which
make make GSI = IRQ = the same number independent of probe order.
With this patch applied, please boot in ACPI+IOAPIC mode,
capture /proc/interrupts and paste them here, and attach the dmesg.
Comment 8 Len Brown 2007-06-04 00:40:15 UTC
Looking up the _PRT entries for these devices in the DSDT:

0000:00:1f.2[D] is hard-coded to GSI x13 = GSI 19

               Package (0x04)
                {
                    0x001FFFFF,
                    0x03,
                    0x00,
                    0x13
                },

0000:00:1f.4[C] is hard-coded to GSI x17 = GSI 23

             Package (0x04)
                {
                    0x001FFFFF,
                    0x02,
                    0x00,
                    0x17
                },

0000:02:0c.0[A] is hard-coded to GSI x12 = GSI 18
                    Package (0x04)
                    {
                        0x000CFFFF,
                        0x00,
                        0x00,
                        0x12
                    },
This confirms the presumption above that ACPI isn't programming
anything here in IOAPIC mode -- it is just following the description
of the hard-coded interrupt connections on the motherboard.
Comment 9 Tear 2007-06-04 07:38:18 UTC
Created attachment 11673 [details]
Output of lspci -vv
Comment 10 Tear 2007-06-04 08:10:24 UTC
Created attachment 11674 [details]
dmesg with acpi=ht and IO-APIC enabled (another)

I booted with acpi=ht and here's what my /proc/interrupts looks like:

	   CPU0
  0:	     62   IO-APIC-edge	    timer
  1:	   5363   IO-APIC-edge	    i8042
  2:	      0    XT-PIC-XT	    cascade
  6:	      5   IO-APIC-edge	    floppy
  7:	      0   IO-APIC-edge	    parport0
  8:	      1   IO-APIC-edge	    rtc
 12:	  19599   IO-APIC-edge	    i8042
 14:	  21515   IO-APIC-edge	    ide0
 15:	  13867   IO-APIC-edge	    ide1
 16:	 114548   IO-APIC-fasteoi   r128@pci:0000:01:00.0
 17:	      0   IO-APIC-fasteoi   Intel 82801BA-ICH2
 18:	   2743   IO-APIC-fasteoi   uhci_hcd:usb2, eth0
 19:	    723   IO-APIC-fasteoi   uhci_hcd:usb1
NMI:	      0
LOC:	 423652
ERR:	      0
MIS:	      0


When I use the ports on rear panel (fast), the line which
increments is the following:
 19:	    903   IO-APIC-fasteoi   uhci_hcd:usb1

When I use the ports on the front panel (slow), the line which
increments is the following:
 18:	   2983   IO-APIC-fasteoi   uhci_hcd:usb2, eth0
Comment 11 Tear 2007-06-04 08:27:49 UTC
Created attachment 11675 [details]
dmesg with acpi=force and the i386-irq-kill-irq-compression.patch patch applied

I applied i386-irq-kill-irq-compression.patch and
booted with acpi=force.

In addition, here's /proc/interrupts:

	   CPU0
  0:	     71   IO-APIC-edge	    timer
  1:	   1250   IO-APIC-edge	    i8042
  6:	      5   IO-APIC-edge	    floppy
  7:	      0   IO-APIC-edge	    parport0
  8:	      1   IO-APIC-edge	    rtc
  9:	      1   IO-APIC-fasteoi   acpi
 12:	   7485   IO-APIC-edge	    i8042
 14:	   8114   IO-APIC-edge	    ide0
 15:	   2959   IO-APIC-edge	    ide1
 16:	  22683   IO-APIC-fasteoi   r128@pci:0000:01:00.0
 17:	      0   IO-APIC-fasteoi   Intel 82801BA-ICH2
 18:	    287   IO-APIC-fasteoi   eth0
 19:	     46   IO-APIC-fasteoi   uhci_hcd:usb1
 23:	      0   IO-APIC-fasteoi   uhci_hcd:usb2
NMI:	      0
LOC:	  92660
ERR:	      0
MIS:	      0

Front USB port is
 23:	    498   IO-APIC-fasteoi   uhci_hcd:usb2
Rear USB port is 
 19:	     46   IO-APIC-fasteoi   uhci_hcd:usb1
Comment 12 Len Brown 2007-06-04 23:49:51 UTC
Thanks for confirming that usb1 on IRQ19 works properly
in both ACPI and legacy IOAPIC mode.

The problematic front usb2 port appears alone on IRQ23
in ACPI mode, and it appears shared with eth0 on irq18
in MPS mode, so it is looking like the theory above is correct
and that this box has a bogus MPS table entry.

Please test the front usb1 in acpi=off mode with
the ethernet cable detached.  I expect it should
be worse than slow -- it may not work at all.
Also, you might be able to make it run fast by causing
a lot of ethernet interrupts when you are using usb1.
This would confirm the reason for the speed differences
in your tests are due to the rate of ethernet interrupts
on irq18.

Please also test the "irqpoll" workaround in acpi=off IOAPIC mode.
Comment 13 Len Brown 2007-06-05 00:02:27 UTC
> Please test the front usb1

er. typo, in comment above,
please test the problematic front usb2, of course...
Comment 14 Tear 2007-06-05 10:29:14 UTC
Mr. Brown,

You are right: When I disconnected the ethernet
cable and attached my USB enabled digital
camera to the front USB port, nothing happened.
The camera was not even detected by the kernel.
When I connected the ethernet cable, the camera
was detected by the kernel - in slow speed that is.

I have also tried appending "irqpoll" to the
kernel commandline. It seemed to make the slow
transfer speed even slower (on the front port;
I haven't tested the rear port.)

# dd if=dsc00684.jpg of=/dev/null
4654+1 records in
4654+1 records out
2383349 bytes (2,4 MB) copied, 27.7139 seconds, 86,0 kB/s

Note: I have conducted these tests with the patch
named "i386-irq-kill-irq-compression.patch" applied.
If this could change the test results, please let
me know and I will try a vanilla kernel.
Comment 15 Len Brown 2007-07-25 20:12:20 UTC
Thanks for testing.
The remaining problem on this machine is that the front-USB
controller has a bad entry in the BIOS MPS table.

Options:
1. run in ACPI mode -- which gets it right
2. run in MPS mode, but with "noapic"
3. run in MPS mode, with a patch to do #2 automatically
4. run in MPS mode, with a new patch to correct just the bad entry
5. run in MPS mode, and use the back ports, not the front ports.

The ACPI issue is closed and the MPS issue is root-caused
and has multiple workarounds.  I recommend options #1 and #5 --
I do not recommend options 2,3,4 since it would just clutter
the kernel with a model-specific BIOS workaround for a mode
that most people don't use anyway.

patch in comment #3 shipped in Linux-2.6.23-rc1
closed.

Note You need to log in before you can comment on or make changes to this bug.