2.6.18 - another DWARF2

2.6.18 - another DWARF2

[Martin Lorenz]

just got the following on resume:

[87026.242000] usb 4-2: USB disconnect, address 18
[87026.448000] usb 4-2: new full speed USB device using uhci_hcd and address
20
[87026.613000] usb 4-2: configuration #1 chosen from 1 choice
[87026.704000] IRQ handler type mismatch for IRQ 90
[87026.704000]  [<c0103d7c>] show_trace_log_lvl+0x5b/0x16d
[87026.704000]  [<c01044cb>] show_trace+0xf/0x11
[87026.705000]  [<c01045ce>] dump_stack+0x15/0x17
[87026.705000]  [<c01403d7>] setup_irq+0x17d/0x190
[87026.705000]  [<c0140466>] request_irq+0x7c/0x98
[87026.706000]  [<c0251745>] e1000_open+0xcd/0x1a4
[87026.707000]  [<c029565c>] dev_open+0x2b/0x62
[87026.708000]  [<c0294181>] dev_change_flags+0x47/0xe4
[87026.709000]  [<c02c7cd1>] devinet_ioctl+0x252/0x556
[87026.711000]  [<c028b5a3>] sock_ioctl+0x19a/0x1be
[87026.712000]  [<c016b6af>] do_ioctl+0x1f/0x62
[87026.712000]  [<c016b937>] vfs_ioctl+0x245/0x257
[87026.713000]  [<c016b995>] sys_ioctl+0x4c/0x67
[87026.714000]  [<c0102db3>] syscall_call+0x7/0xb
[87026.714000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
[87026.715000] Leftover inexact backtrace:
[87026.715000] e1000: eth0: e1000_request_irq: Unable to allocate interrupt
Error: -16
[87027.026000] usb 4-1: new full speed USB device using uhci_hcd and address
21
[87027.055000] ata1: waiting for device to spin up (7 secs)
[87027.186000] usb 4-1: configuration #1 chosen from 1 choice
[87027.757000] IRQ handler type mismatch for IRQ 98
[87027.757000]  [<c0103d7c>] show_trace_log_lvl+0x5b/0x16d
[87027.757000]  [<c01044cb>] show_trace+0xf/0x11
[87027.758000]  [<c01045ce>] dump_stack+0x15/0x17
[87027.758000]  [<c01403d7>] setup_irq+0x17d/0x190
[87027.758000]  [<c0140466>] request_irq+0x7c/0x98
[87027.759000]  [<c0251745>] e1000_open+0xcd/0x1a4
[87027.760000]  [<c029565c>] dev_open+0x2b/0x62
[87027.761000]  [<c0294181>] dev_change_flags+0x47/0xe4
[87027.762000]  [<c02c7cd1>] devinet_ioctl+0x252/0x556
[87027.764000]  [<c028b5a3>] sock_ioctl+0x19a/0x1be
[87027.765000]  [<c016b6af>] do_ioctl+0x1f/0x62
[87027.766000]  [<c016b937>] vfs_ioctl+0x245/0x257
[87027.766000]  [<c016b995>] sys_ioctl+0x4c/0x67
[87027.767000]  [<c0102db3>] syscall_call+0x7/0xb
[87027.767000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
[87027.767000] Leftover inexact backtrace:
[87027.767000] e1000: eth0: e1000_request_irq: Unable to allocate interrupt
Error: -16
[87028.810000] IRQ handler type mismatch for IRQ 106
[87028.810000]  [<c0103d7c>] show_trace_log_lvl+0x5b/0x16d
[87028.810000]  [<c01044cb>] show_trace+0xf/0x11
[87028.811000]  [<c01045ce>] dump_stack+0x15/0x17
[87028.811000]  [<c01403d7>] setup_irq+0x17d/0x190
[87028.811000]  [<c0140466>] request_irq+0x7c/0x98
[87028.812000]  [<c0251745>] e1000_open+0xcd/0x1a4
[87028.813000]  [<c029565c>] dev_open+0x2b/0x62
[87028.814000]  [<c0294181>] dev_change_flags+0x47/0xe4
[87028.815000]  [<c02c7cd1>] devinet_ioctl+0x252/0x556
[87028.817000]  [<c028b5a3>] sock_ioctl+0x19a/0x1be
[87028.818000]  [<c016b6af>] do_ioctl+0x1f/0x62
[87028.818000]  [<c016b937>] vfs_ioctl+0x245/0x257
[87028.819000]  [<c016b995>] sys_ioctl+0x4c/0x67
[87028.820000]  [<c0102db3>] syscall_call+0x7/0xb
[87028.820000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
[87028.820000] Leftover inexact backtrace:
[87028.820000] e1000: eth0: e1000_request_irq: Unable to allocate interrupt
Error: -16
[87029.863000] IRQ handler type mismatch for IRQ 114
[87029.863000]  [<c0103d7c>] show_trace_log_lvl+0x5b/0x16d
[87029.863000]  [<c01044cb>] show_trace+0xf/0x11
[87029.864000]  [<c01045ce>] dump_stack+0x15/0x17
[87029.864000]  [<c01403d7>] setup_irq+0x17d/0x190
[87029.864000]  [<c0140466>] request_irq+0x7c/0x98
[87029.865000]  [<c0251745>] e1000_open+0xcd/0x1a4
[87029.866000]  [<c029565c>] dev_open+0x2b/0x62
[87029.867000]  [<c0294181>] dev_change_flags+0x47/0xe4
[87029.868000]  [<c02c7cd1>] devinet_ioctl+0x252/0x556
[87029.870000]  [<c028b5a3>] sock_ioctl+0x19a/0x1be
[87029.871000]  [<c016b6af>] do_ioctl+0x1f/0x62
[87029.871000]  [<c016b937>] vfs_ioctl+0x245/0x257
[87029.872000]  [<c016b995>] sys_ioctl+0x4c/0x67
[87029.873000]  [<c0102db3>] syscall_call+0x7/0xb
[87029.873000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
[87029.873000] Leftover inexact backtrace:
[87029.873000] e1000: eth0: e1000_request_irq: Unable to allocate interrupt
Error: -16
[87030.917000] IRQ handler type mismatch for IRQ 122
[87030.917000]  [<c0103d7c>] show_trace_log_lvl+0x5b/0x16d
[87030.917000]  [<c01044cb>] show_trace+0xf/0x11
[87030.918000]  [<c01045ce>] dump_stack+0x15/0x17
[87030.918000]  [<c01403d7>] setup_irq+0x17d/0x190
[87030.918000]  [<c0140466>] request_irq+0x7c/0x98
[87030.919000]  [<c0251745>] e1000_open+0xcd/0x1a4
[87030.920000]  [<c029565c>] dev_open+0x2b/0x62
[87030.921000]  [<c0294181>] dev_change_flags+0x47/0xe4
[87030.922000]  [<c02c7cd1>] devinet_ioctl+0x252/0x556
[87030.924000]  [<c028b5a3>] sock_ioctl+0x19a/0x1be
[87030.925000]  [<c016b6af>] do_ioctl+0x1f/0x62
[87030.925000]  [<c016b937>] vfs_ioctl+0x245/0x257
[87030.926000]  [<c016b995>] sys_ioctl+0x4c/0x67
[87030.927000]  [<c0102db3>] syscall_call+0x7/0xb
[87030.927000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
[87030.927000] Leftover inexact backtrace:
[87030.927000] e1000: eth0: e1000_request_irq: Unable to allocate interrupt
Error: -16
[87031.970000] IRQ handler type mismatch for IRQ 130
[87031.970000]  [<c0103d7c>] show_trace_log_lvl+0x5b/0x16d
[87031.970000]  [<c01044cb>] show_trace+0xf/0x11
[87031.971000]  [<c01045ce>] dump_stack+0x15/0x17
[87031.971000]  [<c01403d7>] setup_irq+0x17d/0x190
[87031.971000]  [<c0140466>] request_irq+0x7c/0x98
[87031.972000]  [<c0251745>] e1000_open+0xcd/0x1a4
[87031.973000]  [<c029565c>] dev_open+0x2b/0x62
[87031.974000]  [<c0294181>] dev_change_flags+0x47/0xe4
[87031.975000]  [<c02c7cd1>] devinet_ioctl+0x252/0x556
[87031.977000]  [<c028b5a3>] sock_ioctl+0x19a/0x1be
[87031.978000]  [<c016b6af>] do_ioctl+0x1f/0x62
[87031.978000]  [<c016b937>] vfs_ioctl+0x245/0x257
[87031.979000]  [<c016b995>] sys_ioctl+0x4c/0x67
[87031.980000]  [<c0102db3>] syscall_call+0x7/0xb
[87031.980000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
[87031.980000] Leftover inexact backtrace:
[87031.980000] e1000: eth0: e1000_request_irq: Unable to allocate interrupt
Error: -16
[87034.525000] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)

full dmesg is at 
http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.18-ie-la-tp-41.5+0813.boot
(boot time) and 
http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.18-ie-la-tp-41.5+0813.out
(runtime)

gruss
  mlo
--
Dipl.-Ing. Martin Lorenz

            They that can give up essential liberty 
	    to obtain a little temporary safety 
	    deserve neither liberty nor safety.
                                   Benjamin Franklin

please encrypt your mail to me
GnuPG key-ID: F1AAD37D
get it here:
http://blackhole.pca.dfn.de:11371/pks/lookup?op=get&search=0xF1AAD37D

ICQ UIN: 33588107

Re: 2.6.18 - another DWARF2

[Jesse Brandeburg]

On 10/16/06, Martin Lorenz <martin@lorenz.eu.org> wrote:
> just got the following on resume:
>
> [87026.242000] usb 4-2: USB disconnect, address 18
> [87026.448000] usb 4-2: new full speed USB device using uhci_hcd and address
> 20
> [87026.613000] usb 4-2: configuration #1 chosen from 1 choice
> [87026.704000] IRQ handler type mismatch for IRQ 90
> [87026.704000]  [<c0103d7c>] show_trace_log_lvl+0x5b/0x16d
> [87026.704000]  [<c01044cb>] show_trace+0xf/0x11
> [87026.705000]  [<c01045ce>] dump_stack+0x15/0x17
> [87026.705000]  [<c01403d7>] setup_irq+0x17d/0x190
> [87026.705000]  [<c0140466>] request_irq+0x7c/0x98
> [87026.706000]  [<c0251745>] e1000_open+0xcd/0x1a4
> [87026.707000]  [<c029565c>] dev_open+0x2b/0x62
> [87026.708000]  [<c0294181>] dev_change_flags+0x47/0xe4
> [87026.709000]  [<c02c7cd1>] devinet_ioctl+0x252/0x556
> [87026.711000]  [<c028b5a3>] sock_ioctl+0x19a/0x1be
> [87026.712000]  [<c016b6af>] do_ioctl+0x1f/0x62
> [87026.712000]  [<c016b937>] vfs_ioctl+0x245/0x257
> [87026.713000]  [<c016b995>] sys_ioctl+0x4c/0x67
> [87026.714000]  [<c0102db3>] syscall_call+0x7/0xb
> [87026.714000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
> [87026.715000] Leftover inexact backtrace:
> [87026.715000] e1000: eth0: e1000_request_irq: Unable to allocate interrupt
> Error: -16

I'm pretty sure this isn't an e1000 problem.  you need to talk to
whoever is maintaining the IRQ subsystem for x86.  E1000 is attempting
to register a shared interrupt and someone has already registered that
interrupt unshared.
from your dmesg
[    0.289935] Intel(R) PRO/1000 Network Driver - version 7.1.9-k4-NAPI
[    0.290030] Copyright (c) 1999-2006 Intel Corporation.
[    0.290196] ACPI: PCI Interrupt 0000:02:00.0[A] -> GSI 16 (level,
low) -> IRQ 201
[    0.291176] PCI: Setting latency timer of device 0000:02:00.0 to 64
[    0.336827] e1000: 0000:02:00.0: e1000_probe: (PCI
Express:2.5Gb/s:Width x1) 00:16:d3:22:9b:82
[    0.381316] e1000: eth0: e1000_probe: Intel(R) PRO/1000 Network Connection
[    0.381553] netconsole: not configured, aborting
[    0.381759] libata version 2.00 loaded.
[    0.381815] ahci 0000:00:1f.2: version 2.0
[    0.381835] ACPI: PCI Interrupt 0000:00:1f.2[B] -> GSI 16 (level,
low) -> IRQ 201
and
[    7.107822] USB Universal Host Controller Interface driver v3.0
[    7.107988] ACPI: PCI Interrupt 0000:00:1d.0[A] -> GSI 16 (level,
low) -> IRQ 201

looks like several devices are sharing IRQ 201 (aka GSI 16) and ahci
or usb uhci_hcd is likely the problem, or the (acpi) power management
subsystem.

Hope this helps get the right people involved.

Jesse

un/shared IRQ problem (was: Re: 2.6.18 - another DWARF2)

[Martin Lorenz]

On Tue, Oct 17, 2006 at 11:52:16AM -0700, Jesse Brandeburg wrote:
> On 10/16/06, Martin Lorenz <martin@lorenz.eu.org> wrote:
> >just got the following on resume:
> >
> >[87026.706000]  [<c0251745>] e1000_open+0xcd/0x1a4
> >[87026.714000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
> >[87026.715000] Leftover inexact backtrace:
> >[87026.715000] e1000: eth0: e1000_request_irq: Unable to allocate interrupt
> >Error: -16
> 
> I'm pretty sure this isn't an e1000 problem.  you need to talk to
> whoever is maintaining the IRQ subsystem for x86.  E1000 is attempting
> to register a shared interrupt and someone has already registered that
> interrupt unshared.

interestingly though it always involves e1000 when I see dumps like this.
I already reported more of those :-)
this one dosen't seem to do any harm to system stability. it occurs on every
suspend/resume and I can circumvent it by disabling msi

> 
> looks like several devices are sharing IRQ 201 (aka GSI 16) and ahci
> or usb uhci_hcd is likely the problem, or the (acpi) power management
> subsystem.
> 
> Hope this helps get the right people involved.

thank you

gruss
  mlo
--
Dipl.-Ing. Martin Lorenz

            They that can give up essential liberty 
	    to obtain a little temporary safety 
	    deserve neither liberty nor safety.
                                   Benjamin Franklin

please encrypt your mail to me
GnuPG key-ID: F1AAD37D
get it here:
http://blackhole.pca.dfn.de:11371/pks/lookup?op=get&search=0xF1AAD37D

ICQ UIN: 33588107

Re: un/shared IRQ problem (was: Re: 2.6.18 - another DWARF2)

[Andrew Morton]

On Wed, 18 Oct 2006 08:34:31 +0200
Martin Lorenz <martin@lorenz.eu.org> wrote:

> On Tue, Oct 17, 2006 at 11:52:16AM -0700, Jesse Brandeburg wrote:
> > On 10/16/06, Martin Lorenz <martin@lorenz.eu.org> wrote:
> > >just got the following on resume:
> > >
> > >[87026.706000]  [<c0251745>] e1000_open+0xcd/0x1a4
> > >[87026.714000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
> > >[87026.715000] Leftover inexact backtrace:
> > >[87026.715000] e1000: eth0: e1000_request_irq: Unable to allocate interrupt
> > >Error: -16
> > 
> > I'm pretty sure this isn't an e1000 problem.  you need to talk to
> > whoever is maintaining the IRQ subsystem for x86.  E1000 is attempting
> > to register a shared interrupt and someone has already registered that
> > interrupt unshared.
> 
> interestingly though it always involves e1000 when I see dumps like this.
> I already reported more of those :-)
> this one dosen't seem to do any harm to system stability. it occurs on every
> suspend/resume and I can circumvent it by disabling msi
> 
> > 
> > looks like several devices are sharing IRQ 201 (aka GSI 16) and ahci
> > or usb uhci_hcd is likely the problem, or the (acpi) power management
> > subsystem.
> > 
> > Hope this helps get the right people involved.
> 
> thank you

Could we see the /proc/interrupts please, so we can find out where the
clash is happening?

Re: un/shared IRQ problem (was: Re: 2.6.18 - another DWARF2)

[Martin Lorenz]

On Wed, Oct 18, 2006 at 11:26:03PM -0700, Andrew Morton wrote:
> On Wed, 18 Oct 2006 08:34:31 +0200
> Martin Lorenz <martin@lorenz.eu.org> wrote:
> 
> > On Tue, Oct 17, 2006 at 11:52:16AM -0700, Jesse Brandeburg wrote:
> > > On 10/16/06, Martin Lorenz <martin@lorenz.eu.org> wrote:
> > > >just got the following on resume:
> > > >
> > > >[87026.706000]  [<c0251745>] e1000_open+0xcd/0x1a4
> > > >[87026.714000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
> > > >[87026.715000] Leftover inexact backtrace:
> > > >[87026.715000] e1000: eth0: e1000_request_irq: Unable to allocate interrupt
> > > >Error: -16
> > > 
> > > I'm pretty sure this isn't an e1000 problem.  you need to talk to
> > > whoever is maintaining the IRQ subsystem for x86.  E1000 is attempting
> > > to register a shared interrupt and someone has already registered that
> > > interrupt unshared.
> > 
> > interestingly though it always involves e1000 when I see dumps like this.
> > I already reported more of those :-)
> > this one dosen't seem to do any harm to system stability. it occurs on every
> > suspend/resume and I can circumvent it by disabling msi
> > 
> > > 
> > > looks like several devices are sharing IRQ 201 (aka GSI 16) and ahci
> > > or usb uhci_hcd is likely the problem, or the (acpi) power management
> > > subsystem.
> > > 
> > > Hope this helps get the right people involved.
> > 
> > thank you
> 
> Could we see the /proc/interrupts please, so we can find out where the
> clash is happening?


here you are

~# cat /proc/interrupts
           CPU0       CPU1
  0:   76521957    2009390    IO-APIC-edge  timer
  1:      39599          0    IO-APIC-edge  i8042
  8:        128          0    IO-APIC-edge  rtc
  9:     415044          0   IO-APIC-level  acpi
 12:     862451          0    IO-APIC-edge  i8042
 58:      68014     326850         PCI-MSI  libata
 66:     508910      17187   IO-APIC-level  sdhci:slot0, uhci_hcd:usb3
 74:    3156375          0   IO-APIC-level  uhci_hcd:usb2, ohci1394, HDA Intel
 82:     134828          0   IO-APIC-level  uhci_hcd:usb4, ehci_hcd:usb5
 90:      46548          0         PCI-MSI  eth0
201:     100133          0   IO-APIC-level  uhci_hcd:usb1, yenta, i915@pci:0000:00:02.0
NMI:          0          0
LOC:   78530935   78520308
ERR:          0
MIS:          0


gruss
  mlo
--
Dipl.-Ing. Martin Lorenz

            They that can give up essential liberty 
	    to obtain a little temporary safety 
	    deserve neither liberty nor safety.
                                   Benjamin Franklin

please encrypt your mail to me
GnuPG key-ID: F1AAD37D
get it here:
http://blackhole.pca.dfn.de:11371/pks/lookup?op=get&search=0xF1AAD37D

ICQ UIN: 33588107

Re: un/shared IRQ problem (was: Re: 2.6.18 - another DWARF2)

[Andrew Morton]

On Thu, 19 Oct 2006 08:39:21 +0200
Martin Lorenz <martin@lorenz.eu.org> wrote:

> On Wed, Oct 18, 2006 at 11:26:03PM -0700, Andrew Morton wrote:
> > On Wed, 18 Oct 2006 08:34:31 +0200
> > Martin Lorenz <martin@lorenz.eu.org> wrote:
> > 
> > > On Tue, Oct 17, 2006 at 11:52:16AM -0700, Jesse Brandeburg wrote:
> > > > On 10/16/06, Martin Lorenz <martin@lorenz.eu.org> wrote:
> > > > >just got the following on resume:
> > > > >
> > > > >[87026.706000]  [<c0251745>] e1000_open+0xcd/0x1a4
> > > > >[87026.714000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
> > > > >[87026.715000] Leftover inexact backtrace:
> > > > >[87026.715000] e1000: eth0: e1000_request_irq: Unable to allocate interrupt
> > > > >Error: -16
> > > > 
> > > > I'm pretty sure this isn't an e1000 problem.  you need to talk to
> > > > whoever is maintaining the IRQ subsystem for x86.  E1000 is attempting
> > > > to register a shared interrupt and someone has already registered that
> > > > interrupt unshared.
> > > 
> > > interestingly though it always involves e1000 when I see dumps like this.
> > > I already reported more of those :-)
> > > this one dosen't seem to do any harm to system stability. it occurs on every
> > > suspend/resume and I can circumvent it by disabling msi
> > > 
> > > > 
> > > > looks like several devices are sharing IRQ 201 (aka GSI 16) and ahci
> > > > or usb uhci_hcd is likely the problem, or the (acpi) power management
> > > > subsystem.
> > > > 
> > > > Hope this helps get the right people involved.
> > > 
> > > thank you
> > 
> > Could we see the /proc/interrupts please, so we can find out where the
> > clash is happening?
> 
> 
> here you are
> 
> ~# cat /proc/interrupts
>            CPU0       CPU1
>   0:   76521957    2009390    IO-APIC-edge  timer
>   1:      39599          0    IO-APIC-edge  i8042
>   8:        128          0    IO-APIC-edge  rtc
>   9:     415044          0   IO-APIC-level  acpi
>  12:     862451          0    IO-APIC-edge  i8042
>  58:      68014     326850         PCI-MSI  libata
>  66:     508910      17187   IO-APIC-level  sdhci:slot0, uhci_hcd:usb3
>  74:    3156375          0   IO-APIC-level  uhci_hcd:usb2, ohci1394, HDA Intel
>  82:     134828          0   IO-APIC-level  uhci_hcd:usb4, ehci_hcd:usb5
>  90:      46548          0         PCI-MSI  eth0
> 201:     100133          0   IO-APIC-level  uhci_hcd:usb1, yenta, i915@pci:0000:00:02.0
> NMI:          0          0
> LOC:   78530935   78520308
> ERR:          0
> MIS:          0
> 

There are already three interrupt sources on 201, so they are all happy to
share.

It's e1000.  Jesse, you fibbed ;)

static int e1000_request_irq(struct e1000_adapter *adapter)
{
	...
	if (adapter->have_msi)
		flags &= ~IRQF_SHARED;

Re: un/shared IRQ problem (was: Re: 2.6.18 - another DWARF2)

[Eric W. Biederman]

Andrew Morton <akpm@osdl.org> writes:

> On Thu, 19 Oct 2006 08:39:21 +0200
> Martin Lorenz <martin@lorenz.eu.org> wrote:
>
>> On Wed, Oct 18, 2006 at 11:26:03PM -0700, Andrew Morton wrote:
>> > On Wed, 18 Oct 2006 08:34:31 +0200
>> > Martin Lorenz <martin@lorenz.eu.org> wrote:
>> > 
>> > > On Tue, Oct 17, 2006 at 11:52:16AM -0700, Jesse Brandeburg wrote:
>> > > > On 10/16/06, Martin Lorenz <martin@lorenz.eu.org> wrote:
>> > > > >just got the following on resume:
>> > > > >
>> > > > >[87026.706000]  [<c0251745>] e1000_open+0xcd/0x1a4
>> > > > >[87026.714000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
>> > > > >[87026.715000] Leftover inexact backtrace:
>> > > > >[87026.715000] e1000: eth0: e1000_request_irq: Unable to allocate
> interrupt
>> > > > >Error: -16
>> > > > 
>> > > > I'm pretty sure this isn't an e1000 problem.  you need to talk to
>> > > > whoever is maintaining the IRQ subsystem for x86.  E1000 is attempting
>> > > > to register a shared interrupt and someone has already registered that
>> > > > interrupt unshared.
>> > > 
>> > > interestingly though it always involves e1000 when I see dumps like this.
>> > > I already reported more of those :-)
>> > > this one dosen't seem to do any harm to system stability. it occurs on
> every
>> > > suspend/resume and I can circumvent it by disabling msi
>> > > 
>> > > > 
>> > > > looks like several devices are sharing IRQ 201 (aka GSI 16) and ahci
>> > > > or usb uhci_hcd is likely the problem, or the (acpi) power management
>> > > > subsystem.
>> > > > 
>> > > > Hope this helps get the right people involved.
>> > > 
>> > > thank you
>> > 
>> > Could we see the /proc/interrupts please, so we can find out where the
>> > clash is happening?
>> 
>> 
>> here you are
>> 
>> ~# cat /proc/interrupts
>>            CPU0       CPU1
>>   0:   76521957    2009390    IO-APIC-edge  timer
>>   1:      39599          0    IO-APIC-edge  i8042
>>   8:        128          0    IO-APIC-edge  rtc
>>   9:     415044          0   IO-APIC-level  acpi
>>  12:     862451          0    IO-APIC-edge  i8042
>>  58:      68014     326850         PCI-MSI  libata
>>  66:     508910      17187   IO-APIC-level  sdhci:slot0, uhci_hcd:usb3
>> 74: 3156375 0 IO-APIC-level uhci_hcd:usb2, ohci1394, HDA Intel
>>  82:     134828          0   IO-APIC-level  uhci_hcd:usb4, ehci_hcd:usb5
>>  90:      46548          0         PCI-MSI  eth0
>> 201: 100133 0 IO-APIC-level uhci_hcd:usb1, yenta, i915@pci:0000:00:02.0
>> NMI:          0          0
>> LOC:   78530935   78520308
>> ERR:          0
>> MIS:          0
>> 
>
> There are already three interrupt sources on 201, so they are all happy to
> share.
>
> It's e1000.  Jesse, you fibbed ;)
>
> static int e1000_request_irq(struct e1000_adapter *adapter)
> {
> 	...
> 	if (adapter->have_msi)
> 		flags &= ~IRQF_SHARED;

Well MSI irqs can't be shared, as they are edged triggered.
Is the e1000 really trying to use irq 201?   That would indicate
a logic failure in the msi irq allocator.  It should never allocate
an inuse irq.

I have to ask what is the state in 2.6.19-rc2? I'm wondering if
my turning of the msi irq allocator inside out has fixed this problem.

Does this situation work if MSI is disabled, in 2.6.18?

The backwards msi irq allocator in 2.6.18 is so convoluted it may have
a corner case where it fails, and that is triggering this mess.

If 2.6.19 works with MSI's enabled and 2.6.18 works with MSI disabled
I'm inclined to say I have done all that is reasonable.

Eric

Re: un/shared IRQ problem (was: Re: 2.6.18 - another DWARF2)

[Andrew Morton]

On Thu, 19 Oct 2006 08:48:10 -0600
ebiederm@xmission.com (Eric W. Biederman) wrote:

> >
> > There are already three interrupt sources on 201, so they are all happy to
> > share.
> >
> > It's e1000.  Jesse, you fibbed ;)
> >
> > static int e1000_request_irq(struct e1000_adapter *adapter)
> > {
> > 	...
> > 	if (adapter->have_msi)
> > 		flags &= ~IRQF_SHARED;
> 
> Well MSI irqs can't be shared, as they are edged triggered.
> Is the e1000 really trying to use irq 201?   That would indicate
> a logic failure in the msi irq allocator.  It should never allocate
> an inuse irq.

It's gone very bad.  See 
http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.18-ie-la-tp-41.5+0813.boot
http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.18-ie-la-tp-41.5+0813.out

> I have to ask what is the state in 2.6.19-rc2? I'm wondering if
> my turning of the msi irq allocator inside out has fixed this problem.

Martin, please try  CONFIG_PCI_MSI=n.  I'd expect that to fix it (it always does)

> Does this situation work if MSI is disabled, in 2.6.18?
> 
> The backwards msi irq allocator in 2.6.18 is so convoluted it may have
> a corner case where it fails, and that is triggering this mess.
> 
> If 2.6.19 works with MSI's enabled and 2.6.18 works with MSI disabled
> I'm inclined to say I have done all that is reasonable.

oh, we haven't tried 2.6.19-rc2 yet?   Please do that, with CONFIG_PCI_MSI=y.

Re: un/shared IRQ problem (was: Re: 2.6.18 - another DWARF2)

[Martin Lorenz]

On Thu, Oct 19, 2006 at 10:14:11AM -0700, Andrew Morton wrote:
> On Thu, 19 Oct 2006 08:48:10 -0600
> ebiederm@xmission.com (Eric W. Biederman) wrote:
> 
> > >
> > > There are already three interrupt sources on 201, so they are all happy to
> > > share.
> > >
> > > It's e1000.  Jesse, you fibbed ;)
> > >
> > > static int e1000_request_irq(struct e1000_adapter *adapter)
> > > {
> > > 	...
> > > 	if (adapter->have_msi)
> > > 		flags &= ~IRQF_SHARED;
> > 
> > Well MSI irqs can't be shared, as they are edged triggered.
> > Is the e1000 really trying to use irq 201?   That would indicate
> > a logic failure in the msi irq allocator.  It should never allocate
> > an inuse irq.
> 
> It's gone very bad.  See 
> http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.18-ie-la-tp-41.5+0813.boot
> http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.18-ie-la-tp-41.5+0813.out
> 
> > I have to ask what is the state in 2.6.19-rc2? I'm wondering if
> > my turning of the msi irq allocator inside out has fixed this problem.
> 
> Martin, please try  CONFIG_PCI_MSI=n.  I'd expect that to fix it (it always does)
> 
> > Does this situation work if MSI is disabled, in 2.6.18?
> > 
> > The backwards msi irq allocator in 2.6.18 is so convoluted it may have
> > a corner case where it fails, and that is triggering this mess.
> > 
> > If 2.6.19 works with MSI's enabled and 2.6.18 works with MSI disabled
> > I'm inclined to say I have done all that is reasonable.
> 
> oh, we haven't tried 2.6.19-rc2 yet?   Please do that, with CONFIG_PCI_MSI=y.

ok...
I compliled and installed the latest git yesterday evening and another one
this morning because of a configuration mistake I made

there are new DWARFs but the one I reported for 2.6.18 seem to be fixed
at least I diden't succeed in triggering it

the new ones are in 
http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.19-rc2-tp-ie-e1-42.5+0737-gce9e3d99-dirty.run
http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.19-rc2-tp-ie-e1-42.5+0737-gce9e3d99-dirty.boot

http://www.lorenz.eu.org/~mlo/kernel/interrupts_2.6.19-rc2-tp-ie-e1-42.5+0737-gce9e3d99-dirty
is there too

http://www.lorenz.eu.org/~mlo/kernel/?C=M;O=D
for a list of files I uploaded

[   64.655000] kobject_add failed for vcs6 with -EEXIST, don't try to register things with the same name in the same directory.
[   64.655000]  [<c0103bfd>] dump_trace+0x69/0x1af
[   64.655000]  [<c0103d5b>] show_trace_log_lvl+0x18/0x2c
[   64.656000]  [<c01043fa>] show_trace+0xf/0x11
[   64.656000]  [<c01044fd>] dump_stack+0x15/0x17
[   64.656000]  [<c01fbf3d>] kobject_add+0x160/0x189
[   64.657000]  [<c0250fec>] class_device_add+0xa2/0x3d8
[   64.658000]  [<c02513ae>] class_device_create+0x7c/0x9c
[   64.659000]  [<c0237858>] vcs_make_sysfs+0x3c/0x7e
[   64.659000]  [<c023c641>] con_open+0x6f/0x7c
[   64.660000]  [<c023259b>] tty_open+0x179/0x2f0
[   64.661000]  [<c016226e>] chrdev_open+0x124/0x13f
[   64.662000]  [<c015e665>] __dentry_open+0xc7/0x1ab
[   64.662000]  [<c015e7c3>] nameidata_to_filp+0x24/0x33
[   64.662000]  [<c015e804>] do_filp_open+0x32/0x39
[   64.663000]  [<c015e84d>] do_sys_open+0x42/0xc3
[   64.663000]  [<c015e907>] sys_open+0x1c/0x1e
[   64.664000]  [<c0102de7>] syscall_call+0x7/0xb
[   64.664000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
[   64.664000] 
[   64.664000] Leftover inexact backtrace:
[   64.664000] 
[   64.664000]  =======================
[   64.666000] kobject_add failed for vcsa6 with -EEXIST, don't try to register things with the same name in the same directory.
[   64.666000]  [<c0103bfd>] dump_trace+0x69/0x1af
[   64.666000]  [<c0103d5b>] show_trace_log_lvl+0x18/0x2c
[   64.666000]  [<c01043fa>] show_trace+0xf/0x11
[   64.666000]  [<c01044fd>] dump_stack+0x15/0x17
[   64.667000]  [<c01fbf3d>] kobject_add+0x160/0x189
[   64.667000]  [<c0250fec>] class_device_add+0xa2/0x3d8
[   64.668000]  [<c02513ae>] class_device_create+0x7c/0x9c
[   64.668000]  [<c0237895>] vcs_make_sysfs+0x79/0x7e
[   64.669000]  [<c023c641>] con_open+0x6f/0x7c
[   64.670000]  [<c023259b>] tty_open+0x179/0x2f0
[   64.670000]  [<c016226e>] chrdev_open+0x124/0x13f
[   64.670000]  [<c015e665>] __dentry_open+0xc7/0x1ab
[   64.671000]  [<c015e7c3>] nameidata_to_filp+0x24/0x33
[   64.671000]  [<c015e804>] do_filp_open+0x32/0x39
[   64.671000]  [<c015e84d>] do_sys_open+0x42/0xc3
[   64.672000]  [<c015e907>] sys_open+0x1c/0x1e
[   64.673000]  [<c0102de7>] syscall_call+0x7/0xb
[   64.673000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
[   64.673000] 
[   64.673000] Leftover inexact backtrace:
[   64.673000] 
[   64.673000]  =======================

gruss
  mlo
--
Dipl.-Ing. Martin Lorenz

            They that can give up essential liberty 
	    to obtain a little temporary safety 
	    deserve neither liberty nor safety.
                                   Benjamin Franklin

please encrypt your mail to me
GnuPG key-ID: F1AAD37D
get it here:
http://blackhole.pca.dfn.de:11371/pks/lookup?op=get&search=0xF1AAD37D

ICQ UIN: 33588107

Re: un/shared IRQ problem (was: Re: 2.6.18 - another DWARF2)

[Andrew Morton]

On Fri, 20 Oct 2006 10:37:41 +0200
Martin Lorenz <martin@lorenz.eu.org> wrote:

> On Thu, Oct 19, 2006 at 10:14:11AM -0700, Andrew Morton wrote:
> > On Thu, 19 Oct 2006 08:48:10 -0600
> > ebiederm@xmission.com (Eric W. Biederman) wrote:
> > 
> > > >
> > > > There are already three interrupt sources on 201, so they are all happy to
> > > > share.
> > > >
> > > > It's e1000.  Jesse, you fibbed ;)
> > > >
> > > > static int e1000_request_irq(struct e1000_adapter *adapter)
> > > > {
> > > > 	...
> > > > 	if (adapter->have_msi)
> > > > 		flags &= ~IRQF_SHARED;
> > > 
> > > Well MSI irqs can't be shared, as they are edged triggered.
> > > Is the e1000 really trying to use irq 201?   That would indicate
> > > a logic failure in the msi irq allocator.  It should never allocate
> > > an inuse irq.
> > 
> > It's gone very bad.  See 
> > http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.18-ie-la-tp-41.5+0813.boot
> > http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.18-ie-la-tp-41.5+0813.out
> > 
> > > I have to ask what is the state in 2.6.19-rc2? I'm wondering if
> > > my turning of the msi irq allocator inside out has fixed this problem.
> > 
> > Martin, please try  CONFIG_PCI_MSI=n.  I'd expect that to fix it (it always does)
> > 
> > > Does this situation work if MSI is disabled, in 2.6.18?
> > > 
> > > The backwards msi irq allocator in 2.6.18 is so convoluted it may have
> > > a corner case where it fails, and that is triggering this mess.
> > > 
> > > If 2.6.19 works with MSI's enabled and 2.6.18 works with MSI disabled
> > > I'm inclined to say I have done all that is reasonable.
> > 
> > oh, we haven't tried 2.6.19-rc2 yet?   Please do that, with CONFIG_PCI_MSI=y.
> 
> ok...
> I compliled and installed the latest git yesterday evening and another one
> this morning because of a configuration mistake I made

OK, sounds like Eric's MSI changes have helped.

> there are new DWARFs but the one I reported for 2.6.18 seem to be fixed
> at least I diden't succeed in triggering it
> 
> the new ones are in 
> http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.19-rc2-tp-ie-e1-42.5+0737-gce9e3d99-dirty.run
> http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.19-rc2-tp-ie-e1-42.5+0737-gce9e3d99-dirty.boot

Confused.  I see no backtraces in the above.

> http://www.lorenz.eu.org/~mlo/kernel/interrupts_2.6.19-rc2-tp-ie-e1-42.5+0737-gce9e3d99-dirty
> is there too
> 
> http://www.lorenz.eu.org/~mlo/kernel/?C=M;O=D
> for a list of files I uploaded
> 
> [   64.655000] kobject_add failed for vcs6 with -EEXIST, don't try to register things with the same name in the same directory.
> [   64.655000]  [<c0103bfd>] dump_trace+0x69/0x1af
> [   64.655000]  [<c0103d5b>] show_trace_log_lvl+0x18/0x2c
> [   64.656000]  [<c01043fa>] show_trace+0xf/0x11
> [   64.656000]  [<c01044fd>] dump_stack+0x15/0x17
> [   64.656000]  [<c01fbf3d>] kobject_add+0x160/0x189
> [   64.657000]  [<c0250fec>] class_device_add+0xa2/0x3d8
> [   64.658000]  [<c02513ae>] class_device_create+0x7c/0x9c
> [   64.659000]  [<c0237858>] vcs_make_sysfs+0x3c/0x7e
> [   64.659000]  [<c023c641>] con_open+0x6f/0x7c
> [   64.660000]  [<c023259b>] tty_open+0x179/0x2f0
> [   64.661000]  [<c016226e>] chrdev_open+0x124/0x13f
> [   64.662000]  [<c015e665>] __dentry_open+0xc7/0x1ab
> [   64.662000]  [<c015e7c3>] nameidata_to_filp+0x24/0x33
> [   64.662000]  [<c015e804>] do_filp_open+0x32/0x39
> [   64.663000]  [<c015e84d>] do_sys_open+0x42/0xc3
> [   64.663000]  [<c015e907>] sys_open+0x1c/0x1e
> [   64.664000]  [<c0102de7>] syscall_call+0x7/0xb
> [   64.664000] DWARF2 unwinder stuck at syscall_call+0x7/0xb

hm, people report that occasionally - I don't think anyone knows what's
causing it.

Re: un/shared IRQ problem (was: Re: 2.6.18 - another DWARF2)

[Martin Lorenz]

On Fri, Oct 20, 2006 at 01:47:53AM -0700, Andrew Morton wrote:
> On Fri, 20 Oct 2006 10:37:41 +0200
> Martin Lorenz <martin@lorenz.eu.org> wrote:
> 
> > 
> > the new ones are in 
> > http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.19-rc2-tp-ie-e1-42.5+0737-gce9e3d99-dirty.run
> > http://www.lorenz.eu.org/~mlo/kernel/dmesg_2.6.19-rc2-tp-ie-e1-42.5+0737-gce9e3d99-dirty.boot
> 
> Confused.  I see no backtraces in the above.

only the ones I copied below
so the original issue of this thread seems to be solved in the 2.6.19-rc2


> 
> > http://www.lorenz.eu.org/~mlo/kernel/interrupts_2.6.19-rc2-tp-ie-e1-42.5+0737-gce9e3d99-dirty
> > is there too
> > 
> > http://www.lorenz.eu.org/~mlo/kernel/?C=M;O=D
> > for a list of files I uploaded
> > 
> > [   64.655000] kobject_add failed for vcs6 with -EEXIST, don't try to register things with the same name in the same directory.
> > [   64.655000]  [<c0103bfd>] dump_trace+0x69/0x1af
> > [   64.655000]  [<c0103d5b>] show_trace_log_lvl+0x18/0x2c
> > [   64.656000]  [<c01043fa>] show_trace+0xf/0x11
> > [   64.656000]  [<c01044fd>] dump_stack+0x15/0x17
> > [   64.656000]  [<c01fbf3d>] kobject_add+0x160/0x189
> > [   64.657000]  [<c0250fec>] class_device_add+0xa2/0x3d8
> > [   64.658000]  [<c02513ae>] class_device_create+0x7c/0x9c
> > [   64.659000]  [<c0237858>] vcs_make_sysfs+0x3c/0x7e
> > [   64.659000]  [<c023c641>] con_open+0x6f/0x7c
> > [   64.660000]  [<c023259b>] tty_open+0x179/0x2f0
> > [   64.661000]  [<c016226e>] chrdev_open+0x124/0x13f
> > [   64.662000]  [<c015e665>] __dentry_open+0xc7/0x1ab
> > [   64.662000]  [<c015e7c3>] nameidata_to_filp+0x24/0x33
> > [   64.662000]  [<c015e804>] do_filp_open+0x32/0x39
> > [   64.663000]  [<c015e84d>] do_sys_open+0x42/0xc3
> > [   64.663000]  [<c015e907>] sys_open+0x1c/0x1e
> > [   64.664000]  [<c0102de7>] syscall_call+0x7/0xb
> > [   64.664000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
> 
> hm, people report that occasionally - I don't think anyone knows what's
> causing it.
> 
so I'll simply ignore it :-)


gruss
  mlo
--
Dipl.-Ing. Martin Lorenz

            They that can give up essential liberty 
	    to obtain a little temporary safety 
	    deserve neither liberty nor safety.
                                   Benjamin Franklin

please encrypt your mail to me
GnuPG key-ID: F1AAD37D
get it here:
http://blackhole.pca.dfn.de:11371/pks/lookup?op=get&search=0xF1AAD37D

ICQ UIN: 33588107