NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

Hi DaveM

I just bought the Sun x8 Express Quad Gigabit Ethernet Adapter you
recommended to me.  It seem to work with the NIU driver (I can ping
through the box), but I get a kernel warning when spamming it with
pktgen...

Where do I go from here?
And what do you want me to try?

Tested on kernels:
  Kernel: 2.6.28-rc2
  Kernel: 2.6.27

CPU:    Intel(R) Xeon(R) CPU E5335  @ 2.00GHz
System: HP ProLiant DL380-G5

------------[ cut here ]------------
WARNING: at net/sched/sch_generic.c:226 dev_watchdog+0x21e/0x230()
NETDEV WATCHDOG: eth2 (niu): transmit timed out
Modules linked in: ehci_hcd ipmi_si ipmi_msghandler rng_core hpwdt
uhci_hcd serio_raw hpilo bnx2 zlib_inflate niu
Pid: 0, comm: swapper Not tainted 2.6.28-rc2-torvalds #2
Call Trace:
 [<c0126773>] warn_slowpath+0x63/0x80
 [<c01201ce>] ? __enqueue_entity+0x8e/0xb0
 [<c01202fd>] ? enqueue_task_fair+0x2d/0xe0
 [<c0108ca9>] ? read_tsc+0x9/0x30
 [<c0108ca9>] ? read_tsc+0x9/0x30
 [<c013f52b>] ? getnstimeofday+0x3b/0xe0
 [<c021f48e>] ? strlcpy+0x1e/0x60
 [<c0326a8e>] dev_watchdog+0x21e/0x230
 [<c0108ca9>] ? read_tsc+0x9/0x30
 [<c013f52b>] ? getnstimeofday+0x3b/0xe0
 [<c012f19b>] ? cascade+0x4b/0x60
 [<c012f2cf>] run_timer_softirq+0x11f/0x190
 [<c014399c>] ? tick_dev_program_event+0x3c/0xc0
 [<c0326870>] ? dev_watchdog+0x0/0x230
 [<c012b024>] __do_softirq+0x94/0x160
 [<c013cc7a>] ? hrtimer_interrupt+0x14a/0x170
 [<c012b12b>] do_softirq+0x3b/0x50
 [<c012b335>] irq_exit+0x75/0x90
 [<c01141ca>] smp_apic_timer_interrupt+0x5a/0x90
 [<c013ca8a>] ? hrtimer_start+0x1a/0x20
 [<c0103ee0>] apic_timer_interrupt+0x28/0x30
 [<c0109cd5>] ? mwait_idle+0x35/0x40
 [<c0101c1e>] cpu_idle+0x4e/0xa0
---[ end trace 28edc9a90244cfaf ]---
niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting
niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting
niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting
niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting
niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting


-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Jesper Dangaard Brouer <jdb@comx.dk>
Date: Tue, 04 Nov 2008 15:45:09 +0100

> I just bought the Sun x8 Express Quad Gigabit Ethernet Adapter you
> recommended to me.  It seem to work with the NIU driver (I can ping
> through the box), but I get a kernel warning when spamming it with
> pktgen...
> 
> Where do I go from here?
> And what do you want me to try?

Looks like the transmitter is wedged.

Using current sources I assume?

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

[-- Attachment #1: Type: text/plain, Size: 3820 bytes --]

On Tue, 2008-11-04 at 13:42 -0800, David Miller wrote:
> From: Jesper Dangaard Brouer <jdb@comx.dk>
> Date: Tue, 04 Nov 2008 15:45:09 +0100
> 
> > I just bought the Sun x8 Express Quad Gigabit Ethernet Adapter you
> > recommended to me.  It seem to work with the NIU driver (I can ping
> > through the box), but I get a kernel warning when spamming it with
> > pktgen...
> > 
> > Where do I go from here?
> > And what do you want me to try?
> 
> Looks like the transmitter is wedged.

I have attached niu related output from kern.log.
(cat /var/log/kern.log | grep niu | awk -F'kernel:' '{print $2}')

> Using current sources I assume?

Yes, your latest tree.  Both with and without your latest change to the
niu driver (niu: Use pci_ioremap_bar().).

Also tried a debian 2.6.26-1-686, that kernel actually crashed (in
net_rx_action, __do_softirq, do_softirq, irq_exit, do_IRQ, mwait_idle).

A strange observation is the IRQ allocations seen via /proc/interrupts:
(e.g. eth2 has assigned no less than 12 IRQs !?!)

dcu-router-ng:~# cat /proc/interrupts 
           CPU0       CPU1       CPU2       CPU3       
  0:        123          1          0          1   IO-APIC-edge      timer
  1:          1          0          0          1   IO-APIC-edge      i8042
  3:          2          2          1          2   IO-APIC-edge      serial
  9:          0          0          0          0   IO-APIC-fasteoi   acpi
 12:          0          1          2          1   IO-APIC-edge      i8042
 14:         15         14         13         15   IO-APIC-edge      ata_piix
 15:          0          0          0          0   IO-APIC-edge      ata_piix
 16:        404        412        424        367   IO-APIC-fasteoi   uhci_hcd:usb1, ehci_hcd:usb6, eth0
 17:          0          0          0          0   IO-APIC-fasteoi   uhci_hcd:usb2, eth3
 18:          8          9          8          9   IO-APIC-fasteoi   uhci_hcd:usb3
 19:          0          0          0          0   IO-APIC-fasteoi   uhci_hcd:usb4
 20:          0          0          0          0   PCI-MSI-edge      eth2
 21:        963        959        942        997   IO-APIC-fasteoi   ipmi_si, eth2
 22:         23         23         24         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:        318        310        319        317   PCI-MSI-edge      cciss0
NMI:          0          0          0          0   Non-maskable interrupts
LOC:      89420     334612     485037     172341   Local timer interrupts
RES:        101        270        159        174   Rescheduling interrupts
CAL:         83        132        122         74   Function call interrupts
TLB:        259        226        350        315   TLB shootdowns
TRM:          0          0          0          0   Thermal event interrupts
SPU:          0          0          0          0   Spurious interrupts
ERR:          0
MIS:          0

-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

[-- Attachment #2: niu_kern.log --]
[-- Type: text/x-log, Size: 4992 bytes --]

cat /var/log/kern.log | grep niu | awk -F'kernel:' '{print $2}' > niu_kern.log

 niu.c:v0.9 (May 4, 2008)
 niu 0000:0b:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
 niu: niu_get_parent: platform_type[1] port[0]
 niu: niu_new_parent: Creating new parent.
 niu 0000:0b:00.0: setting latency timer to 64
 niu: niu_get_invariants: VPD offset [00016a00]
 niu: VPD_SCAN: start[16a14] end[16b98]
 niu: VPD_SCAN: Reading in property [local-mac-address] len[6]
 niu: VPD_SCAN: Reading in property [version] len[38]
 niu: VPD_SCAN: Reading in property [model] len[14]
 niu: VPD_SCAN: Reading in property [board-model] len[12]
 niu: VPD_SCAN: Reading in property [num-mac-addresses] len[1]
 niu: VPD_SCAN: Reading in property [phy-type] len[4]
 niu: VPD_SCAN: FCODE major(3) minor(9)
 niu: niu_get_and_validate_port: port[0] num_ports[4]
 niu: niu_probe_ports(): port_phy[00000000]
 niu0: Found PHY 002060b1 type MII at phy_port 10
 niu0: Found PHY 002060b1 type MII at phy_port 11
 niu0: Found PHY 002060b1 type MII at phy_port 12
 niu0: Found PHY 002060b1 type MII at phy_port 13
 niu: niu0: Port 0 [4 RX chans] [6 TX chans]
 niu: niu0: Port 1 [4 RX chans] [6 TX chans]
 niu: niu0: Port 2 [4 RX chans] [6 TX chans]
 niu: niu0: Port 3 [4 RX chans] [6 TX chans]
 niu: niu0: Port 0 RDC tbl(0) [ 0 1 2 3 0 1 2 3 0 1 2 3 0 1 2 3 ]
 niu: niu0: Port 0 RDC tbl(1) [ 0 1 2 3 0 1 2 3 0 1 2 3 0 1 2 3 ]
 niu: niu0: Port 1 RDC tbl(2) [ 4 5 6 7 4 5 6 7 4 5 6 7 4 5 6 7 ]
 niu: niu0: Port 1 RDC tbl(3) [ 4 5 6 7 4 5 6 7 4 5 6 7 4 5 6 7 ]
 niu: niu0: Port 2 RDC tbl(4) [ 8 9 10 11 8 9 10 11 8 9 10 11 8 9 10 11 ]
 niu: niu0: Port 2 RDC tbl(5) [ 8 9 10 11 8 9 10 11 8 9 10 11 8 9 10 11 ]
 niu: niu0: Port 3 RDC tbl(6) [ 12 13 14 15 12 13 14 15 12 13 14 15 12 13 14 15 ]
 niu: niu0: Port 3 RDC tbl(7) [ 12 13 14 15 12 13 14 15 12 13 14 15 12 13 14 15 ]
 niu 0000:0b:00.0: irq 32 for MSI/MSI-X
 niu 0000:0b:00.0: irq 31 for MSI/MSI-X
 niu 0000:0b:00.0: irq 30 for MSI/MSI-X
 niu 0000:0b:00.0: irq 29 for MSI/MSI-X
 niu 0000:0b:00.0: irq 28 for MSI/MSI-X
 niu 0000:0b:00.0: irq 27 for MSI/MSI-X
 niu 0000:0b:00.0: irq 26 for MSI/MSI-X
 niu 0000:0b:00.0: irq 25 for MSI/MSI-X
 niu 0000:0b:00.0: irq 24 for MSI/MSI-X
 niu 0000:0b:00.0: irq 23 for MSI/MSI-X
 niu 0000:0b:00.0: irq 22 for MSI/MSI-X
 niu 0000:0b:00.0: irq 21 for MSI/MSI-X
 niu 0000:0b:00.0: irq 20 for MSI/MSI-X
 niu: niu_classifier_swstate_init: num_tcam(256)
 niu: fflp_early_init: Initting hw on port 0
 niu: fflp_early_init: Success
 niu 0000:0b:00.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
 niu: niu_get_parent: platform_type[1] port[1]
 niu 0000:0b:00.1: setting latency timer to 64
 niu: niu_get_invariants: VPD offset [00016a00]
 niu: VPD_SCAN: start[16a14] end[16b98]
 niu: VPD_SCAN: Reading in property [local-mac-address] len[6]
 niu: VPD_SCAN: Reading in property [version] len[38]
 niu: VPD_SCAN: Reading in property [model] len[14]
 niu: VPD_SCAN: Reading in property [board-model] len[12]
 niu: VPD_SCAN: Reading in property [num-mac-addresses] len[1]
 niu: VPD_SCAN: Reading in property [phy-type] len[4]
 niu: VPD_SCAN: FCODE major(3) minor(9)
 niu: niu_get_and_validate_port: port[1] num_ports[4]
 niu: niu_probe_ports(): port_phy[000000aa]
 niu: niu_classifier_swstate_init: num_tcam(256)
 niu 0000:0b:00.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 niu: niu_get_parent: platform_type[1] port[2]
 niu 0000:0b:00.2: setting latency timer to 64
 niu: niu_get_invariants: VPD offset [00016a00]
 niu: VPD_SCAN: start[16a14] end[16b98]
 niu: VPD_SCAN: Reading in property [local-mac-address] len[6]
 niu: VPD_SCAN: Reading in property [version] len[38]
 niu: VPD_SCAN: Reading in property [model] len[14]
 niu: VPD_SCAN: Reading in property [board-model] len[12]
 niu: VPD_SCAN: Reading in property [num-mac-addresses] len[1]
 niu: VPD_SCAN: Reading in property [phy-type] len[4]
 niu: VPD_SCAN: FCODE major(3) minor(9)
 niu: niu_get_and_validate_port: port[2] num_ports[4]
 niu: niu_probe_ports(): port_phy[000000aa]
 niu: niu_classifier_swstate_init: num_tcam(256)
 niu 0000:0b:00.3: PCI INT D -> GSI 19 (level, low) -> IRQ 19
 niu: niu_get_parent: platform_type[1] port[3]
 niu 0000:0b:00.3: setting latency timer to 64
 niu: niu_get_invariants: VPD offset [00016a00]
 niu: VPD_SCAN: start[16a14] end[16b98]
 niu: VPD_SCAN: Reading in property [local-mac-address] len[6]
 niu: VPD_SCAN: Reading in property [version] len[38]
 niu: VPD_SCAN: Reading in property [model] len[14]
 niu: VPD_SCAN: Reading in property [board-model] len[12]
 niu: VPD_SCAN: Reading in property [num-mac-addresses] len[1]
 niu: VPD_SCAN: Reading in property [phy-type] len[4]
 niu: VPD_SCAN: FCODE major(3) minor(9)
 niu: niu_get_and_validate_port: port[3] num_ports[4]
 niu: niu_probe_ports(): port_phy[000000aa]
 niu: niu_classifier_swstate_init: num_tcam(256)
 niu: eth2: Link is up at 1Gb/sec, full duplex
 niu: eth3: Link is up at 1Gb/sec, full duplex

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Jesper Dangaard Brouer <jdb@comx.dk>
Date: Wed, 05 Nov 2008 08:05:44 +0100

> A strange observation is the IRQ allocations seen via /proc/interrupts:
> (e.g. eth2 has assigned no less than 12 IRQs !?!)

One for each TX and RX queue and then one for "other events".

If you disable MSI on the system (I forget the kernel command
line option offhand) does that make the problem go away?

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

On Tue, 2008-11-04 at 23:33 -0800, David Miller wrote:
> From: Jesper Dangaard Brouer <jdb@comx.dk>
> Date: Wed, 05 Nov 2008 08:05:44 +0100
> 
> > A strange observation is the IRQ allocations seen via /proc/interrupts:
> > (e.g. eth2 has assigned no less than 12 IRQs !?!)
> 
> One for each TX and RX queue and then one for "other events".
> 
> If you disable MSI on the system (I forget the kernel command
> line option offhand) 

pci=nomsi

> does that make the problem go away?

No :-(

I can trick the bug by simply doing a 'ping -A' from the host it self.

The /proc/interrupts output now only has one IRQ per interface.

dcu-router-ng:~# cat /proc/interrupts 
           CPU0       CPU1       CPU2       CPU3       
  0:        124          2          0          0   IO-APIC-edge      timer
  1:          1          0          0          1   IO-APIC-edge      i8042
  3:          2          2          1          2   IO-APIC-edge      serial
  9:          0          0          0          0   IO-APIC-fasteoi   acpi
 12:          0          1          2          1   IO-APIC-edge      i8042
 14:         14         15         13         15   IO-APIC-edge      ata_piix
 15:          0          0          0          0   IO-APIC-edge      ata_piix
 16:        627        620        603        614   IO-APIC-fasteoi   uhci_hcd:usb1, ehci_hcd:usb6, eth0, eth2
 17:         60         64         60         59   IO-APIC-fasteoi   uhci_hcd:usb2, eth3
 18:       2623       2623       2629       2622   IO-APIC-fasteoi   cciss0, uhci_hcd:usb3
 19:          0          0          0          0   IO-APIC-fasteoi   uhci_hcd:usb4
 21:       1182       1179       1203       1196   IO-APIC-fasteoi   ipmi_si
 22:         24         26         23         24   IO-APIC-fasteoi   uhci_hcd:usb5
NMI:          0          0          0          0   Non-maskable interrupts
LOC:     104435     484481     543096     164600   Local timer interrupts
RES:        111        123        234        229   Rescheduling interrupts
CAL:         89        130        133         68   Function call interrupts
TLB:        266        263        363        449   TLB shootdowns
TRM:          0          0          0          0   Thermal event interrupts
SPU:          0          0          0          0   Spurious interrupts
ERR:          0
MIS:          0


niu: eth2: Link is up at 1Gb/sec, full duplex
niu: eth3: Link is up at 1Gb/sec, full duplex
bnx2: eth0 NIC Copper Link is Up, 1000 Mbps full duplex
------------[ cut here ]------------
WARNING: at net/sched/sch_generic.c:226 dev_watchdog+0x21e/0x230()
NETDEV WATCHDOG: eth3 (niu): transmit timed out
Modules linked in: ehci_hcd hpwdt ipmi_si ipmi_msghandler uhci_hcd bnx2 zlib_inflate rng_core serio_raw hpilo niu sr_mod cdrom
Pid: 0, comm: swapper Not tainted 2.6.28-rc2-davem #15
Call Trace:
 [<c01256a3>] warn_slowpath+0x63/0x80
 [<c0145154>] ? __lock_acquire+0x104/0x8e0
 [<c0145154>] ? __lock_acquire+0x104/0x8e0
 [<c0145154>] ? __lock_acquire+0x104/0x8e0
 [<c0144899>] ? lock_release_holdtime+0x79/0xc0
 [<c021fb4e>] ? strlcpy+0x1e/0x60
 [<c031f2ae>] dev_watchdog+0x21e/0x230
 [<c0144899>] ? lock_release_holdtime+0x79/0xc0
 [<c012e33d>] ? run_timer_softirq+0x10d/0x190
 [<c012e34f>] run_timer_softirq+0x11f/0x190
 [<c014333c>] ? tick_dev_program_event+0x3c/0xc0
 [<c031f090>] ? dev_watchdog+0x0/0x230
 [<c012a084>] __do_softirq+0x94/0x160
 [<c013c4c0>] ? hrtimer_interrupt+0x150/0x180
 [<c012a18b>] do_softirq+0x3b/0x50
 [<c012a395>] irq_exit+0x75/0x90
 [<c011365a>] smp_apic_timer_interrupt+0x5a/0x90
 [<c0103f0c>] apic_timer_interrupt+0x28/0x30
 [<c01090e5>] ? mwait_idle+0x35/0x40
 [<c0101c1e>] cpu_idle+0x4e/0xa0
---[ end trace aceba7adff184265 ]---
niu 0000:0b:00.1: niu: eth3: Transmit timed out, resetting




-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Jesper Dangaard Brouer <jdb@comx.dk>
Date: Wed, 05 Nov 2008 10:30:27 +0100

> I can trick the bug by simply doing a 'ping -A' from the host it
> self.

I can't reproduce here, sorry.

There must be something unique about your card or system.

I won't have time to dig more deeply into this until
next week some time.  View this as an excellent opportunity
for you to lean how the chip and the driver works yourself
and to start trying to dump TX ring chip information when
the hang occurs. :-)

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Krogh]

Jesper Dangaard Brouer wrote:
> Hi DaveM
> 
> I just bought the Sun x8 Express Quad Gigabit Ethernet Adapter you
> recommended to me.  It seem to work with the NIU driver (I can ping
> through the box), but I get a kernel warning when spamming it with
> pktgen...
> 
> Where do I go from here?
> And what do you want me to try?
> 
> Tested on kernels:
>   Kernel: 2.6.28-rc2
>   Kernel: 2.6.27
> 
> CPU:    Intel(R) Xeon(R) CPU E5335  @ 2.00GHz
> System: HP ProLiant DL380-G5
> 
> ------------[ cut here ]------------
> WARNING: at net/sched/sch_generic.c:226 dev_watchdog+0x21e/0x230()
> NETDEV WATCHDOG: eth2 (niu): transmit timed out
> Modules linked in: ehci_hcd ipmi_si ipmi_msghandler rng_core hpwdt
> uhci_hcd serio_raw hpilo bnx2 zlib_inflate niu
> Pid: 0, comm: swapper Not tainted 2.6.28-rc2-torvalds #2
> Call Trace:
>  [<c0126773>] warn_slowpath+0x63/0x80
>  [<c01201ce>] ? __enqueue_entity+0x8e/0xb0
>  [<c01202fd>] ? enqueue_task_fair+0x2d/0xe0
>  [<c0108ca9>] ? read_tsc+0x9/0x30
>  [<c0108ca9>] ? read_tsc+0x9/0x30
>  [<c013f52b>] ? getnstimeofday+0x3b/0xe0
>  [<c021f48e>] ? strlcpy+0x1e/0x60
>  [<c0326a8e>] dev_watchdog+0x21e/0x230
>  [<c0108ca9>] ? read_tsc+0x9/0x30
>  [<c013f52b>] ? getnstimeofday+0x3b/0xe0
>  [<c012f19b>] ? cascade+0x4b/0x60
>  [<c012f2cf>] run_timer_softirq+0x11f/0x190
>  [<c014399c>] ? tick_dev_program_event+0x3c/0xc0
>  [<c0326870>] ? dev_watchdog+0x0/0x230
>  [<c012b024>] __do_softirq+0x94/0x160
>  [<c013cc7a>] ? hrtimer_interrupt+0x14a/0x170
>  [<c012b12b>] do_softirq+0x3b/0x50
>  [<c012b335>] irq_exit+0x75/0x90
>  [<c01141ca>] smp_apic_timer_interrupt+0x5a/0x90
>  [<c013ca8a>] ? hrtimer_start+0x1a/0x20
>  [<c0103ee0>] apic_timer_interrupt+0x28/0x30
>  [<c0109cd5>] ? mwait_idle+0x35/0x40
>  [<c0101c1e>] cpu_idle+0x4e/0xa0
> ---[ end trace 28edc9a90244cfaf ]---
> niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting
> niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting
> niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting
> niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting
> niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting

Not that it solves the problem, but it looks awfully much like this 
problem I reported 6 months back on the niu-driver just using a 10GbitE 
card.

http://article.gmane.org/gmane.linux.kernel/677545/match=niu

I shifted to a binary driver i got from Matheos Worku and that
hasn't blown up since. (I expect that can rule out hardware problems).

Jesper
-- 
Jesper Krogh

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Jesper Krogh <jesper@krogh.cc>
Date: Tue, 11 Nov 2008 20:19:16 +0100

> Not that it solves the problem, but it looks awfully much like this problem I reported 6 months back on the niu-driver just using a 10GbitE card.
> 
> http://article.gmane.org/gmane.linux.kernel/677545/match=niu
> 
> I shifted to a binary driver i got from Matheos Worku and that
> hasn't blown up since. (I expect that can rule out hardware problems).

Since I've never seen this behavior myself (and neither have people
doing very high log routing tests with these cards, such as Robert
Olsson) I plan to start putting together some debugging patches for
analyzing this TX hang.

