Regression: Bisected, IRQ and MSI allocations screwed without sparse irq

Jesper Dangaard Brouer
2008-11-20T19:48:50Z

[-- Attachment #1: Type: TEXT/PLAIN, Size: 4263 bytes --]

Hi Thomas Gleixner,

I have bisected a regression to your commit
3235e936c0cc3589309280b6f59e5096779adae3,
"x86: remove sparse irq from Kconfig".

Its actually not necessary your fault, as your commit simply removes
the config option HAVE_SPARSE_IRQ. This revels the bug / regression
I'm exposted to.

Guess I should bisect again to find the exact faulty commit, but I'm
rather sick of bisecting at the moment, and though you might have a
better idea whats going wrong. I would rather spend my time
performance tuning the multiqueue routing code...

[The regression]:

During my testing of the Sun Neptune based NICs. On kernel 2.6.27 I
get really good performance (900-1200kpps) compared to 2.6.28 (davem
git net-2.6).

The cause of this problem (tracked down together with Robert Olsson)
is that on 2.6.28 I have a lot less IRQs available. It seems max 34
IRQs. Due the reduced number of IRQs the NIU driver cannot get
enough IRQs to the interfaces, and starts to use "IO-APIC" based
IRQs.

On kernel 2.6.28: My eth2 is using 10 IRQs all "PCI-MSI-edge". BUT
my eth3 is using a single IRQ using "IO-APIC-fasteoi" and shared with
the usb driver. That my performance problem on 2.6.28.

[Other related bugs]:
Is that unloading the "niu" driver will give a kernel BUG during
deallocation og MSI interrupts. (See dmesg output below if interested)

(I have attached full bisect history)

Cheers,
Jesper Brouer

--
-------------------------------------------------------------------
MSc. Master of Computer Science
Dept. of Computer Science, University of Copenhagen
Author of http://www.adsl-optimizer.dk
-------------------------------------------------------------------

On Wed, 19 Nov 2008, David Miller wrote:
> From: Jesper Dangaard Brouer <hawk@diku.dk>
> Date: Wed, 19 Nov 2008 23:58:12 +0100 (CET)
>
>> Well that was not the real cause of the performance loss. Because
>> on kernel 2.6.27 I get really good performance (900-1200kpps)
>> compared to 2.6.28 (git net-2.6).
>>
>> The cause of this problem (tracked down together with Robert Olsson)
>> is that on 2.6.28 I have a lot less IRQs available. It seems max 34
>> IRQs.
>>
>> Due the reduced number of IRQs the NIU driver cannot get enough IRQs
>> to the interfaces, and starts to use "IO-APIC" based IRQs.
>
> This is almost certainly related to the driver unload bug.
>
> I know you ran into unbuildable/unbootable kernels during a bisect,
> but you really need to track down this regression.

------------[ cut here ]------------
kernel BUG at drivers/pci/msi.c:632!
invalid opcode: 0000 [#1] PREEMPT SMP
Modules linked in: ehci_hcd bnx2 uhci_hcd zlib_inflate serio_raw hpilo
niu(-)

Pid: 3036, comm: rmmod Not tainted (2.6.27-bisect #5) ProLiant DL380 G5
EIP: 0060:[<c021ecac>] EFLAGS: 00010286 CPU: 2
EIP is at msi_free_irqs+0xdc/0xe0
EAX: f6b8f860 EBX: 00000030 ECX: f7156ba8 EDX: c0420500
ESI: f7156800 EDI: f7156ba8 EBP: f6431eb4 ESP: f6431ea8
DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
Process rmmod (pid: 3036, ti=f6430000 task=f70f9b20 task.ti=f6430000)
Stack:
f7156800 f670c400 f7156800 f6431ebc c021ecb8 f6431ec8 c021ef41 f670c000
f6431edc f809d3f8 f7156800 f80a1ed4 f80a1ed4 f6431ee8 c0219c29 f7156858
f6431ef8 c026b0d4 f7156858 f7156914 f6431f0c c026b197 f80a1ea0 f80a1ed4
Call Trace:
[<c021ecb8>] ? msix_free_all_irqs+0x8/0x10
[<c021ef41>] ? pci_disable_msix+0x31/0x40
[<f809d3f8>] ? niu_pci_remove_one+0x88/0x8a [niu]
[<c0219c29>] ? pci_device_remove+0x19/0x40
[<c026b0d4>] ? __device_release_driver+0x54/0x80
[<c026b197>] ? driver_detach+0x97/0xa0
[<c026a475>] ? bus_remove_driver+0x75/0xa0
[<c026b609>] ? driver_unregister+0x39/0x40
[<c0219e51>] ? pci_unregister_driver+0x21/0x80
[<f809a0ad>] ? niu_exit+0xd/0x10 [niu]
[<c0145d74>] ? sys_delete_module+0x114/0x1d0
[<c016810a>] ? remove_vma+0x3a/0x50
[<c0168c29>] ? do_munmap+0x189/0x1e0
[<c0103229>] ? sysenter_do_call+0x12/0x21
[<c0330000>] ? quirk_disable_msi+0x30/0x50
Code: b7 43 08 8b 53 1c c1 e0 04 01 d0 ba 01 00 00 00 83 c0 0c 89 10 3b 7b
14 75 aa 8b 43 1c e8 3d 92 ef ff eb a0 5b 31 c0 5e 5f 5d c3 <0f> 0b eb fe
55 89 e5 e8 18 ff ff ff 5d c3 8d b6 00 00 00 00 55
EIP: [<c021ecac>] msi_free_irqs+0xdc/0xe0 SS:ESP 0068:f6431ea8
---[ end trace f72de2e283920207 ]---

[-- Attachment #2: Type: TEXT/plain, Size: 32509 bytes --]

~~ -*-text-*-

-------------------------------------------------------
Bisecting IRQ change:
What change reduced the IRQs
-------------------------------------------------------
Jesper Dangaard Brouer (jdb@comx.dk)
-------------------------------------------------------
$LastChangedRevision: 786 $
$Date: 2008-11-20 20:44:51 +0100 (Thu, 20 Nov 2008) $
-------------------------------------------------------

git clone
~~~~~~~~~

+---------
cd /var/kernels/git/davem
git clone git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-2.6.git net-2.6-bisect-irqs
+---------

Description / Reason to find
~~~~~~~~~~~~~~~~~~~~~~~~~~~~

During my testing of the Sun Neptune based NICs.

On kernel 2.6.27 I get really good performance (900-1200kpps)
compared to 2.6.28 (git net-2.6).

The cause of this problem (tracked down together with Robert Olsson)
is that on 2.6.28 I have a lot less IRQs available. It seems max 34
IRQs.

Due the reduced number of IRQs the NIU driver cannot get enough IRQs
to the interfaces, and starts to use "IO-APIC" based IRQs.

On kernel 2.6.28:

My eth2 is using 10 IRQs all "PCI-MSI-edge".

BUT my eth3 is using a single IRQ using "IO-APIC-fasteoi" and shared
with the usb driver...

Think thats must be my performance problem on 2.6.28.

Known: Good and bad
~~~~~~~~~~~~~~~~~~~

GOOD:
git bisect good v2.6.27

BAD:
git bisect bad 92b29b86fe2e183d44eb467e5e74a5f718ef2e43

[92b29b86fe2e183d44eb467e5e74a5f718ef2e43] #Merge branch
'tracing-v28-for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip

HiSTORY:
~~~~~~~~

+--------
cd /var/kernels/git/davem/net-2.6-bisect-irqs/
git bisect start
git bisect good v2.6.27
+--------

+--------------
git bisect bad 92b29b86fe2e183d44eb467e5e74a5f718ef2e43
Bisecting: 3220 revisions left to test after this
[af5c2bd16ac2e5688c3bf46ea1f95112d696d294] x86: fix virt_addr_valid() with CONFIG_DEBUG_VIRTUAL=y, v2
+--------------

CONFIG_LOCALVERSION="-bisect"

+-------------
cp ../net-2.6-bisect/.config .
script make_oldconfig_01
make oldconfig
exit
#Script done, file is make_oldconfig_01
+-------------

+----------------
time make -j6 bzImage modules
#
#real 9m22.739s
#user 16m56.776s
#sys 1m4.672s
+----------------

Booted kernel: GOOD: irqs and (niu rmmod good)

+----------------
git bisect good
Bisecting: 1614 revisions left to test after this
[36ac1d2f323f8bf8bc10c25b88f617657720e241] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/dtor/input
+----------------

Compiling:

+----------------
time make -j6 bzImage modules
+----------------

Booted kernel: GOOD: irqs and (niu rmmod good)

+-----------
git bisect good
Bisecting: 807 revisions left to test after this
[1aece34833721d64eb33fc15cd923c727296d3d3] container freezer: rename check_if_frozen()
+-----------

Compiling...

+----------------
time make -j6 bzImage modules
#real 10m1.561s
#user 17m23.293s
#sys 1m5.744s
+----------------

Installing...

Booted kernel:

+----
dcu-router-ng:~# uname -a
Linux dcu-router-ng 2.6.27-bisect #3 SMP PREEMPT Thu Nov 20 12:33:02 CET 2008 i686 GNU/Linux
+----

Results: GOOD: irqs and (niu rmmod good)

+------
git bisect good
Bisecting: 403 revisions left to test after this
[1d9a8a47d659f053abeca9ece45651b4d94780c8] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/mszeredi/fuse
+------

Compiling...

+----------------
time make -j6 bzImage modules
#real 10m9.371s
#user 17m21.781s
#sys 1m6.052s
+----------------

Installing...

Booting ...

+-------
dcu-router-ng:~# uname -a
Linux dcu-router-ng 2.6.27-bisect #4 SMP PREEMPT Thu Nov 20 12:50:39 CET 2008 i686 GNU/Linux
+-------

Results: GOOD: irqs and (niu rmmod good)

+-------
git-bisect good
Bisecting: 223 revisions left to test after this
[dd3a1db900f2a215a7d7dd71b836e149a6cf5fed] genirq: improve include files
+-------

+----------------
time make -j6 bzImage modules
+----------------

Booting ...

+--------
Linux dcu-router-ng 2.6.27-bisect #5 SMP PREEMPT Thu Nov 20 13:58:34 CET 2008 i686 GNU/Linux
+--------

Results: BAD: irqs and (niu rmmod also BAD)

+-------
cat /proc/interrupts
CPU0 CPU1 CPU2 CPU3
0: 125 0 0 0 IO-APIC-edge timer
1: 0 0 1 1 IO-APIC-edge i8042
3: 2 1 2 2 IO-APIC-edge serial
8: 0 2 0 0 IO-APIC-edge rtc
9: 0 0 0 0 IO-APIC-fasteoi acpi
12: 1 2 1 0 IO-APIC-edge i8042
16: 103 108 108 112 IO-APIC-fasteoi uhci_hcd:usb1, ehci_hcd:usb6, eth0
17: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb2
18: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb3
19: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb4, eth3
20: 0 0 0 0 PCI-MSI-edge eth2
21: 0 0 0 0 PCI-MSI-edge eth2
22: 24 23 23 23 IO-APIC-fasteoi uhci_hcd:usb5, eth2
23: 0 0 0 0 PCI-MSI-edge eth2
24: 0 0 0 0 PCI-MSI-edge eth2
25: 0 0 0 0 PCI-MSI-edge eth2
26: 0 0 0 0 PCI-MSI-edge eth2
27: 0 0 0 0 PCI-MSI-edge eth2
28: 0 0 0 0 PCI-MSI-edge eth2
29: 0 0 0 0 PCI-MSI-edge eth2
30: 0 0 0 0 PCI-MSI-edge eth2
31: 0 0 0 0 PCI-MSI-edge eth2
32: 0 0 0 0 PCI-MSI-edge eth2
34: 271 268 268 264 PCI-MSI-edge cciss0
NMI: 0 0 0 0 Non-maskable interrupts
LOC: 3301 2970 2594 2389 Local timer interrupts
RES: 28 560 6 13 Rescheduling interrupts
CAL: 50 104 99 62 Function call interrupts
TLB: 241 224 287 279 TLB shootdowns
TRM: 0 0 0 0 Thermal event interrupts
SPU: 0 0 0 0 Spurious interrupts
ERR: 0
MIS: 0
+-------

OUTPUT "rmmod niu" (gives segfault) and "dmesg"

+-------
------------[ cut here ]------------
kernel BUG at drivers/pci/msi.c:632!
invalid opcode: 0000 [#1] PREEMPT SMP
Modules linked in: ehci_hcd bnx2 uhci_hcd zlib_inflate serio_raw hpilo niu(-)

Pid: 3036, comm: rmmod Not tainted (2.6.27-bisect #5) ProLiant DL380 G5
EIP: 0060:[<c021ecac>] EFLAGS: 00010286 CPU: 2
EIP is at msi_free_irqs+0xdc/0xe0
EAX: f6b8f860 EBX: 00000030 ECX: f7156ba8 EDX: c0420500
ESI: f7156800 EDI: f7156ba8 EBP: f6431eb4 ESP: f6431ea8
DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
Process rmmod (pid: 3036, ti=f6430000 task=f70f9b20 task.ti=f6430000)
Stack:
f7156800 f670c400 f7156800 f6431ebc c021ecb8 f6431ec8 c021ef41 f670c000
f6431edc f809d3f8 f7156800 f80a1ed4 f80a1ed4 f6431ee8 c0219c29 f7156858
f6431ef8 c026b0d4 f7156858 f7156914 f6431f0c c026b197 f80a1ea0 f80a1ed4
Call Trace:
[<c021ecb8>] ? msix_free_all_irqs+0x8/0x10
[<c021ef41>] ? pci_disable_msix+0x31/0x40
[<f809d3f8>] ? niu_pci_remove_one+0x88/0x8a [niu]
[<c0219c29>] ? pci_device_remove+0x19/0x40
[<c026b0d4>] ? __device_release_driver+0x54/0x80
[<c026b197>] ? driver_detach+0x97/0xa0
[<c026a475>] ? bus_remove_driver+0x75/0xa0
[<c026b609>] ? driver_unregister+0x39/0x40
[<c0219e51>] ? pci_unregister_driver+0x21/0x80
[<f809a0ad>] ? niu_exit+0xd/0x10 [niu]
[<c0145d74>] ? sys_delete_module+0x114/0x1d0
[<c016810a>] ? remove_vma+0x3a/0x50
[<c0168c29>] ? do_munmap+0x189/0x1e0
[<c0103229>] ? sysenter_do_call+0x12/0x21
[<c0330000>] ? quirk_disable_msi+0x30/0x50
Code: b7 43 08 8b 53 1c c1 e0 04 01 d0 ba 01 00 00 00 83 c0 0c 89 10 3b 7b 14 75 aa 8b 43 1c e8 3d 92 ef ff eb a0 5b 31 c0 5e 5f 5d c3 <0f> 0b eb fe 55 89 e5 e8 18 ff ff ff 5d c3 8d b6 00 00 00 00 55
EIP: [<c021ecac>] msi_free_irqs+0xdc/0xe0 SS:ESP 0068:f6431ea8
---[ end trace f72de2e283920207 ]---
+-------

+------
git-bisect bad
Bisecting: 89 revisions left to test after this
[db4b5525caafd846ec20f95afbc6403c792e22cf] x86: apic_64.c - setup_APIC_timer has to be __cpuinit function
+------

Related config change? (make oldconfig)

+------
script make_oldconfig_02
make oldconfig
Script done, file is make_oldconfig_02
+------

+------
Support sparse irq numbering (HAVE_SPARSE_IRQ) [Y/n/?] (NEW) ? ?Y

This enables support for sparse irq, esp for msi/msi-x. the irq
number will be bus/dev/fn + 12bit. You may need if you have lots of
cards supports msi-x installed.

If you don't know what to do here, say Y.
+------

Compiling...

+----------------
time make -j6 bzImage modules
#
#real 9m29.556s
#user 17m10.396s
#sys 1m5.056s
+----------------

Booting ...

+-------
Linux dcu-router-ng 2.6.27-bisect #6 SMP PREEMPT Thu Nov 20 14:25:40 CET 2008 i686 GNU/Linux
+-------

The output from /proc/interrupts changed, very weird!
BUT eth3 does use a "PCI-MSI-edge" interrupt.

Guess this is a GOOD state even though it looks weird.

Unloading NIU driver also GOOD.

+---------
cat /proc/interrupts
CPU0 CPU1 CPU2 CPU3
0x0: 124 1 0 0 IO-APIC-edge timer
0x1: 1 0 0 1 IO-APIC-edge i8042
0x3: 2 1 2 2 IO-APIC-edge serial
0x8: 1 0 0 1 IO-APIC-edge rtc
0x9: 0 0 0 0 IO-APIC-fasteoi acpi
0xc: 0 1 2 1 IO-APIC-edge i8042
0x10: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb1, ehci_hcd:usb6
0x11: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb2
0x12: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb3
0x6000fe: 288 289 290 290 PCI-MSI-edge cciss0
0x16: 23 24 23 23 IO-APIC-fasteoi uhci_hcd:usb5
0xb00100: 0 0 0 0 PCI-MSI-edge eth2
0xb000ff: 0 0 0 0 PCI-MSI-edge eth2
0xb000fe: 0 0 0 0 PCI-MSI-edge eth2
0xb000fd: 0 0 0 0 PCI-MSI-edge eth2
0xb000fc: 0 0 0 0 PCI-MSI-edge eth2
0xb000fb: 0 0 0 0 PCI-MSI-edge eth2
0xb000fa: 0 0 0 0 PCI-MSI-edge eth2
0xb000f9: 0 0 0 0 PCI-MSI-edge eth2
0xb000f8: 0 0 0 0 PCI-MSI-edge eth2
0xb000f7: 0 0 0 0 PCI-MSI-edge eth2
0xb000f6: 0 0 0 0 PCI-MSI-edge eth2
0xb000f5: 0 0 0 0 PCI-MSI-edge eth2
0xb000f4: 0 0 0 0 PCI-MSI-edge eth2
0xb01100: 0 0 0 0 PCI-MSI-edge eth3
0xb010ff: 0 0 0 0 PCI-MSI-edge eth3
0xb010fe: 0 0 0 0 PCI-MSI-edge eth3
0xb010fd: 0 0 0 0 PCI-MSI-edge eth3
0xb010fc: 0 0 0 0 PCI-MSI-edge eth3
0xb010fb: 0 0 0 0 PCI-MSI-edge eth3
0xb010fa: 0 0 0 0 PCI-MSI-edge eth3
0xb010f9: 0 0 0 0 PCI-MSI-edge eth3
0xb010f8: 0 0 0 0 PCI-MSI-edge eth3
0xb010f7: 0 0 0 0 PCI-MSI-edge eth3
0xb010f6: 0 0 0 0 PCI-MSI-edge eth3
0x13: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb4
0x300100: 210 210 210 208 PCI-MSI-edge eth0
NMI: 0 0 0 0 Non-maskable interrupts
LOC: 3630 3265 3103 2711 Local timer interrupts
RES: 34 226 12 417 Rescheduling interrupts
CAL: 89 55 90 78 Function call interrupts
TLB: 253 205 311 267 TLB shootdowns
TRM: 0 0 0 0 Thermal event interrupts
SPU: 0 0 0 0 Spurious interrupts
ERR: 0
MIS: 0
+---------

Guess it a GOOD situation...

+------
git-bisect good
Bisecting: 44 revisions left to test after this
[ba374c9baef910fbc5373541d98c50f15e82c3f8] x86: fix HPET compiler error when not using CONFIG_PCI_MSI
+------

Compiling ...

+--------
time make -j6 bzImage modules
#real 9m28.062s
#user 17m7.492s
#sys 1m4.248s
+--------

Installing ...

Booting ...

+------
Linux dcu-router-ng 2.6.27-bisect #7 SMP PREEMPT Thu Nov 20 14:52:45 CET 2008 i686 GNU/Linux
+------

Still looks GOOD (/proc/interrupts still looks weird).

And rmmod NIU driver GOOD.

+------
git-bisect good
Bisecting: 22 revisions left to test after this
[922402f15a85f7a064926eb1db68cc52bc4d4a91] x86: Add UV partition call v4
+------

Compiling ...

+--------
time make -j6 bzImage modules
#real 0m34.622s
#user 0m41.139s
#sys 0m5.812s
+--------

Install ...

Booting ...

+-----
Linux dcu-router-ng 2.6.27-bisect #8 SMP PREEMPT Thu Nov 20 15:04:11 CET 2008 i686 GNU/Linux
+-----

Looks GOOD, and /proc/interrupts changed again! Now the interrupts
are not i HEX anymore, but in decimal, but still strange/large
numbers for MSI.

Unloading NIU driver GOOD.

+------
cat /proc/interrupts
CPU0 CPU1 CPU2 CPU3
0: 124 0 0 0 IO-APIC-edge timer
1: 0 0 1 1 IO-APIC-edge i8042
3: 2 2 1 2 IO-APIC-edge serial
8: 0 0 1 1 IO-APIC-edge rtc
9: 0 0 0 0 IO-APIC-fasteoi acpi
12: 1 2 1 0 IO-APIC-edge i8042
16: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb1, ehci_hcd:usb6
17: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb2
18: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb3
6291710: 828 821 828 823 PCI-MSI-edge cciss0
22: 23 24 24 22 IO-APIC-fasteoi uhci_hcd:usb5
11534592: 0 0 0 0 PCI-MSI-edge eth2
11534591: 0 0 0 0 PCI-MSI-edge eth2
11534590: 0 0 0 0 PCI-MSI-edge eth2
11534589: 0 0 0 0 PCI-MSI-edge eth2
11534588: 0 0 0 0 PCI-MSI-edge eth2
11534587: 0 0 0 0 PCI-MSI-edge eth2
11534586: 0 0 0 0 PCI-MSI-edge eth2
11534585: 0 0 0 0 PCI-MSI-edge eth2
11534584: 0 0 0 0 PCI-MSI-edge eth2
11534583: 0 0 0 0 PCI-MSI-edge eth2
11534582: 0 0 0 0 PCI-MSI-edge eth2
11534581: 0 0 0 0 PCI-MSI-edge eth2
11534580: 0 0 0 0 PCI-MSI-edge eth2
11538688: 0 0 0 0 PCI-MSI-edge eth3
11538687: 0 0 0 0 PCI-MSI-edge eth3
11538686: 0 0 0 0 PCI-MSI-edge eth3
11538685: 0 0 0 0 PCI-MSI-edge eth3
11538684: 0 0 0 0 PCI-MSI-edge eth3
11538683: 0 0 0 0 PCI-MSI-edge eth3
11538682: 0 0 0 0 PCI-MSI-edge eth3
11538681: 0 0 0 0 PCI-MSI-edge eth3
11538680: 0 0 0 0 PCI-MSI-edge eth3
11538679: 0 0 0 0 PCI-MSI-edge eth3
11538678: 0 0 0 0 PCI-MSI-edge eth3
19: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb4
3145984: 9993 9994 9987 9993 PCI-MSI-edge eth0
NMI: 0 0 0 0 Non-maskable interrupts
LOC: 10075 11448 8001 8787 Local timer interrupts
RES: 297 17 349 26 Rescheduling interrupts
CAL: 173 189 95 173 Function call interrupts
TLB: 299 259 330 345 TLB shootdowns
TRM: 0 0 0 0 Thermal event interrupts
SPU: 0 0 0 0 Spurious interrupts
ERR: 0
MIS: 0
+------

+-------
git-bisect good
Bisecting: 11 revisions left to test after this
[a1aca5de08a0cb840a90fb3f729a5940f8d21185] genirq: remove artifacts from sparseirq removal
+-------

Compiling

+--------
time make -j6 bzImage modules
#real 9m30.767s
#user 17m10.808s
#sys 1m6.388s
+--------

Installing ...

Booting ...

+-----
Linux dcu-router-ng 2.6.27-bisect #9 SMP PREEMPT Thu Nov 20 15:28:17 CET 2008 i686 GNU/Linux
+-----

BAD kernel version, max IRQ is 34. And eth3 got assigned a
IO-APIC-fasteoi shared with uhci_hcd:usb2.

Also BAD unloading of NIU driver.

BUG is some where in between:

git log 922402f15a85f7a064926eb1db68cc52bc4d4a91..a1aca5de08a0cb840a90fb3f729a5940f8d21185 | grep ^commit | wc -l

11 commits

+-------
git-bisect bad
Bisecting: 5 revisions left to test after this
[3235e936c0cc3589309280b6f59e5096779adae3] x86: remove sparse irq from Kconfig
+-------

Compiling...

+--------
time make -j6 bzImage modules
+--------

Install ...

Booting

+------
Linux dcu-router-ng 2.6.27-bisect #10 SMP PREEMPT Thu Nov 20 15:56:10 CET 2008 i686 GNU/Linux
+------

BAD kernel.

BAD rmmod NIU driver.

+---------
git bisect bad
Bisecting: 2 revisions left to test after this
[4c66a73f0796dacc2ff0d4af75794ec843ceb3d1] x86: sparse_irq: fix typo in debug print out
+---------

Compiling...

+------
time make -j6 bzImage modules
#real 7m23.814s
#user 12m15.718s
#sys 0m42.183s
+------

Config change prompting:

+-----
Support sparse irq numbering (HAVE_SPARSE_IRQ) [Y/n/?] (NEW) Y
+-----

Installing ...

Booting ...

+-------
Linux dcu-router-ng 2.6.27-bisect #11 SMP PREEMPT Thu Nov 20 16:19:29 CET 2008 i686 GNU/Linux
+-------

GOOD!!!

+--------
cat /proc/interrupts
CPU0 CPU1 CPU2 CPU3
0: 124 0 0 0 IO-APIC-edge timer
1: 0 0 1 1 IO-APIC-edge i8042
3: 2 2 2 2 IO-APIC-edge serial
8: 1 0 0 1 IO-APIC-edge rtc
9: 0 0 0 0 IO-APIC-fasteoi acpi
12: 1 2 1 0 IO-APIC-edge i8042
16: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb1, ehci_hcd:usb6
17: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb2
18: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb3
6291710: 285 288 293 287 PCI-MSI-edge cciss0
11534592: 0 0 0 0 PCI-MSI-edge eth2
11534591: 0 0 0 0 PCI-MSI-edge eth2
11534590: 0 0 0 0 PCI-MSI-edge eth2
11534589: 0 0 0 0 PCI-MSI-edge eth2
11534588: 0 0 0 0 PCI-MSI-edge eth2
11534587: 0 0 0 0 PCI-MSI-edge eth2
11534586: 0 0 0 0 PCI-MSI-edge eth2
11534585: 0 0 0 0 PCI-MSI-edge eth2
11534584: 0 0 0 0 PCI-MSI-edge eth2
11534583: 0 0 0 0 PCI-MSI-edge eth2
11534582: 0 0 0 0 PCI-MSI-edge eth2
11534581: 0 0 0 0 PCI-MSI-edge eth2
11534580: 0 0 0 0 PCI-MSI-edge eth2
22: 23 24 23 23 IO-APIC-fasteoi uhci_hcd:usb5
11538688: 0 0 0 0 PCI-MSI-edge eth3
11538687: 0 0 0 0 PCI-MSI-edge eth3
11538686: 0 0 0 0 PCI-MSI-edge eth3
11538685: 0 0 0 0 PCI-MSI-edge eth3
11538684: 0 0 0 0 PCI-MSI-edge eth3
11538683: 0 0 0 0 PCI-MSI-edge eth3
11538682: 0 0 0 0 PCI-MSI-edge eth3
11538681: 0 0 0 0 PCI-MSI-edge eth3
11538680: 0 0 0 0 PCI-MSI-edge eth3
11538679: 0 0 0 0 PCI-MSI-edge eth3
11538678: 0 0 0 0 PCI-MSI-edge eth3
19: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb4
3145984: 244 242 238 241 PCI-MSI-edge eth0
NMI: 0 0 0 0 Non-maskable interrupts
LOC: 3715 3104 2853 2542 Local timer interrupts
RES: 88 52 280 258 Rescheduling interrupts
CAL: 76 75 93 59 Function call interrupts
TLB: 245 241 312 283 TLB shootdowns
TRM: 0 0 0 0 Thermal event interrupts
SPU: 0 0 0 0 Spurious interrupts
ERR: 0
MIS: 0
+---------

+---------
git-bisect good
Bisecting: 1 revisions left to test after this
[7ef0c30dbf96a8d9a234e90c248eb19df3c031be] genirq: define nr_irqs for architectures with GENERIC_HARDIRQS=n
+----------

Compiling ...

+------
time make -j6 bzImage modules
+------

Install...

Boot ...

+-------
Linux dcu-router-ng 2.6.27-bisect #12 SMP PREEMPT Thu Nov 20 16:33:11 CET 2008 i686 GNU/Linux
+-------

+--------
cat /proc/interrupts
CPU0 CPU1 CPU2 CPU3
0: 124 0 0 0 IO-APIC-edge timer
1: 0 0 1 1 IO-APIC-edge i8042
3: 1 2 2 2 IO-APIC-edge serial
8: 2 0 0 0 IO-APIC-edge rtc
9: 0 0 0 0 IO-APIC-fasteoi acpi
12: 1 2 1 0 IO-APIC-edge i8042
16: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb1, ehci_hcd:usb6
17: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb2
18: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb3
6291710: 268 269 268 267 PCI-MSI-edge cciss0
11534592: 0 0 0 0 PCI-MSI-edge eth2
11534591: 0 0 0 0 PCI-MSI-edge eth2
11534590: 0 0 0 0 PCI-MSI-edge eth2
11534589: 0 0 0 0 PCI-MSI-edge eth2
11534588: 0 0 0 0 PCI-MSI-edge eth2
11534587: 0 0 0 0 PCI-MSI-edge eth2
11534586: 0 0 0 0 PCI-MSI-edge eth2
11534585: 0 0 0 0 PCI-MSI-edge eth2
11534584: 0 0 0 0 PCI-MSI-edge eth2
11534583: 0 0 0 0 PCI-MSI-edge eth2
11534582: 0 0 0 0 PCI-MSI-edge eth2
11534581: 0 0 0 0 PCI-MSI-edge eth2
11534580: 0 0 0 0 PCI-MSI-edge eth2
11538688: 0 0 0 0 PCI-MSI-edge eth3
11538687: 0 0 0 0 PCI-MSI-edge eth3
11538686: 0 0 0 0 PCI-MSI-edge eth3
11538685: 0 0 0 0 PCI-MSI-edge eth3
11538684: 0 0 0 0 PCI-MSI-edge eth3
11538683: 0 0 0 0 PCI-MSI-edge eth3
11538682: 0 0 0 0 PCI-MSI-edge eth3
11538681: 0 0 0 0 PCI-MSI-edge eth3
11538680: 0 0 0 0 PCI-MSI-edge eth3
11538679: 0 0 0 0 PCI-MSI-edge eth3
11538678: 0 0 0 0 PCI-MSI-edge eth3
19: 0 0 0 0 IO-APIC-fasteoi uhci_hcd:usb4
22: 25 23 24 25 IO-APIC-fasteoi uhci_hcd:usb5
3145984: 175 174 176 178 PCI-MSI-edge eth0
NMI: 0 0 0 0 Non-maskable interrupts
LOC: 3508 2902 2765 2489 Local timer interrupts
RES: 238 35 461 6 Rescheduling interrupts
CAL: 61 90 59 81 Function call interrupts
TLB: 257 220 299 300 TLB shootdowns
TRM: 0 0 0 0 Thermal event interrupts
SPU: 0 0 0 0 Spurious interrupts
ERR: 0
MIS: 0
+--------

GOOD.

+----------
git-bisect good
3235e936c0cc3589309280b6f59e5096779adae3 is first bad commit
commit 3235e936c0cc3589309280b6f59e5096779adae3
Author: Thomas Gleixner <tglx@linutronix.de>
Date: Wed Oct 15 13:16:00 2008 +0200

x86: remove sparse irq from Kconfig

This code is not ready yet.

Signed-off-by: Thomas Gleixner <tglx@linutronix.de>

:040000 040000 6043e32465556e828de0fbb6aa497b277239af01 2dd75ba207990d83a3a4c7b7b16abccfe2d5e10d M arch
+--------

Found bad commit:
3235e936c0cc3589309280b6f59e5096779adae3

Git bisect LOG
~~~~~~~~~~~~~~

+-------
git-bisect log
git-bisect start
# good: [3fa8749e584b55f1180411ab1b51117190bac1e5] Linux 2.6.27
git-bisect good 3fa8749e584b55f1180411ab1b51117190bac1e5
# bad: [92b29b86fe2e183d44eb467e5e74a5f718ef2e43] Merge branch 'tracing-v28-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
git-bisect bad 92b29b86fe2e183d44eb467e5e74a5f718ef2e43
# good: [af5c2bd16ac2e5688c3bf46ea1f95112d696d294] x86: fix virt_addr_valid() with CONFIG_DEBUG_VIRTUAL=y, v2
git-bisect good af5c2bd16ac2e5688c3bf46ea1f95112d696d294
# good: [36ac1d2f323f8bf8bc10c25b88f617657720e241] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/dtor/input
git-bisect good 36ac1d2f323f8bf8bc10c25b88f617657720e241
# good: [1aece34833721d64eb33fc15cd923c727296d3d3] container freezer: rename check_if_frozen()
git-bisect good 1aece34833721d64eb33fc15cd923c727296d3d3
# good: [1d9a8a47d659f053abeca9ece45651b4d94780c8] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/mszeredi/fuse
git-bisect good 1d9a8a47d659f053abeca9ece45651b4d94780c8
# bad: [dd3a1db900f2a215a7d7dd71b836e149a6cf5fed] genirq: improve include files
git-bisect bad dd3a1db900f2a215a7d7dd71b836e149a6cf5fed
# good: [db4b5525caafd846ec20f95afbc6403c792e22cf] x86: apic_64.c - setup_APIC_timer has to be __cpuinit function
git-bisect good db4b5525caafd846ec20f95afbc6403c792e22cf
# good: [ba374c9baef910fbc5373541d98c50f15e82c3f8] x86: fix HPET compiler error when not using CONFIG_PCI_MSI
git-bisect good ba374c9baef910fbc5373541d98c50f15e82c3f8
# good: [922402f15a85f7a064926eb1db68cc52bc4d4a91] x86: Add UV partition call v4
git-bisect good 922402f15a85f7a064926eb1db68cc52bc4d4a91
# bad: [a1aca5de08a0cb840a90fb3f729a5940f8d21185] genirq: remove artifacts from sparseirq removal
git-bisect bad a1aca5de08a0cb840a90fb3f729a5940f8d21185
# bad: [3235e936c0cc3589309280b6f59e5096779adae3] x86: remove sparse irq from Kconfig
git-bisect bad 3235e936c0cc3589309280b6f59e5096779adae3
# good: [4c66a73f0796dacc2ff0d4af75794ec843ceb3d1] x86: sparse_irq: fix typo in debug print out
git-bisect good 4c66a73f0796dacc2ff0d4af75794ec843ceb3d1
# good: [7ef0c30dbf96a8d9a234e90c248eb19df3c031be] genirq: define nr_irqs for architectures with GENERIC_HARDIRQS=n
git-bisect good 7ef0c30dbf96a8d9a234e90c248eb19df3c031be
+-------

Email
~~~~~

To:
Thomas Gleixner <tglx@linutronix.de>
David Miller <davem@davemloft.net>,
Jesper Dangaard Brouer <jdb@comx.dk>,
netdev <netdev@vger.kernel.org>,
linux-kernel@vger.kernel.org,
Robert Olsson <Robert.Olsson@data.slu.se>

Subj.:
Regression: Bisected, IRQ and MSI allocations screwed without sparse irq

Hi Thomas Gleixner,

I have bisected a regression to your commit
3235e936c0cc3589309280b6f59e5096779adae3, "x86: remove sparse irq
from Kconfig".

Its actually not necessary your fault, as your commit simply removes
the config option HAVE_SPARSE_IRQ. This revels the bug / regression
I'm exposted to.

Guess I should bisect again to find the exact faulty commit, but I'm
rather sick of bisecting at the moment, and though you might have a
better idea whats going wrong. I would rather spend my time
performance tuning the multiqueue routing code...

[The regression]:

During my testing of the Sun Neptune based NICs. On kernel 2.6.27 I
get really good performance (900-1200kpps) compared to 2.6.28 (davem
git net-2.6).

The cause of this problem (tracked down together with Robert Olsson)
is that on 2.6.28 I have a lot less IRQs available. It seems max 34
IRQs. Due the reduced number of IRQs the NIU driver cannot get
enough IRQs to the interfaces, and starts to use "IO-APIC" based
IRQs.

On kernel 2.6.28: My eth2 is using 10 IRQs all "PCI-MSI-edge". BUT
my eth3 is using a single IRQ using "IO-APIC-fasteoi" and shared with
the usb driver. That my performance problem on 2.6.28.

[Other related bugs]:
Is that unloading the "niu" driver will give a kernel BUG.