Bug 252321 - spurious interrupts when harddisk is under high load
spurious interrupts when harddisk is under high load
Status: CLOSED WONTFIX
Product: Fedora
Classification: Fedora
Component: kernel (Show other bugs)
7
x86_64 Linux
medium Severity medium
: ---
: ---
Assigned To: Kernel Maintainer List
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2007-08-15 08:31 EDT by Egon Kastelijn
Modified: 2008-06-16 22:09 EDT (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2008-06-16 22:09:55 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
lspci output (45.33 KB, text/plain)
2007-09-27 09:27 EDT, Egon Kastelijn
no flags Details
dmesg output (466 bytes, text/plain)
2007-09-27 09:29 EDT, Egon Kastelijn
no flags Details
/var/log/dmesg (22.30 KB, text/plain)
2007-09-27 12:15 EDT, Egon Kastelijn
no flags Details

  None (edit)
Description Egon Kastelijn 2007-08-15 08:31:03 EDT
From Bugzilla Helper:
User-Agent: Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.8.1.5) Gecko/20070718 Fedora/2.0.0.5-1.fc7 Firefox/2.0.0.5

Description of problem:
Syslog shows spurious interrupts when the harddisks are under heavy load.

The system is an x86_64 Pentium D940 Dual Core with an Asus mainboard with onboard SATA-2 controllers and drives with NCQ.
It has Linux software RAID-5 and LVM2 on Ext-3.

The load is generated using Bonnie++.


Version-Release number of selected component (if applicable):
2.6.20-2925.13.fc7xen

How reproducible:
Always


Steps to Reproduce:
1. Start Bonnie++

Actual Results:
Aug 15 13:59:15 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7e03ffff)
Aug 15 13:59:26 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x660)
Aug 15 13:59:41 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7efebfff)
Aug 15 13:59:42 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x79ffffff)
Aug 15 13:59:43 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x33)
Aug 15 13:59:46 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x1df1ff)
Aug 15 13:59:46 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7ffffcff)
Aug 15 13:59:46 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fcfffff)
Aug 15 13:59:47 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fe7ffff)
Aug 15 13:59:51 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x112)
Aug 15 13:59:56 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x73ffffff)
Aug 15 13:59:57 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0xff8fff)
Aug 15 14:00:01 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x3fffff9f)
Aug 15 14:00:26 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fcff3)
Aug 15 14:00:35 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fffdbff)
Aug 15 14:00:36 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0xfb9)
Aug 15 14:00:47 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7ff1ffff)
Aug 15 14:00:47 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x209)
Aug 15 14:00:56 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7ffff9ff)
Aug 15 14:01:00 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fffff8f)
Aug 15 14:01:12 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7bfdffff)
Aug 15 14:01:13 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fff9fff)
Aug 15 14:01:21 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7ffffcff)
Aug 15 14:01:27 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7ffff3cf)
Aug 15 14:01:28 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7ffffddf)
Aug 15 14:01:32 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fffc3ff)
Aug 15 14:01:33 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fe9ffff)
Aug 15 14:01:36 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x5)
Aug 15 14:01:39 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x3ffe3)
Aug 15 14:01:42 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fffff5f)
Aug 15 14:01:44 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x19)
Aug 15 14:01:58 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x1f79)
Aug 15 14:02:08 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x8c40f9)
Aug 15 14:02:13 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x3)
Aug 15 14:02:21 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x100002)
Aug 15 14:02:26 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7ffffd7f)
Aug 15 14:02:31 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7ff807ff)
Aug 15 14:02:32 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x80043)
Aug 15 14:02:39 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x1fffeff7)
Aug 15 14:02:39 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fff7bff)
Aug 15 14:02:57 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7f7fdfff)
Aug 15 14:03:07 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0xe978)
Aug 15 14:03:13 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7f3fffff)
Aug 15 14:03:26 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x3c07)
Aug 15 14:03:36 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x63ffffff)
Aug 15 14:03:36 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fffff3f)
Aug 15 14:03:58 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7bc3fe3f)
Aug 15 14:04:28 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0xbdc)
Aug 15 14:04:31 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x1f)
Aug 15 14:05:07 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fefbfff)
Aug 15 14:05:10 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7e000c0f)
Aug 15 14:05:31 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7ffffff6)
Aug 15 14:05:34 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0xf83b3f)
Aug 15 14:05:35 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7e7fffff)
Aug 15 14:05:37 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x6000103)
Aug 15 14:05:46 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x3f800f8)
Aug 15 14:05:47 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x7fffeeff)
Aug 15 14:05:53 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag 0xfafbfcfd sactive 0x1800201)