If you could run those test patches when I post them and give
the log messages they produce, I'd appreciate it.

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: David Miller <davem@davemloft.net>
Date: Tue, 11 Nov 2008 15:50:41 -0800 (PST)

> If you could run those test patches when I post them and give
> the log messages they produce, I'd appreciate it.

Ok, let's start with this debugging patch below.

When the chip gets a TX timeout it's going to dump a lot of
state.  First it will dump the state of the logic device group
interrupt vectors (both hardware and software copies).

Then, for each TX ring, it will dump the TX_CS register (both
software and hardware copies), the mapping from that TX ring
to logical-device number and logical device group.  It will
also print out how many packets are in the ring but not freed
up yet.

Please post the dump that results when the condition triggers.
Just provide the first dump the kernel spits out.

Thanks.

diff --git a/drivers/net/niu.c b/drivers/net/niu.c
index 2c3bb36..beffbc5 100644
--- a/drivers/net/niu.c
+++ b/drivers/net/niu.c
@@ -6070,12 +6070,79 @@ static void niu_reset_task(struct work_struct *work)
 	spin_unlock_irqrestore(&np->lock, flags);
 }
 
+static void niu_dump_ldg_vecs(struct net_device *dev)
+{
+	struct niu *np = netdev_priv(dev);
+	int i;
+
+	for (i = 0; i < np->num_ldg; i++) {
+		struct niu_ldg *lp = &np->ldg[i];
+		u64 v0, v1, v2;
+
+		v0 = nr64(LDSV0(lp->ldg_num));
+		v1 = nr64(LDSV1(lp->ldg_num));
+		v2 = nr64(LDSV2(lp->ldg_num));
+
+		dev_err(np->device, PFX "%s: LDG[idx(%d):num(%u)] "
+			"V0[sw(0x%llx)hw(0x%llx)] "
+			"V1[sw(0x%llx)hw(0x%llx)] "
+			"V2[sw(0x%llx)hw(0x%llx)]\n",
+			dev->name, i, lp->ldg_num,
+			(unsigned long long) lp->v0,
+			(unsigned long long) v0,
+			(unsigned long long) lp->v1,
+			(unsigned long long) v1,
+			(unsigned long long) lp->v2,
+			(unsigned long long) v2);
+	}
+}
+
+static void niu_dump_one_tx_ring(struct net_device *dev,
+				 struct niu *np, int index)
+{
+	struct tx_ring_info *rp = &np->tx_rings[index];
+	struct niu_parent *parent = np->parent;
+	int ldn = LDN_TXDMA(rp->tx_channel);
+	int i, num_pending_skbs = 0;
+
+	dev_err(np->device, PFX "%s: TX_RING[%2u] CHANNEL %u LDN %u\n",
+		dev->name, index, rp->tx_channel, ldn);
+
+	dev_err(np->device, PFX "%s: TX_RING[%2u] parent->lgd_map[ldn] %u\n",
+		dev->name, index, parent->ldg_map[ldn]);
+
+	for (i = 0; i < MAX_TX_RING_SIZE; i++) {
+		if (rp->tx_buffs[i].skb)
+			num_pending_skbs++;
+	}
+	dev_err(np->device, PFX "%s: TX_RING[%2u] Num pending TX SKBs: %d\n",
+		dev->name, index, num_pending_skbs);
+	dev_err(np->device, PFX "%s: TX_RING[%2u] TX_CS sw[%016llx] "
+		"hw[%016llx]\n",
+		dev->name, index,
+		(unsigned long long) rp->tx_cs,
+		(unsigned long long) nr64(TX_CS(rp->tx_channel)));
+}
+
+static void niu_dump_tx_state(struct net_device *dev)
+{
+	struct niu *np = netdev_priv(dev);
+	int i;
+
+	dev_err(np->device, PFX "%s: Dumping transmitter state.\n",
+		dev->name);
+	for (i = 0; i < np->num_tx_rings; i++)
+		niu_dump_one_tx_ring(dev, np, i);
+}
+
 static void niu_tx_timeout(struct net_device *dev)
 {
 	struct niu *np = netdev_priv(dev);
 
 	dev_err(np->device, PFX "%s: Transmit timed out, resetting\n",
 		dev->name);
+	niu_dump_ldg_vecs(dev);
+	niu_dump_tx_state(dev);
 
 	schedule_work(&np->reset_task);
 }

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

