[PATCH] V4L/DVB: saa7146: IRQF_DISABLED causes only trouble

[PATCH] V4L/DVB: saa7146: IRQF_DISABLED causes only trouble

[Bjørn Mork]

As discussed many times, e.g. in http://lkml.org/lkml/2007/7/26/401
mixing IRQF_DISABLED with IRQF_SHARED just doesn't make sense.

Remove IRQF_DISABLED to avoid random unexpected behaviour.

Ever since I started using the saa7146 driver, I've had occasional
soft lockups.  I do not have any real evidence that the saa7146
driver is the cause, but the lockups are gone after removing the
IRQF_DISABLED flag from this driver.

On my system, this driver shares an irq17 with the pata_jmicron
driver:

 17:       2115      10605    9422844    8193902   IO-APIC-fasteoi   pata_jmicron, saa7146 (0)

This may be a mitigating factor.

Signed-off-by: Bjørn Mork <bjorn@mork.no>
Cc: stable@kernel.org
---
 drivers/media/common/saa7146_core.c |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)

diff --git a/drivers/media/common/saa7146_core.c b/drivers/media/common/saa7146_core.c
index 982f000..038dcc8 100644
--- a/drivers/media/common/saa7146_core.c
+++ b/drivers/media/common/saa7146_core.c
@@ -416,7 +416,7 @@ static int saa7146_init_one(struct pci_dev *pci, const struct pci_device_id *ent
 	saa7146_write(dev, MC2, 0xf8000000);
 
 	/* request an interrupt for the saa7146 */
-	err = request_irq(pci->irq, interrupt_hw, IRQF_SHARED | IRQF_DISABLED,
+	err = request_irq(pci->irq, interrupt_hw, IRQF_SHARED,
 			  dev->name, dev);
 	if (err < 0) {
 		ERR(("request_irq() failed.\n"));
-- 
1.5.6.5

Re: [PATCH] V4L/DVB: saa7146: IRQF_DISABLED causes only trouble

[Andy Walls]

On Sun, 2010-03-21 at 21:08 +0100, Bjørn Mork wrote:
> As discussed many times, e.g. in http://lkml.org/lkml/2007/7/26/401
> mixing IRQF_DISABLED with IRQF_SHARED just doesn't make sense.
> 
> Remove IRQF_DISABLED to avoid random unexpected behaviour.
> 
> Ever since I started using the saa7146 driver, I've had occasional
> soft lockups.  I do not have any real evidence that the saa7146
> driver is the cause, but the lockups are gone after removing the
> IRQF_DISABLED flag from this driver.
> 
> On my system, this driver shares an irq17 with the pata_jmicron
> driver:
> 
>  17:       2115      10605    9422844    8193902   IO-APIC-fasteoi   pata_jmicron, saa7146 (0)
> 
> This may be a mitigating factor.
> 
> Signed-off-by: Bjørn Mork <bjorn@mork.no>
> Cc: stable@kernel.org

And here are some more recent discussions:

http://lkml.org/lkml/2009/11/30/215
http://lkml.org/lkml/2009/3/2/33
http://lkml.org/lkml/2009/3/2/225
http://www.mail-archive.com/ivtv-devel@ivtvdriver.org/msg06319.html
http://www.mail-archive.com/ivtv-devel@ivtvdriver.org/msg06362.html

And the ones on the LKML seem prettry inconclusive to me.


If the saa7146 driver was registered second, then this change should
have no effect on your system.

If the saa7146 driver was registered first, then this can cause the
saa7146 driver's interrupt handler to be interrupted.  I doubt the
saa7146 driver is prepared for this contingency.

I doubt that this is the "proper" fix for your problem.


Does the "soft lockup" put an Oops or BUG message in dmesg
or /var/log/messages? 

What precisely do you mean by "soft lockup"?

Regards,
Andy

> ---
>  drivers/media/common/saa7146_core.c |    2 +-
>  1 files changed, 1 insertions(+), 1 deletions(-)
> 
> diff --git a/drivers/media/common/saa7146_core.c b/drivers/media/common/saa7146_core.c
> index 982f000..038dcc8 100644
> --- a/drivers/media/common/saa7146_core.c
> +++ b/drivers/media/common/saa7146_core.c
> @@ -416,7 +416,7 @@ static int saa7146_init_one(struct pci_dev *pci, const struct pci_device_id *ent
>  	saa7146_write(dev, MC2, 0xf8000000);
>  
>  	/* request an interrupt for the saa7146 */
> -	err = request_irq(pci->irq, interrupt_hw, IRQF_SHARED | IRQF_DISABLED,
> +	err = request_irq(pci->irq, interrupt_hw, IRQF_SHARED,
>  			  dev->name, dev);
>  	if (err < 0) {
>  		ERR(("request_irq() failed.\n"));

Re: [PATCH] V4L/DVB: saa7146: IRQF_DISABLED causes only trouble

[Bjørn Mork]

Andy Walls <awalls@radix.net> writes:
> On Sun, 2010-03-21 at 21:08 +0100, Bjørn Mork wrote:
>> As discussed many times, e.g. in http://lkml.org/lkml/2007/7/26/401
>> mixing IRQF_DISABLED with IRQF_SHARED just doesn't make sense.
>> 
>> Remove IRQF_DISABLED to avoid random unexpected behaviour.
>> 
>> Ever since I started using the saa7146 driver, I've had occasional
>> soft lockups.  I do not have any real evidence that the saa7146
>> driver is the cause, but the lockups are gone after removing the
>> IRQF_DISABLED flag from this driver.
>> 
>> On my system, this driver shares an irq17 with the pata_jmicron
>> driver:
>> 
>>  17:       2115      10605    9422844    8193902   IO-APIC-fasteoi   pata_jmicron, saa7146 (0)
>> 
>> This may be a mitigating factor.
>> 
>> Signed-off-by: Bjørn Mork <bjorn@mork.no>
>> Cc: stable@kernel.org
>
> And here are some more recent discussions:
>
> http://lkml.org/lkml/2009/11/30/215
> http://lkml.org/lkml/2009/3/2/33
> http://lkml.org/lkml/2009/3/2/225
> http://www.mail-archive.com/ivtv-devel@ivtvdriver.org/msg06319.html
> http://www.mail-archive.com/ivtv-devel@ivtvdriver.org/msg06362.html
>
> And the ones on the LKML seem prettry inconclusive to me.

OK, I don't really feel up to arguing against any of those.

But the argument seems to be more along the lines of whether the
requirement should be always disabled or always enabled.  Most people
seem to agree that it should be one or the other, and *not* a mix, and
hence that the IRQF_DISABLED should go away (but possibly be replaced by
disabled as default behaviour).

The discussion about which is correct, always disabled or always
enabled, is way out of my league.  But I believe that current drivers
have to adapt to the current kernel default, and that is always enabled.

The patch in http://lkml.org/lkml/2009/3/2/33 might be the correct
solution eventually, but attempting to implement this in a handful
drivers is not going to work.  By using IRQF_DISABLED you are only
triggering the bugs which makes Linus hesitate to take that patch,
in a very random and rather undebuggable way.  That's not good.

To quote one of Linus' followups to http://lkml.org/lkml/2009/3/2/33
(in http://lkml.org/lkml/2009/3/2/186):

"The whole - and only - point is that there are drivers that are _known_ to 
 require non-IRQF_DISABLED semantics. IDE is one such one."



*This* is what makes using IRQF_SHARED || IRQF_DISABLED risky, IMHO.
You can't currently guarantee that you don't share the line with one of
those drivers.


> If the saa7146 driver was registered second, then this change should
> have no effect on your system.
>
> If the saa7146 driver was registered first, then this can cause the
> saa7146 driver's interrupt handler to be interrupted.  I doubt the
> saa7146 driver is prepared for this contingency.
>
> I doubt that this is the "proper" fix for your problem.

No, maybe it's not.  But doesn't the fact that you can't predict the
actual effect of the IRQF_DISABLED flag tell you that using it is wrong? 
Removing it will at least provide a predictable outcome.

The problem you miss above is how the other drivers sharing this
interrupt will deal with the, to them, unexpected occasional disabled
interrupts.  How the heck do you ensure that they can handle it?

I assume the real fix would be to ensure that the saa7146 interrupt
handler can be interrupted.  I have no idea how to to that.  Do you know
why it can't be interrupted?  It doesn't look particularily
uninterruptable to me.  And as you say: It will be interrupted even with
the IRQF_DISABLED flag.

The alternative to making ensure that the saa7146 interrupt handler can
be interrupted is really not keeping IRQF_DISABLED, but
 - making sure that *every* interrupt handler in the kernel can run with
   interrupts disabled, and
 - change the default to running with interrupts disabled

I believe it's easier to modify the saa7146 driver...

> Does the "soft lockup" put an Oops or BUG message in dmesg
> or /var/log/messages? 
>
> What precisely do you mean by "soft lockup"?

I mean CPU cores getting stuck, like:

Mar 20 01:02:56 canardo kernel: [96555.159999] BUG: soft lockup - CPU#0 stuck for 61s! [lmcoretemp:7424]
Mar 20 01:02:56 canardo kernel: [96603.480497] BUG: soft lockup - CPU#1 stuck for 61s! [kswapd0:47]
Mar 20 01:02:56 canardo kernel: [96603.480999] BUG: soft lockup - CPU#2 stuck for 61s! [rndc:9119]
Mar 20 01:02:56 canardo kernel: [96620.659996] BUG: soft lockup - CPU#0 stuck for 61s! [lmcoretemp:7424]
Mar 20 01:02:56 canardo kernel: [96668.976496] BUG: soft lockup - CPU#1 stuck for 61s! [kswapd0:47]
Mar 20 01:02:56 canardo kernel: [96668.976995] BUG: soft lockup - CPU#2 stuck for 61s! [rndc:9119]
Mar 20 01:02:56 canardo kernel: [96686.159997] BUG: soft lockup - CPU#0 stuck for 61s! [lmcoretemp:7424]


As the syslogging is local, you can't really trust syslog's timestamp.
But the kernel timestamps should be accurate.

The incident above started with

Mar 20 01:02:56 canardo kernel: [96513.561007] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.577006] DVB: TDA10023(0): tda10023_writereg, writereg error (reg == 0x0d, val == 0x86, ret == -5)
Mar 20 01:02:56 canardo kernel: [96513.589006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.617006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.645006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.673005] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.689006] DVB: TDA10023(0): tda10023_writereg, writereg error (reg == 0x3d, val == 0x00, ret == -5)
Mar 20 01:02:56 canardo kernel: [96513.701006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.729006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.757006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.785006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.801005] DVB: TDA10023(0): tda10023_writereg, writereg error (reg == 0x05, val == 0x26, ret == -5)
Mar 20 01:02:56 canardo kernel: [96513.813005] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.841007] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.869005] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
Mar 20 01:02:56 canardo kernel: [96513.897007] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer

and a few thousand more of those before:

Mar 20 01:02:56 canardo kernel: [96712.636963] Clocksource tsc unstable (delta = 1700735019709 ns)

Which I believe is pretty weird...

Mar 20 01:02:58 canardo kernel: [96714.968443] Switching to clocksource hpet

OK, consequence of the above.

Mar 20 01:02:58 canardo kernel: [96714.973077] saa7146: unregister extension 'budget_av'.
Mar 20 01:02:58 canardo kernel: [96714.973536] budget_av 0000:05:01.0: PCI INT A disabled

And this seems to be what "solved" the problem.  I don't know why
budget_av was unloaded here.  It was not manual intervention.  Does it
unload itself due to the extensive timeouts?  

Anyway, disabling the IRQ allowed the machine to continue. Unfortunately 
with rather ugly side effects like libata giving up on a few of the
disks and disabling them, but still better than just crashing...

I assume you can argue that this is caused by a bug in some other
driver's interrupt handler.  And you are of course right.  But that bug
is in practice allowed today, due to the fact that the default is
running with interrupts enabled.

Allowing saa7146 to run with interrupts enabled hides that bug for me.



Bjørn

[PATCH] V4L/DVB: saa7146: Making IRQF_DISABLED or IRQF_SHARED optional

[Bjørn Mork]

As discussed many times, e.g. in http://lkml.org/lkml/2007/7/26/401
mixing IRQF_DISABLED with IRQF_SHARED may cause unpredictable and
unexpected results.

Add a module parameter to allow fine tuning the request_irq
flags based on local system requirements.  Some may need to turn
off IRQF_DISABLED to be able to share interrupt with drivers
needing interrupts enabled, while others may want to turn off
IRQF_SHARED to ensure that IRQF_DISABLED has an effect.

Signed-off-by: Bjørn Mork <bjorn@mork.no>
---

I have reiterated through the previous discussions to find the real reason 
why IRQF_DISABLED is kept in assorted V4L/DVB drivers, and do now understand 
that my first approach was a bit too optimistically simple....

The argument for IRQF_DISABLED seems to be that running with interrupts 
enabled may cause multimedia capture devices to drop frames.  Which sounds 
plausible.

But there are two problems with this:
1) as long as you use IRQF_SHARED there is no guarantee that IRQF_DISABLED 
  has any effect, and you may still drop frames
2) drivers sharing the interrupt may assume that interrupts are enabled

The actual effect is highly system dependant and may change with every 
little change to the PCI system, including adding or removing cards,
moving cards around, or even upgrading the kernel without doing any
hardware or driver change at all.

So I propose adding a module parameter allowing a system administrator to
configure a more predictable behaviour by turning off either IRQF_DISABLED or
IRQF_SHARED.  Those with enough interrupt lines and a wish to enforce 
IRQF_DISABLED to avoid dropping frames may disable IRQF_SHARED, and those
experiencing problems with sharing drivers may try to disable one or the
other.

The default is kept as IRQF_SHARED | IRQF_DISABLED



 drivers/media/common/saa7146_core.c |    6 +++++-
 1 files changed, 5 insertions(+), 1 deletions(-)

diff --git a/drivers/media/common/saa7146_core.c b/drivers/media/common/saa7146_core.c
index 982f000..21127f6 100644
--- a/drivers/media/common/saa7146_core.c
+++ b/drivers/media/common/saa7146_core.c
@@ -26,9 +26,13 @@ DEFINE_MUTEX(saa7146_devices_lock);
 static int saa7146_num;
 
 unsigned int saa7146_debug;
+static int irqflags = IRQF_SHARED | IRQF_DISABLED;
 
 module_param(saa7146_debug, uint, 0644);
 MODULE_PARM_DESC(saa7146_debug, "debug level (default: 0)");
+module_param(irqflags, int, 0444);
+MODULE_PARM_DESC(irqflags, "request_irq flags - default: 0xA0 = 0x20 (IRQF_DISABLED) | 0x80 (IRQF_SHARED)");
+
 
 #if 0
 static void dump_registers(struct saa7146_dev* dev)
@@ -416,7 +420,7 @@ static int saa7146_init_one(struct pci_dev *pci, const struct pci_device_id *ent
 	saa7146_write(dev, MC2, 0xf8000000);
 
 	/* request an interrupt for the saa7146 */
-	err = request_irq(pci->irq, interrupt_hw, IRQF_SHARED | IRQF_DISABLED,
+	err = request_irq(pci->irq, interrupt_hw, irqflags,
 			  dev->name, dev);
 	if (err < 0) {
 		ERR(("request_irq() failed.\n"));
-- 
1.5.6.5

Re: [PATCH] V4L/DVB: saa7146: Making IRQF_DISABLED or IRQF_SHARED optional

[Oliver Endriss]

Hi,

Bjørn Mork wrote:
> As discussed many times, e.g. in http://lkml.org/lkml/2007/7/26/401
> mixing IRQF_DISABLED with IRQF_SHARED may cause unpredictable and
> unexpected results.
> 
> Add a module parameter to allow fine tuning the request_irq
> flags based on local system requirements.  Some may need to turn
> off IRQF_DISABLED to be able to share interrupt with drivers
> needing interrupts enabled, while others may want to turn off
> IRQF_SHARED to ensure that IRQF_DISABLED has an effect.

NAK. We should not add module parameters for this kind of crap.

Let's check whether IRQF_DISABLED is really required.
Afaics it can be removed.

@all:
Please check whether the first patch causes any problems.

CU
Oliver

-- 
----------------------------------------------------------------
VDR Remote Plugin 0.4.0: http://www.escape-edv.de/endriss/vdr/
4 MByte Mod: http://www.escape-edv.de/endriss/dvb-mem-mod/
Full-TS Mod: http://www.escape-edv.de/endriss/dvb-full-ts-mod/
----------------------------------------------------------------

Re: [PATCH] V4L/DVB: saa7146: Making IRQF_DISABLED or IRQF_SHARED optional

[Bjørn Mork]

Oliver Endriss <o.endriss@gmx.de> writes:
> Bjørn Mork wrote:
>> As discussed many times, e.g. in http://lkml.org/lkml/2007/7/26/401
>> mixing IRQF_DISABLED with IRQF_SHARED may cause unpredictable and
>> unexpected results.
>> 
>> Add a module parameter to allow fine tuning the request_irq
>> flags based on local system requirements.  Some may need to turn
>> off IRQF_DISABLED to be able to share interrupt with drivers
>> needing interrupts enabled, while others may want to turn off
>> IRQF_SHARED to ensure that IRQF_DISABLED has an effect.
>
> NAK. We should not add module parameters for this kind of crap.

OK.  You are perfectly right.  This is something that Should Just Work(tm)
without any user intervention.  Sorry for adding confusion.

> Let's check whether IRQF_DISABLED is really required.
> Afaics it can be removed.

Thanks for reviewing.

> @all:
> Please check whether the first patch causes any problems.


Anyone?  

FWIW, I do have real stabilitity problems with IRQF_DISABLED.  Removing
it seem to have resolved these, and I have not noticed any regressions.

If it matters, this is tested on a quad core system with two DVB-C cards
(one budget-av and one mantis):

bjorn@canardo:~$ lspci -nn
00:00.0 Host bridge [0600]: Intel Corporation 82G33/G31/P35/P31 Express DRAM Controller [8086:29c0] (rev 02)
00:01.0 PCI bridge [0604]: Intel Corporation 82G33/G31/P35/P31 Express PCI Express Root Port [8086:29c1] (rev 02)
00:1a.0 USB Controller [0c03]: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #4 [8086:2937] (rev 02)
00:1a.1 USB Controller [0c03]: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #5 [8086:2938] (rev 02)
00:1a.2 USB Controller [0c03]: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #6 [8086:2939] (rev 02)
00:1a.7 USB Controller [0c03]: Intel Corporation 82801I (ICH9 Family) USB2 EHCI Controller #2 [8086:293c] (rev 02)
00:1c.0 PCI bridge [0604]: Intel Corporation 82801I (ICH9 Family) PCI Express Port 1 [8086:2940] (rev 02)
00:1c.4 PCI bridge [0604]: Intel Corporation 82801I (ICH9 Family) PCI Express Port 5 [8086:2948] (rev 02)
00:1c.5 PCI bridge [0604]: Intel Corporation 82801I (ICH9 Family) PCI Express Port 6 [8086:294a] (rev 02)
00:1d.0 USB Controller [0c03]: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #1 [8086:2934] (rev 02)
00:1d.1 USB Controller [0c03]: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #2 [8086:2935] (rev 02)
00:1d.2 USB Controller [0c03]: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #3 [8086:2936] (rev 02)
00:1d.7 USB Controller [0c03]: Intel Corporation 82801I (ICH9 Family) USB2 EHCI Controller #1 [8086:293a] (rev 02)
00:1e.0 PCI bridge [0604]: Intel Corporation 82801 PCI Bridge [8086:244e] (rev 92)
00:1f.0 ISA bridge [0601]: Intel Corporation 82801IB (ICH9) LPC Interface Controller [8086:2918] (rev 02)
00:1f.2 SATA controller [0106]: Intel Corporation 82801IB (ICH9) 4 port SATA AHCI Controller [8086:2923] (rev 02)
00:1f.3 SMBus [0c05]: Intel Corporation 82801I (ICH9 Family) SMBus Controller [8086:2930] (rev 02)
01:00.0 Ethernet controller [0200]: Intel Corporation 82571EB Gigabit Ethernet Controller [8086:105e] (rev 06)
01:00.1 Ethernet controller [0200]: Intel Corporation 82571EB Gigabit Ethernet Controller [8086:105e] (rev 06)
02:00.0 Ethernet controller [0200]: Atheros Communications L1 Gigabit Ethernet Adapter [1969:1048] (rev b0)
03:00.0 SATA controller [0106]: JMicron Technology Corp. JMB362/JMB363 Serial ATA Controller [197b:2363] (rev 03)
03:00.1 IDE interface [0101]: JMicron Technology Corp. JMB362/JMB363 Serial ATA Controller [197b:2363] (rev 03)
04:00.0 RAID bus controller [0104]: Silicon Image, Inc. SiI 3132 Serial ATA Raid II Controller [1095:3132] (rev 01)
05:00.0 Multimedia controller [0480]: Twinhan Technology Co. Ltd Mantis DTV PCI Bridge Controller [Ver 1.0] [1822:4e35] (rev 01)
05:01.0 Multimedia controller [0480]: Philips Semiconductors SAA7146 [1131:7146] (rev 01)
05:02.0 PCI bridge [0604]: Intel Corporation 80960RP (i960RP) Microprocessor/Bridge [8086:0960] (rev 05)
05:02.1 Memory controller [0580]: Intel Corporation 80960RP (i960RP) Microprocessor [8086:1960] (rev 05)
05:03.0 FireWire (IEEE 1394) [0c00]: VIA Technologies, Inc. VT6306/7/8 [Fire II(M)] IEEE 1394 OHCI Controller [1106:3044] (rev c0)
06:00.0 VGA compatible controller [0300]: ATI Technologies Inc 3D Rage IIC 215IIC [Mach64 GT IIC] [1002:4756] (rev 7a)

canardo:/tmp# lspci -vvnns 5:0
05:00.0 Multimedia controller [0480]: Twinhan Technology Co. Ltd Mantis DTV PCI Bridge Controller [Ver 1.0] [1822:4e35] (rev 01)
        Subsystem: TERRATEC Electronic GmbH Device [153b:1178]
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort+ <MAbort- >SERR- <PERR- INTx-
        Latency: 64 (2000ns min, 63750ns max)
        Interrupt: pin A routed to IRQ 16
        Region 0: Memory at fcfff000 (32-bit, prefetchable) [size=4K]
        Kernel driver in use: Mantis

canardo:/tmp# lspci -vvnns 5:1
05:01.0 Multimedia controller [0480]: Philips Semiconductors SAA7146 [1131:7146] (rev 01)
        Subsystem: KNC One Device [1894:0022]
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap- 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 64 (3750ns min, 9500ns max)
        Interrupt: pin A routed to IRQ 17
        Region 0: Memory at feaffc00 (32-bit, non-prefetchable) [size=512]
        Kernel driver in use: budget_av
        Kernel modules: budget-av


bjorn@canardo:~$ cat /proc/interrupts 
           CPU0       CPU1       CPU2       CPU3       
  0:       2048        490         41       2367   IO-APIC-edge      timer
  1:          1          2          2          3   IO-APIC-edge      i8042
  4:        451        226        240        239   IO-APIC-edge      serial
  8:          1          0          0          0   IO-APIC-edge      rtc0
  9:          0          0          0          0   IO-APIC-fasteoi   acpi
 16:   22944148   25223238 1359277942 1112660476   IO-APIC-fasteoi   uhci_hcd:usb1, firewire_ohci, sata_sil24, ahci, Mantis Core
 17:       2115      10605   88099554   83744140   IO-APIC-fasteoi   pata_jmicron, saa7146 (0)
 18:         12         10    9317665    9123739   IO-APIC-fasteoi   uhci_hcd:usb3, uhci_hcd:usb6, ehci_hcd:usb7, crid
 19:          0          0          0          0   IO-APIC-fasteoi   uhci_hcd:usb5
 21:          0          0          0          0   IO-APIC-fasteoi   uhci_hcd:usb2
 23:          0          0          0          0   IO-APIC-fasteoi   uhci_hcd:usb4, ehci_hcd:usb8
 29:   99482204       2166      15663      10401   PCI-MSI-edge      ahci
 30:  475961398        551        552        569   PCI-MSI-edge      eth1
NMI:          0          0          0          0   Non-maskable interrupts
LOC:  637443973  130774380  705012685  181373819   Local timer interrupts
SPU:          0          0          0          0   Spurious interrupts
PMI:          0          0          0          0   Performance monitoring interrupts
PND:          0          0          0          0   Performance pending work
RES:    1140661    1111450    5481035    3395225   Rescheduling interrupts
CAL:   37565380     232935   25021255     311097   Function call interrupts
TLB:    4019151    1214696    3119638    4351900   TLB shootdowns
TRM:          0          0          0          0   Thermal event interrupts
THR:          0          0          0          0   Threshold APIC interrupts
MCE:          0          0          0          0   Machine check exceptions
MCP:       4862       4862       4862       4862   Machine check polls
ERR:          3
MIS:          0



This system has now been running continously for 16 days with
IRQF_DISABLED removed from the saa7146 driver.  With IRQF_DISABLED it
would usually lock up completely after a couple of days.


Bjørn

Re: [PATCH] V4L/DVB: saa7146: IRQF_DISABLED causes only trouble

[Andy Walls]

On Mon, 2010-03-22 at 10:28 +0100, Bjørn Mork wrote:
> Andy Walls <awalls@radix.net> writes:
> > On Sun, 2010-03-21 at 21:08 +0100, Bjørn Mork wrote:
> >> As discussed many times, e.g. in http://lkml.org/lkml/2007/7/26/401
> >> mixing IRQF_DISABLED with IRQF_SHARED just doesn't make sense.
> >> 
> >> Remove IRQF_DISABLED to avoid random unexpected behaviour.
> >> 
> >> Ever since I started using the saa7146 driver, I've had occasional
> >> soft lockups.  I do not have any real evidence that the saa7146
> >> driver is the cause, but the lockups are gone after removing the
> >> IRQF_DISABLED flag from this driver.
> >> 
> >> On my system, this driver shares an irq17 with the pata_jmicron
> >> driver:
> >> 
> >>  17:       2115      10605    9422844    8193902   IO-APIC-fasteoi   pata_jmicron, saa7146 (0)
> >> 
> >> This may be a mitigating factor.
> >> 
> >> Signed-off-by: Bjørn Mork <bjorn@mork.no>
> >> Cc: stable@kernel.org
> >
> > And here are some more recent discussions:
> >
> > http://lkml.org/lkml/2009/11/30/215
> > http://lkml.org/lkml/2009/3/2/33
> > http://lkml.org/lkml/2009/3/2/225
> > http://www.mail-archive.com/ivtv-devel@ivtvdriver.org/msg06319.html
> > http://www.mail-archive.com/ivtv-devel@ivtvdriver.org/msg06362.html
> >
> > And the ones on the LKML seem prettry inconclusive to me.
> 
> OK, I don't really feel up to arguing against any of those.
> 
> But the argument seems to be more along the lines of whether the
> requirement should be always disabled or always enabled.  Most people
> seem to agree that it should be one or the other, and *not* a mix,

Which is likely why the argument hasn't come to resolution.  The answer
is it depends on the situation.



>  and
> hence that the IRQF_DISABLED should go away (but possibly be replaced by
> disabled as default behaviour).

The real problem appears to be really kernel infrastructure not fixing a
known problem in IRQ handling.

linux/kernel/irq/manage.c has this comment:

        /*
         * handle_IRQ_event() always ignores IRQF_DISABLED except for
         * the _first_ irqaction (sigh).  That can cause oopsing, but
         * the behavior is classified as "will not fix" so we need to
         * start nudging drivers away from using that idiom.
         */
        if ((irqflags & (IRQF_SHARED|IRQF_DISABLED)) ==
                                        (IRQF_SHARED|IRQF_DISABLED)) {
                pr_warning(
                  "IRQ %d/%s: IRQF_DISABLED is not guaranteed on shared IRQs\n",
                        irq, devname);
        }

Looking in linux/kernel/irq/handle.c, 'first' means the first irq
handler registered. 

        irqreturn_t handle_IRQ_event(unsigned int irq, struct irqaction *action)
        {
                irqreturn_t ret, retval = IRQ_NONE;
                unsigned int status = 0;
        
                if (!(action->flags & IRQF_DISABLED))
                        local_irq_enable_in_hardirq();
	[...]

(note: action->next is not looped over for this check.)

Given your /proc/interrupts output, the first handler registered would
be the pata_jmicron module's irq handler.  So interrupts will be enabled
when the saa7146 module's irq handler runs.

So this is puzzling to me as to why IRQF_DISABLED for the saa7146 module
matters at all for your situation.  It should be ignored.



> The discussion about which is correct, always disabled or always
> enabled, is way out of my league.  But I believe that current drivers
> have to adapt to the current kernel default, and that is always enabled.

Why do you believe that?

For hardware devices which, after a short period of time, overwrite
their information about what caused the interrupt (i.e. CX23418),
yielding to another IRQ handler increases the potential for losing
information (i.e. losing tack of video buffers). 



> The patch in http://lkml.org/lkml/2009/3/2/33 might be the correct
> solution eventually, but attempting to implement this in a handful
> drivers is not going to work.  By using IRQF_DISABLED you are only
> triggering the bugs which makes Linus hesitate to take that patch,
> in a very random and rather undebuggable way.  That's not good.
> 
> To quote one of Linus' followups to http://lkml.org/lkml/2009/3/2/33
> (in http://lkml.org/lkml/2009/3/2/186):
> 
> "The whole - and only - point is that there are drivers that are _known_ to 
>  require non-IRQF_DISABLED semantics. IDE is one such one."

And I have driver, cx18, which is known to required IRQF_DISABLED (if it
can get the behavior from the kernel), if one doesn't want to lose video
buffers.


> *This* is what makes using IRQF_SHARED || IRQF_DISABLED risky, IMHO.
> You can't currently guarantee that you don't share the line with one of
> those drivers.


Really the kernel needs to be smarter about identifying these cases:

1. an IRQ line where all the drivers request IRQF_DISABLED
2. an IRQ line where all the drivers request IRQs remain enabled
3. an IRQ line where the drivers have mixed requests

Case 3 is the only case that requires resolution.  It's a system level
decision that the user should be able to set as to whether he wants one
type of behavior or the other on that interrupt line.  The kernel can
never know absolutely what's right for the user in case 3.


> 
> > If the saa7146 driver was registered second, then this change should
> > have no effect on your system.
> >
> > If the saa7146 driver was registered first, then this can cause the
> > saa7146 driver's interrupt handler to be interrupted.

That statement of mine was wrong.  If the saa7146 driver was registered
first, neither driver's irq handler will be interrupted.


>   I doubt the
> > saa7146 driver is prepared for this contingency.
> >
> > I doubt that this is the "proper" fix for your problem.
> 
> No, maybe it's not.  But doesn't the fact that you can't predict the
> actual effect of the IRQF_DISABLED flag tell you that using it is wrong? 

No.  Not being able to reliably predict an outcome, doesn't really speak
to the correctness of settings that appear to affect the outcome
(correlation is not causation).

I do know that on any particular machine, one should be able to know
whether IRQF_DISABLED will be ignored or enforced on all IRQ handlers on
an interrupt line.


> Removing it will at least provide a predictable outcome.
> 
> The problem you miss above is how the other drivers sharing this
> interrupt will deal with the, to them, unexpected occasional disabled
> interrupts.  How the heck do you ensure that they can handle it?

They can't necessarily either.  This is a system level issue that the
kernel leaves no option to the user as to how the user may want to
handle it.  Even though the user may have the best knowledge about their
desired mode of operation for their system, users get the kernel's
decided default behavior and no other choice in this case. :(


> I assume the real fix would be to ensure that the saa7146 interrupt
> handler can be interrupted.  I have no idea how to to that.  Do you know
> why it can't be interrupted?  It doesn't look particularily
> uninterruptable to me.  And as you say: It will be interrupted even with
> the IRQF_DISABLED flag.

It looks interruptable, and yes it should be interrupted in your
situation anyway.  It is likely safe to remove the flag for the saa7164
driver.



> The alternative to making ensure that the saa7146 interrupt handler can
> be interrupted is really not keeping IRQF_DISABLED, but
>  - making sure that *every* interrupt handler in the kernel can run with
>    interrupts disabled, and
>  - change the default to running with interrupts disabled
> 
> I believe it's easier to modify the saa7146 driver...
> 
> > Does the "soft lockup" put an Oops or BUG message in dmesg
> > or /var/log/messages? 
> >
> > What precisely do you mean by "soft lockup"?
> 
> I mean CPU cores getting stuck, like:
> 
> Mar 20 01:02:56 canardo kernel: [96555.159999] BUG: soft lockup - CPU#0 stuck for 61s! [lmcoretemp:7424]
> Mar 20 01:02:56 canardo kernel: [96603.480497] BUG: soft lockup - CPU#1 stuck for 61s! [kswapd0:47]
> Mar 20 01:02:56 canardo kernel: [96603.480999] BUG: soft lockup - CPU#2 stuck for 61s! [rndc:9119]
> Mar 20 01:02:56 canardo kernel: [96620.659996] BUG: soft lockup - CPU#0 stuck for 61s! [lmcoretemp:7424]
> Mar 20 01:02:56 canardo kernel: [96668.976496] BUG: soft lockup - CPU#1 stuck for 61s! [kswapd0:47]
> Mar 20 01:02:56 canardo kernel: [96668.976995] BUG: soft lockup - CPU#2 stuck for 61s! [rndc:9119]
> Mar 20 01:02:56 canardo kernel: [96686.159997] BUG: soft lockup - CPU#0 stuck for 61s! [lmcoretemp:7424]
> 
> 
> As the syslogging is local, you can't really trust syslog's timestamp.
> But the kernel timestamps should be accurate.
> 
> The incident above started with
> 
> Mar 20 01:02:56 canardo kernel: [96513.561007] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.577006] DVB: TDA10023(0): tda10023_writereg, writereg error (reg == 0x0d, val == 0x86, ret == -5)
> Mar 20 01:02:56 canardo kernel: [96513.589006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.617006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.645006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.673005] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.689006] DVB: TDA10023(0): tda10023_writereg, writereg error (reg == 0x3d, val == 0x00, ret == -5)
> Mar 20 01:02:56 canardo kernel: [96513.701006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.729006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.757006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.785006] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.801005] DVB: TDA10023(0): tda10023_writereg, writereg error (reg == 0x05, val == 0x26, ret == -5)
> Mar 20 01:02:56 canardo kernel: [96513.813005] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.841007] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.869005] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer
> Mar 20 01:02:56 canardo kernel: [96513.897007] saa7146 (0) saa7146_i2c_writeout [irq]: timed out waiting for end of xfer

So, if this happened first, you had some sort of saa7146 bridge chip or
or tuner I2C chip hardware error that lead to this downward spiral.

It also looks like the IRQF_DISABLED flag is being honored for the
saa7146's irq handler.  Which is not something I would have thought to
be the case.  (Maybe the output of module names in /proc/interrupts is
in reverse registration order?)


> and a few thousand more of those before:
> 
> Mar 20 01:02:56 canardo kernel: [96712.636963] Clocksource tsc unstable (delta = 1700735019709 ns)
> 
> Which I believe is pretty weird...

Agree.

> Mar 20 01:02:58 canardo kernel: [96714.968443] Switching to clocksource hpet
> 
> OK, consequence of the above.

Agree.

> Mar 20 01:02:58 canardo kernel: [96714.973077] saa7146: unregister extension 'budget_av'.
> Mar 20 01:02:58 canardo kernel: [96714.973536] budget_av 0000:05:01.0: PCI INT A disabled
> 
> And this seems to be what "solved" the problem.  I don't know why
> budget_av was unloaded here.  It was not manual intervention.  Does it
> unload itself due to the extensive timeouts?  

I have no idea what unloaded a kernel driver all on it's own.

> Anyway, disabling the IRQ allowed the machine to continue. Unfortunately 
> with rather ugly side effects like libata giving up on a few of the
> disks and disabling them, but still better than just crashing...
> 
> I assume you can argue that this is caused by a bug in some other
> driver's interrupt handler.  And you are of course right.  But that bug
> is in practice allowed today, due to the fact that the default is
> running with interrupts enabled.
> 
> Allowing saa7146 to run with interrupts enabled hides that bug for me.

I'm guessing it's  actually a saa7164 bug or I2C connected chip related
bug.

Regards,
Andy

> Bjørn

Re: [PATCH] V4L/DVB: saa7146: IRQF_DISABLED causes only trouble

[Bjørn Mork]

Ehh...., this is very embarrassing, but please disregard all my
statements about a hanging system related to IRQF_DISABLED.

It turns out that I've had a faulty SATA hard drive which probably have
caused all these problems.  I do not understand the inner workings of
the SATA hardware and software, but it appears that this drive has been
able to block interrupts for a considerable time without SMART detecting
any error at all.  I wrongly suspected saa7146 to be the cause because
these problems appeared after adding the saa7146 hardware.  But that was
probably just a coincidence (or maybe not really, only unrelated: I
suspect that the problem was triggered by the powercycle when adding
this card)

The drive has now been replaced, and I will start verifying that use of
saa7146 with IRQF_DISABLED does not in fact pose any real problems at
all.

I still find the discussion about it's usefulness interesting though...


Andy Walls <awalls@md.metrocast.net> writes:

> Given your /proc/interrupts output, the first handler registered would
> be the pata_jmicron module's irq handler.  So interrupts will be enabled
> when the saa7146 module's irq handler runs.
>
> So this is puzzling to me as to why IRQF_DISABLED for the saa7146 module
> matters at all for your situation.  It should be ignored.

Yes, it probably was ignored.  Sorry for not being able to sort that out
earlier.

>> The discussion about which is correct, always disabled or always
>> enabled, is way out of my league.  But I believe that current drivers
>> have to adapt to the current kernel default, and that is always enabled.
>
> Why do you believe that?

Because any other driver sharing the interrupt otherwise will cause
unpredictable results.  

But your suggestions that one should be able to detect the current state
and make system level policy decision would make that argument void, and
are generally much better solutions.

> For hardware devices which, after a short period of time, overwrite
> their information about what caused the interrupt (i.e. CX23418),
> yielding to another IRQ handler increases the potential for losing
> information (i.e. losing tack of video buffers). 

Sure, I can see that problem.  But you can't avoid it unless you find
some way to ensure that IRQF_DISABLED is enforced.  And today, that
would mean not sharing at all, would it not?

> Really the kernel needs to be smarter about identifying these cases:
>
> 1. an IRQ line where all the drivers request IRQF_DISABLED
> 2. an IRQ line where all the drivers request IRQs remain enabled
> 3. an IRQ line where the drivers have mixed requests
>
> Case 3 is the only case that requires resolution.  It's a system level
> decision that the user should be able to set as to whether he wants one
> type of behavior or the other on that interrupt line.  The kernel can
> never know absolutely what's right for the user in case 3.

Sounds like a solution to me.

And the current warning should be disabled in case 1, as the behaviour
is predictable.  But this means that the kernel also need to be smart
enough to notice both when the case changes from 1 to 3 and from 2 to 3.

>> No, maybe it's not.  But doesn't the fact that you can't predict the
>> actual effect of the IRQF_DISABLED flag tell you that using it is wrong? 
>
> No.  Not being able to reliably predict an outcome, doesn't really speak
> to the correctness of settings that appear to affect the outcome
> (correlation is not causation).

OK.

> I do know that on any particular machine, one should be able to know
> whether IRQF_DISABLED will be ignored or enforced on all IRQ handlers on
> an interrupt line.

Yes, that would be useful.  Like it is now, you have to inspect the
source code and the current driver load order to know the actual state. 



Bjørn

Re: [PATCH] V4L/DVB: saa7146: IRQF_DISABLED causes only trouble

[Andy Walls]

On Thu, 2010-04-08 at 12:05 +0200, Bjørn Mork wrote:
> Ehh...., this is very embarrassing, but please disregard all my
> statements about a hanging system related to IRQF_DISABLED.
> 
> It turns out that I've had a faulty SATA hard drive which probably have
> caused all these problems.  I do not understand the inner workings of
> the SATA hardware and software, but it appears that this drive has been
> able to block interrupts for a considerable time without SMART detecting
> any error at all.  I wrongly suspected saa7146 to be the cause because
> these problems appeared after adding the saa7146 hardware.  But that was
> probably just a coincidence (or maybe not really, only unrelated: I
> suspect that the problem was triggered by the powercycle when adding
> this card)
> 
> The drive has now been replaced, and I will start verifying that use of
> saa7146 with IRQF_DISABLED does not in fact pose any real problems at
> all.

Don't bother.

It's probably a good thing you found your root cause.  Your patch was
going to be invalidated in the near future: 

	http://lwn.net/Articles/380931/

It appears that IRQF_DISABLED behavior is to be the default behavior for
all drivers and the flag is to have no effect.



> I still find the discussion about it's usefulness interesting though...

Good. :)


Regards,
Andy