Expected Results:
No messages in syslog

Additional info:
Comment 1 Christopher Brown 2007-09-25 10:26:49 EDT
Hello,

I'm reviewing this bug as part of the kernel bug triage project, an attempt to
isolate current bugs in the fedora kernel.

http://fedoraproject.org/wiki/KernelBugTriage

I am CC'ing myself to this bug and will try and assist you in resolving it if I can.

There hasn't been much activity on this bug for a while. Could you tell me if
you are still having problems with the latest kernel?

If the problem no longer exists then please close this bug or I'll do so in a
few days if there is no additional information lodged.
Comment 2 Egon Kastelijn 2007-09-25 14:49:55 EDT
Hi Christopher,

Yes, I am still experiencing the problem.
At the moment I am running kernel 2.6.20-2931.fc7xen.

A small extract of my logfile (/var/log/messages)
Sep 23 19:15:57 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag
0xfafbfcfd sactive 0x1c)
Sep 23 20:05:02 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag
0xfafbfcfd sactive 0x113)
Sep 24 00:01:09 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag
0xfafbfcfd sactive 0x7f87c7)
Sep 24 18:33:01 virtix kernel: ata2: spurious interrupt (irq_stat 0x8 active_tag
0xfafbfcfd sactive 0x2)
Sep 25 04:39:56 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag
0xfafbfcfd sactive 0x33)
Sep 25 11:09:10 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag
0xfafbfcfd sactive 0x3fffff)
Sep 25 11:59:51 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag
0xfafbfcfd sactive 0x5)
Sep 25 20:08:34 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag
0xfafbfcfd sactive 0xfdf7f)
Sep 25 20:10:00 virtix kernel: ata1: spurious interrupt (irq_stat 0x8 active_tag
0xfafbfcfd sactive 0x3fff)
Sep 25 20:11:20 virtix kernel: ata3: spurious interrupt (irq_stat 0x8 active_tag
0xfafbfcfd sactive 0x3ffef)

Comment 3 Christopher Brown 2007-09-26 15:46:36 EDT
Okay, thanks for the update. Please could you attach the output from:

# lspci -vvxxx
dmesg

and I can then re-assign to the relevant maintainer. This *may* be an issue with
NCQ as seen in:

http://lkml.org/lkml/2006/12/27/174

and fixed in 2.6.21 by blacklisting of your drive however as you are running a
xen kernel things are lagging behind somewhat. You could try:

echo 1 > /sys/block/sdX/device/queue_depth