Hi DaveM

Before trying out the patch, I'll give you a small status on my
progress.

When using Sun's "nxge" driver everything works.  Although this driver
is quite slow because it does not use the new TX qdisc scheme.  I hacked
net/core/dev.c to avoid the qdisc TX code-path, and got an amazing
speedup, as I now can route 930 kpps (packets per sec).

I played a bit with the msglvl (debug log level) via:
  ethtool -s eth2 msglvl 0x587

Enabling:
 NETIF_MSG_TX_ERR
 NETIF_MSG_TX_QUEUED
 NETIF_MSG_TX_DONE

The thing I noticed is that it looks like the function niu_tx_work() is
never called... (it contains a niudbg(TX_DONE, ...))

-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Jesper Dangaard Brouer <jdb@comx.dk>
Date: Wed, 12 Nov 2008 10:36:33 +0100

> The thing I noticed is that it looks like the function niu_tx_work() is
> never called... (it contains a niudbg(TX_DONE, ...))

That means no interrupts are arriving at all for TX.

Oddly, you tried without MSI enabled (do I remember right ?) and that
still failed, so it doesn't seem like it could be a MSI specific
problem.

Get the dump from the patch I sent and I should be able to have some
idea why this problem might be happening.

Thanks.

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

On Wed, 2008-11-12 at 01:49 -0800, David Miller wrote:
> From: Jesper Dangaard Brouer <jdb@comx.dk>
> Date: Wed, 12 Nov 2008 10:36:33 +0100
>
> Oddly, you tried without MSI enabled (do I remember right ?) and that
> still failed, so it doesn't seem like it could be a MSI specific
> problem.

Yes, I have tried to disable MSI.

> Get the dump from the patch I sent and I should be able to have some
> idea why this problem might be happening.

------------[ cut here ]------------
WARNING: at net/sched/sch_generic.c:226 dev_watchdog+0x21e/0x230()
NETDEV WATCHDOG: eth2 (niu): transmit timed out
Modules linked in: niu rng_core hpilo bnx2 serio_raw ipmi_si ipmi_msghandler hpwdt zlib_inflate ehci_hcd uhci_hcd sr_mod cdrom [last unloaded: nxge]
Pid: 0, comm: swapper Not tainted 2.6.28-rc2-davem #15
Call Trace:
 [<c01256a3>] warn_slowpath+0x63/0x80
 [<c011ef6e>] ? __enqueue_entity+0x8e/0xb0
 [<c0145154>] ? __lock_acquire+0x104/0x8e0
 [<c0144899>] ? lock_release_holdtime+0x79/0xc0
 [<c021fb4e>] ? strlcpy+0x1e/0x60
 [<c031f2ae>] dev_watchdog+0x21e/0x230
 [<c0144899>] ? lock_release_holdtime+0x79/0xc0
 [<c012e33d>] ? run_timer_softirq+0x10d/0x190
 [<c012e34f>] run_timer_softirq+0x11f/0x190
 [<c014333c>] ? tick_dev_program_event+0x3c/0xc0
 [<c031f090>] ? dev_watchdog+0x0/0x230
 [<c012a084>] __do_softirq+0x94/0x160
 [<c013c4c0>] ? hrtimer_interrupt+0x150/0x180
 [<c012a18b>] do_softirq+0x3b/0x50
 [<c012a395>] irq_exit+0x75/0x90
 [<c011365a>] smp_apic_timer_interrupt+0x5a/0x90
 [<c013c2ca>] ? hrtimer_start+0x1a/0x20
 [<c0103f0c>] apic_timer_interrupt+0x28/0x30
 [<c01090e5>] ? mwait_idle+0x35/0x40
 [<c0101c1e>] cpu_idle+0x4e/0xa0
---[ end trace aebd29b927afeb8b ]---
niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting
niu 0000:0b:00.0: niu: eth2: LDG[idx(0):num(0)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(1):num(1)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(2):num(2)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(3):num(3)] V0[sw(0x1)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(4):num(4)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(5):num(5)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(6):num(6)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(7):num(7)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(8):num(8)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(9):num(9)] V0[sw(0x400000000)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: Dumping transmitter state.
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] CHANNEL 0 LDN 32
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] parent->lgd_map[ldn] 7
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] Num pending TX SKBs: 3
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] TX_CS sw[0000000000000000] hw[0003000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] CHANNEL 1 LDN 33
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] parent->lgd_map[ldn] 8
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] TX_CS sw[0000000000000000] hw[0000000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] CHANNEL 2 LDN 34
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] parent->lgd_map[ldn] 9
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] Num pending TX SKBs: 237
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] TX_CS sw[00c000bf00000000] hw[00ed00bf00000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] CHANNEL 3 LDN 35
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] parent->lgd_map[ldn] 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] TX_CS sw[0000000000000000] hw[0000000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] CHANNEL 4 LDN 36
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] parent->lgd_map[ldn] 1
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] TX_CS sw[0000000000000000] hw[0000000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] CHANNEL 5 LDN 37
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] parent->lgd_map[ldn] 2
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] TX_CS sw[0000000000000000] hw[0000000000000000]

-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

On Wed, 2008-11-12 at 01:49 -0800, David Miller wrote:
> Oddly, you tried without MSI enabled (do I remember right ?) and that
> still failed, so it doesn't seem like it could be a MSI specific
> problem.

Just to be absolutly sure that MSI got disabled, I have compiled a
kernel without SMP and without MSI support.

This kernel still shows the problem.

dcu-router-ng:~# cat /proc/interrupts 
           CPU0       
  0:     373724    XT-PIC-XT        timer
  1:          2    XT-PIC-XT        i8042
  2:          0    XT-PIC-XT        cascade
  3:          7    XT-PIC-XT        serial
  5:       4539    XT-PIC-XT        uhci_hcd:usb1, ehci_hcd:usb6, ipmi_si, eth0, eth2
  7:          0    XT-PIC-XT        uhci_hcd:usb2, eth3
  9:          0    XT-PIC-XT        acpi
 10:      40319    XT-PIC-XT        cciss0, uhci_hcd:usb3, uhci_hcd:usb4, uhci_hcd:usb5
 12:          4    XT-PIC-XT        i8042
 14:         58    XT-PIC-XT        ata_piix
 15:          0    XT-PIC-XT        ata_piix
NMI:          0   Non-maskable interrupts
TRM:          0   Thermal event interrupts
ERR:          0


niu: disagrees about version of symbol struct_module
------------[ cut here ]------------
WARNING: at net/sched/sch_generic.c:226 dev_watchdog+0x221/0x230()
NETDEV WATCHDOG: eth2 (niu): transmit timed out
Modules linked in: serio_raw ipmi_si ipmi_msghandler hpilo hpwdt rng_core ehci_hcd uhci_hcd bnx2 zlib_inflate niu sr_mod cdrom
Pid: 0, comm: swapper Not tainted 2.6.28-rc4-davem-nosmp #16
Call Trace:
 [<c0118fe3>] warn_slowpath+0x63/0x80
 [<c0130030>] ? down_interruptible+0x30/0x50
 [<c0136249>] ? lock_release_holdtime+0x79/0xc0
 [<c0132ffb>] ? clocksource_get_next+0x3b/0x50
 [<c0107fbc>] ? native_sched_clock+0x1c/0x70
 [<c0136abd>] ? __lock_acquire+0xfd/0x8e0
 [<c0136abd>] ? __lock_acquire+0xfd/0x8e0
 [<c0136abd>] ? __lock_acquire+0xfd/0x8e0
 [<c0136249>] ? lock_release_holdtime+0x79/0xc0
 [<c020c87e>] ? strlcpy+0x1e/0x60
 [<c0308f71>] dev_watchdog+0x221/0x230
 [<c0136249>] ? lock_release_holdtime+0x79/0xc0
 [<c01217d7>] ? run_timer_softirq+0x107/0x180
 [<c01217e9>] run_timer_softirq+0x119/0x180
 [<c0308d50>] ? dev_watchdog+0x0/0x230
 [<c011d754>] __do_softirq+0x64/0x110
 [<c014d660>] ? handle_level_irq+0xa0/0xd0
 [<c011d82b>] do_softirq+0x2b/0x40
 [<c011dac5>] irq_exit+0x65/0x80
 [<c0104c16>] do_IRQ+0x46/0x80
 [<c0103d6f>] common_interrupt+0x23/0x28
 [<c0108800>] ? mwait_idle+0x30/0x40
 [<c0101c01>] cpu_idle+0x31/0x80
 [<c035aa61>] rest_init+0x61/0x70
---[ end trace d500bfdcd991627f ]---
niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting
niu 0000:0b:00.0: niu: eth2: LDG[idx(0):num(0)] V0[sw(0x1)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: Dumping transmitter state.
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] CHANNEL 0 LDN 32
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] parent->lgd_map[ldn] 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] Num pending TX SKBs: 2
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] TX_CS sw[0000000000000000] hw[0002000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] CHANNEL 1 LDN 33
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] parent->lgd_map[ldn] 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] TX_CS sw[0000000000000000] hw[0000000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] CHANNEL 2 LDN 34
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] parent->lgd_map[ldn] 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] TX_CS sw[0000000000000000] hw[0000000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] CHANNEL 3 LDN 35
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] parent->lgd_map[ldn] 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] TX_CS sw[0000000000000000] hw[0000000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] CHANNEL 4 LDN 36
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] parent->lgd_map[ldn] 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] Num pending TX SKBs: 237
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] TX_CS sw[00c000bf00000000] hw[00ed00bf00000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] CHANNEL 5 LDN 37
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] parent->lgd_map[ldn] 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] TX_CS sw[0000000000000000] hw[0000000000000000]


-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Jesper Dangaard Brouer <jdb@comx.dk>
Date: Wed, 12 Nov 2008 12:01:50 +0100

> On Wed, 2008-11-12 at 01:49 -0800, David Miller wrote:
> > Oddly, you tried without MSI enabled (do I remember right ?) and that
> > still failed, so it doesn't seem like it could be a MSI specific
> > problem.
> 
> Just to be absolutly sure that MSI got disabled, I have compiled a
> kernel without SMP and without MSI support.

Thanks for the additional checks.

niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] CHANNEL 4 LDN 36
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] parent->lgd_map[ldn] 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] Num pending TX SKBs: 237
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] TX_CS sw[00c000bf00000000] hw[00ed00bf00000000]

So what's supposed to happen is that, in the TX ring, we periodically
set the MARK bit in the TX descriptors.

MARK bits are what trigger TX ring interrupts.

The TX ring is full (237 ~= TX_RING_SIZE [256] - MAX_SKB_FRAGS [18]).

What's supposed to happen is that when a MARK bit is seen, the completion
of sending that packet causes the TX_CS_MK bit to be set (or, alternatively,
the TX_CS_MMK bit if TX_CS_MK is already set) and then the interrupt
is signaled.

Reading the TX_CS register clears the TX_CS_MK bit.

But in all of these traces the TX_CS_MK bit is not set, but we DID
sample the TX_CS register which means we did get an interrupt signaled
for that TX ring.

niu_tx_work() never runs because it doesn't see the TX_CS_MK bit set.
I don't see any error bits set and there are no TX error dumps in your
logs.

Ok, Jesper, please try two things for me, leave the debugging patch
in there for all the tests:

1) Retrigger the problem (with or without MSI, doesn't matter) but
   add back in that test I asked you to try last week.  The one
   where the "if (++rp->mark_counter == rp->mark_freq)" condition
   test in niu_start_xmit() is commented out, so that the
   "mrk |= TX_DESC_MARK;" statement always runs.

   Get me the log dump produced by that scenerio.

2) Next, simply comment out the:

	if (unlikely(!(cs & (TX_CS_MK | TX_CS_MMK))))
		goto out;

   lines in niu_tx_work().

Let's see what new info we can get out of this.

Thanks.

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: David Miller <davem@davemloft.net>
Date: Wed, 12 Nov 2008 03:52:40 -0800 (PST)

> Ok, Jesper, please try two things for me, leave the debugging patch
> in there for all the tests:
> 
> 1) Retrigger the problem (with or without MSI, doesn't matter) but
>    add back in that test I asked you to try last week.  The one
>    where the "if (++rp->mark_counter == rp->mark_freq)" condition
>    test in niu_start_xmit() is commented out, so that the
>    "mrk |= TX_DESC_MARK;" statement always runs.
> 
>    Get me the log dump produced by that scenerio.
> 
> 2) Next, simply comment out the:
> 
> 	if (unlikely(!(cs & (TX_CS_MK | TX_CS_MMK))))
> 		goto out;
> 
>    lines in niu_tx_work().
> 
> Let's see what new info we can get out of this.

These tests are still useful for me, so please perform them,
but I think I've found the bug.

I am guessing you're running a 32-bit x86 kernel.

In such a case the driver has to define a local readq()
and writeq() implementation.

What I provide for NIU right now reads the upper 32-bits
then the lower 32-bits of the register.

