Not sure who to CC on this one...
On my new HP 2510p laptop I'm seeing the following error after resume from
suspend to RAM:
<snip>
CPU1 is up
ACPI: Waking up from system sleep state S3
APIC error on CPU1: 00(40)
ACPI: EC: non-query interrupt received, switching to interrupt mode
</snip>
The weird thing is that this only happens on resume. During system boot I
can see no APIC related issues.
Full dmesg from system boot plus a single suspend/resume cycle attached,
and also the kernel config.
I've no idea (yet) whether this is a regression or not.
Note that I've sent a separate mail for the hci_usb related issues that
are shown later in the dmesg output.
Cheers,
FJP
On Wednesday, 20 of August 2008, Frans Pop wrote:
> Not sure who to CC on this one...
>
> On my new HP 2510p laptop I'm seeing the following error after resume from
> suspend to RAM:
>
> <snip>
> CPU1 is up
> ACPI: Waking up from system sleep state S3
> APIC error on CPU1: 00(40)
> ACPI: EC: non-query interrupt received, switching to interrupt mode
> </snip>
>
> The weird thing is that this only happens on resume. During system boot I
> can see no APIC related issues.
>
> Full dmesg from system boot plus a single suspend/resume cycle attached,
> and also the kernel config.
>
> I've no idea (yet) whether this is a regression or not.
> Note that I've sent a separate mail for the hci_usb related issues that
> are shown later in the dmesg output.
Does the box work after that?
Rafael
Thanks for the quick responses Rafael.
On Wednesday 20 August 2008, Rafael wrote:
> On Wednesday, 20 of August 2008, Frans Pop wrote:
> > <snip>
> > CPU1 is up
> > ACPI: Waking up from system sleep state S3
> > APIC error on CPU1: 00(40)
> > ACPI: EC: non-query interrupt received, switching to interrupt mode
> > </snip>
>
> Does the box work after that?
Yes, it does. Both cores seem to be working fine.
The only weirdness I can see (only spotted that just now) is that both
cores will always seem to be changing frequency together (using ondemand
governor), even when 'top' shows one as idle. On my other Core Duo system
(an older desktop) the cores react independently.
This also happens immediately after boot (so not suspend related) and may
be "normal" or unrelated.
On Wednesday, 20 of August 2008, Frans Pop wrote:
> Thanks for the quick responses Rafael.
>
> On Wednesday 20 August 2008, Rafael wrote:
> > On Wednesday, 20 of August 2008, Frans Pop wrote:
> > > <snip>
> > > CPU1 is up
> > > ACPI: Waking up from system sleep state S3
> > > APIC error on CPU1: 00(40)
> > > ACPI: EC: non-query interrupt received, switching to interrupt mode
> > > </snip>
> >
> > Does the box work after that?
>
> Yes, it does. Both cores seem to be working fine.
>
> The only weirdness I can see (only spotted that just now) is that both
> cores will always seem to be changing frequency together (using ondemand
> governor), even when 'top' shows one as idle. On my other Core Duo system
> (an older desktop) the cores react independently.
> This also happens immediately after boot (so not suspend related) and may
> be "normal" or unrelated.
On my box I see many "APIC error on CPU1: 00(40)" messages that don't seem
to be related to anything obviously bad and I've alwas been seeing them.
Please monitor things for some time to check if you can find a connection
between those messages and any erroneous behavior.
Thanks,
Rafael
On Wed, 20 Aug 2008, Rafael J. Wysocki wrote:
> On my box I see many "APIC error on CPU1: 00(40)" messages that don't seem
> to be related to anything obviously bad and I've alwas been seeing them.
Barring a hardware erratum, this is a bug in the kernel. It should be
moderately easy to track down with some debugging added to writes
accessing LVT and redirection table entries.
Maciej
On Thu, Aug 21, 2008 at 11:27 AM, Maciej W. Rozycki
<[email protected]> wrote:
> On Wed, 20 Aug 2008, Rafael J. Wysocki wrote:
>
>> On my box I see many "APIC error on CPU1: 00(40)" messages that don't seem
>> to be related to anything obviously bad and I've alwas been seeing them.
>
> Barring a hardware erratum, this is a bug in the kernel. It should be
> moderately easy to track down with some debugging added to writes
> accessing LVT and redirection table entries.
Hi,
I've also seen this a lot, so I have now written (I think) such a
debug patch (it's very crude) and tested it on my laptop, which
exhibits this problem.
The patch and full dmesg (with debug output) can be found here:
http://userweb.kernel.org/~vegard/bugs/20080821-apic/
The output looks like this (with register annotations by me; CPU id is
the second column)
APIC error on CPU0: 00(40)
Last 16 APIC writes:
0: 1: [00000380] = 00001f79
1: 1: [000000b0] = 00000000
2: 1: [00000380] = 00001f7e
3: 1: [000000b0] = 00000000
4: 1: [00000380] = 00001fa5
5: 1: [000000b0] = 00000000
6: 1: [00000380] = 00001f8c
7: 1: [000000b0] = 00000000
8: 1: [000000b0] = 00000000
9: 1: [00000380] = 00001e4e
10: 1: [000000b0] = 00000000
11: 1: [00000380] = 00001fa5
12: 1: [000000b0] = 00000000
13: 1: [00000380] = 00001f87 # Initial Count Register (for Timer)
14: 0: [00000280] = 00000000 # Error Status Register
15: 0: [000000b0] = 00000000 # EOI Register
The order is from oldest (0) to newest (15) write. I don't see any
writes to ICR in there, which means that IPIs can be ruled out? It
seems that it is the write to Timer that causes it. In another place,
we have this:
13: 1: [00000320] = 000100ef # LVT Timer Register
14: 0: [00000280] = 00000000
15: 0: [000000b0] = 00000000
This would be APIC_LVT_MASKED | LOCAL_TIMER_VECTOR.
The APIC error is seen approximately every 3 minutes.
Vegard
--
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
-- E. W. Dijkstra, EWD1036
On Wed, Aug 20, 2008 at 11:56:32PM +0200, Rafael J. Wysocki wrote:
> On my box I see many "APIC error on CPU1: 00(40)" messages that don't seem
> to be related to anything obviously bad and I've alwas been seeing them.
This is on the 6325? I'd always assumed they were due to the broken
timer setup.
--
Matthew Garrett | [email protected]
On Wed, Aug 20, 2008 at 10:26:45PM +0200, Frans Pop wrote:
> The only weirdness I can see (only spotted that just now) is that both
> cores will always seem to be changing frequency together (using ondemand
> governor), even when 'top' shows one as idle. On my other Core Duo system
> (an older desktop) the cores react independently.
The cores can't actually be independently scaled. Some older kernels
would give the impression that they could, but the package itself will
run at the greater of the defined frequencies.
--
Matthew Garrett | [email protected]
On Thu, 21 Aug 2008, Vegard Nossum wrote:
> I've also seen this a lot, so I have now written (I think) such a
> debug patch (it's very crude) and tested it on my laptop, which
> exhibits this problem.
[...]
> APIC error on CPU0: 00(40)
> Last 16 APIC writes:
[...]
> The order is from oldest (0) to newest (15) write. I don't see any
> writes to ICR in there, which means that IPIs can be ruled out? It
> seems that it is the write to Timer that causes it. In another place,
> we have this:
You are correct about the ICR -- IPIs are unlikely to be a problem
because only a couple of predefined vectors are used. Besides, they are
normally critical enoug for the system to become unstable if unhandled.
Otherwise there is no correlation between the sequence of APIC writes and
an error triggering -- a bad vector in a LVT or interrupt redirection
entry will be reported whenever its associated interrupt line gets active
even though the entry might have been initialised long ago. Depending on
the device signalling hardware interrupts may quite often be ignored for a
long time without affecting the stability of the rest of the system.
Maciej
On Thu, 21 Aug 2008, Maciej W. Rozycki wrote:
> Otherwise there is no correlation between the sequence of APIC writes and
> an error triggering -- a bad vector in a LVT or interrupt redirection
> entry will be reported whenever its associated interrupt line gets active
> even though the entry might have been initialised long ago. Depending on
> the device signalling hardware interrupts may quite often be ignored for a
> long time without affecting the stability of the rest of the system.
The same applies to a broken MSI or HT setup too; I am not sure what
other sources of APIC interrupts may have been imaginatively added to
maintain the proper complexity of x86 systems as well.
Maciej
On Thu, Aug 21, 2008 at 1:51 PM, Maciej W. Rozycki <[email protected]> wrote:
> Otherwise there is no correlation between the sequence of APIC writes and
> an error triggering -- a bad vector in a LVT or interrupt redirection
> entry will be reported whenever its associated interrupt line gets active
> even though the entry might have been initialised long ago. Depending on
> the device signalling hardware interrupts may quite often be ignored for a
> long time without affecting the stability of the rest of the system.
Ah, right. Here is a dump of the LVT registers:
[00000320] = 000100ef
[00000330] = 00000200
[00000340] = 00010000
[00000350] = 00010700
[00000360] = 00000400
[00000370] = 000000fe
Maybe I've misunderstood something (again), but should those vectors
really be 0 for 330-360? (At least 330 + 360, which are not masked.)
Intel manual says: "Receive Illegal Vector : Set when the local APIC
detects an illegal vector in the message it received, including an
illegal vector code in the local vector table interrupts or in a
self-interrupt."
And 0 is clearly an illegal value for the vector code: "When an
interrupt vector in the range 0 to 15 is sent or received through the
local APIC, the APIC indicates an illegal vector in its Error Status
Register [...]".
But I still find the whole thing slightly confusing. Will play a bit
with the LVT, maybe I can learn something more :-) Thanks for the
help!
Vegard
--
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
-- E. W. Dijkstra, EWD1036
On Thu, 21 Aug 2008, Vegard Nossum wrote:
> Ah, right. Here is a dump of the LVT registers:
>
> [00000320] = 000100ef
> [00000330] = 00000200
> [00000340] = 00010000
> [00000350] = 00010700
> [00000360] = 00000400
> [00000370] = 000000fe
>
> Maybe I've misunderstood something (again), but should those vectors
> really be 0 for 330-360? (At least 330 + 360, which are not masked.)
Masked entries should be fine long-term, although I have a vague
recollection at least some implementations do send a vector error when an
LVT register is written with a masked entry implying an invalid vector,
e.g. a value like 0x00010000.
Overall the issue of the validity of the vector exists for interrupts
using the native APIC priority model only, that is ones using the Fixed
and LoPri delivery modes. All the others either ignore the vector
altogether, such as the ExtINTA delivery mode, or assign a special meaning
to it, such as the StartUp mode.
In this case the thermal entry at 0x330 uses the SMI delivery mode and
the LINT1 entry at 0x360 uses the NMI mode, so the vector is ignored for
both.
Thus this LVT is entirely valid and if you receive invalid vector
interrupts, then the reason must be elsewhere. Of course you cannot
exclude a possibility where at some intermediate stage the LVT of your
system has not been correctly initialised.
Maciej
On Thu, Aug 21, 2008 at 2:57 PM, Maciej W. Rozycki <[email protected]> wrote:
> On Thu, 21 Aug 2008, Vegard Nossum wrote:
>
>> Ah, right. Here is a dump of the LVT registers:
>>
>> [00000320] = 000100ef
>> [00000330] = 00000200
>> [00000340] = 00010000
>> [00000350] = 00010700
>> [00000360] = 00000400
>> [00000370] = 000000fe
>>
>> Maybe I've misunderstood something (again), but should those vectors
>> really be 0 for 330-360? (At least 330 + 360, which are not masked.)
>
> Masked entries should be fine long-term, although I have a vague
> recollection at least some implementations do send a vector error when an
> LVT register is written with a masked entry implying an invalid vector,
> e.g. a value like 0x00010000.
>
> Overall the issue of the validity of the vector exists for interrupts
> using the native APIC priority model only, that is ones using the Fixed
> and LoPri delivery modes. All the others either ignore the vector
> altogether, such as the ExtINTA delivery mode, or assign a special meaning
> to it, such as the StartUp mode.
>
> In this case the thermal entry at 0x330 uses the SMI delivery mode and
> the LINT1 entry at 0x360 uses the NMI mode, so the vector is ignored for
> both.
>
> Thus this LVT is entirely valid and if you receive invalid vector
> interrupts, then the reason must be elsewhere. Of course you cannot
> exclude a possibility where at some intermediate stage the LVT of your
> system has not been correctly initialised.
Thank you for the excellent explanations! I've double-checked and
everything you said makes perfect sense.
The reason must be elsewhere.
Vegard
PS: My APICs have version 0x20, which according to the Intel manual is
a reserved value. My book is from 2005, though.
--
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
-- E. W. Dijkstra, EWD1036
Maciej W. Rozycki writes:
> On Thu, 21 Aug 2008, Vegard Nossum wrote:
>
> > Ah, right. Here is a dump of the LVT registers:
> >
> > [00000320] = 000100ef
> > [00000330] = 00000200
> > [00000340] = 00010000
> > [00000350] = 00010700
> > [00000360] = 00000400
> > [00000370] = 000000fe
> >
> > Maybe I've misunderstood something (again), but should those vectors
> > really be 0 for 330-360? (At least 330 + 360, which are not masked.)
>
> Masked entries should be fine long-term, although I have a vague
> recollection at least some implementations do send a vector error when an
> LVT register is written with a masked entry implying an invalid vector,
> e.g. a value like 0x00010000.
The original Intel P6s do that. Dunno about the post-P4 ones.
On Thursday 21 August 2008, Matthew Garrett wrote:
> On Wed, Aug 20, 2008 at 10:26:45PM +0200, Frans Pop wrote:
> > The only weirdness I can see (only spotted that just now) is that
> > both cores will always seem to be changing frequency together (using
> > ondemand governor), even when 'top' shows one as idle. On my other
> > Core Duo system (an older desktop) the cores react independently.
>
> The cores can't actually be independently scaled.
That makes sense.
> Some older kernels
> would give the impression that they could, but the package itself will
> run at the greater of the defined frequencies.
It does not seem to be kernel related, but processor related.
Here are some results from two different systems (desktop and laptop)
running an _identical_ 2.6.27-rc4 x86_64 kernel.
(The desktop is actually Pentium D, not also Core Duo.)
Desktop
=======
processor : 1
vendor_id : GenuineIntel
cpu family : 15
model : 4
model name : Intel(R) Pentium(R) D CPU 3.20GHz
stepping : 7
cpu MHz : 2800.000
cache size : 1024 KB
physical id : 0
siblings : 2
core id : 1
cpu cores : 2
Samples from /sys/devices/system/cpu/cpu*/cpufreq/scaling_cur_freq:
2800000 2800000
2800000 2800000
2800000 3200000 # Start single busy loop, one core idle
3200000 3200000
2800000 3200000
2800000 3200000
Laptop
======
processor : 1
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Core(TM)2 Duo CPU U7700 @ 1.33GHz
stepping : 13
cpu MHz : 1333.000
cache size : 2048 KB
physical id : 0
siblings : 2
core id : 1
cpu cores : 2
Samples from /sys/devices/system/cpu/cpu*/cpufreq/scaling_cur_freq:
800000 800000
800000 800000
1333000 1333000 # Start single busy loop, one core idle
1333000 1333000
1333000 1333000
So in the first case frequency changes are reported as if the cores are
independent while in the second case the cores appear linked.
Is a Pentium D really different from a Core Duo in that respect?
On Thursday 21 August 2008, Maciej W. Rozycki wrote:
> On Wed, 20 Aug 2008, Rafael J. Wysocki wrote:
> > On my box I see many "APIC error on CPU1: 00(40)" messages that don't
> > seem to be related to anything obviously bad and I've alwas been
> > seeing them.
>
> Barring a hardware erratum, this is a bug in the kernel. It should be
> moderately easy to track down with some debugging added to writes
> accessing LVT and redirection table entries.
Could you please provide some more specific debugging instructions? I'm at
a complete loss what I should do here.
I just re-read the rest of the thread, but I'm afraid most of it is Greek
to me :-/
TIA,
FJP
On Thu, Aug 21, 2008 at 5:20 AM, Vegard Nossum <[email protected]> wrote:
> On Thu, Aug 21, 2008 at 1:51 PM, Maciej W. Rozycki <[email protected]> wrote:
>> Otherwise there is no correlation between the sequence of APIC writes and
>> an error triggering -- a bad vector in a LVT or interrupt redirection
>> entry will be reported whenever its associated interrupt line gets active
>> even though the entry might have been initialised long ago. Depending on
>> the device signalling hardware interrupts may quite often be ignored for a
>> long time without affecting the stability of the rest of the system.
>
> Ah, right. Here is a dump of the LVT registers:
>
> [00000320] = 000100ef
> [00000330] = 00000200
> [00000340] = 00010000
> [00000350] = 00010700
> [00000360] = 00000400
> [00000370] = 000000fe
>
> Maybe I've misunderstood something (again), but should those vectors
> really be 0 for 330-360? (At least 330 + 360, which are not masked.)
>
> Intel manual says: "Receive Illegal Vector : Set when the local APIC
> detects an illegal vector in the message it received, including an
> illegal vector code in the local vector table interrupts or in a
> self-interrupt."
>
> And 0 is clearly an illegal value for the vector code: "When an
> interrupt vector in the range 0 to 15 is sent or received through the
> local APIC, the APIC indicates an illegal vector in its Error Status
> Register [...]".
can you try dump the io apic registers too?
YH
On Sat, 30 Aug 2008, Frans Pop wrote:
> > Barring a hardware erratum, this is a bug in the kernel. It should be
> > moderately easy to track down with some debugging added to writes
> > accessing LVT and redirection table entries.
>
> Could you please provide some more specific debugging instructions? I'm at
> a complete loss what I should do here.
Debugging code can be added to apic_write() and io_apic_{write,modify}()
so that a warning is output into the kernel log whenever a suspicious
value is written to one of the vector registers. Similarly for MSI/HT
interrupts, although I do not know names of the functions involved off the
head. Due to performance considerations it is unfortunately infeasible to
have such debugging enabled in production kernels.
Maciej