and replace sdX with whatever drive has the issue.
Comment 4 Egon Kastelijn 2007-09-27 09:27:16 EDT
Created attachment 208441 [details]
lspci output
Comment 5 Egon Kastelijn 2007-09-27 09:29:05 EDT
Created attachment 208451 [details]
dmesg output
Comment 6 Chuck Ebbert 2007-09-27 10:39:53 EDT
(In reply to comment #5)
> Created an attachment (id=208451) [edit]
> dmesg output
> 

We need the entire dmesg so we can see which device ata1 is.
(Just upload /var/log/dmesg)
Comment 7 Egon Kastelijn 2007-09-27 12:15:18 EDT
Created attachment 208561 [details]
/var/log/dmesg
Comment 8 Egon Kastelijn 2007-09-27 12:16:04 EDT
I entered the command 'echo 1 > /sys/block/sdX/device/queue_depth' on my system.
After that I am not seeing any 'spurious interrupts' anymore when I am running
Bonnie++.
So this is indeed a (nice) workaround.
Comment 9 Chuck Ebbert 2007-09-27 13:50:36 EDT
On AHCI controller:
Maxtor 6H500F0   HA43
Comment 10 Christopher Brown 2008-01-11 12:03:03 EST
Hello,

There hasn't been much activity on this bug for a while. Are you still having to
use the above workaround?
Comment 11 Egon Kastelijn 2008-01-11 15:38:59 EST
I am sorry. I did not retest the problem after my kernel update.

At this moment I am running kernel 2.6.21-2952.fc8xen, and I am unable to
reproduce the "spurious interrupt" problem. So that's nice in my opinion.
The strange thing is that I am having having other "spurious completions"
messages in my /var/log/messages ever since.

Quote:
Jan  8 22:07:27 virtix kernel: ata1.00: (spurious completions during NCQ
issue=0x2 SAct=0xfb FIS=004040a1:00000004)
Jan  8 22:08:22 virtix kernel: ata2.00: (spurious completions during NCQ
issue=0x0 SAct=0x1f FIS=004040a1:00000002)
Jan  8 22:08:48 virtix kernel: ata3.00: (spurious completions during NCQ
issue=0x0 SAct=0x7 FIS=004040a1:00000001)
Jan  8 22:09:42 virtix kernel: ata3.00: (spurious completions during NCQ
issue=0x2 SAct=0xcf FIS=004040a1:00000020)
Jan  8 22:10:05 virtix kernel: ata2.00: (spurious completions during NCQ
issue=0x0 SAct=0x1ff00100 FIS=004040a1:00080000)
Jan  9 19:28:09 virtix kernel: ata1.00: (spurious completions during NCQ
issue=0x0 SAct=0x7f801 FIS=004040a1:00000400)
Jan  9 19:46:19 virtix kernel: ata1.00: (spurious completions during NCQ
issue=0x0 SAct=0x6003ffff FIS=004040a1:10000000)
Jan  9 21:43:49 virtix kernel: ata1.00: (spurious completions during NCQ
issue=0x0 SAct=0x201 FIS=004040a1:00000100)
Jan  9 21:53:18 virtix kernel: ata1.00: (spurious completions during NCQ
issue=0x1 SAct=0x37d FIS=004040a1:00000002)
Jan  9 23:01:59 virtix kernel: ata1.00: (spurious completions during NCQ
issue=0x0 SAct=0x5 FIS=004040a1:00000010)
Jan  9 23:32:12 virtix kernel: ata1.00: (spurious completions during NCQ
issue=0x0 SAct=0x7f00001f FIS=004040a1:00800000)
Jan  9 23:32:52 virtix kernel: ata1.00: (spurious completions during NCQ
issue=0x80 SAct=0xff FIS=004040a1:00000400)
Jan  9 23:33:51 virtix kernel: ata1.00: (spurious completions during NCQ
issue=0x0 SAct=0x7 FIS=004040a1:00000008)
Jan  9 23:41:04 virtix kernel: ata1.00: (spurious completions during NCQ
issue=0xa SAct=0x7f FIS=004040a1:00000008)

Should I register this new problem under a seperate Bug?
Comment 12 Christopher Brown 2008-01-11 16:15:13 EST
I think its still the same underlying issue but I'll leave one of the kernel
team to comment on that.
Comment 13 Bug Zapper 2008-05-14 09:59:45 EDT
This message is a reminder that Fedora 7 is nearing the end of life. Approximately 30 (thirty) days from now Fedora will stop maintaining and issuing updates for Fedora 7. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as WONTFIX if it remains open with a Fedora 'version' of '7'.

Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version prior to Fedora 7's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that we may not be able to fix it before Fedora 7 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora please change the 'version' of this bug. If you are unable to change the version, please add a comment here and someone will do it for you.

Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete. If possible, it is recommended that you try the newest available Fedora distribution to see if your bug still exists.

Please read the Release Notes for the newest Fedora distribution to make sure it will meet your needs:
http://docs.fedoraproject.org/release-notes/

The process we are following is described here: http://fedoraproject.org/wiki/BugZappers/HouseKeeping
Comment 14 Bug Zapper 2008-06-16 22:09:52 EDT
Fedora 7 changed to end-of-life (EOL) status on June 13, 2008. 
Fedora 7 is no longer maintained, which means that it will not 
receive any further security or bug fix updates. As a result we 
are closing this bug. 

If you can reproduce this bug against a currently maintained version 
of Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.

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