Guess what that does?  The packet counters live in the upper
32-bits and the MARK bits live in the lower 32-bits of the
TX_CS register.

So it first reads the packet counters, and as a side effect that
clears the MARK bits in the TX_CS register.  So when we read the lower
32-bits the MARK bits are always seen as zero.

BzzaaarT!

So the following patch should fix this bug.  writeq() should
be OK as-is, so doesn't need a similar change.

diff --git a/drivers/net/niu.c b/drivers/net/niu.c
index 9acb5d7..d8463b1 100644
--- a/drivers/net/niu.c
+++ b/drivers/net/niu.c
@@ -51,8 +51,7 @@ MODULE_VERSION(DRV_MODULE_VERSION);
 #ifndef readq
 static u64 readq(void __iomem *reg)
 {
-	return (((u64)readl(reg + 0x4UL) << 32) |
-		(u64)readl(reg));
+	return ((u64) readl(reg)) | (((u64) readl(reg + 4UL)) << 32);
 }
 
 static void writeq(u64 val, void __iomem *reg)

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

On Wed, 2008-11-12 at 04:11 -0800, David Miller wrote:
> From: David Miller <davem@davemloft.net>
> Date: Wed, 12 Nov 2008 03:52:40 -0800 (PST)
>
> These tests are still useful for me, so please perform them,

As a gratitude for your work and being allowed to operate your expresso
machine, I'll be happy to perform the tests even though the bug has been
found.

> but I think I've found the bug.

Yes! you have found the bug! :-)

(This is on the non SMP and non MSI kernel.  First test pktgen test says
I can route 319 kpps using a single CPU, promising as I got 160 kpps
using the Sun nxge driver)

Tested-by: Jesper Dangaard Brouer <jdb@comx.dk>

-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

> I am guessing you're running a 32-bit x86 kernel.
> 
> In such a case the driver has to define a local readq()
> and writeq() implementation.
> 
> What I provide for NIU right now reads the upper 32-bits
> then the lower 32-bits of the register.
> 
> Guess what that does?  The packet counters live in the upper
> 32-bits and the MARK bits live in the lower 32-bits of the
> TX_CS register.
> 
> So it first reads the packet counters, and as a side effect that
> clears the MARK bits in the TX_CS register.  So when we read the lower
> 32-bits the MARK bits are always seen as zero.
> 
> BzzaaarT!
> 
> So the following patch should fix this bug.  writeq() should
> be OK as-is, so doesn't need a similar change.
> 
> diff --git a/drivers/net/niu.c b/drivers/net/niu.c
> index 9acb5d7..d8463b1 100644
> --- a/drivers/net/niu.c
> +++ b/drivers/net/niu.c
> @@ -51,8 +51,7 @@ MODULE_VERSION(DRV_MODULE_VERSION);
>  #ifndef readq
>  static u64 readq(void __iomem *reg)
>  {
> -	return (((u64)readl(reg + 0x4UL) << 32) |
> -		(u64)readl(reg));
> +	return ((u64) readl(reg)) | (((u64) readl(reg + 4UL)) << 32);
>  }
>  
>  static void writeq(u64 val, void __iomem *reg)

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

Another bug... while unloading the niu module.

During my testing I'm unloading/loading the niu module, I usually take
down the interfaces _before_ unloading the module, but I forgot one
time, and got the following BUG in the kern log.


niu: niu_put_parent: port[3]
niu 0000:0b:00.3: PCI INT D disabled
niu: niu_put_parent: port[2]
niu 0000:0b:00.2: PCI INT C disabled
niu: niu_put_parent: port[1]
niu 0000:0b:00.1: PCI INT B disabled
------------[ cut here ]------------
kernel BUG at drivers/pci/msi.c:630!
invalid opcode: 0000 [#1] PREEMPT SMP 
last sysfs file: /sys/class/net/lo/operstate
Modules linked in: hpilo serio_raw bnx2 zlib_inflate ipmi_si
ipmi_msghandler hpwdt rng_core ehci_hcd uhci_hcd niu(-) sr_mod cdrom

Pid: 3307, comm: rmmod Tainted: G        W  (2.6.28-rc4-davem #17)
ProLiant DL380 G5
EIP: 0060:[<c02314fc>] EFLAGS: 00010282 CPU: 0
EIP is at msi_free_irqs+0xdc/0xe0
EAX: f60ad420 EBX: 00000030 ECX: f664ff14 EDX: c04a5680
ESI: f71d1000 EDI: f71d146c EBP: f6305eb4 ESP: f6305ea8
 DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
Process rmmod (pid: 3307, ti=f6304000 task=f6aaa570 task.ti=f6304000)
Stack:
 f71d1000 f62b4540 f71d1000 f6305ebc c0231508 f6305ec8 c0231791 f62b4000
 f6305edc f81777f8 f71d1000 f817c5d4 f817c5d4 f6305ee8 c022c3e9 f71d1058
 f6305ef8 c0281609 f71d1058 f71d1184 f6305f0c c02816dd f817c5a0 f817c5d4
Call Trace:
 [<c0231508>] ? msix_free_all_irqs+0x8/0x10
 [<c0231791>] ? pci_disable_msix+0x31/0x40
 [<f81777f8>] ? niu_pci_remove_one+0x88/0x8a [niu]
 [<c022c3e9>] ? pci_device_remove+0x19/0x40
 [<c0281609>] ? __device_release_driver+0x59/0x90
 [<c02816dd>] ? driver_detach+0x9d/0xb0
 [<c0280975>] ? bus_remove_driver+0x75/0xa0
 [<c0281b89>] ? driver_unregister+0x39/0x40
 [<c022c641>] ? pci_unregister_driver+0x21/0x80
 [<f817443d>] ? niu_exit+0xd/0x10 [niu]
 [<c014d646>] ? sys_delete_module+0x116/0x1f0
 [<c01744e0>] ? do_munmap+0x1f0/0x250
 [<c01755f6>] ? sys_munmap+0x46/0x60
 [<c0103231>] ? sysenter_do_call+0x12/0x2c
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 bd 6f ee 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: [<c02314fc>] msi_free_irqs+0xdc/0xe0 SS:ESP 0068:f6305ea8
---[ end trace 6594bbb8d1cf29ee ]---


-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Jesper Dangaard Brouer <jdb@comx.dk>
Date: Thu, 13 Nov 2008 09:50:22 +0100

> Another bug... while unloading the niu module.
> 
> During my testing I'm unloading/loading the niu module, I usually take
> down the interfaces _before_ unloading the module, but I forgot one
> time, and got the following BUG in the kern log.
> 
> niu: niu_put_parent: port[3]
> niu 0000:0b:00.3: PCI INT D disabled
> niu: niu_put_parent: port[2]
> niu 0000:0b:00.2: PCI INT C disabled
> niu: niu_put_parent: port[1]
> niu 0000:0b:00.1: PCI INT B disabled
> ------------[ cut here ]------------
> kernel BUG at drivers/pci/msi.c:630!

Weird.  When the module is unloaded, unregister_netdev() will
do a dev_close() which will invoke dev->stop() which is
niu_close().

And niu_close() will call free_irq() on every MSI interrupt
registered in niu_open().

So I can't see how this can happen but obviously it is happening.

I suspect that something might be changing np->num_ldg, but
anyways the following debugging patch should provide some
clues.  Please reproduce this and send the logs it generates.

Thanks.

diff --git a/drivers/net/niu.c b/drivers/net/niu.c
index d8463b1..c0eedd3 100644
--- a/drivers/net/niu.c
+++ b/drivers/net/niu.c
@@ -5600,12 +5600,20 @@ static int niu_request_irq(struct niu *np)
 	int i, j, err;
 
 	err = 0;
+#if 1
+	dev_err(np->device, PFX "%s: niu_request_irq() num_ldg[%d]\n",
+		np->dev->name, np->num_ldg);
+#endif
 	for (i = 0; i < np->num_ldg; i++) {
 		struct niu_ldg *lp = &np->ldg[i];
 
 		err = request_irq(lp->irq, niu_interrupt,
 				  IRQF_SHARED | IRQF_SAMPLE_RANDOM,
 				  np->dev->name, lp);
+#if 1
+		dev_err(np->device, PFX "%s: Request IRQ %u, lp(%p), err=%d\n",
+			np->dev->name, lp->irq, lp, err);
+#endif
 		if (err)
 			goto out_free_irqs;
 
@@ -5617,6 +5625,11 @@ out_free_irqs:
 	for (j = 0; j < i; j++) {
 		struct niu_ldg *lp = &np->ldg[j];
 
+#if 1
+		dev_err(np->device, PFX "%s: out_free_irqs, "
+			"free IRQ %u, lp(%p)\n",
+			np->dev->name, lp->irq, lp);
+#endif
 		free_irq(lp->irq, lp);
 	}
 	return err;
@@ -5626,9 +5639,17 @@ static void niu_free_irq(struct niu *np)
 {
 	int i;
 
+#if 1
+	dev_err(np->device, PFX "%s: niu_free_irq() num_ldg[%d]\n",
+		np->dev->name, np->num_ldg);
+#endif
 	for (i = 0; i < np->num_ldg; i++) {
 		struct niu_ldg *lp = &np->ldg[i];
 
+#if 1
+		dev_err(np->device, PFX "%s: free IRQ %u, lp(%p)\n",
+			np->dev->name, lp->irq, lp);
+#endif
 		free_irq(lp->irq, lp);
 	}
 }

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter (rmmod BUG)

[Jesper Dangaard Brouer]

On Thu, 2008-11-13 at 14:08 -0800, David Miller wrote:
> I suspect that something might be changing np->num_ldg, but
> anyways the following debugging patch should provide some
> clues.  Please reproduce this and send the logs it generates.

Debugging the rmmod problem...

I found a strange behavior, rmmod'ing the niu driver will only cause a
kernel BUG, if the driver was loaded at boot time.  If I remove the
niu.ko driver from /lib/modules/2.6.28-rc4-davem/kernel/drivers/net/
reboot the system.  After that I can load and unload the niu.ko driver
without problems... hmmm

Here is you dmesg output with extra debug statements:
-----------------------------------------------------
niu 0000:0b:00.3: PCI INT D -> GSI 19 (level, low) -> IRQ 19
niu: niu_get_parent: platform_type[1] port[3]
niu 0000:0b:00.3: setting latency timer to 64
niu: niu_get_invariants: VPD offset [00016a00]
niu: VPD_SCAN: start[16a14] end[16b98]
niu: VPD_SCAN: Reading in property [local-mac-address] len[6]
niu: VPD_SCAN: Reading in property [version] len[38]
niu: VPD_SCAN: Reading in property [model] len[14]
niu: VPD_SCAN: Reading in property [board-model] len[12]
niu: VPD_SCAN: Reading in property [num-mac-addresses] len[1]
niu: VPD_SCAN: Reading in property [phy-type] len[4]
niu: VPD_SCAN: FCODE major(3) minor(9)
niu: niu_get_and_validate_port: port[3] num_ports[4]
niu: niu_probe_ports(): port_phy[000000aa]
niu: niu_classifier_swstate_init: num_tcam(256)
eth4: Broadcom NetXtreme II BCM5708 1000Base-T (B2) PCI-X 64-bit 133MHz found at mem f4000000, IRQ 17, node addr 00:1e:0b:71:60:84
usb 5-2: configuration #1 chosen from 1 choice
udev: renamed network interface eth4 to eth1
hub 5-2:1.0: USB hub found
hub 5-2:1.0: 7 ports detected
usb 5-2: New USB device found, idVendor=03f0, idProduct=1327
usb 5-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
usb 5-2: Product: Virtual Hub
usb 5-2: Manufacturer: HP
eth4: NIU Ethernet 00:14:4f:da:17:09
eth4: Port type[BMAC] mode[1G:COPPER] XCVR[MII] phy[mif]
udev: renamed network interface eth1_rename to eth0
udev: renamed network interface eth2 to eth3
udev: renamed network interface eth4 to eth5
udev: renamed network interface eth0_rename to eth2
udev: renamed network interface eth3_rename to eth4
Adding 3903784k swap on /dev/cciss/c0d0p2.  Priority:-1 extents:1 across:3903784k
EXT3 FS on cciss/c0d0p1, internal journal
kjournald starting.  Commit interval 5 seconds
EXT3 FS on cciss/c0d0p3, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
IPv4 FIB: Using LC-trie version 0.408
niu 0000:0b:00.0: niu: eth2: niu_request_irq() num_ldg[13]
niu 0000:0b:00.0: niu: eth2: Request IRQ 32, lp(f62b46d4), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 31, lp(f62b470c), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 30, lp(f62b4744), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 29, lp(f62b477c), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 28, lp(f62b47b4), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 27, lp(f62b47ec), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 26, lp(f62b4824), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 25, lp(f62b485c), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 24, lp(f62b4894), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 23, lp(f62b48cc), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 22, lp(f62b4904), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 21, lp(f62b493c), err=0
niu 0000:0b:00.0: niu: eth2: Request IRQ 20, lp(f62b4974), err=0
niu 0000:0b:00.1: niu: eth3: niu_request_irq() num_ldg[1]
niu 0000:0b:00.1: niu: eth3: Request IRQ 17, lp(f63e46d4), err=0
niu: eth2: Link is up at 1Gb/sec, full duplex
niu: eth3: Link is up at 1Gb/sec, full duplex
bnx2: eth0 NIC Copper Link is Up, 1000 Mbps full duplex
niu: niu_put_parent: port[3]
niu 0000:0b:00.3: PCI INT D disabled
niu: niu_put_parent: port[2]
niu 0000:0b:00.2: PCI INT C disabled
niu 0000:0b:00.1: niu: eth3: niu_free_irq() num_ldg[1]
niu 0000:0b:00.1: niu: eth3: free IRQ 17, lp(f63e46d4)
niu: niu_put_parent: port[1]
niu 0000:0b:00.1: PCI INT B disabled
niu 0000:0b:00.0: niu: eth2: niu_free_irq() num_ldg[13]
niu 0000:0b:00.0: niu: eth2: free IRQ 32, lp(f62b46d4)
niu 0000:0b:00.0: niu: eth2: free IRQ 31, lp(f62b470c)
niu 0000:0b:00.0: niu: eth2: free IRQ 30, lp(f62b4744)
niu 0000:0b:00.0: niu: eth2: free IRQ 29, lp(f62b477c)
niu 0000:0b:00.0: niu: eth2: free IRQ 28, lp(f62b47b4)
niu 0000:0b:00.0: niu: eth2: free IRQ 27, lp(f62b47ec)
niu 0000:0b:00.0: niu: eth2: free IRQ 26, lp(f62b4824)
niu 0000:0b:00.0: niu: eth2: free IRQ 25, lp(f62b485c)
niu 0000:0b:00.0: niu: eth2: free IRQ 24, lp(f62b4894)
niu 0000:0b:00.0: niu: eth2: free IRQ 23, lp(f62b48cc)
niu 0000:0b:00.0: niu: eth2: free IRQ 22, lp(f62b4904)
niu 0000:0b:00.0: niu: eth2: free IRQ 21, lp(f62b493c)
niu 0000:0b:00.0: niu: eth2: free IRQ 20, lp(f62b4974)
------------[ cut here ]------------
kernel BUG at drivers/pci/msi.c:630!
invalid opcode: 0000 [#1] PREEMPT SMP 
last sysfs file: /sys/class/net/lo/operstate
Modules linked in: thermal rng_core hpwdt hpilo serio_raw ehci_hcd uhci_hcd bnx2 zlib_inflate niu(-) processor sr_mod cdrom

Pid: 3153, comm: rmmod Not tainted (2.6.28-rc4-davem #19) ProLiant DL380 G5
EIP: 0060:[<c0230cdc>] EFLAGS: 00010286 CPU: 2
EIP is at msi_free_irqs+0xdc/0xe0
EAX: f61887c0 EBX: 00000030 ECX: f6472694 EDX: c049c680
ESI: f7222000 EDI: f722246c EBP: f590feb4 ESP: f590fea8
 DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
Process rmmod (pid: 3153, ti=f590e000 task=f718b2c0 task.ti=f590e000)
Stack:
 f7222000 f62b4540 f7222000 f590febc c0230ce8 f590fec8 c0230f71 f62b4000
 f590fedc f81fe678 f7222000 f82033d4 f82033d4 f590fee8 c022bbc9 f7222058
 f590fef8 c027b1a9 f7222058 f7222184 f590ff0c c027b27d f82033a0 f82033d4
Call Trace:
 [<c0230ce8>] ? msix_free_all_irqs+0x8/0x10
 [<c0230f71>] ? pci_disable_msix+0x31/0x40
 [<f81fe678>] ? niu_pci_remove_one+0x88/0x8a [niu]
 [<c022bbc9>] ? pci_device_remove+0x19/0x40
 [<c027b1a9>] ? __device_release_driver+0x59/0x90
 [<c027b27d>] ? driver_detach+0x9d/0xb0
 [<c027a515>] ? bus_remove_driver+0x75/0xa0
 [<c027b729>] ? driver_unregister+0x39/0x40
 [<c022be21>] ? pci_unregister_driver+0x21/0x80
 [<f81fb29d>] ? niu_exit+0xd/0x10 [niu]
 [<c014ce46>] ? sys_delete_module+0x116/0x1f0
 [<c0144309>] ? lock_release_holdtime+0x79/0xc0
 [<c0174df6>] ? sys_munmap+0x46/0x60
 [<c0103231>] ? sysenter_do_call+0x12/0x2c
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 dd 77 ee ff eb a0 5b 31 c0 5e 5f 5d c3 <0f> 0b eb fe 55 89 e
5 e8 18 ff ff ff 5d c3 8d b6 00 00 00 00 55 
EIP: [<c0230cdc>] msi_free_irqs+0xdc/0xe0 SS:ESP 0068:f590fea8
---[ end trace 8eed6b3e1ad2a790 ]---


-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter (rmmod BUG)

[Jesper Dangaard Brouer]

On Fri, 2008-11-14 at 13:38 +0100, Jesper Dangaard Brouer wrote:
> On Thu, 2008-11-13 at 14:08 -0800, David Miller wrote:
> > I suspect that something might be changing np->num_ldg, but
> > anyways the following debugging patch should provide some
> > clues.  Please reproduce this and send the logs it generates.
> 
> Debugging the rmmod problem...
> 
> I found a strange behavior, rmmod'ing the niu driver will only cause a
> kernel BUG, if the driver was loaded at boot time.  If I remove the
> niu.ko driver from /lib/modules/2.6.28-rc4-davem/kernel/drivers/net/
> reboot the system.  After that I can load and unload the niu.ko driver
> without problems... hmmm

Perhaps this is a regression, as the problem is not in v2.6.27.

I'll start bisecting monday...

I'm not sure its a NIU driver bug, as the number of changes to niu.c is
very small since v2.6.27. (git log v2.6.27.. drivers/net/niu.c)

-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter (rmmod BUG)

[David Miller]

From: Jesper Dangaard Brouer <jdb@comx.dk>
Date: Fri, 14 Nov 2008 19:49:22 +0100

> On Fri, 2008-11-14 at 13:38 +0100, Jesper Dangaard Brouer wrote:
> > On Thu, 2008-11-13 at 14:08 -0800, David Miller wrote:
> > > I suspect that something might be changing np->num_ldg, but
> > > anyways the following debugging patch should provide some
> > > clues.  Please reproduce this and send the logs it generates.
> > 
> > Debugging the rmmod problem...
> > 
> > I found a strange behavior, rmmod'ing the niu driver will only cause a
> > kernel BUG, if the driver was loaded at boot time.  If I remove the
> > niu.ko driver from /lib/modules/2.6.28-rc4-davem/kernel/drivers/net/
> > reboot the system.  After that I can load and unload the niu.ko driver
> > without problems... hmmm
> 
> Perhaps this is a regression, as the problem is not in v2.6.27.

This is what I started to suspect as well.

> I'll start bisecting monday...
> 
> I'm not sure its a NIU driver bug, as the number of changes to niu.c is
> very small since v2.6.27. (git log v2.6.27.. drivers/net/niu.c)

Ok, let me know what your bisect finds.

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter (rmmod BUG)

[Jesper Dangaard Brouer]

[-- Attachment #1: Type: text/plain, Size: 1599 bytes --]

On Fri, 2008-11-14 at 16:21 -0800, David Miller wrote:
> From: Jesper Dangaard Brouer <jdb@comx.dk>
> Date: Fri, 14 Nov 2008 19:49:22 +0100
> 
> > On Fri, 2008-11-14 at 13:38 +0100, Jesper Dangaard Brouer wrote:
> > > On Thu, 2008-11-13 at 14:08 -0800, David Miller wrote:
> > > > I suspect that something might be changing np->num_ldg, but
> > > > anyways the following debugging patch should provide some
> > > > clues.  Please reproduce this and send the logs it generates.
> > > 
> > > Debugging the rmmod problem...
> > > 
> > > I found a strange behavior, rmmod'ing the niu driver will only cause a
> > > kernel BUG, if the driver was loaded at boot time.  If I remove the
> > > niu.ko driver from /lib/modules/2.6.28-rc4-davem/kernel/drivers/net/
> > > reboot the system.  After that I can load and unload the niu.ko driver
> > > without problems... hmmm
> > 
> > Perhaps this is a regression, as the problem is not in v2.6.27.
> 
> This is what I started to suspect as well.
> 
> > I'll start bisecting monday...
> > 
> > I'm not sure its a NIU driver bug, as the number of changes to niu.c is
> > very small since v2.6.27. (git log v2.6.27.. drivers/net/niu.c)
> 
> Ok, let me know what your bisect finds.

I have given up bisecting because during my bisect I have hit a kernel
that will not boot on my system (it hangs...)

I have attached the full bisect history document...

-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

[-- Attachment #2: bisect_niu_rmmod.apt --]
[-- Type: text/plain, Size: 10091 bytes --]

~~ -*-text-*-

       -------------------------------------------------------
			    Bisecting bug:
		      NIU driver rmmod MSI-X bug
       -------------------------------------------------------
		 Jesper Dangaard Brouer (jdb@comx.dk)
       -------------------------------------------------------
	$LastChangedRevision: 772 $
	$Date: 2008-11-19 13:08:13 +0100 (Wed, 19 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
+---------


Bug description
~~~~~~~~~~~~~~~

 NIU driver rmmod kernel MSI-X bug.

 I found a strange behavior, rmmod'ing the niu driver will only cause
 a kernel BUG, if the driver was loaded at boot time.  If I remove the
 niu.ko driver from /lib/modules/2.6.28-rc4-davem/kernel/drivers/net/
 reboot the system.  After that I can load and unload the niu.ko
 driver without problems... hmmm.

Reproduce / test
~~~~~~~~~~~~~~~~

 1. Boot machine

 2. rmmod niu

 3. look at dmesg for kernel BUG output


Install trick
~~~~~~~~~~~~~

 Installing kernel in a seperate directory.

+--------
 export VER=`cat include/config/kernel.release`
 echo $VER

 export INSTALL_MOD_PATH=/var/kernels/git/install/
 rm -rf $INSTALL_MOD_PATH/lib/modules/$VER/kernel/
 make modules_install

 export BOOT="$INSTALL_MOD_PATH/boot/"
 [ -d $BOOT ] ||  mkdir $BOOT

 cp -v arch/x86/boot/bzImage $BOOT/vmlinuz-$VER
 cp -v arch/i386/boot/bzImage $BOOT/vmlinuz-$VER
 cp -v System.map $BOOT/System.map-$VER
 cp -v vmlinux $BOOT/vmlinux-$VER
+--------

* Push to test host
  ~~~~~~~~~~~~~~~~~

 export KERNEL=2.6.27-davem
 export KERNEL=2.6.28-rc2-davem
 export KERNEL=2.6.28-rc4-davem

+--------
 export HOST=ng
 export KERNEL=$VER
 pushd /var/kernels/git/install
 rsync -e ssh -avz boot/vmlinuz-${KERNEL} root@${HOST}:/boot/
 rsync -e ssh -avz boot/vmlinux-${KERNEL} root@${HOST}:/boot/
 rsync -e ssh -avz --delete lib/modules/${KERNEL}  root@${HOST}:/lib/modules/
 popd
+--------


Create branch from tag:
~~~~~~~~~~~~~~~~~~~~~~~

 Known good starting point.

+-----------
 git branch   tag_v2.6.27 v2.6.27
 git checkout tag_v2.6.27
+-----------


Start bisect
~~~~~~~~~~~~

+--------
 git checkout master
 git bisect start
 git bisect good v2.6.27
 git bisect bad master
+--------

 Create .config by <<<make oldconfig>>> or <<<make menuconfig>>>

+-------
 bisect good
#Bisecting: 2157 revisions left to test after this
#[92b29b86fe2e183d44eb467e5e74a5f718ef2e43]
#Merge branch 'tracing-v28-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
+-------

 compile:
  time make -j6 bzImage modules


 Sort of "good" version, problem is that number of IRQs when down a
 lot!  This probably means bad performance as I cannot get enough IRQs
 for the Sun NIC.

+--------
 bisect good
#Bisecting: 1066 revisions left to test after this
#[ea541686d8454efac4f2b5c0767affb12d4b6a52] 
#Merge branch 'for-linus' of git://git.o-hand.com/linux-rpurdie-leds
+--------

 compile:
  time make -j6 bzImage modules


 CRAP! - kernel (commit ea541686d8454efac4f2b5c0767affb12d4b6a52) will
 not boot on my system :-(((

 Stops with message:

+------
 hpet0: 3 comparators, 64-bit 14.318180 Mhz counter
+------

 <<Try to:>> removed "High Resolution Timer Support" in .config
 CONFIG_HIGH_RES_TIMERS and CONFIG_SCHED_HRTICK.

 Disable "HPET Timer Support" (under "Processor type and features").
 Undefs CONFIG_HPET_TIMER and CONFIG_HPET_EMULATE_RTC.

 Compiling ... installing ... It was not the problem... now I get a
 "BUG: soft lockup" kstop EIP is a stop_cpu+0x37/0xb0.


* Parallel process#1:
~~~~~~~~~~~~~~~~~~~~

 <<Try to:>> Pick a new commit point a make a new seperate branch and
 try to see if we cab boot... random picked commit
 9a1c3542768b5a58e45a9216921cd10a3bae1205

 git checkout -b new_bisect_point01 9a1c3542768b5a58e45a9216921cd10a3bae1205

 Compile on another tree davem/net-2.6-copy.

 Kernel named "-test".

 It can boot and unloading "niu" driver WORKS!

 If I understand bisect it should be possible to call:

   git-bisect good 9a1c3542768b5a58e45a9216921cd10a3bae1205


* Parallel process#2:
~~~~~~~~~~~~~~~~~~~~

 <<Try to:>> use git-bisect skip

+------
git-bisect skip
Bisecting: 1066 revisions left to test after this
[969907a956752f88dde4aa23fa8c033b9a939aee] Merge git://git.kernel.org/pub/scm/linux/kernel/git/bart/ide-2.6
+------

 STILL HANGS on boot :-(((


* Back on track...
~~~~~~~~~~~~~~~~~~

+--------
git-bisect good 9a1c3542768b5a58e45a9216921cd10a3bae1205
Bisecting: 1000 revisions left to test after this
[1137fb670465b6b5d15b9db7d01707a5833ee3ae] arm ide breakage
+--------

 compile... install...

 BAD: Booting (now 2.6.28-rc1-bisect) and unloading "niu" causes the bug!

 Mark bisecting as BAD.

+----------
git-bisect bad
Bisecting: 508 revisions left to test after this
[36ec891895020f3bc9953c8b11d079c6d77d76bd] Merge git://git.kernel.org/pub/scm/linux/kernel/git/lethal/sh-2.6
+----------

 compile ... install ... (back on ver. 2.6.27-bisect)

 GRRRR... Now I cannot boot again! :-(((

* Try to find a new place
  ~~~~~~~~~~~~~~~~~~~~~~~

 Random pick: dbacefc9c4f6bd365243db379473ab7041656d90

+--------
 cd /var/kernels/git/davem/net-2.6-copy/
 git checkout -b new_bisect_point02 dbacefc9c4f6bd365243db379473ab7041656d90
+--------

 VER=2.6.27-rc1-test

 This version can boot and unloading niu works.

* Back on track(2) ... but not :-(
~~~~~~~~~~~~~~~~~~

 git-bisect good dbacefc9c4f6bd365243db379473ab7041656d90

+--------
git-bisect good dbacefc9c4f6bd365243db379473ab7041656d90
Bisecting: 508 revisions left to test after this
[36ec891895020f3bc9953c8b11d079c6d77d76bd] Merge git://git.kernel.org/pub/scm/linux/kernel/git/lethal/sh-2.6
+---------

 Hmmm... commit 36ec891895020f3bc9953c8b11d079c6d77d76bd was the same
 as before... which could not boot...

* Try a bisect skip...
 ~~~~~~~~~~~~~~~~~~~~~

+---------
 git bisect skip
Bisecting: 508 revisions left to test after this
[70740d6c93030b339b4ad17fd58ee135dfc13913] Merge branch 'drm-next' of git://git.kernel.org/pub/scm/linux/kernel/git/airlied/drm-2.6
+---------

 compile ... install ... boot... CANNOT BOOT !!! :-(((


* Doing lucky guessing
~~~~~~~~~~~~~~~~~~~~~~

 git-bisect good

+--------------
git-bisect good
Bisecting: 259 revisions left to test after this
[22484856402bfa1ff3defe47f6029ab0418240d9] Merge git://git.kernel.org/pub/scm/linux/kernel/git/viro/bdev
+--------------

 ARGH!!! -- cannot boot this kernel, it hangs :-(((

* Doing desperate guessing
~~~~~~~~~~~~~~~~~~~~~~~~~~

+--------
git-bisect good
Bisecting: 132 revisions left to test after this
[c3c9897c63ebb0b93b7f78724e38d6ee1da04041] Merge branch 'x86-fixes-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
+--------

 compiling ... installing ...
 ... booting -- ARGH! cannot boot hang!


* Doing hopeless guessing
~~~~~~~~~~~~~~~~~~~~~~~~~

 This is hopeless, I should give up!

+-----------------
git-bisect good
Bisecting: 65 revisions left to test after this
[969907a956752f88dde4aa23fa8c033b9a939aee] Merge git://git.kernel.org/pub/scm/linux/kernel/git/bart/ide-2.6
+------------------

 compiling ...
 installing ...
 still hangs after boot... :-(((

 ... GIVING UP!!!


* git bisect log
~~~~~~~~~~~~~~~~

+-------
git-bisect start
# good: [3fa8749e584b55f1180411ab1b51117190bac1e5] Linux 2.6.27
git-bisect good 3fa8749e584b55f1180411ab1b51117190bac1e5
# bad: [5f9021cfdc3524a4c5e3d7ae2d049eb7adcd6776] rtnetlink: propagate error from dev_change_flags in do_setlink()
git-bisect bad 5f9021cfdc3524a4c5e3d7ae2d049eb7adcd6776
# good: [29415c37f043d1d54dcf356601d738ff6633b72b] KVM: set debug registers after "schedulable" section
git-bisect good 29415c37f043d1d54dcf356601d738ff6633b72b
# good: [92b29b86fe2e183d44eb467e5e74a5f718ef2e43] Merge branch 'tracing-v28-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
git-bisect good 92b29b86fe2e183d44eb467e5e74a5f718ef2e43
# skip: [ea541686d8454efac4f2b5c0767affb12d4b6a52] Merge branch 'for-linus' of git://git.o-hand.com/linux-rpurdie-leds
git-bisect skip ea541686d8454efac4f2b5c0767affb12d4b6a52
# good: [9a1c3542768b5a58e45a9216921cd10a3bae1205] pass fmode_t to blkdev_put()
git-bisect good 9a1c3542768b5a58e45a9216921cd10a3bae1205
# bad: [1137fb670465b6b5d15b9db7d01707a5833ee3ae] arm ide breakage
git-bisect bad 1137fb670465b6b5d15b9db7d01707a5833ee3ae
# good: [dbacefc9c4f6bd365243db379473ab7041656d90] fs/buffer.c: uninline __remove_assoc_queue()
git-bisect good dbacefc9c4f6bd365243db379473ab7041656d90
# skip: [36ec891895020f3bc9953c8b11d079c6d77d76bd] Merge git://git.kernel.org/pub/scm/linux/kernel/git/lethal/sh-2.6
git-bisect skip 36ec891895020f3bc9953c8b11d079c6d77d76bd
# good: [70740d6c93030b339b4ad17fd58ee135dfc13913] Merge branch 'drm-next' of git://git.kernel.org/pub/scm/linux/kernel/git/airlied/drm-2.6
git-bisect good 70740d6c93030b339b4ad17fd58ee135dfc13913
# good: [22484856402bfa1ff3defe47f6029ab0418240d9] Merge git://git.kernel.org/pub/scm/linux/kernel/git/viro/bdev
git-bisect good 22484856402bfa1ff3defe47f6029ab0418240d9
# good: [c3c9897c63ebb0b93b7f78724e38d6ee1da04041] Merge branch 'x86-fixes-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
git-bisect good c3c9897c63ebb0b93b7f78724e38d6ee1da04041
+-------


Compile:
~~~~~~~~

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


NOTES:
~~~~~~

 git log 29415c37f043d1d54dcf356601d738ff6633b72b..5f9021cfdc3524a4c5e3d7ae2d049eb7adcd6776

 NR_IRQS changed ... could this be releated?

 git show 7db282fa67b58daff8a57f9e1c93d4474b5908ff
 git show 1b4897688011cd05e07f00dcfe6af3331eb36a3c
 git show c78d0cf2925bffae8a6f00e7d9b8e971b0392edd

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Ben Hutchings]

On Wed, 2008-11-12 at 04:11 -0800, David Miller wrote:
[...]
> So the following patch should fix this bug.  writeq() should
> be OK as-is, so doesn't need a similar change.
> 
> diff --git a/drivers/net/niu.c b/drivers/net/niu.c
> index 9acb5d7..d8463b1 100644
> --- a/drivers/net/niu.c
> +++ b/drivers/net/niu.c
> @@ -51,8 +51,7 @@ MODULE_VERSION(DRV_MODULE_VERSION);
>  #ifndef readq
>  static u64 readq(void __iomem *reg)
>  {
> -	return (((u64)readl(reg + 0x4UL) << 32) |
> -		(u64)readl(reg));
> +	return ((u64) readl(reg)) | (((u64) readl(reg + 4UL)) << 32);
>  }

Since there's no sequence point between the reads, there's no guarantee
that the reads happen in the order written (regardless of barriers
inside readl()).  This needs to be split into two statements.

Ben.

-- 
Ben Hutchings, Senior Software Engineer, Solarflare Communications
Not speaking for my employer; that's the marketing department's job.
They asked us to note that Solarflare product names are trademarked.

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

On Wed, 2008-11-12 at 12:54 +0000, Ben Hutchings wrote:
> On Wed, 2008-11-12 at 04:11 -0800, David Miller wrote:
> [...]
> > So the following patch should fix this bug.  writeq() should
> > be OK as-is, so doesn't need a similar change.
> > 
> > diff --git a/drivers/net/niu.c b/drivers/net/niu.c
> > index 9acb5d7..d8463b1 100644
> > --- a/drivers/net/niu.c
> > +++ b/drivers/net/niu.c
> > @@ -51,8 +51,7 @@ MODULE_VERSION(DRV_MODULE_VERSION);
> >  #ifndef readq
> >  static u64 readq(void __iomem *reg)
> >  {
> > -	return (((u64)readl(reg + 0x4UL) << 32) |
> > -		(u64)readl(reg));
> > +	return ((u64) readl(reg)) | (((u64) readl(reg + 4UL)) << 32);
> >  }
> 
> Since there's no sequence point between the reads, there's no guarantee
> that the reads happen in the order written (regardless of barriers
> inside readl()).  This needs to be split into two statements.

The nxge driver does this:

#ifndef readq
static inline uint64_t readq(void *addr)
{
	uint32_t val32 = readl(addr);
	uint64_t val64 = (uint64_t) readl(addr + 4);
	return (val32 | (val64 << 32));
}
#endif

#ifndef writeq
static inline void writeq(uint64_t val64, void *addr)
{
	writel((uint32_t)(val64), addr);
	writel((uint32_t)(val64 >> 32), (addr + 4));
}
#endif

-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Ben Hutchings <bhutchings@solarflare.com>
Date: Wed, 12 Nov 2008 12:54:53 +0000

> On Wed, 2008-11-12 at 04:11 -0800, David Miller wrote:
> [...]
> > So the following patch should fix this bug.  writeq() should
> > be OK as-is, so doesn't need a similar change.
> > 
> > diff --git a/drivers/net/niu.c b/drivers/net/niu.c
> > index 9acb5d7..d8463b1 100644
> > --- a/drivers/net/niu.c
> > +++ b/drivers/net/niu.c
> > @@ -51,8 +51,7 @@ MODULE_VERSION(DRV_MODULE_VERSION);
> >  #ifndef readq
> >  static u64 readq(void __iomem *reg)
> >  {
> > -	return (((u64)readl(reg + 0x4UL) << 32) |
> > -		(u64)readl(reg));
> > +	return ((u64) readl(reg)) | (((u64) readl(reg + 4UL)) << 32);
> >  }
> 
> Since there's no sequence point between the reads, there's no guarantee
> that the reads happen in the order written (regardless of barriers
> inside readl()).  This needs to be split into two statements.

What version of the C language are you using?

I personally think it's safe.  If the compiler sees "A | B" it's going
to emit the code to compute A, then the code to emit B, and finally
the "|" operation.

Everything I've always seen says that for "|" the expressions are
evaluated left to right.

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Ben Hutchings]

On Wed, 2008-11-12 at 13:46 -0800, David Miller wrote:
> From: Ben Hutchings <bhutchings@solarflare.com>
> Date: Wed, 12 Nov 2008 12:54:53 +0000
> 
> > On Wed, 2008-11-12 at 04:11 -0800, David Miller wrote:
> > [...]
> > > So the following patch should fix this bug.  writeq() should
> > > be OK as-is, so doesn't need a similar change.
> > > 
> > > diff --git a/drivers/net/niu.c b/drivers/net/niu.c
> > > index 9acb5d7..d8463b1 100644
> > > --- a/drivers/net/niu.c
> > > +++ b/drivers/net/niu.c
> > > @@ -51,8 +51,7 @@ MODULE_VERSION(DRV_MODULE_VERSION);
> > >  #ifndef readq
> > >  static u64 readq(void __iomem *reg)
> > >  {
> > > -	return (((u64)readl(reg + 0x4UL) << 32) |
> > > -		(u64)readl(reg));
> > > +	return ((u64) readl(reg)) | (((u64) readl(reg + 4UL)) << 32);
> > >  }
> > 
> > Since there's no sequence point between the reads, there's no guarantee
> > that the reads happen in the order written (regardless of barriers
> > inside readl()).  This needs to be split into two statements.
> 
> What version of the C language are you using?

Any version will do.

> I personally think it's safe.  If the compiler sees "A | B" it's going
> to emit the code to compute A, then the code to emit B, and finally
> the "|" operation.
> 
> Everything I've always seen says that for "|" the expressions are
> evaluated left to right.

I think you're confusing it with "||" which does have this sequencing
rule.

See <http://c-faq.com/expr/seqpoints.html> if you're not convinced.

Ben.

-- 
Ben Hutchings, Senior Software Engineer, Solarflare Communications
Not speaking for my employer; that's the marketing department's job.
They asked us to note that Solarflare product names are trademarked.

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Ben Hutchings <bhutchings@solarflare.com>
Date: Wed, 12 Nov 2008 21:50:57 +0000

> See <http://c-faq.com/expr/seqpoints.html> if you're not convinced.

I don't think that has any implications for the piece of
code we are talking about.

Just google "C order of evaluation" and you will get hundreds
of tables, and all of them will have an entry for "|" (not
just "||") which says that operands are evaluated left to
right.

And since these MMIO reads are volatile operations, there is
no way the compiler can execute them out of order.

And the plain truth is that no compiler does, and that is what
matters in the end.

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Roland Dreier]

 > Just google "C order of evaluation" and you will get hundreds
 > of tables, and all of them will have an entry for "|" (not
 > just "||") which says that operands are evaluated left to
 > right.

You're talking about associativity, which says how an expression like
"a | b | c" is implicitly parenthesized.  The order of evaluation is
undefined -- in fact the C standard I have says:

  Except as specified later (for the function-call (), &&, ||, ?:, and
  comma operators), the order of evaluation of subexpressions and the
  order in which side effects take place are both unspecified.

So there is no rule about which subexpression is evaluated first in an
expression like "a | b".

 > And since these MMIO reads are volatile operations, there is
 > no way the compiler can execute them out of order.

"volatile" just means that accessing a volatile expression is considered
a side effect -- and side effects are only ordered with respect to
sequence points.

So according to my understanding of the C standard, there is no required
on which readl() is done first in an expression like "readl(a) | readl(b)".

 > And the plain truth is that no compiler does, and that is what
 > matters in the end.

I think it's cleaner to avoid relying on undefined behavior (eg gcc 4.5
will probably break things), especially when the fix is so simple --
something the following should work fine:

diff --git a/drivers/net/niu.c b/drivers/net/niu.c
index 9acb5d7..1fb0d2f 100644
--- a/drivers/net/niu.c
+++ b/drivers/net/niu.c
@@ -51,8 +51,8 @@ MODULE_VERSION(DRV_MODULE_VERSION);
 #ifndef readq
 static u64 readq(void __iomem *reg)
 {
-	return (((u64)readl(reg + 0x4UL) << 32) |
-		(u64)readl(reg));
+	u64 v = readl(reg);
+	return v | (u64) readl(reg + 0x4UL) << 32;
 }
 
 static void writeq(u64 val, void __iomem *reg)

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Krogh]

David Miller wrote:
> I am guessing you're running a 32-bit x86 kernel.
> 
> In such a case the driver has to define a local readq()
> and writeq() implementation.
> 
> What I provide for NIU right now reads the upper 32-bits
> then the lower 32-bits of the register.
> 
> Guess what that does?  The packet counters live in the upper
> 32-bits and the MARK bits live in the lower 32-bits of the
> TX_CS register.
> 
> So it first reads the packet counters, and as a side effect that
> clears the MARK bits in the TX_CS register.  So when we read the lower
> 32-bits the MARK bits are always seen as zero.
> 
> BzzaaarT!
> 
> So the following patch should fix this bug.  writeq() should
> be OK as-is, so doesn't need a similar change.
> 
> diff --git a/drivers/net/niu.c b/drivers/net/niu.c
> index 9acb5d7..d8463b1 100644
> --- a/drivers/net/niu.c
> +++ b/drivers/net/niu.c
> @@ -51,8 +51,7 @@ MODULE_VERSION(DRV_MODULE_VERSION);
>  #ifndef readq
>  static u64 readq(void __iomem *reg)
>  {
> -	return (((u64)readl(reg + 0x4UL) << 32) |
> -		(u64)readl(reg));
> +	return ((u64) readl(reg)) | (((u64) readl(reg + 4UL)) << 32);
>  }
>  
>  static void writeq(u64 val, void __iomem *reg)

On my system, I'm not in a position where I can just pull down the 
server and test, but if the above seems plausible that it is the same 
bug I hit using the 10GBitE card, then I'll definately try to test it out.

I sort-of reliably hit the problem after a few day of production on a 16 
core, amd64 system running NFS-server.

Does it seem likely to be the same problem?

Thanks
-- 
Jesper Krogh

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Jesper Krogh <jesper@krogh.cc>
Date: Wed, 12 Nov 2008 18:56:48 +0100

> I sort-of reliably hit the problem after a few day of production on
> a 16 core, amd64 system running NFS-server.
>
> Does it seem likely to be the same problem?

Not really, it sounds like you're using a 64-bit kernel (this only
effects 32-bit ones) and the problem triggers after the first 256
packets are sent to the send destination so it should happen quickly.

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

Hi Google,

On Wed, 12 Nov 2008, David Miller wrote:

> Guess what that does?  The packet counters live in the upper
> 32-bits and the MARK bits live in the lower 32-bits of the
> TX_CS register.
>
> So it first reads the packet counters, and as a side effect that
> clears the MARK bits in the TX_CS register.  So when we read the lower
> 32-bits the MARK bits are always seen as zero.

For the thorough reader, the TX_CS Transmit Control and Status register is 
described in table 26-15 page 761-762 in the PDF document titled: 
"UltraSPARC T2 supplement to UltraSPARC architecture 2007", downloadable 
from: 
http://opensparc-t2.sunsource.net/specs/UST2-UASuppl-current-draft-HP-EXT.pdf

Cheers,
   Jesper Brouer

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

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Matheos Worku]

Jesper Dangaard Brouer wrote:

>
> Hi Google,
>
> On Wed, 12 Nov 2008, David Miller wrote:
>
>> Guess what that does?  The packet counters live in the upper
>> 32-bits and the MARK bits live in the lower 32-bits of the
>> TX_CS register.
>>
>> So it first reads the packet counters, and as a side effect that
>> clears the MARK bits in the TX_CS register.  So when we read the lower
>> 32-bits the MARK bits are always seen as zero.
>
>
> For the thorough reader, the TX_CS Transmit Control and Status 
> register is described in table 26-15 page 761-762 in the PDF document 
> titled: "UltraSPARC T2 supplement to UltraSPARC architecture 2007", 
> downloadable from: 
> http://opensparc-t2.sunsource.net/specs/UST2-UASuppl-current-draft-HP-EXT.pdf 
>
>
> Cheers,
>   Jesper Brouer
>
> -- 
> -------------------------------------------------------------------
> MSc. Master of Computer Science
> Dept. of Computer Science, University of Copenhagen
> Author of http://www.adsl-optimizer.dk
> -------------------------------------------------------------------
> -- 
> To unsubscribe from this list: send the line "unsubscribe netdev" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

The niu/neptune HW puts some requirement on 32 bit reads of 64 bit 
registers. You need to read the lower 32 bits first and then the upper 
32 bits.  The same ordering applies to writes as well.
On some 64 bit platforms, the 64 bit reads  are split into two 32 bit 
reads as well, regardless of the OS.

Regards
Matheos

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

On Wed, 2008-11-12 at 04:11 -0800, David Miller wrote:
> From: David Miller <davem@davemloft.net>
> Date: Wed, 12 Nov 2008 03:52:40 -0800 (PST)
> 
> > Ok, Jesper, please try two things for me, leave the debugging patch
> > in there for all the tests:
> > 
> > 1) Retrigger the problem (with or without MSI, doesn't matter) but
> >    add back in that test I asked you to try last week.  The one
> >    where the "if (++rp->mark_counter == rp->mark_freq)" condition
> >    test in niu_start_xmit() is commented out, so that the
> >    "mrk |= TX_DESC_MARK;" statement always runs.
> > 
> >    Get me the log dump produced by that scenerio.

------------[ cut here ]------------
WARNING: at net/sched/sch_generic.c:226 dev_watchdog+0x21e/0x230()
NETDEV WATCHDOG: eth2 (niu): transmit timed out
Modules linked in: niu ipmi_si hpwdt serio_raw bnx2 zlib_inflate rng_core ipmi_msghandler hpilo ehci_hcd uhci_hcd sr_mod cdrom
Pid: 0, comm: swapper Not tainted 2.6.28-rc4-davem #17
Call Trace:
 [<c0125823>] warn_slowpath+0x63/0x80
 [<c011f03e>] ? __enqueue_entity+0x8e/0xb0
 [<c010888c>] ? native_sched_clock+0x1c/0x80
 [<c01453c4>] ? __lock_acquire+0x104/0x8e0
 [<c01453c4>] ? __lock_acquire+0x104/0x8e0
 [<c010888c>] ? native_sched_clock+0x1c/0x80
 [<c013f19b>] ? getnstimeofday+0x3b/0xe0
 [<c0144b09>] ? lock_release_holdtime+0x79/0xc0
 [<c021fd2e>] ? strlcpy+0x1e/0x60
 [<c031f4be>] dev_watchdog+0x21e/0x230
 [<c0144b09>] ? lock_release_holdtime+0x79/0xc0
 [<c012e55d>] ? run_timer_softirq+0x10d/0x190
 [<c012e56f>] run_timer_softirq+0x11f/0x190
 [<c014362c>] ? tick_dev_program_event+0x3c/0xc0
 [<c031f2a0>] ? dev_watchdog+0x0/0x230
 [<c012a204>] __do_softirq+0x94/0x160
 [<c013c7c0>] ? hrtimer_interrupt+0x150/0x180
 [<c013c651>] ? ktime_get+0x11/0x30
 [<c012a30b>] do_softirq+0x3b/0x50
 [<c012a515>] irq_exit+0x75/0x90
 [<c011364a>] smp_apic_timer_interrupt+0x5a/0x90
 [<c013c5ca>] ? hrtimer_start+0x1a/0x20
 [<c0103f0c>] apic_timer_interrupt+0x28/0x30
 [<c01090d5>] ? mwait_idle+0x35/0x40
 [<c0101c1e>] cpu_idle+0x4e/0xa0
---[ end trace 3045c940a424568f ]---
niu 0000:0b:00.0: niu: eth2: Transmit timed out, resetting
niu 0000:0b:00.0: niu: eth2: LDG[idx(0):num(0)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(1):num(1)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(2):num(2)] V0[sw(0x2000000000)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(3):num(3)] V0[sw(0x1)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(4):num(4)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(5):num(5)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(6):num(6)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(7):num(7)] V0[sw(0x100000000)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(8):num(8)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: LDG[idx(9):num(9)] V0[sw(0x0)hw(0x0)] V1[sw(0x0)hw(0x0)] V2[sw(0x0)hw(0x0)]
niu 0000:0b:00.0: niu: eth2: Dumping transmitter state.
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] CHANNEL 0 LDN 32
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] parent->lgd_map[ldn] 7
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] Num pending TX SKBs: 2
niu 0000:0b:00.0: niu: eth2: TX_RING[ 0] TX_CS sw[0002000100000000] hw[0002000100000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] CHANNEL 1 LDN 33
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] parent->lgd_map[ldn] 8
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 1] TX_CS sw[0000000000000000] hw[0000000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] CHANNEL 2 LDN 34
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] parent->lgd_map[ldn] 9
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 2] TX_CS sw[0000000000000000] hw[0000000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] CHANNEL 3 LDN 35
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] parent->lgd_map[ldn] 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 3] TX_CS sw[0000000000000000] hw[0000000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] CHANNEL 4 LDN 36
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] parent->lgd_map[ldn] 1
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] Num pending TX SKBs: 0
niu 0000:0b:00.0: niu: eth2: TX_RING[ 4] TX_CS sw[0000000000000000] hw[0000000000000000]
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] CHANNEL 5 LDN 37
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] parent->lgd_map[ldn] 2
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] Num pending TX SKBs: 237
niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] TX_CS sw[00ed00ec00000000] hw[00ed00ec00000000]


-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Jesper Dangaard Brouer <jdb@comx.dk>
Date: Thu, 13 Nov 2008 10:10:12 +0100

> On Wed, 2008-11-12 at 04:11 -0800, David Miller wrote:
> > From: David Miller <davem@davemloft.net>
> > Date: Wed, 12 Nov 2008 03:52:40 -0800 (PST)
> > 
> > > Ok, Jesper, please try two things for me, leave the debugging patch
> > > in there for all the tests:
> > > 
> > > 1) Retrigger the problem (with or without MSI, doesn't matter) but
> > >    add back in that test I asked you to try last week.  The one
> > >    where the "if (++rp->mark_counter == rp->mark_freq)" condition
> > >    test in niu_start_xmit() is commented out, so that the
> > >    "mrk |= TX_DESC_MARK;" statement always runs.
> > > 
> > >    Get me the log dump produced by that scenerio.
> 
> ------------[ cut here ]------------
> WARNING: at net/sched/sch_generic.c:226 dev_watchdog+0x21e/0x230()
> NETDEV WATCHDOG: eth2 (niu): transmit timed out
> Modules linked in: niu ipmi_si hpwdt serio_raw bnx2 zlib_inflate rng_core ipmi_msghandler hpilo ehci_hcd uhci_hcd sr_mod cdrom
> Pid: 0, comm: swapper Not tainted 2.6.28-rc4-davem #17
> Call Trace:

Thanks a lot for making this test Jesper, even though the bug
is fixed.

> niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] CHANNEL 5 LDN 37
> niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] parent->lgd_map[ldn] 2
> niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] Num pending TX SKBs: 237
> niu 0000:0b:00.0: niu: eth2: TX_RING[ 5] TX_CS sw[00ed00ec00000000] hw[00ed00ec00000000]

Same signature, counters advancing yet no mark bits are set.

Now if we can fix that MSIX BUG() and start analyzing your
pps performance with oprofile, we'll be in good shape :)

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[Jesper Dangaard Brouer]

On Wed, 2008-11-12 at 04:11 -0800, David Miller wrote:
> From: David Miller <davem@davemloft.net>
> Date: Wed, 12 Nov 2008 03:52:40 -0800 (PST)
> 
> > Ok, Jesper, please try two things for me, leave the debugging patch
> > in there for all the tests:
> > 
> > 1) Retrigger the problem (with or without MSI, doesn't matter) but
> >    add back in that test I asked you to try last week.  The one
> >    where the "if (++rp->mark_counter == rp->mark_freq)" condition
> >    test in niu_start_xmit() is commented out, so that the
> >    "mrk |= TX_DESC_MARK;" statement always runs.
> > 
> >    Get me the log dump produced by that scenerio.
> > 
> > 2) Next, simply comment out the:
> > 
> >       if (unlikely(!(cs & (TX_CS_MK | TX_CS_MMK))))
> >               goto out;
> > 
> >    lines in niu_tx_work().
> > 
> > Let's see what new info we can get out of this.

Both applying test#1 and test#2.

After applying test#2, I cannot get it to do a TX transmit timed out.
And every thing seem to work... which after the known bug fix was kind
of the expected behaviour...

Although I'm not happy about the new perf numbers, as I now on a SMP
system only can route approx 290 kpps, remember I could route 319 kpps
using a single CPU nosmp kernel. (even more anyoing is that oprofile is
broken)

-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter

[David Miller]

From: Jesper Dangaard Brouer <jdb@comx.dk>
Date: Thu, 13 Nov 2008 11:29:31 +0100

> Although I'm not happy about the new perf numbers, as I now on a SMP
> system only can route approx 290 kpps, remember I could route 319 kpps
> using a single CPU nosmp kernel.

That unfortunately (can be) the cost of SMP :-/

With multi-flow tests, Robert Olsson is getting 4.2 mpps rates with
NIU and pktgen.  That's what this card is designed for, good
multi-flow workload performance, rather than striving for maximum
single-flow performance.

> (even more anyoing is that oprofile is broken)

Yes, people on lkml are trying to figure out what is causing
that regression on x86.

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter (perf + regression IRQs)

[Jesper Dangaard Brouer]

On Thu, 13 Nov 2008, David Miller wrote:

> From: Jesper Dangaard Brouer <jdb@comx.dk>
> Date: Thu, 13 Nov 2008 11:29:31 +0100
>
>> Although I'm not happy about the new perf numbers, as I now on a SMP
>> system only can route approx 290 kpps, remember I could route 319 kpps
>> using a single CPU nosmp kernel.
>
> That unfortunately (can be) the cost of SMP :-/

[Regression]

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.

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.


> With multi-flow tests, Robert Olsson is getting 4.2 mpps rates with
> NIU and pktgen.  That's what this card is designed for, good
> multi-flow workload performance, rather than striving for maximum
> single-flow performance.

[Packet performance]

Yes, I know, I do use pktgen and multi-flows (rand dest IP+port).

For the two drivers NIU and Suns NXGE, my packet per sec performance is 
now, on 2.6.27 (with backported NIU fixes).

   With NIU driver I can route 900 kpps.

   With NXGE driver (and enqueue=NULL hack) I can route 1200 kpps.

Actually I think I can go higher, because I'm limited by my packet rate 
generator. I use pktgen (with rand dst IP+port) and can only generate 1200 
kpps.

(I have actually ordered some new hardware, so I can get a faster pktgen 
machine and perhaps test it as a router too.  Also ordered the hardware 
because I want to test PCI-express v.2.0. I have a prototype 12-port 
gigabit NIC (from hotlava systems) that support PCIe v.2.0 and has 6x 
82575 chips (4RX/4TX queues))


Hilsen
   Jesper Brouer

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

Re: NIU driver: Sun x8 Express Quad Gigabit Ethernet Adapter (perf + regression IRQs)

[David Miller]

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.

There were a lot of IRQ changes, especially on x86.  The sequence is
something like:

1) dyn irqs
2) APIC/IO_APIC handling integration
3) by-hand REVERT of dyn irqs, it was done by hand in order to not
   lose the #2 changes
4) interrupt remapping support

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

[Jesper Dangaard Brouer]

[-- 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.

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

[Thomas Gleixner]

Jesper,

On Thu, 20 Nov 2008, Jesper Dangaard Brouer wrote:
> 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.

Yup, the bisect result is pretty useless.
 
> 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.

Can you please try the attached patch ?

Thanks,

	tglx

-----
 arch/x86/kernel/io_apic.c |   22 +---------------------
 1 file changed, 1 insertion(+), 21 deletions(-)

Index: linux-2.6/arch/x86/kernel/io_apic.c
===================================================================
--- linux-2.6.orig/arch/x86/kernel/io_apic.c
+++ linux-2.6/arch/x86/kernel/io_apic.c
@@ -3594,27 +3594,7 @@ int __init io_apic_get_redir_entries (in
 
 int __init probe_nr_irqs(void)
 {
-	int idx;
-	int nr = 0;
-#ifndef CONFIG_XEN
-	int nr_min = 32;
-#else
-	int nr_min = NR_IRQS;
-#endif
-
-	for (idx = 0; idx < nr_ioapics; idx++)
-		nr += io_apic_get_redir_entries(idx) + 1;
-
-	/* double it for hotplug and msi and nmi */
-	nr <<= 1;
-
-	/* something wrong ? */
-	if (nr < nr_min)
-		nr = nr_min;
-	if (WARN_ON(nr > NR_IRQS))
-		nr = NR_IRQS;
-
-	return nr;
+	return NR_IRQS;
 }
 
 /* --------------------------------------------------------------------------

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

[Jesper Dangaard Brouer]

On Thu, 2008-11-20 at 16:34 -0800, Thomas Gleixner wrote:
> On Thu, 20 Nov 2008, Jesper Dangaard Brouer wrote:
> > 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.
> 
> Yup, the bisect result is pretty useless.
>  
> > 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.
> 
> Can you please try the attached patch ?

I have tried the patch and it solved the problem! :-)

I'll gladly test other patches from your.  Guess this patch needs to be
brushed up before a mainline patch is ready.

My hardware is a HP ProLiant DL380-G5.


> -----
>  arch/x86/kernel/io_apic.c |   22 +---------------------
>  1 file changed, 1 insertion(+), 21 deletions(-)
> 
> Index: linux-2.6/arch/x86/kernel/io_apic.c
> ===================================================================
> --- linux-2.6.orig/arch/x86/kernel/io_apic.c
> +++ linux-2.6/arch/x86/kernel/io_apic.c
> @@ -3594,27 +3594,7 @@ int __init io_apic_get_redir_entries (in
>  
>  int __init probe_nr_irqs(void)
>  {
> -	int idx;
> -	int nr = 0;
> -#ifndef CONFIG_XEN
> -	int nr_min = 32;
> -#else
> -	int nr_min = NR_IRQS;
> -#endif
> -
> -	for (idx = 0; idx < nr_ioapics; idx++)
> -		nr += io_apic_get_redir_entries(idx) + 1;
> -
> -	/* double it for hotplug and msi and nmi */
> -	nr <<= 1;
> -
> -	/* something wrong ? */
> -	if (nr < nr_min)
> -		nr = nr_min;
> -	if (WARN_ON(nr > NR_IRQS))
> -		nr = NR_IRQS;
> -
> -	return nr;
> +	return NR_IRQS;
>  }
>  

-- 
Med venlig hilsen / Best regards
  Jesper Brouer
  ComX Networks A/S
  Linux Network developer
  Cand. Scient Datalog / MSc.
  Author of http://adsl-optimizer.dk
  LinkedIn: http://www.linkedin.com/in/brouer

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

[Thomas Gleixner]

On Fri, 21 Nov 2008, Jesper Dangaard Brouer wrote:
> > Can you please try the attached patch ?
> 
> I have tried the patch and it solved the problem! :-)
> 
> I'll gladly test other patches from your.  Guess this patch needs to be
> brushed up before a mainline patch is ready.

Ok, I queue it for mainline. This solves just the number of irqs
limitation, the rmmod problem still persists, right ?

Thanks,

	tglx

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

[Jesper Dangaard Brouer]

On Fri, 21 Nov 2008, Thomas Gleixner wrote:

> On Fri, 21 Nov 2008, Jesper Dangaard Brouer wrote:
>>> Can you please try the attached patch ?
>>
>> I have tried the patch and it solved the problem! :-)
>>
>> I'll gladly test other patches from your.  Guess this patch needs to be
>> brushed up before a mainline patch is ready.
>
> Ok, I queue it for mainline. This solves just the number of irqs
> limitation, the rmmod problem still persists, right ?

It solves both the irq limit and the NIU driver unload bug.

We should give it a good description.
I have cooked up a patch with a description below, will you accept that?

Who's tree do you want it to go upsteam via?
(You are listed as one of the X86 maintainers, but Ingo's tree seems more 
up-to-date. My patch below is agains DaveM's tree)

Cheers,
   Jesper Brouer

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

Fixing irq limit and NIU driver unload bug.

Removing the config option HAVE_SPARSE_IRQ (commit
3235e936c0cc3589309280b6f59e5096779adae3) revealed a regression that
limited the number of irqs on the system.

Besides limiting the number of IRQ, this also caused unloading of the
NIU driver to fail during msi_free_irqs(). The reduced number of IRQs
caused the NIU driver to use "IO-APIC" based IRQs instead of
"PCI-MSI-edge".

This patch changes probe_nr_irqs() to return NR_IRQS, which is
basically the same as the NOT CONFIG_X86_IO_APIC case.  Thus being
fairly safe.

Thus, solving both the irq limit and the NIU driver unload bug.

Tested-by: Jesper Dangaard Brouer <hawk@comx.dk>
Signed-off-by: Jesper Dangaard Brouer <hawk@comx.dk>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
---
  arch/x86/kernel/io_apic.c |   22 +---------------------
  1 files changed, 1 insertions(+), 21 deletions(-)

diff --git a/arch/x86/kernel/io_apic.c b/arch/x86/kernel/io_apic.c
index c9513e1..1fec0f9 100644
--- a/arch/x86/kernel/io_apic.c
+++ b/arch/x86/kernel/io_apic.c
@@ -3608,27 +3608,7 @@ int __init io_apic_get_redir_entries (int ioapic)

  int __init probe_nr_irqs(void)
  {
-	int idx;
-	int nr = 0;
-#ifndef CONFIG_XEN
-	int nr_min = 32;
-#else
-	int nr_min = NR_IRQS;
-#endif
-
-	for (idx = 0; idx < nr_ioapics; idx++)
-		nr += io_apic_get_redir_entries(idx) + 1;
-
-	/* double it for hotplug and msi and nmi */
-	nr <<= 1;
-
-	/* something wrong ? */
-	if (nr < nr_min)
-		nr = nr_min;
-	if (WARN_ON(nr > NR_IRQS))
-		nr = NR_IRQS;
-
-	return nr;
+	return NR_IRQS;
  }

  /* --------------------------------------------------------------------------
-- 
1.5.4.2

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

[Thomas Gleixner]

On Fri, 21 Nov 2008, Jesper Dangaard Brouer wrote:
> > Ok, I queue it for mainline. This solves just the number of irqs
> > limitation, the rmmod problem still persists, right ?
> 
> It solves both the irq limit and the NIU driver unload bug.

I don't believe that it solves it. It hides it at the best.
 
> We should give it a good description.
> I have cooked up a patch with a description below, will you accept that?
> 
> Who's tree do you want it to go upsteam via?
> (You are listed as one of the X86 maintainers, but Ingo's tree seems more
> up-to-date. My patch below is agains DaveM's tree)

I queued it already with a description of the irq nr. problem. 

The rmmod problem is something different and should be investigated
thoroughly instead of declaring it solved by magic.
 
Thanks,

	tglx

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

[David Miller]

From: Jesper Dangaard Brouer <hawk@diku.dk>
Date: Fri, 21 Nov 2008 20:35:32 +0100 (CET)

> On Fri, 21 Nov 2008, Thomas Gleixner wrote:
> 
> > On Fri, 21 Nov 2008, Jesper Dangaard Brouer wrote:
> >>> Can you please try the attached patch ?
> >>
> >> I have tried the patch and it solved the problem! :-)
> >>
> >> I'll gladly test other patches from your.  Guess this patch needs to be
> >> brushed up before a mainline patch is ready.
> >
> > Ok, I queue it for mainline. This solves just the number of irqs
> > limitation, the rmmod problem still persists, right ?
> 
> It solves both the irq limit and the NIU driver unload bug.

I think it "solves" the unload BUG because the driver never has
to fallback to IO_APIC irqs and abort trying to use MSI-X
any longer.

Only the IRQ limit bug is fixed by Thomas's patch.